7:12 a.m.
Hi all,
I'm trying to set up a replica on CentOS 7, the master is on CentOS 6. Eventually, I
want to retire the CentOS 6 host. I'm following this migration guide:
https://www.freeipa.org/page/Howto/Migration#Migrating_existing_FreeIPA_d...
However, running `ipa-replica-install --setup-ca ./replica-info-replica.fqdn.gpg` always
gets stuck and eventually fails when setting up pki-tomcatd:
Configuring certificate server (pki-tomcatd). Estimated time: 3 minutes
[1/28]: configuring certificate server instance
[2/28]: exporting Dogtag certificate store pin
[3/28]: stopping certificate server instance to update CS.cfg
[4/28]: backing up CS.cfg
[5/28]: disabling nonces
[6/28]: set up CRL publishing
[7/28]: enable PKIX certificate path discovery and validation
[8/28]: starting certificate server instance
[9/28]: configure certmonger for renewals
[10/28]: importing RA certificate from PKCS #12 file
[11/28]: setting audit signing renewal to 2 years
[12/28]: restarting certificate server
[13/28]: authorizing RA to modify profiles
[14/28]: authorizing RA to manage lightweight CAs
[15/28]: Ensure lightweight CAs container exists
[16/28]: Ensuring backward compatibility
[17/28]: configure certificate renewals
[18/28]: configure Server-Cert certificate renewal
[19/28]: Configure HTTP to proxy connections
[20/28]: restarting certificate server
[21/28]: updating IPA configuration
[22/28]: enabling CA instance
[23/28]: exposing CA instance on LDAP
[24/28]: migrating certificate profiles to LDAP
[25/28]: importing IPA certificate profiles
[26/28]: adding default CA ACL
[27/28]: adding 'ipa' CA entry
[28/28]: configuring certmonger renewal for lightweight CAs
Done configuring certificate server (pki-tomcatd).
Your system may be partly configured.
Run /usr/sbin/ipa-server-install --uninstall to clean up.
ipapython.admintool: ERROR CA did not start in 300.0s
ipapython.admintool: ERROR The ipa-replica-install command failed. See
/var/log/ipareplica-install.log for more information
Looking at `ipareplica-install.log`:
2019-07-24T11:14:21Z DEBUG stderr=
2019-07-24T11:14:21Z DEBUG wait_for_open_ports: localhost [8080, 8443] timeout 300
2019-07-24T11:14:21Z DEBUG waiting for port: 8080
2019-07-24T11:14:21Z DEBUG Failed to connect to port 8080 tcp on ::1
2019-07-24T11:14:21Z DEBUG Failed to connect to port 8080 tcp on 127.0.0.1
2019-07-24T11:14:25Z DEBUG SUCCESS: port: 8080
2019-07-24T11:14:25Z DEBUG waiting for port: 8443
2019-07-24T11:14:25Z DEBUG SUCCESS: port: 8443
2019-07-24T11:14:25Z DEBUG Start of pki-tomcatd(a)pki-tomcat.service complete
2019-07-24T11:14:25Z DEBUG Waiting until the CA is running
2019-07-24T11:14:25Z DEBUG request POST http://replica.fqdn:8080/ca/admin/ca/getStatus
2019-07-24T11:14:25Z DEBUG request body ''
2019-07-24T11:14:44Z DEBUG response status 500
2019-07-24T11:14:44Z DEBUG response headers Server: Apache-Coyote/1.1
Content-Type: text/html;charset=utf-8
Content-Language: en
Content-Length: 2208
Date: Wed, 24 Jul 2019 11:14:44 GMT
Connection: close
2019-07-24T11:14:44Z 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 requ
est.</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:500)\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:1087)\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.TaskThrea
d$WrappingRunnable.run(TaskThread.java:61)\n\tjava.lang.Thread.run(Thread.java:748)\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>'
2019-07-24T11:14:44Z DEBUG The CA status is: check interrupted due to error: Retrieving CA
status failed with status 500
2019-07-24T11:14:44Z DEBUG Waiting for CA to start...
2019-07-24T11:14:45Z DEBUG request POST http://replica.fqdn:8080/ca/admin/ca/getStatus
2019-07-24T11:14:45Z DEBUG request body ''
2019-07-24T11:14:45Z DEBUG response status 500
2019-07-24T11:14:45Z DEBUG response headers Server: Apache-Coyote/1.1
Content-Type: text/html;charset=utf-8
Content-Language: en
Content-Length: 2208
Date: Wed, 24 Jul 2019 11:14:45 GMT
Connection: close
Looking into the log of pki-tomcatd, I see the following:
Internal Database Error encountered: Could not connect to LDAP server host replica.fqdn
port 636 Error netscape.ldap.LDAPException: Authentication failed (48)
[...]
WARNING: Exception processing realm com.netscape.cms.tomcat.ProxyRealm@6ae79124 background
process
javax.ws.rs.ServiceUnavailableException: Subsystem unavailable
at com.netscape.cms.tomcat.ProxyRealm.backgroundProcess(ProxyRealm.java:137)
at org.apache.catalina.core.ContainerBase.backgroundProcess(ContainerBase.java:1356)
at org.apache.catalina.core.StandardContext.backgroundProcess(StandardContext.java:5958)
at
org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1542)
at
org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1552)
at
org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1552)
at
org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1520)
at java.lang.Thread.run(Thread.java:748)
I checked that the pki-tomcatd uses the right certificates, following this guide:
https://floblanc.wordpress.com/2017/09/11/troubleshooting-freeipa-pki-tom...
Everything looked fine, i.e., tomcat uses the correct certificate and can also read the
private key.
Interestingly, during the setup of the replica, the setup is stuck for quite some time
(~30 minutes) in the step " [1/28]: configuring certificate server instance".
In the ns-slapd log, I can see a lot of the following:
INFO - import_monitor_threads - import ipaca: Processed 40105 entries -- average rate
123.8/sec, recent rate 114.0/sec, hit ratio 100%
I'm surprised by the number of entries. I had set up the same host as a replica in a
previous try, but needed to remove it due to another error. May those be left-overs from
the previous replica instance? I didn't see this happening on the first attempt.
Before redoing the setup, I removed the host from the replica set with `ipa-replica-manage
del --force`, from the csreplica with `ipa-csreplica-manage del --force`, and also deleted
the host entry itself with `ipa host-del`. I also uninstalled the freeipa server on the
replica host.
I'm also wondering about the `Authentication failed (48)`, as 48 indicates
LDAP_INAPPROPRIATE_AUTH.
I'm not sure how to debug this. Any help is appreciated!
Kind regards,
Till