IPA API can't talk to PKI

[Sam Morris]

Hi folks. PKI-related commands have started to fail on my setup:

$ ipa cert-find 
    ipa: ERROR: Certificate operation cannot be completed: Unable to communicate with CMS (403)

$ ipa vaultconfig-show
    ipa: ERROR: an internal error has occurred

In /var/log/httpd/error_log I can see, respectively (stripping out the
dates, pids, ip addresses etc):

ipa: ERROR: ra.find(): Unable to communicate with CMS (403)
    ipa: INFO: [jsonserver_session] [e-mail]: cert_find/1(None, version='2.245'): CertificateOperationError

and:

ipa: ERROR: non-public: HTTPError: 403 Client Error: 403 for url: https://ipa3.ipa.example.com:443/kra/rest/config/cert/transport                                                                                                                
    Traceback (most recent call last):
      File "/usr/lib/python3.6/site-packages/pki/__init__.py", line 437, in handler
        json = exc_val.response.json()
      File "/usr/lib/python3.6/site-packages/requests/models.py", line 897, in json
        return complexjson.loads(self.text, **kwargs)
      File "/usr/lib64/python3.6/json/__init__.py", line 354, in loads
        return _default_decoder.decode(s)
      File "/usr/lib64/python3.6/json/decoder.py", line 339, in decode
        obj, end = self.raw_decode(s, idx=_w(s, 0).end())
      File "/usr/lib64/python3.6/json/decoder.py", line 357, in raw_decode
        raise JSONDecodeError("Expecting value", s, err.value) from None
    json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
      File "/usr/lib/python3.6/site-packages/ipaserver/rpcserver.py", line 407, in wsgi_execute
        result = command(*args, **options)
      File "/usr/lib/python3.6/site-packages/ipalib/frontend.py", line 471, in __call__
        return self.__do_call(*args, **options)
      File "/usr/lib/python3.6/site-packages/ipalib/frontend.py", line 499, in __do_call
        ret = self.run(*args, **options)
      File "/usr/lib/python3.6/site-packages/ipalib/frontend.py", line 821, in run
        return self.execute(*args, **options)
      File "/usr/lib/python3.6/site-packages/ipaserver/plugins/vault.py", line 1003, in execute
        transport_cert = kra_client.system_certs.get_transport_cert()
      File "/usr/lib/python3.6/site-packages/pki/__init__.py", line 442, in handler
        six.reraise(exc_type, exc_val, exc_tb)
      File "/usr/lib/python3.6/site-packages/six.py", line 693, in reraise
        raise value
      File "/usr/lib/python3.6/site-packages/pki/__init__.py", line 431, in handler
        return fn_call(inst, *args, **kwargs)
      File "/usr/lib/python3.6/site-packages/pki/systemcert.py", line 62, in get_transport_cert
        response = self.connection.get(url, self.headers)
      File "/usr/lib/python3.6/site-packages/pki/client.py", line 55, in wrapper
        return func(self, *args, **kwargs)
      File "/usr/lib/python3.6/site-packages/pki/client.py", line 261, in get
        r.raise_for_status()
      File "/usr/lib/python3.6/site-packages/requests/models.py", line 940, in raise_for_status
        raise HTTPError(http_error_msg, response=self)
    requests.exceptions.HTTPError: 403 Client Error: 403 for url: https://ipa3.example.com:443/kra/rest/config/cert/transport

ipa: INFO: [jsonserver_session] [e-mail]: vaultconfig_show/1(version='2.245'): InternalError

The only messages I can find on the PKI server side are in
</var/log/pki/pki-tomcat/localhost_access_log.2022-04-27.txt>:

2001:db8::1 - - [27/Apr/2022:11:59:14 +0000] "POST /ca/rest/certs/search?size=2147483647 HTTP/1.1" 403 618
    2001:db8::1 - - [27/Apr/2022:11:59:17 +0000] "GET /kra/rest/config/cert/transport HTTP/1.1" 403 618

