[Freeipa-users] Having Issues with Dogtag After Updating IPA and Rebooting

Martin Kosek mkosek at redhat.com
Mon Mar 23 11:07:19 UTC 2015


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?

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: mike at colovore.com
> C: 408.316.2154
>   <http://www.colovore.com>
> 
> On Sun, Mar 22, 2015 at 12:05 AM, Michael Pawlak <mike at colovore.com> 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
>>
>>
> 
> 
> 




More information about the Freeipa-users mailing list