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?
-- Sam Morris https://robots.org.uk/ PGP: rsa4096/CAAA AA1A CA69 A83A 892B 1855 D20B 4202 5CDA 27B9
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
On Fri, Sep 01, 2023 at 01:59:00PM -0400, Rob Crittenden via FreeIPA-users wrote:
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.
Thanks rob. I think debug mode is correctly enabled because when I restart httpd I see a lot of messages as the API server loads plugins, etc. But when submitting the signing request the only log lines are:
==> /var/log/httpd/error_log <== [Mon Sep 04 09:46:17.942879 2023] [wsgi:error] [pid 220090:tid 140379473487616] [remote 192.168.88.3:47188] ipa: DEBUG: WSGI wsgi_dispatch.__call__: [Mon Sep 04 09:46:17.943152 2023] [wsgi:error] [pid 220090:tid 140379473487616] [remote 192.168.88.3:47188] ipa: DEBUG: WSGI jsonserver.__call__: [Mon Sep 04 09:46:17.943276 2023] [wsgi:error] [pid 220090:tid 140379473487616] [remote 192.168.88.3:47188] ipa: DEBUG: KerberosWSGIExecutioner.__call__:
I've made some slight progress. I noticed that at the same time, the KDC logs these messages:
==> /var/log/krb5kdc.log <== Sep 04 09:46:17 ipa5.ipa.example.com krb5kdc[183962](info): TGS_REQ : handle_authdata (-1765328371) Sep 04 09:46:17 ipa5.ipa.example.com krb5kdc[183962](info): TGS_REQ (6 etypes {aes256-cts-hmac-sha1-96(18), aes256-cts-hmac-sha384-192(20), camellia256-cts-cmac(26), aes128-cts-hmac-sha1-96(17), aes128-cts-hmac-sha256-128(19), camellia128-cts-cmac(25)}) 192.168.88.5: HANDLE_AUTHDATA: authtime 1693820777, etypes {rep=UNSUPPORTED:(0)} HTTP/ipa5.ipa.example.com@IPA.EXAMPLE.COM for ldap/ipa5.ipa.example.com@IPA.EXAMPLE.COM, KDC can't fulfill requested option Sep 04 09:46:17 ipa5.ipa.example.com krb5kdc[183962](info): ... CONSTRAINED-DELEGATION s4u-client=host/xoanon.ipa.example.com@IPA.EXAMPLE.COM Sep 04 09:46:17 ipa5.ipa.example.com krb5kdc[183962](info): closing down fd 12
I guess this is showing that HTTP/ipa5.ipa.example.com (the IPA API server) is trying to obtain a ticket to LDAP/ipa5.ipa.example.com on behalf of host/xoanon.ipa.example.com but the KDC is rejecting the request.
If that's right then I guess I need to figure out why that might be. Unfortunately setting 'debug = true' in /etc/krb5.conf's [logging] section doesn't cause any more detailed messages to be logged.
If I run gssproxy with --debug-level=2 I can see it logging some stuff but I guess it's just showing the calls that result in the kdc logging the above...
-- Logs begin at Sun 2022-08-28 20:23:46 UTC. -- Sep 04 10:55:49 gssproxy[221575]: [2023/09/04 10:55:49]: Client [2023/09/04 10:55:49]: (/usr/sbin/httpd) [2023/09/04 10:55:49]: connected (fd = 15)[2023/09/04 10:55:49]: (pid = 220686) (uid = 48) (gid = 48)[2023/09/04 10:55:49]: (context = system_u:system_r:httpd_t:s0)[2023/09/04 10:55:49]: Sep 04 10:55:49 gssproxy[221575]: [CID 15][2023/09/04 10:55:49]: Connection matched service ipa-httpd Sep 04 10:55:49 gssproxy[221575]: [CID 15][2023/09/04 10:55:49]: gp_rpc_execute: executing 6 (GSSX_ACQUIRE_CRED) for service "ipa-httpd", euid: 48,socket: (null) Sep 04 10:55:49 gssproxy[221575]: GSSX_ARG_ACQUIRE_CRED( call_ctx: { "" [ ] } input_cred_handle: { "HTTP/ipa5.ipa.example.com@IPA.EXAMPLE.COM" [ { "HTTP/ipa5.ipa.example.com@IPA.EXAMPLE.COM" { 1 2 840 113554 1 2 2 } BOTH 84028 84028 } ] [ .I...b1Z........... ] 0 } add_cred: 0 desired_name: <Null> time_req: 4294967295 desired_mechs: { { 1 2 840 113554 1 2 2 } } cred_usage: BOTH initiator_time_req: 0 acceptor_time_req: 0 ) Sep 04 10:55:49 gssproxy[221575]: GSSX_RES_ACQUIRE_CRED( status: { 0 { 1 2 840 113554 1 2 2 } 0 "" "" [ ] } output_cred_handle: { "HTTP/ipa5.ipa.example.com@IPA.EXAMPLE.COM" [ { "HTTP/ipa5.ipa.example.com@IPA.EXAMPLE.COM" { 1 2 840 113554 1 2 2 } BOTH 84028 84028 } ] [ .I...b1Z........... ] 0 } ) Sep 04 10:55:49 gssproxy[221575]: [CID 15][2023/09/04 10:55:49]: Connection matched service ipa-httpd Sep 04 10:55:49 gssproxy[221575]: [CID 15][2023/09/04 10:55:49]: gp_rpc_execute: executing 6 (GSSX_ACQUIRE_CRED) for service "ipa-httpd", euid: 48,socket: (null) Sep 04 10:55:49 gssproxy[221575]: GSSX_ARG_ACQUIRE_CRED( call_ctx: { "" [ ] } input_cred_handle: { "HTTP/ipa5.ipa.example.com@IPA.EXAMPLE.COM" [ { "HTTP/ipa5.ipa.example.com@IPA.EXAMPLE.COM" { 1 2 840 113554 1 2 2 } BOTH 84028 84028 } ] [ .I...b1Z........... ] 0 } add_cred: 0 desired_name: <Null> time_req: 4294967295 desired_mechs: { { 1 2 840 113554 1 2 2 } } cred_usage: BOTH initiator_time_req: 0 acceptor_time_req: 0 ) Sep 04 10:55:49 gssproxy[221575]: GSSX_RES_ACQUIRE_CRED( status: { 0 { 1 2 840 113554 1 2 2 } 0 "" "" [ ] } output_cred_handle: { "HTTP/ipa5.ipa.example.com@IPA.EXAMPLE.COM" [ { "HTTP/ipa5.ipa.example.com@IPA.EXAMPLE.COM" { 1 2 840 113554 1 2 2 } BOTH 84028 84028 } ] [ .I...b1Z........... ] 0 } ) Sep 04 10:55:49 gssproxy[221575]: [CID 15][2023/09/04 10:55:49]: Connection matched service ipa-httpd Sep 04 10:55:49 gssproxy[221575]: [CID 15][2023/09/04 10:55:49]: gp_rpc_execute: executing 9 (GSSX_ACCEPT_SEC_CONTEXT) for service "ipa-httpd", euid: 48,socket: (null) Sep 04 10:55:49 gssproxy[221575]: GSSX_ARG_ACCEPT_SEC_CONTEXT( call_ctx: { "" [ ] } context_handle: <Null> cred_handle: { "HTTP/ipa5.ipa.example.com@IPA.EXAMPLE.COM" [ { "HTTP/ipa5.ipa.example.com@IPA.EXAMPLE.COM" { 1 2 840 113554 1 2 2 } BOTH 84028 84028 } ] [ .I...b1Z........... ] 0 } input_token: [ ........H.......... ] input_cb: <Null> ret_deleg_cred: 1 ) Sep 04 10:55:49 gssproxy[221575]: GSSX_RES_ACCEPT_SEC_CONTEXT( status: { 0 { 1 2 840 113554 1 2 2 } 0 "" "" [ ] } context_handle: { [ ......H............ ] [ ] 0 { 1 2 840 113554 1 2 2 } "host/xoanon.ipa.example.com@IPA.EXAMPLE.COM" "HTTP/ipa5.ipa.example.com@IPA.EXAMPLE.COM" 84387 439 0 1 } output_token: [ .......H........... ] delegated_cred_handle: { "host/xoanon.ipa.example.com@IPA.EXAMPLE.COM" [ { "host/xoanon.ipa.example.com@IPA.EXAMPLE.COM" { 1 2 840 113554 1 2 2 } INITIATE 84087 0 } ] [ ................... ] 0 } ) Sep 04 10:55:49 gssproxy[221575]: [2023/09/04 10:55:49]: Client [2023/09/04 10:55:49]: (/usr/sbin/httpd) [2023/09/04 10:55:49]: connected (fd = 16)[2023/09/04 10:55:49]: (pid = 220685) (uid = 988) (gid = 983)[2023/09/04 10:55:49]: (context = system_u:system_r:httpd_t:s0)[2023/09/04 10:55:49]: Sep 04 10:55:49 gssproxy[221575]: [CID 16][2023/09/04 10:55:49]: Connection matched service ipa-api Sep 04 10:55:49 gssproxy[221575]: [CID 16][2023/09/04 10:55:49]: gp_rpc_execute: executing 6 (GSSX_ACQUIRE_CRED) for service "ipa-api", euid: 988,socket: (null) Sep 04 10:55:49 gssproxy[221575]: GSSX_ARG_ACQUIRE_CRED( call_ctx: { "" [ ] } input_cred_handle: { "host/xoanon.ipa.example.com@IPA.EXAMPLE.COM" [ { "host/xoanon.ipa.example.com@IPA.EXAMPLE.COM" { 1 2 840 113554 1 2 2 } INITIATE 84087 0 } ] [ ................... ] 0 } add_cred: 0 desired_name: <Null> time_req: 4294967295 desired_mechs: { { 1 2 840 113554 1 2 2 } } cred_usage: INITIATE initiator_time_req: 0 acceptor_time_req: 0 ) Sep 04 10:55:49 gssproxy[221575]: GSSX_RES_ACQUIRE_CRED( status: { 0 { 1 2 840 113554 1 2 2 } 0 "" "" [ ] } output_cred_handle: { "host/xoanon.ipa.example.com@IPA.EXAMPLE.COM" [ { "host/xoanon.ipa.example.com@IPA.EXAMPLE.COM" { 1 2 840 113554 1 2 2 } INITIATE 84087 0 } ] [ ................... ] 0 } ) Sep 04 10:55:49 gssproxy[221575]: [CID 16][2023/09/04 10:55:49]: Connection matched service ipa-api Sep 04 10:55:49 gssproxy[221575]: [CID 16][2023/09/04 10:55:49]: gp_rpc_execute: executing 6 (GSSX_ACQUIRE_CRED) for service "ipa-api", euid: 988,socket: (null) Sep 04 10:55:49 gssproxy[221575]: GSSX_ARG_ACQUIRE_CRED( call_ctx: { "" [ ] } input_cred_handle: { "host/xoanon.ipa.example.com@IPA.EXAMPLE.COM" [ { "host/xoanon.ipa.example.com@IPA.EXAMPLE.COM" { 1 2 840 113554 1 2 2 } INITIATE 84087 0 } ] [ ................... ] 0 } add_cred: 0 desired_name: <Null> time_req: 4294967295 desired_mechs: { { 1 2 840 113554 1 2 2 } } cred_usage: INITIATE initiator_time_req: 0 acceptor_time_req: 0 ) Sep 04 10:55:49 gssproxy[221575]: GSSX_RES_ACQUIRE_CRED( status: { 0 { 1 2 840 113554 1 2 2 } 0 "" "" [ ] } output_cred_handle: { "host/xoanon.ipa.example.com@IPA.EXAMPLE.COM" [ { "host/xoanon.ipa.example.com@IPA.EXAMPLE.COM" { 1 2 840 113554 1 2 2 } INITIATE 84087 0 } ] [ ................... ] 0 } ) Sep 04 10:55:49 gssproxy[221575]: [CID 16][2023/09/04 10:55:49]: Connection matched service ipa-api Sep 04 10:55:49 gssproxy[221575]: [CID 16][2023/09/04 10:55:49]: gp_rpc_execute: executing 6 (GSSX_ACQUIRE_CRED) for service "ipa-api", euid: 988,socket: (null) Sep 04 10:55:49 gssproxy[221575]: GSSX_ARG_ACQUIRE_CRED( call_ctx: { "" [ ] } input_cred_handle: { "host/xoanon.ipa.example.com@IPA.EXAMPLE.COM" [ { "host/xoanon.ipa.example.com@IPA.EXAMPLE.COM" { 1 2 840 113554 1 2 2 } INITIATE 84087 0 } ] [ ................... ] 0 } add_cred: 0 desired_name: <Null> time_req: 4294967295 desired_mechs: { { 1 2 840 113554 1 2 2 } } cred_usage: INITIATE initiator_time_req: 0 acceptor_time_req: 0 ) Sep 04 10:55:49 gssproxy[221575]: GSSX_RES_ACQUIRE_CRED( status: { 0 { 1 2 840 113554 1 2 2 } 0 "" "" [ ] } output_cred_handle: { "host/xoanon.ipa.example.com@IPA.EXAMPLE.COM" [ { "host/xoanon.ipa.example.com@IPA.EXAMPLE.COM" { 1 2 840 113554 1 2 2 } INITIATE 84087 0 } ] [ ................... ] 0 } ) Sep 04 10:55:49 gssproxy[221575]: [CID 16][2023/09/04 10:55:49]: Connection matched service ipa-api Sep 04 10:55:49 gssproxy[221575]: [CID 16][2023/09/04 10:55:49]: gp_rpc_execute: executing 6 (GSSX_ACQUIRE_CRED) for service "ipa-api", euid: 988,socket: (null) Sep 04 10:55:49 gssproxy[221575]: GSSX_ARG_ACQUIRE_CRED( call_ctx: { "" [ ] } input_cred_handle: { "host/xoanon.ipa.example.com@IPA.EXAMPLE.COM" [ { "host/xoanon.ipa.example.com@IPA.EXAMPLE.COM" { 0 2 840 113554 1 2 2 } INITIATE 84087 0 } ] [ ................... ] 0 } add_cred: 0 desired_name: <Null> time_req: 0 desired_mechs: { } cred_usage: INITIATE initiator_time_req: 0 acceptor_time_req: 0 ) Sep 04 10:55:49 gssproxy[221575]: GSSX_RES_ACQUIRE_CRED( status: { 0 { 1 2 840 113554 1 2 2 } 0 "" "" [ ] } output_cred_handle: { "host/xoanon.ipa.example.com@IPA.EXAMPLE.COM" [ { "host/xoanon.ipa.example.com@IPA.EXAMPLE.COM" { 1 2 840 113554 1 2 2 } INITIATE 84087 0 } ] [ ................... ] 0 } ) Sep 04 10:55:49 gssproxy[221575]: [CID 16][2023/09/04 10:55:49]: Connection matched service ipa-api Sep 04 10:55:49 gssproxy[221575]: [CID 16][2023/09/04 10:55:49]: gp_rpc_execute: executing 8 (GSSX_INIT_SEC_CONTEXT) for service "ipa-api", euid: 988,socket: (null) Sep 04 10:55:49 gssproxy[221575]: GSSX_ARG_INIT_SEC_CONTEXT( call_ctx: { "" [ ] } context_handle: <Null> cred_handle: { "host/xoanon.ipa.example.com@IPA.EXAMPLE.COM" [ { "host/xoanon.ipa.example.com@IPA.EXAMPLE.COM" { 1 2 840 113554 1 2 2 } INITIATE 84087 0 } ] [ ................... ] 0 } target_name: "ldap@ipa5.ipa.example.com" mech_type: { 1 2 840 113554 1 2 2 } req_flags: 58 time_req: 0 input_cb: <Null> input_token: <Null> [ { [ sync.modified.cr... ] [ 64656661756c740 ] } ] ) Sep 04 10:55:49 gssproxy[221575]: [CID 16][2023/09/04 10:55:49]: Credentials allowed by configuration Sep 04 10:55:49 gssproxy[221575]: GSSX_RES_INIT_SEC_CONTEXT( status: { 851968 { 1 2 840 113554 1 2 2 } 2529638925 "Unspecified GSS failure. Minor code may provide more information" "KDC can't fulfill requested option" [ ] } context_handle: <Null> output_token: <Null> )
The delegation rule looks normal to me:
$ ipa servicedelegationrule-show ipa-http-delegation Delegation name: ipa-http-delegation Allowed Target: ipa-ldap-delegation-targets, ipa-cifs-delegation-targets Member principals: HTTP/ipa3.ipa.example.com@IPA.EXAMPLE.COM, HTTP/ipa5.ipa.example.com@IPA.EXAMPLE.COM, HTTP/ipa6.ipa.example.com@IPA.EXAMPLE.COM
$ ipa servicedelegationtarget-show ipa-ldap-delegation-targets Delegation name: ipa-ldap-delegation-targets Member principals: ldap/ipa3.ipa.example.com@IPA.EXAMPLE.COM, ldap/ipa5.ipa.example.com@IPA.EXAMPLE.COM, ldap/ipa6.ipa.example.com@IPA.EXAMPLE.COM
Looking through the krb5 source code, "KDC can't fulfill requested option" corresponds to the error code KRB5KDC_ERR_BADOPTION, which can be returned by krb5_ldap_check_allowed_to_delegate. But it could also be returned in a couple of other places, and I haven't figured out where it's coming from yet.
On Пан, 04 вер 2023, Sam Morris via FreeIPA-users wrote:
I've made some slight progress. I noticed that at the same time, the KDC logs these messages:
==> /var/log/krb5kdc.log <== Sep 04 09:46:17 ipa5.ipa.example.com krb5kdc[183962](info): TGS_REQ : handle_authdata (-1765328371) Sep 04 09:46:17 ipa5.ipa.example.com krb5kdc[183962](info): TGS_REQ (6 etypes {aes256-cts-hmac-sha1-96(18), aes256-cts-hmac-sha384-192(20), camellia256-cts-cmac(26), aes128-cts-hmac-sha1-96(17), aes128-cts-hmac-sha256-128(19), camellia128-cts-cmac(25)}) 192.168.88.5: HANDLE_AUTHDATA: authtime 1693820777, etypes {rep=UNSUPPORTED:(0)} HTTP/ipa5.ipa.example.com@IPA.EXAMPLE.COM for ldap/ipa5.ipa.example.com@IPA.EXAMPLE.COM, KDC can't fulfill requested option Sep 04 09:46:17 ipa5.ipa.example.com krb5kdc[183962](info): ... CONSTRAINED-DELEGATION s4u-client=host/xoanon.ipa.example.com@IPA.EXAMPLE.COM Sep 04 09:46:17 ipa5.ipa.example.com krb5kdc[183962](info): closing down fd 12
It is HANDLE_AUTHDATA issue which is typically a sign of a PAC that cannot be generated. S4U (constrained delegation) operation requires PAC presence.
Since the client here is host/xoanon.ipa.example.com, this means this client most likely has no SID associated with it and cannot be associated with any of the two supported classes of PAC-enabled services: IPA servers and IPA clients. Otherwise it would have had a PAC in the ticket.
I just tried to simulate that with S4U2Self operation where HTTP/master.ipa.test service would pretend that it authenticate host/client.ipa.test via a different protocol and then asked for a service ticket to itself. We have a tool (ipa-print-pac) that allows to print the content of the PAC:
[root@master ~]# kinit -k -t /var/lib/ipa/gssproxy/http.keytab HTTP/master.ipa.test [root@master ~]# /usr/libexec/ipa/ipa-print-pac -E -k /var/lib/ipa/gssproxy/http.keytab impersonate host/client.ipa.test Acquired credentials for host/client.ipa.test PAC_DATA: struct PAC_DATA num_buffers : 0x00000008 (8) version : 0x00000000 (0) buffers: ARRAY(8) buffers: struct PAC_BUFFER type : PAC_TYPE_LOGON_INFO (1) _ndr_size : 0x000001e0 (480) info : * info : union PAC_INFO(case 1) logon_info: struct PAC_LOGON_INFO_CTR info : * info: struct PAC_LOGON_INFO info3: struct netr_SamInfo3 base: struct netr_SamBaseInfo logon_time : Mon Sep 4 13:39:23 2023 UTC logoff_time : Thu Sep 14 02:48:05 30828 UTC kickoff_time : Thu Sep 14 02:48:05 30828 UTC last_password_change : Mon Sep 4 13:37:22 2023 UTC allow_password_change : Mon Sep 4 13:37:22 2023 UTC force_password_change : Thu Sep 14 02:48:05 30828 UTC account_name: struct lsa_String length : 0x001e (30) size : 0x001e (30) string : * string : 'client.ipa.test' full_name: struct lsa_String length : 0x001e (30) size : 0x001e (30) string : * string : 'client.ipa.test' logon_script: struct lsa_String length : 0x0000 (0) size : 0x0000 (0) string : * string : '' profile_path: struct lsa_String length : 0x0000 (0) size : 0x0000 (0) string : * string : '' home_directory: struct lsa_String length : 0x0000 (0) size : 0x0000 (0) string : * string : '' home_drive: struct lsa_String length : 0x0000 (0) size : 0x0000 (0) string : * string : '' logon_count : 0x0000 (0) bad_password_count : 0x0000 (0) rid : 0x00000203 (515) primary_gid : 0x00000203 (515) groups: struct samr_RidWithAttributeArray count : 0x00000000 (0) rids : * rids: ARRAY(0) user_flags : 0x00000020 (32) 0: NETLOGON_GUEST 0: NETLOGON_NOENCRYPTION 0: NETLOGON_CACHED_ACCOUNT 0: NETLOGON_USED_LM_PASSWORD 1: NETLOGON_EXTRA_SIDS 0: NETLOGON_SUBAUTH_SESSION_KEY 0: NETLOGON_SERVER_TRUST_ACCOUNT 0: NETLOGON_NTLMV2_ENABLED 0: NETLOGON_RESOURCE_GROUPS 0: NETLOGON_PROFILE_PATH_RETURNED 0: NETLOGON_GRACE_LOGON key: struct netr_UserSessionKey key: ARRAY(16): <REDACTED SECRET VALUES> logon_server: struct lsa_StringLarge length : 0x000c (12) size : 0x000e (14) string : * string : 'MASTER' logon_domain: struct lsa_StringLarge length : 0x0006 (6) size : 0x0008 (8) string : * string : 'IPA' domain_sid : * domain_sid : S-1-5-21-2093978176-3761652416-3478956151 LMSessKey: struct netr_LMSessionKey key: ARRAY(8): <REDACTED SECRET VALUES> acct_flags : 0x00000080 (128) 0: ACB_DISABLED 0: ACB_HOMDIRREQ 0: ACB_PWNOTREQ 0: ACB_TEMPDUP 0: ACB_NORMAL 0: ACB_MNS 0: ACB_DOMTRUST 1: ACB_WSTRUST 0: ACB_SVRTRUST 0: ACB_PWNOEXP 0: ACB_AUTOLOCK 0: ACB_ENC_TXT_PWD_ALLOWED 0: ACB_SMARTCARD_REQUIRED 0: ACB_TRUSTED_FOR_DELEGATION 0: ACB_NOT_DELEGATED 0: ACB_USE_DES_KEY_ONLY 0: ACB_DONT_REQUIRE_PREAUTH 0: ACB_PW_EXPIRED 0: ACB_TRUSTED_TO_AUTHENTICATE_FOR_DELEGATION 0: ACB_NO_AUTH_DATA_REQD 0: ACB_PARTIAL_SECRETS_ACCOUNT 0: ACB_USE_AES_KEYS sub_auth_status : 0x00000000 (0) last_successful_logon : NTTIME(0) last_failed_logon : NTTIME(0) failed_logon_count : 0x00000000 (0) reserved : 0x00000000 (0) sidcount : 0x00000001 (1) sids : * sids: ARRAY(1) sids: struct netr_SidAttr sid : * sid : S-1-18-2 attributes : 0x00000007 (7) 1: SE_GROUP_MANDATORY 1: SE_GROUP_ENABLED_BY_DEFAULT 1: SE_GROUP_ENABLED 0: SE_GROUP_OWNER 0: SE_GROUP_USE_FOR_DENY_ONLY 0: SE_GROUP_INTEGRITY 0: SE_GROUP_INTEGRITY_ENABLED 0: SE_GROUP_RESOURCE 0x00: SE_GROUP_LOGON_ID (0) resource_groups: struct PAC_DOMAIN_GROUP_MEMBERSHIP domain_sid : NULL groups: struct samr_RidWithAttributeArray count : 0x00000000 (0) rids : NULL _pad : 0x00000000 (0) buffers: struct PAC_BUFFER type : PAC_TYPE_UPN_DNS_INFO (12) _ndr_size : 0x000000a2 (162) info : * info : union PAC_INFO(case 12) upn_dns_info: struct PAC_UPN_DNS_INFO upn_name_size : 0x003a (58) upn_name : * upn_name : 'host/client.ipa.test@IPA.TEST' dns_domain_name_size : 0x0010 (16) dns_domain_name : * dns_domain_name : 'IPA.TEST' flags : 0x00000002 (2) 0: PAC_UPN_DNS_FLAG_CONSTRUCTED 1: PAC_UPN_DNS_FLAG_HAS_SAM_NAME_AND_SID ex : union PAC_UPN_DNS_INFO_EX(case 2) sam_name_and_sid: struct PAC_UPN_DNS_INFO_SAM_NAME_AND_SID samaccountname_size : 0x001e (30) samaccountname : * samaccountname : 'client.ipa.test' objectsid_size : 0x001c (28) objectsid : * objectsid : S-1-5-21-2093978176-3761652416-3478956151-515 _pad : 0x00000000 (0) buffers: struct PAC_BUFFER type : PAC_TYPE_ATTRIBUTES_INFO (17) _ndr_size : 0x00000008 (8) info : * info : union PAC_INFO(case 17) attributes_info: struct PAC_ATTRIBUTES_INFO flags_length : 0x00000002 (2) flags : 0x00000002 (2) 0: PAC_ATTRIBUTE_FLAG_PAC_WAS_REQUESTED 1: PAC_ATTRIBUTE_FLAG_PAC_WAS_GIVEN_IMPLICITLY _pad : 0x00000000 (0) buffers: struct PAC_BUFFER type : PAC_TYPE_TICKET_CHECKSUM (16) _ndr_size : 0x0000001c (28) info : * info : union PAC_INFO(case 16) ticket_checksum: struct PAC_SIGNATURE_DATA type : 0x00000014 (20) signature : DATA_BLOB length=24 [0000] 58 2E 4D 1A 2D B3 3C 90 30 D5 72 82 BB 93 E4 87 X.M.-.<. 0.r..... [0010] 74 F6 75 4F 9C 1E 22 D5 t.uO..". _pad : 0x00000000 (0) buffers: struct PAC_BUFFER type : PAC_TYPE_LOGON_NAME (10) _ndr_size : 0x00000034 (52) info : * info : union PAC_INFO(case 10) logon_name: struct PAC_LOGON_NAME logon_time : Mon Sep 4 13:39:23 2023 UTC size : 0x002a (42) account_name : 'host/client.ipa.test' _pad : 0x00000000 (0) buffers: struct PAC_BUFFER type : PAC_TYPE_SRV_CHECKSUM (6) _ndr_size : 0x0000001c (28) info : * info : union PAC_INFO(case 6) srv_cksum: struct PAC_SIGNATURE_DATA type : 0x00000014 (20) signature : DATA_BLOB length=24 [0000] A5 D3 8A 27 C0 91 F1 A0 C3 A0 6A 1A 4D E6 62 F5 ...'.... ..j.M.b. [0010] EF 94 64 02 81 AC 2C A7 ..d...,. _pad : 0x00000000 (0) buffers: struct PAC_BUFFER type : PAC_TYPE_KDC_CHECKSUM (7) _ndr_size : 0x0000001c (28) info : * info : union PAC_INFO(case 7) kdc_cksum: struct PAC_SIGNATURE_DATA type : 0x00000014 (20) signature : DATA_BLOB length=24 [0000] 28 C3 C4 97 20 1A CE F2 33 49 85 B6 C8 2F 97 3E (... ... 3I.../.> [0010] 8B 65 E5 02 4A 03 6F B2 .e..J.o. _pad : 0x00000000 (0) buffers: struct PAC_BUFFER type : PAC_TYPE_FULL_CHECKSUM (19) _ndr_size : 0x0000001c (28) info : * info : union PAC_INFO(case 19) full_checksum: struct PAC_SIGNATURE_DATA type : 0x00000014 (20) signature : DATA_BLOB length=24 [0000] 54 F2 48 08 35 EB E4 F2 46 84 93 9F F9 5C 6B 62 T.H.5... F....\kb [0010] 0B 5E 51 50 FA 76 8E 60 .^QP.v.` _pad : 0x00000000 (0)
In case of a failure I would not be able to get PAC output like this.
I guess this is showing that HTTP/ipa5.ipa.example.com (the IPA API server) is trying to obtain a ticket to LDAP/ipa5.ipa.example.com on behalf of host/xoanon.ipa.example.com but the KDC is rejecting the request.
Correct.
If that's right then I guess I need to figure out why that might be. Unfortunately setting 'debug = true' in /etc/krb5.conf's [logging] section doesn't cause any more detailed messages to be logged.
krb5 library does not support debugging this way.
If I run gssproxy with --debug-level=2 I can see it logging some stuff but I guess it's just showing the calls that result in the kdc logging the above...
gssproxy is not involved in ticket issuance. It is a client app, effectively.
On Mon, Sep 04, 2023 at 04:42:59PM +0300, Alexander Bokovoy via FreeIPA-users wrote:
On Пан, 04 вер 2023, Sam Morris via FreeIPA-users wrote:
I've made some slight progress. I noticed that at the same time, the KDC logs these messages:
==> /var/log/krb5kdc.log <== Sep 04 09:46:17 ipa5.ipa.example.com krb5kdc[183962](info): TGS_REQ : handle_authdata (-1765328371) Sep 04 09:46:17 ipa5.ipa.example.com krb5kdc[183962](info): TGS_REQ (6 etypes {aes256-cts-hmac-sha1-96(18), aes256-cts-hmac-sha384-192(20), camellia256-cts-cmac(26), aes128-cts-hmac-sha1-96(17), aes128-cts-hmac-sha256-128(19), camellia128-cts-cmac(25)}) 192.168.88.5: HANDLE_AUTHDATA: authtime 1693820777, etypes {rep=UNSUPPORTED:(0)} HTTP/ipa5.ipa.example.com@IPA.EXAMPLE.COM for ldap/ipa5.ipa.example.com@IPA.EXAMPLE.COM, KDC can't fulfill requested option Sep 04 09:46:17 ipa5.ipa.example.com krb5kdc[183962](info): ... CONSTRAINED-DELEGATION s4u-client=host/xoanon.ipa.example.com@IPA.EXAMPLE.COM Sep 04 09:46:17 ipa5.ipa.example.com krb5kdc[183962](info): closing down fd 12
It is HANDLE_AUTHDATA issue which is typically a sign of a PAC that cannot be generated. S4U (constrained delegation) operation requires PAC presence.
Since the client here is host/xoanon.ipa.example.com, this means this client most likely has no SID associated with it and cannot be associated with any of the two supported classes of PAC-enabled services: IPA servers and IPA clients. Otherwise it would have had a PAC in the ticket.
Are hosts supposed to have a ipaNTSecurityIdentifier attribute or am I misunderstanding? None of my hosts do (at least according to 'ipa host-show --all --raw'), while my users do.
I just tried to simulate that with S4U2Self operation where HTTP/master.ipa.test service would pretend that it authenticate host/client.ipa.test via a different protocol and then asked for a service ticket to itself. We have a tool (ipa-print-pac) that allows to print the content of the PAC:
[root@master ~]# kinit -k -t /var/lib/ipa/gssproxy/http.keytab HTTP/master.ipa.test [root@master ~]# /usr/libexec/ipa/ipa-print-pac -E -k /var/lib/ipa/gssproxy/http.keytab impersonate host/client.ipa.test
Here's my output. There is one less buffer in my PAC: mine is missing the PAC_TYPE_TICKET_CHECKSUM buffer.
# /usr/libexec/ipa/ipa-print-pac -E -k /var/lib/ipa/gssproxy/http.keytab impersonate host/xoanon.ipa.example.com Acquired credentials for host/xoanon.ipa.example.com PAC_DATA: struct PAC_DATA num_buffers : 0x00000007 (7) version : 0x00000000 (0) buffers: ARRAY(7) buffers: struct PAC_BUFFER type : PAC_TYPE_LOGON_INFO (1) _ndr_size : 0x00000200 (512) info : * info : union PAC_INFO(case 1) logon_info: struct PAC_LOGON_INFO_CTR info : * info: struct PAC_LOGON_INFO info3: struct netr_SamInfo3 base: struct netr_SamBaseInfo logon_time : Mon Sep 4 17:17:03 2023 UTC logoff_time : Thu Sep 14 02:48:05 30828 UTC kickoff_time : Thu Sep 14 02:48:05 30828 UTC last_password_change : Fri Jun 4 15:02:46 2021 UTC allow_password_change : Fri Jun 4 15:02:46 2021 UTC force_password_change : Thu Sep 14 02:48:05 30828 UTC account_name: struct lsa_String length : 0x0030 (48) size : 0x0030 (48) string : * string : 'xoanon.ipa.example.com' full_name: struct lsa_String length : 0x0030 (48) size : 0x0030 (48) string : * string : 'xoanon.ipa.example.com' logon_script: struct lsa_String length : 0x0000 (0) size : 0x0000 (0) string : * string : '' profile_path: struct lsa_String length : 0x0000 (0) size : 0x0000 (0) string : * string : '' home_directory: struct lsa_String length : 0x0000 (0) size : 0x0000 (0) string : * string : '' home_drive: struct lsa_String length : 0x0000 (0) size : 0x0000 (0) string : * string : '' logon_count : 0x0000 (0) bad_password_count : 0x0000 (0) rid : 0x00000203 (515) primary_gid : 0x00000203 (515) groups: struct samr_RidWithAttributeArray count : 0x00000000 (0) rids : * rids: ARRAY(0) user_flags : 0x00000020 (32) 0: NETLOGON_GUEST 0: NETLOGON_NOENCRYPTION 0: NETLOGON_CACHED_ACCOUNT 0: NETLOGON_USED_LM_PASSWORD 1: NETLOGON_EXTRA_SIDS 0: NETLOGON_SUBAUTH_SESSION_KEY 0: NETLOGON_SERVER_TRUST_ACCOUNT 0: NETLOGON_NTLMV2_ENABLED 0: NETLOGON_RESOURCE_GROUPS 0: NETLOGON_PROFILE_PATH_RETURNED 0: NETLOGON_GRACE_LOGON key: struct netr_UserSessionKey key: ARRAY(16): <REDACTED SECRET VALUES> logon_server: struct lsa_StringLarge length : 0x0008 (8) size : 0x000a (10) string : * string : 'IPA5' logon_domain: struct lsa_StringLarge length : 0x000c (12) size : 0x000e (14) string : * string : 'EXAMPLE' domain_sid : * domain_sid : S-1-5-21-1341176315-1040986168-522724017 LMSessKey: struct netr_LMSessionKey key: ARRAY(8): <REDACTED SECRET VALUES> acct_flags : 0x00000080 (128) 0: ACB_DISABLED 0: ACB_HOMDIRREQ 0: ACB_PWNOTREQ 0: ACB_TEMPDUP 0: ACB_NORMAL 0: ACB_MNS 0: ACB_DOMTRUST 1: ACB_WSTRUST 0: ACB_SVRTRUST 0: ACB_PWNOEXP 0: ACB_AUTOLOCK 0: ACB_ENC_TXT_PWD_ALLOWED 0: ACB_SMARTCARD_REQUIRED 0: ACB_TRUSTED_FOR_DELEGATION 0: ACB_NOT_DELEGATED 0: ACB_USE_DES_KEY_ONLY 0: ACB_DONT_REQUIRE_PREAUTH 0: ACB_PW_EXPIRED 0: ACB_TRUSTED_TO_AUTHENTICATE_FOR_DELEGATION 0: ACB_NO_AUTH_DATA_REQD 0: ACB_PARTIAL_SECRETS_ACCOUNT 0: ACB_USE_AES_KEYS sub_auth_status : 0x00000000 (0) last_successful_logon : NTTIME(0) last_failed_logon : NTTIME(0) failed_logon_count : 0x00000000 (0) reserved : 0x00000000 (0) sidcount : 0x00000001 (1) sids : * sids: ARRAY(1) sids: struct netr_SidAttr sid : * sid : S-1-18-2 attributes : 0x00000007 (7) 1: SE_GROUP_MANDATORY 1: SE_GROUP_ENABLED_BY_DEFAULT 1: SE_GROUP_ENABLED 0: SE_GROUP_OWNER 0: SE_GROUP_USE_FOR_DENY_ONLY 0: SE_GROUP_INTEGRITY 0: SE_GROUP_INTEGRITY_ENABLED 0: SE_GROUP_RESOURCE 0x00: SE_GROUP_LOGON_ID (0) resource_groups: struct PAC_DOMAIN_GROUP_MEMBERSHIP domain_sid : NULL groups: struct samr_RidWithAttributeArray count : 0x00000000 (0) rids : NULL _pad : 0x00000000 (0) buffers: struct PAC_BUFFER type : PAC_TYPE_UPN_DNS_INFO (12) _ndr_size : 0x000000ec (236) info : * info : union PAC_INFO(case 12) upn_dns_info: struct PAC_UPN_DNS_INFO upn_name_size : 0x005e (94) upn_name : * upn_name : 'host/xoanon.ipa.example.com@IPA.EXAMPLE.COM' dns_domain_name_size : 0x0022 (34) dns_domain_name : * dns_domain_name : 'IPA.EXAMPLE.COM' flags : 0x00000002 (2) 0: PAC_UPN_DNS_FLAG_CONSTRUCTED 1: PAC_UPN_DNS_FLAG_HAS_SAM_NAME_AND_SID ex : union PAC_UPN_DNS_INFO_EX(case 2) sam_name_and_sid: struct PAC_UPN_DNS_INFO_SAM_NAME_AND_SID samaccountname_size : 0x0030 (48) samaccountname : * samaccountname : 'xoanon.ipa.example.com' objectsid_size : 0x001c (28) objectsid : * objectsid : S-1-5-21-1341176315-1040986168-522724017-515 _pad : 0x00000000 (0) buffers: struct PAC_BUFFER type : PAC_TYPE_ATTRIBUTES_INFO (17) _ndr_size : 0x00000008 (8) info : * info : union PAC_INFO(case 17) attributes_info: struct PAC_ATTRIBUTES_INFO flags_length : 0x00000002 (2) flags : 0x00000002 (2) 0: PAC_ATTRIBUTE_FLAG_PAC_WAS_REQUESTED 1: PAC_ATTRIBUTE_FLAG_PAC_WAS_GIVEN_IMPLICITLY _pad : 0x00000000 (0) buffers: struct PAC_BUFFER type : PAC_TYPE_LOGON_NAME (10) _ndr_size : 0x00000046 (70) info : * info : union PAC_INFO(case 10) logon_name: struct PAC_LOGON_NAME logon_time : Mon Sep 4 17:17:03 2023 UTC size : 0x003c (60) account_name : 'host/xoanon.ipa.example.com' _pad : 0x00000000 (0) buffers: struct PAC_BUFFER type : PAC_TYPE_SRV_CHECKSUM (6) _ndr_size : 0x00000010 (16) info : * info : union PAC_INFO(case 6) srv_cksum: struct PAC_SIGNATURE_DATA type : 0x00000010 (16) signature : DATA_BLOB length=12 [0000] 3B 51 6F E5 9D 90 7A 5F 8D 39 83 7D ;Qo...z_ .9.} _pad : 0x00000000 (0) buffers: struct PAC_BUFFER type : PAC_TYPE_KDC_CHECKSUM (7) _ndr_size : 0x00000010 (16) info : * info : union PAC_INFO(case 7) kdc_cksum: struct PAC_SIGNATURE_DATA type : 0x00000010 (16) signature : DATA_BLOB length=12 [0000] F3 F2 5B CC CB FC 9F EC E2 99 7D E8 ..[..... ..}. _pad : 0x00000000 (0) buffers: struct PAC_BUFFER type : PAC_TYPE_FULL_CHECKSUM (19) _ndr_size : 0x00000010 (16) info : * info : union PAC_INFO(case 19) full_checksum: struct PAC_SIGNATURE_DATA type : 0x00000010 (16) signature : DATA_BLOB length=12 [0000] B9 F3 A3 DB C6 1A 9D 17 B1 8E 26 E9 ........ ..&. _pad : 0x00000000 (0)
... other than that it looks similar.
I get the same when I run it on ipa3 (also running RHEL 8).
If I run it on ipa6 (RHEL 9) I get all 8 buffers including PAC_TYPE_TICKET_CHECKSUM..
On Mon, Sep 04, 2023 at 06:43:02PM +0100, Sam Morris via FreeIPA-users wrote:
I get the same when I run it on ipa3 (also running RHEL 8).
I changed 'server' in /etc/ipa/default.conf to point to this server and I see the same errors:
Sep 05 14:02:49 ipa3.ipa.example.com krb5kdc[1715](info): TGS_REQ : handle_authdata (-1765328371) Sep 05 14:02:49 ipa3.ipa.example.com krb5kdc[1715](info): TGS_REQ (6 etypes {aes256-cts-hmac-sha1-96(18), aes256-cts-hmac-sha384-192(20), camellia256-cts-cmac(26), aes128-cts-hmac-sha1-96(17), aes128-cts-hmac-sha256-128(19), camellia128-cts-cmac(25)}) 157.90.149.68: HANDLE_AUTHDATA: authtime 1693922568, etypes {rep=UNSUPPORTED:(0)} HTTP/ipa3.ipa.example.com@IPA.EXAMPLE.COM for ldap/ipa3.ipa.example.com@IPA.EXAMPLE.COM, KDC can't fulfill requested option Sep 05 14:02:49 ipa3.ipa.example.com krb5kdc[1715](info): ... CONSTRAINED-DELEGATION s4u-client=host/xoanon.ipa.example.com@IPA.EXAMPLE.COM
I had a look through the kdc logs with the following command:
$ grep -h -A2 'TGS_REQ : handle_authdata' /var/log/krb5kdc.log-* /var/log/krb5kdc.log
... and the results are interesting. It seems that since May 12, my RHEL 8 servers started refusing to perform constrained delegation requests for both user and host/service principals.
The failures for users stopped after I ran 'ipa config-mod --enable-sid --add-sids' as kindly recommended by Alex in the thread at https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedorahosted.org/thread/RSAXURG6AR3MWONR3CZSOOI5ULDB2UVC/.
But since then, the RHEL 8 servers have continued to fail to process constrained delegation requests on behalf of host and service principals.
In another reply in this thread, Alex wrote:
Since the client here is host/xoanon.ipa.example.com, this means this client most likely has no SID associated with it and cannot be associated with any of the two supported classes of PAC-enabled services: IPA servers and IPA clients. Otherwise it would have had a PAC in the ticket.
Now that I understand a little more about what's going on I have found that I can reproduce this problem without having to involve dogtag and certmonger.
I believe this problem prevents any IPA API from a host or service princpal from succeding, when the request is being processed on a RHEL 8 server, for the reason that the kdc refuses the constrained delegation request made by the API to get a ticket to the ldap server on behalf of the client.
[root@xoanon ~]# KRB5_CLIENT_KTNAME=/etc/hitron-exporter.keytab kinit -V -c /tmp/hitron.cc -k -i Using specified cache: /tmp/hitron.cc Using principal: HTTP/hitron-exporter.ipa.example.com@IPA.EXAMPLE.COM Authenticated to Kerberos v5
[root@xoanon ~]# KRB5CCNAME=/tmp/hitron.cc ipa -d service-show HTTP/hitron-exporter.ipa.example.com [...] ipa: DEBUG: trying https://ipa5.ipa.example.com/ipa/session/json ipa: DEBUG: New HTTP connection (ipa5.ipa.example.com) ipa: DEBUG: HTTP connection destroyed (ipa5.ipa.example.com) Traceback (most recent call last): File "/usr/lib/python3.6/site-packages/ipalib/rpc.py", line 730, in single_request response.msg) xmlrpc.client.ProtocolError: <ProtocolError for ipa5.ipa.example.com/ipa/session/json: 401 Unauthorized> ipa: DEBUG: trying https://ipa5.ipa.example.com/ipa/session/json ipa: DEBUG: New HTTP connection (ipa5.ipa.example.com) ipa: DEBUG: HTTP connection destroyed (ipa5.ipa.example.com) Traceback (most recent call last): File "/usr/lib/python3.6/site-packages/ipalib/rpc.py", line 730, in single_request response.msg) xmlrpc.client.ProtocolError: <ProtocolError for ipa5.ipa.example.com/ipa/session/json: 401 Unauthorized> ipa: INFO: Connection to https://ipa5.ipa.example.com/ipa/session/json failed with <ProtocolError for ipa5.ipa.example.com/ipa/session/json: 401 Unauthorized> [... client goes on to try ipa6, an RHEL 9 server, which works ...]
On ipa5:
Sep 05 14:53:10 ipa5.ipa.example.com krb5kdc[223385](info): TGS_REQ : handle_authdata (-1765328371) Sep 05 14:53:10 ipa5.ipa.example.com krb5kdc[223385](info): TGS_REQ (6 etypes {aes256-cts-hmac-sha1-96(18), aes256-cts-hmac-sha384-192(20), camellia256-cts-cmac(26), aes128-cts-hmac-sha1-96(17), aes128-cts-hmac-sha256-128(19), camellia128-cts-cmac(25)}) 192.168.88.5: HANDLE_AUTHDATA: authtime 1693925569, etypes {rep=UNSUPPORTED:(0)} HTTP/ipa5.ipa.example.com@IPA.EXAMPLE.COM for ldap/ipa5.ipa.example.com@IPA.EXAMPLE.COM, KDC can't fulfill requested option Sep 05 14:53:10 ipa5.ipa.example.com krb5kdc[223385](info): ... CONSTRAINED-DELEGATION s4u-client=HTTP/hitron-exporter.ipa.example.com@IPA.EXAMPLE.COM
In most cases python-ipaclient automatically retries, and eventually hits a RHEL 9 server which is why I hadn't noticed until now. It's only certmonger's ipa-getcert command that gives up immediately instead of trying another server.
If you're reading along and have an up-to-date RHEL 8 environment, please try calling the IPA API on behalf of a host or service principal and report the result. In the mean time I'll see if I can reproduce this on a fresh CentOS Stream 8 server.
On Аўт, 05 вер 2023, Sam Morris via FreeIPA-users wrote:
On Mon, Sep 04, 2023 at 06:43:02PM +0100, Sam Morris via FreeIPA-users wrote:
I get the same when I run it on ipa3 (also running RHEL 8).
I changed 'server' in /etc/ipa/default.conf to point to this server and I see the same errors:
Sep 05 14:02:49 ipa3.ipa.example.com krb5kdc[1715](info): TGS_REQ : handle_authdata (-1765328371) Sep 05 14:02:49 ipa3.ipa.example.com krb5kdc[1715](info): TGS_REQ (6 etypes {aes256-cts-hmac-sha1-96(18), aes256-cts-hmac-sha384-192(20), camellia256-cts-cmac(26), aes128-cts-hmac-sha1-96(17), aes128-cts-hmac-sha256-128(19), camellia128-cts-cmac(25)}) 157.90.149.68: HANDLE_AUTHDATA: authtime 1693922568, etypes {rep=UNSUPPORTED:(0)} HTTP/ipa3.ipa.example.com@IPA.EXAMPLE.COM for ldap/ipa3.ipa.example.com@IPA.EXAMPLE.COM, KDC can't fulfill requested option Sep 05 14:02:49 ipa3.ipa.example.com krb5kdc[1715](info): ... CONSTRAINED-DELEGATION s4u-client=host/xoanon.ipa.example.com@IPA.EXAMPLE.COM
I had a look through the kdc logs with the following command:
$ grep -h -A2 'TGS_REQ : handle_authdata' /var/log/krb5kdc.log-* /var/log/krb5kdc.log
... and the results are interesting. It seems that since May 12, my RHEL 8 servers started refusing to perform constrained delegation requests for both user and host/service principals.
The failures for users stopped after I ran 'ipa config-mod --enable-sid --add-sids' as kindly recommended by Alex in the thread at https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedorahosted.org/thread/RSAXURG6AR3MWONR3CZSOOI5ULDB2UVC/.
But since then, the RHEL 8 servers have continued to fail to process constrained delegation requests on behalf of host and service principals.
In another reply in this thread, Alex wrote:
Since the client here is host/xoanon.ipa.example.com, this means this client most likely has no SID associated with it and cannot be associated with any of the two supported classes of PAC-enabled services: IPA servers and IPA clients. Otherwise it would have had a PAC in the ticket.
Now that I understand a little more about what's going on I have found that I can reproduce this problem without having to involve dogtag and certmonger.
I believe this problem prevents any IPA API from a host or service princpal from succeding, when the request is being processed on a RHEL 8 server, for the reason that the kdc refuses the constrained delegation request made by the API to get a ticket to the ldap server on behalf of the client.
[root@xoanon ~]# KRB5_CLIENT_KTNAME=/etc/hitron-exporter.keytab kinit -V -c /tmp/hitron.cc -k -i Using specified cache: /tmp/hitron.cc Using principal: HTTP/hitron-exporter.ipa.example.com@IPA.EXAMPLE.COM Authenticated to Kerberos v5
[root@xoanon ~]# KRB5CCNAME=/tmp/hitron.cc ipa -d service-show HTTP/hitron-exporter.ipa.example.com [...] ipa: DEBUG: trying https://ipa5.ipa.example.com/ipa/session/json ipa: DEBUG: New HTTP connection (ipa5.ipa.example.com) ipa: DEBUG: HTTP connection destroyed (ipa5.ipa.example.com) Traceback (most recent call last): File "/usr/lib/python3.6/site-packages/ipalib/rpc.py", line 730, in single_request response.msg) xmlrpc.client.ProtocolError: <ProtocolError for ipa5.ipa.example.com/ipa/session/json: 401 Unauthorized> ipa: DEBUG: trying https://ipa5.ipa.example.com/ipa/session/json ipa: DEBUG: New HTTP connection (ipa5.ipa.example.com) ipa: DEBUG: HTTP connection destroyed (ipa5.ipa.example.com) Traceback (most recent call last): File "/usr/lib/python3.6/site-packages/ipalib/rpc.py", line 730, in single_request response.msg) xmlrpc.client.ProtocolError: <ProtocolError for ipa5.ipa.example.com/ipa/session/json: 401 Unauthorized> ipa: INFO: Connection to https://ipa5.ipa.example.com/ipa/session/json failed with <ProtocolError for ipa5.ipa.example.com/ipa/session/json: 401 Unauthorized> [... client goes on to try ipa6, an RHEL 9 server, which works ...]
On ipa5:
Sep 05 14:53:10 ipa5.ipa.example.com krb5kdc[223385](info): TGS_REQ : handle_authdata (-1765328371) Sep 05 14:53:10 ipa5.ipa.example.com krb5kdc[223385](info): TGS_REQ (6 etypes {aes256-cts-hmac-sha1-96(18), aes256-cts-hmac-sha384-192(20), camellia256-cts-cmac(26), aes128-cts-hmac-sha1-96(17), aes128-cts-hmac-sha256-128(19), camellia128-cts-cmac(25)}) 192.168.88.5: HANDLE_AUTHDATA: authtime 1693925569, etypes {rep=UNSUPPORTED:(0)} HTTP/ipa5.ipa.example.com@IPA.EXAMPLE.COM for ldap/ipa5.ipa.example.com@IPA.EXAMPLE.COM, KDC can't fulfill requested option Sep 05 14:53:10 ipa5.ipa.example.com krb5kdc[223385](info): ... CONSTRAINED-DELEGATION s4u-client=HTTP/hitron-exporter.ipa.example.com@IPA.EXAMPLE.COM
In most cases python-ipaclient automatically retries, and eventually hits a RHEL 9 server which is why I hadn't noticed until now. It's only certmonger's ipa-getcert command that gives up immediately instead of trying another server.
If you're reading along and have an up-to-date RHEL 8 environment, please try calling the IPA API on behalf of a host or service principal and report the result. In the mean time I'll see if I can reproduce this on a fresh CentOS Stream 8 server.
Thanks for these details.
It may well be either IPA part in https://pagure.io/freeipa/blob/master/f/daemons/ipa-kdb/ipa_kdb_mspac_v6.c#_... which means we have more than one PAC buffer returned (unlikely), or ipadb_check_allowed_to_delegate returns incorrect result.
The latter was fixed quite some time ago and should be in 4.9.11+:
either commit e86807b58c67a607bceb568d206af3b3abc03dea
ipa-kdb: handle empty S4U proxy in allowed_to_delegate
With krb5 1.20, S4U processing code uses a special case of passing an empty S4U proxy to allowed_to_delegate() callback to identify if the server cannot get forwardable S4U2Self tickets according to [MS-PAC] 3.2.5.1.2.
This means we need to ensure NULL proxy is a valid one and return an appropriate response to that.
Fixes: https://pagure.io/freeipa/issue/9083
or commit commit 21d99b457d688528bf7e4dcd64d20f7189d16fec
ipa-kdb: for delegation check, use different error codes before and after krb5 1.20
With MIT krb5 1.20, a call to krb5_db_check_allowed_to_delegate() and krb5_db_check_allowed_to_delegate_from() expects to return either KRB5KDC_ERR_BADOPTION for a policy denial or KRB5_PLUGIN_OP_NOTSUPP in case plugin does not handle the policy case. This is part of the MIT krb5 commit a441fbe329ebbd7775eb5d4ccc4a05eef370f08b which added a minimal MS-PAC generator.
Prior to MIT krb5 1.20, the same call was expected to return either KRB5KDC_ERR_POLICY or KRB5_PLUGIN_OP_NOTSUPP errors.
Related: https://pagure.io/freeipa/issue/9083
Since you are saying it started after May 2023, that might be actually the 4.9.11 change. This would affect services which have no constrained delegation rules on defined.
I guess it is actually the first one, may be it is incomplete and returns wrong error code back to krb5 which it doesn't expect.
Can you please give exact versions of krb5 and ipa packages?
Finally, it could be code in handle_signticket() in krb5 1.18 where AD-SIGNEDPATH authdata element is missing. The latter is unlikely too.
On Tue, Sep 05, 2023 at 08:14:28PM +0300, Alexander Bokovoy via FreeIPA-users wrote:
Since you are saying it started after May 2023, that might be actually the 4.9.11 change. This would affect services which have no constrained delegation rules on defined.
I guess that explains why, if I kinit with e.g. host/ipa3.ipa.example.com, I can make IPA API calls just fine. It's only if I kinit as a non IPA server host or service do I see these errors.
Can you please give exact versions of krb5 and ipa packages?
That would be:
krb5-server-1.18.2-25.el8_8.x86_64 ipa-server-4.9.11-6.module+el8.8.0+19022+e8902f4b.x86_64
On Tue, Sep 05, 2023 at 07:22:51PM +0100, Sam Morris via FreeIPA-users wrote:
On Tue, Sep 05, 2023 at 08:14:28PM +0300, Alexander Bokovoy via FreeIPA-users wrote:
Since you are saying it started after May 2023, that might be actually the 4.9.11 change. This would affect services which have no constrained delegation rules on defined.
I guess that explains why, if I kinit with e.g. host/ipa3.ipa.example.com, I can make IPA API calls just fine. It's only if I kinit as a non IPA server host or service do I see these errors.
Actually there could be something else going on here.
I wanted to see what would happen if I copied the keytab for HTTP/hitron-exporter.ipa.example.com to ipa5 and ipa6, and ran kinit over there, then copied the ccaches from the servers back to xoanon, and used each of them to run 'ipa -d user-show admin'.
This would tell me if there was something particular about the credentials cache generated by running kinit on xoanon as opposed to either of the IPA servers.
Unfortunately what I've found is that I can now no longer reproduce the constrained delegation request failures!
I tried re-running the original 'getcert resubmit' command that sent me down this rabbit hole and... it also worked.
So I'm now really confused... I didn't change the configuration on any IPA server while working on the above, or even restart any services--the RHEL 8 IPA servers just started to issue the tickets via the API server's constrained delegation requests seemingly without any further intervention from me...
Argh!
Can you please give exact versions of krb5 and ipa packages?
That would be:
krb5-server-1.18.2-25.el8_8.x86_64 ipa-server-4.9.11-6.module+el8.8.0+19022+e8902f4b.x86_64
For the record, on xoanon the IPA client I have:
krb5-workstation-1.18.2-25.el8_8.x86_64 ipa-client-4.9.11-5.module+el8.8.0+18147+84fe6ec1.x86_64
On Аўт, 05 вер 2023, Sam Morris wrote:
On Tue, Sep 05, 2023 at 07:22:51PM +0100, Sam Morris via FreeIPA-users wrote:
On Tue, Sep 05, 2023 at 08:14:28PM +0300, Alexander Bokovoy via FreeIPA-users wrote:
Since you are saying it started after May 2023, that might be actually the 4.9.11 change. This would affect services which have no constrained delegation rules on defined.
I guess that explains why, if I kinit with e.g. host/ipa3.ipa.example.com, I can make IPA API calls just fine. It's only if I kinit as a non IPA server host or service do I see these errors.
Actually there could be something else going on here.
I wanted to see what would happen if I copied the keytab for HTTP/hitron-exporter.ipa.example.com to ipa5 and ipa6, and ran kinit over there, then copied the ccaches from the servers back to xoanon, and used each of them to run 'ipa -d user-show admin'.
This would tell me if there was something particular about the credentials cache generated by running kinit on xoanon as opposed to either of the IPA servers.
Unfortunately what I've found is that I can now no longer reproduce the constrained delegation request failures!
I tried re-running the original 'getcert resubmit' command that sent me down this rabbit hole and... it also worked.
So I'm now really confused... I didn't change the configuration on any IPA server while working on the above, or even restart any services--the RHEL 8 IPA servers just started to issue the tickets via the API server's constrained delegation requests seemingly without any further intervention from me...
It would help to see logs (krb5kdc.log) from RHEL8 servers for this communication, both on ipa5/ipa6 and back to xoanon.
On Wed, Sep 06, 2023 at 02:50:32PM +0300, Alexander Bokovoy via FreeIPA-users wrote:
It would help to see logs (krb5kdc.log) from RHEL8 servers for this communication, both on ipa5/ipa6 and back to xoanon.
I've created a script to test this automatically.
[root@xoanon ~]# (set -eu; export SSSD_KRB5_LOCATOR_DISABLE=1; for tgt in 5 6; do for st in 5 6; do for ipa in 5 6; do (export KRB5CCNAME=/tmp/ipa-$tgt-$st-$ipa.cc; KRB5_CONFIG=/tmp/krb5-ipa${tgt}-min.conf kinit -k; if KRB5_CONFIG=/tmp/krb5-ipa${st}-min.conf ipa -v -e xmlrpc_uri=https://ipa$%7Bipa%7D.ipa.example.com/ipa/xml user-show admin 2>&1 | grep -q 'GSSAPI Error'; then result=FAIL; else result=OK; fi; echo $tgt $st $ipa $result); done; done; done) 5 5 5 OK 5 5 6 OK 5 6 5 FAIL 5 6 6 OK 6 5 5 OK 6 5 6 OK 6 6 5 FAIL 6 6 6 OK
Each test case is a line. The numbers tell you:
* which KDC gave the TGT to the client * which KDC gave the ST for the IPA API to the client * which IPA server the client made the API request to
... followed by the result.
Analysing the output, it seems that the IPA API running on the RHEL 8 server is not able to perform its constrained delegation request using an evidence ticket that was generated by the RHEL 9 server.
The KDC from which the client obtains its TGT doesn't affect the result.
Here are the krb5.conf files used in the testing:
[root@xoanon ~]# cat /tmp/krb5-ipa5-min.conf include /etc/krb5.conf
[realms] IPA.EXAMPLE.COM = { kdc = ipa5.ipa.example.com }
[root@xoanon ~]# cat /tmp/krb5-ipa5-min.conf include /etc/krb5.conf
[realms] IPA.EXAMPLE.COM = { kdc = ipa5.ipa.example.com }
(BTW, is there something I can put into /etc/ipa/default.conf to prevent the ipa client from reacting to the error from the server under test by making another request to another server? It would cut down on noise in the output/logs).
Here are the log messages from one of the failed test cases, first we see the service ticket for ipa5 being requested fron ipa6:
Sep 07 09:24:40 ipa6.ipa.example.com krb5kdc[207733](info): TGS_REQ (6 etypes {aes256-cts-hmac-sha1-96(18), aes256-cts-hmac-sha384-192(20), camellia256-cts-cmac(26), aes128-cts-hmac-sha1-96(17), aes128-cts-hmac-sha256-128(19), camellia128-cts-cmac(25)}) 192.168.88.3: ISSUE: authtime 1694078668, etypes {rep=aes256-cts-hmac-sha1-96(18), tkt=aes256-cts-hmac-sha1-96(18), ses=aes256-cts-hmac-sha1-96(18)}, host/xoanon.ipa.example.com@IPA.EXAMPLE.COM for HTTP/ipa5.ipa.example.com@IPA.EXAMPLE.COM Sep 07 09:24:40 ipa6.ipa.example.com krb5kdc[207733](info): closing down fd 11
Then on ipa5 we see the constrained delegation request from its API server fail:
Sep 07 09:24:40 ipa5.ipa.example.com krb5kdc[239017](info): TGS_REQ : handle_authdata (-1765328371) Sep 07 09:24:40 ipa5.ipa.example.com krb5kdc[239017](info): TGS_REQ (6 etypes {aes256-cts-hmac-sha1-96(18), aes256-cts-hmac-sha384-192(20), camellia256-cts-cmac(26), aes128-cts-hmac-sha1-96(17), aes128-cts-hmac-sha256-128(19), camellia128-cts-cmac(25)}) 192.168.88.5: HANDLE_AUTHDATA: authtime 1694078668, etypes {rep=UNSUPPORTED:(0)} HTTP/ipa5.ipa.example.com@IPA.EXAMPLE.COM for ldap/ipa5.ipa.example.com@IPA.EXAMPLE.COM, KDC can't fulfill requested option Sep 07 09:24:40 ipa5.ipa.example.com krb5kdc[239017](info): ... CONSTRAINED-DELEGATION s4u-client=host/xoanon.ipa.example.com@IPA.EXAMPLE.COM Sep 07 09:24:40 ipa5.ipa.example.com krb5kdc[239017](info): closing down fd 12
Finally on ipa6 we see the client retrying its API request against ipa6, which involves fetching the service ticket for HTTP/ipa6, followed by ipa6's own constrained delegation request (actaully there are two, and I don't know why, not that it matters).
Sep 07 09:24:40 ipa6.ipa.example.com krb5kdc[207732](info): TGS_REQ (6 etypes {aes256-cts-hmac-sha1-96(18), aes256-cts-hmac-sha384-192(20), camellia256-cts-cmac(26), aes128-cts-hmac-sha1-96(17), aes128-cts-hmac-sha256-128(19), camellia128-cts-cmac(25)}) 192.168.88.3: ISSUE: authtime 1694078668, etypes {rep=aes256-cts-hmac-sha1-96(18), tkt=aes256-cts-hmac-sha1-96(18), ses=aes256-cts-hmac-sha1-96(18)}, host/xoanon.ipa.example.com@IPA.EXAMPLE.COM for HTTP/ipa6.ipa.example.com@IPA.EXAMPLE.COM Sep 07 09:24:40 ipa6.ipa.example.com krb5kdc[207732](info): closing down fd 11 Sep 07 09:24:40 ipa6.ipa.example.com krb5kdc[207733](info): TGS_REQ (4 etypes {aes256-cts-hmac-sha1-96(18), aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes128-cts-hmac-sha1-96(17)}) 192.168.88.6: ISSUE: authtime 1694078668, etypes {rep=aes256-cts-hmac-sha1-96(18), tkt=aes256-cts-hmac-sha1-96(18), ses=aes256-cts-hmac-sha1-96(18)}, HTTP/ipa6.ipa.example.com@IPA.EXAMPLE.COM for ldap/ipa6.ipa.example.com@IPA.EXAMPLE.COM Sep 07 09:24:40 ipa6.ipa.example.com krb5kdc[207733](info): ... CONSTRAINED-DELEGATION s4u-client=host/xoanon.ipa.example.com@IPA.EXAMPLE.COM Sep 07 09:24:40 ipa6.ipa.example.com krb5kdc[207733](info): closing down fd 11 Sep 07 09:24:40 ipa6.ipa.example.com krb5kdc[207732](info): TGS_REQ (4 etypes {aes256-cts-hmac-sha1-96(18), aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes128-cts-hmac-sha1-96(17)}) 192.168.88.6: ISSUE: authtime 1694078668, etypes {rep=aes256-cts-hmac-sha1-96(18), tkt=aes256-cts-hmac-sha1-96(18), ses=aes256-cts-hmac-sha1-96(18)}, HTTP/ipa6.ipa.example.com@IPA.EXAMPLE.COM for ldap/ipa6.ipa.example.com@IPA.EXAMPLE.COM Sep 07 09:24:40 ipa6.ipa.example.com krb5kdc[207732](info): ... CONSTRAINED-DELEGATION s4u-client=host/xoanon.ipa.example.com@IPA.EXAMPLE.COM Sep 07 09:24:40 ipa6.ipa.example.com krb5kdc[207732](info): closing down fd 11
If you want the full logs from the servers and/or the full debug output from the client just let me know and I'll collect them up and mail them to you.
On Чцв, 07 вер 2023, Sam Morris wrote:
On Wed, Sep 06, 2023 at 02:50:32PM +0300, Alexander Bokovoy via FreeIPA-users wrote:
It would help to see logs (krb5kdc.log) from RHEL8 servers for this communication, both on ipa5/ipa6 and back to xoanon.
I've created a script to test this automatically.
Thank you!
I filed https://pagure.io/freeipa/issue/9448 to track this issue. I'll be on vacation next week and Julien (krb5 maintainer) is on vacation too, so we'll look at it after we are both back to work.
[root@xoanon ~]# (set -eu; export SSSD_KRB5_LOCATOR_DISABLE=1; for tgt in 5 6; do for st in 5 6; do for ipa in 5 6; do (export KRB5CCNAME=/tmp/ipa-$tgt-$st-$ipa.cc; KRB5_CONFIG=/tmp/krb5-ipa${tgt}-min.conf kinit -k; if KRB5_CONFIG=/tmp/krb5-ipa${st}-min.conf ipa -v -e xmlrpc_uri=https://ipa$%7Bipa%7D.ipa.example.com/ipa/xml user-show admin 2>&1 | grep -q 'GSSAPI Error'; then result=FAIL; else result=OK; fi; echo $tgt $st $ipa $result); done; done; done) 5 5 5 OK 5 5 6 OK 5 6 5 FAIL 5 6 6 OK 6 5 5 OK 6 5 6 OK 6 6 5 FAIL 6 6 6 OK
Each test case is a line. The numbers tell you:
- which KDC gave the TGT to the client
- which KDC gave the ST for the IPA API to the client
- which IPA server the client made the API request to
... followed by the result.
Analysing the output, it seems that the IPA API running on the RHEL 8 server is not able to perform its constrained delegation request using an evidence ticket that was generated by the RHEL 9 server.
The KDC from which the client obtains its TGT doesn't affect the result.
Here are the krb5.conf files used in the testing:
[root@xoanon ~]# cat /tmp/krb5-ipa5-min.conf include /etc/krb5.conf
[realms] IPA.EXAMPLE.COM = { kdc = ipa5.ipa.example.com }
[root@xoanon ~]# cat /tmp/krb5-ipa5-min.conf include /etc/krb5.conf
[realms] IPA.EXAMPLE.COM = { kdc = ipa5.ipa.example.com }
(BTW, is there something I can put into /etc/ipa/default.conf to prevent the ipa client from reacting to the error from the server under test by making another request to another server? It would cut down on noise in the output/logs).
Here are the log messages from one of the failed test cases, first we see the service ticket for ipa5 being requested fron ipa6:
Sep 07 09:24:40 ipa6.ipa.example.com krb5kdc[207733](info): TGS_REQ (6 etypes {aes256-cts-hmac-sha1-96(18), aes256-cts-hmac-sha384-192(20), camellia256-cts-cmac(26), aes128-cts-hmac-sha1-96(17), aes128-cts-hmac-sha256-128(19), camellia128-cts-cmac(25)}) 192.168.88.3: ISSUE: authtime 1694078668, etypes {rep=aes256-cts-hmac-sha1-96(18), tkt=aes256-cts-hmac-sha1-96(18), ses=aes256-cts-hmac-sha1-96(18)}, host/xoanon.ipa.example.com@IPA.EXAMPLE.COM for HTTP/ipa5.ipa.example.com@IPA.EXAMPLE.COM Sep 07 09:24:40 ipa6.ipa.example.com krb5kdc[207733](info): closing down fd 11
Then on ipa5 we see the constrained delegation request from its API server fail:
Sep 07 09:24:40 ipa5.ipa.example.com krb5kdc[239017](info): TGS_REQ : handle_authdata (-1765328371) Sep 07 09:24:40 ipa5.ipa.example.com krb5kdc[239017](info): TGS_REQ (6 etypes {aes256-cts-hmac-sha1-96(18), aes256-cts-hmac-sha384-192(20), camellia256-cts-cmac(26), aes128-cts-hmac-sha1-96(17), aes128-cts-hmac-sha256-128(19), camellia128-cts-cmac(25)}) 192.168.88.5: HANDLE_AUTHDATA: authtime 1694078668, etypes {rep=UNSUPPORTED:(0)} HTTP/ipa5.ipa.example.com@IPA.EXAMPLE.COM for ldap/ipa5.ipa.example.com@IPA.EXAMPLE.COM, KDC can't fulfill requested option Sep 07 09:24:40 ipa5.ipa.example.com krb5kdc[239017](info): ... CONSTRAINED-DELEGATION s4u-client=host/xoanon.ipa.example.com@IPA.EXAMPLE.COM Sep 07 09:24:40 ipa5.ipa.example.com krb5kdc[239017](info): closing down fd 12
Finally on ipa6 we see the client retrying its API request against ipa6, which involves fetching the service ticket for HTTP/ipa6, followed by ipa6's own constrained delegation request (actaully there are two, and I don't know why, not that it matters).
Sep 07 09:24:40 ipa6.ipa.example.com krb5kdc[207732](info): TGS_REQ (6 etypes {aes256-cts-hmac-sha1-96(18), aes256-cts-hmac-sha384-192(20), camellia256-cts-cmac(26), aes128-cts-hmac-sha1-96(17), aes128-cts-hmac-sha256-128(19), camellia128-cts-cmac(25)}) 192.168.88.3: ISSUE: authtime 1694078668, etypes {rep=aes256-cts-hmac-sha1-96(18), tkt=aes256-cts-hmac-sha1-96(18), ses=aes256-cts-hmac-sha1-96(18)}, host/xoanon.ipa.example.com@IPA.EXAMPLE.COM for HTTP/ipa6.ipa.example.com@IPA.EXAMPLE.COM Sep 07 09:24:40 ipa6.ipa.example.com krb5kdc[207732](info): closing down fd 11 Sep 07 09:24:40 ipa6.ipa.example.com krb5kdc[207733](info): TGS_REQ (4 etypes {aes256-cts-hmac-sha1-96(18), aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes128-cts-hmac-sha1-96(17)}) 192.168.88.6: ISSUE: authtime 1694078668, etypes {rep=aes256-cts-hmac-sha1-96(18), tkt=aes256-cts-hmac-sha1-96(18), ses=aes256-cts-hmac-sha1-96(18)}, HTTP/ipa6.ipa.example.com@IPA.EXAMPLE.COM for ldap/ipa6.ipa.example.com@IPA.EXAMPLE.COM Sep 07 09:24:40 ipa6.ipa.example.com krb5kdc[207733](info): ... CONSTRAINED-DELEGATION s4u-client=host/xoanon.ipa.example.com@IPA.EXAMPLE.COM Sep 07 09:24:40 ipa6.ipa.example.com krb5kdc[207733](info): closing down fd 11 Sep 07 09:24:40 ipa6.ipa.example.com krb5kdc[207732](info): TGS_REQ (4 etypes {aes256-cts-hmac-sha1-96(18), aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes128-cts-hmac-sha1-96(17)}) 192.168.88.6: ISSUE: authtime 1694078668, etypes {rep=aes256-cts-hmac-sha1-96(18), tkt=aes256-cts-hmac-sha1-96(18), ses=aes256-cts-hmac-sha1-96(18)}, HTTP/ipa6.ipa.example.com@IPA.EXAMPLE.COM for ldap/ipa6.ipa.example.com@IPA.EXAMPLE.COM Sep 07 09:24:40 ipa6.ipa.example.com krb5kdc[207732](info): ... CONSTRAINED-DELEGATION s4u-client=host/xoanon.ipa.example.com@IPA.EXAMPLE.COM Sep 07 09:24:40 ipa6.ipa.example.com krb5kdc[207732](info): closing down fd 11
If you want the full logs from the servers and/or the full debug output from the client just let me know and I'll collect them up and mail them to you.
-- Sam Morris https://robots.org.uk/ PGP: rsa4096/CAAA AA1A CA69 A83A 892B 1855 D20B 4202 5CDA 27B9
On 07/09/2023 13:35, Alexander Bokovoy via FreeIPA-users wrote:
On Чцв, 07 вер 2023, Sam Morris wrote:
On Wed, Sep 06, 2023 at 02:50:32PM +0300, Alexander Bokovoy via FreeIPA-users wrote:
It would help to see logs (krb5kdc.log) from RHEL8 servers for this communication, both on ipa5/ipa6 and back to xoanon.
I've created a script to test this automatically.
Thank you!
I filed https://pagure.io/freeipa/issue/9448 to track this issue. I'll be on vacation next week and Julien (krb5 maintainer) is on vacation too, so we'll look at it after we are both back to work.
You're welcome, enjoy your vacation!
On Чцв, 07 вер 2023, Sam Morris via FreeIPA-users wrote:
On 07/09/2023 13:35, Alexander Bokovoy via FreeIPA-users wrote:
On Чцв, 07 вер 2023, Sam Morris wrote:
On Wed, Sep 06, 2023 at 02:50:32PM +0300, Alexander Bokovoy via FreeIPA-users wrote:
It would help to see logs (krb5kdc.log) from RHEL8 servers for this communication, both on ipa5/ipa6 and back to xoanon.
I've created a script to test this automatically.
Thank you!
I filed https://pagure.io/freeipa/issue/9448 to track this issue. I'll be on vacation next week and Julien (krb5 maintainer) is on vacation too, so we'll look at it after we are both back to work.
You're welcome, enjoy your vacation!
I want to close down a loop here. We ended up implementing a dynamic Kerberos PAC ticket signature enforcement mechanism to address cross-version interoperability issue.
https://access.redhat.com/articles/7046409 documents fixes to this issue, thanks to Julien (krb5 maintainer). If you don't have free RHEL developer subscription, then one can be subscribed to at https://developers.redhat.com/about.
freeipa-users@lists.fedorahosted.org