On Feb 8, 2016, at 4:28 AM, Rob Crittenden 
<rcrit...@redhat.com<mailto:rcrit...@redhat.com>> wrote:

Timothy Geier wrote:
Greetings all,

For the record,this is a CentOS 7.2 box with all current patches. 
(ipa-server-4.2.0-15.el7.centos.3.x86_64, etc.)

The situation is that pki-tomcatd on the lone CA server in our IPA cluster 
refuses to start cleanly.  The issues started earlier this week after the certs
subsystemCert, ocspSigningCert, and auditSigningCert all simultaneously expired 
without warning; apparently, certmonger failed to renew them automatically.  We
attempted timeshifting and following instructions for what appeared to be 
similar issues, but nothing at all has worked.

Today, we attempted removing the certificates in question (of course, the files 
in /etc/pki/pki-tomcat/alias were backed up beforehand) and using certutil to 
issue new  certificates.   This process worked but pki-tomcatd is still 
refusing to start.  We can get IPA to run on this server by manually starting 
pki-tomcatd, running ipactl start, and then ctrl-c’ing it when it gets to 
"Starting pki-tomcatd" but this is not a tenable long-term solution.

Relevant log entries/information:

/var/log/pki/pki-tomcat/ca/debug:
Could not connect to LDAP server host 
ipa01.XXXXXXXXX.net<http://ipa01.XXXXXXXXX.net> port 636 Error 
netscape.ldap.LDAPException: IO Error creating JSS SSL Socket (-1)
Internal Database Error encountered: Could not connect to LDAP server host 
ipa01.XXXXXXXXX.net<http://ipa01.XXXXXXXXX.net> port 636 Error 
netscape.ldap.LDAPException: IO Error creating JSS SSL Socket (-1)
Internal Database Error encountered: Could not connect to LDAP server host 
ipa01.XXXXXXXXX.net<http://ipa01.XXXXXXXXX.net> port 636 Error 
netscape.ldap.LDAPException: Authentication failed (49)

/var/log/pki/pki-tomcat/localhost.2016-02-04.log:
org.apache.catalina.core.StandardContext loadOnStartup
SEVERE: Servlet /ca threw load() exception
java.lang.NullPointerException

# getcert list:

Number of certificates and requests being tracked: 8.
Request ID '20151015022737':
status: MONITORING
ca-error: Error setting up ccache for "host" service on client using default 
keytab: Generic error (see e-text).
stuck: no
key pair storage: 
type=NSSDB,location='/etc/dirsrv/slapd-XXXXXXXXX-NET',nickname='Server-Cert',token='NSS
 Certificate DB',pinfile='/etc/dirsrv/slapd-XXXXXXXXX-NET/pwdfile.txt'