So I'm guessing that whatever certificate the IPA API uses to
communicate with the PKI server has expired.

ipa-healthcheck has been telling me about certificates with mismatches
between their NSS databases and their copies within CS.cfg for a while.
I reported these at https://github.com/dogtagpki/pki/issues/3877 in
the hope that it would lead somewhere, before the warning actually
started causing problems. And then forgot all about it, naturally. :)

Here are the failed checks from ipa-healtcheck, followed by certmonger's
status for each tracking request, and the details of the certificate in
the NSS database and its copy within CS.cfg:

{
      "source": "pki.server.healthcheck.meta.csconfig",
      "check": "KRADogtagCertsConfigCheck",
      "result": "ERROR",
      "uuid": "38ada44b-ded5-4ae9-9365-6d171bc5b0fa",
      "when": "20220427040032Z",
      "duration": "0.193909",
      "kw": {
        "key": "kra_transport",
        "nickname": "transportCert cert-pki-kra",
        "directive": "kra.transport.cert",
        "configfile": "/var/lib/pki/pki-tomcat/kra/conf/CS.cfg",
        "msg": "Certificate 'transportCert cert-pki-kra' does not match the value of kra.transport.cert in /var/lib/pki/pki-tomcat/kra/conf/CS.cfg"
      }
    }
    {
      "source": "ipahealthcheck.dogtag.ca",
      "check": "DogtagCertsConfigCheck",
      "result": "ERROR",
      "uuid": "24b190a9-e445-47d8-9664-742ec413f18e",
      "when": "20220427040033Z",
      "duration": "0.471634",
      "kw": {
        "key": "transportCert cert-pki-kra",
        "directive": "ca.connector.KRA.transportCert",
        "configfile": "/var/lib/pki/pki-tomcat/conf/ca/CS.cfg",
        "msg": "Certificate 'transportCert cert-pki-kra' does not match the value of ca.connector.KRA.transportCert in /var/lib/pki/pki-tomcat/conf/ca/CS.cfg"
      }
    }

# getcert list -d /etc/pki/pki-tomcat/alias -n 'transportCert cert-pki-kra'
    Number of certificates and requests being tracked: 12.
    Request ID '20210518174640':
        status: MONITORING
        stuck: no
        key pair storage: type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='transportCert cert-pki-kra',token='NSS Certificate DB',pin set
        certificate: type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='transportCert cert-pki-kra',token='NSS Certificate DB'
        CA: dogtag-ipa-ca-renew-agent
        issuer: CN=Certificate Authority,O=IPA.EXAMPLE.COM
        subject: CN=KRA Transport Certificate,O=IPA.EXAMPLE.COM
        expires: 2023-03-31 21:42:06 UTC
        key usage: digitalSignature,nonRepudiation,keyEncipherment,dataEncipherment
        eku: id-kp-clientAuth
        profile: caTransportCert
        pre-save command: /usr/libexec/ipa/certmonger/stop_pkicad
        post-save command: /usr/libexec/ipa/certmonger/renew_ca_cert "transportCert cert-pki-kra"
        track: yes
        auto-renew: yes

# certutil -d /etc/pki/pki-tomcat/alias -L -n 'transportCert cert-pki-kra' -a | openssl x509 -noout -issuer -serial -subject -dates
    issuer=O = IPA.EXAMPLE.COM, CN = Certificate Authority
    serial=2FFF000B
    subject=O = IPA.EXAMPLE.COM, CN = KRA Transport Certificate
    notBefore=Apr 10 21:42:06 2021 GMT
    notAfter=Mar 31 21:42:06 2023 GMT

# crudini --get /etc/pki/pki-tomcat/kra/CS.cfg '' kra.transport.cert | base64 -d | openssl x509 -inform der -noout -issuer -serial -subject -dates
    issuer=O = IPA.EXAMPLE.COM, CN = Certificate Authority
    serial=0B
    subject=O = IPA.EXAMPLE.COM, CN = KRA Transport Certificate
    notBefore=Mar 18 00:15:01 2019 GMT
    notAfter=Mar  7 00:15:01 2021 GMT

