[Freeipa-users] PKI-CAD service fails, IPA won't start

Thu Sep 10 15:35:24 UTC 2015

Hello:

So recently, we received some new workstations that I loaded with Ubuntu 12.04. The person who had this sysadmin position before me set up the IPA domain and had it running for quite some time. I went to add one of the systems to the domain through a script he created, something in the configuration failed so I performed an uninstall and was gonna return to it after I retool the script. However, since then IPA has failed to function for more than two minutes at a time. Upon a "ipactl start" it will start every service (even allowing IPA commands to be executed) until it hits the pki-cad service, where it hangs for a while, then seemingly hits a timeout limit and assumes that it fails. Sometimes it does fail, but ipactl doesn't react to this immediately, and it always seems to hit the timeout. Running a journalctl -f as soon as I can, I see the following:

Sep 10 14:40:42 [IPA server] systemd[1]: Reached target 389 Directory Server.
Sep 10 14:40:42 [IPA server] systemd[1]: Starting 389 Directory Server [org name]....
Sep 10 14:40:42 [IPA server] systemd[1]: Ignoring invalid environment 'export KRB5_KTNAME=/etc/dirsrv/ds.keytab': /etc/sysconfig/dirsrv
Sep 10 14:40:42 [IPA server] systemd[1]: Starting 389 Directory Server PKI-IPA....
Sep 10 14:40:42 [IPA server] systemd[1]: Ignoring invalid environment 'export KRB5_KTNAME=/etc/dirsrv/ds.keytab': /etc/sysconfig/dirsrv
Sep 10 14:40:43 [IPA server] systemd[1]: Started 389 Directory Server PKI-IPA..
Sep 10 14:40:43 [IPA server] systemd[1]: Started 389 Directory Server [org name]..
Sep 10 14:41:00 [IPA server] systemd[1]: Starting Kerberos 5 KDC...
Sep 10 14:41:00 [IPA server] systemd[1]: Started Kerberos 5 KDC.
Sep 10 14:41:00 [IPA server] systemd[1]: Starting Kerberos 5 Password-changing and Administration...
Sep 10 14:41:01 [IPA server] systemd[1]: Started Kerberos 5 Password-changing and Administration.
Sep 10 14:41:01 [IPA server] systemd[1]: Starting Berkeley Internet Name Domain (DNS)...
[huge wall of DNS config, completes successfully]
Sep 10 14:41:02 [IPA server] systemd[1]: Started Berkeley Internet Name Domain (DNS).
Sep 10 14:41:02 [IPA server] systemd[1]: Starting Host and Network Name Lookups.
Sep 10 14:41:02 [IPA server] systemd[1]: Reached target Host and Network Name Lookups.
Sep 10 14:41:02 [IPA server] systemd[1]: Started IPA memcached daemon, increases IPA server performance.
Sep 10 14:41:03 [IPA server] systemd[1]: Starting The Apache HTTP Server...
Sep 10 14:41:05 [IPA server] httpd[841]: [Thu Sep 10 14:41:05.050236 2015] [so:warn] [pid 841] AH01574: module nss_module is already loaded, skipping
Sep 10 14:41:06 [IPA server] systemd[1]: Started The Apache HTTP Server.
Sep 10 14:41:06 [IPA server] systemd[1]: Starting PKI Certificate Authority Server.
Sep 10 14:41:06 [IPA server] systemd[1]: Reached target PKI Certificate Authority Server.
Sep 10 14:41:06 [IPA server] systemd[1]: Starting PKI Certificate Authority Server pki-ca...
Sep 10 14:41:06 [IPA server] ns-slapd[690]: GSSAPI server step 1
Sep 10 14:41:06 [IPA server] ns-slapd[690]: GSSAPI server step 2
Sep 10 14:41:06 [IPA server] ns-slapd[690]: GSSAPI server step 3
Sep 10 14:41:07 [IPA server] runuser[958]: pam_unix(runuser-l:session): session opened for user pkiuser by (uid=0)
Sep 10 14:41:07 [IPA server] runuser[958]: pam_unix(runuser-l:session): session closed for user pkiuser
Sep 10 14:41:07 [IPA server] named[828]: zone [subnet].in-addr.arpa/IN: sending notifies (serial 2012080892)
Sep 10 14:41:07 [IPA server] named[828]: zone [org name]/IN: sending notifies (serial 2012080918)
Sep 10 14:41:08 [IPA server] httpd[846]: GSSAPI client step 1
Sep 10 14:41:08 [IPA server] httpd[846]: GSSAPI client step 1
Sep 10 14:41:08 [IPA server] ns-slapd[690]: GSSAPI server step 1
Sep 10 14:41:08 [IPA server] httpd[846]: GSSAPI client step 1
Sep 10 14:41:08 [IPA server] ns-slapd[690]: GSSAPI server step 2
Sep 10 14:41:08 [IPA server] httpd[846]: GSSAPI client step 2
Sep 10 14:41:08 [IPA server] ns-slapd[690]: GSSAPI server step 3
Sep 10 14:41:10 [IPA server] httpd[845]: GSSAPI client step 1
Sep 10 14:41:10 [IPA server] httpd[845]: GSSAPI client step 1
Sep 10 14:41:10 [IPA server] ns-slapd[690]: GSSAPI server step 1
Sep 10 14:41:10 [IPA server] httpd[845]: GSSAPI client step 1
Sep 10 14:41:10 [IPA server] ns-slapd[690]: GSSAPI server step 2
Sep 10 14:41:10 [IPA server] httpd[845]: GSSAPI client step 2
Sep 10 14:41:10 [IPA server] ns-slapd[690]: GSSAPI server step 3
Sep 10 14:41:12 [IPA server] ns-slapd[690]: GSSAPI server step 1
Sep 10 14:41:12 [IPA server] ns-slapd[690]: GSSAPI server step 2
Sep 10 14:41:12 [IPA server] ns-slapd[690]: GSSAPI server step 3
Sep 10 14:41:12 [IPA server] runuser[1061]: pam_unix(runuser-l:session): session opened for user pkiuser by (uid=0)
Sep 10 14:41:12 [IPA server] runuser[1061]: pam_unix(runuser-l:session): session closed for user pkiuser
Sep 10 14:41:13 [IPA server] pkicontrol[1039]: /var/lib/pki-ca/pki-ca: line 101: log_success_msg: command not found
Sep 10 14:41:13 [IPA server] systemd[1]: Started PKI Certificate Authority Server pki-ca.
Sep 10 14:41:16 [IPA server] ns-slapd[690]: GSSAPI server step 1
Sep 10 14:41:16 [IPA server] ns-slapd[690]: GSSAPI server step 2
Sep 10 14:41:16 [IPA server] ns-slapd[690]: GSSAPI server step 3
Sep 10 14:41:25 [IPA server] ns-slapd[690]: GSSAPI server step 1
Sep 10 14:41:25 [IPA server] ns-slapd[690]: GSSAPI server step 2
Sep 10 14:41:25 [IPA server] ns-slapd[690]: GSSAPI server step 3
Sep 10 14:41:34 [IPA server] httpd[846]: GSSAPI client step 1
Sep 10 14:41:34 [IPA server] httpd[846]: GSSAPI client step 1
Sep 10 14:41:34 [IPA server] ns-slapd[690]: GSSAPI server step 1
Sep 10 14:41:34 [IPA server] httpd[846]: GSSAPI client step 1
Sep 10 14:41:34 [IPA server] ns-slapd[690]: GSSAPI server step 2
Sep 10 14:41:34 [IPA server] httpd[846]: GSSAPI client step 2
Sep 10 14:41:34 [IPA server] ns-slapd[690]: GSSAPI server step 3
Sep 10 14:41:39 [IPA server] ns-slapd[690]: GSSAPI server step 1
Sep 10 14:41:39 [IPA server] ns-slapd[690]: GSSAPI server step 2
Sep 10 14:41:39 [IPA server] ns-slapd[690]: GSSAPI server step 3
Sep 10 14:41:50 [IPA server] ns-slapd[690]: GSSAPI server step 1
Sep 10 14:41:50 [IPA server] ns-slapd[690]: GSSAPI server step 2
Sep 10 14:41:50 [IPA server] ns-slapd[690]: GSSAPI server step 3
Sep 10 14:43:32 [IPA server] ns-slapd[690]: GSSAPI server step 1
Sep 10 14:43:32 [IPA server] ns-slapd[690]: GSSAPI server step 2
Sep 10 14:43:32 [IPA server] ns-slapd[690]: GSSAPI server step 3
Sep 10 14:46:06 [IPA server] ipactl[545]: Failed to start pki-cad Service
Sep 10 14:46:06 [IPA server] ipactl[545]: Shutting down

