Bugzilla will be upgraded to version 5.0. The upgrade date is tentatively scheduled for 2 December 2018, pending final testing and feedback.
First Last Prev Next    This bug is not in your last search results.
Bug 1173207 - IPA certs fail to autorenew simultaneouly
IPA certs fail to autorenew simultaneouly
Status: CLOSED ERRATA
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: ipa (Show other bugs)
7.1
Unspecified Unspecified
medium Severity unspecified
: rc
: ---
Assigned To: IPA Maintainers
Namita Soman
:
Depends On:
Blocks:
  Show dependency tree / graph
 
Reported: 2014-12-11 11:50 EST by Scott Poore
Modified: 2015-03-05 05:18 EST (History)
4 users (show)

See Also:
Fixed In Version: ipa-4.1.0-14.el7
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2015-03-05 05:18:57 EST
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---

Attachments (Terms of Use)
pki debug log (11.38 MB, text/plain)
2014-12-11 12:09 EST, Scott Poore 		no flags Details
all of /var/log (1.40 MB, application/x-gzip)
2014-12-11 12:09 EST, Scott Poore 		no flags Details
Add an attachment (proposed patch, testcase, etc.)


External Trackers
Tracker ID Priority Status Summary Last Updated
Red Hat Product Errata RHSA-2015:0442 normal SHIPPED_LIVE Moderate: ipa security, bug fix, and enhancement update 2015-03-05 09:50:39 EST

  None (edit)
Description Scott Poore 2014-12-11 11:50:20 EST 
Description of problem:

Testing IPA CA Certificate autorenewal I am seeing certificate autorenewal fail because it's trying to renew everything at the same time.

Version-Release number of selected component (if applicable):
ipa-server-4.1.0-12.el7.x86_64
certmonger-0.75.14-2.el7.x86_64
pki-ca-10.1.2-5.el7.noarch


How reproducible:
always

Steps to Reproduce:

1.  Setup IPA server

ipa-server-install --setup-dns --forwarder=<IP> -r <REALM> -a <PASSWORD> -p <PASSWORD> -U

2.  Walk the time forward till you reach the CA Certificate renewal threshold.

getcert list | egrep "status|expires|Request|subject|ca-error"
date -u <soonest expiration date - 4 weeks>
# check with getcert until everything back in monitoring then repeat

3.  When you reach time for CA expire, all certs should show same expiration equal to that of CA certificate's.  

4.  Change time to within 4 weeks of expiration.


Actual results:

[root@vm1 ~]# date -u; getcert list | egrep "status|expires|Request|subject|ca-error"
Mon Nov 13 15:06:03 UTC 2034
Request ID '20141211150642':
	status: NOTIFYING_VALIDITY
	subject: CN=CA Audit,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150643':
	status: NOTIFYING_VALIDITY
	subject: CN=OCSP Subsystem,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150644':
	status: NOTIFYING_VALIDITY
	subject: CN=CA Subsystem,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150645':
	status: NOTIFYING_VALIDITY
	subject: CN=Certificate Authority,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150646':
	status: NOTIFYING_VALIDITY
	subject: CN=IPA RA,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150647':
	status: GENERATING_CSR
	subject: CN=vm1.example.test,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150648':
	status: GENERATING_CSR
	subject: CN=vm1.example.test,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150715':
	status: GENERATING_CSR
	subject: CN=vm1.example.test,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC

[root@vm1 ~]# date -u; getcert list | egrep "status|expires|Request|subject|ca-error"
Mon Nov 13 15:06:46 UTC 2034
Request ID '20141211150642':
	status: CA_UNREACHABLE
	ca-error: Internal error
	subject: CN=CA Audit,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150643':
	status: CA_UNREACHABLE
	ca-error: Internal error
	subject: CN=OCSP Subsystem,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150644':
	status: CA_UNREACHABLE
	ca-error: Internal error
	subject: CN=CA Subsystem,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150645':
	status: CA_UNREACHABLE
	ca-error: Internal error
	subject: CN=Certificate Authority,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150646':
	status: CA_UNREACHABLE
	ca-error: Internal error
	subject: CN=IPA RA,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150647':
	status: CA_UNREACHABLE
	ca-error: Error 7 connecting to http://vm1.example.test:8080/ca/ee/ca/profileSubmit: Couldn't connect to server.
	subject: CN=vm1.example.test,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150648':
	status: CA_UNREACHABLE
	ca-error: Error setting up ccache for "host" service on client using default keytab: Cannot contact any KDC for realm 'EXAMPLE.TEST'.
	subject: CN=vm1.example.test,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150715':
	status: CA_UNREACHABLE
	ca-error: Error setting up ccache for "host" service on client using default keytab: Cannot contact any KDC for realm 'EXAMPLE.TEST'.
	subject: CN=vm1.example.test,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC

