Attachment 924785 Details for Bug 1127270 – ldap_child.log

ldap_child.log

ldap_child.log (text/x-log), 22.98 KB, created by David Spurek on 2014-08-07 08:26:00 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: David Spurek

Created: 2014-08-07 08:26:00 UTC

Size: 22.98 KB

patch

obsolete

>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [main] (0x0400): ldap_child started.
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [main] (0x2000): context initialized
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [unpack_buffer] (0x1000): total buffer size: 63
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [unpack_buffer] (0x1000): realm_str size: 9
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [unpack_buffer] (0x1000): got realm_str: TESTREALM
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [unpack_buffer] (0x1000): princ_str size: 38
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [unpack_buffer] (0x1000): got princ_str: host/x86-64-v08.lab.eng.brq.redhat.com
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [unpack_buffer] (0x1000): keytab_name size: 0
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [unpack_buffer] (0x1000): lifetime: 86400
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [main] (0x2000): getting TGT sync
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [ldap_child_get_tgt_sync] (0x2000): Kerberos context initialized
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [ldap_child_get_tgt_sync] (0x2000): got realm_name: [TESTREALM]
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [host/x86-64-v08.lab.eng.brq.redhat.com@TESTREALM]
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [default]
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [ldap_child_get_tgt_sync] (0x2000): keytab ccname: [FILE:/var/lib/sss/db/ccache_TESTREALM]
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [ldap_child_get_tgt_sync] (0x0100): Will canonicalize principals
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.534247: Getting initial credentials for host/x86-64-v08.lab.eng.brq.redhat.com@TESTREALM
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.534832: Looked up etypes in keytab: aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.540833: Sending request (208 bytes) to TESTREALM
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.541492: Sending initial UDP request to dgram 10.34.36.98:88
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.553141: Received answer from dgram 10.34.36.98:88
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.553511: Response was from master KDC
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.553604: Received error from KDC: -1765328359/Additional pre-authentication required
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.553766: Processing preauth types: 136, 19, 2, 133
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.553814: Selected etype info: etype aes256-cts, salt "(null)", params ""
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.553834: Received cookie: MIT
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.554115: Retrieving host/x86-64-v08.lab.eng.brq.redhat.com@TESTREALM from FILE:/etc/krb5.keytab (vno 0, enctype aes256-cts) with result: 0/Success
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.554348: AS key obtained for encrypted timestamp: aes256-cts/9AA4
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.554613: Encrypted timestamp (for 1407396522.554368): plain 301AA011180F32303134303830373037323834325AA1050203087580, encrypted CA1C92D6F542BE6D1A9BFFCEBDB4315736869F5414832193C2FA9D5A6B0AE35C790F2675F1A78A561FEC619F1A6616E8C8F7FDD50DF886D7
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.554654: Preauth module encrypted_timestamp (2) (flags=1) returned: 0/Success
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.554673: Produced preauth for next request: 133, 2
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.554708: Sending request (303 bytes) to TESTREALM
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.554805: Sending initial UDP request to dgram 10.34.36.98:88
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.603328: Received answer from dgram 10.34.36.98:88
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.603575: Response was from master KDC
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.603745: Processing preauth types: 19
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.603785: Selected etype info: etype aes256-cts, salt "(null)", params ""
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.603811: Produced preauth for next request: (empty)
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.603839: Salt derived from principal: TESTREALMhostx86-64-v08.lab.eng.brq.redhat.com
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.603883: AS key determined by preauth: aes256-cts/9AA4
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.604238: Decrypted AS reply; session key is: aes256-cts/070B
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.604288: FAST negotiation: available
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [ldap_child_get_tgt_sync] (0x2000): credentials initialized
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.604440: Initializing FILE:/var/lib/sss/db/ccache_TESTREALM with default princ host/x86-64-v08.lab.eng.brq.redhat.com@TESTREALM
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [main] (0x0400): ldap_child started.
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [main] (0x2000): context initialized
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [unpack_buffer] (0x1000): total buffer size: 63
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [unpack_buffer] (0x1000): realm_str size: 9
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [unpack_buffer] (0x1000): got realm_str: TESTREALM
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [unpack_buffer] (0x1000): princ_str size: 38
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [unpack_buffer] (0x1000): got princ_str: host/x86-64-v08.lab.eng.brq.redhat.com
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [unpack_buffer] (0x1000): keytab_name size: 0
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [unpack_buffer] (0x1000): lifetime: 86400
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [main] (0x2000): getting TGT sync
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [ldap_child_get_tgt_sync] (0x2000): Kerberos context initialized
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [ldap_child_get_tgt_sync] (0x2000): got realm_name: [TESTREALM]
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [host/x86-64-v08.lab.eng.brq.redhat.com@TESTREALM]
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [default]
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [ldap_child_get_tgt_sync] (0x2000): keytab ccname: [FILE:/var/lib/sss/db/ccache_TESTREALM]
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [ldap_child_get_tgt_sync] (0x0100): Will canonicalize principals
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.617687: Getting initial credentials for host/x86-64-v08.lab.eng.brq.redhat.com@TESTREALM
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.618057: Looked up etypes in keytab: aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.618160: Sending request (208 bytes) to TESTREALM
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.618889: Sending initial UDP request to dgram 10.34.36.98:88
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.627491: Received answer from dgram 10.34.36.98:88
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.627645: Response was from master KDC
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.627709: Received error from KDC: -1765328359/Additional pre-authentication required
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.627822: Processing preauth types: 136, 19, 2, 133
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.627879: Selected etype info: etype aes256-cts, salt "(null)", params ""
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.627933: Received cookie: MIT
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.628075: Retrieving host/x86-64-v08.lab.eng.brq.redhat.com@TESTREALM from FILE:/etc/krb5.keytab (vno 0, enctype aes256-cts) with result: 0/Success
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.628223: AS key obtained for encrypted timestamp: aes256-cts/9AA4
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.628368: Encrypted timestamp (for 1407396522.628255): plain 301AA011180F32303134303830373037323834325AA105020309961F, encrypted 904350E9B9AEC9AE34EBD856048C24F5010A241106C4C6FB761FF7F4CFB672DD4D04AB2EC9E783AC7F27BF1C481F7BDC8070AC18C7DC7E9C
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.628395: Preauth module encrypted_timestamp (2) (flags=1) returned: 0/Success
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.628413: Produced preauth for next request: 133, 2
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.628445: Sending request (303 bytes) to TESTREALM
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.628546: Sending initial UDP request to dgram 10.34.36.98:88
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.663161: Received answer from dgram 10.34.36.98:88
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.663410: Response was from master KDC
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.663524: Processing preauth types: 19
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.663572: Selected etype info: etype aes256-cts, salt "(null)", params ""
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.663624: Produced preauth for next request: (empty)
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.663647: Salt derived from principal: TESTREALMhostx86-64-v08.lab.eng.brq.redhat.com
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.663681: AS key determined by preauth: aes256-cts/9AA4
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.663853: Decrypted AS reply; session key is: aes256-cts/F436
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.663896: FAST negotiation: available
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [ldap_child_get_tgt_sync] (0x2000): credentials initialized
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [sss_child_krb5_trace_cb] (0x4000): [28320] 1407396522.664052: Initializing FILE:/var/lib/sss/db/ccache_TESTREALM with default princ host/x86-64-v08.lab.eng.brq.redhat.com@TESTREALM
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.844435: Removing host/x86-64-v08.lab.eng.brq.redhat.com@TESTREALM -> krbtgt/TESTREALM@TESTREALM from FILE:/var/lib/sss/db/ccache_TESTREALM
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [sss_child_krb5_trace_cb] (0x4000): [28319] 1407396522.844494: Storing host/x86-64-v08.lab.eng.brq.redhat.com@TESTREALM -> krbtgt/TESTREALM@TESTREALM in FILE:/var/lib/sss/db/ccache_TESTREALM
>
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [ldap_child_get_tgt_sync] (0x2000): credentials stored
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [ldap_child_get_tgt_sync] (0x2000): Got KDC time offset
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [prepare_response] (0x0400): Building response for result [0]
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [pack_buffer] (0x2000): response size: 57
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [pack_buffer] (0x1000): result [0] krberr [0] msgsize [37] msg [FILE:/var/lib/sss/db/ccache_TESTREALM]
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28319]]]] [main] (0x0400): ldap_child completed successfully
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [ldap_child_get_tgt_sync] (0x0040): Failed to init ccache: Internal credentials cache error
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [main] (0x0020): ldap_child_get_tgt_sync failed.
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [prepare_response] (0x0400): Building response for result [-1765328188]
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [pack_buffer] (0x2000): response size: 52
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [pack_buffer] (0x1000): result [14] krberr [-1765328188] msgsize [32] msg [Internal credentials cache error]
>(Thu Aug  7 09:28:42 2014) [[sssd[ldap_child[28320]]]] [main] (0x0400): ldap_child completed successfully
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [main] (0x0400): ldap_child started.
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [main] (0x2000): context initialized
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [unpack_buffer] (0x1000): total buffer size: 63
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [unpack_buffer] (0x1000): realm_str size: 9
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [unpack_buffer] (0x1000): got realm_str: TESTREALM
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [unpack_buffer] (0x1000): princ_str size: 38
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [unpack_buffer] (0x1000): got princ_str: host/x86-64-v08.lab.eng.brq.redhat.com
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [unpack_buffer] (0x1000): keytab_name size: 0
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [unpack_buffer] (0x1000): lifetime: 86400
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [main] (0x2000): getting TGT sync
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [ldap_child_get_tgt_sync] (0x2000): Kerberos context initialized
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [ldap_child_get_tgt_sync] (0x2000): got realm_name: [TESTREALM]
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [host/x86-64-v08.lab.eng.brq.redhat.com@TESTREALM]
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [default]
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [ldap_child_get_tgt_sync] (0x2000): keytab ccname: [FILE:/var/lib/sss/db/ccache_TESTREALM]
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [ldap_child_get_tgt_sync] (0x0100): Will canonicalize principals
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.47165: Getting initial credentials for host/x86-64-v08.lab.eng.brq.redhat.com@TESTREALM
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.47467: Looked up etypes in keytab: aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.47559: Sending request (208 bytes) to TESTREALM
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.48088: Sending initial UDP request to dgram 10.34.36.98:88
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.52041: Received answer from dgram 10.34.36.98:88
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.52146: Response was from master KDC
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.52206: Received error from KDC: -1765328359/Additional pre-authentication required
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.52303: Processing preauth types: 136, 19, 2, 133
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.52340: Selected etype info: etype aes256-cts, salt "(null)", params ""
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.52359: Received cookie: MIT
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.52427: Retrieving host/x86-64-v08.lab.eng.brq.redhat.com@TESTREALM from FILE:/etc/krb5.keytab (vno 0, enctype aes256-cts) with result: 0/Success
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.52506: AS key obtained for encrypted timestamp: aes256-cts/9AA4
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.52622: Encrypted timestamp (for 1407396589.52525): plain 301AA011180F32303134303830373037323934395AA105020300CD2D, encrypted 583AF53C676DA5037C4D45EEE7B9E075E3890F9BE985F302B48BE30D4722BEF8F6724FB7E6FE6538B2BF64F27CBD68EE427647F0E007A38E
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.52651: Preauth module encrypted_timestamp (2) (flags=1) returned: 0/Success
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.52671: Produced preauth for next request: 133, 2
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.52704: Sending request (303 bytes) to TESTREALM
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.52794: Sending initial UDP request to dgram 10.34.36.98:88
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.110665: Received answer from dgram 10.34.36.98:88
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.110957: Response was from master KDC
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.111060: Processing preauth types: 19
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.111086: Selected etype info: etype aes256-cts, salt "(null)", params ""
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.111105: Produced preauth for next request: (empty)
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.111124: Salt derived from principal: TESTREALMhostx86-64-v08.lab.eng.brq.redhat.com
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.111157: AS key determined by preauth: aes256-cts/9AA4
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.111310: Decrypted AS reply; session key is: aes256-cts/AE18
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.111347: FAST negotiation: available
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [ldap_child_get_tgt_sync] (0x2000): credentials initialized
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.111465: Initializing FILE:/var/lib/sss/db/ccache_TESTREALM with default princ host/x86-64-v08.lab.eng.brq.redhat.com@TESTREALM
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.350939: Removing host/x86-64-v08.lab.eng.brq.redhat.com@TESTREALM -> krbtgt/TESTREALM@TESTREALM from FILE:/var/lib/sss/db/ccache_TESTREALM
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [sss_child_krb5_trace_cb] (0x4000): [28330] 1407396589.351004: Storing host/x86-64-v08.lab.eng.brq.redhat.com@TESTREALM -> krbtgt/TESTREALM@TESTREALM in FILE:/var/lib/sss/db/ccache_TESTREALM
>
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [ldap_child_get_tgt_sync] (0x2000): credentials stored
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [ldap_child_get_tgt_sync] (0x2000): Got KDC time offset
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [prepare_response] (0x0400): Building response for result [0]
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [pack_buffer] (0x2000): response size: 57
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [pack_buffer] (0x1000): result [0] krberr [0] msgsize [37] msg [FILE:/var/lib/sss/db/ccache_TESTREALM]
>(Thu Aug  7 09:29:49 2014) [[sssd[ldap_child[28330]]]] [main] (0x0400): ldap_child completed successfully

Actions: View

Attachments on bug 1127270: 924785 | 924787