[Freeipa-users] IPA certificates expired, please help!

Petr Vobornik pvoborni at redhat.com
Thu Jul 21 15:46:24 UTC 2016


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 at 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: admin at TELOIP.NET 
> <mailto:admin at 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 at 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 at 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 at 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 at 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.suresh at gmail.com 
> <mailto:linov.suresh at gmail.com>> wrote:
> 
>     This could be because of incorrect trust attributes trust on the
>     certificates, the current attributes are,
> 
>     [root at 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 <pvoborni at redhat.com
>     <mailto:pvoborni at 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 at 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 at 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 <rcritten at redhat.com <mailto:rcritten at redhat.com>
>         > <mailto:rcritten at redhat.com <mailto:rcritten at 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




More information about the Freeipa-users mailing list