Not entirely sure what the issue is here, the server config wasn't modified at all. Most of the logfiles in /var/log/pki-ca are completely empty. The dirsrv access logs for the slapd-PKI-IPA directory cut off around the time that I attempted the client install. The dirsrv error log contains:

[10/Sep/2015:14:40:44 +0000] - 389-Directory/1.3.1.22.a1 B2014.073.1751 starting up
[10/Sep/2015:14:40:46 +0000] NSMMReplicationPlugin - ruv_compare_ruv: RUV [changelog max RUV] does not contain element [{replica 96 ldap://[IPA server]:7389} 5022b749000000600000 54931184000100600000] which is present in RUV [database RUV]
[10/Sep/2015:14:40:46 +0000] NSMMReplicationPlugin - replica_check_for_data_reload: Warning: for replica o=ipaca there were some differences between the changelog max RUV and the database RUV.  If there are obsolete elements in the database RUV, you should remove them using the CLEANALLRUV task.  If they are not obsolete, you should check their status to see why there are no changes from those servers in the changelog.
[10/Sep/2015:14:40:46 +0000] - slapd started.  Listening on All Interfaces port 7389 for LDAP requests
[10/Sep/2015:14:40:46 +0000] - Listening on All Interfaces port 7390 for LDAPS requests
[10/Sep/2015:14:40:48 +0000] slapi_ldap_bind - Error: could not send startTLS request: error -1 (Can't contact LDAP server) errno 107 (Transport endpoint is not connected)

That last message repeats a few more times until the ipactl process kills the directory services. I'm at a complete loss. Has anyone else seen this or could point out what exactly happened? I can start the individual services, but the IPA service always fails, due to either the PKI-CAD service failing or the timeout. Sorry for the wall of text.

James Cassidy

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://listman.redhat.com/archives/freeipa-users/attachments/20150910/c119325f/attachment.htm>