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

Michael Pawlak mike at colovore.com
Mon Mar 23 17:09:52 UTC 2015


Martin,

The CA service definitely appears to be up and selinux is disabled on the
host.

----- ipactl status -----

Directory Service: RUNNING
KDC Service: RUNNING
KPASSWD Service: RUNNING
DNS Service: RUNNING
MEMCACHE Service: RUNNING
HTTP Service: RUNNING
CA Service: RUNNING

----- service pki-cad status -----

pki-ca (pid 17719) is running...                           [  OK  ]
    Unsecure Port       = http://ipa.example.com:9180/ca/ee/ca
    Secure Agent Port   = https://ipa.example.com:9443/ca/agent/ca
    Secure EE Port      = https://ipa.example.com:9444/ca/ee/ca
    Secure Admin Port   = https://ipa.example.com:9445/ca/services
    EE Client Auth Port = https://ipa.example.com:9446/ca/eeca/ca
    PKI Console Port    = pkiconsole https://ipa.example.com:9445/ca
    Tomcat Port         = 9701 (for shutdown)

    PKI Instance Name:   pki-ca

    PKI Subsystem Type:  CA Clone (Security Domain)

    Registered PKI Security Domain Information:

==========================================================================
    Name:  IPA
    URL:   https://ipa.example.com:443

==========================================================================

----- cat /etc/selinux/config -----

# This file controls the state of SELinux on the system.
# SELINUX= can take one of these three values:
#    enforcing - SELinux security policy is enforced.
#    permissive - SELinux prints warnings instead of enforcing.
#    disabled - SELinux is fully disabled.
SELINUX=disabled
# SELINUXTYPE= type of policy in use. Possible values are:
#    targeted - Only targeted network daemons are protected.
#    strict - Full SELinux protection.
SELINUXTYPE=targeted



On Mon, Mar 23, 2015 at 4:07 AM, Martin Kosek <mkosek at redhat.com> 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?
>
> 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
> >>
> >>
> >
> >
> >
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://listman.redhat.com/archives/freeipa-users/attachments/20150323/83682164/attachment.htm>


More information about the Freeipa-users mailing list