# crudini --get /var/lib/pki/pki-tomcat/conf/ca/CS.cfg '' ca.connector.KRA.transportCert | base64 -d | openssl x509 -inform der -noout -issuer -serial -subject -dates
    issuer=O = IPA.EXAMPLE.COM, CN = Certificate Authority
    serial=0B
    subject=O = IPA.EXAMPLE.COM, CN = KRA Transport Certificate
    notBefore=Mar 18 00:15:01 2019 GMT
    notAfter=Mar  7 00:15:01 2021 GMT

{
      "source": "pki.server.healthcheck.meta.csconfig",
      "check": "KRADogtagCertsConfigCheck",
      "result": "ERROR",
      "uuid": "c90d8174-bf9d-4efe-a24c-4e4ece90d7f9",
      "when": "20220427040032Z",
      "duration": "0.256320",
      "kw": {
        "key": "kra_storage",
        "nickname": "storageCert cert-pki-kra",
        "directive": "kra.storage.cert",
        "configfile": "/var/lib/pki/pki-tomcat/kra/conf/CS.cfg",
        "msg": "Certificate 'storageCert cert-pki-kra' does not match the value of kra.storage.cert in /var/lib/pki/pki-tomcat/kra/conf/CS.cfg"
      }
    }

# getcert list -d /etc/pki/pki-tomcat/alias -n 'storageCert cert-pki-kra'
    Number of certificates and requests being tracked: 12.
    Request ID '20210518174641':
        status: MONITORING
        stuck: no
        key pair storage: type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='storageCert cert-pki-kra',token='NSS Certificate DB',pin set
        certificate: type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='storageCert cert-pki-kra',token='NSS Certificate DB'
        CA: dogtag-ipa-ca-renew-agent
        issuer: CN=Certificate Authority,O=IPA.EXAMPLE.COM
        subject: CN=KRA Storage Certificate,O=IPA.EXAMPLE.COM
        expires: 2023-03-31 21:42:23 UTC
        key usage: digitalSignature,nonRepudiation,keyEncipherment,dataEncipherment
        eku: id-kp-clientAuth
        profile: caStorageCert
        pre-save command: /usr/libexec/ipa/certmonger/stop_pkicad
        post-save command: /usr/libexec/ipa/certmonger/renew_ca_cert "storageCert cert-pki-kra"
        track: yes
        auto-renew: yes

# certutil -d /etc/pki/pki-tomcat/alias -L -n 'storageCert cert-pki-kra' -a | openssl x509 -noout -issuer -serial -subject -dates
    issuer=O = IPA.EXAMPLE.COM, CN = Certificate Authority
    serial=2FFF000D
    subject=O = IPA.EXAMPLE.COM, CN = KRA Storage Certificate
    notBefore=Apr 10 21:42:23 2021 GMT
    notAfter=Mar 31 21:42:23 2023 GMT

# crudini --get /etc/pki/pki-tomcat/kra/CS.cfg '' kra.storage.cert | base64 -d | openssl x509 -inform der -noout -issuer -serial -subject -dates
    issuer=O = IPA.EXAMPLE.COM, CN = Certificate Authority
    serial=0C
    subject=O = IPA.EXAMPLE.COM, CN = KRA Storage Certificate
    notBefore=Mar 18 00:15:01 2019 GMT
    notAfter=Mar  7 00:15:01 2021 GMT

{
      "source": "pki.server.healthcheck.meta.csconfig",
      "check": "KRADogtagCertsConfigCheck",
      "result": "ERROR",
      "uuid": "95187b54-782d-455f-8dae-39d6eaee71e5",
      "when": "20220427040033Z",
      "duration": "0.319186",
      "kw": {
        "key": "kra_audit_signing",
        "nickname": "auditSigningCert cert-pki-kra",
        "directive": "kra.audit_signing.cert",
        "configfile": "/var/lib/pki/pki-tomcat/kra/conf/CS.cfg",
        "msg": "Certificate 'auditSigningCert cert-pki-kra' does not match the value of kra.audit_signing.cert in /var/lib/pki/pki-tomcat/kra/conf/CS.cfg"
      }
    }

