[Freeipa-users] Debugging failed password checks (SSH) for AD users at the other end of 1-way trusts

List dedicated to discussions about use, configuration and deployment of the IPA server. freeipa-users at redhat.com
Tue Dec 6 20:17:33 UTC 2016


Appreciate the assistance!

Is there a better debug level balance than 10 for this sort of 
situation? The domain logs were several hundred MBs by the time I 
started looking for useful info if there is a different level I can use 
that would better at producing actionable error/log messages I'll gladly 
switch ...


List dedicated to discussions about use, configuration and deployment of 
the IPA server. wrote:
>> (Tue Dec  6 15:36:48 2016) [[sssd[krb5_child[4005]]]] [main] (0x0400):
>> >  krb5_child started.
>> >  (Tue Dec  6 15:36:48 2016) [[sssd[krb5_child[4005]]]] [unpack_buffer]
>> >  (0x1000): total buffer size: [158]
>> >  (Tue Dec  6 15:36:48 2016) [[sssd[krb5_child[4005]]]] [unpack_buffer]
>> >  (0x0100): cmd [241] uid [1843770609] gid [1843770609] validate [false]
>> >  enterprise principal [false] offline [true] UPN [user at COMPANY.ORG]
>
>                                ^^^^^^^^^^^^^^^
>
> The backend switch to offline mode, please send the SSSD domain logs
> around this time as well. If possible please start about 5 minutes
> earlier.
>
> bye,
> Sumit

I searched through the massive SSSD domain logs and had trouble finding 
the right area so here are the lines surrounding my own username when I 
tried to authenticate via SSH using AD credentials:


/var/log/sssd/sssd_DOMAIN.log  (Sanitized)
-------------------------------------------
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[be_req_set_domain] (0x0400): Changing request domain from 
[company-idm.org] to [NAFTA.COMPANY.ORG]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] [ldb] (0x4000): 
Added timed event "ltdb_callback": 0x7f78cb39e850

(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] [ldb] (0x4000): 
Added timed event "ltdb_timeout": 0x7f78cb3b7200

(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] [ldb] (0x4000): 
Running timer event 0x7f78cb39e850 "ltdb_callback"

(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] [ldb] (0x4000): 
Destroying timer event 0x7f78cb3b7200 "ltdb_timeout"

(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] [ldb] (0x4000): 
Ending timer event 0x7f78cb39e850 "ltdb_callback"