expires: 2017-10-15 02:09:06 UTC
track: yes
auto-renew: yes
Request ID '20151015022949':
status: MONITORING
ca-error: Error setting up ccache for "host" service on client using default 
keytab: Generic error (see e-text).
stuck: no
key pair storage: 
type=NSSDB,location='/etc/httpd/alias',nickname='Server-Cert',token='NSS 
Certificate DB',pinfile='/etc/httpd/alias/pwdfile.txt'
certificate: 
type=NSSDB,location='/etc/httpd/alias',nickname='Server-Cert',token='NSS 
Certificate DB'
expires: 2017-10-15 02:09:10 UTC
track: yes
auto-renew: yes
Request ID '20160127202548':
status: MONITORING
stuck: no
key pair storage: 
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='caSigningCert 
cert-pki-ca',token='NSS Certificate DB',pin set
certificate: 
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='caSigningCert 
cert-pki-ca',token='NSS Certificate DB'
expires: 2034-02-11 19:46:43 UTC
track: yes
auto-renew: yes
Request ID '20160127202549':
status: MONITORING
stuck: no
key pair storage: 
type=NSSDB,location='/etc/httpd/alias',nickname='ipaCert',token='NSS 
Certificate DB',pinfile='/etc/httpd/alias/pwdfile.txt'
certificate: 
type=NSSDB,location='/etc/httpd/alias',nickname='ipaCert',token='NSS 
Certificate DB'
expires: 2017-12-25 04:27:49 UTC
key usage: digitalSignature,nonRepudiation,keyEncipherment,dataEncipherment
track: yes
auto-renew: yes
Request ID '20160127202550':
status: MONITORING
ca-error: Server at "http://ipa01.XXXXXXXXX.net:8080/ca/ee/ca/profileSubmit"; 
replied: Profile caServerCert Not Found
stuck: no
key pair storage: 
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='Server-Cert 
cert-pki-ca',token='NSS Certificate DB',pin set
certificate: 
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='Server-Cert 
cert-pki-ca',token='NSS Certificate DB'
expires: 2017-10-04 02:28:53 UTC
track: yes
auto-renew: yes
Request ID '20160204165453':
status: MONITORING
stuck: no
key pair storage: 
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='auditSigningCert 
cert-pki-ca',token='NSS Certificate DB',pin set
certificate: 
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='auditSigningCert 
cert-pki-ca',token='NSS Certificate DB'
expires: 2016-05-04 16:40:23 UTC
track: yes
auto-renew: yes
Request ID '20160204170246':
status: MONITORING
stuck: no
key pair storage: 
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='ocspSigningCert 
cert-pki-ca',token='NSS Certificate DB',pin set
certificate: 
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='ocspSigningCert 
cert-pki-ca',token='NSS Certificate DB'
expires: 2016-05-04 16:59:18 UTC
track: yes
auto-renew: yes
Request ID '20160204170752':
status: MONITORING
stuck: no
key pair storage: 
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='subsystemCert 
cert-pki-ca',token='NSS Certificate DB',pin set
certificate: 
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='subsystemCert 
cert-pki-ca',token='NSS Certificate DB'
expires: 2016-05-04 17:05:29 UTC
track: yes
auto-renew: yes

# certutil -L -d /var/lib/pki/pki-tomcat/alias/

Certificate Nickname                                         Trust Attributes
                                                             SSL,S/MIME,JAR/XPI
auditSigningCert cert-pki-ca                                 u,u,Pu
ocspSigningCert cert-pki-ca                                  u,u,u
caSigningCert cert-pki-ca                                    CTu,Cu,Cu
subsystemCert cert-pki-ca                                    u,u,u
Server-Cert cert-pki-ca                                      u,u,u

# certutil -L -d /etc/dirsrv/slapd-XXXXXXXXX-NET/

Certificate Nickname                                         Trust Attributes
                                                             SSL,S/MIME,JAR/XPI
Server-Cert                                                                 
u,u,u
XXXXXXXXX.NET<http://XXXXXXXXX.NET> IPA CA                                      
   CT,C,C



The only thing that making new certs seemed to resolve was removing these 
errors from /var/log/pki/pki-tomcat/ca/system :

Cannot authenticate agent with certificate Serial <redacted> Subject DN CN=IPA 
RA,O=XXXXXXXXX.NET<http://XXXXXXXXX.NET>. Error: User not found

Thus, the root cause(s) appears to be something else entirely that we are 
totally unfamilar with..we can provide any other required information to help 
with troubleshooting.

It appears that the CA is not fully starting, perhaps due to these renewal 
issues, perhaps something else. You'll need to dig into the logs. I'd start 
with /var/lib/pki/pki-ca/pki-tomcat/logs/debug and selftests.log.


The debug log has a lot of instances of:

Could not connect to LDAP server host xxx.xxxx port 636 Error 
netscape.ldap.LDAPException: IO Error creating JSS SSL Socket (-1)
Internal Database Error encountered: Could not connect to LDAP server host 
xxx.xxxx port 636 Error netscape.ldap.LDAPException: IO Error creating JSS SSL 
Socket (-1)

but nothing else of note other than those errors.

We’ve also noticed lots of 500 errors in 
/var/log/pki/pki-tomcat/localhost_access.log
[08/Feb/2016:10:34:29 -0600] "GET 
/ca/ee/ca/profileSubmit?profileId=caServerCert&serial_num=5&renewal=true&xml=true
 HTTP/1.1" 500 2134
