Error upgrading to version 4.11.0

[Luis Correia]

Hello all.
I'm currently running a FreeIPA server on Docker using the rocky-9-4.10.2 and trying to upgrade my installation to version rocky-9-4.11.0, but currently getting this error:

2024-08-28T09:21:52Z DEBUG Failed to check CA status: cannot connect to 'http://<my-freeipa-hostname>:8080/ca/admin/ca/getStatus': [Errno 111] Connection refused

2024-08-28T09:22:38Z ERROR IPA server upgrade failed: Inspect /var/log/ipaupgrade.log and run command ipa-server-upgrade manually.
2024-08-28T09:22:38Z DEBUG   File "/usr/lib/python3.9/site-packages/ipapython/admintool.py", line 180, in execute
    return_value = self.run()
  File "/usr/lib/python3.9/site-packages/ipaserver/install/ipa_server_upgrade.py", line 54, in run
    server.upgrade()
  File "/usr/lib/python3.9/site-packages/ipaserver/install/server/upgrade.py", line 2081, in upgrade
    upgrade_configuration()
  File "/usr/lib/python3.9/site-packages/ipaserver/install/server/upgrade.py", line 1803, in upgrade_configuration
    ca.start('pki-tomcat')
  File "/usr/lib/python3.9/site-packages/ipaserver/install/service.py", line 575, in start
    self.service.start(instance_name, capture_output=capture_output, wait=wait)
  File "/usr/lib/python3.9/site-packages/ipaplatform/base/services.py", line 304, in start
    ipautil.run([paths.SYSTEMCTL, "start",
  File "/usr/lib/python3.9/site-packages/ipapython/ipautil.py", line 599, in run
    raise CalledProcessError(

2024-08-28T09:22:38Z DEBUG The ipa-server-upgrade command failed, exception: CalledProcessError: CalledProcessError(Command ['/bin/systemctl', 'start', '[e-mail]'] returned non-zero exit status 1: 'Job for [e-mail] canceled.\n')
2024-08-28T09:22:38Z ERROR Unexpected error - see /var/log/ipaupgrade.log for details:
CalledProcessError: CalledProcessError(Command ['/bin/systemctl', 'start', '[e-mail]'] returned non-zero exit status 1: 'Job for [e-mail] canceled.\n')
2024-08-28T09:22:38Z ERROR The ipa-server-upgrade command failed. See /var/log/ipaupgrade.log for more information

The endpoint that FreeIPA tries to connect to eventually generates a 404 error (logs from var/log/pki/pki-tomcat/localhost_access_log.2024-08-28.txt):
172.18.0.2 - - [28/Aug/2024:09:22:33 +0000] "GET /ca/admin/ca/getStatus HTTP/1.1" 404 784
172.18.0.2 - - [28/Aug/2024:09:22:34 +0000] "GET /ca/admin/ca/getStatus HTTP/1.1" 404 784
172.18.0.2 - - [28/Aug/2024:09:22:35 +0000] "GET /ca/admin/ca/getStatus HTTP/1.1" 404 784
172.18.0.2 - - [28/Aug/2024:09:22:36 +0000] "GET /ca/admin/ca/getStatus HTTP/1.1" 404 784
172.18.0.2 - - [28/Aug/2024:09:22:37 +0000] "GET /ca/admin/ca/getStatus HTTP/1.1" 404 784
172.18.0.2 - - [28/Aug/2024:09:22:38 +0000] "GET /ca/admin/ca/getStatus HTTP/1.1" 404 784

Can anyone help? This makes it so that I'm completely unable to update FreeIPA to the latest version, which I currently need to do.
Thanks!

[Duarte Petiz]

I'm facing the same problem

On Wed, Aug 28, 2024 at 12:01 PM Luis Correia via FreeIPA-users <
[e-mail]> wrote:
> Hello all.
> I'm currently running a FreeIPA server on Docker using the rocky-9-4.10.2
> and trying to upgrade my installation to version rocky-9-4.11.0, but
> currently getting this error:
>
> 2024-08-28T09:21:52Z DEBUG Failed to check CA status: cannot connect to
> 'http://<my-freeipa-hostname>:8080/ca/admin/ca/getStatus': [Errno 111]
> Connection refused
>
> 2024-08-28T09:22:38Z ERROR IPA server upgrade failed: Inspect
> /var/log/ipaupgrade.log and run command ipa-server-upgrade manually.
> 2024-08-28T09:22:38Z DEBUG   File
> "/usr/lib/python3.9/site-packages/ipapython/admintool.py", line 180, in
> execute
>     return_value = self.run()
>   File
> "/usr/lib/python3.9/site-packages/ipaserver/install/ipa_server_upgrade.py",
> line 54, in run
>     server.upgrade()
>   File
> "/usr/lib/python3.9/site-packages/ipaserver/install/server/upgrade.py",
> line 2081, in upgrade
>     upgrade_configuration()
>   File
> "/usr/lib/python3.9/site-packages/ipaserver/install/server/upgrade.py",
> line 1803, in upgrade_configuration
>     ca.start('pki-tomcat')
>   File "/usr/lib/python3.9/site-packages/ipaserver/install/service.py",
> line 575, in start
>     self.service.start(instance_name, capture_output=capture_output,
> wait=wait)
>   File "/usr/lib/python3.9/site-packages/ipaplatform/base/services.py",
> line 304, in start
>     ipautil.run([paths.SYSTEMCTL, "start",
>   File "/usr/lib/python3.9/site-packages/ipapython/ipautil.py", line 599,
> in run
>     raise CalledProcessError(
>
> 2024-08-28T09:22:38Z DEBUG The ipa-server-upgrade command failed,
> exception: CalledProcessError: CalledProcessError(Command
> ['/bin/systemctl', 'start', '[e-mail]'] returned
> non-zero exit status 1: 'Job for [e-mail]
> canceled.\n')
> 2024-08-28T09:22:38Z ERROR Unexpected error - see /var/log/ipaupgrade.log
> for details:
> CalledProcessError: CalledProcessError(Command ['/bin/systemctl', 'start',
> '[e-mail]'] returned non-zero exit status 1: 'Job
> for [e-mail] canceled.\n')
> 2024-08-28T09:22:38Z ERROR The ipa-server-upgrade command failed. See
> /var/log/ipaupgrade.log for more information
>
> The endpoint that FreeIPA tries to connect to eventually generates a 404
> error (logs from
> var/log/pki/pki-tomcat/localhost_access_log.2024-08-28.txt):
> 172.18.0.2 - - [28/Aug/2024:09:22:33 +0000] "GET /ca/admin/ca/getStatus
> HTTP/1.1" 404 784
> 172.18.0.2 - - [28/Aug/2024:09:22:34 +0000] "GET /ca/admin/ca/getStatus
> HTTP/1.1" 404 784
> 172.18.0.2 - - [28/Aug/2024:09:22:35 +0000] "GET /ca/admin/ca/getStatus
> HTTP/1.1" 404 784
> 172.18.0.2 - - [28/Aug/2024:09:22:36 +0000] "GET /ca/admin/ca/getStatus
> HTTP/1.1" 404 784
> 172.18.0.2 - - [28/Aug/2024:09:22:37 +0000] "GET /ca/admin/ca/getStatus
> HTTP/1.1" 404 784
> 172.18.0.2 - - [28/Aug/2024:09:22:38 +0000] "GET /ca/admin/ca/getStatus
> HTTP/1.1" 404 784
>
> Can anyone help? This makes it so that I'm completely unable to update
> FreeIPA to the latest version, which I currently need to do.
> Thanks!
> --
> _______________________________________________
> 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

[Rob Crittenden]

Luis Correia via FreeIPA-users wrote:
> Hello all.
> I'm currently running a FreeIPA server on Docker using the rocky-9-4.10.2 and trying to upgrade my installation to version rocky-9-4.11.0, but currently getting this error:
>
> 2024-08-28T09:21:52Z DEBUG Failed to check CA status: cannot connect to 'http://<my-freeipa-hostname>:8080/ca/admin/ca/getStatus': [Errno 111] Connection refused
>
> 2024-08-28T09:22:38Z ERROR IPA server upgrade failed: Inspect /var/log/ipaupgrade.log and run command ipa-server-upgrade manually.
> 2024-08-28T09:22:38Z DEBUG   File "/usr/lib/python3.9/site-packages/ipapython/admintool.py", line 180, in execute
>     return_value = self.run()
>   File "/usr/lib/python3.9/site-packages/ipaserver/install/ipa_server_upgrade.py", line 54, in run
>     server.upgrade()
>   File "/usr/lib/python3.9/site-packages/ipaserver/install/server/upgrade.py", line 2081, in upgrade
>     upgrade_configuration()
>   File "/usr/lib/python3.9/site-packages/ipaserver/install/server/upgrade.py", line 1803, in upgrade_configuration
>     ca.start('pki-tomcat')
>   File "/usr/lib/python3.9/site-packages/ipaserver/install/service.py", line 575, in start
>     self.service.start(instance_name, capture_output=capture_output, wait=wait)
>   File "/usr/lib/python3.9/site-packages/ipaplatform/base/services.py", line 304, in start
>     ipautil.run([paths.SYSTEMCTL, "start",
>   File "/usr/lib/python3.9/site-packages/ipapython/ipautil.py", line 599, in run
>     raise CalledProcessError(
>
> 2024-08-28T09:22:38Z DEBUG The ipa-server-upgrade command failed, exception: CalledProcessError: CalledProcessError(Command ['/bin/systemctl', 'start', '[e-mail]'] returned non-zero exit status 1: 'Job for [e-mail] canceled.\n')
> 2024-08-28T09:22:38Z ERROR Unexpected error - see /var/log/ipaupgrade.log for details:
> CalledProcessError: CalledProcessError(Command ['/bin/systemctl', 'start', '[e-mail]'] returned non-zero exit status 1: 'Job for [e-mail] canceled.\n')
> 2024-08-28T09:22:38Z ERROR The ipa-server-upgrade command failed. See /var/log/ipaupgrade.log for more information
>
> The endpoint that FreeIPA tries to connect to eventually generates a 404 error (logs from var/log/pki/pki-tomcat/localhost_access_log.2024-08-28.txt):
> 172.18.0.2 - - [28/Aug/2024:09:22:33 +0000] "GET /ca/admin/ca/getStatus HTTP/1.1" 404 784
> 172.18.0.2 - - [28/Aug/2024:09:22:34 +0000] "GET /ca/admin/ca/getStatus HTTP/1.1" 404 784
> 172.18.0.2 - - [28/Aug/2024:09:22:35 +0000] "GET /ca/admin/ca/getStatus HTTP/1.1" 404 784
> 172.18.0.2 - - [28/Aug/2024:09:22:36 +0000] "GET /ca/admin/ca/getStatus HTTP/1.1" 404 784
> 172.18.0.2 - - [28/Aug/2024:09:22:37 +0000] "GET /ca/admin/ca/getStatus HTTP/1.1" 404 784
> 172.18.0.2 - - [28/Aug/2024:09:22:38 +0000] "GET /ca/admin/ca/getStatus HTTP/1.1" 404 784
>
> Can anyone help? This makes it so that I'm completely unable to update FreeIPA to the latest version, which I currently need to do.
> Thanks!

Your CA likely did not start. You'll need to look at the CA logs to try
to determine why. /var/log/pki/pki-tomcat/ca/debug-<date>.log

rob

[Luis Correia]

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?

[Rob Crittenden]

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

[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

[Florence Blanc-Renaud]

Hi,

On Fri, Aug 30, 2024 at 11:59 AM Duarte Petiz via FreeIPA-users <
[e-mail]> wrote:
> 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)

When the PKI server starts, it tries to establish a connection to the LDAP
server and authenticates with a certificate.
The error 49 means invalid credentials.
You can find troubleshooting tips in
https://floblanc.wordpress.com/2017/09/11/troubleshooting-freeipa-pki-tomcat...

flo

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
>
> --
> *Kind Regards*
>
> *Duarte Petiz*
> *DevOps Team Lead *| jscrambler.com
>
> --
> _______________________________________________
> 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

[Duarte Petiz]

Thank you for your help!
I'm following your guide, and in fact the certificate is different.
So i'm updated the certificate to use the same as the server

Steps:
1- install fresh server
2- restore data
> [root@prod-us-freeipa backup]# ipa-restore --data
> ipa-full-2024-09-02-04-02-13/
> Directory Manager (existing master) password:
>
> Preparing restore from /var/lib/ipa/backup/ipa-full-2024-09-02-04-02-13/
> on prod-us-freeipa.example.com
> Performing DATA restore from FULL 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 JSCRAMBLER-COM
> Restoring from ipaca in JSCRAMBLER-COM
> Starting Directory Server
> Restoring umask to 18
> The ipa-restore command was successful

3- fix the certificate
> [root@prod-us-freeipa backup]# ldapmodify -D "cn=directory manager" -W -f
> updatecert.ldif
> Enter LDAP Password:
> modifying entry "uid=pkidbuser,ou=people,o=ipaca"

4- restart freeipa
> [root@prod-us-freeipa backup]# ipactl restart
> Restarting Directory Service
> Restarting krb5kdc Service
> Restarting kadmin Service
> Restarting httpd Service
> Restarting ipa-custodia Service
> Restarting pki-tomcatd Service
> Restarting ipa-otpd Service
> ipa: INFO: The ipactl command was successful

Expected result:
- Freeipa running with all services UP (check, PKI is back online)
> [root@prod-us-freeipa /]# ipactl status
> Directory Service: RUNNING
> krb5kdc Service: RUNNING
> kadmin Service: RUNNING
> httpd Service: RUNNING
> ipa-custodia Service: RUNNING
> pki-tomcatd Service: RUNNING
> ipa-otpd Service: RUNNING
> ipa: INFO: The ipactl command was successful

Problem logging in the dashboard
[image: image.png]

[root@prod-us-freeipa /]# tail -f /var/log/httpd/error_log

[Mon Sep 02 10:33:37.100922 2024] [auth_gssapi:error] [pid 661:tid 665]
> [client 192.168.32.2:58200] GSS ERROR gss_acquire_cred[_from]() failed to
> get server creds: [No credentials were supplied, or the credentials were
> unavailable or inaccessible ( SPNEGO cannot find mechanisms to negotiate)]

[Mon Sep 02 10:33:37.102384 2024] [wsgi:error] [pid 254:tid 429] [remote
> 37.27.47.71:50740] ipa: INFO: 401 Unauthorized: No session cookie found

Any idea?

On Fri, Aug 30, 2024 at 2:10 PM Florence Blanc-Renaud 
wrote:
> Hi,
>
> On Fri, Aug 30, 2024 at 11:59 AM Duarte Petiz via FreeIPA-users <
> [e-mail]> wrote:
> > 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)
>
> When the PKI server starts, it tries to establish a connection to the LDAP
> server and authenticates with a certificate.
> The error 49 means invalid credentials.
> You can find troubleshooting tips in
> https://floblanc.wordpress.com/2017/09/11/troubleshooting-freeipa-pki-tomcat...
>
> flo
>
> 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
> >
> > --
> > *Kind Regards*
> >
> > *Duarte Petiz*
> > *DevOps Team Lead *| jscrambler.com
> >
> > --
> > _______________________________________________
> > 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

[Duarte Petiz]

Thank you for your help!
I'm following your guide, and in fact the certificate is different.
So i'm updated the certificate to use the same as the server

Steps:
1- install fresh server
2- restore data
> [root@prod-us-freeipa backup]# ipa-restore --data
> ipa-full-2024-09-02-04-02-13/
> Directory Manager (existing master) password:
>
> Preparing restore from /var/lib/ipa/backup/ipa-full-2024-09-02-04-02-13/
> on prod-us-freeipa.example.com
> Performing DATA restore from FULL 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

3- fix the certificate
> [root@prod-us-freeipa backup]# ldapmodify -D "cn=directory manager" -W -f
> updatecert.ldif
> Enter LDAP Password:
> modifying entry "uid=pkidbuser,ou=people,o=ipaca"

4- restart freeipa
> [root@prod-us-freeipa backup]# ipactl restart
> Restarting Directory Service
> Restarting krb5kdc Service
> Restarting kadmin Service
> Restarting httpd Service
> Restarting ipa-custodia Service
> Restarting pki-tomcatd Service
> Restarting ipa-otpd Service
> ipa: INFO: The ipactl command was successful

Expected result:
- Freeipa running with all services UP (check, PKI is back online)
> [root@prod-us-freeipa /]# ipactl status
> Directory Service: RUNNING
> krb5kdc Service: RUNNING
> kadmin Service: RUNNING
> httpd Service: RUNNING
> ipa-custodia Service: RUNNING
> pki-tomcatd Service: RUNNING
> ipa-otpd Service: RUNNING
> ipa: INFO: The ipactl command was successful

Problem logging in the dashboard
"Login failed due to an unknown reason"

[root@prod-us-freeipa /]# tail -f /var/log/httpd/error_log

[Mon Sep 02 10:33:37.100922 2024] [auth_gssapi:error] [pid 661:tid 665]
> [client 192.168.32.2:58200] GSS ERROR gss_acquire_cred[_from]() failed to
> get server creds: [No credentials were supplied, or the credentials were
> unavailable or inaccessible ( SPNEGO cannot find mechanisms to negotiate)]

[Mon Sep 02 10:33:37.102384 2024] [wsgi:error] [pid 254:tid 429] [remote
> 37.27.47.71:50740] ipa: INFO: 401 Unauthorized: No session cookie found

to try to Fixit i've done: ipa-getkeytab -D "cn=directory manager" -w
Password -s prod-us-freeipa.example.com -p 'HTTP/prod-us-freeipa.example.com'
-r -k /var/lib/ipa/gssproxy/http.keytab

Now Try to login into dashboard:
Error message "Your session has expired. Please log in again."

On the logs
> [root@prod-us-freeipa /]# tail -f /var/log/httpd/error_log

[Mon Sep 02 11:01:18.503915 2024] [wsgi:error] [pid 270:tid 450] [remote
> 37.27.47.71:50893] ipa: INFO: 401 Unauthorized: Insufficient access:
>  Invalid credentials
> [Mon Sep 02 11:01:18.682533 2024] [:warn] [pid 274:tid 321] [client
> 37.27.47.71:50893] failed to set perms (3140) on file
> (/run/ipa/ccaches/[e-mail]-nHgKeH)!, referer:
> https://prod-us-freeipa.jscrambler.com/ipa/ui/
> [Mon Sep 02 11:01:18.905861 2024] [wsgi:error] [pid 271:tid 456] [remote
> 37.27.47.71:50893] ipa: INFO: 401 Unauthorized: Insufficient access:
>  Invalid credentials

On Mon, Sep 2, 2024 at 11:34 AM Duarte Petiz 
wrote:
> Thank you for your help!
> I'm following your guide, and in fact the certificate is different.
> So i'm updated the certificate to use the same as the server
>
> Steps:
> 1- install fresh server
> 2- restore data
> > [root@prod-us-freeipa backup]# ipa-restore --data
> > ipa-full-2024-09-02-04-02-13/
> > Directory Manager (existing master) password:
> >
> > Preparing restore from /var/lib/ipa/backup/ipa-full-2024-09-02-04-02-13/
> > on prod-us-freeipa.example.com
> > Performing DATA restore from FULL 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 JSCRAMBLER-COM
> > Restoring from ipaca in JSCRAMBLER-COM
> > Starting Directory Server
> > Restoring umask to 18
> > The ipa-restore command was successful
>
> 3- fix the certificate
> > [root@prod-us-freeipa backup]# ldapmodify -D "cn=directory manager" -W
> > -f updatecert.ldif
> > Enter LDAP Password:
> > modifying entry "uid=pkidbuser,ou=people,o=ipaca"
>
> 4- restart freeipa
> > [root@prod-us-freeipa backup]# ipactl restart
> > Restarting Directory Service
> > Restarting krb5kdc Service
> > Restarting kadmin Service
> > Restarting httpd Service
> > Restarting ipa-custodia Service
> > Restarting pki-tomcatd Service
> > Restarting ipa-otpd Service
> > ipa: INFO: The ipactl command was successful
>
> Expected result:
> Freeipa running with all services UP (check, PKI is back online)
> > [root@prod-us-freeipa /]# ipactl status
> > Directory Service: RUNNING
> > krb5kdc Service: RUNNING
> > kadmin Service: RUNNING
> > httpd Service: RUNNING
> > ipa-custodia Service: RUNNING
> > pki-tomcatd Service: RUNNING
> > ipa-otpd Service: RUNNING
> > ipa: INFO: The ipactl command was successful
>
> Problem logging in the dashboard
> [image: image.png]
>
> [root@prod-us-freeipa /]# tail -f /var/log/httpd/error_log
>
> [Mon Sep 02 10:33:37.100922 2024] [auth_gssapi:error] [pid 661:tid 665]
> > [client 192.168.32.2:58200] GSS ERROR gss_acquire_cred[_from]() failed
> > to get server creds: [No credentials were supplied, or the credentials were
> > unavailable or inaccessible ( SPNEGO cannot find mechanisms to negotiate)]
>
> [Mon Sep 02 10:33:37.102384 2024] [wsgi:error] [pid 254:tid 429] [remote
> > 37.27.47.71:50740] ipa: INFO: 401 Unauthorized: No session cookie found
>
> Any idea?
>
> On Fri, Aug 30, 2024 at 2:10 PM Florence Blanc-Renaud 
> wrote:
> > Hi,
> >
> > On Fri, Aug 30, 2024 at 11:59 AM Duarte Petiz via FreeIPA-users <
> > [e-mail]> wrote:
> > > 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)
> >
> > When the PKI server starts, it tries to establish a connection to the
> > LDAP server and authenticates with a certificate.
> > The error 49 means invalid credentials.
> > You can find troubleshooting tips in
> > https://floblanc.wordpress.com/2017/09/11/troubleshooting-freeipa-pki-tomcat...
> >
> > flo
> >
> > 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
> > >
> > > --
> > > *Kind Regards*
> > >
> > > *Duarte Petiz*
> > > *DevOps Team Lead *| jscrambler.com
> > >
> > > --
> > > _______________________________________________
> > > 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
>
> --
> *Kind Regards*
>
> *Duarte Petiz*
> *DevOps Team Lead *| jscrambler.com

[John Michelle]

Hello
i face the same error
have you reslov this error .? if yes , can you please tell me how ?
thanks