(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_id_op_connect_step] (0x4000): reusing cached connection
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_id_op_connect_step] (0x4000): reusing cached connection
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[ipa_get_ad_override_connect_done] (0x4000): Searching for overrides in 
view [Default Trust View] with filter 
[(&(objectClass=ipaUserOverride)(uid=t859531))].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_print_server] (0x2000): Searching 10.127.64.11
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with 
[(&(objectClass=ipaUserOverride)(uid=t859531))][cn=Default Trust 
View,cn=views,cn=accounts,dc=companyidm,dc=org].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 118
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] [sdap_op_add] 
(0x2000): New operation 118 timeout 60
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_process_result] (0x2000): Trace: sh[0x7f78cb2224a0], connected[1], 
ops[0x7f78cb39efa0], ldap[0x7f78cb1cfb40]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no 
errmsg set
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_op_destructor] (0x2000): Operation 117 finished
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[ipa_get_ad_override_done] (0x4000): No override found with filter 
[(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:SID:S-1-5-21-299502267-823518204-725345543-160433))].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_id_op_destroy] (0x4000): releasing operation connection
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_id_op_destroy] (0x4000): releasing operation connection
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success 
(Success)
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_process_result] (0x2000): Trace: sh[0x7f78cb2224a0], connected[1], 
ops[0x7f78cb39efa0], ldap[0x7f78cb1cfb40]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no 
errmsg set
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_op_destructor] (0x2000): Operation 118 finished
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[ipa_get_ad_override_done] (0x4000): No override found with filter 
[(&(objectClass=ipaUserOverride)(uid=t859531))].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_id_op_destroy] (0x4000): releasing operation connection
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[ipa_srv_ad_acct_lookup_step] (0x0400): Looking up AD account
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_id_op_connect_step] (0x4000): reusing cached connection
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_initgr_send] (0x4000): Retrieving info for initgroups call
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_initgr_next_base] (0x0400): Searching for users with base 
[dc=nafta,dc=company,dc=org]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_print_server] (0x2000): Searching 15.189.131.14
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with 
[(&(sAMAccountName=t859531)(objectclass=user)(objectSID=*))][dc=nafta,dc=company,dc=org].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 9
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] [sdap_op_add] 
(0x2000): New operation 9 timeout 6
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_process_result] (0x2000): Trace: sh[0x7f78cb2224a0], connected[1], 
ops[(nil)], ldap[0x7f78cb1cfb40]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_process_result] (0x2000): Trace: ldap_result found nothing!
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_process_result] (0x2000): Trace: sh[0x7f78cb39e540], connected[1], 
ops[0x7f78cb39eb60], ldap[0x7f78cb396250]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_parse_entry] (0x1000): OriginalDN: [CN=Dagdigian Chris 
USRE:t859531,OU=USRC,OU=Users,OU=usr,OU=objects,DC=NAFTA,DC=SYNGENTA,DC=ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_parse_range] (0x2000): No sub-attributes for [objectClass]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_parse_range] (0x2000): No sub-attributes for [whenChanged]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_parse_range] (0x2000): No sub-attributes for [memberOf]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_parse_range] (0x2000): No sub-attributes for [uSNChanged]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_parse_range] (0x2000): No sub-attributes for [name]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_parse_range] (0x2000): No sub-attributes for [objectGUID]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_parse_range] (0x2000): No sub-attributes for [userAccountControl]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_parse_range] (0x2000): No sub-attributes for [primaryGroupID]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_parse_range] (0x2000): No sub-attributes for [objectSid]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_parse_range] (0x2000): No sub-attributes for [sAMAccountName]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_parse_range] (0x2000): No sub-attributes for [userPrincipalName]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_process_result] (0x2000): Trace: sh[0x7f78cb39e540], connected[1], 
ops[0x7f78cb39eb60], ldap[0x7f78cb396250]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no 
errmsg set
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_op_destructor] (0x2000): Operation 9 finished
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_initgr_user] (0x4000): Receiving info for the user
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] [ldb] (0x4000): 
start ldb transaction (nesting: 0)
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_initgr_user] (0x4000): Storing the user
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] [sdap_save_user] 
(0x0400): Save user
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_get_primary_name] (0x0400): Processing object 
t859531 at NAFTA.COMPANY.ORG
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] [sdap_save_user] 
(0x0400): Processing user t859531 at NAFTA.COMPANY.ORG
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] [sdap_save_user] 
(0x1000): Mapping user [t859531 at NAFTA.COMPANY.ORG] objectSID 
[S-1-5-21-1801674531-1767777339-682003330-170609] to unix ID
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] [sdap_save_user] 
(0x2000): Adding originalDN [CN=Dagdigian Chris 
USRE:t859531,OU=USRC,OU=Users,OU=usr,OU=objects,DC=NAFTA,DC=SYNGENTA,DC=ORG] 
to attributes of [t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] [sdap_save_user] 
(0x0400): Adding original memberOf attributes to 
[t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_attrs_add_ldap_attr] (0x2000): Adding original mod-Timestamp 
[20161205151624.0Z] to attributes of [t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] [sdap_save_user] 
(0x0400): Adding user principal [t859531 at COMPANY.ORG] to attributes of 
[t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_attrs_add_ldap_attr] (0x2000): shadowLastChange is not available 
for [t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_attrs_add_ldap_attr] (0x2000): shadowMin is not available for 
[t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_attrs_add_ldap_attr] (0x2000): shadowMax is not available for 
[t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_attrs_add_ldap_attr] (0x2000): shadowWarning is not available for 
[t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_attrs_add_ldap_attr] (0x2000): shadowInactive is not available for 
[t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_attrs_add_ldap_attr] (0x2000): shadowExpire is not available for 
[t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_attrs_add_ldap_attr] (0x2000): shadowFlag is not available for 
[t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_attrs_add_ldap_attr] (0x2000): krbLastPwdChange is not available 
for [t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_attrs_add_ldap_attr] (0x2000): krbPasswordExpiration is not 
available for [t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_attrs_add_ldap_attr] (0x2000): pwdAttribute is not available for 
[t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_attrs_add_ldap_attr] (0x2000): authorizedService is not available 
for [t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_attrs_add_ldap_attr] (0x2000): adAccountExpires is not available 
for [t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_attrs_add_ldap_attr] (0x2000): Adding adUserAccountControl [512] 
to attributes of [t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_attrs_add_ldap_attr] (0x2000): nsAccountLock is not available for 
[t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_attrs_add_ldap_attr] (0x2000): authorizedHost is not available for 
[t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_attrs_add_ldap_attr] (0x2000): ndsLoginDisabled is not available 
for [t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_attrs_add_ldap_attr] (0x2000): ndsLoginExpirationTime is not 
available for [t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_attrs_add_ldap_attr] (0x2000): ndsLoginAllowedTimeMap is not 
available for [t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_attrs_add_ldap_attr] (0x2000): sshPublicKey is not available for 
[t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_attrs_add_ldap_attr] (0x2000): authType is not available for 
[t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sdap_attrs_add_ldap_attr] (0x2000): userCertificate is not available 
for [t859531 at NAFTA.COMPANY.ORG].
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] 
[sysdb_attrs_get_aliases] (0x2000): Domain is case-insensitive; will add 
lowercased aliases
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] [sdap_save_user] 
(0x0400): Storing info for user t859531 at NAFTA.COMPANY.ORG
(Tue Dec  6 18:24:22 2016) [sssd[be[company-idm.org]]] [ldb] (0x4000): 
start ldb transaction (nesting: 1)


