New subject: FreeIPA having problem after upgrading from Fedora 30 to 31

Tuesday, 29 October 2019

Hello,

I got problem upgrading from FC30 to FC31.
Before upgrade the FreeIPA in FC30 is running fine.

After OS upgrade, IPA cannot start and checked that it stuck at the CA part.
I run ipa-server-upgrade manually but there is problem.

2019-10-29T21:03:58Z DEBUG request GET
https://home.local.nonet:8443/ca/rest/account/login
2019-10-29T21:03:58Z DEBUG request body ''
2019-10-29T21:03:58Z DEBUG response status 500
2019-10-29T21:03:58Z DEBUG response headers Content-Type:
text/html;charset=utf-8
Content-Language: en
Content-Length: 2481
Date: Tue, 29 Oct 2019 21:03:58 GMT
Connection: close

2019-10-29T21:03:58Z DEBUG response body (decoded): b'<!doctype html><html
lang="en"><head><title>HTTP Status 500 \xe2\x80\x93 Internal
Server
Error</title><style type="text/css">h1
{font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:22px;}
h2
{font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:16px;}
h3
{font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:14px;}
body
{font-family:Tahoma,Arial,sans-serif;color:black;background-color:white;} b
{font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;}
p
{font-family:Tahoma,Arial,sans-serif;background:white;color:black;font-size:12px;}
a {color:black;} a.name {color:black;} .line
{height:1px;background-color:#525D76;border:none;}</style></head><body><h1>HTTP
Status 500 \xe2\x80\x93 Internal Server Error</h1><hr class="line"
/><p><b>Type</b> Exception
Report</p><p><b>Message</b> Subsystem
unavailable</p><p><b>Description</b> The server encountered an
unexpected
condition that prevented it from fulfilling the
request.</p><p><b>Exception</b></p><pre>javax.ws.rs.ServiceUnavailableException:
Subsystem
unavailable\n\tcom.netscape.cms.tomcat.ProxyRealm.findSecurityConstraints(ProxyRealm.java:150)\n\torg.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:515)\n\tcom.netscape.cms.tomcat.ExternalAuthenticationValve.invoke(ExternalAuthenticationValve.java:82)\n\torg.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)\n\torg.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:678)\n\torg.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)\n\torg.apache.coyote.http11.Http11Processor.service(Http11Processor.java:408)\n\torg.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)\n\torg.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:860)\n\torg.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1589)\n\torg.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)\n\tjava.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)\n\tjava.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)\n\torg.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)\n\tjava.lang.Thread.run(Thread.java:748)\n</pre><p><b>Note</b>
The full stack trace of the root cause is available in the server
logs.</p><hr class="line" /><h3>Apache
Tomcat/9.0.26</h3></body></html>'
2019-10-29T21:03:58Z ERROR IPA server upgrade failed: Inspect
/var/log/ipaupgrade.log and run command ipa-server-upgrade manually.
2019-10-29T21:03:58Z DEBUG   File
"/usr/lib/python3.7/site-packages/ipapython/admintool.py", line 179, in
execute
    return_value = self.run()
  File
"/usr/lib/python3.7/site-packages/ipaserver/install/ipa_server_upgrade.py",
line 54, in run
    server.upgrade()
  File
"/usr/lib/python3.7/site-packages/ipaserver/install/server/upgrade.py",
line 2223, in upgrade
    upgrade_configuration()
  File
"/usr/lib/python3.7/site-packages/ipaserver/install/server/upgrade.py",
line 2093, in upgrade_configuration
    ca_enable_ldap_profile_subsystem(ca)
  File
"/usr/lib/python3.7/site-packages/ipaserver/install/server/upgrade.py",
line 414, in ca_enable_ldap_profile_subsystem
    cainstance.migrate_profiles_to_ldap()
  File "/usr/lib/python3.7/site-packages/ipaserver/install/cainstance.py",
line 1937, in migrate_profiles_to_ldap
    _create_dogtag_profile(profile_id, profile_data, overwrite=False)
  File "/usr/lib/python3.7/site-packages/ipaserver/install/cainstance.py",
line 1943, in _create_dogtag_profile
    with api.Backend.ra_certprofile as profile_api:
  File "/usr/lib/python3.7/site-packages/ipaserver/plugins/dogtag.py", line
