On Thu, Jun 06, 2019 at 04:38:03AM +0000, Robert Sturrock via FreeIPA-users
wrote:
> Hi All.
>
> I have a small test installation of IPA (RHEL7,
> ipa-server-4.6.4-10.el7_6.3.x86_64) in a sync arrangement with our local AD
> (passwords sync’d via Passsync).
>
> When trying to login to the IPA server as myself (rns) or other IPA user,
> sssd seems to report going offline in krb5_child.log after initially being
> online (log level = 9 here) and the login attempt fails:
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]] [unpack_buffer]
> (0x0100): cmd [249] uid [10846] gid [10000] validate [true] enterprise
> principal [false] offline [false] UPN [rns@LOCALREALM]
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]] [unpack_buffer]
> (0x2000): No old ccache
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]] [unpack_buffer]
> (0x0100): ccname: [KEYRING:persistent:10846] old_ccname: [not set] keytab:
> [/etc/krb5.keytab]
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]] [k5c_setup_fast]
> (0x0100): Fast principal is set to [host/ipa-server.localdomain@LOCALREALM]
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [find_principal_in_keytab] (0x4000): Trying to find principal
> host/ipa-server.localdomain@LOCALREALM in keytab.
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]] [match_principal]
> (0x1000): Principal matched to the sample
> (host/ipa-server.localdomain@LOCALREALM).
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]] [get_tgt_times]
> (0x1000): FAST ccache must be recreated
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4192]]]] [become_user] (0x0200):
> Trying to become user [0][0].
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4192]]]] [become_user] (0x0200):
> Already user [0].
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4192]]]] [check_fast_ccache]
> (0x2000): Running as [0][0].
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4192]]]]
> [set_canonicalize_option] (0x0100): Canonicalization is set to [true]
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4192]]]] [create_ccache]
> (0x4000): Initializing ccache of type [FILE]
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4192]]]] [create_ccache]
> (0x4000): returning: 0
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]] [check_fast_ccache]
> (0x0200): FAST TGT was successfully recreated!
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]] [become_user] (0x0200):
> Trying to become user [10846][10000].
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]] [main] (0x2000):
> Running as [10846][10000].
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]] [k5c_setup] (0x2000):
> Running as [10846][10000].
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]] [set_lifetime_options]
> (0x0100): No specific renewable lifetime requested.
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]] [set_lifetime_options]
> (0x0100): No specific lifetime requested.
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [set_canonicalize_option] (0x0100): Canonicalization is set to [true]
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]] [main] (0x0400): Will
> perform pre-auth
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]] [tgt_req_child]
> (0x1000): Attempting to get a TGT
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]] [get_and_save_tgt]
> (0x0400): Attempting kinit for realm [LOCALREALM]
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205507: Getting initial
> credentials for rns@LOCALREALM
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205508: FAST armor
> ccache: MEMORY:/var/lib/sss/db/fast_ccache_LOCALREALM
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205509: Retrieving
> host/ipa-server.localdomain@LOCALREALM ->
> krb5_ccache_conf_data/fast_avail/krbtgt\/LOCALREALM\@LOCALREALM@X-CACHECONF:
> from MEMORY:/var/lib/sss/db/fast_ccache_LOCALREALM with result:
> -1765328243/Matching credential not found
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205511: Sending
> unauthenticated request
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205512: Sending request
> (189 bytes) to LOCALREALM
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205513: Initiating TCP
> connection to stream 172.22.6.6:88
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205514: Sending TCP
> request to stream 172.22.6.6:88
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205515: Received answer
> (327 bytes) from stream 172.22.6.6:88
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205516: Terminating TCP
> connection to stream 172.22.6.6:88
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205517: Response was
> from master KDC
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205518: Received error
> from KDC: -1765328359/Additional pre-authentication required
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205519: Upgrading to
> FAST due to presence of PA_FX_FAST in reply
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205520: FAST armor
> ccache: MEMORY:/var/lib/sss/db/fast_ccache_LOCALREALM
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205521: Retrieving
> host/ipa-server.localdomain@LOCALREALM ->
> krb5_ccache_conf_data/fast_avail/krbtgt\/LOCALREALM\@LOCALREALM@X-CACHECONF:
> from MEMORY:/var/lib/sss/db/fast_ccache_LOCALREALM with result:
> -1765328243/Matching credential not found
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205522: Getting
> credentials host/ipa-server.localdomain@LOCALREALM ->
> krbtgt/LOCALREALM@LOCALREALM using ccache
> MEMORY:/var/lib/sss/db/fast_ccache_LOCALREALM
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205523: Retrieving
> host/ipa-server.localdomain@LOCALREALM -> krbtgt/LOCALREALM@LOCALREALM from
> MEMORY:/var/lib/sss/db/fast_ccache_LOCALREALM with result: 0/Success
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205524: Armor ccache
> sesion key: aes256-cts/F8B1
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205526: Creating
> authenticator for host/ipa-server.localdomain@LOCALREALM ->
> krbtgt/LOCALREALM@LOCALREALM, seqnum 0, subkey aes256-cts/D6BB, session key
> aes256-cts/F8B1
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205528: FAST armor key:
> aes256-cts/B572
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205530: Sending
> unauthenticated request
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205531: Encoding
> request body and padata into FAST request
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205532: Sending request
> (1793 bytes) to LOCALREALM
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205533: Initiating TCP
> connection to stream 172.22.6.6:88
>
> (Thu Jun 6 13:47:02 2019) [[sssd[krb5_child[4191]]]]
> [sss_child_krb5_trace_cb] (0x4000): [4191] 1559792822.205534: Sending TCP
> request to stream 172.22.6.6:88
Hi,
looks like the request to get a ticket for the host itself which is used
as FAST armor ticket times out.
Can you try if
KRB5_TRACE=/dev/stdout kinit -k 'host/ipa-server.localdomain@LOCALREALM'
works as expected or if there is a delay as well and send the output?
bye,
Sumit
>
> (Thu Jun 6 13:47:11 2019) [[sssd[krb5_child[4218]]]] [main] (0x0400):
> krb5_child started.
> (Thu Jun 6 13:47:11 2019) [[sssd[krb5_child[4218]]]] [unpack_buffer]
> (0x1000): total buffer size: [130]
> (Thu Jun 6 13:47:11 2019) [[sssd[krb5_child[4218]]]] [unpack_buffer]
> (0x0100): cmd [241] uid [10846] gid [10000] validate [true] enterprise
> principal [false] offline [true] UPN [rns@LOCALREALM]
> (Thu Jun 6 13:47:11 2019) [[sssd[krb5_child[4218]]]] [unpack_buffer]
> (0x2000): No old ccache
> (Thu Jun 6 13:47:11 2019) [[sssd[krb5_child[4218]]]] [unpack_buffer]
> (0x0100): ccname: [KEYRING:persistent:10846] old_ccname: [not set] keytab:
> [/etc/krb5.keytab]
> (Thu Jun 6 13:47:11 2019) [[sssd[krb5_child[4218]]]] [k5c_precreate_ccache]
> (0x4000): Recreating ccache
> (Thu Jun 6 13:47:11 2019) [[sssd[krb5_child[4218]]]] [become_user] (0x0200):
> Trying to become user [10846][10000].
> (Thu Jun 6 13:47:11 2019) [[sssd[krb5_child[4218]]]] [main] (0x2000):
> Running as [10846][10000].
> (Thu Jun 6 13:47:11 2019) [[sssd[krb5_child[4218]]]] [become_user] (0x0200):
> Trying to become user [10846][10000].
> (Thu Jun 6 13:47:11 2019) [[sssd[krb5_child[4218]]]] [become_user] (0x0200):
> Already user [10846].
> (Thu Jun 6 13:47:11 2019) [[sssd[krb5_child[4218]]]] [k5c_setup] (0x2000):
> Running as [10846][10000].
> (Thu Jun 6 13:47:11 2019) [[sssd[krb5_child[4218]]]] [set_lifetime_options]
> (0x0100): No specific renewable lifetime requested.
> (Thu Jun 6 13:47:11 2019) [[sssd[krb5_child[4218]]]] [set_lifetime_options]
> (0x0100): No specific lifetime requested.
> (Thu Jun 6 13:47:11 2019) [[sssd[krb5_child[4218]]]] [main] (0x0400): Will
> perform offline auth
>
>
> Can someone with more knowledge of IPA provide some pointers as to what I
> should look for to help debug this issue? A plain old ‘kinit
> rns@LOCALDOMAIN’ works fine, FWIW.
>
> Regards,
>
> Robert.
> _______________________________________________
> FreeIPA-users mailing list -- [email protected]
> To unsubscribe send an email to [email protected]
> Fedora Code of Conduct: https://getfedora.org/code-of-conduct.html
> List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
> List Archives:
> https://lists.fedorahosted.org/archives/list/[email protected]
_______________________________________________
FreeIPA-users mailing list -- [email protected]
To unsubscribe send an email to [email protected]
Fedora Code of Conduct: https://getfedora.org/code-of-conduct.html
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives:
https://lists.fedorahosted.org/archives/list/[email protected]
