Sam Morris via FreeIPA-users wrote:
Hi folks, I've got a machine where certmonger is unable to renew a certificate request:
# getcert list -i 20220519165212 Number of certificates and requests being tracked: 2. Request ID '20220519165212': status: MONITORING ca-error: Server at https://ipa5.ipa.example.com/ipa/json denied our request, giving up: 2100 (Insufficient access: SASL(-1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Credential cache is empty)). stuck: no key pair storage: type=FILE,location='/etc/cockpit/ws-certs.d/51-xoanon.key' certificate: type=FILE,location='/etc/cockpit/ws-certs.d/51-xoanon.crt' CA: IPA issuer: CN=Certificate Authority,O=IPA.EXAMPLE.COM subject: CN=xoanon.ipa.example.com,O=IPA.EXAMPLE.COM issued: 2023-06-21 07:49:49 UTC expires: 2023-09-19 07:49:49 UTC dns: xoanon.ipa.example.com principal name: host/xoanon.ipa.example.com@IPA.EXAMPLE.COM key usage: digitalSignature,nonRepudiation,keyEncipherment,dataEncipherment eku: id-kp-serverAuth,id-kp-clientAuth pre-save command: post-save command: track: yes auto-renew: yes
I'm manually attempting to renew the certificate with:
[root@xoanon ~]# getcert resubmit -w -v -i 20220519165212 Resubmitting "20220519165212" to "IPA". State GENERATING_CSR, stuck: no. State SUBMITTING, stuck: no. State MONITORING, stuck: no.
On the server side, I'm unable to find any errors being logged anywhere. Even after I set 'debug = true' in /etc/ipa/default.conf & restarted httpd.service, the only log messages are:
==> /var/log/httpd/error_log <== [Wed Aug 23 10:59:50.765980 2023] [wsgi:error] [pid 124570:tid 140295030843136] [remote 192.168.88.3:52224] ipa: DEBUG: WSGI wsgi_dispatch.__call__: [Wed Aug 23 10:59:50.766232 2023] [wsgi:error] [pid 124570:tid 140295030843136] [remote 192.168.88.3:52224] ipa: DEBUG: WSGI jsonserver.__call__: [Wed Aug 23 10:59:50.766352 2023] [wsgi:error] [pid 124570:tid 140295030843136] [remote 192.168.88.3:52224] ipa: DEBUG: KerberosWSGIExecutioner.__call__: ==> /var/log/httpd/access_log <== 192.168.88.3 - host/xoanon.ipa.example.com@IPA.EXAMPLE.COM [23/Aug/2023:10:59:50 +0000] "POST /ipa/json HTTP/1.1" 200 526
... which show that the API call was successful. On the other hand, according to 'ipa cert-find --subject=xoanon.ipa.example.com', no certificates have been issued.
It looks like the API isn't calling out to PKI/Dogtag, since nothing is logged to /var/log/pki/pki-tomcat/localhost_access_log.*.txt or /var/log/pki/pki-tomcat/ca/debug.*.log.
I also looked for AVC denials and didn't see anything in /var/log/audit.
So, back to the client. certmonger logs the following:
2023-08-23 11:15:50 [834693] Wrote to /var/lib/certmonger/requests/20220519165212 2023-08-23 11:15:50 [834693] Wrote to /var/lib/certmonger/requests/20220519165212 2023-08-23 11:15:50 [834693] Wrote to /var/lib/certmonger/requests/20220519165212 2023-08-23 11:15:50 [834693] Wrote to /var/lib/certmonger/requests/20220519165212 2023-08-23 11:15:50 [834693] Wrote to /var/lib/certmonger/requests/20220519165212 2023-08-23 11:15:50 [834693] Wrote to /var/lib/certmonger/requests/20220519165212 2023-08-23 11:15:50 [834693] Wrote to /var/lib/certmonger/requests/20220519165212 2023-08-23 11:15:50 [834693] Wrote to /var/lib/certmonger/requests/20220519165212 2023-08-23 11:15:50 [836073] Setting "CERTMONGER_REQ_SUBJECT" to "CN=xoanon.ipa.example.com" for child. 2023-08-23 11:15:50 [836073] Setting "CERTMONGER_REQ_HOSTNAME" to "xoanon.ipa.example.com" for child. 2023-08-23 11:15:50 [836073] Setting "CERTMONGER_REQ_PRINCIPAL" to "host/xoanon.ipa.example.com@IPA.EXAMPLE.COM" for child. 2023-08-23 11:15:50 [836073] Setting "CERTMONGER_OPERATION" to "SUBMIT" for child. 2023-08-23 11:15:50 [836073] Setting "CERTMONGER_CSR" to "-----BEGIN CERTIFICATE REQUEST----- MIIEpzCCAw8CAQAwIzEhMB8GA1UEAxMYeG9hbm9uLmlwYS5yb2JvdHMub3JnLnVr [...] 4d6BlUMScGAgCAxfxEb1eXymTxVm/Do/liHaOqnHGVIr+1OjZNftrUODFQ== -----END CERTIFICATE REQUEST----- " for child. 2023-08-23 11:15:50 [836073] Setting "CERTMONGER_SPKAC" to "[...]" for child. 2023-08-23 11:15:50 [836073] Setting "CERTMONGER_SPKI" to "[...]" for child. 2023-08-23 11:15:50 [836073] Setting "CERTMONGER_LOCAL_CA_DIR" to "/var/lib/certmonger/local" for child. 2023-08-23 11:15:50 [836073] Setting "CERTMONGER_KEY_TYPE" to "RSA" for child. 2023-08-23 11:15:50 [836073] Setting "CERTMONGER_CA_NICKNAME" to "IPA" for child. 2023-08-23 11:15:50 [836073] Setting "CERTMONGER_CERTIFICATE" to "-----BEGIN CERTIFICATE----- MIIFajCCBFKgAwIBAgIET/8AJDANBgkqhkiG9w0BAQsFADA8MRowGAYDVQQKDBFJ [...] dF6L+2tIIpjYylCxKQISWaexKkv1jVQaIPB1foIKyLGaf9YtyaIwyoM9G80UaQ== -----END CERTIFICATE----- " for child. 2023-08-23 11:15:50 [836073] Redirecting stdin to /dev/null, leaving stdout and stderr open for child "/usr/libexec/certmonger/ipa-submit". 2023-08-23 11:15:50 [836073] Running enrollment helper "/usr/libexec/certmonger/ipa-submit". 2023-08-23 11:15:50 [834693] Wrote to /var/lib/certmonger/requests/20220519165212 Submitting request to "https://ipa5.ipa.example.com/ipa/json". JSON-RPC error: 2100: Insufficient access: SASL(-1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Credential cache is empty) 2023-08-23 11:15:50 [834693] Certificate submission still ongoing. 2023-08-23 11:15:50 [834693] Certificate submission attempt complete. 2023-08-23 11:15:50 [834693] Child status = 2. 2023-08-23 11:15:50 [834693] Child output: "Server at https://ipa5.ipa.example.com/ipa/json denied our request, giving up: 2100 (Insufficient access: SASL(-1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Credential cache is empty)). " 2023-08-23 11:15:50 [834693] Server at https://ipa5.ipa.example.com/ipa/json denied our request, giving up: 2100 (Insufficient access: SASL(-1): generic failure: GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Credential cache is empty)). 2023-08-23 11:15:50 [834693] Certificate not (yet?) issued. 2023-08-23 11:15:50 [834693] Wrote to /var/lib/certmonger/requests/20220519165212
I found that I could add 'OPTS=-d9' to /etc/sysconfig/certmonger & restart certmonger.service, which does cause it to log more, but it doesn't give any further insight into the messages exchanged with the server.
Does anyone know where I can look next?
I'd look at the httpd error log again. It's returning a 2100 error which is an ACIError which means that the request has been received and processed. Particularly in debug mode you should have a dozen or more log entries.
A common reason for this is the requesting host doesn't manage the subject host (xoanon.ipa.example.com). Of course if it is the same host then never mind.
rob