Rob, Thanks. Any additional eyes would be greatly apprecated.
*Michael Pawlak* Web Systems Administrator | Colovore LLC E: [email protected] C: 408.316.2154 <http://www.colovore.com> On Mon, Mar 23, 2015 at 6:24 AM, Rob Crittenden <[email protected]> wrote: > Martin Kosek wrote: > > This may mean that Dogtag is not up. Can you please check with "ipactl > status" > > that it (pki-ca) is up and running and that there are no related SELinux > AVCs? > > > > The problem seems to be java-related: > > The self test plugin named selftests.container.logger.class contains a > value com.netscape.cms.logging.RollingLogFile which is invalid. > > I've seen cases where selftest failures don't cause the CA to not start > up but does prevent it from actually operating. > > The bottom line of the errors you are seeing is that the CA is not > completely running. I've cc'd a couple of dogtag developers to see if > they can help with the Java exception. > > rob > > > On 03/23/2015 04:52 AM, Michael Pawlak wrote: > >> Does anybody have any thoughts on this? > >> > >> *Michael Pawlak* > >> Web Systems Administrator | Colovore LLC > >> E: [email protected] > >> C: 408.316.2154 > >> <http://www.colovore.com> > >> > >> On Sun, Mar 22, 2015 at 12:05 AM, Michael Pawlak <[email protected]> > wrote: > >> > >>> I am not able to setup a replica using the 'ipa-replica-prepare' > command. > >>> After some debugging this appears related to the certmonger/dogtag > system > >>> that is incorporated with FreeIPA. I am including the output below of > any > >>> relevant logs / commands. > >>> > >>> ----- ipa-replica-prepare ----- > >>> > >>> ipa-replica-prepare newipa.example.com --ca=/etc/ipa/ca.crt --password > >>> 'somepassword' > >>> Preparing replica for newipa.example.com from ipa.example.com > >>> Creating SSL certificate for the Directory Server > >>> Certificate operation cannot be completed: Unable to communicate with > CMS > >>> (Not Found) > >>> > >>> ----- ipa-getcert list ----- > >>> > >>> Number of certificates and requests being tracked: 8. > >>> Request ID '20140811232518': > >>> status: CA_UNREACHABLE > >>> ca-error: Server at https://ipa.example.com/ipa/xml failed > request, > >>> will retry: 4301 (RPC failed at server. Certificate operation cannot > be > >>> completed: Unable to communicate with CMS (Not Found)). > >>> stuck: no > >>> key pair storage: > >>> > type=NSSDB,location='/etc/dirsrv/slapd-PKI-IPA',nickname='Server-Cert',token='NSS > >>> Certificate DB',pinfile='/etc/dirsrv/slapd-PKI-IPA/pwdfile.txt' > >>> certificate: > >>> > type=NSSDB,location='/etc/dirsrv/slapd-PKI-IPA',nickname='Server-Cert',token='NSS > >>> Certificate DB' > >>> CA: IPA > >>> issuer: CN=Certificate Authority,O=EXAMPLE > >>> subject: CN=ipa.example.com,O=EXAMPLE > >>> expires: 2016-08-11 23:24:36 UTC > >>> key usage: > >>> digitalSignature,nonRepudiation,keyEncipherment,dataEncipherment > >>> eku: id-kp-serverAuth,id-kp-clientAuth > >>> pre-save command: > >>> post-save command: > >>> track: yes > >>> auto-renew: yes > >>> Request ID '20140811232742': > >>> status: CA_UNREACHABLE > >>> ca-error: Server at https://ipa.example.com/ipa/xml failed > request, > >>> will retry: 4301 (RPC failed at server. Certificate operation cannot > be > >>> completed: Unable to communicate with CMS (Not Found)). > >>> stuck: no > >>> key pair storage: > >>> > type=NSSDB,location='/etc/dirsrv/slapd-EXAMPLE',nickname='Server-Cert',token='NSS > >>> Certificate DB',pinfile='/etc/dirsrv/slapd-COLOVORE/pwdfile.txt' > >>> certificate: > >>> > type=NSSDB,location='/etc/dirsrv/slapd-EXAMPLE',nickname='Server-Cert',token='NSS > >>> Certificate DB' > >>> CA: IPA > >>> issuer: CN=Certificate Authority,O=EXAMPLE > >>> subject: CN=ipa.example.com,O=EXAMPLE > >>> expires: 2016-08-11 23:24:34 UTC > >>> key usage: > >>> digitalSignature,nonRepudiation,keyEncipherment,dataEncipherment > >>> eku: id-kp-serverAuth,id-kp-clientAuth > >>> pre-save command: > >>> post-save command: > >>> track: yes > >>> auto-renew: yes > >>> Request ID '20140811232843': > >>> status: CA_UNREACHABLE > >>> ca-error: Server at https://ipa.example.com/ipa/xml failed > request, > >>> will retry: 4301 (RPC failed at server. Certificate operation cannot > be > >>> completed: Unable to communicate with CMS (Not Found)). > >>> stuck: no > >>> key pair storage: > >>> > type=NSSDB,location='/etc/httpd/alias',nickname='Server-Cert',token='NSS > >>> Certificate DB',pinfile='/etc/httpd/alias/pwdfile.txt' > >>> certificate: > >>> > type=NSSDB,location='/etc/httpd/alias',nickname='Server-Cert',token='NSS > >>> Certificate DB' > >>> CA: IPA > >>> issuer: CN=Certificate Authority,O=EXAMPLE > >>> subject: CN=ipa.example.com,O=EXAMPLE > >>> expires: 2016-08-11 23:24:37 UTC > >>> key usage: > >>> digitalSignature,nonRepudiation,keyEncipherment,dataEncipherment > >>> eku: id-kp-serverAuth,id-kp-clientAuth > >>> pre-save command: > >>> post-save command: > >>> track: yes > >>> auto-renew: yes > >>> > >>> ----- /etc/pki-ca/password.conf ----- > >>> > >>> internal=829325937546 > >>> internaldb=somepassword > >>> replicationdb=1270571739 > >>> > >>> ----- /var/log/pki-ca/debug ----- > >>> > >>> [22/Mar/2015:06:45:10][main]: CMSEngine: done init id=profile > >>> [22/Mar/2015:06:45:10][main]: CMSEngine: initialized profile > >>> [22/Mar/2015:06:45:10][main]: CMSEngine: initSubsystem id=selftests > >>> [22/Mar/2015:06:45:10][main]: CMSEngine: ready to init id=selftests > >>> [22/Mar/2015:06:45:10][main]: SelfTestSubsystem::init(): ENTERING . . > . > >>> [22/Mar/2015:06:45:10][main]: SelfTestSubsystem::init(): loading > self > >>> test logger parameters > >>> [22/Mar/2015:06:45:10][main]: CMS:Caught EBaseException > >>> The self test plugin named selftests.container.logger.class contains a > >>> value com.netscape.cms.logging.RollingLogFile which is invalid. > >>> at > >>> > com.netscape.cmscore.selftests.SelfTestSubsystem.init(SelfTestSubsystem.java:1422) > >>> at > >>> com.netscape.cmscore.apps.CMSEngine.initSubsystem(CMSEngine.java:866) > >>> at > >>> com.netscape.cmscore.apps.CMSEngine.initSubsystems(CMSEngine.java:795) > >>> at com.netscape.cmscore.apps.CMSEngine.init(CMSEngine.java:316) > >>> at com.netscape.certsrv.apps.CMS.init(CMS.java:153) > >>> at com.netscape.certsrv.apps.CMS.start(CMS.java:1530) > >>> at > >>> > com.netscape.cms.servlet.base.CMSStartServlet.init(CMSStartServlet.java:85) > >>> at > >>> > org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1173) > >>> at > >>> org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:993) > >>> at > >>> > org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:4425) > >>> at > >>> > org.apache.catalina.core.StandardContext.start(StandardContext.java:4738) > >>> at > >>> > org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:791) > >>> at > >>> org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:771) > >>> at > >>> org.apache.catalina.core.StandardHost.addChild(StandardHost.java:526) > >>> at > >>> > org.apache.catalina.startup.HostConfig.deployDirectory(HostConfig.java:1041) > >>> at > >>> > org.apache.catalina.startup.HostConfig.deployDirectories(HostConfig.java:964) > >>> at > >>> org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:502) > >>> at > org.apache.catalina.startup.HostConfig.start(HostConfig.java:1277) > >>> at > >>> > org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:321) > >>> at > >>> > org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:142) > >>> at > >>> org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1053) > >>> at > org.apache.catalina.core.StandardHost.start(StandardHost.java:722) > >>> at > >>> org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1045) > >>> at > >>> org.apache.catalina.core.StandardEngine.start(StandardEngine.java:443) > >>> at > >>> > org.apache.catalina.core.StandardService.start(StandardService.java:516) > >>> at > >>> org.apache.catalina.core.StandardServer.start(StandardServer.java:710) > >>> at org.apache.catalina.startup.Catalina.start(Catalina.java:593) > >>> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > >>> at > >>> > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) > >>> at > >>> > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > >>> at java.lang.reflect.Method.invoke(Method.java:606) > >>> at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:289) > >>> at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:414) > >>> [22/Mar/2015:06:45:10][main]: CMSEngine.shutdown() > >>> [22/Mar/2015:06:45:25][http-9444-1]: according to ccMode, authorization > >>> for servlet: caProfileSubmitSSLClient is LDAP based, not XML {1}, use > >>> default authz mgr: {2}. > >>> [22/Mar/2015:06:45:25][http-9444-1]: according to ccMode, authorization > >>> for servlet: caProfileSubmitSSLClient is LDAP based, not XML {1}, use > >>> default authz mgr: {2}. > >>> [22/Mar/2015:06:50:09][Timer-0]: CMSEngine: getPasswordStore(): > password > >>> store initialized before. > >>> [22/Mar/2015:06:50:09][Timer-0]: CMSEngine: getPasswordStore(): > password > >>> store initialized. > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: About to start > >>> updateCertStatus > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: Starting > updateCertStatus > >>> (entered lock) > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: In updateCertStatus() > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: In > >>> LdapBoundConnFactory::getConn() > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: masterConn is > connected: > >>> true > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: getConn: conn is > connected > >>> true > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: getConn: mNumConns now > 2 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: > >>> getInvalidCertificatesByNotBeforeDate filter (certStatus=INVALID) > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: > >>> getInvalidCertificatesByNotBeforeDate: about to call > findCertRecordsInList > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: In > >>> LdapBoundConnFactory::getConn() > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: masterConn is > connected: > >>> true > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: getConn: conn is > connected > >>> true > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: getConn: mNumConns now > 1 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: In > >>> findCertRecordsInListRawJumpto with Jumpto 20150322065510Z > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: In DBVirtualList filter > >>> attrs startFrom sortKey pageSize filter: (certStatus=INVALID) attrs: > >>> [objectclass, certRecordId, x509cert] pageSize -200 startFrom > >>> 20150322065510Z > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: returnConn: mNumConns > now 2 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: In > >>> getInvalidCertsByNotBeforeDate finally. > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: returnConn: mNumConns > now 3 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: getEntries returning 0 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: mTop 0 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: Getting Virtual List > size: > >>> 0 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: index may be empty > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: In > >>> LdapBoundConnFactory::getConn() > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: masterConn is > connected: > >>> true > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: getConn: conn is > connected > >>> true > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: getConn: mNumConns now > 2 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: > >>> getValidCertsByNotAfterDate filter (certStatus=VALID) > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: In > >>> LdapBoundConnFactory::getConn() > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: masterConn is > connected: > >>> true > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: getConn: conn is > connected > >>> true > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: getConn: mNumConns now > 1 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: In > >>> findCertRecordsInListRawJumpto with Jumpto 20150322065510Z > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: In DBVirtualList filter > >>> attrs startFrom sortKey pageSize filter: (certStatus=VALID) attrs: > >>> [objectclass, certRecordId, x509cert] pageSize -200 startFrom > >>> 20150322065510Z > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: returnConn: mNumConns > now 2 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: returnConn: mNumConns > now 3 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: getEntries returning 1 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: mTop 0 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: Getting Virtual List > size: > >>> 69 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: > transidValidCertificates: > >>> list size: 69 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: > transitValidCertificates: > >>> ltSize 1 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: getElementAt: 0 mTop 0 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: reverse direction > getting > >>> index 0 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: Record does not > >>> qualify,notAfter Sat Jul 09 05:12:31 UTC 2016 date Sun Mar 22 06:55:10 > UTC > >>> 2015 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: transitCertList EXPIRED > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: In > >>> LdapBoundConnFactory::getConn() > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: masterConn is > connected: > >>> true > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: getConn: conn is > connected > >>> true > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: getConn: mNumConns now > 2 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: > >>> getRevokedCertificatesByNotAfterDate filter (certStatus=REVOKED) > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: > >>> getRevokedCertificatesByNotAfterDate: about to call > findCertRecordsInList > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: In > >>> LdapBoundConnFactory::getConn() > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: masterConn is > connected: > >>> true > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: getConn: conn is > connected > >>> true > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: getConn: mNumConns now > 1 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: In > >>> findCertRecordsInListRawJumpto with Jumpto 20150322065510Z > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: In DBVirtualList filter > >>> attrs startFrom sortKey pageSize filter: (certStatus=REVOKED) attrs: > >>> [objectclass, certRevokedOn, certRecordId, certRevoInfo, notAfter, > >>> x509cert] pageSize -200 startFrom 20150322065510Z > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: returnConn: mNumConns > now 2 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: returnConn: mNumConns > now 3 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: getEntries returning 1 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: mTop 0 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: Getting Virtual List > size: > >>> 5 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: > >>> transitRevokedExpiredCertificates: list size: 5 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: > >>> transitRevokedExpiredCertificates: ltSize 1 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: getElementAt: 0 mTop 0 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: reverse direction > getting > >>> index 0 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: transitRevokedExpired: > >>> curRec: 0 CertRecord: 268369925 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: Record does not > >>> qualify,notAfter Wed Jul 20 06:25:57 UTC 2016 date Sun Mar 22 06:55:10 > UTC > >>> 2015 > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: transitCertList > >>> REVOKED_EXPIRED > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: updateCertStatus done > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: Starting cert > checkRanges > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: Server not completely > >>> started. Returning .. > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: cert checkRanges done > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: Starting request > >>> checkRanges > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: Server not completely > >>> started. Returning .. > >>> [22/Mar/2015:06:55:10][CertStatusUpdateThread]: request checkRanges > done > >>> > >>> > >> > >> > >> > > > >
-- 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
