The httpd_error log doesn't contain the part where `ipa cert-show 1` was run. If it is from the same time.
*I am not sure about that, please see httpd_error when `ipa cert-show 1` was run* [root@caer ~]# *tail -f /var/log/httpd/error_log* [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: WSGI wsgi_dispatch.__call__: [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: WSGI xmlserver_session.__call__: [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: found session cookie_id = bc2c7ed0eccd840dc266efaf9ece913c [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: found session data in cache with id=bc2c7ed0eccd840dc266efaf9ece913c [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: xmlserver_session.__call__: session_id=bc2c7ed0eccd840dc266efaf9ece913c start_timestamp=2016-07-21T11:58:54 access_timestamp=2016-07-21T12:01:21 expiration_timestamp=2016-07-21T12:18:54 [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: storing ccache data into file "/var/run/ipa_memcached/krbcc_13554" [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: get_credential_times: principal=HTTP/caer.teloip....@teloip.net, authtime=07/21/16 10:31:46, starttime=07/21/16 10:43:26, endtime=07/22/16 10:31:44, renew_till=12/31/69 19:00:00 [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: get_credential_times: principal=HTTP/caer.teloip....@teloip.net, authtime=07/21/16 10:31:46, starttime=07/21/16 10:43:26, endtime=07/22/16 10:31:44, renew_till=12/31/69 19:00:00 [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: KRB5_CCache FILE:/var/run/ipa_memcached/krbcc_13554 endtime=1469197904 (07/22/16 10:31:44) [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: set_session_expiration_time: duration_type=inactivity_timeout duration=1200 max_age=1469197604 expiration=1469118081.77 (2016-07-21T12:21:21) [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: WSGI xmlserver.__call__: [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: Created connection context.ldap2 [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: WSGI WSGIExecutioner.__call__: [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: raw: cert_show(u'1') [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: cert_show(u'1') [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: IPA: virtual verify retrieve certificate [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: ipaserver.plugins.dogtag.ra.get_certificate() [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: https_request ' https://caer.teloip.net:443/ca/agent/ca/displayBySerial' [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: https_request post 'xml=true&serialNumber=1' [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: NSSConnection init caer.teloip.net [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: Connecting: 10.20.0.75:0 [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: auth_certificate_callback: check_sig=True is_server=False *.* *.* *.* [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: approved_usage = SSLServer intended_usage = SSLServer [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: cert valid True for "CN= caer.teloip.net,O=TELOIP.NET" [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: handshake complete, peer = 10.20.0.75:443 [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: auth_certificate_callback: check_sig=True is_server=False *.* *.* *.* [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: approved_usage = SSLServer intended_usage = SSLServer [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: cert valid True for "CN= caer.teloip.net,O=TELOIP.NET" [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: handshake complete, peer = 10.20.0.75:443 [Thu Jul 21 12:01:21 2016] [error] ipa: ERROR: ipaserver.plugins.dogtag.ra.get_certificate(): Unable to communicate with CMS (Not Found) [Thu Jul 21 12:01:21 2016] [error] ipa: INFO: ad...@teloip.net: cert_show(u'1'): CertificateOperationError [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: response: CertificateOperationError: Certificate operation cannot be completed: Unable to communicate with CMS (Not Found) [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: Destroyed connection context.ldap2 [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: reading ccache data from file "/var/run/ipa_memcached/krbcc_13554" [Thu Jul 21 12:01:21 2016] [error] ipa: DEBUG: store session: session_id=bc2c7ed0eccd840dc266efaf9ece913c start_timestamp=2016-07-21T11:58:54 access_timestamp=2016-07-21T12:01:21 expiration_timestamp=2016-07-21T12:21:21 Does `ipa cert-show` communicate with the same replica? Could be verified by `ipa -vv cert-show` *It's asking for the serial number of the certificate. If I give 64 (serial number of ipaCert ), I get ipa: ERROR: Certificate operation cannot be completed: Unable to communicate with CMS (Not Found)* *[root@caer ~]# ipa -vv cert-show* ipa: DEBUG: importing all plugin modules in '/usr/lib/python2.6/site-packages/ipalib/plugins'... *.* *.* *.* ipa: DEBUG: stdout=ipa_session=bc2c7ed0eccd840dc266efaf9ece913c; Domain= caer.teloip.net; Path=/ipa; Expires=Thu, 21 Jul 2016 16:25:32 GMT; Secure; HttpOnly ipa: DEBUG: stderr= ipa: DEBUG: found session_cookie in persistent storage for principal ' ad...@teloip.net', cookie: 'ipa_session=bc2c7ed0eccd840dc266efaf9ece913c; Domain=caer.teloip.net; Path=/ipa; Expires=Thu, 21 Jul 2016 16:25:32 GMT; Secure; HttpOnly' ipa: DEBUG: setting session_cookie into context 'ipa_session=bc2c7ed0eccd840dc266efaf9ece913c;' ipa: INFO: trying https://caer.teloip.net/ipa/session/xml ipa: DEBUG: Created connection context.xmlclient Serial number: 64 ipa: DEBUG: raw: cert_show(u'64') ipa: DEBUG: cert_show(u'64') ipa: INFO: Forwarding 'cert_show' to server u' https://caer.teloip.net/ipa/session/xml' ipa: DEBUG: NSSConnection init caer.teloip.net ipa: DEBUG: Connecting: 10.20.0.75:0 send: u'POST /ipa/session/xml HTTP/1.0\r\nHost: caer.teloip.net\r\nAccept-Language: en-us\r\nReferer: https://caer.teloip.net/ipa/xml\r\nCookie: ipa_session=bc2c7ed0eccd840dc266efaf9ece913c;\r\nUser-Agent: xmlrpclib.py/1.0.1 (by www.pythonware.com)\r\nContent-Type: text/xml\r\nContent-Length: 268\r\n\r\n' ipa: DEBUG: auth_certificate_callback: check_sig=True is_server=False *.* *.* *.* ipa: DEBUG: approved_usage = SSLServer intended_usage = SSLServer ipa: DEBUG: cert valid True for "CN=caer.teloip.net,O=TELOIP.NET" ipa: DEBUG: handshake complete, peer = 10.20.0.75:443 send: "<?xml version='1.0' encoding='UTF-8'?>\n<methodCall>\n<methodName>cert_show</methodName>\n<params>\n<param>\n<value><array><data>\n<value><string>64</string></value>\n</data></array></value>\n</param>\n<param>\n<value><struct>\n</struct></value>\n</param>\n</params>\n</methodCall>\n" reply: 'HTTP/1.1 200 Success\r\n' header: Date: Thu, 21 Jul 2016 16:05:40 GMT header: Server: Apache/2.2.15 (CentOS) header: Set-Cookie: ipa_session=bc2c7ed0eccd840dc266efaf9ece913c; Domain= caer.teloip.net; Path=/ipa; Expires=Thu, 21 Jul 2016 16:25:40 GMT; Secure; HttpOnly header: Connection: close header: Content-Type: text/xml; charset=utf-8 ipa: DEBUG: received Set-Cookie 'ipa_session=bc2c7ed0eccd840dc266efaf9ece913c; Domain=caer.teloip.net; Path=/ipa; Expires=Thu, 21 Jul 2016 16:25:40 GMT; Secure; HttpOnly' ipa: DEBUG: storing cookie 'ipa_session=bc2c7ed0eccd840dc266efaf9ece913c; Domain=caer.teloip.net; Path=/ipa; Expires=Thu, 21 Jul 2016 16:25:40 GMT; Secure; HttpOnly' for principal ad...@teloip.net ipa: DEBUG: args=keyctl search @s user ipa_session_cookie:ad...@teloip.net ipa: DEBUG: stdout=457971704 ipa: DEBUG: stderr= ipa: DEBUG: args=keyctl search @s user ipa_session_cookie:ad...@teloip.net ipa: DEBUG: stdout=457971704 ipa: DEBUG: stderr= ipa: DEBUG: args=keyctl pupdate 457971704 ipa: DEBUG: stdout= ipa: DEBUG: stderr= body: "<?xml version='1.0' encoding='UTF-8'?>\n<methodResponse>\n<fault>\n<value><struct>\n<member>\n<name>faultCode</name>\n<value><int>4301</int></value>\n</member>\n<member>\n<name>faultString</name>\n<value><string>Certificate operation cannot be completed: Unable to communicate with CMS (Not Found)</string></value>\n</member>\n</struct></value>\n</fault>\n</methodResponse>\n" ipa: DEBUG: Caught fault 4301 from server https://caer.teloip.net/ipa/session/xml: Certificate operation cannot be completed: Unable to communicate with CMS (Not Found) ipa: DEBUG: Destroyed connection context.xmlclient ipa: ERROR: Certificate operation cannot be completed: Unable to communicate with CMS (Not Found) [root@caer ~]# But more interesting is: SelfTestSubsystem: The CRITICAL self test plugin called selftests.container.instance.SystemCertsVerification running at startup FAILED! Are you sure that CA is running? # ipactl status *Yes, CA is runnig, * *[root@caer ~]# ipactl status* Directory Service: RUNNING KDC Service: RUNNING KPASSWD Service: RUNNING DNS Service: RUNNING MEMCACHE Service: RUNNING HTTP Service: RUNNING CA Service: RUNNING This looks like that self test fail and therefore CA shouldn't start. It also says that some of CA cert is not valid. Which one might be seen in /var/log/pki-ca/debug but a bigger chunk would be needed. *[root@caer ~]# tail -100 /var/log/pki-ca/debug * [21/Jul/2016:11:48:29][CertStatusUpdateThread]: getConn: conn is connected true [21/Jul/2016:11:48:29][CertStatusUpdateThread]: getConn: mNumConns now 1 [21/Jul/2016:11:48:29][CertStatusUpdateThread]: In findCertRecordsInListRawJumpto with Jumpto 20160721114829Z [21/Jul/2016:11:48:29][CertStatusUpdateThread]: In DBVirtualList filter attrs startFrom sortKey pageSize filter: (certStatus=REVOKED) attrs: [objectclass, certRevokedOn, certRecordId, certRevoInfo, notAfter, x509cert] pageSize -200 startFrom 20160721114829Z [21/Jul/2016:11:48:29][CertStatusUpdateThread]: returnConn: mNumConns now 2 [21/Jul/2016:11:48:29][CertStatusUpdateThread]: returnConn: mNumConns now 3 [21/Jul/2016:11:48:29][CertStatusUpdateThread]: getEntries returning 0 [21/Jul/2016:11:48:29][CertStatusUpdateThread]: mTop 0 [21/Jul/2016:11:48:29][CertStatusUpdateThread]: Getting Virtual List size: 0 [21/Jul/2016:11:48:29][CertStatusUpdateThread]: index may be empty [21/Jul/2016:11:48:29][CertStatusUpdateThread]: updateCertStatus done [21/Jul/2016:11:48:29][CertStatusUpdateThread]: Starting cert checkRanges [21/Jul/2016:11:48:29][CertStatusUpdateThread]: Serial numbers left in range: 268369849 [21/Jul/2016:11:48:29][CertStatusUpdateThread]: Last Serial Number: 71 [21/Jul/2016:11:48:29][CertStatusUpdateThread]: Serial Numbers available: 268369849 [21/Jul/2016:11:48:29][CertStatusUpdateThread]: cert checkRanges done [21/Jul/2016:11:48:29][CertStatusUpdateThread]: Starting request checkRanges [21/Jul/2016:11:48:29][CertStatusUpdateThread]: Serial numbers left in range: 9989888 [21/Jul/2016:11:48:29][CertStatusUpdateThread]: Last Serial Number: 112 [21/Jul/2016:11:48:29][CertStatusUpdateThread]: Serial Numbers available: 9989888 [21/Jul/2016:11:48:29][CertStatusUpdateThread]: request checkRanges done [21/Jul/2016:11:53:28][Timer-0]: CMSEngine: getPasswordStore(): password store initialized before. [21/Jul/2016:11:53:28][Timer-0]: CMSEngine: getPasswordStore(): password store initialized. [21/Jul/2016:11:58:28][Timer-0]: CMSEngine: getPasswordStore(): password store initialized before. [21/Jul/2016:11:58:28][Timer-0]: CMSEngine: getPasswordStore(): password store initialized. [21/Jul/2016:11:58:29][CertStatusUpdateThread]: About to start updateCertStatus [21/Jul/2016:11:58:29][CertStatusUpdateThread]: Starting updateCertStatus (entered lock) [21/Jul/2016:11:58:29][CertStatusUpdateThread]: In updateCertStatus() [21/Jul/2016:11:58:29][CertStatusUpdateThread]: In LdapBoundConnFactory::getConn() [21/Jul/2016:11:58:29][CertStatusUpdateThread]: masterConn is connected: true [21/Jul/2016:11:58:29][CertStatusUpdateThread]: getConn: conn is connected true [21/Jul/2016:11:58:29][CertStatusUpdateThread]: getConn: mNumConns now 2 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: getInvalidCertificatesByNotBeforeDate filter (certStatus=INVALID) [21/Jul/2016:11:58:29][CertStatusUpdateThread]: getInvalidCertificatesByNotBeforeDate: about to call findCertRecordsInList [21/Jul/2016:11:58:29][CertStatusUpdateThread]: In LdapBoundConnFactory::getConn() [21/Jul/2016:11:58:29][CertStatusUpdateThread]: masterConn is connected: true [21/Jul/2016:11:58:29][CertStatusUpdateThread]: getConn: conn is connected true [21/Jul/2016:11:58:29][CertStatusUpdateThread]: getConn: mNumConns now 1 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: In findCertRecordsInListRawJumpto with Jumpto 20160721115829Z [21/Jul/2016:11:58:29][CertStatusUpdateThread]: In DBVirtualList filter attrs startFrom sortKey pageSize filter: (certStatus=INVALID) attrs: [objectclass, certRecordId, x509cert] pageSize -200 startFrom 20160721115829Z [21/Jul/2016:11:58:29][CertStatusUpdateThread]: returnConn: mNumConns now 2 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: In getInvalidCertsByNotBeforeDate finally. [21/Jul/2016:11:58:29][CertStatusUpdateThread]: returnConn: mNumConns now 3 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: getEntries returning 0 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: mTop 0 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: Getting Virtual List size: 0 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: index may be empty [21/Jul/2016:11:58:29][CertStatusUpdateThread]: In LdapBoundConnFactory::getConn() [21/Jul/2016:11:58:29][CertStatusUpdateThread]: masterConn is connected: true [21/Jul/2016:11:58:29][CertStatusUpdateThread]: getConn: conn is connected true [21/Jul/2016:11:58:29][CertStatusUpdateThread]: getConn: mNumConns now 2 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: getValidCertsByNotAfterDate filter (certStatus=VALID) [21/Jul/2016:11:58:29][CertStatusUpdateThread]: In LdapBoundConnFactory::getConn() [21/Jul/2016:11:58:29][CertStatusUpdateThread]: masterConn is connected: true [21/Jul/2016:11:58:29][CertStatusUpdateThread]: getConn: conn is connected true [21/Jul/2016:11:58:29][CertStatusUpdateThread]: getConn: mNumConns now 1 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: In findCertRecordsInListRawJumpto with Jumpto 20160721115829Z [21/Jul/2016:11:58:29][CertStatusUpdateThread]: In DBVirtualList filter attrs startFrom sortKey pageSize filter: (certStatus=VALID) attrs: [objectclass, certRecordId, x509cert] pageSize -200 startFrom 20160721115829Z [21/Jul/2016:11:58:29][CertStatusUpdateThread]: returnConn: mNumConns now 2 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: returnConn: mNumConns now 3 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: getEntries returning 1 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: mTop 0 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: Getting Virtual List size: 14 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: transidValidCertificates: list size: 14 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: transitValidCertificates: ltSize 1 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: getElementAt: 0 mTop 0 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: reverse direction getting index 0 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: Record does not qualify,notAfter Thu Jan 12 09:11:48 EST 2017 date Thu Jul 21 11:58:29 EDT 2016 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: transitCertList EXPIRED [21/Jul/2016:11:58:29][CertStatusUpdateThread]: In LdapBoundConnFactory::getConn() [21/Jul/2016:11:58:29][CertStatusUpdateThread]: masterConn is connected: true [21/Jul/2016:11:58:29][CertStatusUpdateThread]: getConn: conn is connected true [21/Jul/2016:11:58:29][CertStatusUpdateThread]: getConn: mNumConns now 2 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: getRevokedCertificatesByNotAfterDate filter (certStatus=REVOKED) [21/Jul/2016:11:58:29][CertStatusUpdateThread]: getRevokedCertificatesByNotAfterDate: about to call findCertRecordsInList [21/Jul/2016:11:58:29][CertStatusUpdateThread]: In LdapBoundConnFactory::getConn() [21/Jul/2016:11:58:29][CertStatusUpdateThread]: masterConn is connected: true [21/Jul/2016:11:58:29][CertStatusUpdateThread]: getConn: conn is connected true [21/Jul/2016:11:58:29][CertStatusUpdateThread]: getConn: mNumConns now 1 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: In findCertRecordsInListRawJumpto with Jumpto 20160721115829Z [21/Jul/2016:11:58:29][CertStatusUpdateThread]: In DBVirtualList filter attrs startFrom sortKey pageSize filter: (certStatus=REVOKED) attrs: [objectclass, certRevokedOn, certRecordId, certRevoInfo, notAfter, x509cert] pageSize -200 startFrom 20160721115829Z [21/Jul/2016:11:58:29][CertStatusUpdateThread]: returnConn: mNumConns now 2 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: returnConn: mNumConns now 3 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: getEntries returning 0 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: mTop 0 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: Getting Virtual List size: 0 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: index may be empty [21/Jul/2016:11:58:29][CertStatusUpdateThread]: updateCertStatus done [21/Jul/2016:11:58:29][CertStatusUpdateThread]: Starting cert checkRanges [21/Jul/2016:11:58:29][CertStatusUpdateThread]: Serial numbers left in range: 268369849 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: Last Serial Number: 71 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: Serial Numbers available: 268369849 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: cert checkRanges done [21/Jul/2016:11:58:29][CertStatusUpdateThread]: Starting request checkRanges [21/Jul/2016:11:58:29][CertStatusUpdateThread]: Serial numbers left in range: 9989888 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: Last Serial Number: 112 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: Serial Numbers available: 9989888 [21/Jul/2016:11:58:29][CertStatusUpdateThread]: request checkRanges done [21/Jul/2016:12:03:28][Timer-0]: CMSEngine: getPasswordStore(): password store initialized before. [21/Jul/2016:12:03:28][Timer-0]: CMSEngine: getPasswordStore(): password store initialized. On Thu, Jul 21, 2016 at 11:46 AM, Petr Vobornik <pvobo...@redhat.com> wrote: > On 07/21/2016 05:14 PM, Linov Suresh wrote: > > I set debug=true in /etc/ipa/default.conf > > > > Here are my logs, > > The httpd_error log doesn't contain the part where `ipa cert-show 1` was > run. If it is from the same time. Does `ipa cert-show` communicate with > the same replica? Could be verified by `ipa -vv cert-show` > > But more interesting is: > > SelfTestSubsystem: The CRITICAL self test plugin called > selftests.container.instance.SystemCertsVerification running at startup > FAILED! > > Are you sure that CA is running? > # ipactl status > > This looks like that self test fail and therefore CA shouldn't start. It > also says that some of CA cert is not valid. Which one might be seen in > /var/log/pki-ca/debug but a bigger chunk would be needed. > > > > > *[root@caer ~]# tail -f /var/log/httpd/error_log* > > [Thu Jul 21 11:00:38 2016] [error] ipa: DEBUG: WSGI > WSGIExecutioner.__call__: > > [Thu Jul 21 11:00:38 2016] [error] ipa: DEBUG: raw: user_show(u'admin', > > rights=False, all=False, raw=False, version=u'2.46') > > [Thu Jul 21 11:00:38 2016] [error] ipa: DEBUG: user_show(u'admin', > rights=False, > > all=False, raw=False, version=u'2.46') > > [Thu Jul 21 11:00:38 2016] [error] ipa: DEBUG: get_memberof: > > entry_dn=uid=admin,cn=users,cn=accounts,dc=teloip,dc=net > > > memberof=[ipapython.dn.DN('cn=admins,cn=groups,cn=accounts,dc=teloip,dc=net'), > > ipapython.dn.DN('cn=replication > > administrators,cn=privileges,cn=pbac,dc=teloip,dc=net'), > ipapython.dn.DN('cn=add > > replication agreements,cn=permissions,cn=pbac,dc=teloip,dc=net'), > > ipapython.dn.DN('cn=modify replication > > agreements,cn=permissions,cn=pbac,dc=teloip,dc=net'), > ipapython.dn.DN('cn=remove > > replication agreements,cn=permissions,cn=pbac,dc=teloip,dc=net'), > > ipapython.dn.DN('cn=unlock user > > accounts,cn=permissions,cn=pbac,dc=teloip,dc=net'), > ipapython.dn.DN('cn=manage > > service keytab,cn=permissions,cn=pbac,dc=teloip,dc=net'), > > ipapython.dn.DN('cn=trust > admins,cn=groups,cn=accounts,dc=teloip,dc=net'), > > ipapython.dn.DN('cn=host > enrollment,cn=privileges,cn=pbac,dc=teloip,dc=net'), > > ipapython.dn.DN('cn=manage host > > keytab,cn=permissions,cn=pbac,dc=teloip,dc=net'), > ipapython.dn.DN('cn=enroll a > > host,cn=permissions,cn=pbac,dc=teloip,dc=net'), ipapython.dn.DN('cn=add > host > > password,cn=permissions,cn=pbac,dc=teloip,dc=net'), > ipapython.dn.DN('cn=add > > krbprincipalname to a host,cn=permissions,cn=pbac,dc=teloip,dc=net')] > > [Thu Jul 21 11:00:38 2016] [error] ipa: DEBUG: get_memberof: result > > > direct=[ipapython.dn.DN('cn=admins,cn=groups,cn=accounts,dc=teloip,dc=net'), > > ipapython.dn.DN('cn=trust > admins,cn=groups,cn=accounts,dc=teloip,dc=net')] > > indirect=[ipapython.dn.DN('cn=replication > > administrators,cn=privileges,cn=pbac,dc=teloip,dc=net'), > ipapython.dn.DN('cn=add > > replication agreements,cn=permissions,cn=pbac,dc=teloip,dc=net'), > > ipapython.dn.DN('cn=modify replication > > agreements,cn=permissions,cn=pbac,dc=teloip,dc=net'), > ipapython.dn.DN('cn=remove > > replication agreements,cn=permissions,cn=pbac,dc=teloip,dc=net'), > > ipapython.dn.DN('cn=unlock user > > accounts,cn=permissions,cn=pbac,dc=teloip,dc=net'), > ipapython.dn.DN('cn=manage > > service keytab,cn=permissions,cn=pbac,dc=teloip,dc=net'), > > ipapython.dn.DN('cn=host > enrollment,cn=privileges,cn=pbac,dc=teloip,dc=net'), > > ipapython.dn.DN('cn=manage host > > keytab,cn=permissions,cn=pbac,dc=teloip,dc=net'), > ipapython.dn.DN('cn=enroll a > > host,cn=permissions,cn=pbac,dc=teloip,dc=net'), ipapython.dn.DN('cn=add > host > > password,cn=permissions,cn=pbac,dc=teloip,dc=net'), > ipapython.dn.DN('cn=add > > krbprincipalname to a host,cn=permissions,cn=pbac,dc=teloip,dc=net')] > > [Thu Jul 21 11:00:38 2016] [error] ipa: INFO: ad...@teloip.net > > <mailto:ad...@teloip.net>: user_show(u'admin', rights=False, all=False, > > raw=False, version=u'2.46'): SUCCESS > > [Thu Jul 21 11:00:38 2016] [error] ipa: DEBUG: response: entries > returned 1 > > [Thu Jul 21 11:00:38 2016] [error] ipa: DEBUG: Destroyed connection > context.ldap2 > > [Thu Jul 21 11:00:38 2016] [error] ipa: DEBUG: reading ccache data from > file > > "/var/run/ipa_memcached/krbcc_13554" > > [Thu Jul 21 11:00:38 2016] [error] ipa: DEBUG: store session: > > session_id=10c5de02f8ae0f3969b96ef0f2e3a96d > start_timestamp=2016-07-21T10:43:26 > > access_timestamp=2016-07-21T11:00:38 > expiration_timestamp=2016-07-21T11:20:38 > > > > *[root@caer ~]# tail -f /var/log/pki-ca/debug* > > [21/Jul/2016:11:08:29][CertStatusUpdateThread]: RequestQueue: curReqId: > 9990001 > > [21/Jul/2016:11:08:29][CertStatusUpdateThread]: getElementAt: 1 mTop 107 > > [21/Jul/2016:11:08:29][CertStatusUpdateThread]: reverse direction > getting index 4 > > [21/Jul/2016:11:08:29][CertStatusUpdateThread]: RequestQueue: curReqId: > 112 > > [21/Jul/2016:11:08:29][CertStatusUpdateThread]: RequestQueue: > getLastRequestId : > > returning value 112 > > [21/Jul/2016:11:08:29][CertStatusUpdateThread]: Repository: > mLastSerialNo: 112 > > [21/Jul/2016:11:08:29][CertStatusUpdateThread]: Serial numbers left in > range: > > 9989888 > > [21/Jul/2016:11:08:29][CertStatusUpdateThread]: Last Serial Number: 112 > > [21/Jul/2016:11:08:29][CertStatusUpdateThread]: Serial Numbers > available: 9989888 > > [21/Jul/2016:11:08:29][CertStatusUpdateThread]: request checkRanges done > > > > *[root@caer ~]# tail -f /var/log/pki-ca/transactions* > > 6563.CRLIssuingPoint-MasterCRL - [20/Jul/2016:17:00:00 EDT] [20] [1] CRL > Update > > completed. CRL ID: MasterCRL CRL Number: 8,912 last update time: 7/20/16 > 5:00 PM > > next update time: 7/20/16 9:00 PM Number of entries in the CRL: 11 time: > 25 CRL > > time: 25 delta CRL time: 0 (0,0,0,0,0,0,0,8,17,0,0,25,25) > > 6563.CRLIssuingPoint-MasterCRL - [20/Jul/2016:21:00:00 EDT] [20] [1] CRL > update > > started. CRL ID: MasterCRL CRL Number: 8,913 Delta CRL Enabled: > false CRL > > Cache Enabled: true Cache Recovery Enabled: true Cache Cleared: false > Cache: > > 11,0,0,0 > > 6563.CRLIssuingPoint-MasterCRL - [20/Jul/2016:21:00:00 EDT] [20] [1] CRL > Update > > completed. CRL ID: MasterCRL CRL Number: 8,913 last update time: 7/20/16 > 9:00 PM > > next update time: 7/21/16 1:00 AM Number of entries in the CRL: 11 time: > 11 CRL > > time: 11 delta CRL time: 0 (0,0,0,0,0,0,0,6,5,0,0,11,11) > > 6563.CRLIssuingPoint-MasterCRL - [21/Jul/2016:01:00:00 EDT] [20] [1] CRL > update > > started. CRL ID: MasterCRL CRL Number: 8,914 Delta CRL Enabled: > false CRL > > Cache Enabled: true Cache Recovery Enabled: true Cache Cleared: false > Cache: > > 11,0,0,0 > > 6563.CRLIssuingPoint-MasterCRL - [21/Jul/2016:01:00:00 EDT] [20] [1] CRL > Update > > completed. CRL ID: MasterCRL CRL Number: 8,914 last update time: 7/21/16 > 1:00 AM > > next update time: 7/21/16 5:00 AM Number of entries in the CRL: 11 time: > 13 CRL > > time: 13 delta CRL time: 0 (0,0,0,0,0,0,0,6,7,0,0,13,13) > > 6563.CRLIssuingPoint-MasterCRL - [21/Jul/2016:05:00:00 EDT] [20] [1] CRL > update > > started. CRL ID: MasterCRL CRL Number: 8,915 Delta CRL Enabled: > false CRL > > Cache Enabled: true Cache Recovery Enabled: true Cache Cleared: false > Cache: > > 11,0,0,0 > > 6563.CRLIssuingPoint-MasterCRL - [21/Jul/2016:05:00:00 EDT] [20] [1] CRL > Update > > completed. CRL ID: MasterCRL CRL Number: 8,915 last update time: 7/21/16 > 5:00 AM > > next update time: 7/21/16 9:00 AM Number of entries in the CRL: 11 time: > 16 CRL > > time: 16 delta CRL time: 0 (0,0,0,0,0,0,0,8,8,0,0,16,16) > > 6563.CRLIssuingPoint-MasterCRL - [21/Jul/2016:09:00:00 EDT] [20] [1] CRL > update > > started. CRL ID: MasterCRL CRL Number: 8,916 Delta CRL Enabled: > false CRL > > Cache Enabled: true Cache Recovery Enabled: true Cache Cleared: false > Cache: > > 11,0,0,0 > > 6563.CRLIssuingPoint-MasterCRL - [21/Jul/2016:09:00:00 EDT] [20] [1] CRL > Update > > completed. CRL ID: MasterCRL CRL Number: 8,916 last update time: 7/21/16 > 9:00 AM > > next update time: 7/21/16 1:00 PM Number of entries in the CRL: 11 time: > 13 CRL > > time: 13 delta CRL time: 0 (0,0,0,0,0,0,0,6,7,0,0,13,13) > > 10657.http-9443-2 - [21/Jul/2016:10:28:19 EDT] [20] [1] renewal reqID 112 > > fromAgent userID: ipara authenticated by certUserDBAuthMgr is completed > DN > > requested: CN=CA Audit,O=TELOIP.NET <http://TELOIP.NET> cert issued > serial > > number: 0x47 time: 39 > > > > *[root@caer ~]# tail -f /var/log/pki-ca/selftests.log* > > 14116.main - [21/Jul/2016:10:58:29 EDT] [20] [1] SelfTestSubsystem: > loading all > > self test plugin logger parameters > > 14116.main - [21/Jul/2016:10:58:29 EDT] [20] [1] SelfTestSubsystem: > loading all > > self test plugin instances > > 14116.main - [21/Jul/2016:10:58:29 EDT] [20] [1] SelfTestSubsystem: > loading all > > self test plugin instance parameters > > 14116.main - [21/Jul/2016:10:58:29 EDT] [20] [1] SelfTestSubsystem: > loading > > self test plugins in on-demand order > > 14116.main - [21/Jul/2016:10:58:29 EDT] [20] [1] SelfTestSubsystem: > loading > > self test plugins in startup order > > 14116.main - [21/Jul/2016:10:58:29 EDT] [20] [1] SelfTestSubsystem: Self > test > > plugins have been successfully loaded! > > 14116.main - [21/Jul/2016:10:58:30 EDT] [20] [1] SelfTestSubsystem: > Running self > > test plugins specified to be executed at startup: > > 14116.main - [21/Jul/2016:10:58:30 EDT] [20] [1] CAPresence: CA is > present > > 14116.main - [21/Jul/2016:10:58:30 EDT] [20] [1] > SystemCertsVerification: system > > certs verification failure > > 14116.main - [21/Jul/2016:10:58:30 EDT] [20] [1] SelfTestSubsystem: The > CRITICAL > > self test plugin called > selftests.container.instance.SystemCertsVerification > > running at startup FAILED! > > > > But intrestingly, [root@caer ~]# ipa cert-show 1 returns "*ipa: ERROR: > > Certificate operation cannot be completed: Unable to communicate with > CMS (Not > > Found)*" > > > > On Thu, Jul 21, 2016 at 10:04 AM, Linov Suresh <linov.sur...@gmail.com > > <mailto:linov.sur...@gmail.com>> wrote: > > > > This could be because of incorrect trust attributes trust on the > > certificates, the current attributes are, > > > > [root@caer ~]# certutil -L -d /var/lib/pki-ca/alias > > > > Certificate Nickname Trust > Attributes > > > SSL,S/MIME,JAR/XPI > > > > ocspSigningCert cert-pki-ca u,u,Pu > > subsystemCert cert-pki-ca u,u,Pu > > caSigningCert cert-pki-ca > CTu,Cu,Cu > > subsystemCert cert-pki-ca u,u,Pu > > Server-Cert cert-pki-ca > u,u,u > > auditSigningCert cert-pki-ca u,u,Pu > > > > I'm going to fix the trust attributes and try. > > > > On Thu, Jul 21, 2016 at 9:45 AM, Petr Vobornik <pvobo...@redhat.com > > <mailto:pvobo...@redhat.com>> wrote: > > > > On 07/20/2016 09:41 PM, Linov Suresh wrote: > > > I have restarted the pki-cad and checked if communication with > the CA is > > > working, but no luck, > > > > > > Debug logs in /var/log/pki-ca do not have anything unusual. > Can you think of > > > anything other than this? > > > > /var/log/httpd/error_log when /etc/ipa.conf is set to debug=true > > > https://www.freeipa.org/page/Troubleshooting#ipa_command_crashes_or_returns_no_data > > > > /var/log/pki-ca/debug > > /var/log/pki-ca/transactions > > /var/log/pki-ca/selftest.log > > > > > > > > [root@caer ~]# ipa cert-show 1 > > > Certificate: > MIIDizCCAnOgAwIBAgIBATANBgkqhkiG9w0BAQsFADA1MRMwEQYDVQQKEwpURUxP > > > > SVAuTkVUMR4wHAYDVQQDExVDZXJ0aWZpY2F0ZSBBdXRob3JpdHkwHhcNMTExMjE0 > > > > MjIyOTU2WhcNMTkxMjE0MjIyOTU2WjA1MRMwEQYDVQQKEwpURUxPSVAuTkVUMR4w > > > > HAYDVQQDExVDZXJ0aWZpY2F0ZSBBdXRob3JpdHkwggEiMA0GCSqGSIb3DQEBAQUA > > > > A4IBDwAwggEKAoIBAQDegJ5XVR0JSc76s9FPkkkuug3PtZi5Ysad0Dr1I5ngjTOV > > > > ctm/P7buk2g8LxBSXLO+7Rq7PTtTD5AJ7vQjrv2RtoYTPdRebAuukTKd6RhtYa5e > > > > tX7z0DBjQ8g9Erqf9GzLxlQqim8ZvscATBhf6MLb5cXA/pWHYuE2j0OlnrSNWqsb > > > > UgwMsM73RlsNACsvLUk4iJY0wuxj4L/0EBQWUPGr8qBk3QBST4LDnInuvvGsAFNe > > > > tyebENMRWnEaDFYKPapACrtKAl3hQNDB7dVGk64Dd7paXss9F8vgVnofgFpjiJs7 > > > > 5DNtKhKxzFQyanINU+uuIVs/CNIO3jV9I26ems2zAgMBAAGjgaUwgaIwHwYDVR0j > > > > BBgwFoAUx5/ZpwOfXZQ5KNwC42cBW+Y+bGIwDwYDVR0TAQH/BAUwAwEB/zAOBgNV > > > > HQ8BAf8EBAMCAcYwHQYDVR0OBBYEFMef2acDn12UOSjcAuNnAVvmPmxiMD8GCCsG > > > > AQUFBwEBBDMwMTAvBggrBgEFBQcwAYYjaHR0cDovL2NhZXIudGVsb2lwLm5ldDo5 > > > > MTgwL2NhL29jc3AwDQYJKoZIhvcNAQELBQADggEBAHGElN0OcepokvNIN8f4mvTj > > > > kL9wcuZwbbX9gZGdKSZf5Redp4tsJW8EJCy8yu9F5U+Ym3RcvJBiby9gHCVVbW+y > > > > 5IgziiJ3kd4UlVJCDVKtbdq62bODcatFsMH8wJSMW6Cw096RyfGgu2qSyXzdZ2xV > > > > nMovO3+Eaz2n0x4ZvaEj9Ixym/KI+QPCAL7gPkK36X4JYgM3CXUCYCN/QJY/psFt > > > > e+121ubSZX5u3Yntux4KziJ3cx9wZ74iKff1BOVxOCi0JyLn2k15bvBXGvxxgmhK > > > > b8YUVbDJDb9oWSbixl/TQI9PZysXYIvBNJM8h+HRKIJksKGQhKOERzrYoqABt30= > > > Subject: CN=Certificate Authority,O=TELOIP.NET < > http://TELOIP.NET> > > <http://TELOIP.NET> > > > Issuer: CN=Certificate Authority,O=TELOIP.NET < > http://TELOIP.NET> > > <http://TELOIP.NET> > > > Not Before: Wed Dec 14 22:29:56 2011 UTC > > > Not After: Sat Dec 14 22:29:56 2019 UTC > > > Fingerprint (MD5): > c9:27:1d:84:4c:2c:97:38:a4:7b:9a:c0:78:3e:7f:7a > > > Fingerprint (SHA1): > ce:d7:11:84:70:dd:cb:4e:e2:08:f5:c0:ac:ff:b3:c5:bb:81:77:7e > > > Serial number (hex): 0x1 > > > Serial number: 1 > > > [root@caer ~]# > > > > > > *ca-error: Internal error: no response to > > > > > " > http://caer.teloip.net:9180/ca/ee/ca/profileSubmit?profileId=caServerCert&serial_num=63&renewal=true&xml=true > ". > > > * > > > > > > > > > > > > On Wed, Jul 20, 2016 at 2:22 PM, Rob Crittenden < > rcrit...@redhat.com <mailto:rcrit...@redhat.com> > > > <mailto:rcrit...@redhat.com <mailto:rcrit...@redhat.com>>> > wrote: > > > > > > Linov Suresh wrote: > > > > > > Thanks for your help Rob, I will create a separate > thread for IPA > > > replication issue. But we are still getting > > > * > > > * > > > *ca-error: Internal error: no response to > > > " > http://caer.teloip.net:9180/ca/ee/ca/profileSubmit?profileId=caServerCert&serial_num=60&renewal=true&xml=true > ".* > > > > > > Could you please help us to fix this? > > > > > > > > > I think your CA isn't quite fixed yet. I'd restart pki-cad > then do something > > > like: ipa cert-show 1 > > > > > > You should get back a cert (doesn't really matter what > cert). > > > > > > Otherwise I'd check the CA debug log somewhere in > /var/log/pki > > > > > > rob > > > > > > -- > Petr Vobornik >
-- 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