Hi, I’m wondering if anyone might be able to help me figure out why my KRA is failing after a fairly recent installation. It's throwing exceptions about LDAP authentication that look like the following (note, I’ve truncated some of the stacks for brevity:
Apr 12 21:14:22 server[7515]: Could not connect to LDAP server host ipa-1.mydomain.com port 636 Error netscape.ldap.LDAPException: error result (49) Apr 12 21:14:22 server[7515]: at com.netscape.cmscore.ldapconn.LdapBoundConnFactory.makeConnection(LdapBoundConnFactory.java:205) Apr 12 21:14:22 server[7515]: at com.netscape.cmscore.ldapconn.LdapBoundConnFactory.getConn(LdapBoundConnFactory.java:332) Apr 12 21:14:22 server[7515]: at com.netscape.cmscore.ldapconn.LdapBoundConnFactory.getConn(LdapBoundConnFactory.java:295) Apr 12 21:14:22 server[7515]: at com.netscape.cmscore.dbs.DBSubsystem.hasRangeConflict(DBSubsystem.java:475) Apr 12 21:14:22 server[7515]: at com.netscape.cmscore.dbs.Repository.checkRanges(Repository.java:500) Apr 12 21:14:22 server[7515]: at com.netscape.cmscore.dbs.KeyRepository.updateKeyStatus(KeyRepository.java:189) Apr 12 21:14:22 server[7515]: at com.netscape.cmscore.dbs.KeyStatusUpdateTask.run(KeyRepository.java:604) Apr 12 21:14:22 server[7515]: at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ... Apr 12 21:14:22 server[7515]: Could not connect to LDAP server host ipa-1.mydomain.com port 636 Error netscape.ldap.LDAPException: error result (49) Apr 12 21:14:22 server[7515]: at com.netscape.cmscore.ldapconn.LdapBoundConnFactory.makeConnection(LdapBoundConnFactory.java:205) Apr 12 21:14:22 server[7515]: at com.netscape.cmscore.ldapconn.LdapBoundConnFactory.getConn(LdapBoundConnFactory.java:332) Apr 12 21:14:22 server[7515]: at com.netscape.cmscore.ldapconn.LdapBoundConnFactory.getConn(LdapBoundConnFactory.java:295) Apr 12 21:14:22 server[7515]: at com.netscape.cmscore.dbs.DBSubsystem.hasRangeConflict(DBSubsystem.java:475) Apr 12 21:14:22 server[7515]: at com.netscape.cmscore.dbs.Repository.checkRanges(Repository.java:500) Apr 12 21:14:22 server[7515]: at com.netscape.cmscore.dbs.KeyRepository.updateKeyStatus(KeyRepository.java:193) Apr 12 21:14:22 server[7515]: at com.netscape.cmscore.dbs.KeyStatusUpdateTask.run(KeyRepository.java:604) ... When I restart IPA, I get the following: Apr 12 21:18:34 server[32159]: CA is started. Apr 12 21:18:34 server[32159]: SSLAuthenticatorWithFallback: Creating SSL authenticator with fallback Apr 12 21:18:34 server[32159]: SSLAuthenticatorWithFallback: Setting container Apr 12 21:18:35 server[32159]: SSLAuthenticatorWithFallback: Initializing authenticators Apr 12 21:18:35 server[32159]: SSLAuthenticatorWithFallback: Starting authenticators Apr 12 21:18:35 server[32159]: CMSEngine.initializePasswordStore() begins Apr 12 21:18:35 server[32159]: CMSEngine.initializePasswordStore(): tag=internaldb Apr 12 21:18:35 server[32159]: testLDAPConnection connecting to ipa-1.mydomain.com:636 Apr 12 21:18:35 server[32159]: testLDAPConnection: Invalid Password Apr 12 21:18:36 server[32159]: testLDAPConnection connecting to ipa-1.mydomain.com:636 Apr 12 21:18:36 server[32159]: testLDAPConnection: Invalid Password Apr 12 21:18:36 server[32159]: testLDAPConnection connecting to ipa-1.mydomain.com:636 Apr 12 21:18:36 server[32159]: testLDAPConnection: Invalid Password Apr 12 21:18:36 server[32159]: CMSEngine: init(): password test execution failed: 2 Apr 12 21:18:36 server[32159]: Password test execution failed. Is the database up? Apr 12 21:18:36 server[32159]: Password test execution failed. Is the database up? Apr 12 21:18:36 server[32159]: at com.netscape.cmscore.apps.CMSEngine.initializePasswordStore(CMSEngine.java:469) Apr 12 21:18:36 server[32159]: at com.netscape.cmscore.apps.CMSEngine.init(CMSEngine.java:537) Apr 12 21:18:36 server[32159]: at com.netscape.certsrv.apps.CMS.init(CMS.java:188) Apr 12 21:18:36 server[32159]: at com.netscape.certsrv.apps.CMS.start(CMS.java:1621) Apr 12 21:18:36 server[32159]: at com.netscape.cms.servlet.base.CMSStartServlet.init(CMSStartServlet.java:114) Apr 12 21:18:36 server[32159]: at javax.servlet.GenericServlet.init(GenericServlet.java:158) ... If I then try to add or delete a vault, I get the following: Apr 12 22:19:08 server[32159]: SSLAuthenticatorWithFallback: Authenticate with client certificate authentication Apr 12 22:19:08 server[32159]: java.lang.NullPointerException Apr 12 22:19:08 server[32159]: at com.netscape.cms.realm.PKIRealm.authenticate(PKIRealm.java:114) Apr 12 22:19:08 server[32159]: at com.netscape.cms.tomcat.ProxyRealm.authenticate(ProxyRealm.java:86) Apr 12 22:19:08 server[32159]: at org.apache.catalina.authenticator.SSLAuthenticator.authenticate(SSLAuthenticator.java:81) Apr 12 22:19:08 server[32159]: at com.netscape.cms.tomcat.SSLAuthenticatorWithFallback.doSubAuthenticate(SSLAuthenticatorWithFallback.java:37) Apr 12 22:19:08 server[32159]: at com.netscape.cms.tomcat.AbstractPKIAuthenticator.doAuthenticate(AbstractPKIAuthenticator.java:86) Apr 12 22:19:08 server[32159]: at com.netscape.cms.tomcat.SSLAuthenticatorWithFallback.authenticate(SSLAuthenticatorWithFallback.java:47) ... Apr 12 22:19:08 server[32159]: SSLAuthenticatorWithFallback: Result: false I’ve got the following in /var/log/pki/pki-tomcat/kra/debug: [12/Apr/2017:21:14:22][KeyStatusUpdateTask]: Starting request checkRanges [12/Apr/2017:21:14:22][KeyStatusUpdateTask]: Serial numbers left in range: 10000 [12/Apr/2017:21:14:22][KeyStatusUpdateTask]: Last Serial Number: 9990000 [12/Apr/2017:21:14:22][KeyStatusUpdateTask]: Serial Numbers in next range: 10000000 [12/Apr/2017:21:14:22][KeyStatusUpdateTask]: Serial Numbers available: 10010000 [12/Apr/2017:21:14:22][KeyStatusUpdateTask]: Checking for a range conflict [12/Apr/2017:21:14:22][KeyStatusUpdateTask]: In LdapBoundConnFactory::getConn() [12/Apr/2017:21:14:22][KeyStatusUpdateTask]: masterConn is null. [12/Apr/2017:21:14:22][KeyStatusUpdateTask]: makeConnection: errorIfDown true [12/Apr/2017:21:14:22][KeyStatusUpdateTask]: TCP Keep-Alive: true [12/Apr/2017:21:14:22][KeyStatusUpdateTask]: SSL handshake happened [12/Apr/2017:21:14:22][KeyStatusUpdateTask]: Can't create master connection in LdapBoundConnFactory::getConn! Could not connect to LDAP server host ipa-1.mydomain.com port 636 Error netscape.ldap.LDAPException: error result (49) [12/Apr/2017:21:14:22][KeyStatusUpdateTask]: DBSubsystem: hasRangeConflict. Error while checking next range.Could not connect to LDAP server host ipa-1.mydomain.com port 636 Error netscape.ldap.LDAPException: error result (49) [12/Apr/2017:21:14:22][KeyStatusUpdateTask]: request checkRanges done This is IPA 4.4.4-1.fc25, installed fairly recently. I’m not sure if this is relevant, but this was installed as a new master on new infrastructure based on an old Fedora 23, IPA 4.3 master that never had a KRA. I initially replicated to a new Fedora 23 host and upgraded that host to Fedora 25 (it may have still been connected to the 4.3 master during and after the upgrade). ipa-kra-install was then run on that Fedora 25 host which was again replicated to what is now presenting this problem. I believe the KRA started up fine at that point but I didn’t thoroughly test it. I then disconnected the old Fedora 25 host and shut down the old infrastructure. I’m now running on a single master IPA node with this broken KRA problem. Note that everything else about this installation seems to work. I wouldn’t have even really noticed if not for trying to replicate again and failing due to KRA issues. Thanks! — Ilya Kogan
signature.asc
Description: Message signed with OpenPGP
-- Manage your subscription for the Freeipa-users mailing list: https://www.redhat.com/mailman/listinfo/freeipa-users Go to http://freeipa.org for more info on the project