[Freeipa-users] Centos IPA Client fails after upgrade to 6.6
Jakub Hrozek
jhrozek at redhat.com
Mon Nov 10 10:10:45 UTC 2014
On Fri, Nov 07, 2014 at 04:00:19PM -0800, Michael Lasevich wrote:
> Exactly 16 hours after reboot the problem returned on both servers. What
> has a 16 hour timeout?
>
> I set log level to 10 and got some logs, but they are long and not sure
> what I am looking for. I am attaching some logs ( out of sheer paranoia I
> have slightly sanitized them, 1.1.1.2 is the secondary IPA server,
> username at MY.DOMAIN.COM is the principle and endserver.my.domain.com is the
> IPA client this is happening on)
Thank you, I see some errors in the log:
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [get_and_save_tgt] (0x0020): 1021: [-1765328188][Internal credentials cache error]
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [map_krb5_error] (0x0020): 1043: [-1765328188][Internal credentials cache error]
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [k5c_send_data] (0x0200): Received error code 1432158209
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [pack_response_packet] (0x2000): response packet size: [20]
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [k5c_send_data] (0x4000): Response sent.
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [main] (0x0400): krb5_child completed successfully
The complete run for that particular process is:
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [main] (0x0400): krb5_child started.
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [unpack_buffer] (0x1000): total buffer size: [132]
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [unpack_buffer] (0x0100): cmd [241] uid [241600006] gid [241600006] validate [true] enterprise principal [false] offline [false] UPN [username at MY.DOMAIN.COM]
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [unpack_buffer] (0x0100): ccname: [FILE:/tmp/krb5cc_241600006_jgS4rv] keytab: [/etc/krb5.keytab]
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_RENEWABLE_LIFETIME] from environment.
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from environment.
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [set_canonicalize_option] (0x0100): SSSD_KRB5_CANONICALIZE is set to [true]
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [k5c_setup_fast] (0x0100): SSSD_KRB5_FAST_PRINCIPAL is set to [host/endserver.my.domain.com at MY.DOMAIN.COM]
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [find_principal_in_keytab] (0x4000): Trying to find principal host/endserver.my.domain.com at MY.DOMAIN.COM in keytab.
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [match_principal] (0x1000): Principal matched to the sample (host/endserver.my.domain.com at MY.DOMAIN.COM).
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401793.988922: Retrieving host/endserver.my.domain.com at MY.DOMAIN.COM -> krbtgt/MY.DOMAIN.COM at MY.DOMAIN.COM from FILE:/var/lib/sss/db/fast_ccache_MY.DOMAIN.COM with result: 0/Success
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [check_fast_ccache] (0x0200): FAST TGT is still valid.
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [main] (0x0400): Will perform online auth
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [tgt_req_child] (0x1000): Attempting to get a TGT
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [get_and_save_tgt] (0x0400): Attempting kinit for realm [MY.DOMAIN.COM]
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401793.989029: Getting initial credentials for username at MY.DOMAIN.COM
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401793.989099: FAST armor ccache: FILE:/var/lib/sss/db/fast_ccache_MY.DOMAIN.COM
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401793.989173: Retrieving host/endserver.my.domain.com at MY.DOMAIN.COM -> krb5_ccache_conf_data/fast_avail/krbtgt\/MY.DOMAIN.COM\@MY.DOMAIN.COM at X-CACHECONF: from FILE:/var/lib/sss/db/fast_ccache_MY.DOMAIN.COM with result: -1765328243/Matching credential not found
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401793.989247: Sending request (190 bytes) to MY.DOMAIN.COM
(Fri Nov 7 16:09:53 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401793.989534: Sending initial UDP request to dgram 1.1.1.2:88
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2160: Received answer from dgram 1.1.1.2:88
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2229: Response was from master KDC
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2258: Received error from KDC: -1765328359/Additional pre-authentication required
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2283: Upgrading to FAST due to presence of PA_FX_FAST in reply
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2300: Restarting to upgrade to FAST
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2320: FAST armor ccache: FILE:/var/lib/sss/db/fast_ccache_MY.DOMAIN.COM
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2390: Retrieving host/endserver.my.domain.com at MY.DOMAIN.COM -> krb5_ccache_conf_data/fast_avail/krbtgt\/MY.DOMAIN.COM\@MY.DOMAIN.COM at X-CACHECONF: from FILE:/var/lib/sss/db/fast_ccache_MY.DOMAIN.COM with result: -1765328243/Matching credential not found
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2414: Upgrading to FAST due to presence of PA_FX_FAST in reply
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2431: FAST armor ccache: FILE:/var/lib/sss/db/fast_ccache_MY.DOMAIN.COM
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2489: Retrieving host/endserver.my.domain.com at MY.DOMAIN.COM -> krb5_ccache_conf_data/fast_avail/krbtgt\/MY.DOMAIN.COM\@MY.DOMAIN.COM at X-CACHECONF: from FILE:/var/lib/sss/db/fast_ccache_MY.DOMAIN.COM with result: -1765328243/Matching credential not found
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2551: Getting credentials host/endserver.my.domain.com at MY.DOMAIN.COM -> krbtgt/MY.DOMAIN.COM at MY.DOMAIN.COM using ccache FILE:/var/lib/sss/db/fast_ccache_MY.DOMAIN.COM
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2607: Retrieving host/endserver.my.domain.com at MY.DOMAIN.COM -> krbtgt/MY.DOMAIN.COM at MY.DOMAIN.COM from FILE:/var/lib/sss/db/fast_ccache_MY.DOMAIN.COM with result: 0/Success
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2643: Armor ccache sesion key: aes256-cts/CB2D
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2694: Creating authenticator for host/endserver.my.domain.com at MY.DOMAIN.COM -> krbtgt/MY.DOMAIN.COM at MY.DOMAIN.COM, seqnum 0, subkey aes256-cts/73F3, session key aes256-cts/CB2D
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2774: FAST armor key: aes256-cts/581F
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2811: Encoding request body and padata into FAST request
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2885: Sending request (1092 bytes) to MY.DOMAIN.COM (master)
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.2978: Sending initial UDP request to dgram 1.1.1.2:88
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.7625: Received answer from dgram 1.1.1.2:88
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.7658: Received error from KDC: -1765328359/Additional pre-authentication required
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.7672: Decoding FAST response
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.7728: Processing preauth types: 136, 19, 138, 133, 137
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.7748: Selected etype info: etype aes256-cts, salt "MY.DOMAIN.COMusername", params ""
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.7759: Received cookie: MIT
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.26210: Preauth module encrypted_challenge (138) (flags=1) returned: 0/Success
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.26229: Produced preauth for next request: 133, 138
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.26239: Encoding request body and padata into FAST request
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.26287: Sending request (1190 bytes) to MY.DOMAIN.COM (master)
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.26349: Sending initial UDP request to dgram 1.1.1.2:88
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.46917: Received answer from dgram 1.1.1.2:88
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.46954: Decoding FAST response
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47024: Processing preauth types: 19, 138
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47048: Selected etype info: etype aes256-cts, salt "MY.DOMAIN.COMusername", params ""
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47104: Preauth module encrypted_challenge (138) (flags=1) returned: 0/Success
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47124: Produced preauth for next request: (empty)
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47145: AS key determined by preauth: aes256-cts/33DF
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47184: FAST reply key: aes256-cts/1E4A
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47232: Decrypted AS reply; session key is: aes256-cts/6732
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47266: FAST negotiation: available
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_krb5_expire_callback_func] (0x2000): exp_time: [10357377]
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [validate_tgt] (0x2000): Found keytab entry with the realm of the credential.
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47385: Retrieving host/endserver.my.domain.com at MY.DOMAIN.COM from FILE:/etc/krb5.keytab (vno 0, enctype 0) with result: 0/Success
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47405: Resolving unique ccache of type MEMORY
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47430: Initializing MEMORY:YCZ1t6d with default princ username at MY.DOMAIN.COM
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47451: Removing username at MY.DOMAIN.COM -> krbtgt/MY.DOMAIN.COM at MY.DOMAIN.COM from MEMORY:YCZ1t6d
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47495: Storing username at MY.DOMAIN.COM -> krbtgt/MY.DOMAIN.COM at MY.DOMAIN.COM in MEMORY:YCZ1t6d
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47527: Getting credentials username at MY.DOMAIN.COM -> host/endserver.my.domain.com at MY.DOMAIN.COM using ccache MEMORY:YCZ1t6d
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47561: Retrieving username at MY.DOMAIN.COM -> host/endserver.my.domain.com at MY.DOMAIN.COM from MEMORY:YCZ1t6d with result: -1765328243/Matching credential not found
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47592: Retrieving username at MY.DOMAIN.COM -> krbtgt/MY.DOMAIN.COM at MY.DOMAIN.COM from MEMORY:YCZ1t6d with result: 0/Success
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47613: Found cached TGT for service realm: username at MY.DOMAIN.COM -> krbtgt/MY.DOMAIN.COM at MY.DOMAIN.COM
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47630: Requesting tickets for host/endserver.my.domain.com at MY.DOMAIN.COM, referrals on
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47660: Generated subkey for TGS request: aes256-cts/4300
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47682: etypes requested in TGS request: aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47759: Sending request (761 bytes) to MY.DOMAIN.COM
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.47849: Sending initial UDP request to dgram 1.1.1.2:88
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.61746: Received answer from dgram 1.1.1.2:88
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.61822: Response was from master KDC
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.61893: TGS reply is for username at MY.DOMAIN.COM -> host/endserver.my.domain.com at MY.DOMAIN.COM with session key aes256-cts/61B8
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.61931: TGS request result: 0/Success
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.61960: Received creds for desired service host/endserver.my.domain.com at MY.DOMAIN.COM
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.61989: Removing username at MY.DOMAIN.COM -> host/endserver.my.domain.com at MY.DOMAIN.COM from MEMORY:YCZ1t6d
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.62014: Storing username at MY.DOMAIN.COM -> host/endserver.my.domain.com at MY.DOMAIN.COM in MEMORY:YCZ1t6d
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.62057: Creating authenticator for username at MY.DOMAIN.COM -> host/endserver.my.domain.com at MY.DOMAIN.COM, seqnum 0, subkey (null, session key aes256-cts/61B8
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.62152: Retrieving host/endserver.my.domain.com at MY.DOMAIN.COM from FILE:/etc/krb5.keytab (vno 1, enctype aes256-cts) with result: 0/Success
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.62213: Decrypted AP-REQ with specified server principal host/endserver.my.domain.com at MY.DOMAIN.COM: aes256-cts/AFF6
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.62244: AP-REQ ticket: username at MY.DOMAIN.COM -> host/endserver.my.domain.com at MY.DOMAIN.COM, session key aes256-cts/61B8
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.62456: Negotiated enctype based on authenticator: aes256-cts
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.62510: Initializing MEMORY:rd_req2 with default princ username at MY.DOMAIN.COM
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.62541: Removing username at MY.DOMAIN.COM -> host/endserver.my.domain.com at MY.DOMAIN.COM from MEMORY:rd_req2
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.62567: Storing username at MY.DOMAIN.COM -> host/endserver.my.domain.com at MY.DOMAIN.COM in MEMORY:rd_req2
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.62597: Destroying ccache MEMORY:YCZ1t6d
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [validate_tgt] (0x0400): TGT verified using key for [host/endserver.my.domain.com at MY.DOMAIN.COM].
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_child_krb5_trace_cb] (0x4000): [13722] 1415401794.62666: Destroying ccache MEMORY:rd_req2
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [become_user] (0x0200): Trying to become user [241600006][241600006].
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_get_ccache_name_for_principal] (0x4000): Location: [FILE:/tmp/krb5cc_241600006_jgS4rv]
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [sss_get_ccache_name_for_principal] (0x2000): krb5_cc_cache_match failed: [-1765328243][Can't find client principal username at MY.DOMAIN.COM in cache collection]
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [create_ccache] (0x4000): Initializing ccache of type [FILE]
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [get_and_save_tgt] (0x0020): 1021: [-1765328188][Internal credentials cache error]
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [map_krb5_error] (0x0020): 1043: [-1765328188][Internal credentials cache error]
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [k5c_send_data] (0x0200): Received error code 1432158209
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [pack_response_packet] (0x2000): response packet size: [20]
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [k5c_send_data] (0x4000): Response sent.
(Fri Nov 7 16:09:54 2014) [[sssd[krb5_child[13722]]]] [main] (0x0400): krb5_child completed successfully
So according to the logs, the create_ccache() function failed. Unfortunately,
we don't do very good job at logging the failures there..
Michael, are you able to run a custom package with extra debugging? It
would help us pinpoint which line actually is failing.
Thanks a lot for providing the logs!
More information about the Freeipa-users
mailing list