Dear all,
after a short power outage this morning the server hosting our virtual machine ipa2 (running ipa-server-4.6.4-10) had lost its harddisks. After a reboot the server and the virtual machine ipa2 are back, but the ipa service cannot be started (it trys a long time to start pki-tomcat and then fails).
The attached error messages are the best I could find in the logs ... any help is much appreciated!!!!
Thanks a lot in advance!
Best regards, Marisa
[root@ipa2 slapd-PLEIADES-UNI-WUPPERTAL-DE]# tail -f errors [18/Mar/2019:14:36:27.539686690 +0100] - ERR - NSMMReplicationPlugin - ruv_compare_ruv - RUV [changelog max RUV] does not contain element [{replica 97 ldap://ipa2.pleiades.uni-wuppertal.de:389} 5645e979000000610000 57ac3411000400610000] which is present in RUV [database RUV] [18/Mar/2019:14:36:27.545032725 +0100] - WARN - NSMMReplicationPlugin - replica_check_for_data_reload - 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. [18/Mar/2019:14:36:27.577557647 +0100] - ERR - set_krb5_creds - Could not get initial credentials for principal [ldap/ipa2.pleiades.uni-wuppertal.de@PLEIADES.UNI-WUPPERTAL.DE] in keytab [FILE:/etc/dirsrv/ds.keytab]: -1765328324 (Generic error (see e-text)) [18/Mar/2019:14:36:27.641236527 +0100] - INFO - slapd_daemon - slapd started. Listening on All Interfaces port 389 for LDAP requests [18/Mar/2019:14:36:27.663628433 +0100] - INFO - slapd_daemon - Listening on All Interfaces port 636 for LDAPS requests [18/Mar/2019:14:36:27.668455970 +0100] - INFO - slapd_daemon - Listening on /var/run/slapd-PLEIADES-UNI-WUPPERTAL-DE.socket for LDAPI requests [18/Mar/2019:14:36:28.168206235 +0100] - ERR - schema-compat-plugin - schema-compat-plugin tree scan will start in about 5 seconds! [18/Mar/2019:14:36:33.531027962 +0100] - ERR - schema-compat-plugin - warning: no entries set up under ou=sudoers,dc=pleiades,dc=uni-wuppertal,dc=de [18/Mar/2019:14:36:33.969987161 +0100] - ERR - schema-compat-plugin - warning: no entries set up under cn=computers, cn=compat,dc=pleiades,dc=uni-wuppertal,dc=de [18/Mar/2019:14:36:33.987009592 +0100] - ERR - schema-compat-plugin - Finished plugin initialization.
[root@ipa2 slapd-PLEIADES-UNI-WUPPERTAL-DE]# ipa-replica-manage list-ruv Directory Manager password:
Replica Update Vectors: ipa2.pleiades.uni-wuppertal.de:389: 10 ipa.pleiades.uni-wuppertal.de:389: 11 Certificate Server Replica Update Vectors: ipa2.pleiades.uni-wuppertal.de:389: 81 ipa.pleiades.uni-wuppertal.de:389: 1095 ipa.pleiades.uni-wuppertal.de:389: 96 ipacentos7.pleiades.uni-wuppertal.de:389: 86 ipacentos7.pleiades.uni-wuppertal.de:389: 91 ipa2.pleiades.uni-wuppertal.de:389: 97 [root@ipa2 slapd-PLEIADES-UNI-WUPPERTAL-DE]#
Marisa Sandhoff via FreeIPA-users freeipa-users@lists.fedorahosted.org writes:
[18/Mar/2019:14:36:27.577557647 +0100] - ERR - set_krb5_creds - Could not get initial credentials for principal [ldap/ipa2.pleiades.uni-wuppertal.de@PLEIADES.UNI-WUPPERTAL.DE] in keytab [FILE:/etc/dirsrv/ds.keytab]: -1765328324 (Generic error (see e-text))
Can you inspect this keytab? `klist -ekt /etc/dirsrv/ds.keytab`?
Thanks, --Robbie
Robbie Harwood via FreeIPA-users wrote:
Marisa Sandhoff via FreeIPA-users freeipa-users@lists.fedorahosted.org writes:
[18/Mar/2019:14:36:27.577557647 +0100] - ERR - set_krb5_creds - Could not get initial credentials for principal [ldap/ipa2.pleiades.uni-wuppertal.de@PLEIADES.UNI-WUPPERTAL.DE] in keytab [FILE:/etc/dirsrv/ds.keytab]: -1765328324 (Generic error (see e-text))
Can you inspect this keytab? `klist -ekt /etc/dirsrv/ds.keytab`?
Those errors are normal. 389-ds was rather chatty about starting up when it doesn't have a ccache.
You should look at the CA logs in /var/log/pki/pki-tomcat/ca
To bring IPA up without the CA to limp along while you diagnose the problem run: ipactl start --ignore-service-failures
rob
Hi Rob,
thanks for pointing us into that direction.
Actually, I already looked into /var/log/pkg/pkg-tomcat/ca/debug, but couldn't find anything that rang the bell. Here are the last couple of lines.
[root@ipa2 ca]# tail -40 debug [18/Mar/2019:14:36:39][SerialNumberUpdateTask]: TCP Keep-Alive: true [18/Mar/2019:14:36:39][SerialNumberUpdateTask]: SSLClientCertificateSelectionCB: Setting desired cert nickname to: subsystemCert cert-pki-ca [18/Mar/2019:14:36:39][SerialNumberUpdateTask]: LdapJssSSLSocket: set client auth cert nickname subsystemCert cert-pki-ca [18/Mar/2019:14:36:39][SerialNumberUpdateTask]: SSL handshake happened [18/Mar/2019:14:36:39][SerialNumberUpdateTask]: Established LDAP connection with SSL client auth to ipa2.pleiades.uni-wuppertal.de:636 [18/Mar/2019:14:36:39][SerialNumberUpdateTask]: getConn: conn is connected false [18/Mar/2019:14:36:39][SerialNumberUpdateTask]: Attempt to bring back down connection. [18/Mar/2019:14:36:39][SerialNumberUpdateTask]: Re-animated connection: LDAPConnection {ldaps://ipa2.pleiades.uni-wuppertal.de:636 (2) ldapVersion:3 bindDN:""} [18/Mar/2019:14:36:39][SerialNumberUpdateTask]: getConn: mNumConns now 2 [18/Mar/2019:14:36:39][SerialNumberUpdateTask]: Releasing ldap connection [18/Mar/2019:14:36:39][SerialNumberUpdateTask]: returnConn: mNumConns now 3 [18/Mar/2019:14:36:39][SerialNumberUpdateTask]: DBSubsystem: getEntryAttribute: dn=ou=certificateRepository, ou=ca, o=ipaca attr=description:; [18/Mar/2019:14:36:39][SerialNumberUpdateTask]: CertificateRepository: updateCounter mEnableRandomSerialNumbers=false [18/Mar/2019:14:36:39][SerialNumberUpdateTask]: CertificateRepository: updateCounter CertificateRepositoryMode = [18/Mar/2019:14:36:39][SerialNumberUpdateTask]: CertificateRepository: updateCounter modeChange=false [18/Mar/2019:14:36:39][SerialNumberUpdateTask]: CertificateRepository: UpdateCounter mEnableRandomSerialNumbers=false mCounter=-1 [18/Mar/2019:14:36:39][SerialNumberUpdateTask]: Starting cert checkRanges [18/Mar/2019:14:36:39][SerialNumberUpdateTask]: Repository: Server not completely started. Returning .. [18/Mar/2019:14:36:39][SerialNumberUpdateTask]: Starting request checkRanges [18/Mar/2019:14:36:39][SerialNumberUpdateTask]: Repository: Server not completely started. Returning .. [18/Mar/2019:14:36:39][SerialNumberUpdateTask]: updateSerialNumbers done [18/Mar/2019:14:46:39][SerialNumberUpdateTask]: About to start updateSerialNumbers [18/Mar/2019:14:46:39][SerialNumberUpdateTask]: Starting updateSerialNumbers (entered lock) [18/Mar/2019:14:46:39][SerialNumberUpdateTask]: CertificateRepository: updateCounter mEnableRandomSerialNumbers=false mCounter=-1 [18/Mar/2019:14:46:39][SerialNumberUpdateTask]: In LdapBoundConnFactory::getConn() [18/Mar/2019:14:46:39][SerialNumberUpdateTask]: masterConn is connected: true [18/Mar/2019:14:46:39][SerialNumberUpdateTask]: getConn: conn is connected true [18/Mar/2019:14:46:39][SerialNumberUpdateTask]: getConn: mNumConns now 2 [18/Mar/2019:14:46:39][SerialNumberUpdateTask]: Releasing ldap connection [18/Mar/2019:14:46:39][SerialNumberUpdateTask]: returnConn: mNumConns now 3 [18/Mar/2019:14:46:39][SerialNumberUpdateTask]: DBSubsystem: getEntryAttribute: dn=ou=certificateRepository, ou=ca, o=ipaca attr=description:; [18/Mar/2019:14:46:39][SerialNumberUpdateTask]: CertificateRepository: updateCounter mEnableRandomSerialNumbers=false [18/Mar/2019:14:46:39][SerialNumberUpdateTask]: CertificateRepository: updateCounter CertificateRepositoryMode = [18/Mar/2019:14:46:39][SerialNumberUpdateTask]: CertificateRepository: updateCounter modeChange=false [18/Mar/2019:14:46:39][SerialNumberUpdateTask]: CertificateRepository: UpdateCounter mEnableRandomSerialNumbers=false mCounter=-1 [18/Mar/2019:14:46:39][SerialNumberUpdateTask]: Starting cert checkRanges [18/Mar/2019:14:46:39][SerialNumberUpdateTask]: Repository: Server not completely started. Returning .. [18/Mar/2019:14:46:39][SerialNumberUpdateTask]: Starting request checkRanges [18/Mar/2019:14:46:39][SerialNumberUpdateTask]: Repository: Server not completely started. Returning .. [18/Mar/2019:14:46:39][SerialNumberUpdateTask]: updateSerialNumbers done [root@ipa2 ca]#
However, the "system" file contains tons of:
0.profileChangeMonitor - [18/Mar/2019:14:36:25 CET] [8] [3] In Ldap (bound) connection pool to host ipa2.pleiades.uni-wuppertal.de port 636, Cannot connect to LDAP server. Error: netscape.ldap.LDAPException: Unable to create socket: java.net.ConnectException: Connection refused (Connection refused) (-1) 0.profileChangeMonitor - [18/Mar/2019:14:36:26 CET] [8] [3] In Ldap (bound) connection pool to host ipa2.pleiades.uni-wuppertal.de port 636, Cannot connect to LDAP server. Error: netscape.ldap.LDAPException: Unable to create socket: java.net.ConnectException: Connection refused (Connection refused) (-1) 0.authorityMonitor - [18/Mar/2019:14:36:26 CET] [8] [3] In Ldap (bound) connection pool to host ipa2.pleiades.uni-wuppertal.de port 636, Cannot connect to LDAP server. Error: netscape.ldap.LDAPException: Unable to create socket: java.net.ConnectException: Connection refused (Connection refused) (-1)
We started IPA with the "--ignore-service-failures" flag, but still noone could log in. We switched ipa off at the moment so the other server is inquired which still works ok.
Thanks for your help!!!
Kind regards
Torsten
Am 18. März 2019 19:00:54 MEZ schrieb Rob Crittenden rcritten@redhat.com:
Robbie Harwood via FreeIPA-users wrote:
Marisa Sandhoff via FreeIPA-users
freeipa-users@lists.fedorahosted.org
writes:
[18/Mar/2019:14:36:27.577557647 +0100] - ERR - set_krb5_creds -
Could
not get initial credentials for principal [ldap/ipa2.pleiades.uni-wuppertal.de@PLEIADES.UNI-WUPPERTAL.DE] in keytab [FILE:/etc/dirsrv/ds.keytab]: -1765328324 (Generic error (see e-text))
Can you inspect this keytab? `klist -ekt /etc/dirsrv/ds.keytab`?
Those errors are normal. 389-ds was rather chatty about starting up when it doesn't have a ccache.
You should look at the CA logs in /var/log/pki/pki-tomcat/ca
To bring IPA up without the CA to limp along while you diagnose the problem run: ipactl start --ignore-service-failures
rob
Dear all,
thank you very much for your help.
After some more searching, I found that this command (from https://floblanc.wordpress.com/2017/09/11/troubleshooting-freeipa-pki-tomcat...)
[root@ipa2 ~] certutil -L -d /etc/pki/pki-tomcat/alias -n 'subsystemCert cert-pki-ca'
shows that there is a valid certificate:
Certificate: Data: Version: 3 (0x2) Serial Number: ... Signature Algorithm: PKCS #1 SHA-256 With RSA Encryption Issuer: "CN=Certificate Authority,O=PLEIADES.UNI-WUPPERTAL.DE" Validity: Not Before: Fri Jan 25 08:55:41 2019 Not After : Thu Jan 14 08:55:41 2021 Subject: "CN=CA Subsystem,O=PLEIADES.UNI-WUPPERTAL.DE" Subject Public Key Info: Public Key Algorithm: PKCS #1 RSA Encryption RSA Public Key:
But then I get:
[root@ipa2 ~]# grep internal /var/lib/pki/pki-tomcat/conf/password.conf | cut -d= -f2 > /tmp/pwdfile.txt
[root@ipa2 ~]# certutil -K -d /etc/pki/pki-tomcat/alias -f /tmp/pwdfile.txt -n 'subsystemCert cert-pki-ca' certutil: Checking token "NSS Certificate DB" in slot "NSS User Private Key and Certificate Services" certutil: problem listing keys: SEC_ERROR_UNRECOGNIZED_OID: Unrecognized Object Identifier.
[root@ipa2 ~]# certutil -K -d /etc/pki/pki-tomcat/alias -f /tmp/pwdfile.txt -n 'NSS Certificate DB: subsystemCert cert-pki-ca' certutil: Checking token "NSS Certificate DB" in slot "NSS User Private Key and Certificate Services" certutil: problem listing keys: SEC_ERROR_UNRECOGNIZED_OID: Unrecognized Object Identifier. [root@ipa2 ~]#
What can I do?????
Thanks a lot!!!
Best regards, Marisa
On 3/19/19 11:08 AM, Marisa Sandhoff via FreeIPA-users wrote:
Dear all,
thank you very much for your help.
After some more searching, I found that this command (from https://floblanc.wordpress.com/2017/09/11/troubleshooting-freeipa-pki-tomcat...)
[root@ipa2 ~] certutil -L -d /etc/pki/pki-tomcat/alias -n 'subsystemCert cert-pki-ca'
shows that there is a valid certificate:
Certificate: Data: Version: 3 (0x2) Serial Number: ... Signature Algorithm: PKCS #1 SHA-256 With RSA Encryption Issuer: "CN=Certificate Authority,O=PLEIADES.UNI-WUPPERTAL.DE" Validity: Not Before: Fri Jan 25 08:55:41 2019 Not After : Thu Jan 14 08:55:41 2021 Subject: "CN=CA Subsystem,O=PLEIADES.UNI-WUPPERTAL.DE" Subject Public Key Info: Public Key Algorithm: PKCS #1 RSA Encryption RSA Public Key:
But then I get:
[root@ipa2 ~]# grep internal /var/lib/pki/pki-tomcat/conf/password.conf | cut -d= -f2 > /tmp/pwdfile.txt
[root@ipa2 ~]# certutil -K -d /etc/pki/pki-tomcat/alias -f /tmp/pwdfile.txt -n 'subsystemCert cert-pki-ca' certutil: Checking token "NSS Certificate DB" in slot "NSS User Private Key and Certificate Services" certutil: problem listing keys: SEC_ERROR_UNRECOGNIZED_OID: Unrecognized Object Identifier.
[root@ipa2 ~]# certutil -K -d /etc/pki/pki-tomcat/alias -f /tmp/pwdfile.txt -n 'NSS Certificate DB: subsystemCert cert-pki-ca' certutil: Checking token "NSS Certificate DB" in slot "NSS User Private Key and Certificate Services" certutil: problem listing keys: SEC_ERROR_UNRECOGNIZED_OID: Unrecognized Object Identifier. [root@ipa2 ~]#
What can I do?????
Hi Marisa, this may be a red herring. Did you try the next steps (comparison of the uid=pkidbuser,ou=people,o=ipaca usercertificate with the cert stored in /etc/pki/pki-tomcat/alias)?
flo
Thanks a lot!!!
Best regards, Marisa
Dear Florence, dear all,
thanks for this hint.
I searched/checked further and found somewhere in an old thread on this list with
ldapsearch -xLLL -D "cn=Directory Manager" -W -b ou=certificateprofiles,ou=ca,o=ipaca '(&(nsds5ReplConflict=*)(objectclass=ldapsubentry)
an entry
dn: cn=KDCs_PKINIT_Certs+nsuniqueid=9e022602-2f7911e9-a45ee6ee-1e585ae9,ou=certificateProfiles,ou=ca,o=ipaca
after deleting this conflict entry pki-tomcat did start :-)
Thanks for all of your help!
Regards, Marisa
Hi Marisa, this may be a red herring. Did you try the next steps (comparison of the uid=pkidbuser,ou=people,o=ipaca usercertificate with the cert stored in /etc/pki/pki-tomcat/alias)?
flo
Hi,
thanks for coming back to this.
here is the output:
[root@ipa2 ~]# klist -ekt /etc/dirsrv/ds.keytab Keytab name: FILE:/etc/dirsrv/ds.keytab KVNO Timestamp Principal ---- ------------------- ------------------------------------------------------ 2 08/15/2016 11:18:33 ldap/ipa2.pleiades.uni-wuppertal.de@PLEIADES.UNI-WUPPERTAL.DE (aes256-cts-hmac-sha1-96) 2 08/15/2016 11:18:33 ldap/ipa2.pleiades.uni-wuppertal.de@PLEIADES.UNI-WUPPERTAL.DE (aes128-cts-hmac-sha1-96) 2 08/15/2016 11:18:33 ldap/ipa2.pleiades.uni-wuppertal.de@PLEIADES.UNI-WUPPERTAL.DE (des3-cbc-sha1) 2 08/15/2016 11:18:33 ldap/ipa2.pleiades.uni-wuppertal.de@PLEIADES.UNI-WUPPERTAL.DE (arcfour-hmac) 2 08/15/2016 11:18:33 ldap/ipa2.pleiades.uni-wuppertal.de@PLEIADES.UNI-WUPPERTAL.DE (camellia128-cts-cmac) 2 08/15/2016 11:18:33 ldap/ipa2.pleiades.uni-wuppertal.de@PLEIADES.UNI-WUPPERTAL.DE (camellia256-cts-cmac) 2 08/15/2016 11:18:33 ldap/ipa2.pleiades.uni-wuppertal.de@PLEIADES.UNI-WUPPERTAL.DE (des-cbc-crc) [root@ipa2 ~]#
Hope it tells you something.
Kind regards,
Torsten
Am 18. März 2019 18:20:06 MEZ schrieb Robbie Harwood via FreeIPA-users freeipa-users@lists.fedorahosted.org:
Marisa Sandhoff via FreeIPA-users freeipa-users@lists.fedorahosted.org writes:
[18/Mar/2019:14:36:27.577557647 +0100] - ERR - set_krb5_creds - Could not get initial credentials for principal [ldap/ipa2.pleiades.uni-wuppertal.de@PLEIADES.UNI-WUPPERTAL.DE] in keytab [FILE:/etc/dirsrv/ds.keytab]: -1765328324 (Generic error (see e-text))
Can you inspect this keytab? `klist -ekt /etc/dirsrv/ds.keytab`?
Thanks, --Robbie
freeipa-users@lists.fedorahosted.org
-
Florence Blanc-Renaud -
Marisa Sandhoff -
Rob Crittenden -
Robbie Harwood -
Torsten Harenberg