[Freeipa-users] Certificate not found: auditSigningCert cert-pki-ca - Can't run pki-tomcatd Service

[Ferdinand Babas]

Hi All,

I've been trying to work through this issue but can't find the magic formula to
get it working so I'm turning to the community for help.

We are currently running VERSION: 4.4.0, API_VERSION: 2.213 in a 4 node multi master
environment and the steps listed below were performed on the IPA CA renewal master. 
Please let me know if any additional information is needed regarding the environment.

As background we had expired certificates (both /etc/httpd/alias and
/etc/pki/pki-tomcat/alias) which were renewed by setting the date in the past and
restarting certmonger.  Now on the IPA CA renewal master all certs have valid
'expires' dates and have a status of MONITORING.  Note that the other nodes still
have expired certs.

On the IPA CA renewal master when I start up the pki-tomcatd(a)pki-tomcat.service with the
default CS.cfg and password.conf file I get the following error:

Internal Database Error encountered: Could not connect to LDAP server host francolin.local
port 636 Error netscape.ldap.LDAPException: Authentication failed (48)

So I changed the CS.cfg file to use Basic Auth and added the directory-manager-password to
password.conf, restarted pki-tomcatd(a)pki-tomcat.service and now I get the following:

/var/log/messages

Jan  6 10:54:30 francolin systemd: Started PKI Tomcat Server pki-tomcat.
Jan  6 10:54:30 francolin server: Java virtual machine used:
/usr/lib/jvm/jre-1.8.0-openjdk/bin/java
Jan  6 10:54:30 francolin server: classpath used:
/usr/share/tomcat/bin/bootstrap.jar:/usr/share/tomcat/bin/tomcat-juli.jar:/usr/share/java/commons-daemon.jar
Jan  6 10:54:30 francolin server: main class used: org.apache.catalina.startup.Bootstrap
Jan  6 10:54:30 francolin server: flags used: -DRESTEASY_LIB=/usr/share/java/resteasy-base
-Djava.library.path=/usr/lib64/nuxwdog-jni
Jan  6 10:54:30 francolin server: options used: -Dcatalina.base=/var/lib/pki/pki-tomcat
-Dcatalina.home=/usr/share/tomcat -Djava.endorsed.dirs=
-Djava.io.tmpdir=/var/lib/pki/pki-tomcat/temp
-Djava.util.logging.config.file=/var/lib/pki/pki-tomcat/conf/logging.properties
-Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager    
-Djava.security.manager    
-Djava.security.policy==/var/lib/pki/pki-tomcat/conf/catalina.policy
Jan  6 10:54:30 francolin server: arguments used: start
Jan  6 10:54:30 francolin server: WARNING: Problem with JAR file
[/usr/share/pki/server/common/lib/symkey.jar], exists: [false], canRead: [false]
Jan  6 10:54:31 francolin server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'enableOCSP' to
'false' did not find a matching property.
Jan  6 10:54:31 francolin server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'ocspResponderURL' to 'http://francolin.local:9080/ca/ocsp' did not find a
matching property.
Jan  6 10:54:31 francolin server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'ocspResponderCertNickname' to 'ocspSigningCert cert-pki-ca' did not find
a matching property.
Jan  6 10:54:31 francolin server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'ocspCacheSize'
to '1000' did not find a matching property.
Jan  6 10:54:31 francolin server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'ocspMinCacheEntryDuration' to '60' did not find a matching property.
Jan  6 10:54:31 francolin server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'ocspMaxCacheEntryDuration' to '120' did not find a matching property.
Jan  6 10:54:31 francolin server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'ocspTimeout' to
'10' did not find a matching property.
Jan  6 10:54:31 francolin server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'strictCiphers'
to 'true' did not find a matching property.
Jan  6 10:54:31 francolin server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'sslOptions' to
'ssl2=false,ssl3=false,tls=true' did not find a matching property.
Jan  6 10:54:31 francolin server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'ssl2Ciphers' to
'-SSL2_RC4_128_WITH_MD5,-SSL2_RC4_128_EXPORT40_WITH_MD5,-SSL2_RC2_128_CBC_WITH_MD5,-SSL2_RC2_128_CBC_EXPORT40_WITH_MD5,-SSL2_DES_64_CBC_WITH_MD5,-SSL2_DES_192_EDE3_CBC_WITH_MD5'
did not find a matching property.
Jan  6 10:54:31 francolin server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'ssl3Ciphers' to
'-SSL3_FORTEZZA_DMS_WITH_NULL_SHA,-SSL3_FORTEZZA_DMS_WITH_RC4_128_SHA,+SSL3_RSA_WITH_RC4_128_SHA,-SSL3_RSA_EXPORT_WITH_RC4_40_MD5,+SSL3_RSA_WITH_3DES_EDE_CBC_SHA,-SSL3_RSA_WITH_DES_CBC_SHA,-SSL3_RSA_EXPORT_WITH_RC2_CBC_40_MD5,-SSL3_FORTEZZA_DMS_WITH_FORTEZZA_CBC_SHA,-SSL_RSA_FIPS_WITH_DES_CBC_SHA,+SSL_RSA_FIPS_WITH_3DES_EDE_CBC_SHA,-SSL3_RSA_WITH_NULL_MD5,-TLS_RSA_EXPORT1024_WITH_RC4_56_SHA,-TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA,+TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA'
did not find a matching property.
Jan  6 10:54:31 francolin server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'tlsCiphers' to
'-TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA,-TLS_ECDH_ECDSA_WITH_3DES_EDE_CBC_SHA,+TLS_ECDH_RSA_WITH_3DES_EDE_CBC_SHA,+TLS_ECDH_RSA_WITH_AES_128_CBC_SHA,+TLS_ECDH_RSA_WITH_AES_256_CBC_SHA,-TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA,+TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA,+TLS_RSA_WITH_3DES_EDE_CBC_SHA,+TLS_RSA_WITH_AES_128_CBC_SHA,+TLS_RSA_WITH_AES_256_CBC_SHA,+TLS_ECDHE_ECDSA_WITH_3DES_EDE_CBC_SHA,+TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA,-TLS_ECDHE_RSA_WITH_3DES_EDE_CBC_SHA,-TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA,-TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA,+TLS_DHE_DSS_WITH_3DES_EDE_CBC_SHA,+TLS_DHE_DSS_WITH_AES_128_CBC_SHA,+TLS_DHE_DSS_WITH_AES_256_CBC_SHA,+TLS_DHE_RSA_WITH_3DES_EDE_CBC_SHA,+TLS_DHE_RSA_WITH_AES_128_CBC_SHA,+TLS_DHE_RSA_WITH_AES_256_CBC_SHA'
did not find a matching property.
Jan  6 10:54:31 francolin server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'sslVersionRangeStream' to 'tls1_0:tls1_2' did not find a matching
property.
Jan  6 10:54:31 francolin server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'sslVersionRangeDatagram' to 'tls1_1:tls1_2' did not find a matching
property.
Jan  6 10:54:31 francolin server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'sslRangeCiphers' to
'-TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA,-TLS_ECDH_ECDSA_WITH_3DES_EDE_CBC_SHA,-TLS_ECDH_RSA_WITH_3DES_EDE_CBC_SHA,-TLS_ECDH_RSA_WITH_AES_128_CBC_SHA,-TLS_ECDH_RSA_WITH_AES_256_CBC_SHA,-TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA,-TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA,-TLS_ECDHE_ECDSA_WITH_3DES_EDE_CBC_SHA,-TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA,-TLS_ECDHE_RSA_WITH_3DES_EDE_CBC_SHA,-TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA,-TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA,-TLS_DHE_DSS_WITH_3DES_EDE_CBC_SHA,-TLS_DHE_DSS_WITH_AES_128_CBC_SHA,-TLS_DHE_DSS_WITH_AES_256_CBC_SHA,-TLS_DHE_RSA_WITH_3DES_EDE_CBC_SHA,-TLS_DHE_RSA_WITH_AES_128_CBC_SHA,-TLS_DHE_RSA_WITH_AES_256_CBC_SHA,-TLS_DHE_RSA_WITH_AES_128_CBC_SHA256,-TLS_DHE_RSA_WITH_AES_256_CBC_SHA256,-TLS_DHE_RSA_WITH_AES_128_GCM_SHA256,-TLS_DHE_DSS_WITH_AES_128_GCM_SHA256,-TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256,-TLS_ECDHE_RSA_WITH_AES_128_CB