Expected results:

CA Certificate renews first, then others in proper order to prevent CA_UNREACHABLE due to conflicts with renewing some at the same time.

Additional info:
I'll also attach the PKI debug log.
Comment 2 Scott Poore 2014-12-11 12:09:10 EST 
Created attachment 967330 [details]
pki debug log

Unfortunately I had truncated the previous test run debug log.  Here's a second run though.

[root@vm1 ~]# date -u; getcert list | egrep "status|expires|Request|subject|ca-error"
Thu Dec 11 17:00:16 UTC 2014
Request ID '20141211150642':
	status: MONITORING
	subject: CN=CA Audit,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150643':
	status: MONITORING
	subject: CN=OCSP Subsystem,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150644':
	status: MONITORING
	subject: CN=CA Subsystem,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150645':
	status: MONITORING
	subject: CN=Certificate Authority,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150646':
	status: MONITORING
	subject: CN=IPA RA,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150647':
	status: MONITORING
	subject: CN=vm1.example.test,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150648':
	status: MONITORING
	subject: CN=vm1.example.test,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150715':
	status: MONITORING
	subject: CN=vm1.example.test,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC

[root@vm1 ~]# date -u 111315062034
Mon Nov 13 15:06:00 UTC 2034

[root@vm1 ~]# date -u; getcert list | egrep "status|expires|Request|subject|ca-error"
Mon Nov 13 15:06:03 UTC 2034
Request ID '20141211150642':
	status: NOTIFYING_VALIDITY
	subject: CN=CA Audit,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150643':
	status: NOTIFYING_VALIDITY
	subject: CN=OCSP Subsystem,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150644':
	status: NOTIFYING_VALIDITY
	subject: CN=CA Subsystem,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150645':
	status: NOTIFYING_VALIDITY
	subject: CN=Certificate Authority,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150646':
	status: NOTIFYING_VALIDITY
	subject: CN=IPA RA,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150647':
	status: GENERATING_CSR
	subject: CN=vm1.example.test,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150648':
	status: GENERATING_CSR
	subject: CN=vm1.example.test,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150715':
	status: GENERATING_CSR
	subject: CN=vm1.example.test,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC


[root@vm1 ~]# date -u; getcert list | egrep "status|expires|Request|subject|ca-error"
Mon Nov 13 15:10:25 UTC 2034
Request ID '20141211150642':
	status: CA_UNREACHABLE
	ca-error: Internal error
	subject: CN=CA Audit,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150643':
	status: CA_UNREACHABLE
	ca-error: Internal error
	subject: CN=OCSP Subsystem,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150644':
	status: CA_UNREACHABLE
	ca-error: Internal error
	subject: CN=CA Subsystem,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150645':
	status: CA_UNREACHABLE
	ca-error: Internal error
	subject: CN=Certificate Authority,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150646':
	status: CA_UNREACHABLE
	ca-error: Internal error
	subject: CN=IPA RA,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150647':
	status: CA_UNREACHABLE
	ca-error: Error 7 connecting to http://vm1.example.test:8080/ca/ee/ca/profileSubmit: Couldn't connect to server.
	subject: CN=vm1.example.test,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150648':
	status: CA_UNREACHABLE
	ca-error: Error setting up ccache for "host" service on client using default keytab: Cannot contact any KDC for realm 'EXAMPLE.TEST'.
	subject: CN=vm1.example.test,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Request ID '20141211150715':
	status: CA_UNREACHABLE
	ca-error: Error setting up ccache for "host" service on client using default keytab: Cannot contact any KDC for realm 'EXAMPLE.TEST'.
	subject: CN=vm1.example.test,O=EXAMPLE.TEST
	expires: 2034-12-11 15:06:02 UTC
Comment 3 Scott Poore 2014-12-11 12:09:45 EST 
Created attachment 967331 [details]
all of /var/log
Comment 4 Jan Cholasta 2014-12-12 05:12:01 EST 
Upstream ticket:
https://fedorahosted.org/freeipa/ticket/4803
Comment 7 Scott Poore 2015-01-14 20:16:28 EST 
Verified.

Version ::

ipa-server-4.1.0-15.el7.x86_64

Results ::

I setup a self-signed install and walked the time forward incrementally until I reached the CA cert expiration threshold.  

 Starting expirations:

[root@vm1 ~]# getcert list | egrep "status|expires|Request|subject|ca-error"
Request ID '20150114194236':
    status: MONITORING
    subject: CN=CA Audit,O=EXAMPLE.TEST
    expires: 2017-01-03 19:42:01 UTC