1315, in __enter__
    raise errors.RemoteRetrieveError(reason=_('Failed to authenticate to CA
REST API'))

2019-10-29T21:03:58Z DEBUG The ipa-server-upgrade command failed,
exception: RemoteRetrieveError: Failed to authenticate to CA REST API
2019-10-29T21:03:58Z ERROR Unexpected error - see /var/log/ipaupgrade.log
for details:
RemoteRetrieveError: Failed to authenticate to CA REST API
2019-10-29T21:03:58Z ERROR The ipa-server-upgrade command failed. See
/var/log/ipaupgrade.log for more information

From /var/log/pki/pki-tomcat/ca/debug log file:
2019-10-30 05:03:50 [main] FINE: LdapAuthInfo: init()
2019-10-30 05:03:50 [main] FINE: LdapAuthInfo: init begins
2019-10-30 05:03:50 [main] FINEST: Getting
internaldb.ldapauth.authtype=SslClientAuth
2019-10-30 05:03:50 [main] FINE: LdapAuthInfo: init ends
2019-10-30 05:03:50 [main] FINEST: Property internaldb.errorIfDown not found
2019-10-30 05:03:50 [main] FINEST: Getting internaldb.errorIfDown=true
2019-10-30 05:03:50 [main] FINEST: Property internaldb.doCloning not found
2019-10-30 05:03:50 [main] FINEST: Getting internaldb.doCloning=true
2019-10-30 05:03:50 [main] FINE: LdapBoundConnFactory: doCloning: true
2019-10-30 05:03:50 [main] FINE: LdapBoundConnFactory: mininum: 3
2019-10-30 05:03:50 [main] FINE: LdapBoundConnFactory: maximum: 15
2019-10-30 05:03:50 [main] FINE: LdapBoundConnFactory: host:
home.local.nonet
2019-10-30 05:03:50 [main] FINE: LdapBoundConnFactory: port: 636
2019-10-30 05:03:50 [main] FINE: LdapBoundConnFactory: secure: true
2019-10-30 05:03:50 [main] FINE: LdapBoundConnFactory: authentication: 2
2019-10-30 05:03:50 [main] FINE: LdapBoundConnFactory: makeConnection(true)
2019-10-30 05:03:50 [main] FINEST: Getting
internaldb.ldapauth.clientCertNickname=subsystemCert cert-pki-ca
2019-10-30 05:03:50 [main] FINEST: Property tcp.keepAlive not found
2019-10-30 05:03:50 [main] FINEST: Getting tcp.keepAlive=true
2019-10-30 05:03:50 [main] FINE: TCP Keep-Alive: true
2019-10-30 05:03:50 [main] FINE: LdapBoundConnection: Connecting to
home.local.nonet:636 with client cert auth
2019-10-30 05:03:50 [main] FINE: ldapconn/PKISocketFactory.makeSSLSocket:
begins
2019-10-30 05:03:50 [main] SEVERE: Unable to create socket:
java.net.ConnectException: Connection refused (Connection refused)
java.net.ConnectException: Connection refused (Connection refused)
        at java.net.PlainSocketImpl.socketConnect(Native Method)
        at
java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
        at
java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
        at
java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
        at java.net.Socket.connect(Socket.java:607)
        at java.net.Socket.connect(Socket.java:556)
        at java.net.Socket.<init>(Socket.java:452)
        at java.net.Socket.<init>(Socket.java:262)

Some error is logged to /var/log/messages:
Oct 30 05:26:50 home server[65722]: WARNING: Exception processing realm
[com.netscape.cms.tomcat.ProxyRealm@5647a92b] background process
Oct 30 05:26:50 home server[65722]:
javax.ws.rs.ServiceUnavailableException: Subsystem unavailable
Oct 30 05:26:50 home server[65722]: #011at
com.netscape.cms.tomcat.ProxyRealm.backgroundProcess(ProxyRealm.java:142)
Oct 30 05:26:50 home server[65722]: #011at
org.apache.catalina.core.ContainerBase.backgroundProcess(ContainerBase.java:1137)
Oct 30 05:26:50 home server[65722]: #011at
org.apache.catalina.core.StandardContext.backgroundProcess(StandardContext.java:5566)
Oct 30 05:26:50 home server[65722]: #011at
org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1353)
Oct 30 05:26:50 home server[65722]: #011at
org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1357)
Oct 30 05:26:50 home server[65722]: #011at
org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1335)
Oct 30 05:26:50 home server[65722]: #011at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
Oct 30 05:26:50 home server[65722]: #011at
java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
Oct 30 05:26:50 home server[65722]: #011at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
Oct 30 05:26:50 home server[65722]: #011at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
Oct 30 05:26:50 home server[65722]: #011at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
Oct 30 05:26:50 home server[65722]: #011at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
Oct 30 05:26:50 home server[65722]: #011at
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
Oct 30 05:26:50 home server[65722]: #011at
java.lang.Thread.run(Thread.java:748)

I am able to connect to my ldap server port 636 with TLS without problem.

Thanks,
Patrick

2024

2023

2022

2021

2020

2019

2018

2017

FreeIPA having problem after upgrading from Fedora 30 to 31