# getcert list -d /etc/pki/pki-tomcat/alias -n 'auditSigningCert cert-pki-kra'
    Number of certificates and requests being tracked: 12.
    Request ID '20210518174639':
        status: MONITORING
        stuck: no
        key pair storage: type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='auditSigningCert cert-pki-kra',token='NSS Certificate DB',pin set
        certificate: type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='auditSigningCert cert-pki-kra',token='NSS Certificate DB'
        CA: dogtag-ipa-ca-renew-agent
        issuer: CN=Certificate Authority,O=IPA.EXAMPLE.COM
        subject: CN=KRA Audit,O=IPA.EXAMPLE.COM
        expires: 2023-03-31 21:42:08 UTC
        key usage: digitalSignature,nonRepudiation
        profile: caAuditSigningCert
        pre-save command: /usr/libexec/ipa/certmonger/stop_pkicad
        post-save command: /usr/libexec/ipa/certmonger/renew_ca_cert "auditSigningCert cert-pki-kra"
        track: yes
        auto-renew: yes

# certutil -d /etc/pki/pki-tomcat/alias -L -n 'auditSigningCert cert-pki-kra' -a | openssl x509 -noout -issuer -serial -subject -dates
    issuer=O = IPA.EXAMPLE.COM, CN = Certificate Authority
    serial=2FFF000C
    subject=O = IPA.EXAMPLE.COM, CN = KRA Audit
    notBefore=Apr 10 21:42:08 2021 GMT
    notAfter=Mar 31 21:42:08 2023 GMT

# crudini --get /etc/pki/pki-tomcat/kra/CS.cfg '' kra.audit_signing.cert | base64 -d | openssl x509 -inform der -noout -issuer -serial -subject -dates
    issuer=O = IPA.EXAMPLE.COM, CN = Certificate Authority
    serial=0D
    subject=O = IPA.EXAMPLE.COM, CN = KRA Audit
    notBefore=Mar 18 00:15:02 2019 GMT
    notAfter=Mar  7 00:15:02 2021 GMT

I'm really not clear exactly what is supposed to be taking the
certificates from the NSS database and updating CS.cfg. At first I
thought it was the renew_ca_cert script, but looking into the code, it
only seems to update CS.cfg for 'caSigningCert cert-pki-ca'.