Request ID '20150114194237':
    status: MONITORING
    subject: CN=OCSP Subsystem,O=EXAMPLE.TEST
    expires: 2017-01-03 19:42:01 UTC
Request ID '20150114194238':
    status: MONITORING
    subject: CN=CA Subsystem,O=EXAMPLE.TEST
    expires: 2017-01-03 19:42:01 UTC
Request ID '20150114194239':
    status: MONITORING
    subject: CN=Certificate Authority,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Request ID '20150114194240':
    status: MONITORING
    subject: CN=IPA RA,O=EXAMPLE.TEST
    expires: 2017-01-03 19:42:35 UTC
Request ID '20150114194241':
    status: MONITORING
    subject: CN=vm1.example.test,O=EXAMPLE.TEST
    expires: 2017-01-03 19:42:01 UTC
Request ID '20150114194242':
    status: MONITORING
    subject: CN=vm1.example.test,O=EXAMPLE.TEST
    expires: 2017-01-14 19:42:42 UTC
Request ID '20150114194304':
    status: MONITORING
    subject: CN=vm1.example.test,O=EXAMPLE.TEST
    expires: 2017-01-14 19:43:03 UTC

[root@vm1 ~]# date
Wed Jan 14 13:46:08 CST 2015


After walking time forward, I stopped right before the last step forward in time to capture a stable state:

[root@vm1 ~]# g
Request ID '20150114194236':
    status: MONITORING
    subject: CN=CA Audit,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Request ID '20150114194237':
    status: MONITORING
    subject: CN=OCSP Subsystem,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Request ID '20150114194238':
    status: MONITORING
    subject: CN=CA Subsystem,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Request ID '20150114194239':
    status: MONITORING
    subject: CN=Certificate Authority,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Request ID '20150114194240':
    status: MONITORING
    subject: CN=IPA RA,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Request ID '20150114194241':
    status: MONITORING
    subject: CN=vm1.example.test,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Request ID '20150114194242':
    status: MONITORING
    subject: CN=vm1.example.test,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Request ID '20150114194304':
    status: MONITORING
    subject: CN=vm1.example.test,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Thu May 4 22:43:43 CDT 2034

And here I can see it attempts to autorenew everything simultaneously:

[root@vm1 ~]# date -u 121919422034
Tue Dec 19 19:42:00 UTC 2034

[root@vm1 ~]# g
Request ID '20150114194236':
    status: NOTIFYING_VALIDITY
    subject: CN=CA Audit,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Request ID '20150114194237':
    status: NOTIFYING_VALIDITY
    subject: CN=OCSP Subsystem,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Request ID '20150114194238':
    status: NOTIFYING_VALIDITY
    subject: CN=CA Subsystem,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Request ID '20150114194239':
    status: NOTIFYING_VALIDITY
    subject: CN=Certificate Authority,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Request ID '20150114194240':
    status: NOTIFYING_VALIDITY
    subject: CN=IPA RA,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Request ID '20150114194241':
    status: GENERATING_CSR
    subject: CN=vm1.example.test,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Request ID '20150114194242':
    status: GENERATING_CSR
    subject: CN=vm1.example.test,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Request ID '20150114194304':
    status: GENERATING_CSR
    subject: CN=vm1.example.test,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Tue Dec 19 13:42:06 CST 2034

Then wait for a while and check back to see that the CA has renewed and everything is back in MONITORING and nothing fell to CA_UNREACHABLE:

[root@vm1 ~]# sleep 180

[root@vm1 ~]# g
Request ID '20150114194236':
    status: MONITORING
    subject: CN=CA Audit,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Request ID '20150114194237':
    status: MONITORING
    subject: CN=OCSP Subsystem,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Request ID '20150114194238':
    status: MONITORING
    subject: CN=CA Subsystem,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Request ID '20150114194239':
    status: MONITORING
    subject: CN=Certificate Authority,O=EXAMPLE.TEST
    expires: 2054-12-19 19:43:22 UTC
Request ID '20150114194240':
    status: MONITORING
    subject: CN=IPA RA,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Request ID '20150114194241':
    status: MONITORING
    subject: CN=vm1.example.test,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Request ID '20150114194242':
    status: MONITORING
    subject: CN=vm1.example.test,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Request ID '20150114194304':
    status: MONITORING
    subject: CN=vm1.example.test,O=EXAMPLE.TEST
    expires: 2035-01-14 19:42:00 UTC
Tue Dec 19 13:46:08 CST 2034
Comment 9 errata-xmlrpc 2015-03-05 05:18:57 EST 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHSA-2015-0442.html
Note You need to log in before you can comment on or make changes to this bug.
First Last Prev Next    This bug is not in your last search results.