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 [usern...@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....@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 usern...@xxxxx.xxxxx.net (2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619269: Storing usern...@xxxxx.xxxxx.net -> krbtgt/xxxxx.xxxxx....@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 usern...@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 usern...@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 usern...@xxxxx.xxxxx.net -> krbtgt/xxxxx.xxxxx....@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: usern...@xxxxx.xxxxx.net -> krbtgt/xxxxx.xxxxx....@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 usern...@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 usern...@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 usern...@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: usern...@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 usern...@xxxxx.xxxxx.net (2021-05-22 21:39:10): [krb5_child[12908]] [sss_child_krb5_trace_cb] (0x4000): [12908] 1621712350.619298: Storing usern...@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 usern...@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....@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 [usern...@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....@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 usern...@xxxxx.xxxxx.net (2021-05-22 21:41:02): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712462.113686: Storing usern...@xxxxx.xxxxx.net -> krbtgt/xxxxx.xxxxx....@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 usern...@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 usern...@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 usern...@xxxxx.xxxxx.net -> krbtgt/xxxxx.xxxxx....@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: usern...@xxxxx.xxxxx.net -> krbtgt/xxxxx.xxxxx....@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 usern...@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 usern...@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 usern...@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: usern...@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 usern...@xxxxx.xxxxx.net (2021-05-22 21:41:03): [krb5_child[14076]] [sss_child_krb5_trace_cb] (0x4000): [14076] 1621712463.010650: Storing usern...@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 usern...@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....@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 [usern...@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....@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....@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 _______________________________________________ sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-le...@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.org Do not reply to spam on the list, report it: https://pagure.io/fedora-infrastructure