C_SHA256,-TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256,-TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256,-TLS_RSA_WITH_AES_128_CBC_SHA256,-TLS_RSA_WITH_AES_256_CBC_SHA256,-TLS_RSA_WITH_AES_128_GCM_SHA256,+TLS_RSA_WITH_3DES_EDE_CBC_SHA,+TLS_RSA_WITH_AES_128_CBC_SHA,+TLS_RSA_WITH_AES_256_CBC_SHA'
did not find a matching property.
Jan  6 10:54:31 francolin server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'serverCertNickFile' to '/var/lib/pki/pki-tomcat/conf/serverCertNick.conf'
did not find a matching property.
Jan  6 10:54:31 francolin server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'passwordFile'
to '/var/lib/pki/pki-tomcat/conf/password.conf' did not find a matching property.
Jan  6 10:54:31 francolin server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'passwordClass'
to 'org.apache.tomcat.util.net.jss.PlainPasswordFile' did not find a matching
property.
Jan  6 10:54:31 francolin server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'certdbDir' to
'/var/lib/pki/pki-tomcat/alias' did not find a matching property.
Jan  6 10:54:31 francolin server: WARNING: [SetPropertiesRule]{Server/Service/Engine/Host}
Setting property 'xmlValidation' to 'false' did not find a matching
property.
Jan  6 10:54:31 francolin server: WARNING: [SetPropertiesRule]{Server/Service/Engine/Host}
Setting property 'xmlNamespaceAware' to 'false' did not find a matching
property.
Jan  6 10:54:31 francolin server: PKIListener:
org.apache.catalina.core.StandardServer[before_init]
Jan  6 10:54:31 francolin server: PKIListener:
org.apache.catalina.core.StandardServer[after_init]
Jan  6 10:54:31 francolin server: PKIListener:
org.apache.catalina.core.StandardServer[before_start]
Jan  6 10:54:31 francolin server: PKIListener:
org.apache.catalina.core.StandardServer[configure_start]
Jan  6 10:54:31 francolin server: PKIListener:
org.apache.catalina.core.StandardServer[start]
Jan  6 10:54:31 francolin server: SSLAuthenticatorWithFallback: Creating SSL authenticator
with fallback
Jan  6 10:54:31 francolin server: SSLAuthenticatorWithFallback: Setting container
Jan  6 10:54:32 francolin server: SSLAuthenticatorWithFallback: Initializing
authenticators
Jan  6 10:54:32 francolin server: SSLAuthenticatorWithFallback: Starting authenticators
Jan  6 10:54:33 francolin server: CMSEngine.initializePasswordStore() begins
Jan  6 10:54:33 francolin server: CMSEngine.initializePasswordStore(): tag=internaldb
Jan  6 10:54:33 francolin server: testLDAPConnection connecting to francolin.local:389
Jan  6 10:54:33 francolin server: CMSEngine.initializePasswordStore(): tag=replicationdb
Jan  6 10:54:33 francolin server: testLDAPConnection connecting to francolin.local:389
Jan  6 10:54:33 francolin server: testLDAPConnection: The specified user cn=Replication
Manager masterAgreement1-francolin.local-pki-tomcat,cn=config does not exist
Jan  6 10:54:33 francolin server: CMSEngine: init(): password test execution failed for
replicationdbwith NO_SUCH_USER.  This may not be a latest instance.  Ignoring ..
Jan  6 10:54:34 francolin server: SelfTestSubsystem: Disabling "ca" subsystem
due to selftest failure.
Jan  6 10:54:34 francolin server: -----------------------
Jan  6 10:54:34 francolin server: Disabled "ca" subsystem
Jan  6 10:54:34 francolin server: -----------------------
Jan  6 10:54:34 francolin server: Subsystem ID: ca
Jan  6 10:54:34 francolin server: Instance ID: pki-tomcat
Jan  6 10:54:34 francolin server: Enabled: False
Jan  6 10:54:34 francolin server: Invalid class name repositorytop
Jan  6 10:54:35 francolin server: Invalid class name repositorytop
Jan  6 10:54:35 francolin server: at
com.netscape.cmscore.dbs.DBRegistry.createObject(DBRegistry.java:485)
Jan  6 10:54:35 francolin server: at
com.netscape.cmscore.dbs.DBSSession.read(DBSSession.java:167)
Jan  6 10:54:35 francolin server: at
com.netscape.cmscore.dbs.DBSSession.read(DBSSession.java:137)
Jan  6 10:54:35 francolin server: at
com.netscape.cmscore.dbs.Repository.getSerialNumber(Repository.java:125)
Jan  6 10:54:35 francolin server: at
com.netscape.cmscore.dbs.Repository.initCache(Repository.java:244)
Jan  6 10:54:35 francolin server: at
com.netscape.cmscore.dbs.Repository.checkRanges(Repository.java:460)
Jan  6 10:54:35 francolin server: at
com.netscape.cmscore.apps.CMSEngine.startup(CMSEngine.java:1374)
Jan  6 10:54:35 francolin server: at com.netscape.certsrv.apps.CMS.startup(CMS.java:201)
Jan  6 10:54:35 francolin server: at com.netscape.certsrv.apps.CMS.start(CMS.java:1622)
Jan  6 10:54:35 francolin server: at
com.netscape.cms.servlet.base.CMSStartServlet.init(CMSStartServlet.java:114)
Jan  6 10:54:35 francolin server: at
javax.servlet.GenericServlet.init(GenericServlet.java:158)
Jan  6 10:54:35 francolin server: at sun.reflect.NativeMethodAccessorImpl.invoke0(Native
Method)
Jan  6 10:54:35 francolin server: at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
Jan  6 10:54:35 francolin server: at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
Jan  6 10:54:35 francolin server: at java.lang.reflect.Method.invoke(Method.java:498)
Jan  6 10:54:35 francolin server: at
org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:288)
Jan  6 10:54:35 francolin server: at
org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:285)
Jan  6 10:54:35 francolin server: at java.security.AccessController.doPrivileged(Native
Method)
Jan  6 10:54:35 francolin server: at
javax.security.auth.Subject.doAsPrivileged(Subject.java:549)
Jan  6 10:54:35 francolin server: at
org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:320)
Jan  6 10:54:35 francolin server: at
org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:175)
Jan  6 10:54:35 francolin server: at
org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:124)
Jan  6 10:54:35 francolin server: at
org.apache.catalina.core.StandardWrapper.initServlet(StandardWrapper.java:1270)
Jan  6 10:54:35 francolin server: at
org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1195)
Jan  6 10:54:35 francolin server: at
org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:1085)
Jan  6 10:54:35 francolin server: at
org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:5318)
Jan  6 10:54:35 francolin server: at
org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5610)
Jan  6 10:54:35 francolin server: at
org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:147)
Jan  6 10:54:35 francolin server: at
org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:899)
Jan  6 10:54:35 francolin server: at
org.apache.catalina.core.ContainerBase.access$000(ContainerBase.java:133)
Jan  6 10:54:35 francolin server: at
org.apache.catalina.core.ContainerBase$PrivilegedAddChild.run(ContainerBase.java:156)
Jan  6 10:54:35 francolin server: at
org.apache.catalina.core.ContainerBase$PrivilegedAddChild.run(ContainerBase.java:145)
Jan  6 10:54:35 francolin server: at java.security.AccessController.doPrivileged(Native
Method)
Jan  6 10:54:35 francolin server: at
org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:873)
Jan  6 10:54:35 francolin server: at
org.apache.catalina.core.StandardHost.addChild(StandardHost.java:652)
Jan  6 10:54:35 francolin server: at
org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:679)
Jan  6 10:54:35 francolin server: at
org.apache.catalina.startup.HostConfig$DeployDescriptor.run(HostConfig.java:1966)
Jan  6 10:54:35 francolin server: at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
Jan  6 10:54:35 francolin server: at
java.util.concurrent.FutureTask.run(FutureTask.java:266)
Jan  6 10:54:35 francolin server: at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
Jan  6 10:54:35 francolin server: at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
Jan  6 10:54:35 francolin server: at java.lang.Thread.run(Thread.java:748)
Jan  6 10:54:36 francolin server: PKIListener:
org.apache.catalina.core.StandardServer[after_start]
Jan  6 10:54:36 francolin server: PKIListener: Subsystem CA is disabled.
Jan  6 10:54:36 francolin server: PKIListener: Check
/var/log/pki/pki-tomcat/ca/selftests.log for possible errors.
Jan  6 10:54:36 francolin server: PKIListener: To enable the subsystem:
Jan  6 10:54:36 francolin server: PKIListener:   pki-server subsystem-enable -i pki-tomcat
ca
Jan  6 10:54:47 francolin server: SSLAuthenticatorWithFallback: Stopping authenticators
Jan  6 10:54:47 francolin server: SEVERE: The web application [/ca] appears to have
started a thread named [LDAPConnThread-3 ldaps://francolin.local:389] but has failed to
stop it. This is very likely to create a memory leak.
Jan  6 10:54:47 francolin server: SEVERE: The web application [/ca] appears to have
started a thread named [LDAPConnThread-7 ldaps://francolin.local:389] but has failed to
stop it. This is very likely to create a memory leak.
Jan  6 10:54:47 francolin server: SEVERE: The web application [/ca] appears to have
started a thread named [authorityMonitor] but has failed to stop it. This is very likely
to create a memory leak.
Jan  6 10:54:47 francolin server: SEVERE: The web application [/ca] appears to have
started a thread named [LDAPConnThread-9 ldaps://francolin.local:389] but has failed to
stop it. This is very likely to create a memory leak.
Jan  6 10:54:47 francolin server: SEVERE: The web application [/ca] appears to have
started a thread named [profileChangeMonitor] but has failed to stop it. This is very
likely to create a memory leak.
Jan  6 10:54:47 francolin server: SSLAuthenticatorWithFallback: Setting container

/var/log/pki/pki-tomcat/ca/selftests.log

0.localhost-startStop-2 - [06/Jan/2020:10:56:29 HST] [20] [1] SelfTestSubsystem:
Initializing self test plugins:
0.localhost-startStop-2 - [06/Jan/2020:10:56:29 HST] [20] [1] SelfTestSubsystem:  loading
all self test plugin logger parameters
0.localhost-startStop-2 - [06/Jan/2020:10:56:29 HST] [20] [1] SelfTestSubsystem:  loading
all self test plugin instances
0.localhost-startStop-2 - [06/Jan/2020:10:56:29 HST] [20] [1] SelfTestSubsystem:  loading
all self test plugin instance parameters
0.localhost-startStop-2 - [06/Jan/2020:10:56:29 HST] [20] [1] SelfTestSubsystem:  loading
self test plugins in on-demand order
0.localhost-startStop-2 - [06/Jan/2020:10:56:29 HST] [20] [1] SelfTestSubsystem:  loading
self test plugins in startup order
0.localhost-startStop-2 - [06/Jan/2020:10:56:29 HST] [20] [1] SelfTestSubsystem: Self test
plugins have been successfully loaded!
0.localhost-startStop-2 - [06/Jan/2020:10:56:29 HST] [20] [1] SelfTestSubsystem: Running
self test plugins specified to be executed at startup:
0.localhost-startStop-2 - [06/Jan/2020:10:56:29 HST] [20] [1] CAPresence:  CA is present
0.localhost-startStop-2 - [06/Jan/2020:10:56:29 HST] [20] [1] SystemCertsVerification:
system certs verification failure: Certificate not found: auditSigningCert cert-pki-ca
0.localhost-startStop-2 - [06/Jan/2020:10:56:29 HST] [20] [1] SelfTestSubsystem: The
CRITICAL self test plugin called selftests.container.instance.SystemCertsVerification
running at startup FAILED!

I can also confirm that the 'auditSigningCert cert-pka-ca' isn't there when I
run certutil -L -d /etc/pki/pki-tomcat/alias/.  The output is listed below:

Certificate Nickname                                         Trust Attributes
                                                             SSL,S/MIME,JAR/XPI

subsystemCert cert-pki-ca                                    ,,
Server-Cert cert-pki-ca                                      u,u,u
caSigningCert cert-pki-ca                                    CTu,Cu,Cu
ocspSigningCert cert-pki-ca                                  u,u,u

The 'auditSigningCert cert-pka-ca' shows up on the other nodes however:

auditSigningCert cert-pki-ca                                 u,u,Pu

Let me know if there is more information that is needed.  This one is baffling me.

Thanks,

Ferdinand