[Freeipa-users] Re: Error upgrading to version 4.11.0

[Duarte Petiz]

Steps to reproduce:

1- Execute a docker-compose of freeipa with a clean volume (fresh install).
2- Wait until it boots (after 2/3 minutes) everything is ok
> [root@prod-us-freeipa /]# curl
> http://prod-us-freeipa.example.com:8080/ca/admin/ca/getStatus
> {
>   "Response" : {
>     "State" : "1",
>     "Type" : "CA",
>     "Status" : "running",
>     "Version" : "11.3.0-1"
>   }

3- Restore data (backup data only and full tested)
> ipa-restore /var/lib/ipa/backup/ipa-data-2024-08-30-10-28-58/
> Directory Manager (existing master) password:

Preparing restore from /var/lib/ipa/backup/ipa-data-2024-08-30-10-28-58/ on
> prod-us-freeipa.example.com
> Performing DATA restore from DATA backup
> Temporary setting umask to 022
> Restoring data will overwrite existing live data. Continue to restore?
> [no]: yes
> Each master will individually need to be re-initialized or
> re-created from this one. The replication agreements on
> masters running IPA 3.1 or earlier will need to be manually
> re-enabled. See the man page for details.
> Disabling all replication.
> Stopping Directory Server
> Restoring from userRoot in EXAMPLE-COM
> Restoring from ipaca in EXAMPLE-COM
> Starting Directory Server
> Restoring umask to 18

*The ipa-restore command was successful *

4- Freeipa restart
5- pki no more boots
> [root@prod-us-freeipa pki]# curl
> http://prod-us-freeipa.example.com:8080/ca/admin/ca/getStatus
> curl: (7) Failed to connect to prod-us-freeipa.example.com port 8080:
> Connection refused

I'm getting really frustrated with this error...
I don't have replicas so I really need to have this fixed.
Does anyone have any ideas?

cat /var/log/pki/pki-tomcat/ca/debug.2024-08-30.log
2024-08-30 09:48:12 [main] INFO: Shutting down CA subsystem
2024-08-30 09:48:12 [main] INFO: RequestSubsystem: Request subsystem stopped
2024-08-30 09:48:12 [main] INFO: Destroying
LogFile(/var/lib/pki/pki-tomcat/logs/ca/signedAudit/ca_audit)
2024-08-30 09:48:12 [main] SEVERE: Exception sending context initialized
event to listener instance of class [org.dogtagpki.server.ca.CAWebListener]
com.netscape.certsrv.base.PKIException: Unable to start CA engine: Unable
to connect to LDAP server: Authentication failed
at
com.netscape.cmscore.apps.PKIWebListener.contextInitialized(PKIWebListener.java:44)
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.makeNewConnection(LdapBoundConnFactory.java:321)
at
com.netscape.cmscore.ldapconn.LdapBoundConnFactory.makeConnection(LdapBoundConnFactory.java:278)
at
com.netscape.cmscore.ldapconn.LdapBoundConnFactory.init(LdapBoundConnFactory.java:262)
at
com.netscape.cmscore.ldapconn.LdapBoundConnFactory.init(LdapBoundConnFactory.java:224)
at
com.netscape.cmscore.ldapconn.LdapBoundConnFactory.init(LdapBoundConnFactory.java:193)
at org.dogtagpki.server.ca.CAEngine.initDatabase(CAEngine.java:192)
at com.netscape.cmscore.apps.CMSEngine.start(CMSEngine.java:1160)
at
com.netscape.cmscore.apps.PKIWebListener.contextInitialized(PKIWebListener.java:39)
... 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.makeNewConnection(LdapBoundConnFactory.java:303)
... 52 more

2024-08-30 09:48:12 [main] INFO: Shutting down CA subsystem
2024-08-30 09:48:12 [main] INFO: RequestSubsystem: Request subsystem stopped
2024-08-30 09:48:12 [main] INFO: Destroying
LogFile(/var/lib/pki/pki-tomcat/logs/ca/signedAudit/ca_audit)

On Wed, Aug 28, 2024 at 6:51 PM Rob Crittenden via FreeIPA-users <
[e-mail]> wrote:
> Luis Correia via FreeIPA-users wrote:
> > I looked at those logs, and saw that we're getting a lot of these:
> > 2024-08-28 09:05:10 [main] INFO: PKISocketFactory: Creating SSL socket
>
> for <my-freeipa-hostname>:636
> > 2024-08-28 09:05:10 [main] SEVERE: Add listener!!!
>
> org.dogtagpki.server.PKIClientSocketListener@79ac50fe
> > 2024-08-28 09:05:10 [main] INFO: PKISocketFactory: Creating SSL socket
>
> for <my-freeipa-hostname>:636
> > 2024-08-28 09:05:10 [main] SEVERE: Add listener!!!
>
> org.dogtagpki.server.PKIClientSocketListener@79ac50fe
> > 2024-08-28 09:05:10 [main] INFO: PKISocketFactory: Creating SSL socket
>
> for <my-freeipa-hostname>:636
> > 2024-08-28 09:05:10 [main] SEVERE: Add listener!!!
>
> org.dogtagpki.server.PKIClientSocketListener@79ac50fe
> > 2024-08-28 09:05:10 [main] INFO: PKISocketFactory: Creating SSL socket
>
> for <my-freeipa-hostname>:636
> > 2024-08-28 09:05:10 [main] SEVERE: Add listener!!!
>
> org.dogtagpki.server.PKIClientSocketListener@79ac50fe
> > 2024-08-28 09:05:10 [main] INFO: PKISocketFactory: Creating SSL socket
>
> for <my-freeipa-hostname>:636
> > 2024-08-28 09:05:10 [main] SEVERE: Add listener!!!
>
> org.dogtagpki.server.PKIClientSocketListener@79ac50fe
> > 2024-08-28 09:05:10 [main] SEVERE: Exception sending context initialized
>
> event to listener instance of class [org.dogtagpki.server.ca
> .CAWebListener]
> > java.lang.StackOverflowError: java.lang.StackOverflowError
> >         at
>
> java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native
> Method)
> >     at
>
> java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:77)
> >     at
>
> java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
> >     at
>
> java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:500)
> >     at
>
> java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:481)
> >     at
>
> org.mozilla.jss.ssl.SocketBase.processExceptions(SocketBase.java:448)
> >     at org.mozilla.jss.ssl.SSLSocket.forceHandshake(Native Method)
> >     at
>
> com.netscape.cmscore.ldapconn.PKISocketFactory.makeSSLSocket(PKISocketFactory.java:240)
> >     at
>
> com.netscape.cmscore.ldapconn.PKISocketFactory.makeSocket(PKISocketFactory.java:256)
> >     at
>
> netscape.ldap.LDAPConnSetupMgr.connectServer(LDAPConnSetupMgr.java:525)
> >     at
>
> netscape.ldap.LDAPConnSetupMgr.openSerial(LDAPConnSetupMgr.java:451)
> >     at
>
> netscape.ldap.LDAPConnSetupMgr.connect(LDAPConnSetupMgr.java:290)
> >     at
>
> netscape.ldap.LDAPConnSetupMgr.openConnection(LDAPConnSetupMgr.java:215)
> >     at netscape.ldap.LDAPConnThread.connect(LDAPConnThread.java:136)
> >     at netscape.ldap.LDAPConnection.connect(LDAPConnection.java:1126)
> >     at
>
> netscape.ldap.LDAPConnection.restoreConnection(LDAPConnection.java:1905)
> >     at
>
> netscape.ldap.LDAPConnection.sendRequest(LDAPConnection.java:1870)
> >     at netscape.ldap.LDAPSaslBind.saslBind(LDAPSaslBind.java:276)
> >     at netscape.ldap.LDAPSaslBind.bind(LDAPSaslBind.java:194)
> >     at netscape.ldap.LDAPSaslBind.bind(LDAPSaslBind.java:115)
> >     at
>
> netscape.ldap.LDAPConnection.authenticate(LDAPConnection.java:1446)
> >     at
>
> netscape.ldap.LDAPConnection.authenticate(LDAPConnection.java:1406)
> >     at
>
> netscape.ldap.LDAPConnection.checkClientAuth(LDAPConnection.java:1170)
> >     at netscape.ldap.LDAPConnection.connect(LDAPConnection.java:1128)
> >
> > I'm not sure what it could mean though. Do you have any idea?
>
> There isn't really enough information. Probably need more context above
> this. PKI tends to continue past failures so bottom-up debugging isn't
> always fruitful. It also has some red herring warnings so it can be
> difficult, even for experienced admins, to tell what is going on.
>
> It looks like it is having troubles reaching LDAP though. I guess what
> I'd suggest is:
>
> ipactl start --skip-version-check --ignore-service-failures
>
> That should bring the services up without trying the upgrade and without
> failing if PKI fails to start.
>
> Then you can try starting PKI alone to see if that makes a difference.
>
> And/or check on your certificates: getcert list
>
> And see if any are expired or expiring.
>
> rob
>
> --
> _______________________________________________
> FreeIPA-users mailing list -- [e-mail]
> To unsubscribe send an email to [e-mail]
> 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/[e-mail]...
> Do not reply to spam, report it:
> https://pagure.io/fedora-infrastructure/new_issue