(Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [main] (0x0400): krb5_child started. (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [unpack_buffer] (0x1000): total buffer size: [149] (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [unpack_buffer] (0x0100): cmd [249] uid [611030030] gid [611030030] validate [true] enterprise principal [false] offline [false] UPN [myuser@SPLAT.acme.com] (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [unpack_buffer] (0x0100): ccname: [KEYRING:persistent:611030030] old_ccname: [KEYRING:persistent:611030030] keytab: [/etc/krb5.keytab] (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [k5c_setup_fast] (0x0100): Fast principal is set to [host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com] (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [find_principal_in_keytab] (0x4000): Trying to find principal host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com in keytab. (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [match_principal] (0x1000): Principal matched to the sample (host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com). (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [check_fast_ccache] (0x0200): FAST TGT is still valid. (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [become_user] (0x0200): Trying to become user [611030030][611030030]. (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [main] (0x2000): Running as [611030030][611030030]. (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [k5c_setup] (0x2000): Running as [611030030][611030030]. (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [set_lifetime_options] (0x0100): No specific renewable lifetime requested. (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [set_lifetime_options] (0x0100): No specific lifetime requested. (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [set_canonicalize_option] (0x0100): Canonicalization is set to [true] (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [main] (0x0400): Will perform pre-auth (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [tgt_req_child] (0x1000): Attempting to get a TGT (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [get_and_save_tgt] (0x0400): Attempting kinit for realm [SPLAT.acme.com] (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_child_krb5_trace_cb] (0x4000): [23515] 1554731775.16192: Getting initial credentials for myuser@SPLAT.acme.com (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_child_krb5_trace_cb] (0x4000): [23515] 1554731775.16193: FAST armor ccache: MEMORY:/var/lib/sss/db/fast_ccache_IPA.SPLAT.acme.com (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_child_krb5_trace_cb] (0x4000): [23515] 1554731775.16194: Retrieving host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com -> krb5_ccache_conf_data/fast_avail/kracmegt\/SPLAT.acme.com\@SPLAT.acme.com@X-CACHECONF: from MEMORY:/var/lib/sss/db/fast_ccache_IPA.SPLAT.acme.com with result: -1765328243/Matching credential not found (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_child_krb5_trace_cb] (0x4000): [23515] 1554731775.16196: Sending unauthenticated request (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_child_krb5_trace_cb] (0x4000): [23515] 1554731775.16197: Sending request (176 bytes) to SPLAT.acme.com (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_child_krb5_trace_cb] (0x4000): [23515] 1554731775.16198: Initiating TCP connection to stream 172.18.181.36:88 (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_child_krb5_trace_cb] (0x4000): [23515] 1554731775.16199: Sending TCP request to stream 172.18.181.36:88 (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_child_krb5_trace_cb] (0x4000): [23515] 1554731775.16200: Received answer (188 bytes) from stream 172.18.181.36:88 (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_child_krb5_trace_cb] (0x4000): [23515] 1554731775.16201: Terminating TCP connection to stream 172.18.181.36:88 (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_child_krb5_trace_cb] (0x4000): [23515] 1554731775.16202: Response was from master KDC (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_child_krb5_trace_cb] (0x4000): [23515] 1554731775.16203: Received error from KDC: -1765328359/Additional pre-authentication required (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_child_krb5_trace_cb] (0x4000): [23515] 1554731775.16206: Preauthenticating using KDC method data (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_child_krb5_trace_cb] (0x4000): [23515] 1554731775.16207: Processing preauth types: PA-PK-AS-REQ (16), PA-PK-AS-REP_OLD (15), PA-ETYPE-INFO2 (19), PA-ENC-TIMESTAMP (2) (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_child_krb5_trace_cb] (0x4000): [23515] 1554731775.16208: Selected etype info: etype aes256-cts, salt "SPLAT.acme.commyuser", params "" (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_child_krb5_trace_cb] (0x4000): [23515] 1554731775.16209: PKINIT client has no configured identity; giving up (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_krb5_responder] (0x4000): Got question [password]. (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_child_krb5_trace_cb] (0x4000): [23515] 1554731775.16210: PKINIT client has no configured identity; giving up (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_child_krb5_trace_cb] (0x4000): [23515] 1554731775.16211: Preauth module pkinit (16) (real) returned: 22/Invalid argument (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_child_krb5_trace_cb] (0x4000): [23515] 1554731775.16212: PKINIT client has no configured identity; giving up (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_child_krb5_trace_cb] (0x4000): [23515] 1554731775.16213: Preauth module pkinit (14) (real) returned: 22/Invalid argument (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_krb5_prompter] (0x4000): sss_krb5_prompter name [(null)] banner [(null)] num_prompts [1] EINVAL. (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_krb5_prompter] (0x4000): Prompt [0][Password for myuser@SPLAT.acme.com]. (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_krb5_prompter] (0x0020): Cannot handle password prompts. (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [sss_child_krb5_trace_cb] (0x4000): [23515] 1554731775.16214: Preauth module encrypted_timestamp (2) (real) returned: -1765328254/Cannot read password (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [get_and_save_tgt] (0x0400): krb5_get_init_creds_password returned [-1765328174] during pre-auth. (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [k5c_send_data] (0x0200): Received error code 0 (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [pack_response_packet] (0x2000): response packet size: [12] (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [k5c_send_data] (0x4000): Response sent. (Mon Apr 8 13:56:15 2019) [[sssd[krb5_child[23515]]]] [main] (0x0400): krb5_child completed successfully (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [main] (0x0400): krb5_child started. (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [unpack_buffer] (0x1000): total buffer size: [163] (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [unpack_buffer] (0x0100): cmd [241] uid [611030030] gid [611030030] validate [true] enterprise principal [false] offline [false] UPN [myuser@SPLAT.acme.com] (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [unpack_buffer] (0x0100): ccname: [KEYRING:persistent:611030030] old_ccname: [KEYRING:persistent:611030030] keytab: [/etc/krb5.keytab] (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [switch_creds] (0x0200): Switch user to [611030030][611030030]. (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_krb5_cc_verify_ccache] (0x2000): TGT not found or expired. (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [switch_creds] (0x0200): Switch user to [0][0]. (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [k5c_check_old_ccache] (0x4000): Ccache_file is [KEYRING:persistent:611030030] and is not active and TGT is valid. (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [k5c_precreate_ccache] (0x4000): Recreating ccache (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [k5c_setup_fast] (0x0100): Fast principal is set to [host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com] (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [find_principal_in_keytab] (0x4000): Trying to find principal host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com in keytab. (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [match_principal] (0x1000): Principal matched to the sample (host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com). (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [check_fast_ccache] (0x0200): FAST TGT is still valid. (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [become_user] (0x0200): Trying to become user [611030030][611030030]. (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [main] (0x2000): Running as [611030030][611030030]. (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [k5c_setup] (0x2000): Running as [611030030][611030030]. (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [set_lifetime_options] (0x0100): No specific renewable lifetime requested. (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [set_lifetime_options] (0x0100): No specific lifetime requested. (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [set_canonicalize_option] (0x0100): Canonicalization is set to [true] (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [main] (0x0400): Will perform online auth (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [tgt_req_child] (0x1000): Attempting to get a TGT (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [get_and_save_tgt] (0x0400): Attempting kinit for realm [SPLAT.acme.com] (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98512: Getting initial credentials for myuser@SPLAT.acme.com (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98513: FAST armor ccache: MEMORY:/var/lib/sss/db/fast_ccache_IPA.SPLAT.acme.com (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98514: Retrieving host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com -> krb5_ccache_conf_data/fast_avail/kracmegt\/SPLAT.acme.com\@SPLAT.acme.com@X-CACHECONF: from MEMORY:/var/lib/sss/db/fast_ccache_IPA.SPLAT.acme.com with result: -1765328243/Matching credential not found (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98516: Sending unauthenticated request (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98517: Sending request (176 bytes) to SPLAT.acme.com (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98518: Initiating TCP connection to stream 172.18.181.36:88 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98519: Sending TCP request to stream 172.18.181.36:88 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98520: Received answer (188 bytes) from stream 172.18.181.36:88 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98521: Terminating TCP connection to stream 172.18.181.36:88 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98522: Response was from master KDC (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98523: Received error from KDC: -1765328359/Additional pre-authentication required (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98526: Preauthenticating using KDC method data (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98527: Processing preauth types: PA-PK-AS-REQ (16), PA-PK-AS-REP_OLD (15), PA-ETYPE-INFO2 (19), PA-ENC-TIMESTAMP (2) (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98528: Selected etype info: etype aes256-cts, salt "SPLAT.acme.commyuser", params "" (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98529: PKINIT client has no configured identity; giving up (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_krb5_responder] (0x4000): Got question [password]. (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98530: PKINIT client has no configured identity; giving up (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98531: Preauth module pkinit (16) (real) returned: 22/Invalid argument (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98532: PKINIT client has no configured identity; giving up (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98533: Preauth module pkinit (14) (real) returned: 22/Invalid argument (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98534: AS key oacmeained for encrypted timestamp: aes256-cts/C957 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98536: Encrypted timestamp (for 1554731777.305935): plain 301AA011180F32303139303430383133353631375AA105020304AB0F, encrypted 4BF9FD028190ADF7450D64D540220D2ED5A0AF6CBAC6EE674047DE0B5241E3C7FAF845437A0254269B7B252F03A61B798A0608014A687D97 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98537: Preauth module encrypted_timestamp (2) (real) returned: 0/Success (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98538: Produced preauth for next request: PA-ENC-TIMESTAMP (2) (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98539: Sending request (254 bytes) to SPLAT.acme.com (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98540: Initiating TCP connection to stream 172.18.181.36:88 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98541: Sending TCP request to stream 172.18.181.36:88 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98542: Received answer (1659 bytes) from stream 172.18.181.36:88 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98543: Terminating TCP connection to stream 172.18.181.36:88 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98544: Response was from master KDC (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98545: Processing preauth types: PA-ETYPE-INFO2 (19) (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98546: Selected etype info: etype aes256-cts, salt "SPLAT.acme.commyuser", params "" (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98547: Produced preauth for next request: (empty) (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98548: AS key determined by preauth: aes256-cts/C957 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98549: Decrypted AS reply; session key is: aes256-cts/5071 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98550: FAST negotiation: unavailable (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_krb5_expire_callback_func] (0x2000): exp_time: [15832408] (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [validate_tgt] (0x2000): Keytab entry with the realm of the credential not found in keytab. Using the last entry. (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98551: Retrieving host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com from MEMORY:/etc/krb5.keytab (vno 0, enctype 0) with result: 0/Success (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98552: Resolving unique ccache of type MEMORY (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98553: Initializing MEMORY:Z4waBlx with default princ myuser@SPLAT.acme.com (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98554: Storing myuser@SPLAT.acme.com -> kracmegt/SPLAT.acme.com@SPLAT.acme.com in MEMORY:Z4waBlx (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98555: Getting credentials myuser@SPLAT.acme.com -> host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com using ccache MEMORY:Z4waBlx (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98556: Retrieving myuser@SPLAT.acme.com -> host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com from MEMORY:Z4waBlx with result: -1765328243/Matching credential not found (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98557: Retrieving myuser@SPLAT.acme.com -> kracmegt/IPA.SPLAT.acme.com@IPA.SPLAT.acme.com from MEMORY:Z4waBlx with result: -1765328243/Matching credential not found (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98558: Retrieving myuser@SPLAT.acme.com -> kracmegt/SPLAT.acme.com@SPLAT.acme.com from MEMORY:Z4waBlx with result: 0/Success (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98559: Starting with TGT for client realm: myuser@SPLAT.acme.com -> kracmegt/SPLAT.acme.com@SPLAT.acme.com (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98560: Retrieving myuser@SPLAT.acme.com -> kracmegt/IPA.SPLAT.acme.com@IPA.SPLAT.acme.com from MEMORY:Z4waBlx with result: -1765328243/Matching credential not found (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98561: Requesting TGT kracmegt/IPA.SPLAT.acme.com@SPLAT.acme.com using TGT kracmegt/SPLAT.acme.com@SPLAT.acme.com (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98562: Generated subkey for TGS request: aes256-cts/8DCD (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98563: etypes requested in TGS request: aes256-cts, aes128-cts, aes256-sha2, aes128-sha2, des3-cbc-sha1, rc4-hmac, camellia128-cts, camellia256-cts (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98565: Encoding request body and padata into FAST request (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98566: Sending request (1813 bytes) to SPLAT.acme.com (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98567: Initiating TCP connection to stream 172.18.181.36:88 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98568: Sending TCP request to stream 172.18.181.36:88 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98569: Received answer (1759 bytes) from stream 172.18.181.36:88 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98570: Terminating TCP connection to stream 172.18.181.36:88 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98571: Response was from master KDC (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98572: Decoding FAST response (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98573: FAST reply key: aes256-cts/1BAD (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98574: TGS reply is for myuser@SPLAT.acme.com -> kracmegt/IPA.SPLAT.acme.com@SPLAT.acme.com with session key aes256-cts/20C4 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98575: TGS request result: 0/Success (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98576: Storing myuser@SPLAT.acme.com -> kracmegt/IPA.SPLAT.acme.com@SPLAT.acme.com in MEMORY:Z4waBlx (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98577: Received TGT for service realm: kracmegt/IPA.SPLAT.acme.com@SPLAT.acme.com (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98578: Requesting tickets for host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com, referrals on (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98579: Generated subkey for TGS request: aes256-cts/71B0 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98580: etypes requested in TGS request: aes256-cts, aes128-cts, aes256-sha2, aes128-sha2, des3-cbc-sha1, rc4-hmac, camellia128-cts, camellia256-cts (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98582: Encoding request body and padata into FAST request (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98583: Sending request (1848 bytes) to IPA.SPLAT.acme.com (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98584: Initiating TCP connection to stream 172.18.181.132:88 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98585: Sending TCP request to stream 172.18.181.132:88 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98586: Received answer (1789 bytes) from stream 172.18.181.132:88 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98587: Terminating TCP connection to stream 172.18.181.132:88 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98588: Response was from master KDC (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98589: Decoding FAST response (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98590: FAST reply key: aes256-cts/4786 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98591: TGS reply is for myuser@SPLAT.acme.com -> host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com with session key aes256-cts/66D8 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98592: TGS request result: 0/Success (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98593: Received creds for desired service host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98594: Storing myuser@SPLAT.acme.com -> host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com in MEMORY:Z4waBlx (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98595: Creating authenticator for myuser@SPLAT.acme.com -> host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com, seqnum 0, subkey (null), session key aes256-cts/66D8 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98597: Retrieving host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com from MEMORY:/etc/krb5.keytab (vno 2, enctype aes256-cts) with result: 0/Success (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98598: Decrypted AP-REQ with specified server principal host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com: aes256-cts/D945 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98599: AP-REQ ticket: myuser@SPLAT.acme.com -> host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com, session key aes256-cts/66D8 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98600: Negotiated enctype based on authenticator: aes256-cts (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98601: Initializing MEMORY:rd_req2 with default princ myuser@SPLAT.acme.com (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98602: Storing myuser@SPLAT.acme.com -> host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com in MEMORY:rd_req2 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98603: Storing myuser@SPLAT.acme.com -> kracmegt/IPA.SPLAT.acme.com@SPLAT.acme.com in MEMORY:rd_req2 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98604: Destroying ccache MEMORY:Z4waBlx (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [validate_tgt] (0x0400): TGT verified using key for [host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com]. (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_child_krb5_trace_cb] (0x4000): [23517] 1554731777.98605: Destroying ccache MEMORY:rd_req2 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_get_ccache_name_for_principal] (0x4000): Location: [KEYRING:persistent:611030030] (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [sss_get_ccache_name_for_principal] (0x2000): krb5_cc_cache_match failed: [-1750600185][Invalid UID in persistent keyring name] (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [create_ccache] (0x0020): 982: [-1750600185][Invalid UID in persistent keyring name] (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [map_krb5_error] (0x0020): 1808: [-1750600185][Invalid UID in persistent keyring name] (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [k5c_send_data] (0x0200): Received error code 1432158209 (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [pack_response_packet] (0x2000): response packet size: [20] (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [k5c_send_data] (0x4000): Response sent. (Mon Apr 8 13:56:17 2019) [[sssd[krb5_child[23517]]]] [main] (0x0400): krb5_child completed successfully (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [main] (0x0400): krb5_child started. (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [unpack_buffer] (0x1000): total buffer size: [149] (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [unpack_buffer] (0x0100): cmd [249] uid [611030030] gid [611030030] validate [true] enterprise principal [false] offline [false] UPN [myuser@SPLAT.acme.com] (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [unpack_buffer] (0x0100): ccname: [KEYRING:persistent:611030030] old_ccname: [KEYRING:persistent:611030030] keytab: [/etc/krb5.keytab] (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [k5c_setup_fast] (0x0100): Fast principal is set to [host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com] (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [find_principal_in_keytab] (0x4000): Trying to find principal host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com in keytab. (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [match_principal] (0x1000): Principal matched to the sample (host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com). (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [check_fast_ccache] (0x0200): FAST TGT is still valid. (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [become_user] (0x0200): Trying to become user [611030030][611030030]. (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [main] (0x2000): Running as [611030030][611030030]. (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [k5c_setup] (0x2000): Running as [611030030][611030030]. (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [set_lifetime_options] (0x0100): No specific renewable lifetime requested. (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [set_lifetime_options] (0x0100): No specific lifetime requested. (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [set_canonicalize_option] (0x0100): Canonicalization is set to [true] (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [main] (0x0400): Will perform pre-auth (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [tgt_req_child] (0x1000): Attempting to get a TGT (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [get_and_save_tgt] (0x0400): Attempting kinit for realm [SPLAT.acme.com] (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_child_krb5_trace_cb] (0x4000): [23521] 1554731779.259018: Getting initial credentials for myuser@SPLAT.acme.com (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_child_krb5_trace_cb] (0x4000): [23521] 1554731779.259019: FAST armor ccache: MEMORY:/var/lib/sss/db/fast_ccache_IPA.SPLAT.acme.com (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_child_krb5_trace_cb] (0x4000): [23521] 1554731779.259020: Retrieving host/va-prod-ipa01.ipa.splat.acme.com@IPA.SPLAT.acme.com -> krb5_ccache_conf_data/fast_avail/kracmegt\/SPLAT.acme.com\@SPLAT.acme.com@X-CACHECONF: from MEMORY:/var/lib/sss/db/fast_ccache_IPA.SPLAT.acme.com with result: -1765328243/Matching credential not found (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_child_krb5_trace_cb] (0x4000): [23521] 1554731779.259022: Sending unauthenticated request (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_child_krb5_trace_cb] (0x4000): [23521] 1554731779.259023: Sending request (176 bytes) to SPLAT.acme.com (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_child_krb5_trace_cb] (0x4000): [23521] 1554731779.259024: Initiating TCP connection to stream 172.18.181.36:88 (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_child_krb5_trace_cb] (0x4000): [23521] 1554731779.259025: Sending TCP request to stream 172.18.181.36:88 (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_child_krb5_trace_cb] (0x4000): [23521] 1554731779.259026: Received answer (188 bytes) from stream 172.18.181.36:88 (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_child_krb5_trace_cb] (0x4000): [23521] 1554731779.259027: Terminating TCP connection to stream 172.18.181.36:88 (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_child_krb5_trace_cb] (0x4000): [23521] 1554731779.259028: Response was from master KDC (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_child_krb5_trace_cb] (0x4000): [23521] 1554731779.259029: Received error from KDC: -1765328359/Additional pre-authentication required (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_child_krb5_trace_cb] (0x4000): [23521] 1554731779.259032: Preauthenticating using KDC method data (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_child_krb5_trace_cb] (0x4000): [23521] 1554731779.259033: Processing preauth types: PA-PK-AS-REQ (16), PA-PK-AS-REP_OLD (15), PA-ETYPE-INFO2 (19), PA-ENC-TIMESTAMP (2) (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_child_krb5_trace_cb] (0x4000): [23521] 1554731779.259034: Selected etype info: etype aes256-cts, salt "SPLAT.acme.commyuser", params "" (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_child_krb5_trace_cb] (0x4000): [23521] 1554731779.259035: PKINIT client has no configured identity; giving up (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_krb5_responder] (0x4000): Got question [password]. (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_child_krb5_trace_cb] (0x4000): [23521] 1554731779.259036: PKINIT client has no configured identity; giving up (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_child_krb5_trace_cb] (0x4000): [23521] 1554731779.259037: Preauth module pkinit (16) (real) returned: 22/Invalid argument (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_child_krb5_trace_cb] (0x4000): [23521] 1554731779.259038: PKINIT client has no configured identity; giving up (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_child_krb5_trace_cb] (0x4000): [23521] 1554731779.259039: Preauth module pkinit (14) (real) returned: 22/Invalid argument (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_krb5_prompter] (0x4000): sss_krb5_prompter name [(null)] banner [(null)] num_prompts [1] EINVAL. (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_krb5_prompter] (0x4000): Prompt [0][Password for myuser@SPLAT.acme.com]. (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_krb5_prompter] (0x0020): Cannot handle password prompts. (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [sss_child_krb5_trace_cb] (0x4000): [23521] 1554731779.259040: Preauth module encrypted_timestamp (2) (real) returned: -1765328254/Cannot read password (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [get_and_save_tgt] (0x0400): krb5_get_init_creds_password returned [-1765328174] during pre-auth. (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [k5c_send_data] (0x0200): Received error code 0 (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [pack_response_packet] (0x2000): response packet size: [12] (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [k5c_send_data] (0x4000): Response sent. (Mon Apr 8 13:56:19 2019) [[sssd[krb5_child[23521]]]] [main] (0x0400): krb5_child completed successfully