I'm trying to figure out how to get smartcard-authentication working in RHEL 8.3 when the computer is joined to an active directory domain. So far I've managed to configure local authentication using a smart card by mapping a specific local account to a upn in the SAN in the certificate. For obvious reasons not easy to use with a domain account. Anyone with experience on the matter? I've followed the official RHEL guide, but the certificate on the smart card is currently not stored in the userCertificate attribute in active directory, so I really need some way to map the active directory account to the upn specified in the Subject alternate name in the certificate. The customer is currently doing that in Windows. As long as the certificate is verified against their CA and the user name matches what's in the SAN, the user is logged on. How can I do this on a RHEL 8.3 workstation? I tried following the official guide at Redhat, adding the user certificate to the userCertificate attribute in Active directory, but it doesn't seem to work. As soon as i use authselect to enable smartcard logon I end up with a pin prompt without entering a user name and entering the correct pin for the card doesn't work.
Am Wed, May 05, 2021 at 09:45:27AM -0000 schrieb Gary Letth:
I'm trying to figure out how to get smartcard-authentication working in RHEL 8.3 when the computer is joined to an active directory domain. So far I've managed to configure local authentication using a smart card by mapping a specific local account to a upn in the SAN in the certificate. For obvious reasons not easy to use with a domain account. Anyone with experience on the matter? I've followed the official RHEL guide, but the certificate on the smart card is currently not stored in the userCertificate attribute in active directory, so I really need some way to map the active directory account to the upn specified in the Subject alternate name in the certificate. The customer is currently doing that in Windows. As long as the certificate is verified against their CA and the user name matches what's in the SAN, the user is logged on. How can I do this on a RHEL 8.3 workstation?
Hi,
you can add a certificate mapping and matching rule, see man sssd.conf and man sss-certmap for details. In you case something like
[certmap/my.domain/rule_name] matchrule = <ISSUER>^CN=My-CA,DC=MY,DC=DOMAIN$ maprule = (|(userPrincipalName={subject_principal})(samAccountName={subject_principal.short_name})) domains = my.domain priority = 10
where you replace my.domain with the proper domain name of your environment.
I tried following the official guide at Redhat, adding the user certificate to the userCertificate attribute in Active directory, but it doesn't seem to work. As soon as i use authselect to enable smartcard logon I end up with a pin prompt without entering a user name and entering the correct pin for the card doesn't work.
Only seeing the PIN prompt is expected, this is a feature of GDM.
Most probably authentication fails while trying to get the Kerberos ticket with the help of the Smartcard because AD requires some special setting in krb5.conf. To debug this please add 'debug_level = 9' to the [domain/...] section, restart SSSD and try again. The check krb5_child.log or send it here together with your /etc/krb5.conf.
HTH
bye, Sumit
sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/ List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines List Archives: https://lists.fedorahosted.org/archives/list/sssd-users@lists.fedorahosted.o... Do not reply to spam on the list, report it: https://pagure.io/fedora-infrastructure
Thanks for your reply. Where do I find the issuer to create the correct matchrule? The upn of the user is currently stored in the Subject Alternate Name in the certificate. So the full username including the domain. What would the maprule look like then? I don't understand how it's supposed to work if GDM doesn't prompt for a username. The smartcard currently has two separate certificates. Without entering a username, I fail to see how it knows which one to use. krb5_child.log is currently empty. This is krb5.conf:
# To opt out of the system crypto-policies configuration of krb5, remove the # symlink at /etc/krb5.conf.d/crypto-policies which will not be recreated. includedir /etc/krb5.conf.d/
[logging] default = FILE:/var/log/krb5libs.log kdc = FILE:/var/log/krb5kdc.log admin_server = FILE:/var/log/kadmind.log
[libdefaults] dns_lookup_realm = false ticket_lifetime = 24h renew_lifetime = 7d forwardable = true rdns = false pkinit_anchors = FILE:/etc/pki/tls/certs/ca-bundle.crt spake_preauth_groups = edwards25519 default_ccache_name = KEYRING:persistent:%{uid}
[realms] # EXAMPLE.COM = { # kdc = kerberos.example.com # admin_server = kerberos.example.com # }
[domain_realm] # .example.com = EXAMPLE.COM # example.com = EXAMPLE.COM
BR /Gary
After entering the correct pin for the card, this is an anonymized version of krb5_child.log: (2021-05-06 16:27:42): [krb5_child[598307]] [main] (0x0400): krb5_child started. (2021-05-06 16:27:42): [krb5_child[598307]] [unpack_buffer] (0x1000): total buffer size: [189] (2021-05-06 16:27:42): [krb5_child[598307]] [unpack_buffer] (0x0100): cmd [249] uid [57252887] gid [57200513] validate [true] enterprise principal [true] offline [false] UPN [username@XXXXX.XXXXX.NET (2021-05-06 16:27:42): [krb5_child[598307]] [unpack_buffer] (0x2000): No old ccache (2021-05-06 16:27:42): [krb5_child[598307]] [unpack_buffer] (0x0100): ccname: [KCM:] old_ccname: [not set] keytab: [/etc/krb5.keytab] (2021-05-06 16:27:42): [krb5_child[598307]] [check_use_fast] (0x0100): Not using FAST. (2021-05-06 16:27:42): [krb5_child[598307]] [privileged_krb5_setup] (0x0080): Cannot open the PAC responder socket (2021-05-06 16:27:42): [krb5_child[598307]] [switch_creds] (0x0200): Switch user to [0][0]. (2021-05-06 16:27:42): [krb5_child[598307]] [switch_creds] (0x0200): Already user [0]. (2021-05-06 16:27:42): [krb5_child[598307]] [main] (0x2000): Running as [0][0]. (2021-05-06 16:27:42): [krb5_child[598307]] [set_lifetime_options] (0x0100): No specific renewable lifetime requested. (2021-05-06 16:27:42): [krb5_child[598307]] [set_lifetime_options] (0x0100): No specific lifetime requested. (2021-05-06 16:27:42): [krb5_child[598307]] [set_canonicalize_option] (0x0100): Canonicalization is set to [true] (2021-05-06 16:27:42): [krb5_child[598307]] [main] (0x0400): Will perform pre-auth (2021-05-06 16:27:42): [krb5_child[598307]] [tgt_req_child] (0x1000): Attempting to get a TGT (2021-05-06 16:27:42): [krb5_child[598307]] [get_and_save_tgt] (0x4000): Found Smartcard credentials, trying pkinit. (2021-05-06 16:27:42): [krb5_child[598307]] [get_pkinit_identity] (0x4000): Got [IDPrime (basic)][/usr/lib64/pkcs11/libiidp11.so]. (2021-05-06 16:27:42): [krb5_child[598307]] [get_pkinit_identity] (0x4000): Using pkinit identity [PKCS11:module_name=/usr/lib64/pkcs11/libiidp11.so:token=IDPrime (basic):certid=800E531104A944C4]. (2021-05-06 16:27:42): [krb5_child[598307]] [get_and_save_tgt] (0x0400): Attempting kinit for realm [XXXXX.XXXXX.NET] (2021-05-06 16:27:42): [krb5_child[598307]] [sss_child_krb5_trace_cb] (0x4000): [598307] 1620311262.656719: Getting initial credentials for username@XXXXX.XXXXX.NET@XXXXX.XXXXX.NET
(2021-05-06 16:27:42): [krb5_child[598307]] [sss_child_krb5_trace_cb] (0x4000): [598307] 1620311262.656721: Sending unauthenticated request
(2021-05-06 16:27:42): [krb5_child[598307]] [sss_child_krb5_trace_cb] (0x4000): [598307] 1620311262.656722: Sending request (244 bytes) to XXXXX.XXXXX.NET
(2021-05-06 16:27:42): [krb5_child[598307]] [sss_child_krb5_trace_cb] (0x4000): [598307] 1620311262.656723: Sending initial UDP request to dgram 192.168.0.1:88
(2021-05-06 16:27:42): [krb5_child[598307]] [sss_child_krb5_trace_cb] (0x4000): [598307] 1620311262.656724: Received answer (215 bytes) from dgram 192.168.0.1:88
(2021-05-06 16:27:42): [krb5_child[598307]] [sss_child_krb5_trace_cb] (0x4000): [598307] 1620311262.656725: Response was from master KDC
(2021-05-06 16:27:42): [krb5_child[598307]] [sss_child_krb5_trace_cb] (0x4000): [598307] 1620311262.656726: Received error from KDC: -1765328359/Additional pre-authentication required
(2021-05-06 16:27:42): [krb5_child[598307]] [sss_child_krb5_trace_cb] (0x4000): [598307] 1620311262.656729: Preauthenticating using KDC method data
(2021-05-06 16:27:42): [krb5_child[598307]] [sss_child_krb5_trace_cb] (0x4000): [598307] 1620311262.656730: Processing preauth types: PA-PK-AS-REQ (16), PA-PK-AS-REP_OLD (15), PA-ETYPE-INFO2 (19), PA-ENC-T$
(2021-05-06 16:27:42): [krb5_child[598307]] [sss_child_krb5_trace_cb] (0x4000): [598307] 1620311262.656731: Selected etype info: etype aes256-cts, salt "XXXXX.XXXXX.NETusername", params ""
(2021-05-06 16:27:42): [krb5_child[598307]] [sss_krb5_responder] (0x4000): Got question [password]. (2021-05-06 16:27:42): [krb5_child[598307]] [sss_krb5_prompter] (0x4000): sss_krb5_prompter name [(null)] banner [(null)] num_prompts [1] EINVAL. (2021-05-06 16:27:42): [krb5_child[598307]] [sss_krb5_prompter] (0x4000): Prompt [0][Password for username@XXXXX.XXXXX.NET@XXXXX.XXXXX.NET]. (2021-05-06 16:27:42): [krb5_child[598307]] [sss_krb5_prompter] (0x0020): Cannot handle password prompts. (2021-05-06 16:27:42): [krb5_child[598307]] [sss_child_krb5_trace_cb] (0x4000): [598307] 1620311262.656732: Preauth module encrypted_timestamp (2) (real) returned: -1765328254/Cannot read password
(2021-05-06 16:27:42): [krb5_child[598307]] [sss_krb5_get_init_creds_password] (0x0020): 1627: [-1765328174][Pre-authentication failed: Cannot read password] (2021-05-06 16:27:42): [krb5_child[598307]] [get_and_save_tgt] (0x0400): krb5_get_init_creds_password returned [-1765328174] during pre-auth. (2021-05-06 16:27:42): [krb5_child[598307]] [k5c_send_data] (0x0200): Received error code 0 (2021-05-06 16:27:42): [krb5_child[598307]] [pack_response_packet] (0x2000): response packet size: [12] (2021-05-06 16:27:42): [krb5_child[598307]] [k5c_send_data] (0x4000): Response sent. (2021-05-06 16:27:42): [krb5_child[598307]] [main] (0x0400): krb5_child completed successfully
Any idea what could be wrong?
Am Thu, May 06, 2021 at 07:29:06PM -0000 schrieb Gary Letth:
After entering the correct pin for the card, this is an anonymized version of krb5_child.log: (2021-05-06 16:27:42): [krb5_child[598307]] [main] (0x0400): krb5_child started. (2021-05-06 16:27:42): [krb5_child[598307]] [unpack_buffer] (0x1000): total buffer size: [189] (2021-05-06 16:27:42): [krb5_child[598307]] [unpack_buffer] (0x0100): cmd [249] uid [57252887] gid [57200513] validate [true] enterprise principal [true] offline [false] UPN [username@XXXXX.XXXXX.NET
Hi,
this should actually already have happened before you entered the PIN. In this run SSSD tries to figure out if Smartcard authentication (pkinit) is available for the user on the server side. It looks like it is available on the server side but your client cannot handle it. Most probably the krb5-pkinit package isn't installed.
HTH
bye, Sumit
(2021-05-06 16:27:42): [krb5_child[598307]] [unpack_buffer] (0x2000): No old ccache (2021-05-06 16:27:42): [krb5_child[598307]] [unpack_buffer] (0x0100): ccname: [KCM:] old_ccname: [not set] keytab: [/etc/krb5.keytab] (2021-05-06 16:27:42): [krb5_child[598307]] [check_use_fast] (0x0100): Not using FAST. (2021-05-06 16:27:42): [krb5_child[598307]] [privileged_krb5_setup] (0x0080): Cannot open the PAC responder socket (2021-05-06 16:27:42): [krb5_child[598307]] [switch_creds] (0x0200): Switch user to [0][0]. (2021-05-06 16:27:42): [krb5_child[598307]] [switch_creds] (0x0200): Already user [0]. (2021-05-06 16:27:42): [krb5_child[598307]] [main] (0x2000): Running as [0][0]. (2021-05-06 16:27:42): [krb5_child[598307]] [set_lifetime_options] (0x0100): No specific renewable lifetime requested. (2021-05-06 16:27:42): [krb5_child[598307]] [set_lifetime_options] (0x0100): No specific lifetime requested. (2021-05-06 16:27:42): [krb5_child[598307]] [set_canonicalize_option] (0x0100): Canonicalization is set to [true] (2021-05-06 16:27:42): [krb5_child[598307]] [main] (0x0400): Will perform pre-auth (2021-05-06 16:27:42): [krb5_child[598307]] [tgt_req_child] (0x1000): Attempting to get a TGT (2021-05-06 16:27:42): [krb5_child[598307]] [get_and_save_tgt] (0x4000): Found Smartcard credentials, trying pkinit. (2021-05-06 16:27:42): [krb5_child[598307]] [get_pkinit_identity] (0x4000): Got [IDPrime (basic)][/usr/lib64/pkcs11/libiidp11.so]. (2021-05-06 16:27:42): [krb5_child[598307]] [get_pkinit_identity] (0x4000): Using pkinit identity [PKCS11:module_name=/usr/lib64/pkcs11/libiidp11.so:token=IDPrime (basic):certid=800E531104A944C4]. (2021-05-06 16:27:42): [krb5_child[598307]] [get_and_save_tgt] (0x0400): Attempting kinit for realm [XXXXX.XXXXX.NET] (2021-05-06 16:27:42): [krb5_child[598307]] [sss_child_krb5_trace_cb] (0x4000): [598307] 1620311262.656719: Getting initial credentials for username@XXXXX.XXXXX.NET@XXXXX.XXXXX.NET
(2021-05-06 16:27:42): [krb5_child[598307]] [sss_child_krb5_trace_cb] (0x4000): [598307] 1620311262.656721: Sending unauthenticated request
(2021-05-06 16:27:42): [krb5_child[598307]] [sss_child_krb5_trace_cb] (0x4000): [598307] 1620311262.656722: Sending request (244 bytes) to XXXXX.XXXXX.NET
(2021-05-06 16:27:42): [krb5_child[598307]] [sss_child_krb5_trace_cb] (0x4000): [598307] 1620311262.656723: Sending initial UDP request to dgram 192.168.0.1:88
(2021-05-06 16:27:42): [krb5_child[598307]] [sss_child_krb5_trace_cb] (0x4000): [598307] 1620311262.656724: Received answer (215 bytes) from dgram 192.168.0.1:88
(2021-05-06 16:27:42): [krb5_child[598307]] [sss_child_krb5_trace_cb] (0x4000): [598307] 1620311262.656725: Response was from master KDC
(2021-05-06 16:27:42): [krb5_child[598307]] [sss_child_krb5_trace_cb] (0x4000): [598307] 1620311262.656726: Received error from KDC: -1765328359/Additional pre-authentication required
(2021-05-06 16:27:42): [krb5_child[598307]] [sss_child_krb5_trace_cb] (0x4000): [598307] 1620311262.656729: Preauthenticating using KDC method data
(2021-05-06 16:27:42): [krb5_child[598307]] [sss_child_krb5_trace_cb] (0x4000): [598307] 1620311262.656730: Processing preauth types: PA-PK-AS-REQ (16), PA-PK-AS-REP_OLD (15), PA-ETYPE-INFO2 (19), PA-ENC-T$
(2021-05-06 16:27:42): [krb5_child[598307]] [sss_child_krb5_trace_cb] (0x4000): [598307] 1620311262.656731: Selected etype info: etype aes256-cts, salt "XXXXX.XXXXX.NETusername", params ""
(2021-05-06 16:27:42): [krb5_child[598307]] [sss_krb5_responder] (0x4000): Got question [password]. (2021-05-06 16:27:42): [krb5_child[598307]] [sss_krb5_prompter] (0x4000): sss_krb5_prompter name [(null)] banner [(null)] num_prompts [1] EINVAL. (2021-05-06 16:27:42): [krb5_child[598307]] [sss_krb5_prompter] (0x4000): Prompt [0][Password for username@XXXXX.XXXXX.NET@XXXXX.XXXXX.NET]. (2021-05-06 16:27:42): [krb5_child[598307]] [sss_krb5_prompter] (0x0020): Cannot handle password prompts. (2021-05-06 16:27:42): [krb5_child[598307]] [sss_child_krb5_trace_cb] (0x4000): [598307] 1620311262.656732: Preauth module encrypted_timestamp (2) (real) returned: -1765328254/Cannot read password
(2021-05-06 16:27:42): [krb5_child[598307]] [sss_krb5_get_init_creds_password] (0x0020): 1627: [-1765328174][Pre-authentication failed: Cannot read password] (2021-05-06 16:27:42): [krb5_child[598307]] [get_and_save_tgt] (0x0400): krb5_get_init_creds_password returned [-1765328174] during pre-auth. (2021-05-06 16:27:42): [krb5_child[598307]] [k5c_send_data] (0x0200): Received error code 0 (2021-05-06 16:27:42): [krb5_child[598307]] [pack_response_packet] (0x2000): response packet size: [12] (2021-05-06 16:27:42): [krb5_child[598307]] [k5c_send_data] (0x4000): Response sent. (2021-05-06 16:27:42): [krb5_child[598307]] [main] (0x0400): krb5_child completed successfully _______________________________________________ sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/ List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines List Archives: https://lists.fedorahosted.org/archives/list/sssd-users@lists.fedorahosted.o... Do not reply to spam on the list, report it: https://pagure.io/fedora-infrastructure
So I installed the krb5-pkinit package and added the following lines to sssd.conf: [sssd] certificate_verification = no_verification
[domain/xxxxx.xxxxx.net] krb5_use_enterprise_principal = true <- Recommendation from Redhat support.
[certmap/xxxxx.xxxxx.net/smartcard] matchrule = <ISSUER>^CN=XXXXX-CA,DC=XXXXX,DC=XXXXX,DC=NET maprule = (|(userPrincipalName={subject_principal})(samAccountName={subject_principal.short_name})) domains = xxxx.xxxxx.net priority = 10
The full certificate chain from the CA is stored in /etc/sssd/pki/sssd_auth_ca_db.pem
This is the resulting krb5_child.log
(2021-05-12 10:49:57): [krb5_child[2004618]] [main] (0x0400): krb5_child started. (2021-05-12 10:49:57): [krb5_child[2004618]] [unpack_buffer] (0x1000): total buffer size: [195] (2021-05-12 10:49:57): [krb5_child[2004618]] [unpack_buffer] (0x0100): cmd [241] uid [57252887] gid [57200513] validate [true] enterprise principal [true] offline [false] UPN [username@XXXXX.XXXXX.NET] (2021-05-12 10:49:57): [krb5_child[2004618]] [unpack_buffer] (0x2000): No old ccache (2021-05-12 10:49:57): [krb5_child[2004618]] [unpack_buffer] (0x0100): ccname: [KCM:] old_ccname: [not set] keytab: [/etc/krb5.keytab] (2021-05-12 10:49:57): [krb5_child[2004618]] [check_use_fast] (0x0100): Not using FAST. (2021-05-12 10:49:57): [krb5_child[2004618]] [k5c_precreate_ccache] (0x4000): Recreating ccache (2021-05-12 10:49:57): [krb5_child[2004618]] [privileged_krb5_setup] (0x0080): Cannot open the PAC responder socket (2021-05-12 10:49:57): [krb5_child[2004618]] [switch_creds] (0x0200): Switch user to [0][0]. (2021-05-12 10:49:57): [krb5_child[2004618]] [switch_creds] (0x0200): Already user [0]. (2021-05-12 10:49:57): [krb5_child[2004618]] [main] (0x2000): Running as [0][0]. (2021-05-12 10:49:57): [krb5_child[2004618]] [set_lifetime_options] (0x0100): No specific renewable lifetime requested. (2021-05-12 10:49:57): [krb5_child[2004618]] [set_lifetime_options] (0x0100): No specific lifetime requested. (2021-05-12 10:49:57): [krb5_child[2004618]] [set_canonicalize_option] (0x0100): Canonicalization is set to [true] (2021-05-12 10:49:57): [krb5_child[2004618]] [main] (0x0400): Will perform online auth (2021-05-12 10:49:57): [krb5_child[2004618]] [tgt_req_child] (0x1000): Attempting to get a TGT (2021-05-12 10:49:57): [krb5_child[2004618]] [get_and_save_tgt] (0x4000): Found Smartcard credentials, trying pkinit. (2021-05-12 10:49:57): [krb5_child[2004618]] [get_pkinit_identity] (0x4000): Got [IDPrime (basic)][/usr/lib64/pkcs11/libiidp11.so]. (2021-05-12 10:49:57): [krb5_child[2004618]] [get_pkinit_identity] (0x4000): Using pkinit identity [PKCS11:module_name=/usr/lib64/pkcs11/libiidp11.so:token=IDPrime (basic):certid=800E531104A944C4]. (2021-05-12 10:49:57): [krb5_child[2004618]] [get_and_save_tgt] (0x0400): Attempting kinit for realm [XXXXX.XXXXX.NET] (2021-05-12 10:49:57): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809397.219647: Getting initial credentials for username@XXXXX.XXXXX.NET@XXXXX.XXXXX.NET
(2021-05-12 10:49:57): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809397.219649: Sending unauthenticated request
(2021-05-12 10:49:57): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809397.219650: Sending request (244 bytes) to XXXXX.XXXXX.NET
(2021-05-12 10:49:57): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809397.219651: Sending initial UDP request to dgram 10.184.199.13:88
(2021-05-12 10:49:57): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809397.219652: Received answer (215 bytes) from dgram 10.184.199.13:88
(2021-05-12 10:49:57): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809397.219653: Response was from master KDC
(2021-05-12 10:49:57): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809397.219654: Received error from KDC: -1765328359/Additional pre-authentication required
(2021-05-12 10:49:57): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809397.219657: Preauthenticating using KDC method data
(2021-05-12 10:49:57): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809397.219658: Processing preauth types: PA-PK-AS-REQ (16), PA-PK-AS-REP_OLD (15), PA-ETYPE-INFO2 (19), PA-ENC-TIMESTAMP (2)
(2021-05-12 10:49:57): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809397.219659: Selected etype info: etype aes256-cts, salt "XXXXX.XXXXX.NETusername", params ""
(2021-05-12 10:49:57): [krb5_child[2004618]] [sss_krb5_responder] (0x4000): Got question [pkinit]. (2021-05-12 10:49:57): [krb5_child[2004618]] [answer_pkinit] (0x4000): [0] Identity [PKCS11:module_name=/usr/lib64/pkcs11/libiidp11.so:slotid=1:token=IDPrime (basic)] flags [0]. (2021-05-12 10:49:57): [krb5_child[2004618]] [answer_pkinit] (0x4000): Setting pkinit_prompting. (2021-05-12 10:49:57): [krb5_child[2004618]] [pkinit_identity_matches] (0x4000): Found [module_name=/usr/lib64/pkcs11/libiidp11.so] in identity [PKCS11:module_name=/usr/lib64/pkcs11/libiidp11.so:slotid=1:token=IDPrime (basic)]. (2021-05-12 10:49:57): [krb5_child[2004618]] [pkinit_identity_matches] (0x4000): Found [token=IDPrime (basic)] in identity [PKCS11:module_name=/usr/lib64/pkcs11/libiidp11.so:slotid=1:token=IDPrime (basic)]. (2021-05-12 10:49:58): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809398.178582: PKINIT loading CA certs and CRLs from FILE
(2021-05-12 10:49:58): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809398.178583: PKINIT client computed kdc-req-body checksum 9/EE2535428039B767876E61A7EBE92F08F612D298
(2021-05-12 10:49:58): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809398.178585: PKINIT client making DH request
(2021-05-12 10:49:58): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809398.178586: PKINIT OpenSSL error: Failed to verify own certificate (depth 0): unable to get local issuer certificate
(2021-05-12 10:49:58): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809398.178587: Preauth module pkinit (16) (real) returned: -1765328360/Failed to verify own certificate (depth 0): unable to get local issuer certificate
(2021-05-12 10:49:58): [krb5_child[2004618]] [sss_krb5_prompter] (0x4000): sss_krb5_prompter name [(null)] banner [(null)] num_prompts [1] EINVAL. (2021-05-12 10:49:58): [krb5_child[2004618]] [sss_krb5_prompter] (0x4000): Prompt [0][Password for username@XXXXX.XXXXX.NET@XXXXX.XXXXX.NET]. (2021-05-12 10:49:58): [krb5_child[2004618]] [sss_krb5_prompter] (0x0020): Cannot handle password prompts. (2021-05-12 10:49:58): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809398.178588: Preauth module encrypted_timestamp (2) (real) returned: -1765328254/Cannot read password
(2021-05-12 10:49:58): [krb5_child[2004618]] [sss_krb5_get_init_creds_password] (0x0020): 1627: [-1765328174][Pre-authentication failed: Failed to verify own certificate (depth 0): unable to get local issuer certificate] (2021-05-12 10:49:58): [krb5_child[2004618]] [get_and_save_tgt] (0x0020): 1704: [-1765328174][Pre-authentication failed: Failed to verify own certificate (depth 0): unable to get local issuer certificate] (2021-05-12 10:49:58): [krb5_child[2004618]] [map_krb5_error] (0x0020): 1833: [-1765328174][Pre-authentication failed: Failed to verify own certificate (depth 0): unable to get local issuer certificate] (2021-05-12 10:49:58): [krb5_child[2004618]] [k5c_send_data] (0x0200): Received error code 1432158222 (2021-05-12 10:49:58): [krb5_child[2004618]] [pack_response_packet] (0x2000): response packet size: [4] (2021-05-12 10:49:58): [krb5_child[2004618]] [k5c_send_data] (0x4000): Response sent. (2021-05-12 10:49:58): [krb5_child[2004618]] [main] (0x0400): krb5_child completed successfully
Am Wed, May 12, 2021 at 09:35:29AM -0000 schrieb Gary Letth:
So I installed the krb5-pkinit package and added the following lines to sssd.conf: [sssd] certificate_verification = no_verification
[domain/xxxxx.xxxxx.net] krb5_use_enterprise_principal = true <- Recommendation from Redhat support.
[certmap/xxxxx.xxxxx.net/smartcard] matchrule = <ISSUER>^CN=XXXXX-CA,DC=XXXXX,DC=XXXXX,DC=NET maprule = (|(userPrincipalName={subject_principal})(samAccountName={subject_principal.short_name})) domains = xxxx.xxxxx.net priority = 10
The full certificate chain from the CA is stored in /etc/sssd/pki/sssd_auth_ca_db.pem
This is the resulting krb5_child.log
(2021-05-12 10:49:57): [krb5_child[2004618]] [main] (0x0400): krb5_child started. (2021-05-12 10:49:57): [krb5_child[2004618]] [unpack_buffer] (0x1000): total buffer size: [195] (2021-05-12 10:49:57): [krb5_child[2004618]] [unpack_buffer] (0x0100): cmd [241] uid [57252887] gid [57200513] validate [true] enterprise principal [true] offline [false] UPN [username@XXXXX.XXXXX.NET] (2021-05-12 10:49:57): [krb5_child[2004618]] [unpack_buffer] (0x2000): No old ccache (2021-05-12 10:49:57): [krb5_child[2004618]] [unpack_buffer] (0x0100): ccname: [KCM:] old_ccname: [not set] keytab: [/etc/krb5.keytab] (2021-05-12 10:49:57): [krb5_child[2004618]] [check_use_fast] (0x0100): Not using FAST. (2021-05-12 10:49:57): [krb5_child[2004618]] [k5c_precreate_ccache] (0x4000): Recreating ccache (2021-05-12 10:49:57): [krb5_child[2004618]] [privileged_krb5_setup] (0x0080): Cannot open the PAC responder socket (2021-05-12 10:49:57): [krb5_child[2004618]] [switch_creds] (0x0200): Switch user to [0][0]. (2021-05-12 10:49:57): [krb5_child[2004618]] [switch_creds] (0x0200): Already user [0]. (2021-05-12 10:49:57): [krb5_child[2004618]] [main] (0x2000): Running as [0][0]. (2021-05-12 10:49:57): [krb5_child[2004618]] [set_lifetime_options] (0x0100): No specific renewable lifetime requested. (2021-05-12 10:49:57): [krb5_child[2004618]] [set_lifetime_options] (0x0100): No specific lifetime requested. (2021-05-12 10:49:57): [krb5_child[2004618]] [set_canonicalize_option] (0x0100): Canonicalization is set to [true] (2021-05-12 10:49:57): [krb5_child[2004618]] [main] (0x0400): Will perform online auth (2021-05-12 10:49:57): [krb5_child[2004618]] [tgt_req_child] (0x1000): Attempting to get a TGT (2021-05-12 10:49:57): [krb5_child[2004618]] [get_and_save_tgt] (0x4000): Found Smartcard credentials, trying pkinit. (2021-05-12 10:49:57): [krb5_child[2004618]] [get_pkinit_identity] (0x4000): Got [IDPrime (basic)][/usr/lib64/pkcs11/libiidp11.so]. (2021-05-12 10:49:57): [krb5_child[2004618]] [get_pkinit_identity] (0x4000): Using pkinit identity [PKCS11:module_name=/usr/lib64/pkcs11/libiidp11.so:token=IDPrime (basic):certid=800E531104A944C4]. (2021-05-12 10:49:57): [krb5_child[2004618]] [get_and_save_tgt] (0x0400): Attempting kinit for realm [XXXXX.XXXXX.NET] (2021-05-12 10:49:57): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809397.219647: Getting initial credentials for username@XXXXX.XXXXX.NET@XXXXX.XXXXX.NET
(2021-05-12 10:49:57): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809397.219649: Sending unauthenticated request
(2021-05-12 10:49:57): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809397.219650: Sending request (244 bytes) to XXXXX.XXXXX.NET
(2021-05-12 10:49:57): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809397.219651: Sending initial UDP request to dgram 10.184.199.13:88
(2021-05-12 10:49:57): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809397.219652: Received answer (215 bytes) from dgram 10.184.199.13:88
(2021-05-12 10:49:57): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809397.219653: Response was from master KDC
(2021-05-12 10:49:57): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809397.219654: Received error from KDC: -1765328359/Additional pre-authentication required
(2021-05-12 10:49:57): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809397.219657: Preauthenticating using KDC method data
(2021-05-12 10:49:57): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809397.219658: Processing preauth types: PA-PK-AS-REQ (16), PA-PK-AS-REP_OLD (15), PA-ETYPE-INFO2 (19), PA-ENC-TIMESTAMP (2)
(2021-05-12 10:49:57): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809397.219659: Selected etype info: etype aes256-cts, salt "XXXXX.XXXXX.NETusername", params ""
(2021-05-12 10:49:57): [krb5_child[2004618]] [sss_krb5_responder] (0x4000): Got question [pkinit]. (2021-05-12 10:49:57): [krb5_child[2004618]] [answer_pkinit] (0x4000): [0] Identity [PKCS11:module_name=/usr/lib64/pkcs11/libiidp11.so:slotid=1:token=IDPrime (basic)] flags [0]. (2021-05-12 10:49:57): [krb5_child[2004618]] [answer_pkinit] (0x4000): Setting pkinit_prompting. (2021-05-12 10:49:57): [krb5_child[2004618]] [pkinit_identity_matches] (0x4000): Found [module_name=/usr/lib64/pkcs11/libiidp11.so] in identity [PKCS11:module_name=/usr/lib64/pkcs11/libiidp11.so:slotid=1:token=IDPrime (basic)]. (2021-05-12 10:49:57): [krb5_child[2004618]] [pkinit_identity_matches] (0x4000): Found [token=IDPrime (basic)] in identity [PKCS11:module_name=/usr/lib64/pkcs11/libiidp11.so:slotid=1:token=IDPrime (basic)]. (2021-05-12 10:49:58): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809398.178582: PKINIT loading CA certs and CRLs from FILE
(2021-05-12 10:49:58): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809398.178583: PKINIT client computed kdc-req-body checksum 9/EE2535428039B767876E61A7EBE92F08F612D298
(2021-05-12 10:49:58): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809398.178585: PKINIT client making DH request
(2021-05-12 10:49:58): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809398.178586: PKINIT OpenSSL error: Failed to verify own certificate (depth 0): unable to get local issuer certificate
(2021-05-12 10:49:58): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809398.178587: Preauth module pkinit (16) (real) returned: -1765328360/Failed to verify own certificate (depth 0): unable to get local issuer certificate
Hi,
'certificate_verification = no_verification' is only for SSSD's internal processing. The verification for the pkinit plugin of MIT Kerberos cannot be disabled. So you have to add
pkinit_anchors = FILE:/path/to/ca/certs.pem
to krb5.conf, e.g, in the [libdefaults] section and the file must contain the CA certificate of the CA which signed your certificate and the CA certificate if the CA which signed the certificate of the KDC or domain controller, for AD this is typically the CA certificate of the AD CS. If those CA certificates are signed by other CAs it would be good to add those CA certificates as well.
HTH
bye, Sumit
(2021-05-12 10:49:58): [krb5_child[2004618]] [sss_krb5_prompter] (0x4000): sss_krb5_prompter name [(null)] banner [(null)] num_prompts [1] EINVAL. (2021-05-12 10:49:58): [krb5_child[2004618]] [sss_krb5_prompter] (0x4000): Prompt [0][Password for username@XXXXX.XXXXX.NET@XXXXX.XXXXX.NET]. (2021-05-12 10:49:58): [krb5_child[2004618]] [sss_krb5_prompter] (0x0020): Cannot handle password prompts. (2021-05-12 10:49:58): [krb5_child[2004618]] [sss_child_krb5_trace_cb] (0x4000): [2004618] 1620809398.178588: Preauth module encrypted_timestamp (2) (real) returned: -1765328254/Cannot read password
(2021-05-12 10:49:58): [krb5_child[2004618]] [sss_krb5_get_init_creds_password] (0x0020): 1627: [-1765328174][Pre-authentication failed: Failed to verify own certificate (depth 0): unable to get local issuer certificate] (2021-05-12 10:49:58): [krb5_child[2004618]] [get_and_save_tgt] (0x0020): 1704: [-1765328174][Pre-authentication failed: Failed to verify own certificate (depth 0): unable to get local issuer certificate] (2021-05-12 10:49:58): [krb5_child[2004618]] [map_krb5_error] (0x0020): 1833: [-1765328174][Pre-authentication failed: Failed to verify own certificate (depth 0): unable to get local issuer certificate] (2021-05-12 10:49:58): [krb5_child[2004618]] [k5c_send_data] (0x0200): Received error code 1432158222 (2021-05-12 10:49:58): [krb5_child[2004618]] [pack_response_packet] (0x2000): response packet size: [4] (2021-05-12 10:49:58): [krb5_child[2004618]] [k5c_send_data] (0x4000): Response sent. (2021-05-12 10:49:58): [krb5_child[2004618]] [main] (0x0400): krb5_child completed successfully _______________________________________________ sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/ List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines List Archives: https://lists.fedorahosted.org/archives/list/sssd-users@lists.fedorahosted.o... Do not reply to spam on the list, report it: https://pagure.io/fedora-infrastructure
I got a step further by using the following matchrule: matchrule = <EKU>msScLogin I'm now presented with a list of the certificates on the card. After I select one of the identities I get a pin prompt, but that's as far as I get. When I enter the correct pin code the result is a "Sorry, that didn't work. Please try again.". I'm thinking the maprule is incorrect?
BR /Gary
The SAN in the certificate contains the UPN of the user. What would the maprule look like then?
Am Fri, May 21, 2021 at 11:29:54AM -0000 schrieb Gary Letth:
The SAN in the certificate contains the UPN of the user. What would the maprule look like then?
Hi,
please check the entry for subject_principal in man sss-certmap. A typical example for AD would be
(|(userPrincipalName={subject_principal})(samAccountName={subject_principal.short_name}))
But since you said that you see a certificate selection I guess the mapping rule might be already ok.
Please check krb5_child.log, after setting 'debug_level=9' in the [domain/...] section if there are some Kerberos related issues.
Typically you have to set 'pkinit_eku_checking=none' and suitable 'pkinit_kdc_hostname' in /etc/krb5.conf.
bye, Sumit
sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/ List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines List Archives: https://lists.fedorahosted.org/archives/list/sssd-users@lists.fedorahosted.o... Do not reply to spam on the list, report it: https://pagure.io/fedora-infrastructure
Hi Sumit I followed your instructions to the letter and managed to log on with a smart card twice. Then on the third attempt it failed. This is what the krb5_child.log looks like:
(2021-05-22 21:39:08): [krb5_child[12908]] [main] (0x0400): krb5_child started. (2021-05-22 21:39:08): [krb5_child[12908]] [unpack_buffer] (0x1000): total buffer size: [208] (2021-05-22 21:39:08): [krb5_child[12908]] [unpack_buffer] (0x0100): cmd [241 (auth)] uid [57249832] gid [57200513] validate [true] enterprise principal [true] offline [false] UPN [USERNAME@XXXXX.XXXXX.NET] (2021-05-22 21:39:08): [krb5_child[12908]] [unpack_buffer] (0x0100): ccname: [KCM:] old_ccname: [KCM:] keytab: [/etc/krb5.keytab] (2021-05-22 21:39:08): [krb5_child[12908]] [check_use_fast] (0x0100): Not using FAST. (2021-05-22 21:39:08): [krb5_child[12908]] [switch_creds] (0x0200): Switch user to [57249832][57200513]. (2021-05-22 21:39:08): [krb5_child[12908]] [switch_creds] (0x0200): Switch user to [0][0]. (2021-05-22 21:39:08): [krb5_child[12908]] [k5c_check_old_ccache] (0x4000): Ccache_file is [KCM:] and is not active and TGT is valid. (2021-05-22 21:39:08): [krb5_child[12908]] [k5c_precreate_ccache] (0x4000): Recreating ccache (2021-05-22 21:39:08): [krb5_child[12908]] [privileged_krb5_setup] (0x0080): Cannot open the PAC responder socket (2021-05-22 21:39:08): [krb5_child[12908]] [switch_creds] (0x0200): Switch user to [0][0]. (2021-05-22 21:39:08): [krb5_child[12908]] [switch_creds] (0x0200): Already user [0]. (2021-05-22 21:39:08): [krb5_child[12908]] [main] (0x2000): Running as [0][0]. (2021-05-22 21:39:08): [krb5_child[12908]] [set_lifetime_options] (0x0100): No specific renewable lifetime requested. (2021-05-22 21:39:08): [krb5_child[12908]] [set_lifetime_options] (0x0100): No specific lifetime requested. (2021-05-22 21:39:08): [krb5_child[12908]] [set_canonicalize_option] (0x0100): Canonicalization is set to [true] (2021-05-22 21:39:08): [krb5_child[12908]] [main] (0x0400): Will perform auth (2021-05-22 21:39:08): [krb5_child[12908]] [main] (0x0400): Will perform online auth (2021-05-22 21:39:08): [krb5_child[12908]] [tgt_req_child] (0x1000): Attempting to get a TGT (2021-05-22 21:39:08): [krb5_child[12908]] [get_and_save_tgt] (0x4000): Found Smartcard credentials, trying pkinit. (2021-05-22 21:39:08): [krb5_child[12908]] [get_pkinit_identity] (0x4000): Got [IDPrime (basic)][/usr/lib64/pkcs11/libiidp11.so]. (2021-05-22 21:39:08): [krb5_child[12908]] [get_pkinit_identity] (0x4000): Using pkinit identity [PKCS11:module_name=/usr/lib64/pkcs11/libiidp11.so:token=IDPrime (basic):certid=C0538C6C20E35F51:certlabel=Letth Gary]. (2021-05-22 21:39:08): [krb5_child[12908]] [get_and_save_tgt] (0x0400): Attempting kinit for realm [XXXXX.XXXXX.NET] (2021-05-22 21:39:08): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712348.775336: Getting initial credentials for USERNAME@XXXXX.XXXXX.NET@XXXXX.XXXXX.NET
(2021-05-22 21:39:08): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712348.775338: Sending unauthenticated request
(2021-05-22 21:39:08): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712348.775339: Sending request (236 bytes) to XXXXX.XXXXX.NET
(2021-05-22 21:39:08): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712348.775340: Initiating TCP connection to stream 192.168.0.1:88
(2021-05-22 21:39:08): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712348.775341: Sending TCP request to stream 192.168.0.1:88
(2021-05-22 21:39:08): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712348.775342: Received answer (207 bytes) from stream 192.168.0.1:88
(2021-05-22 21:39:08): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712348.775343: Terminating TCP connection to stream 192.168.0.1:88
(2021-05-22 21:39:08): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712348.775344: Response was from master KDC
(2021-05-22 21:39:08): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712348.775345: Received error from KDC: -1765328359/Additional pre-authentication required
(2021-05-22 21:39:08): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712348.775348: Preauthenticating using KDC method data
(2021-05-22 21:39:08): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712348.775349: Processing preauth types: PA-PK-AS-REQ (16), PA-PK-AS-REP_OLD (15), PA-ETYPE-INFO2 (19), PA-ENC-TIMESTAMP (2)
(2021-05-22 21:39:08): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712348.775350: Selected etype info: etype aes256-cts, salt "XXXXX.XXXXX.NETUSERNAME", params ""
(2021-05-22 21:39:09): [krb5_child[12908]] [sss_krb5_responder] (0x4000): Got question [pkinit]. (2021-05-22 21:39:09): [krb5_child[12908]] [answer_pkinit] (0x4000): [0] Identity [PKCS11:module_name=/usr/lib64/pkcs11/libiidp11.so:slotid=1:token=IDPrime (basic)] flags [0]. (2021-05-22 21:39:09): [krb5_child[12908]] [answer_pkinit] (0x4000): Setting pkinit_prompting. (2021-05-22 21:39:09): [krb5_child[12908]] [pkinit_identity_matches] (0x4000): Found [module_name=/usr/lib64/pkcs11/libiidp11.so] in identity [PKCS11:module_name=/usr/lib64/pkcs11/libiidp11.so:slotid=1:token=IDPrime (basic)]. (2021-05-22 21:39:09): [krb5_child[12908]] [pkinit_identity_matches] (0x4000): Found [token=IDPrime (basic)] in identity [PKCS11:module_name=/usr/lib64/pkcs11/libiidp11.so:slotid=1:token=IDPrime (basic)]. (2021-05-22 21:39:09): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712349.768786: PKINIT loading CA certs and CRLs from FILE
(2021-05-22 21:39:09): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712349.768787: PKINIT client computed kdc-req-body checksum 9/861AA32FA35DD352DACB3D5768D2818B64B99735
(2021-05-22 21:39:09): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712349.768789: PKINIT client making DH request
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619245: Preauth module pkinit (16) (real) returned: 0/Success
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619246: Produced preauth for next request: PA-PK-AS-REQ (16)
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619247: Sending request (5547 bytes) to XXXXX.XXXXX.NET
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619248: Initiating TCP connection to stream 192.168.0.1:88
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619249: Sending TCP request to stream 192.168.0.1:88
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619250: Received answer (4924 bytes) from stream 192.168.0.1:88
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619251: Terminating TCP connection to stream 192.168.0.1:88
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619252: Response was from master KDC
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619253: Processing preauth types: PA-PK-AS-REP (17)
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619254: PKINIT client verified DH reply
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619255: PKINIT client config accepts KDC dNSName SAN dc01.xxxxx.xxxxx.net
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619256: PKINIT client found dNSName SAN in KDC cert: dc01.xxxxx.xxxxx.net
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619257: PKINIT client matched KDC hostname dc01.xxxxx.xxxxx.net against dNSName SAN; EKU check still required
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619258: PKINIT client skipping EKU check due to configuration
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619259: PKINIT client found acceptable EKU in KDC cert
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619260: PKINIT client used octetstring2key to compute reply key aes256-cts/7D0E
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619261: Preauth module pkinit (17) (real) returned: 0/Success
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619262: Produced preauth for next request: (empty)
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619263: AS key determined by preauth: aes256-cts/7D0E
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619264: Decrypted AS reply; session key is: aes256-cts/A2ED
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619265: FAST negotiation: unavailable
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_krb5_expire_callback_func] (0x2000): exp_time: [514796935] (2021-05-22 21:39:10): [krb5_child[12908]] [validate_tgt] (0x2000): Found keytab entry with the realm of the credential. (2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619266: Retrieving COMPUTERNAME$@XXXXX.XXXXX.NET from MEMORY:/etc/krb5.keytab (vno 0, enctype 0) with result: 0/Success
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619267: Resolving unique ccache of type MEMORY
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619268: Initializing MEMORY:4eV88Mr with default princ USERNAME@XXXXX.XXXXX.NET
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619269: Storing USERNAME@XXXXX.XXXXX.NET -> krbtgt/XXXXX.XXXXX.NET@XXXXX.XXXXX.NET in MEMORY:4eV88Mr
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619270: Getting credentials USERNAME@XXXXX.XXXXX.NET -> COMPUTERNAME$@XXXXX.XXXXX.NET using ccache MEMORY:4eV88Mr
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619271: Retrieving USERNAME@XXXXX.XXXXX.NET -> COMPUTERNAME$@XXXXX.XXXXX.NET from MEMORY:4eV88Mr with result: -1765328243/Matching credential not found
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619272: Retrieving USERNAME@XXXXX.XXXXX.NET -> krbtgt/XXXXX.XXXXX.NET@XXXXX.XXXXX.NET from MEMORY:4eV88Mr with result: 0/Success
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619273: Starting with TGT for client realm: USERNAME@XXXXX.XXXXX.NET -> krbtgt/XXXXX.XXXXX.NET@XXXXX.XXXXX.NET
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619274: Requesting tickets for COMPUTERNAME$@XXXXX.XXXXX.NET, referrals on
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619275: Generated subkey for TGS request: aes256-cts/258D
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619276: etypes requested in TGS request: aes256-cts, aes256-sha2, camellia256-cts, aes128-cts, aes128-sha2, camellia128-cts, rc4-hmac
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619278: Encoding request body and padata into FAST request
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619279: Sending request (2445 bytes) to XXXXX.XXXXX.NET
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619280: Initiating TCP connection to stream 192.168.0.1:88
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619281: Sending TCP request to stream 192.168.0.1:88
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619282: Received answer (2497 bytes) from stream 192.168.0.1:88
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619283: Terminating TCP connection to stream 192.168.0.1:88
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619284: Response was from master KDC
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619285: Decoding FAST response
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619286: FAST reply key: aes256-cts/A0F1
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619287: TGS reply is for USERNAME@XXXXX.XXXXX.NET -> COMPUTERNAME$@XXXXX.XXXXX.NET with session key aes256-cts/26D3
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619288: TGS request result: 0/Success
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619289: Received creds for desired service COMPUTERNAME$@XXXXX.XXXXX.NET
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619290: Storing USERNAME@XXXXX.XXXXX.NET -> COMPUTERNAME$@XXXXX.XXXXX.NET in MEMORY:4eV88Mr
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619291: Creating authenticator for USERNAME@XXXXX.XXXXX.NET -> COMPUTERNAME$@XXXXX.XXXXX.NET, seqnum 0, subkey (null), session key aes256-cts/26D3
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619293: Retrieving COMPUTERNAME$@XXXXX.XXXXX.NET from MEMORY:/etc/krb5.keytab (vno 2, enctype aes256-cts) with result: 0/Success
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619294: Decrypted AP-REQ with specified server principal COMPUTERNAME$@XXXXX.XXXXX.NET: aes256-cts/0FD8
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619295: AP-REQ ticket: USERNAME@XXXXX.XXXXX.NET -> COMPUTERNAME$@XXXXX.XXXXX.NET, session key aes256-cts/26D3
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619296: Negotiated enctype based on authenticator: aes256-cts
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619297: Initializing MEMORY:rd_req2 with default princ USERNAME@XXXXX.XXXXX.NET
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619298: Storing USERNAME@XXXXX.XXXXX.NET -> COMPUTERNAME$@XXXXX.XXXXX.NET in MEMORY:rd_req2
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619299: Destroying ccache MEMORY:4eV88Mr
(2021-05-22 21:39:10): [krb5_child[12908]] [validate_tgt] (0x0400): TGT verified using key for [COMPUTERNAME$@XXXXX.XXXXX.NET]. (2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619300: Retrieving USERNAME@XXXXX.XXXXX.NET -> COMPUTERNAME$@XXXXX.XXXXX.NET from MEMORY:rd_req2 with result: 0/Success
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619301: Retrieving COMPUTERNAME$@XXXXX.XXXXX.NET from MEMORY:/etc/krb5.keytab (vno 2, enctype aes256-cts) with result: 0/Success
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_send_pac] (0x0040): sss_pac_make_request failed [-1][2]. (2021-05-22 21:39:10): [krb5_child[12908]] [validate_tgt] (0x0040): sss_send_pac failed, group membership for user with principal [USERNAME@XXXXX.XXXXX.NET@XXXXX.XXXXX.NET] might not be correct. (2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619302: Destroying ccache MEMORY:rd_req2
(2021-05-22 21:39:10): [krb5_child[12908]] [become_user] (0x0200): Trying to become user [57249832][57200513]. (2021-05-22 21:39:10): [krb5_child[12908]] [get_and_save_tgt] (0x2000): Running as [57249832][57200513]. (2021-05-22 21:39:10): [krb5_child[12908]] [sss_get_ccache_name_for_principal] (0x4000): Location: [KCM:] (2021-05-22 21:39:10): [krb5_child[12908]] [sss_get_ccache_name_for_principal] (0x4000): tmp_ccname: [KCM:57249832:57728] (2021-05-22 21:39:10): [krb5_child[12908]] [create_ccache] (0x4000): Initializing ccache of type [KCM] (2021-05-22 21:39:10): [krb5_child[12908]] [create_ccache] (0x4000): CC supports switch (2021-05-22 21:39:10): [krb5_child[12908]] [create_ccache] (0x4000): returning: 0 (2021-05-22 21:39:10): [krb5_child[12908]] [safe_remove_old_ccache_file] (0x0400): New and old ccache file are the same, none will be deleted. (2021-05-22 21:39:10): [krb5_child[12908]] [k5c_send_data] (0x0200): Received error code 0 (2021-05-22 21:39:10): [krb5_child[12908]] [pack_response_packet] (0x2000): response packet size: [117] (2021-05-22 21:39:10): [krb5_child[12908]] [k5c_send_data] (0x4000): Response sent. (2021-05-22 21:39:10): [krb5_child[12908]] [main] (0x0400): krb5_child completed successfully (2021-05-22 21:41:01): [krb5_child[14076]] [main] (0x0400): krb5_child started. (2021-05-22 21:41:01): [krb5_child[14076]] [unpack_buffer] (0x1000): total buffer size: [208] (2021-05-22 21:41:01): [krb5_child[14076]] [unpack_buffer] (0x0100): cmd [241 (auth)] uid [57249832] gid [57200513] validate [true] enterprise principal [true] offline [false] UPN [USERNAME@XXXXX.XXXXX.NET] (2021-05-22 21:41:01): [krb5_child[14076]] [unpack_buffer] (0x0100): ccname: [KCM:] old_ccname: [KCM:] keytab: [/etc/krb5.keytab] (2021-05-22 21:41:01): [krb5_child[14076]] [check_use_fast] (0x0100): Not using FAST. (2021-05-22 21:41:01): [krb5_child[14076]] [switch_creds] (0x0200): Switch user to [57249832][57200513]. (2021-05-22 21:41:01): [krb5_child[14076]] [switch_creds] (0x0200): Switch user to [0][0]. (2021-05-22 21:41:01): [krb5_child[14076]] [k5c_check_old_ccache] (0x4000): Ccache_file is [KCM:] and is not active and TGT is valid. (2021-05-22 21:41:01): [krb5_child[14076]] [k5c_precreate_ccache] (0x4000): Recreating ccache (2021-05-22 21:41:01): [krb5_child[14076]] [privileged_krb5_setup] (0x0080): Cannot open the PAC responder socket (2021-05-22 21:41:01): [krb5_child[14076]] [switch_creds] (0x0200): Switch user to [0][0]. (2021-05-22 21:41:01): [krb5_child[14076]] [switch_creds] (0x0200): Already user [0]. (2021-05-22 21:41:01): [krb5_child[14076]] [main] (0x2000): Running as [0][0]. (2021-05-22 21:41:01): [krb5_child[14076]] [set_lifetime_options] (0x0100): No specific renewable lifetime requested. (2021-05-22 21:41:01): [krb5_child[14076]] [set_lifetime_options] (0x0100): No specific lifetime requested. (2021-05-22 21:41:01): [krb5_child[14076]] [set_canonicalize_option] (0x0100): Canonicalization is set to [true] (2021-05-22 21:41:01): [krb5_child[14076]] [main] (0x0400): Will perform auth (2021-05-22 21:41:01): [krb5_child[14076]] [main] (0x0400): Will perform online auth (2021-05-22 21:41:01): [krb5_child[14076]] [tgt_req_child] (0x1000): Attempting to get a TGT (2021-05-22 21:41:01): [krb5_child[14076]] [get_and_save_tgt] (0x4000): Found Smartcard credentials, trying pkinit. (2021-05-22 21:41:01): [krb5_child[14076]] [get_pkinit_identity] (0x4000): Got [IDPrime (basic)][/usr/lib64/pkcs11/libiidp11.so]. (2021-05-22 21:41:01): [krb5_child[14076]] [get_pkinit_identity] (0x4000): Using pkinit identity [PKCS11:module_name=/usr/lib64/pkcs11/libiidp11.so:token=IDPrime (basic):certid=C0538C6C20E35F51:certlabel=Letth Gary]. (2021-05-22 21:41:01): [krb5_child[14076]] [get_and_save_tgt] (0x0400): Attempting kinit for realm [XXXXX.XXXXX.NET] (2021-05-22 21:41:01): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712461.047593: Getting initial credentials for USERNAME@XXXXX.XXXXX.NET@XXXXX.XXXXX.NET
(2021-05-22 21:41:01): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712461.047595: Sending unauthenticated request
(2021-05-22 21:41:01): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712461.047596: Sending request (236 bytes) to XXXXX.XXXXX.NET
(2021-05-22 21:41:01): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712461.047597: Initiating TCP connection to stream 192.168.0.1:88
(2021-05-22 21:41:01): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712461.047598: Sending TCP request to stream 192.168.0.1:88
(2021-05-22 21:41:01): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712461.047599: Received answer (207 bytes) from stream 192.168.0.1:88
(2021-05-22 21:41:01): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712461.047600: Terminating TCP connection to stream 192.168.0.1:88
(2021-05-22 21:41:01): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712461.047601: Response was from master KDC
(2021-05-22 21:41:01): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712461.047602: Received error from KDC: -1765328359/Additional pre-authentication required
(2021-05-22 21:41:01): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712461.047605: Preauthenticating using KDC method data
(2021-05-22 21:41:01): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712461.047606: Processing preauth types: PA-PK-AS-REQ (16), PA-PK-AS-REP_OLD (15), PA-ETYPE-INFO2 (19), PA-ENC-TIMESTAMP (2)
(2021-05-22 21:41:01): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712461.047607: Selected etype info: etype aes256-cts, salt "XXXXX.XXXXX.NETUSERNAME", params ""
(2021-05-22 21:41:01): [krb5_child[14076]] [sss_krb5_responder] (0x4000): Got question [pkinit]. (2021-05-22 21:41:01): [krb5_child[14076]] [answer_pkinit] (0x4000): [0] Identity [PKCS11:module_name=/usr/lib64/pkcs11/libiidp11.so:slotid=1:token=IDPrime (basic)] flags [0]. (2021-05-22 21:41:01): [krb5_child[14076]] [answer_pkinit] (0x4000): Setting pkinit_prompting. (2021-05-22 21:41:01): [krb5_child[14076]] [pkinit_identity_matches] (0x4000): Found [module_name=/usr/lib64/pkcs11/libiidp11.so] in identity [PKCS11:module_name=/usr/lib64/pkcs11/libiidp11.so:slotid=1:token=IDPrime (basic)]. (2021-05-22 21:41:01): [krb5_child[14076]] [pkinit_identity_matches] (0x4000): Found [token=IDPrime (basic)] in identity [PKCS11:module_name=/usr/lib64/pkcs11/libiidp11.so:slotid=1:token=IDPrime (basic)]. (2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113658: PKINIT loading CA certs and CRLs from FILE
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113659: PKINIT client computed kdc-req-body checksum 9/7A29DFAFC36D5337CCEB5A5B130F568C75C79506
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113661: PKINIT client making DH request
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113662: Preauth module pkinit (16) (real) returned: 0/Success
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113663: Produced preauth for next request: PA-PK-AS-REQ (16)
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113664: Sending request (5547 bytes) to XXXXX.XXXXX.NET
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113665: Initiating TCP connection to stream 192.168.0.1:88
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113666: Sending TCP request to stream 192.168.0.1:88
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113667: Received answer (4924 bytes) from stream 192.168.0.1:88
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113668: Terminating TCP connection to stream 192.168.0.1:88
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113669: Response was from master KDC
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113670: Processing preauth types: PA-PK-AS-REP (17)
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113671: PKINIT client verified DH reply
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113672: PKINIT client config accepts KDC dNSName SAN dc01.xxxxx.xxxxx.net
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113673: PKINIT client found dNSName SAN in KDC cert: dc01.xxxxx.xxxxx.net
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113674: PKINIT client matched KDC hostname dc01.xxxxx.xxxxx.net against dNSName SAN; EKU check still required
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113675: PKINIT client skipping EKU check due to configuration
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113676: PKINIT client found acceptable EKU in KDC cert
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113677: PKINIT client used octetstring2key to compute reply key aes256-cts/EA76
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113678: Preauth module pkinit (17) (real) returned: 0/Success
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113679: Produced preauth for next request: (empty)
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113680: AS key determined by preauth: aes256-cts/EA76
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113681: Decrypted AS reply; session key is: aes256-cts/F057
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113682: FAST negotiation: unavailable
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_krb5_expire_callback_func] (0x2000): exp_time: [514796823] (2021-05-22 21:41:02): [krb5_child[14076]] [validate_tgt] (0x2000): Found keytab entry with the realm of the credential. (2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113683: Retrieving COMPUTERNAME$@XXXXX.XXXXX.NET from MEMORY:/etc/krb5.keytab (vno 0, enctype 0) with result: 0/Success
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113684: Resolving unique ccache of type MEMORY
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113685: Initializing MEMORY:Rhk7ok0 with default princ USERNAME@XXXXX.XXXXX.NET
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113686: Storing USERNAME@XXXXX.XXXXX.NET -> krbtgt/XXXXX.XXXXX.NET@XXXXX.XXXXX.NET in MEMORY:Rhk7ok0
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113687: Getting credentials USERNAME@XXXXX.XXXXX.NET -> COMPUTERNAME$@XXXXX.XXXXX.NET using ccache MEMORY:Rhk7ok0
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113688: Retrieving USERNAME@XXXXX.XXXXX.NET -> COMPUTERNAME$@XXXXX.XXXXX.NET from MEMORY:Rhk7ok0 with result: -1765328243/Matching credential not found
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113689: Retrieving USERNAME@XXXXX.XXXXX.NET -> krbtgt/XXXXX.XXXXX.NET@XXXXX.XXXXX.NET from MEMORY:Rhk7ok0 with result: 0/Success
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113690: Starting with TGT for client realm: USERNAME@XXXXX.XXXXX.NET -> krbtgt/XXXXX.XXXXX.NET@XXXXX.XXXXX.NET
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113691: Requesting tickets for COMPUTERNAME$@XXXXX.XXXXX.NET, referrals on
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113692: Generated subkey for TGS request: aes256-cts/9265
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113693: etypes requested in TGS request: aes256-cts, aes256-sha2, camellia256-cts, aes128-cts, aes128-sha2, camellia128-cts, rc4-hmac
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113695: Encoding request body and padata into FAST request
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113696: Sending request (2445 bytes) to XXXXX.XXXXX.NET
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113697: Initiating TCP connection to stream 192.168.0.1:88
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113698: Sending TCP request to stream 192.168.0.1:88
(2021-05-22 21:41:03): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712463.010634: Received answer (2497 bytes) from stream 192.168.0.1:88
(2021-05-22 21:41:03): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712463.010635: Terminating TCP connection to stream 192.168.0.1:88
(2021-05-22 21:41:03): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712463.010636: Response was from master KDC
(2021-05-22 21:41:03): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712463.010637: Decoding FAST response
(2021-05-22 21:41:03): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712463.010638: FAST reply key: aes256-cts/4627
(2021-05-22 21:41:03): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712463.010639: TGS reply is for USERNAME@XXXXX.XXXXX.NET -> COMPUTERNAME$@XXXXX.XXXXX.NET with session key aes256-cts/AAF1
(2021-05-22 21:41:03): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712463.010640: TGS request result: 0/Success
(2021-05-22 21:41:03): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712463.010641: Received creds for desired service COMPUTERNAME$@XXXXX.XXXXX.NET
(2021-05-22 21:41:03): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712463.010642: Storing USERNAME@XXXXX.XXXXX.NET -> COMPUTERNAME$@XXXXX.XXXXX.NET in MEMORY:Rhk7ok0
(2021-05-22 21:41:03): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712463.010643: Creating authenticator for USERNAME@XXXXX.XXXXX.NET -> COMPUTERNAME$@XXXXX.XXXXX.NET, seqnum 0, subkey (null), session key aes256-cts/AAF1
(2021-05-22 21:41:03): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712463.010645: Retrieving COMPUTERNAME$@XXXXX.XXXXX.NET from MEMORY:/etc/krb5.keytab (vno 2, enctype aes256-cts) with result: 0/Success
(2021-05-22 21:41:03): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712463.010646: Decrypted AP-REQ with specified server principal COMPUTERNAME$@XXXXX.XXXXX.NET: aes256-cts/0FD8
(2021-05-22 21:41:03): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712463.010647: AP-REQ ticket: USERNAME@XXXXX.XXXXX.NET -> COMPUTERNAME$@XXXXX.XXXXX.NET, session key aes256-cts/AAF1
(2021-05-22 21:41:03): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712463.010648: Negotiated enctype based on authenticator: aes256-cts
(2021-05-22 21:41:03): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712463.010649: Initializing MEMORY:rd_req2 with default princ USERNAME@XXXXX.XXXXX.NET
(2021-05-22 21:41:03): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712463.010650: Storing USERNAME@XXXXX.XXXXX.NET -> COMPUTERNAME$@XXXXX.XXXXX.NET in MEMORY:rd_req2
(2021-05-22 21:41:03): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712463.010651: Destroying ccache MEMORY:Rhk7ok0
(2021-05-22 21:41:03): [krb5_child[14076]] [validate_tgt] (0x0400): TGT verified using key for [COMPUTERNAME$@XXXXX.XXXXX.NET]. (2021-05-22 21:41:03): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712463.010652: Retrieving USERNAME@XXXXX.XXXXX.NET -> COMPUTERNAME$@XXXXX.XXXXX.NET from MEMORY:rd_req2 with result: 0/Success
(2021-05-22 21:41:03): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712463.010653: Retrieving COMPUTERNAME$@XXXXX.XXXXX.NET from MEMORY:/etc/krb5.keytab (vno 2, enctype aes256-cts) with result: 0/Success
(2021-05-22 21:41:03): [krb5_child[14076]] [sss_send_pac] (0x0040): sss_pac_make_request failed [-1][2]. (2021-05-22 21:41:03): [krb5_child[14076]] [validate_tgt] (0x0040): sss_send_pac failed, group membership for user with principal [USERNAME@XXXXX.XXXXX.NET@XXXXX.XXXXX.NET] might not be correct. (2021-05-22 21:41:03): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712463.010654: Destroying ccache MEMORY:rd_req2
(2021-05-22 21:41:03): [krb5_child[14076]] [become_user] (0x0200): Trying to become user [57249832][57200513]. (2021-05-22 21:41:03): [krb5_child[14076]] [get_and_save_tgt] (0x2000): Running as [57249832][57200513]. (2021-05-22 21:41:03): [krb5_child[14076]] [sss_get_ccache_name_for_principal] (0x4000): Location: [KCM:] (2021-05-22 21:41:03): [krb5_child[14076]] [sss_get_ccache_name_for_principal] (0x4000): tmp_ccname: [KCM:57249832:57728] (2021-05-22 21:41:03): [krb5_child[14076]] [create_ccache] (0x4000): Initializing ccache of type [KCM] (2021-05-22 21:41:03): [krb5_child[14076]] [create_ccache] (0x4000): CC supports switch (2021-05-22 21:41:03): [krb5_child[14076]] [create_ccache] (0x4000): returning: 0 (2021-05-22 21:41:03): [krb5_child[14076]] [safe_remove_old_ccache_file] (0x0400): New and old ccache file are the same, none will be deleted. (2021-05-22 21:41:03): [krb5_child[14076]] [k5c_send_data] (0x0200): Received error code 0 (2021-05-22 21:41:03): [krb5_child[14076]] [pack_response_packet] (0x2000): response packet size: [117] (2021-05-22 21:41:03): [krb5_child[14076]] [k5c_send_data] (0x4000): Response sent. (2021-05-22 21:41:03): [krb5_child[14076]] [main] (0x0400): krb5_child completed successfully (2021-05-22 22:01:51): [krb5_child[21961]] [main] (0x0400): krb5_child started. (2021-05-22 22:01:51): [krb5_child[21961]] [unpack_buffer] (0x1000): total buffer size: [208] (2021-05-22 22:01:51): [krb5_child[21961]] [unpack_buffer] (0x0100): cmd [241 (auth)] uid [57249832] gid [57200513] validate [true] enterprise principal [true] offline [false] UPN [USERNAME@XXXXX.XXXXX.NET] (2021-05-22 22:01:51): [krb5_child[21961]] [unpack_buffer] (0x0100): ccname: [KCM:] old_ccname: [KCM:] keytab: [/etc/krb5.keytab] (2021-05-22 22:01:51): [krb5_child[21961]] [check_use_fast] (0x0100): Not using FAST. (2021-05-22 22:01:51): [krb5_child[21961]] [switch_creds] (0x0200): Switch user to [57249832][57200513]. (2021-05-22 22:01:51): [krb5_child[21961]] [switch_creds] (0x0200): Switch user to [0][0]. (2021-05-22 22:01:51): [krb5_child[21961]] [k5c_check_old_ccache] (0x4000): Ccache_file is [KCM:] and is not active and TGT is valid. (2021-05-22 22:01:51): [krb5_child[21961]] [k5c_precreate_ccache] (0x4000): Recreating ccache (2021-05-22 22:01:51): [krb5_child[21961]] [privileged_krb5_setup] (0x0080): Cannot open the PAC responder socket (2021-05-22 22:01:51): [krb5_child[21961]] [switch_creds] (0x0200): Switch user to [0][0]. (2021-05-22 22:01:51): [krb5_child[21961]] [switch_creds] (0x0200): Already user [0]. (2021-05-22 22:01:51): [krb5_child[21961]] [main] (0x2000): Running as [0][0]. (2021-05-22 22:01:51): [krb5_child[21961]] [set_lifetime_options] (0x0100): No specific renewable lifetime requested. (2021-05-22 22:01:51): [krb5_child[21961]] [set_lifetime_options] (0x0100): No specific lifetime requested. (2021-05-22 22:01:51): [krb5_child[21961]] [set_canonicalize_option] (0x0100): Canonicalization is set to [true] (2021-05-22 22:01:51): [krb5_child[21961]] [main] (0x0400): Will perform auth (2021-05-22 22:01:51): [krb5_child[21961]] [main] (0x0400): Will perform online auth (2021-05-22 22:01:51): [krb5_child[21961]] [tgt_req_child] (0x1000): Attempting to get a TGT (2021-05-22 22:01:51): [krb5_child[21961]] [get_and_save_tgt] (0x4000): Found Smartcard credentials, trying pkinit. (2021-05-22 22:01:51): [krb5_child[21961]] [get_pkinit_identity] (0x4000): Got [IDPrime (basic)][/usr/lib64/pkcs11/libiidp11.so]. (2021-05-22 22:01:51): [krb5_child[21961]] [get_pkinit_identity] (0x4000): Using pkinit identity [PKCS11:module_name=/usr/lib64/pkcs11/libiidp11.so:token=IDPrime (basic):certid=C0538C6C20E35F51:certlabel=Letth Gary]. (2021-05-22 22:01:51): [krb5_child[21961]] [get_and_save_tgt] (0x0400): Attempting kinit for realm [XXXXX.XXXXX.NET] (2021-05-22 22:01:51): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713711.008243: Getting initial credentials for USERNAME@XXXXX.XXXXX.NET@XXXXX.XXXXX.NET
(2021-05-22 22:01:51): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713711.008245: Sending unauthenticated request
(2021-05-22 22:01:51): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713711.008246: Sending request (236 bytes) to XXXXX.XXXXX.NET
(2021-05-22 22:01:51): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713711.008247: Initiating TCP connection to stream 192.168.0.2:88
(2021-05-22 22:01:51): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713711.008248: Sending TCP request to stream 192.168.0.2:88
(2021-05-22 22:01:51): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713711.008249: Received answer (207 bytes) from stream 192.168.0.2:88
(2021-05-22 22:01:51): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713711.008250: Terminating TCP connection to stream 192.168.0.2:88
(2021-05-22 22:01:51): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713711.008251: Response was from master KDC
(2021-05-22 22:01:51): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713711.008252: Received error from KDC: -1765328359/Additional pre-authentication required
(2021-05-22 22:01:51): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713711.008255: Preauthenticating using KDC method data
(2021-05-22 22:01:51): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713711.008256: Processing preauth types: PA-PK-AS-REQ (16), PA-PK-AS-REP_OLD (15), PA-ETYPE-INFO2 (19), PA-ENC-TIMESTAMP (2)
(2021-05-22 22:01:51): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713711.008257: Selected etype info: etype aes256-cts, salt "XXXXX.XXXXX.NETUSERNAME", params ""
(2021-05-22 22:01:51): [krb5_child[21961]] [sss_krb5_responder] (0x4000): Got question [pkinit]. (2021-05-22 22:01:51): [krb5_child[21961]] [answer_pkinit] (0x4000): [0] Identity [PKCS11:module_name=/usr/lib64/pkcs11/libiidp11.so:slotid=1:token=IDPrime (basic)] flags [0]. (2021-05-22 22:01:51): [krb5_child[21961]] [answer_pkinit] (0x4000): Setting pkinit_prompting. (2021-05-22 22:01:51): [krb5_child[21961]] [pkinit_identity_matches] (0x4000): Found [module_name=/usr/lib64/pkcs11/libiidp11.so] in identity [PKCS11:module_name=/usr/lib64/pkcs11/libiidp11.so:slotid=1:token=IDPrime (basic)]. (2021-05-22 22:01:51): [krb5_child[21961]] [pkinit_identity_matches] (0x4000): Found [token=IDPrime (basic)] in identity [PKCS11:module_name=/usr/lib64/pkcs11/libiidp11.so:slotid=1:token=IDPrime (basic)]. (2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123177: PKINIT loading CA certs and CRLs from FILE
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123178: PKINIT client computed kdc-req-body checksum 9/332F3229C5A54EBDD04BD0B31DA11BB162BE5DA9
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123180: PKINIT client making DH request
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123181: Preauth module pkinit (16) (real) returned: 0/Success
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123182: Produced preauth for next request: PA-PK-AS-REQ (16)
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123183: Sending request (5547 bytes) to XXXXX.XXXXX.NET
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123184: Initiating TCP connection to stream 192.168.0.2:88
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123185: Sending TCP request to stream 192.168.0.2:88
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123186: Received answer (4732 bytes) from stream 192.168.0.2:88
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123187: Terminating TCP connection to stream 192.168.0.2:88
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123188: Response was from master KDC
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123189: Processing preauth types: PA-PK-AS-REP (17)
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123190: PKINIT OpenSSL error: Failed to verify received certificate (depth 0): unable to get local issuer certificate
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123191: PKINIT client could not verify DH reply
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123192: Preauth module pkinit (17) (real) returned: -1765328314/Failed to verify received certificate (depth 0): unable to get local issuer certificate
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123193: Produced preauth for next request: (empty)
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_krb5_responder] (0x4000): Got question [password]. (2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123194: Getting AS key, salt "XXXXX.XXXXX.NETUSERNAME", params ""
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_krb5_prompter] (0x4000): sss_krb5_prompter name [(null)] banner [(null)] num_prompts [1] EINVAL. (2021-05-22 22:01:52): [krb5_child[21961]] [sss_krb5_prompter] (0x4000): Prompt [0][Password for USERNAME@XXXXX.XXXXX.NET@XXXXX.XXXXX.NET]. (2021-05-22 22:01:52): [krb5_child[21961]] [sss_krb5_prompter] (0x0200): Prompter interface isn't used for password prompts by SSSD. (2021-05-22 22:01:52): [krb5_child[21961]] [sss_krb5_get_init_creds_password] (0x0020): 1643: [-1765328254][Cannot read password] (2021-05-22 22:01:52): [krb5_child[21961]] [get_and_save_tgt] (0x0020): 1720: [-1765328254][Cannot read password] (2021-05-22 22:01:52): [krb5_child[21961]] [map_krb5_error] (0x0020): 1849: [-1765328254][Cannot read password] (2021-05-22 22:01:52): [krb5_child[21961]] [k5c_send_data] (0x0200): Received error code 1432158219 (2021-05-22 22:01:52): [krb5_child[21961]] [pack_response_packet] (0x2000): response packet size: [4] (2021-05-22 22:01:52): [krb5_child[21961]] [k5c_send_data] (0x4000): Response sent. (2021-05-22 22:01:52): [krb5_child[21961]] [main] (0x0400): krb5_child completed successfully
Am Mon, May 24, 2021 at 08:51:14AM -0000 schrieb Gary Letth:
Hi Sumit I followed your instructions to the letter and managed to log on with a smart card twice. Then on the third attempt it failed. This is what the krb5_child.log looks like:
Hi,
the first two requests use the KDC/AD DC with IP address:
...
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619247: Sending request (5547 bytes) to XXXXX.XXXXX.NET
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619248: Initiating TCP connection to stream 192.168.0.1:88
(2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619249: Sending TCP request to stream 192.168.0.1:88
...
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113664: Sending request (5547 bytes) to XXXXX.XXXXX.NET
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113665: Initiating TCP connection to stream 192.168.0.1:88
(2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113666: Sending TCP request to stream 192.168.0.1:88
While for the last the AD DC with IP address
...
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123183: Sending request (5547 bytes) to XXXXX.XXXXX.NET
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123184: Initiating TCP connection to stream 192.168.0.2:88
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123185: Sending TCP request to stream 192.168.0.2:88
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123186: Received answer (4732 bytes) from stream 192.168.0.2:88
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123187: Terminating TCP connection to stream 192.168.0.2:88
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123188: Response was from master KDC
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123189: Processing preauth types: PA-PK-AS-REP (17)
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123190: PKINIT OpenSSL error: Failed to verify received certificate (depth 0): unable to get local issuer certificate
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123191: PKINIT client could not verify DH reply
(2021-05-22 22:01:52): [krb5_child[21961]] [sss_child_krb5_trace_cb] (0x4000): [21961] 1621713712.123192: Preauth module pkinit (17) (real) returned: -1765328314/Failed to verify received certificate (depth 0): unable to get local issuer certificate
...
So it look like you have all needed certificates to verify the AD DC certificate of 192.168.0.1 in the pkinit_anchors but the one for 192.168.0.2 is missing. I guess you have added the AD DC certificate of 192.168.0.1 directly and not the one of the CA which signed it, I assume both AD DC certificates where issues by the same CA.
HTH
bye, Sumit
It turns out that there were actually one root ca and three other ca:s in the domain. I only added the root ca and one of the other ca:s to the store. Once I added all the certificates to the store everything started working as expected. Now I just need to recreate everything on a new machine to make sure I didn't miss anything.
sssd-users@lists.fedorahosted.org