Sean McLennan via FreeIPA-users wrote:
> Similar to a number of other posts, I have a server on which pki-tomcatd
> won't start.
>
> I just have two servers; a master and replica. I haven't upgraded anything
> recently. The problem started two days ago when the server certificates
> renewed. The renewal appears to have been executed successfully and getcert
> list on both machines shows valid certs (many recently renewed). I believe
> it was the certificate renewal that triggered the problem because the
> replica's localhost_access log shows this transition:
>
> 10.1.5.8 - - [16/Oct/2024:19:30:05 -0600] "POST /ca/admin/ca/getStatus
> HTTP/1.1" 200 119
> 10.1.5.8 - - [16/Oct/2024:20:24:10 -0600] "GET /ca/admin/ca/getStatus
> HTTP/1.1" 404 784
>
> the same day as the renewal (everything before was successful; everything
> after failed). Subsequently last night, the server restarted and pki-tomcatd
> would not restart. I don't think that the master has restarted since the
> renewal and honestly I'm afraid to try it...
>
> I started troubleshooting with
> https://floblanc.wordpress.com/2017/09/11/troubleshooting-freeipa-pki-tomcatd-fails-to-start/
> and the cert on both machines is identical and valid. Like others, this
> command fails on both master and replica:
>
> $ sudo certutil -K -d /etc/pki/pki-tomcat/alias -f /tmp/pwdfile.txt -n
> 'subsystemCert cert-pki-ca'
>
> However, this is successful on both:
>
> $ sudo certutil -K -d /etc/pki/pki-tomcat/alias -f /tmp/pwdfile.txt
>
> and I saw mention somewhere that if the latter is successful, then everything
> must be fine.
It doesn't mean everything is fine. This just lists the CA private keys.
You don't say what distribution or release you are running. I'd
recommend installing {free}ipa-healthcheck and seeing if that detects
any issues.
rob
> /var/log/pki/pki-tomcat/ca/debug log shows:
>
> 2024-10-18 12:30:38 [main] INFO: CMSEngine: initializing password store
> 2024-10-18 12:30:38 [main] INFO: CMSEngine: initializing password store for
> internaldb
> 2024-10-18 12:30:38 [main] INFO: CMSEngine: initializing password store for
> replicationdb
> 2024-10-18 12:30:38 [main] INFO: CMSEngine: Initializing subsystem listeners
> 2024-10-18 12:30:38 [main] INFO: CMSEngine: Java version: 17.0.5
> 2024-10-18 12:30:38 [main] INFO: CMSEngine: security providers:
> 2024-10-18 12:30:38 [main] INFO: PluginRegistry: Loading plugin registry from
> /var/lib/pki/pki-tomcat/conf/ca/registry.cfg
> 2024-10-18 12:30:38 [main] SEVERE: LdapBoundConnFactory: Unable to connect to
> LDAP server: Authentication failed
> netscape.ldap.LDAPException: Authentication failed (49)
> at netscape.ldap.LDAPSaslBind.checkForSASLBindCompletion(Unknown Source)
> at netscape.ldap.LDAPSaslBind.bind(Unknown Source)
> at netscape.ldap.LDAPSaslBind.bind(Unknown Source)
> at netscape.ldap.LDAPConnection.authenticate(Unknown Source)
> at netscape.ldap.LDAPConnection.authenticate(Unknown Source)
> at netscape.ldap.LDAPConnection.checkClientAuth(Unknown Source)
> at netscape.ldap.LDAPConnection.connect(Unknown Source)
> at netscape.ldap.LDAPConnection.connect(Unknown Source)
> at netscape.ldap.LDAPConnection.connect(Unknown Source)
> at
> com.netscape.cmscore.ldapconn.LdapBoundConnection.<init>(LdapBoundConnection.java:108)
> at
> com.netscape.cmscore.ldapconn.LdapBoundConnFactory.makeConnection(LdapBoundConnFactory.java:287)
> at
> com.netscape.cmscore.ldapconn.LdapBoundConnFactory.init(LdapBoundConnFactory.java:263)
> at
> com.netscape.cmscore.ldapconn.LdapBoundConnFactory.init(LdapBoundConnFactory.java:226)
> at
> com.netscape.cmscore.ldapconn.LdapBoundConnFactory.init(LdapBoundConnFactory.java:195)
> at org.dogtagpki.server.ca.CAEngine.initDatabase(CAEngine.java:199)
> at com.netscape.cmscore.apps.CMSEngine.start(CMSEngine.java:1105)
> at
> com.netscape.cmscore.apps.CMSEngine.contextInitialized(CMSEngine.java:1690)
> at
> org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4768)
> at
> org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5230)
> at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
> at
> org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:728)
> at
> org.apache.catalina.core.ContainerBase.access$000(ContainerBase.java:129)
> at
> org.apache.catalina.core.ContainerBase$PrivilegedAddChild.run(ContainerBase.java:150)
> at
> org.apache.catalina.core.ContainerBase$PrivilegedAddChild.run(ContainerBase.java:140)
> at
> java.base/java.security.AccessController.doPrivileged(AccessController.java:318)
> at
> org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:698)
> at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:696)
> at
> org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:690)
> at
> org.apache.catalina.startup.HostConfig$DeployDescriptor.run(HostConfig.java:1889)
> at
> java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
> at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
> at
> org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
> at
> java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:123)
> at
> org.apache.catalina.startup.HostConfig.deployDescriptors(HostConfig.java:583)
> at
> org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:473)
> at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1618)
> at
> org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:319)
> at
> org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:123)
> at
> org.apache.catalina.util.LifecycleBase.setStateInternal(LifecycleBase.java:423)
> at
> org.apache.catalina.util.LifecycleBase.setState(LifecycleBase.java:366)
> at
> org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:948)
> at
> org.apache.catalina.core.StandardHost.startInternal(StandardHost.java:835)
> at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
> at
> org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1398)
> at
> org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1388)
> at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
> at
> org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
> at
> java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:145)
> at
> org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:921)
> at
> org.apache.catalina.core.StandardEngine.startInternal(StandardEngine.java:263)
> at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
> at
> org.apache.catalina.core.StandardService.startInternal(StandardService.java:437)
> at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
> at
> org.apache.catalina.core.StandardServer.startInternal(StandardServer.java:934)
> at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
> at org.apache.catalina.startup.Catalina.start(Catalina.java:772)
> at
> java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
> at
> java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.base/java.lang.reflect.Method.invoke(Method.java:568)
> at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:345)
> at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:476)
>
> 2024-10-18 12:30:38 [main] SEVERE: Unable to start CA engine: Unable to
> connect to LDAP server: Authentication failed
> Unable to connect to LDAP server: Authentication failed
> at
> com.netscape.cmscore.ldapconn.LdapBoundConnFactory.makeConnection(LdapBoundConnFactory.java:305)
> at
> com.netscape.cmscore.ldapconn.LdapBoundConnFactory.init(LdapBoundConnFactory.java:263)
> at
> com.netscape.cmscore.ldapconn.LdapBoundConnFactory.init(LdapBoundConnFactory.java:226)
> at
> com.netscape.cmscore.ldapconn.LdapBoundConnFactory.init(LdapBoundConnFactory.java:195)
> at org.dogtagpki.server.ca.CAEngine.initDatabase(CAEngine.java:199)
> at com.netscape.cmscore.apps.CMSEngine.start(CMSEngine.java:1105)
> at
> com.netscape.cmscore.apps.CMSEngine.contextInitialized(CMSEngine.java:1690)
> at
> org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4768)
> at
> org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5230)
> at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
> at
> org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:728)
> at
> org.apache.catalina.core.ContainerBase.access$000(ContainerBase.java:129)
> at
> org.apache.catalina.core.ContainerBase$PrivilegedAddChild.run(ContainerBase.java:150)
> at
> org.apache.catalina.core.ContainerBase$PrivilegedAddChild.run(ContainerBase.java:140)
> at
> java.base/java.security.AccessController.doPrivileged(AccessController.java:318)
> at
> org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:698)
> at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:696)
> at
> org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:690)
> at
> org.apache.catalina.startup.HostConfig$DeployDescriptor.run(HostConfig.java:1889)
> at
> java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
> at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
> at
> org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
> at
> java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:123)
> at
> org.apache.catalina.startup.HostConfig.deployDescriptors(HostConfig.java:583)
> at
> org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:473)
> at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1618)
> at
> org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:319)
> at
> org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:123)
> at
> org.apache.catalina.util.LifecycleBase.setStateInternal(LifecycleBase.java:423)
> at
> org.apache.catalina.util.LifecycleBase.setState(LifecycleBase.java:366)
> at
> org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:948)
> at
> org.apache.catalina.core.StandardHost.startInternal(StandardHost.java:835)
> at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
> at
> org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1398)
> at
> org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1388)
> at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
> at
> org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
> at
> java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:145)
> at
> org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:921)
> at
> org.apache.catalina.core.StandardEngine.startInternal(StandardEngine.java:263)
> at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
> at
> org.apache.catalina.core.StandardService.startInternal(StandardService.java:437)
> at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
> at
> org.apache.catalina.core.StandardServer.startInternal(StandardServer.java:934)
> at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
> at org.apache.catalina.startup.Catalina.start(Catalina.java:772)
> at
> java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
> at
> java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.base/java.lang.reflect.Method.invoke(Method.java:568)
> at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:345)
> at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:476)
> Caused by: netscape.ldap.LDAPException: Authentication failed (49)
> at netscape.ldap.LDAPSaslBind.checkForSASLBindCompletion(Unknown Source)
> at netscape.ldap.LDAPSaslBind.bind(Unknown Source)
> at netscape.ldap.LDAPSaslBind.bind(Unknown Source)
> at netscape.ldap.LDAPConnection.authenticate(Unknown Source)
> at netscape.ldap.LDAPConnection.authenticate(Unknown Source)
> at netscape.ldap.LDAPConnection.checkClientAuth(Unknown Source)
> at netscape.ldap.LDAPConnection.connect(Unknown Source)
> at netscape.ldap.LDAPConnection.connect(Unknown Source)
> at netscape.ldap.LDAPConnection.connect(Unknown Source)
> at
> com.netscape.cmscore.ldapconn.LdapBoundConnection.<init>(LdapBoundConnection.java:108)
> at
> com.netscape.cmscore.ldapconn.LdapBoundConnFactory.makeConnection(LdapBoundConnFactory.java:287)
> ... 51 more
>
> 2024-10-18 12:30:38 [main] INFO: Shutting down CA subsystem
> 2024-10-18 12:30:38 [main] INFO: RequestSubsystem: Request subsystem stopped
> 2024-10-18 12:30:38 [main] SEVERE: Exception sending context initialized
> event to listener instance of class [org.dogtagpki.server.ca.CAEngine]
> java.lang.RuntimeException: Unable to start CA engine: Unable to connect to
> LDAP server: Authentication failed
> at
> com.netscape.cmscore.apps.CMSEngine.contextInitialized(CMSEngine.java:1695)
> at
> org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4768)
> at
> org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5230)
> at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
> at
> org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:728)
> at
> org.apache.catalina.core.ContainerBase.access$000(ContainerBase.java:129)
> at
> org.apache.catalina.core.ContainerBase$PrivilegedAddChild.run(ContainerBase.java:150)
> at
> org.apache.catalina.core.ContainerBase$PrivilegedAddChild.run(ContainerBase.java:140)
> at
> java.base/java.security.AccessController.doPrivileged(AccessController.java:318)
> at
> org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:698)
> at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:696)
> at
> org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:690)
> at
> org.apache.catalina.startup.HostConfig$DeployDescriptor.run(HostConfig.java:1889)
> at
> java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
> at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
> at
> org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
> at
> java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:123)
> at
> org.apache.catalina.startup.HostConfig.deployDescriptors(HostConfig.java:583)
> at
> org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:473)
> at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1618)
> at
> org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:319)
> at
> org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:123)
> at
> org.apache.catalina.util.LifecycleBase.setStateInternal(LifecycleBase.java:423)
> at
> org.apache.catalina.util.LifecycleBase.setState(LifecycleBase.java:366)
> at
> org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:948)
> at
> org.apache.catalina.core.StandardHost.startInternal(StandardHost.java:835)
> at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
> at
> org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1398)
> at
> org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1388)
> at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
> at
> org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
> at
> java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:145)
> at
> org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:921)
> at
> org.apache.catalina.core.StandardEngine.startInternal(StandardEngine.java:263)
> at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
> at
> org.apache.catalina.core.StandardService.startInternal(StandardService.java:437)
> at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
> at
> org.apache.catalina.core.StandardServer.startInternal(StandardServer.java:934)
> at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
> at org.apache.catalina.startup.Catalina.start(Catalina.java:772)
> at
> java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
> at
> java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.base/java.lang.reflect.Method.invoke(Method.java:568)
> at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:345)
> at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:476)
> Caused by: Unable to connect to LDAP server: Authentication failed
> at
> com.netscape.cmscore.ldapconn.LdapBoundConnFactory.makeConnection(LdapBoundConnFactory.java:305)
> at
> com.netscape.cmscore.ldapconn.LdapBoundConnFactory.init(LdapBoundConnFactory.java:263)
> at
> com.netscape.cmscore.ldapconn.LdapBoundConnFactory.init(LdapBoundConnFactory.java:226)
> at
> com.netscape.cmscore.ldapconn.LdapBoundConnFactory.init(LdapBoundConnFactory.java:195)
> at org.dogtagpki.server.ca.CAEngine.initDatabase(CAEngine.java:199)
> at com.netscape.cmscore.apps.CMSEngine.start(CMSEngine.java:1105)
> at
> com.netscape.cmscore.apps.CMSEngine.contextInitialized(CMSEngine.java:1690)
> ... 45 more
> Caused by: netscape.ldap.LDAPException: Authentication failed (49)
> at netscape.ldap.LDAPSaslBind.checkForSASLBindCompletion(Unknown Source)
> at netscape.ldap.LDAPSaslBind.bind(Unknown Source)
> at netscape.ldap.LDAPSaslBind.bind(Unknown Source)
> at netscape.ldap.LDAPConnection.authenticate(Unknown Source)
> at netscape.ldap.LDAPConnection.authenticate(Unknown Source)
> at netscape.ldap.LDAPConnection.checkClientAuth(Unknown Source)
> at netscape.ldap.LDAPConnection.connect(Unknown Source)
> at netscape.ldap.LDAPConnection.connect(Unknown Source)
> at netscape.ldap.LDAPConnection.connect(Unknown Source)
> at
> com.netscape.cmscore.ldapconn.LdapBoundConnection.<init>(LdapBoundConnection.java:108)
> at
> com.netscape.cmscore.ldapconn.LdapBoundConnFactory.makeConnection(LdapBoundConnFactory.java:287)
> ... 51 more
>
> 2024-10-18 12:30:38 [main] INFO: Shutting down CA subsystem
> 2024-10-18 12:30:38 [main] INFO: RequestSubsystem: Request subsystem stopped
>
> I'm not sure if this is the same issue as other threads have requested help
> with or not—most of them seem to fizzle out without reporting the resolution.
> Any suggestions?
>
--
_______________________________________________
FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org
To unsubscribe send an email to freeipa-users-le...@lists.fedorahosted.org
Fedora Code of Conduct:
https://docs.fedoraproject.org/en-US/project/code-of-conduct/
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives:
https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedorahosted.org
Do not reply to spam, report it:
https://pagure.io/fedora-infrastructure/new_issue
