On 12/09/2013 12:25 PM, Dan Candea wrote:

(Mon Dec 9 10:18:43 2013) [[sssd[krb5_child[1335]]]] [sss_child_krb5_trace_cb] (0x4000): [1335] 1386584323.605000: Getting initial credentials for testuser@2FA.TEST
(Mon Dec 9 10:18:43 2013) [[sssd[krb5_child[1335]]]] [sss_child_krb5_trace_cb] (0x4000): [1335] 1386584323.605161: FAST armor ccache: FILE:/var/lib/sss/db/fast_ccache_2FA.TEST
(Mon Dec 9 10:18:43 2013) [[sssd[krb5_child[1335]]]] [sss_child_krb5_trace_cb] (0x4000): [1335] 1386584323.605262: Retrieving ldapauth@2FA.TEST -> krb5_ccache_conf_data/fast_avail/krbtgt\/2FA.TEST\@2FA.TEST@X-CACHECONF: from FILE:/var/lib/sss/db/fast_ccache_2FA.TEST with result: -1765328243/Matching credential not found
(Mon Dec 9 10:18:43 2013) [[sssd[krb5_child[1335]]]] [sss_child_krb5_trace_cb] (0x4000): [1335] 1386584323.605391: Sending request (171 bytes) to 2FA.TEST
(Mon Dec 9 10:18:43 2013) [[sssd[krb5_child[1335]]]] [sss_child_krb5_trace_cb] (0x4000): [1335] 1386584323.605496: Resolving hostname 2fa-ad.2FA.TEST
(Mon Dec 9 10:18:43 2013) [[sssd[krb5_child[1335]]]] [sss_child_krb5_trace_cb] (0x4000): [1335] 1386584323.605791: Sending initial UDP request to dgram 10.52.13.190:88
(Mon Dec 9 10:18:43 2013) [[sssd[krb5_child[1335]]]] [sss_child_krb5_trace_cb] (0x4000): [1335] 1386584323.607384: Received answer from dgram 10.52.13.190:88
(Mon Dec 9 10:18:43 2013) [[sssd[krb5_child[1335]]]] [sss_child_krb5_trace_cb] (0x4000): [1335] 1386584323.677781: Response was not from master KDC
(Mon Dec 9 10:18:43 2013) [[sssd[krb5_child[1335]]]] [sss_child_krb5_trace_cb] (0x4000): [1335] 1386584323.677933: Salt derived from principal: 2FA.TESTtestuser
(Mon Dec 9 10:18:43 2013) [[sssd[krb5_child[1335]]]] [sss_child_krb5_trace_cb] (0x4000): [1335] 1386584323.677953: Getting AS key, salt "2FA.TESTtestuser", params ""
(Mon Dec 9 10:18:43 2013) [[sssd[krb5_child[1335]]]] [sss_child_krb5_trace_cb] (0x4000): [1335] 1386584323.678158: AS key obtained from gak_fct: rc4-hmac/9C81
(Mon Dec 9 10:18:43 2013) [[sssd[krb5_child[1335]]]] [sss_child_krb5_trace_cb] (0x4000): [1335] 1386584323.678303: Retrying AS request with master KDC

Why sssd is doing this retry?

Here is how kinit is doing

KRB5_TRACE=/dev/stderr kinit testuser
[5332] 1386592069.283264: Getting initial credentials for testuser@2FA.TEST
[5332] 1386592069.283720: Sending request (150 bytes) to 2FA.TEST
[5332] 1386592069.283838: Resolving hostname 2fa-ad.2FA.TEST
[5332] 1386592069.284143: Sending initial UDP request to dgram 10.52.13.190:88
[5332] 1386592069.289908: Received answer from dgram 10.52.13.190:88
[5332] 1386592069.335244: Response was not from master KDC
[5332] 1386592069.335375: Salt derived from principal: 2FA.TESTtestuser
[5332] 1386592069.335438: Getting AS key, salt "2FA.TESTtestuser", params ""
Password for testuser@2FA.TEST:
[5332] 1386592072.864966: AS key obtained from gak_fct: rc4-hmac/53BB
[5332] 1386592072.865226: Decrypted AS reply; session key is: rc4-hmac/8DBC
[5332] 1386592072.865349: FAST negotiation: unavailable
[5332] 1386592072.865491: Initializing FILE:/tmp/krb5cc_0 with default princ testuser@2FA.TEST
[5332] 1386592072.866066: Removing testuser@2FA.TEST -> krbtgt/2FA.TEST@2FA.TEST from FILE:/tmp/krb5cc_0
[5332] 1386592072.866184: Storing testuser@2FA.TEST -> krbtgt/2FA.TEST@2FA.TEST in FILE:/tmp/krb5cc_0

(Mon Dec 9 10:18:43 2013) [[sssd[krb5_child[1335]]]] [sss_child_krb5_trace_cb] (0x4000): [1335] 1386584323.678379: Getting initial credentials for testuser@2FA.TEST
(Mon Dec 9 10:18:43 2013) [[sssd[krb5_child[1335]]]] [sss_child_krb5_trace_cb] (0x4000): [1335] 1386584323.678501: FAST armor ccache: FILE:/var/lib/sssdb/fast_ccache_2FA.TEST
(Mon Dec 9 10:18:43 2013) [[sssd[krb5_child[1335]]]] [sss_child_krb5_trace_cb] (0x4000): [1335] 1386584323.678737: Retrieving ldapauth@2FA.TEST -> krb5_ccache_conf_data/fast_avail/krbtgt\/2FA.TEST\@2FA.TEST@X-CACHECONF: from FILE:/var/lib/sss/db/fast_ccache_2FA.TEST with result: -1765328243/Matching credential not found
(Mon Dec 9 10:18:43 2013) [[sssd[krb5_child[1335]]]] [sss_child_krb5_trace_cb] (0x4000): [1335] 1386584323.678843: Sending request (171 bytes) to 2FA.TEST (master)
(Mon Dec 9 10:18:43 2013) [[sssd[krb5_child[1335]]]] [get_and_save_tgt] (0x0020): 918: [-1765328353][Decrypt integrity check failed]
(Mon Dec 9 10:18:43 2013) [[sssd[krb5_child[1335]]]] [map_krb5_error] (0x0020): 979: [-1765328353][Decrypt integrity check failed]
(Mon Dec 9 10:18:43 2013) [[sssd[krb5_child[1335]]]] [pack_response_packet] (0x2000): response packet size: [4]
(Mon Dec 9 10:18:43 2013) [[sssd[krb5_child[1335]]]] [k5c_send_data] (0x4000): Response sent.
(Mon Dec 9 10:18:43 2013) [[sssd[krb5_child[1335]]]] [main] (0x0400): krb5_child completed successfully

-- 
Dan Cândea
Does God Play Dice?