[08/Feb/2016:10:34:32 -0600] "GET 
/ca/ee/ca/profileSubmit?profileId=caServerCert&serial_num=2&renewal=true&xml=true
 HTTP/1.1" 500 2134
[08/Feb/2016:10:34:50 -0600] "GET 
/ca/ee/ca/profileSubmit?profileId=caServerCert&serial_num=4&renewal=true&xml=true
 HTTP/1.1" 500 2134

which looks like certmonger is continuously trying to renew the 3 certs.

These dates and times from selftests.log are not accurate and are from an 
earlier attempt to renew the certs while time shifted:

0.localhost-startStop-1 - [15/Jan/2016:17:39:34 CST] [20] [1] 
SelfTestSubsystem: Initializing self test plugins:
0.localhost-startStop-1 - [15/Jan/2016:17:39:34 CST] [20] [1] 
SelfTestSubsystem:  loading all self test plugin logger parameters
0.localhost-startStop-1 - [15/Jan/2016:17:39:34 CST] [20] [1] 
SelfTestSubsystem:  loading all self test plugin instances
0.localhost-startStop-1 - [15/Jan/2016:17:39:34 CST] [20] [1] 
SelfTestSubsystem:  loading all self test plugin instance parameters
0.localhost-startStop-1 - [15/Jan/2016:17:39:34 CST] [20] [1] 
SelfTestSubsystem:  loading self test plugins in on-demand order
0.localhost-startStop-1 - [15/Jan/2016:17:39:34 CST] [20] [1] 
SelfTestSubsystem:  loading self test plugins in startup order
0.localhost-startStop-1 - [15/Jan/2016:17:39:34 CST] [20] [1] 
SelfTestSubsystem: Self test plugins have been successfully loaded!
0.localhost-startStop-1 - [15/Jan/2016:17:39:38 CST] [20] [1] 
SelfTestSubsystem: Running self test plugins specified to be executed at 
startup:
0.localhost-startStop-1 - [15/Jan/2016:17:39:38 CST] [20] [1] CAPresence:  CA 
is present
0.localhost-startStop-1 - [15/Jan/2016:17:39:38 CST] [20] [1] 
SystemCertsVerification: system certs verification success
0.localhost-startStop-1 - [15/Jan/2016:17:39:38 CST] [20] [1] 
SelfTestSubsystem: All CRITICAL self test plugins ran SUCCESSFULLY at startup!

There’s nothing in that log with any February dates, so when we try to start 
pki-tomcatd in real time, it's likely not even getting this far.

You mentioned privately that you renamed the IPA host. This is probably what 
broke half of the renewals. The hosts and keytabs and many entries in IPA have 
the hostname baked in so you can't simply rename the host.


Technically, the host wasn’t renamed; a new CentOS 7 host was added to the 
existing IPA cluster that had 4 hosts (1 master CA) at CentOS 6 (using the 
documentation at 
https://access.redhat.com/documentation/en-US/Red_Hat_Enterprise_Linux/7/html/Linux_Domain_Identity_Authentication_and_Policy_Guide/upgrading.html),
 it was promoted to the master CA, all of the C6 hosts were 
decommissioned/removed from replication, and then a new set of C7 hosts were 
created and added as replicas.

Is this the correct procedure to follow when time shifted?

- Stop IPA
- Change the system clock (and the hardware clock) to a point before the 
expiration
- Start IPA
- Run getcert resubmit on the appropriate request IDs
- Stop IPA
- Return to real time
- Start IPA

We haven’t tried it this week yet but all attempts at it last week failed 
without any indication as to why the certs weren’t renewing; are there any 
other logs to check/other steps in the procedure?

Thanks much,

rob





"This message and any attachments may contain confidential information. If you
have received this  message in error, any use or distribution is prohibited. 
Please notify us by reply e-mail if you have mistakenly received this message,
and immediately and permanently delete it and any attachments. Thank you."
-- 
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go to http://freeipa.org for more info on the project

Reply via email to