Hello,
we ran into an issue after an upgrade to FreeIPA 4.6.4, API_VERSION:
2.229 (using the current Docker Image Fedora 27)
The ipa-upgrade ran without issues, but pki-tomcatd is causing trouble
after the upgrade.
The tomcatd system log:
0.localhost-startStop-1 - [05/Nov/2018:08:44:41 UTC] [8] [3] In Ldap
(bound) connection pool to host ipa port 636, Cannot connect to LDAP
server. Error: netscape.ldap.LDAPException: Unable to create socket:
java.net.ConnectException: Connection refused (Connection refused) (-1)
Tomcat Debug log:
java.net.ConnectException: Connection refused (Connection refused)
at java.net.PlainSocketImpl.socketConnect(Native Method)
Could not connect to LDAP server host ipa port 636 Error
netscape.ldap.LDAPException: Unable to create socket:
java.net.ConnectException: Connection refused (Connection refused) (-1)
at
com.netscape.cmscore.ldapconn.LdapBoundConnFactory.makeConnection(LdapBoundConnFactory.java:205)
Internal Database Error encountered: Could not connect to LDAP
server host ipa port 636 Error netscape.ldap.LDAPException: Unable to
create socket: java.net.ConnectException: Connection refused (Connection
refused) (-1)
at com.netscape.cmscore.dbs.DBSubsystem.init(DBSubsystem.java:689)
However, the dirsrv starts just seconds afterwards:
Nov 05 08:44:45 ipa ns-slapd[90]: [05/Nov/2018:08:44:45.159306972
+0000] - INFO - slapd_daemon - slapd started. Listening on All
Interfaces port 389 for LDAP requests
Nov 05 08:44:45 ipa ns-slapd[90]: [05/Nov/2018:08:44:45.162543716
+0000] - INFO - slapd_daemon - Listening on All Interfaces port 636 for
LDAPS requests
Nov 05 08:44:45 ipa systemd[1]: Started 389 Directory Server
Then, certmonger fails to start (probably trying to reach tomcatd, I
assume):
Nov 05 08:45:41 ipa systemd[1]: certmonger.service: Start-post
operation timed out. Stopping.
Nov 05 08:45:50 ipa server[231]: WARNING: Exception processing
realm com.netscape.cms.tomcat.ProxyRealm@3b86a3a1 background process
Nov 05 08:45:50 ipa server[231]:
javax.ws.rs.ServiceUnavailableException: Subsystem unavailable
Nov 05 08:45:50 ipa server[231]: at
com.netscape.cms.tomcat.ProxyRealm.backgroundProcess(ProxyRealm.java:130)
Nov 05 08:45:50 ipa server[231]: at
org.apache.catalina.core.ContainerBase.backgroundProcess(ContainerBase.java:1156)
Nov 05 08:45:50 ipa server[231]: at
org.apache.catalina.core.StandardContext.backgroundProcess(StandardContext.java:5740)
Nov 05 08:45:50 ipa server[231]: at
org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:
1379)
Nov 05 08:45:50 ipa server[231]: at
org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:
1383)
Nov 05 08:45:50 ipa server[231]: at
org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1351)
Nov 05 08:45:50 ipa server[231]: at
java.lang.Thread.run(Thread.java:748)
Nov 05 08:45:56 ipa systemd[1]: Failed to start Certificate
monitoring and PKI enrollment.
Nov 05 08:45:56 ipa systemd[1]: certmonger.service: Unit entered
failed state.
Nov 05 08:45:56 ipa systemd[1]: certmonger.service: Failed with
result 'timeout'.
After that, IPA shuts down after 300 sec.
Nov 05 08:50:01 ipa systemd[1]: Stopping Kerberos 5 KDC...
Nov 05 08:50:01 ipa systemd[1]: Stopped Kerberos 5 KDC.
Nov 05 08:50:01 ipa systemd[1]: Stopping Kerberos 5
Password-changing and Administration...
Nov 05 08:50:01 ipa systemd[1]: kadmin.service: Main process
exited, code=exited, status=2/INVALIDARGUMENT
Nov 05 08:50:01 ipa systemd[1]: Stopped Kerberos 5
Password-changing and Administration.
Nov 05 08:50:01 ipa systemd[1]: kadmin.service: Unit entered failed
state.
Nov 05 08:50:01 ipa systemd[1]: kadmin.service: Failed with result
'exit-code'.
Nov 05 08:50:02 ipa systemd[1]: Stopping The Apache HTTP Server...
Nov 05 08:50:03 ipa systemd[1]: Stopped The Apache HTTP Server.
Nov 05 08:50:03 ipa systemd[1]: Stopping IPA Custodia Service...
Nov 05 08:50:03 ipa systemd[1]: Stopped IPA Custodia Service.
Nov 05 08:50:03 ipa ntpd[73]: ntpd exiting on signal 15 (Terminated)
Nov 05 08:50:03 ipa ntpd[73]: 127.127.1.0 local addr 127.0.0.1 ->
Nov 05 08:50:03 ipa systemd[1]: Stopping Network Time Service...
Nov 05 08:50:03 ipa systemd[1]: Stopped Network Time Service.
Nov 05 08:50:03 ipa systemd[1]: Stopped target PKI Tomcat Server.
Nov 05 08:50:03 ipa systemd[1]: Stopping PKI Tomcat Server
pki-tomcat...
The error is consistent enough, it seems LDAP only comes up seconds
after tomcat tries to reach it.
Nov 05 09:34:57 ipa server[231]: Internal Database Error
encountered: Could not connect to LDAP server host ipa port 636 E rror
netscape.ldap.LDAPException: Unable to create socket:
java.net.ConnectException: Connection refused (Connection refused) (-1)
Nov 05 09:34:59 ipa ns-slapd[83]: [05/Nov/2018:09:34:59.793590657
+0000] - INFO - slapd_daemon - slapd started. Listening on All
Interfaces port 389 for LDAP requests
Nov 05 09:34:59 ipa ns-slapd[83]: [05/Nov/2018:09:34:59.812565603
+0000] - INFO - slapd_daemon - Listening on All Interfaces port 636 for
LDAPS requests
Nov 05 09:34:59 ipa ns-slapd[83]: [05/Nov/2018:09:34:59.814451330
+0000] - INFO - slapd_daemon - Listening on
/var/run/slapd-VISION-FHG-DE.socket for LDAPI requests
Since it's not an Authentication Error, as described here:
https://floblanc.wordpress.com/2017/09/11/troubleshooting-freeipa-pki-tom...
I don't think this is an issue with the certificates. Nonetheless, I
checked them and it seems fine.
When starting FreeIPA via ipactl start, however, the system starts -
certmonger remains failed though. The system isn't fully functional though.
This is how we start the Container:
/usr/bin/docker run \
-h 'ipa' --net bridge -m 0b -e IPA_SERVER_IP=192.168.2.15 \
-e IPA_SERVER_HOSTNAME=ipa \
-p 80:80 \
-p 443:443 \
-p 88:88/tcp \
-p 88:88/udp \
-p 389:389 \
-p 636:636 \
-p 7389:7389 \
-p 464:464/tcp \
-p 464:464/udp \
-p 123:123 \
-p 9443:9443 \
-p 9444:9444 \
-p 9445:9445 \
-v /data/ipa:/data:Z \
-v /sys/fs/cgroup:/sys/fs/cgroup:ro \
--tmpfs /tmp --tmpfs /run --sysctl net.ipv6.conf.all.disable_ipv6=0
--cap-add=SYS_ADMIN --cap-add SYS_TIME \
--name freeipa \
freeipa/freeipa-server:fedora-27 \
Any idea what might cause this, or how we can futher debug it?