(Regarding that, there's maybe another issue to solve here. The CA's
CS.cfg file has subsystem.select=Clone; it looks like that will cause
renew_ca_cert to not update CS.cfg when the CA certificate renews in the
distant future. Should I edit CS.cfg by hand, or maybe promote another
server to be the CA renewal master, and see if subsystem.select is set
properly on that server once it's promoted?)

Anyway. The funny thing about all this is that all these certificates
expired last year. And I am pretty sure I used the ipa vault commands a
couple of weeks ago. So perhaps the problem is actually elsewhere, and
I don't know how to debug the PKI server any further, so...

1. Are the expired certs in CS.cfg causing the problem?
2. Which bit of FreeIPA updates the certificate copies in CS.cfg?
3. Where do I look to debug the PKI server further?

As always, I'm grateful for any assistance, thanks :)

[Sam Morris]

On 27/04/2022 14:09, Sam Morris wrote:
> Hi folks. PKI-related commands have started to fail on my setup:

Oh, it turns out this is 
https://bugzilla.redhat.com/show_bug.cgi?id=2006070 again, but this 
time manifesting slightly differently: secret="oldsecret" was replaced 
by "requiredSecret="newsecret" in </etc/pki/pki-tomcat/server.xml>.
> Are the expired certs in CS.cfg causing the problem?

No. According to https://github.com/dogtagpki/pki/issues/2157 dogtag 
doesn't even use them, is that right? In which case should 
ipa-healthcheck stop warning about them?
> Which bit of FreeIPA updates the certificate copies in CS.cfg?

I'm now pretty sure FreeIPA doesn't update CS.cfg except for the CA 
certificate. And on my CA renewal master, that wouldn't happen because 
subsystem.select is set to Clone. Should I change that?

[Rob Crittenden]

Sam Morris via FreeIPA-users wrote:
> On 27/04/2022 14:09, Sam Morris wrote:
> > Hi folks. PKI-related commands have started to fail on my setup:
>
> Oh, it turns out this is
> https://bugzilla.redhat.com/show_bug.cgi?id=2006070 again, but this
> time manifesting slightly differently: secret="oldsecret" was replaced
> by "requiredSecret="newsecret" in </etc/pki/pki-tomcat/server.xml>.

It depends on the version of tomcat you have installed.
> > Are the expired certs in CS.cfg causing the problem?
>
> No. According to https://github.com/dogtagpki/pki/issues/2157 dogtag
> doesn't even use them, is that right? In which case should
> ipa-healthcheck stop warning about them?

I don't believe they have dropped using the CS.cfg values. The issue is
incorrect as IPA does update these values, because it has to in order
for the CA to work.
> > Which bit of FreeIPA updates the certificate copies in CS.cfg?
>
> I'm now pretty sure FreeIPA doesn't update CS.cfg except for the CA
> certificate. And on my CA renewal master, that wouldn't happen because
> subsystem.select is set to Clone. Should I change that?

It shouldn't be necessary. IPA doesn't examine this value.

And IPA does update CS.cfg for all tracked CA subsystem certificates.

rob

[Sam Morris]

On 27/04/2022 15:52, Rob Crittenden wrote:
> Sam Morris via FreeIPA-users wrote:
> > On 27/04/2022 14:09, Sam Morris wrote:
> > > Hi folks. PKI-related commands have started to fail on my setup:
> >
> > Oh, it turns out this is
> > https://bugzilla.redhat.com/show_bug.cgi?id=2006070 again, but this
> > time manifesting slightly differently: secret="oldsecret" was replaced
> > by "requiredSecret="newsecret" in </etc/pki/pki-tomcat/server.xml>.
>
> It depends on the version of tomcat you have installed.

Indeed, I'm still a bit confused--I ended up with only the 
requiredSecret= attribute, and not both secret= and requiredSecret= as 
in Bugzilla, but it doesn't really matter. I've just taken the new 
secret value and updated </etc/httpd/conf.d/ipa-pki-proxy.conf> to match.
> > > Are the expired certs in CS.cfg causing the problem?
> >
> > No. According to https://github.com/dogtagpki/pki/issues/2157 dogtag
> > doesn't even use them, is that right? In which case should
> > ipa-healthcheck stop warning about them?
>
> I don't believe they have dropped using the CS.cfg values. The issue is
> incorrect as IPA does update these values, because it has to in order
> for the CA to work.

You're right, reading that issue again I guess the intention is to move 
away from storing the certificates in CS.cfg.
> > > Which bit of FreeIPA updates the certificate copies in CS.cfg?
> >
> > I'm now pretty sure FreeIPA doesn't update CS.cfg except for the CA
> > certificate. And on my CA renewal master, that wouldn't happen because
> > subsystem.select is set to Clone. Should I change that?
>
> It shouldn't be necessary. IPA doesn't examine this value.

It's checked at 
https://github.com/freeipa/freeipa/blob/9d88a2fde795f5189cf3f101678bad2384bf1ef7/install/restart_scripts/renew_ca_cert.in#L112
> And IPA does update CS.cfg for all tracked CA subsystem certificates.

I'd like to figure out why it hasn't happened on my servers... The 
post-save command (renew_ca_cert) only updates the CA CS.cfg when the CA 
certificate is renewed; I can't see where the other subsystem 
certificates get written to either CS.cfg file...