Hello,
After running yum update on a EL7.9 system FreeIPA was unable to start asking for manual upgrade.
So I performed the required command, without success:
[root@headnode pki]# ipa-server-upgrade Upgrading IPA:. Estimated time: 1 minute 30 seconds [1/9]: saving configuration [2/9]: disabling listeners [3/9]: enabling DS global lock [4/9]: disabling Schema Compat [5/9]: starting directory server [6/9]: updating schema [7/9]: upgrading server [8/9]: stopping directory server [9/9]: restoring configuration Done. Update complete Upgrading IPA services Upgrading the configuration of the IPA services [Verifying that root certificate is published] [Migrate CRL publish directory] CRL tree already moved [Verifying that CA proxy configuration is correct] IPA server upgrade failed: Inspect /var/log/ipaupgrade.log and run command ipa-server-upgrade manually. CA did not start in 300.0s The ipa-server-upgrade command failed. See /var/log/ipaupgrade.log for more information
Tha /var/log/ipaupgrade.log file is 75k lines long, but looking at it after some hours I think the relevant data is the following:
2023-09-26T22:22:23Z DEBUG stdout=ERROR: No kra subsystem in instance pki-tomcat. 2023-09-26T22:22:35Z DEBUG stderr= 2023-09-26T22:22:35Z DEBUG Starting pki-tomcatd@pki-tomcat. 2023-09-26T22:22:35Z DEBUG Starting external process 2023-09-26T22:22:35Z DEBUG args=/bin/systemctl start pki-tomcatd@pki-tomcat.service 2023-09-26T22:22:36Z DEBUG Process finished, return code=0 2023-09-26T22:22:36Z DEBUG stdout= 2023-09-26T22:22:36Z DEBUG stderr= 2023-09-26T22:22:36Z DEBUG Starting external process 2023-09-26T22:22:36Z DEBUG args=/bin/systemctl is-active pki-tomcatd@pki-tomcat.service 2023-09-26T22:22:36Z DEBUG Process finished, return code=0 2023-09-26T22:22:36Z DEBUG stdout=active 2023-09-26T22:22:36Z DEBUG stderr= 2023-09-26T22:22:36Z DEBUG wait_for_open_ports: localhost [8080, 8443] timeout 300 2023-09-26T22:22:36Z DEBUG waiting for port: 8080 2023-09-26T22:22:36Z DEBUG Failed to connect to port 8080 tcp on ::1 2023-09-26T22:22:36Z DEBUG Failed to connect to port 8080 tcp on 127.0.0.1 2023-09-26T22:22:38Z DEBUG SUCCESS: port: 8080 2023-09-26T22:22:38Z DEBUG waiting for port: 8443 2023-09-26T22:22:38Z DEBUG SUCCESS: port: 8443 2023-09-26T22:22:38Z DEBUG Start of pki-tomcatd@pki-tomcat.service complete 2023-09-26T22:22:38Z DEBUG Waiting until the CA is running 2023-09-26T22:22:38Z DEBUG request POST http://DOMAIN:8080/ca/admin/ca/getStatus 2023-09-26T22:22:38Z DEBUG request body '' 2023-09-26T22:22:42Z DEBUG response status 500 2023-09-26T22:22:42Z DEBUG response headers Server: Apache-Coyote/1.1 2023-09-26T22:22:42Z DEBUG response body '<html><head><title>Apache Tomcat/7.0.76 - Error report</title><style><!--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;}HR {color : #525D76;}--></style> </head><body><h1>HTTP Status 500 - Subsystem unavailable</h1><HR size="1" noshade="noshade"><p><b>type</b> Exception report</p><p><b>message</b> <u>Subsystem unavailable</u></p><p><b>description</b> <u>The server encountered an internal error that prevented it from fulfilling this request.</u></p><p><b>exception</b> <pre>javax.ws.rs.ServiceUnavailableException: Subsystem unavailable\n\tcom.netscape.cms.tomcat.ProxyRealm.findSecurityConstraints(ProxyRealm.java:145)\n\torg.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:492)\n\torg.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)\n\torg.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:962)\n\torg.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:445)\n\torg.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1091)\n\torg.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:637)\n\torg.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)\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:750)\n</pre></p><p><b>note</b> <u>The full stack trace of the root cause is available in the Apache Tomcat/7.0.76 logs.</u></p><HR size="1" noshade="noshade"><h3>Apache Tomcat/7.0.76</h3></body></html>' 2023-09-26T22:22:42Z DEBUG The CA status is: check interrupted due to error: Retrieving CA status failed with status 500 2023-09-26T22:22:42Z DEBUG Waiting for CA to start…
So it seems that the CA is broken.
On /var/log/pki; I can find this:
cat pki-server-upgrade-10.5.* Upgrading PKI server configuration at Mon Sep 18 01:38:43 -03 2023. Upgrading from version 10.5.9 to 10.5.17: 1. Update audit events
Upgrading from version 10.5.17 to 10.5.18: 1. Fix EC admin certificate profile
Upgrading from version 10.5.18 to 10.5.18: 1. Add caAuditSigningCert profile 2. Fix the authentication for caServerKeygen_UserCert profile ERROR: [Errno 2] No such file or directory: '/var/lib/pki/pki-tomcat/ca/profiles/ca/caServerKeygen_UserCert.cfg' Failed upgrading pki-tomcat/ca subsystem.
Upgrade failed in pki-tomcat/ca: [Errno 2] No such file or directory: '/var/lib/pki/pki-tomcat/ca/profiles/ca/caServerKeygen_UserCert.cfg'
Continue (Yes/No) [Y]? Traceback (most recent call last): File "/sbin/pki-server-upgrade", line 211, in <module> main(sys.argv) File "/sbin/pki-server-upgrade", line 204, in main upgrader.upgrade() File "/usr/lib/python2.7/site-packages/pki/upgrade.py", line 623, in upgrade self.upgrade_version(version) File "/usr/lib/python2.7/site-packages/pki/upgrade.py", line 613, in upgrade_version case_sensitive=False).lower() File "/usr/lib/python2.7/site-packages/pki/__init__.py", line 142, in read_text value = input(message) EOFError: EOF when reading a line
But nothing more.
Any ideia of what I should be looking for?
Thanks.
Vinícius Ferrão via FreeIPA-users wrote:
Hello,
After running yum update on a EL7.9 system FreeIPA was unable to start asking for manual upgrade.
So I performed the required command, without success:
[root@headnode pki]# ipa-server-upgrade Upgrading IPA:. Estimated time: 1 minute 30 seconds [1/9]: saving configuration [2/9]: disabling listeners [3/9]: enabling DS global lock [4/9]: disabling Schema Compat [5/9]: starting directory server [6/9]: updating schema [7/9]: upgrading server [8/9]: stopping directory server [9/9]: restoring configuration Done. Update complete Upgrading IPA services Upgrading the configuration of the IPA services [Verifying that root certificate is published] [Migrate CRL publish directory] CRL tree already moved [Verifying that CA proxy configuration is correct] IPA server upgrade failed: Inspect /var/log/ipaupgrade.log and run command ipa-server-upgrade manually. CA did not start in 300.0s The ipa-server-upgrade command failed. See /var/log/ipaupgrade.log for more information
Tha /var/log/ipaupgrade.log file is 75k lines long, but looking at it after some hours I think the relevant data is the following:
2023-09-26T22:22:23Z DEBUG stdout=ERROR: No kra subsystem in instance pki-tomcat. 2023-09-26T22:22:35Z DEBUG stderr= 2023-09-26T22:22:35Z DEBUG Starting pki-tomcatd@pki-tomcat. 2023-09-26T22:22:35Z DEBUG Starting external process 2023-09-26T22:22:35Z DEBUG args=/bin/systemctl start pki-tomcatd@pki-tomcat.service 2023-09-26T22:22:36Z DEBUG Process finished, return code=0 2023-09-26T22:22:36Z DEBUG stdout= 2023-09-26T22:22:36Z DEBUG stderr= 2023-09-26T22:22:36Z DEBUG Starting external process 2023-09-26T22:22:36Z DEBUG args=/bin/systemctl is-active pki-tomcatd@pki-tomcat.service 2023-09-26T22:22:36Z DEBUG Process finished, return code=0 2023-09-26T22:22:36Z DEBUG stdout=active 2023-09-26T22:22:36Z DEBUG stderr= 2023-09-26T22:22:36Z DEBUG wait_for_open_ports: localhost [8080, 8443] timeout 300 2023-09-26T22:22:36Z DEBUG waiting for port: 8080 2023-09-26T22:22:36Z DEBUG Failed to connect to port 8080 tcp on ::1 2023-09-26T22:22:36Z DEBUG Failed to connect to port 8080 tcp on 127.0.0.1 2023-09-26T22:22:38Z DEBUG SUCCESS: port: 8080 2023-09-26T22:22:38Z DEBUG waiting for port: 8443 2023-09-26T22:22:38Z DEBUG SUCCESS: port: 8443 2023-09-26T22:22:38Z DEBUG Start of pki-tomcatd@pki-tomcat.service complete 2023-09-26T22:22:38Z DEBUG Waiting until the CA is running 2023-09-26T22:22:38Z DEBUG request POST http://DOMAIN:8080/ca/admin/ca/getStatus 2023-09-26T22:22:38Z DEBUG request body '' 2023-09-26T22:22:42Z DEBUG response status 500 2023-09-26T22:22:42Z DEBUG response headers Server: Apache-Coyote/1.1 2023-09-26T22:22:42Z DEBUG response body '<html><head><title>Apache Tomcat/7.0.76 - Error report</title><style><!--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;}HR {color : #525D76;}--></style> </head><body><h1>HTTP Status 500 - Subsystem unavailable</h1><HR size="1" noshade="noshade"><p><b>type</b> Exception report</p><p><b>message</b> <u>Subsystem unavailable</u></p><p><b>description</b> <u>The server encountered an internal error that prevented it from fulfilling this request.</u></p><p><b>exception</b> <pre>javax.ws.rs.ServiceUnavailableException: Subsystem unavailable\n\tcom.netscape.cms.tomcat.ProxyRealm.findSecurityConstraints(ProxyRealm.java:145)\n\torg.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:492)\n\torg.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)\n\torg.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:962)\n\torg.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:445)\n\torg.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1091)\n\torg.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:637)\n\torg.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)\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:750)\n</pre></p><p><b>note</b> <u>The full stack trace of the root cause is available in the Apache Tomcat/7.0.76 logs.</u></p><HR size="1" noshade="noshade"><h3>Apache Tomcat/7.0.76</h3></body></html>' 2023-09-26T22:22:42Z DEBUG The CA status is: check interrupted due to error: Retrieving CA status failed with status 500 2023-09-26T22:22:42Z DEBUG Waiting for CA to start…
So it seems that the CA is broken.
On /var/log/pki; I can find this:
cat pki-server-upgrade-10.5.* Upgrading PKI server configuration at Mon Sep 18 01:38:43 -03 2023. Upgrading from version 10.5.9 to 10.5.17:
- Update audit events
Upgrading from version 10.5.17 to 10.5.18:
- Fix EC admin certificate profile
Upgrading from version 10.5.18 to 10.5.18:
- Add caAuditSigningCert profile
- Fix the authentication for caServerKeygen_UserCert profile
ERROR: [Errno 2] No such file or directory: '/var/lib/pki/pki-tomcat/ca/profiles/ca/caServerKeygen_UserCert.cfg' Failed upgrading pki-tomcat/ca subsystem.
Upgrade failed in pki-tomcat/ca: [Errno 2] No such file or directory: '/var/lib/pki/pki-tomcat/ca/profiles/ca/caServerKeygen_UserCert.cfg'
Continue (Yes/No) [Y]? Traceback (most recent call last): File "/sbin/pki-server-upgrade", line 211, in <module> main(sys.argv) File "/sbin/pki-server-upgrade", line 204, in main upgrader.upgrade() File "/usr/lib/python2.7/site-packages/pki/upgrade.py", line 623, in upgrade self.upgrade_version(version) File "/usr/lib/python2.7/site-packages/pki/upgrade.py", line 613, in upgrade_version case_sensitive=False).lower() File "/usr/lib/python2.7/site-packages/pki/__init__.py", line 142, in read_text value = input(message) EOFError: EOF when reading a line
But nothing more.
Any ideia of what I should be looking for?
I'd suggest looking at the pki debug log and/or selftests.log. This may not be related to the upgrade, you're just noticing because the services restarted.
rob
freeipa-users@lists.fedorahosted.org
-
Rob Crittenden -
Vinícius Ferrão