Attachment 876800 Details for Bug 1078840 – krb5_child.log

krb5_child.log

krb5_child.log (text/plain), 31.33 KB, created by Kaushik Banerjee on 2014-03-20 12:10:23 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Kaushik Banerjee

Created: 2014-03-20 12:10:23 UTC

Size: 31.33 KB

patch

obsolete

>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [main] (0x0400): krb5_child started.
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [unpack_buffer] (0x1000): total buffer size: [120]
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [unpack_buffer] (0x0100): cmd [241] uid [770844639] gid [770800513] validate [true] enterprise principal [true] offline [false] UPN [aduser1@SSSDAD.COM]
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [unpack_buffer] (0x0100): ccname: [KEYRING:persistent:770844639] keytab: [/etc/krb5.keytab]
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [k5c_setup] (0x0100): Cannot read [SSSD_KRB5_RENEWABLE_LIFETIME] from environment.
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [k5c_setup] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from environment.
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [krb5_set_canonicalize] (0x0100): SSSD_KRB5_CANONICALIZE is set to [true]
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [k5c_setup] (0x0100): Not using FAST.
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [main] (0x0400): Will perform online auth
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [tgt_req_child] (0x1000): Attempting to get a TGT
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [get_and_save_tgt] (0x0400): Attempting kinit for realm [SSSDAD.COM]
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.789690: Getting initial credentials for aduser1\@SSSDAD.COM@SSSDAD.COM
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.789838: Sending request (195 bytes) to SSSDAD.COM
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.790031: Sending initial UDP request to dgram 10.65.206.100:88
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.791170: Received answer from dgram 10.65.206.100:88
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.791236: Response was from master KDC
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.791273: Received error from KDC: -1765328359/Additional pre-authentication required
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.791320: Processing preauth types: 16, 15, 19, 2
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.791348: Selected etype info: etype aes256-cts, salt "SSSDAD.COMaduser1", params ""
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.802965: AS key obtained for encrypted timestamp: aes256-cts/D64A
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.803037: Encrypted timestamp (for 1395316581.802995): plain 301AA011180F32303134303332303131353632315AA10502030C40B3, encrypted 77E11811A85AAA059A9F2B301506310C9FD177BE5E6BFF356D966697D93AF828EADD60C003052A7B801159D89B8D6040CCBBEBD65947F1BC
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.803067: Preauth module encrypted_timestamp (2) (flags=1) returned: 0/Success
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.803087: Produced preauth for next request: 2
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.803115: Sending request (275 bytes) to SSSDAD.COM
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.803203: Sending initial UDP request to dgram 10.65.206.100:88
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.804191: Received answer from dgram 10.65.206.100:88
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.804260: Response was from master KDC
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.804289: Received error from KDC: -1765328361/Password has expired
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.804324: Preauth tryagain input types: 16, 15, 19, 2
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [get_and_save_tgt] (0x0020): 905: [-1765328361][Password has expired]
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [tgt_req_child] (0x1000): Password was expired
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.804889: Getting initial credentials for aduser1\@SSSDAD.COM@SSSDAD.COM
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.804928: Setting initial creds service to kadmin/changepw
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.804971: Sending request (174 bytes) to SSSDAD.COM
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.805030: Sending initial UDP request to dgram 10.65.206.100:88
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.806094: Received answer from dgram 10.65.206.100:88
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.806168: Response was from master KDC
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.806205: Received error from KDC: -1765328359/Additional pre-authentication required
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.806242: Processing preauth types: 16, 15, 19, 2
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.806264: Selected etype info: etype aes256-cts, salt "SSSDAD.COMaduser1", params ""
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.820359: AS key obtained for encrypted timestamp: aes256-cts/D64A
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.820438: Encrypted timestamp (for 1395316581.820404): plain 301AA011180F32303134303332303131353632315AA10502030C84B4, encrypted 287BA13B215181FFF639A20DC0B3C19F8BE6D000DEFC6C933430AF306B89E4FD5B3C26AE0F1275A37B499188999A49EDAB15F31E07D60F22
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.820464: Preauth module encrypted_timestamp (2) (flags=1) returned: 0/Success
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.820482: Produced preauth for next request: 2
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.820507: Sending request (252 bytes) to SSSDAD.COM
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.820588: Sending initial UDP request to dgram 10.65.206.100:88
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.822249: Received answer from dgram 10.65.206.100:88
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.822319: Response was from master KDC
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.822353: Processing preauth types: 19
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.822425: Selected etype info: etype aes256-cts, salt "SSSDAD.COMaduser1", params ""
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.822446: Produced preauth for next request: (empty)
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.822465: AS key determined by preauth: aes256-cts/D64A
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.822520: Decrypted AS reply; session key is: rc4-hmac/119E
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [sss_child_krb5_trace_cb] (0x4000): [11475] 1395316581.822540: FAST negotiation: unavailable
>
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [pack_response_packet] (0x2000): response packet size: [4]
>(Thu Mar 20 17:26:21 2014) [[sssd[krb5_child[11475]]]] [k5c_send_data] (0x4000): Response sent.
>(Thu Mar 20 17:26:21 2014) [ýýýýýýýýýýýýýýýýýýýýýýýýýý] [main] (0x0400): krb5_child completed successfully
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [main] (0x0400): krb5_child started.
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [unpack_buffer] (0x1000): total buffer size: [120]
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [unpack_buffer] (0x0100): cmd [247] uid [770844639] gid [770800513] validate [true] enterprise principal [true] offline [false] UPN [aduser1@SSSDAD.COM]
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [unpack_buffer] (0x0100): ccname: [KEYRING:persistent:770844639] keytab: [/etc/krb5.keytab]
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [k5c_setup] (0x0100): Cannot read [SSSD_KRB5_RENEWABLE_LIFETIME] from environment.
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [k5c_setup] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from environment.
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [krb5_set_canonicalize] (0x0100): SSSD_KRB5_CANONICALIZE is set to [true]
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [k5c_setup] (0x0100): Not using FAST.
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [main] (0x0400): Will perform password change checks
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [changepw_child] (0x1000): Password change operation
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [changepw_child] (0x0400): Attempting kinit for realm [SSSDAD.COM]
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.818873: Getting initial credentials for aduser1\@SSSDAD.COM@SSSDAD.COM
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.818977: Setting initial creds service to kadmin/changepw
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.819040: Sending request (174 bytes) to SSSDAD.COM
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.819226: Sending initial UDP request to dgram 10.65.206.100:88
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.820432: Received answer from dgram 10.65.206.100:88
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.820512: Response was from master KDC
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.820554: Received error from KDC: -1765328359/Additional pre-authentication required
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.820596: Processing preauth types: 16, 15, 19, 2
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.820624: Selected etype info: etype aes256-cts, salt "SSSDAD.COMaduser1", params ""
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.831993: AS key obtained for encrypted timestamp: aes256-cts/D64A
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.832068: Encrypted timestamp (for 1395316585.832022): plain 301AA011180F32303134303332303131353632355AA10502030CB216, encrypted B8B42CAA869D67823FDF5908F0D646C5EB97C65D292492D233060DE1E266771E25670F89B389A8FAC3FD921A80CEA745ED7CA14BE86F840E
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.832099: Preauth module encrypted_timestamp (2) (flags=1) returned: 0/Success
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.832119: Produced preauth for next request: 2
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.832148: Sending request (252 bytes) to SSSDAD.COM
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.832239: Sending initial UDP request to dgram 10.65.206.100:88
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.833729: Received answer from dgram 10.65.206.100:88
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.833818: Response was from master KDC
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.833867: Processing preauth types: 19
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.833891: Selected etype info: etype aes256-cts, salt "SSSDAD.COMaduser1", params ""
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.833910: Produced preauth for next request: (empty)
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.833931: AS key determined by preauth: aes256-cts/D64A
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.833993: Decrypted AS reply; session key is: rc4-hmac/3DE1
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [sss_child_krb5_trace_cb] (0x4000): [11480] 1395316585.834015: FAST negotiation: unavailable
>
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [changepw_child] (0x1000): Initial authentication for change password operation successful.
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [pack_response_packet] (0x2000): response packet size: [4]
>(Thu Mar 20 17:26:25 2014) [[sssd[krb5_child[11480]]]] [k5c_send_data] (0x4000): Response sent.
>(Thu Mar 20 17:26:25 2014) [ýýýýýýýýýýýýýýýýýýýýýýýýýý] [main] (0x0400): krb5_child completed successfully
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [main] (0x0400): krb5_child started.
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [unpack_buffer] (0x1000): total buffer size: [140]
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [unpack_buffer] (0x0100): cmd [246] uid [770844639] gid [770800513] validate [true] enterprise principal [true] offline [false] UPN [aduser1@SSSDAD.COM]
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [unpack_buffer] (0x0100): ccname: [KEYRING:persistent:770844639] keytab: [/etc/krb5.keytab]
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [k5c_setup] (0x0100): Cannot read [SSSD_KRB5_RENEWABLE_LIFETIME] from environment.
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [k5c_setup] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from environment.
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [krb5_set_canonicalize] (0x0100): SSSD_KRB5_CANONICALIZE is set to [true]
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [k5c_setup] (0x0100): Not using FAST.
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [main] (0x0400): Will perform password change
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [changepw_child] (0x1000): Password change operation
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [changepw_child] (0x0400): Attempting kinit for realm [SSSDAD.COM]
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.809638: Getting initial credentials for aduser1\@SSSDAD.COM@SSSDAD.COM
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.809750: Setting initial creds service to kadmin/changepw
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.809816: Sending request (174 bytes) to SSSDAD.COM
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.810003: Sending initial UDP request to dgram 10.65.206.100:88
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.811116: Received answer from dgram 10.65.206.100:88
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.811203: Response was from master KDC
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.811244: Received error from KDC: -1765328359/Additional pre-authentication required
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.811286: Processing preauth types: 16, 15, 19, 2
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.811312: Selected etype info: etype aes256-cts, salt "SSSDAD.COMaduser1", params ""
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.823018: AS key obtained for encrypted timestamp: aes256-cts/D64A
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.823091: Encrypted timestamp (for 1395316604.823047): plain 301AA011180F32303134303332303131353634345AA10502030C8F07, encrypted 27DA441A83E2DC52F3107E06817967600672C3AB361CC60F316BF9D716D922BC20652F5F01653BB1E180C4F30AB8F3245959C72B63E2F2E8
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.823120: Preauth module encrypted_timestamp (2) (flags=1) returned: 0/Success
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.823139: Produced preauth for next request: 2
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.823167: Sending request (252 bytes) to SSSDAD.COM
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.823251: Sending initial UDP request to dgram 10.65.206.100:88
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.824790: Received answer from dgram 10.65.206.100:88
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.824869: Response was from master KDC
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.824912: Processing preauth types: 19
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.824934: Selected etype info: etype aes256-cts, salt "SSSDAD.COMaduser1", params ""
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.824953: Produced preauth for next request: (empty)
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.824973: AS key determined by preauth: aes256-cts/D64A
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.825029: Decrypted AS reply; session key is: rc4-hmac/2269
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.825057: FAST negotiation: unavailable
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.825141: Creating authenticator for aduser1\@SSSDAD.COM@SSSDAD.COM -> kadmin/changepw@SSSDAD.COM, seqnum 0, subkey rc4-hmac/8227, session key rc4-hmac/2269
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.825266: Sending initial UDP request to dgram 10.65.206.100:464
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.890833: Received answer from dgram 10.65.206.100:464
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.890972: Read AP-REP, time 1395316604.825165, subkey (null), seqnum 0
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [get_and_save_tgt] (0x0400): Attempting kinit for realm [SSSDAD.COM]
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.891102: Getting initial credentials for aduser1\@SSSDAD.COM@SSSDAD.COM
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.891198: Sending request (176 bytes) to SSSDAD.COM
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.891294: Sending initial UDP request to dgram 10.65.206.100:88
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.892245: Received answer from dgram 10.65.206.100:88
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.892327: Response was from master KDC
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.892431: Received error from KDC: -1765328359/Additional pre-authentication required
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.892493: Processing preauth types: 16, 15, 19, 2
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.892526: Selected etype info: etype aes256-cts, salt "SSSDAD.COMaduser1", params ""
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.906341: AS key obtained for encrypted timestamp: aes256-cts/71A3
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.906424: Encrypted timestamp (for 1395316604.906389): plain 301AA011180F32303134303332303131353634345AA10502030DD495, encrypted C86B66F2A2D9C489DDE2A818ED0C72D2B1157B076AE73CAD55E104A1AC23552325E43EBACB631FC5A44B0CF6D53B50E2B118032C7E086C0E
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.906451: Preauth module encrypted_timestamp (2) (flags=1) returned: 0/Success
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.906469: Produced preauth for next request: 2
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.906495: Sending request (254 bytes) to SSSDAD.COM
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.906590: Sending initial UDP request to dgram 10.65.206.100:88
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.908046: Received answer from dgram 10.65.206.100:88
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.908122: Response was from master KDC
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.908155: Processing preauth types: 19
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.908183: Selected etype info: etype aes256-cts, salt "SSSDAD.COMaduser1", params ""
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.908202: Produced preauth for next request: (empty)
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.908221: AS key determined by preauth: aes256-cts/71A3
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.908266: Decrypted AS reply; session key is: rc4-hmac/88AA
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.908284: FAST negotiation: unavailable
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_krb5_expire_callback_func] (0x2000): exp_time: [3628646]
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [validate_tgt] (0x2000): Found keytab entry with the realm of the credential.
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.908528: Retrieving host/dhcp207-186.sssdad.com@SSSDAD.COM from FILE:/etc/krb5.keytab (vno 0, enctype 0) with result: 0/Success
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.908553: Resolving unique ccache of type MEMORY
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.908582: Initializing MEMORY:jmz1dLS with default princ aduser1\@SSSDAD.COM@SSSDAD.COM
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.908605: Removing aduser1\@SSSDAD.COM@SSSDAD.COM -> krbtgt/SSSDAD.COM@SSSDAD.COM from MEMORY:jmz1dLS
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.908624: Storing aduser1\@SSSDAD.COM@SSSDAD.COM -> krbtgt/SSSDAD.COM@SSSDAD.COM in MEMORY:jmz1dLS
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.908653: Getting credentials aduser1\@SSSDAD.COM@SSSDAD.COM -> host/dhcp207-186.sssdad.com@SSSDAD.COM using ccache MEMORY:jmz1dLS
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.908711: Retrieving aduser1\@SSSDAD.COM@SSSDAD.COM -> host/dhcp207-186.sssdad.com@SSSDAD.COM from MEMORY:jmz1dLS with result: -1765328243/Matching credential not found
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.908792: Retrieving aduser1\@SSSDAD.COM@SSSDAD.COM -> krbtgt/SSSDAD.COM@SSSDAD.COM from MEMORY:jmz1dLS with result: 0/Success
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.908820: Found cached TGT for service realm: aduser1\@SSSDAD.COM@SSSDAD.COM -> krbtgt/SSSDAD.COM@SSSDAD.COM
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.908840: Requesting tickets for host/dhcp207-186.sssdad.com@SSSDAD.COM, referrals on
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.908874: Generated subkey for TGS request: rc4-hmac/3D0B
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.908918: etypes requested in TGS request: aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac, camellia128-cts, camellia256-cts
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.908982: Encoding request body and padata into FAST request
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.909054: Sending request (1619 bytes) to SSSDAD.COM
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.909126: Initiating TCP connection to stream 10.65.206.100:88
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.909765: Sending TCP request to stream 10.65.206.100:88
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.911494: Received answer from stream 10.65.206.100:88
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.911573: Response was from master KDC
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.911607: Decoding FAST response
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.911666: TGS reply is for aduser1\@SSSDAD.COM@SSSDAD.COM -> host/dhcp207-186.sssdad.com@SSSDAD.COM with session key rc4-hmac/79FB
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.911702: TGS request result: 0/Success
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.911722: Received creds for desired service host/dhcp207-186.sssdad.com@SSSDAD.COM
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.911762: Removing aduser1\@SSSDAD.COM@SSSDAD.COM -> host/dhcp207-186.sssdad.com@SSSDAD.COM from MEMORY:jmz1dLS
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.911800: Storing aduser1\@SSSDAD.COM@SSSDAD.COM -> host/dhcp207-186.sssdad.com@SSSDAD.COM in MEMORY:jmz1dLS
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.911869: Creating authenticator for aduser1\@SSSDAD.COM@SSSDAD.COM -> host/dhcp207-186.sssdad.com@SSSDAD.COM, seqnum 0, subkey (null), session key rc4-hmac/79FB
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.912008: Retrieving host/dhcp207-186.sssdad.com@SSSDAD.COM from FILE:/etc/krb5.keytab (vno 2, enctype rc4-hmac) with result: 0/Success
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.912082: Decrypted AP-REQ with specified server principal host/dhcp207-186.sssdad.com@SSSDAD.COM: rc4-hmac/7C3B
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.912129: AP-REQ ticket: aduser1\@SSSDAD.COM@SSSDAD.COM -> host/dhcp207-186.sssdad.com@SSSDAD.COM, session key rc4-hmac/79FB
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [sss_child_krb5_trace_cb] (0x4000): [11490] 1395316604.912757: Destroying ccache MEMORY:jmz1dLS
>
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [validate_tgt] (0x0020): TGT failed verification using key for [host/dhcp207-186.sssdad.com@SSSDAD.COM].
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [get_and_save_tgt] (0x0020): 912: [22][Invalid argument]
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [map_krb5_error] (0x0020): 966: [22][Invalid argument]
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [pack_response_packet] (0x2000): response packet size: [20]
>(Thu Mar 20 17:26:44 2014) [[sssd[krb5_child[11490]]]] [k5c_send_data] (0x4000): Response sent.
>(Thu Mar 20 17:26:44 2014) [ýýýýýýýýýýýýýýýýýýýýýýýýýý] [main] (0x0400): krb5_child completed successfully

Actions: View

Attachments on bug 1078840: 876800