(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] [main] (0x0400): 
krb5_child started.
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] [unpack_buffer] 
(0x1000): total buffer size: [52]
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] [unpack_buffer] 
(0x0100): cmd [249] uid [1843770609] gid [1843770609] validate [false] 
enterprise principal [false] offline [false] UPN [t859531 at COMPANY.ORG]
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] [k5c_setup_fast] 
(0x0100): SSSD_KRB5_FAST_PRINCIPAL is set to 
[host/usaeilidmp001.company-idm.org at COMPANY-IDM.ORG]
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[find_principal_in_keytab] (0x4000): Trying to find principal 
host/usaeilidmp001.company-idm.org at COMPANY-IDM.ORG in keytab.
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] [match_principal] 
(0x1000): Principal matched to the sample 
(host/usaeilidmp001.company-idm.org at COMPANY-IDM.ORG).
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[check_fast_ccache] (0x0200): FAST TGT is still valid.
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] [become_user] 
(0x0200): Trying to become user [1843770609][1843770609].
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] [main] (0x2000): 
Running as [1843770609][1843770609].
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] [k5c_setup] 
(0x2000): Running as [1843770609][1843770609].
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[set_lifetime_options] (0x0100): Cannot read 
[SSSD_KRB5_RENEWABLE_LIFETIME] from environment.
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from 
environment.
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[set_canonicalize_option] (0x0100): SSSD_KRB5_CANONICALIZE is set to [true]
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] [main] (0x0400): 
Will perform pre-auth
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] [tgt_req_child] 
(0x1000): Attempting to get a TGT
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[get_and_save_tgt] (0x0400): Attempting kinit for realm [COMPANY.ORG]
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.93516: Getting 
initial credentials for t859531 at COMPANY.ORG

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.95456: FAST armor 
ccache: MEMORY:/var/lib/sss/db/fast_ccache_COMPANY-IDM.ORG

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.95498: Retrieving 
host/usaeilidmp001.company-idm.org at COMPANY-IDM.ORG -> 
krb5_ccache_conf_data/fast_avail/krbtgt\/COMPANY.ORG\@COMPANY.ORG at X-CACHECONF: 
from MEMORY:/var/lib/sss/db/fast_ccache_COMPANY-IDM.ORG with result: 
-1765328243/Matching credential not found

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.95541: Sending 
request (169 bytes) to COMPANY.ORG

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.96088: Resolving 
hostname friawadsgc16.company.org.

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.96518: Sending 
initial UDP request to dgram 15.141.1.63:88

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.183474: Received 
answer (118 bytes) from dgram 15.141.1.63:88

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.183759: Response 
was not from master KDC

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.183788: Received 
error from KDC: -1765328316/Realm not local to KDC

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.183802: Following 
referral to realm NAFTA.COMPANY.ORG

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.183820: FAST 
armor ccache: MEMORY:/var/lib/sss/db/fast_ccache_COMPANY-IDM.ORG

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.183848: 
Retrieving host/usaeilidmp001.company-idm.org at COMPANY-IDM.ORG -> 
krb5_ccache_conf_data/fast_avail/krbtgt\/NAFTA.COMPANY.ORG\@NAFTA.COMPANY.ORG at X-CACHECONF: 
from MEMORY:/var/lib/sss/db/fast_ccache_COMPANY-IDM.ORG with result: 
-1765328243/Matching credential not found

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.183891: Sending 
request (181 bytes) to NAFTA.COMPANY.ORG

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.186283: Resolving 
hostname usetwadsfsmo03.nafta.company.org.

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.186492: Sending 
initial UDP request to dgram 15.189.131.30:88

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.206711: Received 
answer (205 bytes) from dgram 15.189.131.30:88

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.398017: Response 
was not from master KDC

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.398114: Received 
error from KDC: -1765328359/Additional pre-authentication required

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.398168: 
Processing preauth types: 16, 15, 19, 2

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.398188: Selected 
etype info: etype aes256-cts, salt "NAFTA.COMPANY.ORGt859531", params ""

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.398210: PKINIT 
client has no configured identity; giving up

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.398233: PKINIT 
client has no configured identity; giving up

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.398244: Preauth 
module pkinit (16) (real) returned: 22/Invalid argument

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.398255: PKINIT 
client has no configured identity; giving up

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.398262: Preauth 
module pkinit (14) (real) returned: 22/Invalid argument

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_krb5_prompter] (0x0020): Cannot handle password prompts.
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.398278: Preauth 
module encrypted_timestamp (2) (real) returned: -1765328254/Cannot read 
password

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.398292: Retrying 
AS request with master KDC

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.398303: Getting 
initial credentials for t859531 at COMPANY.ORG

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.398322: FAST 
armor ccache: MEMORY:/var/lib/sss/db/fast_ccache_COMPANY-IDM.ORG

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.398345: 
Retrieving host/usaeilidmp001.company-idm.org at COMPANY-IDM.ORG -> 
krb5_ccache_conf_data/fast_avail/krbtgt\/COMPANY.ORG\@COMPANY.ORG at X-CACHECONF: 
from MEMORY:/var/lib/sss/db/fast_ccache_COMPANY-IDM.ORG with result: 
-1765328243/Matching credential not found

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12405] 1481054230.398368: Sending 
request (169 bytes) to COMPANY.ORG (master)

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[get_and_save_tgt] (0x0400): krb5_get_init_creds_password returned [22} 
during pre-auth.
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] [k5c_send_data] 
(0x0200): Received error code 0
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] 
[pack_response_packet] (0x2000): response packet size: [4]
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] [k5c_send_data] 
(0x4000): Response sent.
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12405]]]] [main] (0x0400): 
krb5_child completed successfully
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] [main] (0x0400): 
krb5_child started.
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] [unpack_buffer] 
(0x1000): total buffer size: [158]
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] [unpack_buffer] 
(0x0100): cmd [241] uid [1843770609] gid [1843770609] validate [false] 
enterprise principal [false] offline [false] UPN [t859531 at COMPANY.ORG]
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] [unpack_buffer] 
(0x0100): ccname: [KEYRING:persistent:1843770609] old_ccname: 
[KEYRING:persistent:1843770609] keytab: [/etc/krb5.keytab]
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] [switch_creds] 
(0x0200): Switch user to [1843770609][1843770609].
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_krb5_cc_verify_ccache] (0x2000): TGT not found or expired.
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] [switch_creds] 
(0x0200): Switch user to [0][0].
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[k5c_check_old_ccache] (0x4000): Ccache_file is 
[KEYRING:persistent:1843770609] and is not active and TGT is  valid.
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[k5c_precreate_ccache] (0x4000): Recreating ccache
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] [k5c_setup_fast] 
(0x0100): SSSD_KRB5_FAST_PRINCIPAL is set to 
[host/usaeilidmp001.company-idm.org at COMPANY-IDM.ORG]
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[find_principal_in_keytab] (0x4000): Trying to find principal 
host/usaeilidmp001.company-idm.org at COMPANY-IDM.ORG in keytab.
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] [match_principal] 
(0x1000): Principal matched to the sample 
(host/usaeilidmp001.company-idm.org at COMPANY-IDM.ORG).
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[check_fast_ccache] (0x0200): FAST TGT is still valid.
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] [become_user] 
(0x0200): Trying to become user [1843770609][1843770609].
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] [main] (0x2000): 
Running as [1843770609][1843770609].
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] [k5c_setup] 
(0x2000): Running as [1843770609][1843770609].
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[set_lifetime_options] (0x0100): Cannot read 
[SSSD_KRB5_RENEWABLE_LIFETIME] from environment.
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from 
environment.
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[set_canonicalize_option] (0x0100): SSSD_KRB5_CANONICALIZE is set to [true]
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] [main] (0x0400): 
Will perform online auth
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] [tgt_req_child] 
(0x1000): Attempting to get a TGT
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[get_and_save_tgt] (0x0400): Attempting kinit for realm [COMPANY.ORG]
(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.699127: Getting 
initial credentials for t859531 at COMPANY.ORG

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.701031: FAST 
armor ccache: MEMORY:/var/lib/sss/db/fast_ccache_COMPANY-IDM.ORG

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.701076: 
Retrieving host/usaeilidmp001.company-idm.org at COMPANY-IDM.ORG -> 
krb5_ccache_conf_data/fast_avail/krbtgt\/COMPANY.ORG\@COMPANY.ORG at X-CACHECONF: 
from MEMORY:/var/lib/sss/db/fast_ccache_COMPANY-IDM.ORG with result: 
-1765328243/Matching credential not found

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.701129: Sending 
request (169 bytes) to COMPANY.ORG

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.701679: Resolving 
hostname usetwadsgc01.company.org.

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.702086: Sending 
initial UDP request to dgram 15.189.131.10:88

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.733238: Received 
answer (118 bytes) from dgram 15.189.131.10:88

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.733453: Response 
was not from master KDC

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.733480: Received 
error from KDC: -1765328316/Realm not local to KDC

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.733493: Following 
referral to realm NAFTA.COMPANY.ORG

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.733509: FAST 
armor ccache: MEMORY:/var/lib/sss/db/fast_ccache_COMPANY-IDM.ORG

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.733535: 
Retrieving host/usaeilidmp001.company-idm.org at COMPANY-IDM.ORG -> 
krb5_ccache_conf_data/fast_avail/krbtgt\/NAFTA.COMPANY.ORG\@NAFTA.COMPANY.ORG at X-CACHECONF: 
from MEMORY:/var/lib/sss/db/fast_ccache_COMPANY-IDM.ORG with result: 
-1765328243/Matching credential not found

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.733568: Sending 
request (181 bytes) to NAFTA.COMPANY.ORG

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.735973: Resolving 
hostname usetwadsfsmo04.nafta.company.org.

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.736149: Sending 
initial UDP request to dgram 15.189.131.31:88

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.768127: Received 
answer (205 bytes) from dgram 15.189.131.31:88

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.768302: Response 
was not from master KDC

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.768332: Received 
error from KDC: -1765328359/Additional pre-authentication required

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.768358: 
Processing preauth types: 16, 15, 19, 2

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.768375: Selected 
etype info: etype aes256-cts, salt "NAFTA.COMPANY.ORGt859531", params ""

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.768396: PKINIT 
client has no configured identity; giving up

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.768414: PKINIT 
client has no configured identity; giving up

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.768423: Preauth 
module pkinit (16) (real) returned: 22/Invalid argument

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.768433: PKINIT 
client has no configured identity; giving up

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.768440: Preauth 
module pkinit (14) (real) returned: 22/Invalid argument

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.777142: AS key 
obtained for encrypted timestamp: aes256-cts/3D3B

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.777191: Encrypted 
timestamp (for 1481054230.710717): plain 
301AA011180F32303136313230363139353731305AA10502030AD83D, encrypted 
132EB7BE35E113EC6EF0D40BB7DF9D9A8116AE8F79B0C80787726DA03B0FA30704B7EBB257E72B38528722EB36F04C5AEFAFBDA8DFBFF908

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.777204: Preauth 
module encrypted_timestamp (2) (real) returned: 0/Success

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.777211: Produced 
preauth for next request: 2

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.777226: Sending 
request (260 bytes) to NAFTA.COMPANY.ORG

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.779526: Resolving 
hostname friawadsgc02.nafta.company.org.

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.779717: Sending 
initial UDP request to dgram 15.141.1.11:88

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.876715: Received 
answer (108 bytes) from dgram 15.141.1.11:88

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.876974: Response 
was not from master KDC

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.877004: Received 
error from KDC: -1765328332/Response too big for UDP, retry with TCP

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.877014: Request 
or response is too big for UDP; retrying with TCP

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.877028: Sending 
request (260 bytes) to NAFTA.COMPANY.ORG (tcp only)

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.878309: Resolving 
hostname frgowadsgc02.nafta.company.org.

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.878512: 
Initiating TCP connection to stream 15.141.1.16:88

(Tue Dec  6 19:57:10 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054230.965515: Sending 
TCP request to stream 15.141.1.16:88

(Tue Dec  6 19:57:11 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054231.99940: Received 
answer (2071 bytes) from stream 15.141.1.16:88

(Tue Dec  6 19:57:11 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054231.99963: 
Terminating TCP connection to stream 15.141.1.16:88

(Tue Dec  6 19:57:11 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054231.100136: Response 
was not from master KDC

(Tue Dec  6 19:57:11 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054231.100180: 
Processing preauth types: 19

(Tue Dec  6 19:57:11 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054231.100193: Selected 
etype info: etype aes256-cts, salt "NAFTA.COMPANY.ORGt859531", params ""

(Tue Dec  6 19:57:11 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054231.100202: Produced 
preauth for next request: (empty)

(Tue Dec  6 19:57:11 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054231.100211: AS key 
determined by preauth: aes256-cts/3D3B

(Tue Dec  6 19:57:11 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054231.100256: Decrypted 
AS reply; session key is: aes256-cts/4E6F

(Tue Dec  6 19:57:11 2016) [[sssd[krb5_child[12406]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12406] 1481054231.100264: FAST 
negotiation: unavailable

(Tue Dec  6 19:57:11 2016) [[sssd[krb5_child[12406]]]] 
[sss_krb5_expire_callback_func] (0x2000): exp_time: [2742397]
(Tue Dec  6 19:57:11 2016) [[sssd[krb5_child[12406]]]] 
[get_and_save_tgt] (0x0100): TGT validation is disabled.
(Tue Dec  6 19:57:11 2016) [[sssd[krb5_child[12406]]]] 
[sss_get_ccache_name_for_principal] (0x4000): Location: 
[KEYRING:persistent:1843770609]
(Tue Dec  6 19:57:11 2016) [[sssd[krb5_child[12406]]]] 
[sss_get_ccache_name_for_principal] (0x4000): tmp_ccname: 
[KEYRING:persistent:1843770609:krb_ccache_OVBc5zF]
(Tue Dec  6 19:57:11 2016) [[sssd[krb5_child[12406]]]] [create_ccache] 
(0x4000): Initializing ccache of type [KEYRING]
(Tue Dec  6 19:57:11 2016) [[sssd[krb5_child[12406]]]] [create_ccache] 
(0x4000): CC supports switch
(Tue Dec  6 19:57:11 2016) [[sssd[krb5_child[12406]]]] [create_ccache] 
(0x4000): returning: 0
(Tue Dec  6 19:57:11 2016) [[sssd[krb5_child[12406]]]] 
[safe_remove_old_ccache_file] (0x0400): New and old ccache file are the 
same, none will be deleted.
(Tue Dec  6 19:57:11 2016) [[sssd[krb5_child[12406]]]] [k5c_send_data] 
(0x0200): Received error code 0
(Tue Dec  6 19:57:11 2016) [[sssd[krb5_child[12406]]]] 
[pack_response_packet] (0x2000): response packet size: [144]
(Tue Dec  6 19:57:11 2016) [[sssd[krb5_child[12406]]]] [k5c_send_data] 
(0x4000): Response sent.
(Tue Dec  6 19:57:11 2016) [[sssd[krb5_child[12406]]]] [main] (0x0400): 
krb5_child completed successfully
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] [main] (0x0400): 
krb5_child started.
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] [unpack_buffer] 
(0x1000): total buffer size: [52]
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] [unpack_buffer] 
(0x0100): cmd [249] uid [1843770609] gid [1843770609] validate [false] 
enterprise principal [false] offline [false] UPN [t859531 at COMPANY.ORG]
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] [k5c_setup_fast] 
(0x0100): SSSD_KRB5_FAST_PRINCIPAL is set to 
[host/usaeilidmp001.company-idm.org at COMPANY-IDM.ORG]
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[find_principal_in_keytab] (0x4000): Trying to find principal 
host/usaeilidmp001.company-idm.org at COMPANY-IDM.ORG in keytab.
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] [match_principal] 
(0x1000): Principal matched to the sample 
(host/usaeilidmp001.company-idm.org at COMPANY-IDM.ORG).
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[check_fast_ccache] (0x0200): FAST TGT is still valid.
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] [become_user] 
(0x0200): Trying to become user [1843770609][1843770609].
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] [main] (0x2000): 
Running as [1843770609][1843770609].
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] [k5c_setup] 
(0x2000): Running as [1843770609][1843770609].
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[set_lifetime_options] (0x0100): Cannot read 
[SSSD_KRB5_RENEWABLE_LIFETIME] from environment.
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from 
environment.
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[set_canonicalize_option] (0x0100): SSSD_KRB5_CANONICALIZE is set to [true]
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] [main] (0x0400): 
Will perform pre-auth
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] [tgt_req_child] 
(0x1000): Attempting to get a TGT
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[get_and_save_tgt] (0x0400): Attempting kinit for realm [COMPANY.ORG]
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.72549: Getting 
initial credentials for t859531 at COMPANY.ORG

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.74479: FAST armor 
ccache: MEMORY:/var/lib/sss/db/fast_ccache_COMPANY-IDM.ORG

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.74521: Retrieving 
host/usaeilidmp001.company-idm.org at COMPANY-IDM.ORG -> 
krb5_ccache_conf_data/fast_avail/krbtgt\/COMPANY.ORG\@COMPANY.ORG at X-CACHECONF: 
from MEMORY:/var/lib/sss/db/fast_ccache_COMPANY-IDM.ORG with result: 
-1765328243/Matching credential not found

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.74571: Sending 
request (169 bytes) to COMPANY.ORG

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.75143: Resolving 
hostname friawadsgc11.company.org.

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.75586: Sending 
initial UDP request to dgram 15.141.1.51:88

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.161933: Received 
answer (118 bytes) from dgram 15.141.1.51:88

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.162191: Response 
was not from master KDC

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.162223: Received 
error from KDC: -1765328316/Realm not local to KDC

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.162237: Following 
referral to realm NAFTA.COMPANY.ORG

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.162254: FAST 
armor ccache: MEMORY:/var/lib/sss/db/fast_ccache_COMPANY-IDM.ORG

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.162282: 
Retrieving host/usaeilidmp001.company-idm.org at COMPANY-IDM.ORG -> 
krb5_ccache_conf_data/fast_avail/krbtgt\/NAFTA.COMPANY.ORG\@NAFTA.COMPANY.ORG at X-CACHECONF: 
from MEMORY:/var/lib/sss/db/fast_ccache_COMPANY-IDM.ORG with result: 
-1765328243/Matching credential not found

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.162313: Sending 
request (181 bytes) to NAFTA.COMPANY.ORG

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.164790: Resolving 
hostname friawadsgc12.nafta.company.org.

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.164994: Sending 
initial UDP request to dgram 15.141.1.52:88

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.255512: Received 
answer (205 bytes) from dgram 15.141.1.52:88

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.255774: Response 
was not from master KDC

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.255815: Received 
error from KDC: -1765328359/Additional pre-authentication required

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.255848: 
Processing preauth types: 16, 15, 19, 2

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.255869: Selected 
etype info: etype aes256-cts, salt "NAFTA.COMPANY.ORGt859531", params ""

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.255891: PKINIT 
client has no configured identity; giving up

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.255915: PKINIT 
client has no configured identity; giving up

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.255926: Preauth 
module pkinit (16) (real) returned: 22/Invalid argument

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.255937: PKINIT 
client has no configured identity; giving up

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.255944: Preauth 
module pkinit (14) (real) returned: 22/Invalid argument

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_krb5_prompter] (0x0020): Cannot handle password prompts.
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.255970: Preauth 
module encrypted_timestamp (2) (real) returned: -1765328254/Cannot read 
password

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.255984: Retrying 
AS request with master KDC

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.255992: Getting 
initial credentials for t859531 at COMPANY.ORG

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.256011: FAST 
armor ccache: MEMORY:/var/lib/sss/db/fast_ccache_COMPANY-IDM.ORG

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.256035: 
Retrieving host/usaeilidmp001.company-idm.org at COMPANY-IDM.ORG -> 
krb5_ccache_conf_data/fast_avail/krbtgt\/COMPANY.ORG\@COMPANY.ORG at X-CACHECONF: 
from MEMORY:/var/lib/sss/db/fast_ccache_COMPANY-IDM.ORG with result: 
-1765328243/Matching credential not found

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12415] 1481054234.256059: Sending 
request (169 bytes) to COMPANY.ORG (master)

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[get_and_save_tgt] (0x0400): krb5_get_init_creds_password returned [22} 
during pre-auth.
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] [k5c_send_data] 
(0x0200): Received error code 0
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] 
[pack_response_packet] (0x2000): response packet size: [4]
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] [k5c_send_data] 
(0x4000): Response sent.
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12415]]]] [main] (0x0400): 
krb5_child completed successfully
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] [main] (0x0400): 
krb5_child started.
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] [unpack_buffer] 
(0x1000): total buffer size: [158]
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] [unpack_buffer] 
(0x0100): cmd [241] uid [1843770609] gid [1843770609] validate [false] 
enterprise principal [false] offline [false] UPN [t859531 at COMPANY.ORG]
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] [unpack_buffer] 
(0x0100): ccname: [KEYRING:persistent:1843770609] old_ccname: 
[KEYRING:persistent:1843770609] keytab: [/etc/krb5.keytab]
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] [switch_creds] 
(0x0200): Switch user to [1843770609][1843770609].
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_krb5_cc_verify_ccache] (0x2000): TGT not found or expired.
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] [switch_creds] 
(0x0200): Switch user to [0][0].
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[k5c_check_old_ccache] (0x4000): Ccache_file is 
[KEYRING:persistent:1843770609] and is not active and TGT is  valid.
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[k5c_precreate_ccache] (0x4000): Recreating ccache
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] [k5c_setup_fast] 
(0x0100): SSSD_KRB5_FAST_PRINCIPAL is set to 
[host/usaeilidmp001.company-idm.org at COMPANY-IDM.ORG]
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[find_principal_in_keytab] (0x4000): Trying to find principal 
host/usaeilidmp001.company-idm.org at COMPANY-IDM.ORG in keytab.
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] [match_principal] 
(0x1000): Principal matched to the sample 
(host/usaeilidmp001.company-idm.org at COMPANY-IDM.ORG).
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[check_fast_ccache] (0x0200): FAST TGT is still valid.
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] [become_user] 
(0x0200): Trying to become user [1843770609][1843770609].
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] [main] (0x2000): 
Running as [1843770609][1843770609].
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] [k5c_setup] 
(0x2000): Running as [1843770609][1843770609].
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[set_lifetime_options] (0x0100): Cannot read 
[SSSD_KRB5_RENEWABLE_LIFETIME] from environment.
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from 
environment.
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[set_canonicalize_option] (0x0100): SSSD_KRB5_CANONICALIZE is set to [true]
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] [main] (0x0400): 
Will perform online auth
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] [tgt_req_child] 
(0x1000): Attempting to get a TGT
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[get_and_save_tgt] (0x0400): Attempting kinit for realm [COMPANY.ORG]
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.281781: Getting 
initial credentials for t859531 at COMPANY.ORG

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.283707: FAST 
armor ccache: MEMORY:/var/lib/sss/db/fast_ccache_COMPANY-IDM.ORG

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.283753: 
Retrieving host/usaeilidmp001.company-idm.org at COMPANY-IDM.ORG -> 
krb5_ccache_conf_data/fast_avail/krbtgt\/COMPANY.ORG\@COMPANY.ORG at X-CACHECONF: 
from MEMORY:/var/lib/sss/db/fast_ccache_COMPANY-IDM.ORG with result: 
-1765328243/Matching credential not found

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.283795: Sending 
request (169 bytes) to COMPANY.ORG

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.284321: Resolving 
hostname frgowadsgc01.company.org.

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.284716: Sending 
initial UDP request to dgram 15.141.1.15:88

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.377848: Received 
answer (118 bytes) from dgram 15.141.1.15:88

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.378147: Response 
was not from master KDC

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.378179: Received 
error from KDC: -1765328316/Realm not local to KDC

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.378192: Following 
referral to realm NAFTA.COMPANY.ORG

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.378210: FAST 
armor ccache: MEMORY:/var/lib/sss/db/fast_ccache_COMPANY-IDM.ORG

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.378239: 
Retrieving host/usaeilidmp001.company-idm.org at COMPANY-IDM.ORG -> 
krb5_ccache_conf_data/fast_avail/krbtgt\/NAFTA.COMPANY.ORG\@NAFTA.COMPANY.ORG at X-CACHECONF: 
from MEMORY:/var/lib/sss/db/fast_ccache_COMPANY-IDM.ORG with result: 
-1765328243/Matching credential not found

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.378272: Sending 
request (181 bytes) to NAFTA.COMPANY.ORG

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.380656: Resolving 
hostname usetwadsgc02.nafta.company.org.

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.380857: Sending 
initial UDP request to dgram 15.189.131.11:88

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.405841: Received 
answer (205 bytes) from dgram 15.189.131.11:88

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.406076: Response 
was not from master KDC

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.406110: Received 
error from KDC: -1765328359/Additional pre-authentication required

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.406139: 
Processing preauth types: 16, 15, 19, 2

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.406159: Selected 
etype info: etype aes256-cts, salt "NAFTA.COMPANY.ORGt859531", params ""

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.406181: PKINIT 
client has no configured identity; giving up

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.406199: PKINIT 
client has no configured identity; giving up

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.406209: Preauth 
module pkinit (16) (real) returned: 22/Invalid argument

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.406238: PKINIT 
client has no configured identity; giving up

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.406246: Preauth 
module pkinit (14) (real) returned: 22/Invalid argument

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.414944: AS key 
obtained for encrypted timestamp: aes256-cts/3D3B

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.414987: Encrypted 
timestamp (for 1481054234.344243): plain 
301AA011180F32303136313230363139353731345AA10502030540B3, encrypted 
B631BC6CF58EA1A8B3431F6A23C06ED1A79B8EF46B43B2A4682FC240D272DACCEF2E176992C934484EB60475122E3E3F21A382D9DC362344

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.415000: Preauth 
module encrypted_timestamp (2) (real) returned: 0/Success

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.415006: Produced 
preauth for next request: 2

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.415022: Sending 
request (260 bytes) to NAFTA.COMPANY.ORG

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.417353: Resolving 
hostname usetwadsfsmo03.nafta.company.org.

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.417542: Sending 
initial UDP request to dgram 15.189.131.30:88

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.438536: Received 
answer (108 bytes) from dgram 15.189.131.30:88

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.438704: Response 
was not from master KDC

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.438728: Received 
error from KDC: -1765328332/Response too big for UDP, retry with TCP

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.438738: Request 
or response is too big for UDP; retrying with TCP

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.438750: Sending 
request (260 bytes) to NAFTA.COMPANY.ORG (tcp only)

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.439936: Resolving 
hostname friawadsgc02.nafta.company.org.

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.440123: 
Initiating TCP connection to stream 15.141.1.11:88

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.526159: Sending 
TCP request to stream 15.141.1.11:88

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.630381: Received 
answer (2071 bytes) from stream 15.141.1.11:88

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.630405: 
Terminating TCP connection to stream 15.141.1.11:88

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.630616: Response 
was not from master KDC

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.630656: 
Processing preauth types: 19

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.630667: Selected 
etype info: etype aes256-cts, salt "NAFTA.COMPANY.ORGt859531", params ""

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.630676: Produced 
preauth for next request: (empty)

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.630686: AS key 
determined by preauth: aes256-cts/3D3B

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.630735: Decrypted 
AS reply; session key is: aes256-cts/C0BE

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_child_krb5_trace_cb] (0x4000): [12417] 1481054234.630742: FAST 
negotiation: unavailable

(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_krb5_expire_callback_func] (0x2000): exp_time: [2742394]
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[get_and_save_tgt] (0x0100): TGT validation is disabled.
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_get_ccache_name_for_principal] (0x4000): Location: 
[KEYRING:persistent:1843770609]
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[sss_get_ccache_name_for_principal] (0x4000): tmp_ccname: 
[KEYRING:persistent:1843770609:krb_ccache_OVBc5zF]
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] [create_ccache] 
(0x4000): Initializing ccache of type [KEYRING]
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] [create_ccache] 
(0x4000): CC supports switch
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] [create_ccache] 
(0x4000): returning: 0
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[safe_remove_old_ccache_file] (0x0400): New and old ccache file are the 
same, none will be deleted.
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] [k5c_send_data] 
(0x0200): Received error code 0
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] 
[pack_response_packet] (0x2000): response packet size: [144]
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] [k5c_send_data] 
(0x4000): Response sent.
(Tue Dec  6 19:57:14 2016) [[sssd[krb5_child[12417]]]] [main] (0x0400): 
krb5_child completed successfully








More information about the Freeipa-users mailing list