[Freeipa-users] freeipa permission denied for user

Rakesh Rajasekharan rakesh.rajasekharan at gmail.com
Thu May 5 14:43:00 UTC 2016


Hi There,

I am getting a permission denied error on few of my hosts with IPA.

these are all new hosts which were earlier running openldap and now being
migrated over to freeipa.

In the ssd_domain.log I see  this error "No ccache file for user
[p-testuser] found"

I check the /tmp directory and the permission look fine
drwxrwxrwt 4 root root 4096 May  5 14:36 /tmp

this is the sssd_domain.log after I tried to login

Thu May  5 14:35:37 UTC 2016
p-testuser at localhost's password:
Permission denied, please try again.
p-testuser at localhost's password:
Permission denied, please try again.
p-testuser at localhost's password:
Permission denied (publickey,gssapi-keyex,gssapi-with-mic,password).
Thu May  5 14:35:51 UTC 2016


sssd_domain.log
Thu May  5 14:35:37 2016) [sssd[be[xyz.com]]] [sbus_get_sender_id_send]
(0x2000): Not a sysbus message, quit
(Thu May  5 14:35:37 2016) [sssd[be[xyz.com]]] [be_host_handler] (0x1000):
Got request for [0][name=localhost]
(Thu May  5 14:35:37 2016) [sssd[be[xyz.com]]] [sdap_print_server]
(0x2000): Searching 10.10.3.184
(Thu May  5 14:35:37 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x0400): calling ldap_search_ext with
[(&(objectClass=ipaHost)(fqdn=localhost))][cn=accounts,dc=xyz,dc=com].
(Thu May  5 14:35:37 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [objectClass]
(Thu May  5 14:35:37 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [cn]
(Thu May  5 14:35:37 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [fqdn]
(Thu May  5 14:35:37 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [serverHostname]
(Thu May  5 14:35:37 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [memberOf]
(Thu May  5 14:35:37 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [ipaSshPubKey]
(Thu May  5 14:35:37 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [ipaUniqueID]
(Thu May  5 14:35:37 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x2000): ldap_search_ext called, msgid = 62
(Thu May  5 14:35:37 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[0x2368670],
ldap[0x2332a80]
(Thu May  5 14:35:37 2016) [sssd[be[xyz.com]]]
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
errmsg set
(Thu May  5 14:35:37 2016) [sssd[be[xyz.com]]]
[sdap_get_generic_op_finished] (0x2000): Total count [0]
(Thu May  5 14:35:37 2016) [sssd[be[xyz.com]]] [hosts_get_done] (0x0040):
No host with name [localhost] found.
(Thu May  5 14:35:37 2016) [sssd[be[xyz.com]]] [sysdb_delete_ssh_host]
(0x0400): Deleting host localhost
(Thu May  5 14:35:37 2016) [sssd[be[xyz.com]]] [acctinfo_callback]
(0x0100): Request processed. Returned 3,22,Host lookup failed
(Thu May  5 14:35:37 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[(nil)], ldap[0x2332a80]
(Thu May  5 14:35:37 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: ldap_result found nothing!
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sbus_get_sender_id_send]
(0x2000): Not a sysbus message, quit
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [be_get_account_info]
(0x0200): Got request for [0x3][1][name=p-testuser]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [be_req_set_domain]
(0x0400): Changing request domain from [xyz.com] to [xyz.com]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]]
[sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
domain SID from [(null)]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]]
[sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
domain SID from [(null)]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_initgr_next_base]
(0x0400): Searching for users with base [cn=accounts,dc=xyz,dc=com]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_print_server]
(0x2000): Searching 10.10.3.184
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x0400): calling ldap_search_ext with
[(&(uid=p-testuser)(objectclass=posixAccount)(&(uidNumber=*)(!(uidNumber=0))))][cn=accounts,dc=xyz,dc=com].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [objectClass]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [uid]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [userPassword]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [uidNumber]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [gidNumber]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [gecos]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [homeDirectory]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [loginShell]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [krbPrincipalName]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [cn]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [memberOf]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [ipaUniqueID]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [ipaNTSecurityIdentifier]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [modifyTimestamp]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [entryUSN]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [shadowLastChange]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [shadowMin]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [shadowMax]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [shadowWarning]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [shadowInactive]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [shadowExpire]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [shadowFlag]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [krbLastPwdChange]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [krbPasswordExpiration]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [pwdAttribute]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [authorizedService]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [accountExpires]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [userAccountControl]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [nsAccountLock]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [host]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [loginDisabled]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [loginExpirationTime]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [loginAllowedTimeMap]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [ipaSshPubKey]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [ipaUserAuthType]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x2000): ldap_search_ext called, msgid = 63
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[0x2369390],
ldap[0x2332a80]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_entry] (0x1000):
OriginalDN: [uid=p-testuser,cn=users,cn=accounts,dc=xyz,dc=com].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [objectClass]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [uid]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [uidNumber]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [gidNumber]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [gecos]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [homeDirectory]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [loginShell]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [krbPrincipalName]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [cn]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [memberOf]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [ipaUniqueID]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [modifyTimestamp]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [entryUSN]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [krbLastPwdChange]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [krbPasswordExpiration]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[0x2369390],
ldap[0x2332a80]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]]
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
errmsg set
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_save_user] (0x0400):
Save user
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_get_sid_str]
(0x1000): No [objectSIDString] attribute. [0][Success]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_primary_name]
(0x0400): Processing object p-testuser
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_save_user] (0x0400):
Processing user p-testuser
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]]
[sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
domain SID from [(null)]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_save_user] (0x2000):
Adding originalDN [uid=p-testuser,cn=users,cn=accounts,dc=xyz,dc=com] to
attributes of [p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_save_user] (0x0400):
Adding original memberOf attributes to [p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): Adding original mod-Timestamp [20160505140042Z] to attributes of
[p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_save_user] (0x0400):
Adding user principal [p-testuser at xyz.COM] to attributes of [p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): shadowLastChange is not available for [p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): shadowMin is not available for [p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): shadowMax is not available for [p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): shadowWarning is not available for [p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): shadowInactive is not available for [p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): shadowExpire is not available for [p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): shadowFlag is not available for [p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): Adding krbLastPwdChange [20160505104918Z] to attributes of
[p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): Adding krbPasswordExpiration [20160803104918Z] to attributes of
[p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): pwdAttribute is not available for [p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): authorizedService is not available for [p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): adAccountExpires is not available for [p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): adUserAccountControl is not available for [p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): nsAccountLock is not available for [p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): authorizedHost is not available for [p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): ndsLoginDisabled is not available for [p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): ndsLoginExpirationTime is not available for [p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): ndsLoginAllowedTimeMap is not available for [p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): sshPublicKey is not available for [p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): authType is not available for [p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_save_user] (0x0400):
Storing info for user p-testuser
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [userPassword] from [p-testuser]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [objectSIDString] from [p-testuser]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [shadowLastChange] from [p-testuser]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [shadowMin] from [p-testuser]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [shadowMax] from [p-testuser]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [shadowWarning] from [p-testuser]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [shadowInactive] from [p-testuser]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [shadowExpire] from [p-testuser]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [shadowFlag] from [p-testuser]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [pwdAttribute] from [p-testuser]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [authorizedService] from [p-testuser]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [adAccountExpires] from [p-testuser]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [adUserAccountControl] from [p-testuser]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [nsAccountLock] from [p-testuser]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [authorizedHost] from [p-testuser]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [ndsLoginDisabled] from [p-testuser]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [ndsLoginExpirationTime] from [p-testuser]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [ndsLoginAllowedTimeMap] from [p-testuser]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [sshPublicKey] from [p-testuser]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [authType] from [p-testuser]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_primary_name]
(0x0400): Processing object p-testuser
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_has_deref_support]
(0x0400): The server supports deref method OpenLDAP
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_print_server]
(0x2000): Searching 10.10.3.184
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x0400): calling ldap_search_ext with
[(&(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*))][cn=ipausers,cn=groups,cn=accounts,dc=xyz,dc=com].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [objectClass]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [posixGroup]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [cn]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [userPassword]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [gidNumber]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [member]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [ipaUniqueID]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [ipaNTSecurityIdentifier]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [modifyTimestamp]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [entryUSN]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x2000): ldap_search_ext called, msgid = 64
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[0x23ecf60],
ldap[0x2332a80]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: ldap_result found nothing!
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[0x23ecf60],
ldap[0x2332a80]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_entry] (0x1000):
OriginalDN: [cn=ipausers,cn=groups,cn=accounts,dc=xyz,dc=com].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [objectClass]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [cn]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [member]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [ipaUniqueID]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [modifyTimestamp]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [entryUSN]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[0x23ecf60],
ldap[0x2332a80]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]]
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
errmsg set
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_primary_name]
(0x0400): Processing object ipausers
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_get_direct_parents]
(0x2000): searching sysdb with filter
[(&(objectClass=group)(member=name=ipausers,cn=groups,cn=xyz.com,cn=sysdb))]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_get_direct_parents]
(0x1000): ipausers is a member of 0 sysdb groups
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]]
[sdap_initgr_nested_get_membership_diff] (0x1000): The group ipausers is a
direct member of 0 LDAP groups
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]]
[sdap_initgr_store_user_memberships] (0x1000): The user p-testuser is a
direct member of 1 LDAP groups
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_get_direct_parents]
(0x2000): searching sysdb with filter
[(&(objectClass=group)(member=name=p-testuser,cn=users,cn=xyz.com
,cn=sysdb))]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sysdb_get_direct_parents]
(0x1000): p-testuser is a member of 1 sysdb groups
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]]
[sdap_initgr_store_user_memberships] (0x2000): Updating memberships for
p-testuser
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]]
[sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
domain SID from [(null)]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_groups_next_base]
(0x0400): Searching for groups with base [cn=accounts,dc=xyz,dc=com]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_print_server]
(0x2000): Searching 10.10.3.184
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x0400): calling ldap_search_ext with
[(&(gidNumber=1879000001)(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*)(&(gidNumber=*)(!(gidNumber=0))))][cn=accounts,dc=xyz,dc=com].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [objectClass]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [posixGroup]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [cn]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [userPassword]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [gidNumber]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [member]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [ipaUniqueID]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [ipaNTSecurityIdentifier]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [modifyTimestamp]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [entryUSN]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x2000): ldap_search_ext called, msgid = 65
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[0x237a290],
ldap[0x2332a80]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: ldap_result found nothing!
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[0x237a290],
ldap[0x2332a80]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_entry] (0x1000):
OriginalDN: [cn=p-testuser,cn=groups,cn=accounts,dc=xyz,dc=com].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [objectClass]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [cn]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [gidNumber]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [ipaUniqueID]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [modifyTimestamp]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [entryUSN]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[0x237a290],
ldap[0x2332a80]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]]
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
errmsg set
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_groups_process]
(0x0400): Search for groups, returned 1 results.
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_has_deref_support]
(0x0400): The server supports deref method OpenLDAP
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]]
[sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
domain SID from [(null)]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]]
[sdap_nested_group_process_send] (0x2000): About to process group
[cn=p-testuser,cn=groups,cn=accounts,dc=xyz,dc=com]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_nested_group_recv]
(0x0400): 0 users found in the hash table
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_nested_group_recv]
(0x0400): 1 groups found in the hash table
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_get_sid_str]
(0x1000): No [objectSIDString] attribute. [0][Success]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_primary_name]
(0x0400): Processing object p-testuser
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_save_group] (0x0400):
Processing group p-testuser
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]]
[sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
domain SID from [(null)]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_save_group] (0x2000):
This is a posix group
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): Adding original DN
[cn=p-testuser,cn=groups,cn=accounts,dc=xyz,dc=com] to attributes of
[p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): Adding original mod-Timestamp [20160505104839Z] to attributes of
[p-testuser].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_process_ghost_members]
(0x0400): The group has 0 members
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_process_ghost_members]
(0x0400): Group has 0 members
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_save_group] (0x0400):
Storing info for group p-testuser
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_primary_name]
(0x0400): Processing object p-testuser
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_save_grpmem] (0x0400):
Processing group p-testuser
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_save_grpmem] (0x0400):
Failed to get group sid
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_save_grpmem] (0x0400):
No members for group [p-testuser]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_print_server]
(0x2000): Searching 10.10.3.184
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x0400): calling ldap_search_ext with
[(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:IPA:xyz.com:ed58bb28-12ae-11e6-8a34-0ac54d537681))][cn=Default
Trust View,cn=views,cn=accounts,dc=xyz,dc=com].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x2000): ldap_search_ext called, msgid = 66
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[0x2368670],
ldap[0x2332a80]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: ldap_result found nothing!
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[0x2368670],
ldap[0x2332a80]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]]
[sdap_get_generic_op_finished] (0x0400): Search result: No such object(32),
no errmsg set
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sbus_add_timeout] (0x2000):
0x237fcd0
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[(nil)], ldap[0x2332a80]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: ldap_result found nothing!
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sbus_remove_timeout]
(0x2000): 0x237fcd0
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [acctinfo_callback]
(0x0100): Request processed. Returned 0,0,Success
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [sbus_get_sender_id_send]
(0x2000): Not a sysbus message, quit
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [be_req_set_domain]
(0x0400): Changing request domain from [xyz.com] to [xyz.com]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [be_pam_handler] (0x0100):
Got request with the following data
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
command: PAM_AUTHENTICATE
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
domain: xyz.com
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
user: p-testuser
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
service: sshd
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
tty: ssh
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
ruser:
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
rhost: 127.0.0.1
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
authtok type: 1
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
newauthtok type: 0
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
priv: 1
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
cli_pid: 32253
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
logon name: not set
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]]
[krb5_auth_prepare_ccache_name] (0x1000): No ccache file for user
[p-testuser] found.
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [fo_resolve_service_send]
(0x0100): Trying to resolve service 'IPA'
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [get_server_status]
(0x1000): Status of server 'ipa-master-int.xyz.com' is 'name resolved'
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [get_port_status] (0x1000):
Port status of port 0 for server 'ipa-master-int.xyz.com' is 'working'
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]]
[fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6
seconds
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [get_server_status]
(0x1000): Status of server 'ipa-master-int.xyz.com' is 'name resolved'
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [be_resolve_server_process]
(0x1000): Saving the first resolved server
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [be_resolve_server_process]
(0x0200): Found address for server ipa-master-int.xyz.com: [10.10.3.184]
TTL 60
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [child_handler_setup]
(0x2000): Setting up signal handler up for pid [32274]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [child_handler_setup]
(0x2000): Signal handler set up for pid [32274]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [write_pipe_handler]
(0x0400): All data has been sent!
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [child_sig_handler]
(0x1000): Waiting for child [32274].
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [child_sig_handler]
(0x0100): child [32274] finished successfully.
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [read_pipe_handler]
(0x0400): EOF received, client finished
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [be_pam_handler_callback]
(0x0100): Backend returned: (0, 7, <NULL>) [Success]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [be_pam_handler_callback]
(0x0100): Sending result [7][xyz.com]
(Thu May  5 14:35:40 2016) [sssd[be[xyz.com]]] [be_pam_handler_callback]
(0x0100): Sent result [7][xyz.com]
(Thu May  5 14:35:41 2016) [sssd[be[xyz.com]]] [sbus_get_sender_id_send]
(0x2000): Not a sysbus message, quit
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [sbus_get_sender_id_send]
(0x2000): Not a sysbus message, quit
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [be_req_set_domain]
(0x0400): Changing request domain from [xyz.com] to [xyz.com]
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [be_pam_handler] (0x0100):
Got request with the following data
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
command: PAM_AUTHENTICATE
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
domain: xyz.com
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
user: p-testuser
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
service: sshd
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
tty: ssh
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
ruser:
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
rhost: 127.0.0.1
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
authtok type: 1
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
newauthtok type: 0
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
priv: 1
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
cli_pid: 32253
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
logon name: not set
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]]
[krb5_auth_prepare_ccache_name] (0x1000): No ccache file for user
[p-testuser] found.
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [fo_resolve_service_send]
(0x0100): Trying to resolve service 'IPA'
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [get_server_status]
(0x1000): Status of server 'ipa-master-int.xyz.com' is 'name resolved'
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [get_port_status] (0x1000):
Port status of port 0 for server 'ipa-master-int.xyz.com' is 'working'
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]]
[fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6
seconds
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [get_server_status]
(0x1000): Status of server 'ipa-master-int.xyz.com' is 'name resolved'
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [be_resolve_server_process]
(0x1000): Saving the first resolved server
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [be_resolve_server_process]
(0x0200): Found address for server ipa-master-int.xyz.com: [10.10.3.184]
TTL 60
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [child_handler_setup]
(0x2000): Setting up signal handler up for pid [32275]
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [child_handler_setup]
(0x2000): Signal handler set up for pid [32275]
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [write_pipe_handler]
(0x0400): All data has been sent!
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [read_pipe_handler]
(0x0400): EOF received, client finished
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [be_pam_handler_callback]
(0x0100): Backend returned: (0, 7, <NULL>) [Success]
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [be_pam_handler_callback]
(0x0100): Sending result [7][xyz.com]
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [be_pam_handler_callback]
(0x0100): Sent result [7][xyz.com]
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [child_sig_handler]
(0x1000): Waiting for child [32275].
(Thu May  5 14:35:44 2016) [sssd[be[xyz.com]]] [child_sig_handler]
(0x0100): child [32275] finished successfully.
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sbus_get_sender_id_send]
(0x2000): Not a sysbus message, quit
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [be_get_account_info]
(0x0200): Got request for [0x3][1][name=p-testuser]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [be_req_set_domain]
(0x0400): Changing request domain from [xyz.com] to [xyz.com]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]]
[sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
domain SID from [(null)]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]]
[sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
domain SID from [(null)]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_initgr_next_base]
(0x0400): Searching for users with base [cn=accounts,dc=xyz,dc=com]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_print_server]
(0x2000): Searching 10.10.3.184
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x0400): calling ldap_search_ext with
[(&(uid=p-testuser)(objectclass=posixAccount)(&(uidNumber=*)(!(uidNumber=0))))][cn=accounts,dc=xyz,dc=com].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [objectClass]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [uid]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [userPassword]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [uidNumber]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [gidNumber]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [gecos]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [homeDirectory]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [loginShell]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [krbPrincipalName]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [cn]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [memberOf]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [ipaUniqueID]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [ipaNTSecurityIdentifier]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [modifyTimestamp]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [entryUSN]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [shadowLastChange]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [shadowMin]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [shadowMax]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [shadowWarning]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [shadowInactive]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [shadowExpire]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [shadowFlag]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [krbLastPwdChange]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [krbPasswordExpiration]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [pwdAttribute]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [authorizedService]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [accountExpires]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [userAccountControl]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [nsAccountLock]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [host]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [loginDisabled]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [loginExpirationTime]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [loginAllowedTimeMap]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [ipaSshPubKey]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [ipaUserAuthType]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x2000): ldap_search_ext called, msgid = 67
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[0x2368670],
ldap[0x2332a80]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_entry] (0x1000):
OriginalDN: [uid=p-testuser,cn=users,cn=accounts,dc=xyz,dc=com].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [objectClass]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [uid]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [uidNumber]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [gidNumber]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [gecos]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [homeDirectory]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [loginShell]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [krbPrincipalName]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [cn]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [memberOf]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [ipaUniqueID]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [modifyTimestamp]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [entryUSN]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [krbLastPwdChange]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [krbPasswordExpiration]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[0x2368670],
ldap[0x2332a80]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]]
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
errmsg set
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_save_user] (0x0400):
Save user
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_get_sid_str]
(0x1000): No [objectSIDString] attribute. [0][Success]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_primary_name]
(0x0400): Processing object p-testuser
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_save_user] (0x0400):
Processing user p-testuser
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]]
[sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
domain SID from [(null)]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_save_user] (0x2000):
Adding originalDN [uid=p-testuser,cn=users,cn=accounts,dc=xyz,dc=com] to
attributes of [p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_save_user] (0x0400):
Adding original memberOf attributes to [p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): Adding original mod-Timestamp [20160505140042Z] to attributes of
[p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_save_user] (0x0400):
Adding user principal [p-testuser at xyz.COM] to attributes of [p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): shadowLastChange is not available for [p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): shadowMin is not available for [p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): shadowMax is not available for [p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): shadowWarning is not available for [p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): shadowInactive is not available for [p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): shadowExpire is not available for [p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): shadowFlag is not available for [p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): Adding krbLastPwdChange [20160505104918Z] to attributes of
[p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): Adding krbPasswordExpiration [20160803104918Z] to attributes of
[p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): pwdAttribute is not available for [p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): authorizedService is not available for [p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): adAccountExpires is not available for [p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): adUserAccountControl is not available for [p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): nsAccountLock is not available for [p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): authorizedHost is not available for [p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): ndsLoginDisabled is not available for [p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): ndsLoginExpirationTime is not available for [p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): ndsLoginAllowedTimeMap is not available for [p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): sshPublicKey is not available for [p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): authType is not available for [p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_save_user] (0x0400):
Storing info for user p-testuser
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [userPassword] from [p-testuser]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [objectSIDString] from [p-testuser]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [shadowLastChange] from [p-testuser]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [shadowMin] from [p-testuser]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [shadowMax] from [p-testuser]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [shadowWarning] from [p-testuser]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [shadowInactive] from [p-testuser]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [shadowExpire] from [p-testuser]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [shadowFlag] from [p-testuser]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [pwdAttribute] from [p-testuser]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [authorizedService] from [p-testuser]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [adAccountExpires] from [p-testuser]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [adUserAccountControl] from [p-testuser]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [nsAccountLock] from [p-testuser]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [authorizedHost] from [p-testuser]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [ndsLoginDisabled] from [p-testuser]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [ndsLoginExpirationTime] from [p-testuser]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [ndsLoginAllowedTimeMap] from [p-testuser]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [sshPublicKey] from [p-testuser]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_remove_attrs]
(0x2000): Removing attribute [authType] from [p-testuser]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_primary_name]
(0x0400): Processing object p-testuser
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_has_deref_support]
(0x0400): The server supports deref method OpenLDAP
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_print_server]
(0x2000): Searching 10.10.3.184
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x0400): calling ldap_search_ext with
[(&(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*))][cn=ipausers,cn=groups,cn=accounts,dc=xyz,dc=com].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [objectClass]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [posixGroup]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [cn]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [userPassword]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [gidNumber]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [member]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [ipaUniqueID]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [ipaNTSecurityIdentifier]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [modifyTimestamp]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [entryUSN]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x2000): ldap_search_ext called, msgid = 68
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[0x240b490],
ldap[0x2332a80]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: ldap_result found nothing!
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[0x240b490],
ldap[0x2332a80]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_entry] (0x1000):
OriginalDN: [cn=ipausers,cn=groups,cn=accounts,dc=xyz,dc=com].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [objectClass]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [cn]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [member]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [ipaUniqueID]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [modifyTimestamp]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [entryUSN]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[0x240b490],
ldap[0x2332a80]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]]
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
errmsg set
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_primary_name]
(0x0400): Processing object ipausers
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_get_direct_parents]
(0x2000): searching sysdb with filter
[(&(objectClass=group)(member=name=ipausers,cn=groups,cn=xyz.com,cn=sysdb))]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_get_direct_parents]
(0x1000): ipausers is a member of 0 sysdb groups
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]]
[sdap_initgr_nested_get_membership_diff] (0x1000): The group ipausers is a
direct member of 0 LDAP groups
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]]
[sdap_initgr_store_user_memberships] (0x1000): The user p-testuser is a
direct member of 1 LDAP groups
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_get_direct_parents]
(0x2000): searching sysdb with filter
[(&(objectClass=group)(member=name=p-testuser,cn=users,cn=xyz.com
,cn=sysdb))]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sysdb_get_direct_parents]
(0x1000): p-testuser is a member of 1 sysdb groups
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]]
[sdap_initgr_store_user_memberships] (0x2000): Updating memberships for
p-testuser
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]]
[sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
domain SID from [(null)]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_groups_next_base]
(0x0400): Searching for groups with base [cn=accounts,dc=xyz,dc=com]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_print_server]
(0x2000): Searching 10.10.3.184
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x0400): calling ldap_search_ext with
[(&(gidNumber=1879000001)(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*)(&(gidNumber=*)(!(gidNumber=0))))][cn=accounts,dc=xyz,dc=com].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [objectClass]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [posixGroup]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [cn]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [userPassword]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [gidNumber]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [member]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [ipaUniqueID]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [ipaNTSecurityIdentifier]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [modifyTimestamp]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x1000): Requesting attrs: [entryUSN]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x2000): ldap_search_ext called, msgid = 69
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[0x2376f60],
ldap[0x2332a80]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: ldap_result found nothing!
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[0x2376f60],
ldap[0x2332a80]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_entry] (0x1000):
OriginalDN: [cn=p-testuser,cn=groups,cn=accounts,dc=xyz,dc=com].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [objectClass]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [cn]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [gidNumber]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [ipaUniqueID]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [modifyTimestamp]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_parse_range] (0x2000):
No sub-attributes for [entryUSN]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[0x2376f60],
ldap[0x2332a80]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]]
[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
errmsg set
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_groups_process]
(0x0400): Search for groups, returned 1 results.
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_has_deref_support]
(0x0400): The server supports deref method OpenLDAP
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]]
[sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
domain SID from [(null)]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]]
[sdap_nested_group_process_send] (0x2000): About to process group
[cn=p-testuser,cn=groups,cn=accounts,dc=xyz,dc=com]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_nested_group_recv]
(0x0400): 0 users found in the hash table
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_nested_group_recv]
(0x0400): 1 groups found in the hash table
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_get_sid_str]
(0x1000): No [objectSIDString] attribute. [0][Success]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_primary_name]
(0x0400): Processing object p-testuser
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_save_group] (0x0400):
Processing group p-testuser
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]]
[sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
domain SID from [(null)]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_save_group] (0x2000):
This is a posix group
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): Adding original DN
[cn=p-testuser,cn=groups,cn=accounts,dc=xyz,dc=com] to attributes of
[p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_attrs_add_ldap_attr]
(0x2000): Adding original mod-Timestamp [20160505104839Z] to attributes of
[p-testuser].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_process_ghost_members]
(0x0400): The group has 0 members
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_process_ghost_members]
(0x0400): Group has 0 members
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_save_group] (0x0400):
Storing info for group p-testuser
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_primary_name]
(0x0400): Processing object p-testuser
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_save_grpmem] (0x0400):
Processing group p-testuser
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_save_grpmem] (0x0400):
Failed to get group sid
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_save_grpmem] (0x0400):
No members for group [p-testuser]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_print_server]
(0x2000): Searching 10.10.3.184
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x0400): calling ldap_search_ext with
[(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:IPA:xyz.com:ed58bb28-12ae-11e6-8a34-0ac54d537681))][cn=Default
Trust View,cn=views,cn=accounts,dc=xyz,dc=com].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_get_generic_ext_step]
(0x2000): ldap_search_ext called, msgid = 70
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[0x2368670],
ldap[0x2332a80]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: ldap_result found nothing!
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[0x2368670],
ldap[0x2332a80]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]]
[sdap_get_generic_op_finished] (0x0400): Search result: No such object(32),
no errmsg set
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sbus_add_timeout] (0x2000):
0x23788e0
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: sh[0x2357da0], connected[1], ops[(nil)], ldap[0x2332a80]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sdap_process_result]
(0x2000): Trace: ldap_result found nothing!
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sbus_remove_timeout]
(0x2000): 0x23788e0
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [acctinfo_callback]
(0x0100): Request processed. Returned 0,0,Success
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [sbus_get_sender_id_send]
(0x2000): Not a sysbus message, quit
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [be_req_set_domain]
(0x0400): Changing request domain from [xyz.com] to [xyz.com]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [be_pam_handler] (0x0100):
Got request with the following data
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
command: PAM_AUTHENTICATE
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
domain: xyz.com
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
user: p-testuser
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
service: sshd
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
tty: ssh
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
ruser:
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
rhost: 127.0.0.1
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
authtok type: 1
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
newauthtok type: 0
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
priv: 1
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
cli_pid: 32253
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [pam_print_data] (0x0100):
logon name: not set
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]]
[krb5_auth_prepare_ccache_name] (0x1000): No ccache file for user
[p-testuser] found.
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [fo_resolve_service_send]
(0x0100): Trying to resolve service 'IPA'
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [get_server_status]
(0x1000): Status of server 'ipa-master-int.xyz.com' is 'name resolved'
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [get_port_status] (0x1000):
Port status of port 0 for server 'ipa-master-int.xyz.com' is 'working'
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]]
[fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6
seconds
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [get_server_status]
(0x1000): Status of server 'ipa-master-int.xyz.com' is 'name resolved'
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [be_resolve_server_process]
(0x1000): Saving the first resolved server
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [be_resolve_server_process]
(0x0200): Found address for server ipa-master-int.xyz.com: [10.10.3.184]
TTL 60
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [child_handler_setup]
(0x2000): Setting up signal handler up for pid [32281]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [child_handler_setup]
(0x2000): Signal handler set up for pid [32281]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [write_pipe_handler]
(0x0400): All data has been sent!
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [child_sig_handler]
(0x1000): Waiting for child [32281].
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [child_sig_handler]
(0x0100): child [32281] finished successfully.
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [read_pipe_handler]
(0x0400): EOF received, client finished
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [be_pam_handler_callback]
(0x0100): Backend returned: (0, 7, <NULL>) [Success]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [be_pam_handler_callback]
(0x0100): Sending result [7][xyz.com]
(Thu May  5 14:35:49 2016) [sssd[be[xyz.com]]] [be_pam_handler_callback]
(0x0100): Sent result [7][xyz.com]
(Thu May  5 14:35:51 2016) [sssd[be[xyz.com]]] [sbus_get_sender_id_send]
(0x2000): Not a sysbus message, quit


and here is the krb5_child.log
(Thu May  5 14:35:40 2016) [[sssd[krb5_child[32274]]]] [unpack_buffer]
(0x0100): cmd [241] uid [1879000001] gid [1879000001] validate [true]
enterprise principal [false] offline [false] UPN [p-testuser at xyz.COM]
(Thu May  5 14:35:40 2016) [[sssd[krb5_child[32274]]]] [unpack_buffer]
(0x2000): No old ccache
(Thu May  5 14:35:40 2016) [[sssd[krb5_child[32274]]]] [unpack_buffer]
(0x0100): ccname: [FILE:/tmp/krb5cc_1879000001_XXXXXX] old_ccname: [not
set] keytab: [/etc/krb5.keytab]
(Thu May  5 14:35:40 2016) [[sssd[krb5_child[32274]]]] [k5c_setup_fast]
(0x0100): SSSD_KRB5_FAST_PRINCIPAL is set to [host/10.10.0.127 at xyz.COM]
(Thu May  5 14:35:40 2016) [[sssd[krb5_child[32274]]]] [match_principal]
(0x1000): Principal matched to the sample (host/10.10.0.127 at xyz.COM).
(Thu May  5 14:35:40 2016) [[sssd[krb5_child[32274]]]] [check_fast_ccache]
(0x0200): FAST TGT is still valid.
(Thu May  5 14:35:40 2016) [[sssd[krb5_child[32274]]]] [become_user]
(0x0200): Trying to become user [1879000001][1879000001].
(Thu May  5 14:35:40 2016) [[sssd[krb5_child[32274]]]] [main] (0x2000):
Running as [1879000001][1879000001].
(Thu May  5 14:35:40 2016) [[sssd[krb5_child[32274]]]] [k5c_setup]
(0x2000): Running as [1879000001][1879000001].
(Thu May  5 14:35:40 2016) [[sssd[krb5_child[32274]]]]
[set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_RENEWABLE_LIFETIME]
from environment.
(Thu May  5 14:35:40 2016) [[sssd[krb5_child[32274]]]]
[set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from
environment.
(Thu May  5 14:35:40 2016) [[sssd[krb5_child[32274]]]]
[set_canonicalize_option] (0x0100): SSSD_KRB5_CANONICALIZE is set to [true]
(Thu May  5 14:35:40 2016) [[sssd[krb5_child[32274]]]] [main] (0x0400):
Will perform online auth
(Thu May  5 14:35:40 2016) [[sssd[krb5_child[32274]]]] [tgt_req_child]
(0x1000): Attempting to get a TGT
(Thu May  5 14:35:40 2016) [[sssd[krb5_child[32274]]]] [get_and_save_tgt]
(0x0400): Attempting kinit for realm [xyz.COM]
(Thu May  5 14:35:40 2016) [[sssd[krb5_child[32274]]]] [get_and_save_tgt]
(0x0020): 1000: [-1765328353][Decrypt integrity check failed]
(Thu May  5 14:35:40 2016) [[sssd[krb5_child[32274]]]] [map_krb5_error]
(0x0020): 1069: [-1765328353][Decrypt integrity check failed]
(Thu May  5 14:35:40 2016) [[sssd[krb5_child[32274]]]] [k5c_send_data]
(0x0200): Received error code 1432158219
(Thu May  5 14:35:40 2016) [[sssd[krb5_child[32274]]]]
[pack_response_packet] (0x2000): response packet size: [4]
(Thu May  5 14:35:40 2016) [[sssd[krb5_child[32274]]]] [main] (0x0400):
krb5_child completed successfully
(Thu May  5 14:35:44 2016) [[sssd[krb5_child[32275]]]] [main] (0x0400):
krb5_child started.
(Thu May  5 14:35:44 2016) [[sssd[krb5_child[32275]]]] [unpack_buffer]
(0x1000): total buffer size: [134]
(Thu May  5 14:35:44 2016) [[sssd[krb5_child[32275]]]] [unpack_buffer]
(0x0100): cmd [241] uid [1879000001] gid [1879000001] validate [true]
enterprise principal [false] offline [false] UPN [p-testuser at xyz.COM]
(Thu May  5 14:35:44 2016) [[sssd[krb5_child[32275]]]] [unpack_buffer]
(0x2000): No old ccache
(Thu May  5 14:35:44 2016) [[sssd[krb5_child[32275]]]] [unpack_buffer]
(0x0100): ccname: [FILE:/tmp/krb5cc_1879000001_XXXXXX] old_ccname: [not
set] keytab: [/etc/krb5.keytab]
(Thu May  5 14:35:44 2016) [[sssd[krb5_child[32275]]]] [k5c_setup_fast]
(0x0100): SSSD_KRB5_FAST_PRINCIPAL is set to [host/10.10.0.127 at xyz.COM]
(Thu May  5 14:35:44 2016) [[sssd[krb5_child[32275]]]] [match_principal]
(0x1000): Principal matched to the sample (host/10.10.0.127 at xyz.COM).
(Thu May  5 14:35:44 2016) [[sssd[krb5_child[32275]]]] [check_fast_ccache]
(0x0200): FAST TGT is still valid.
(Thu May  5 14:35:44 2016) [[sssd[krb5_child[32275]]]] [become_user]
(0x0200): Trying to become user [1879000001][1879000001].
(Thu May  5 14:35:44 2016) [[sssd[krb5_child[32275]]]] [main] (0x2000):
Running as [1879000001][1879000001].
(Thu May  5 14:35:44 2016) [[sssd[krb5_child[32275]]]] [k5c_setup]
(0x2000): Running as [1879000001][1879000001].
(Thu May  5 14:35:44 2016) [[sssd[krb5_child[32275]]]]
[set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_RENEWABLE_LIFETIME]
from environment.
(Thu May  5 14:35:44 2016) [[sssd[krb5_child[32275]]]]
[set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from
environment.
(Thu May  5 14:35:44 2016) [[sssd[krb5_child[32275]]]]
[set_canonicalize_option] (0x0100): SSSD_KRB5_CANONICALIZE is set to [true]
(Thu May  5 14:35:44 2016) [[sssd[krb5_child[32275]]]] [main] (0x0400):
Will perform online auth
(Thu May  5 14:35:44 2016) [[sssd[krb5_child[32275]]]] [tgt_req_child]
(0x1000): Attempting to get a TGT
(Thu May  5 14:35:44 2016) [[sssd[krb5_child[32275]]]] [get_and_save_tgt]
(0x0400): Attempting kinit for realm [xyz.COM]
(Thu May  5 14:35:44 2016) [[sssd[krb5_child[32275]]]] [get_and_save_tgt]
(0x0020): 1000: [-1765328353][Decrypt integrity check failed]
(Thu May  5 14:35:44 2016) [[sssd[krb5_child[32275]]]] [map_krb5_error]
(0x0020): 1069: [-1765328353][Decrypt integrity check failed]
(Thu May  5 14:35:44 2016) [[sssd[krb5_child[32275]]]] [k5c_send_data]
(0x0200): Received error code 1432158219
(Thu May  5 14:35:44 2016) [[sssd[krb5_child[32275]]]]
[pack_response_packet] (0x2000): response packet size: [4]
(Thu May  5 14:35:44 2016) [[sssd[krb5_child[32275]]]] [main] (0x0400):
krb5_child completed successfully
(Thu May  5 14:35:49 2016) [[sssd[krb5_child[32281]]]] [main] (0x0400):
krb5_child started.
(Thu May  5 14:35:49 2016) [[sssd[krb5_child[32281]]]] [unpack_buffer]
(0x1000): total buffer size: [134]
(Thu May  5 14:35:49 2016) [[sssd[krb5_child[32281]]]] [unpack_buffer]
(0x0100): cmd [241] uid [1879000001] gid [1879000001] validate [true]
enterprise principal [false] offline [false] UPN [p-testuser at xyz.COM]
(Thu May  5 14:35:49 2016) [[sssd[krb5_child[32281]]]] [unpack_buffer]
(0x2000): No old ccache
(Thu May  5 14:35:49 2016) [[sssd[krb5_child[32281]]]] [unpack_buffer]
(0x0100): ccname: [FILE:/tmp/krb5cc_1879000001_XXXXXX] old_ccname: [not
set] keytab: [/etc/krb5.keytab]
(Thu May  5 14:35:49 2016) [[sssd[krb5_child[32281]]]] [k5c_setup_fast]
(0x0100): SSSD_KRB5_FAST_PRINCIPAL is set to [host/10.10.0.127 at xyz.COM]
(Thu May  5 14:35:49 2016) [[sssd[krb5_child[32281]]]] [match_principal]
(0x1000): Principal matched to the sample (host/10.10.0.127 at xyz.COM).
(Thu May  5 14:35:49 2016) [[sssd[krb5_child[32281]]]] [check_fast_ccache]
(0x0200): FAST TGT is still valid.
(Thu May  5 14:35:49 2016) [[sssd[krb5_child[32281]]]] [become_user]
(0x0200): Trying to become user [1879000001][1879000001].
(Thu May  5 14:35:49 2016) [[sssd[krb5_child[32281]]]] [main] (0x2000):
Running as [1879000001][1879000001].
(Thu May  5 14:35:49 2016) [[sssd[krb5_child[32281]]]] [k5c_setup]
(0x2000): Running as [1879000001][1879000001].
(Thu May  5 14:35:49 2016) [[sssd[krb5_child[32281]]]]
[set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_RENEWABLE_LIFETIME]
from environment.
(Thu May  5 14:35:49 2016) [[sssd[krb5_child[32281]]]]
[set_lifetime_options] (0x0100): Cannot read [SSSD_KRB5_LIFETIME] from
environment.
(Thu May  5 14:35:49 2016) [[sssd[krb5_child[32281]]]]
[set_canonicalize_option] (0x0100): SSSD_KRB5_CANONICALIZE is set to [true]
(Thu May  5 14:35:49 2016) [[sssd[krb5_child[32281]]]] [main] (0x0400):
Will perform online auth
(Thu May  5 14:35:49 2016) [[sssd[krb5_child[32281]]]] [tgt_req_child]
(0x1000): Attempting to get a TGT
(Thu May  5 14:35:49 2016) [[sssd[krb5_child[32281]]]] [get_and_save_tgt]
(0x0400): Attempting kinit for realm [xyz.COM]
(Thu May  5 14:35:49 2016) [[sssd[krb5_child[32281]]]] [get_and_save_tgt]
(0x0020): 1000: [-1765328353][Decrypt integrity check failed]
(Thu May  5 14:35:49 2016) [[sssd[krb5_child[32281]]]] [map_krb5_error]
(0x0020): 1069: [-1765328353][Decrypt integrity check failed]
(Thu May  5 14:35:49 2016) [[sssd[krb5_child[32281]]]] [k5c_send_data]
(0x0200): Received error code 1432158219
(Thu May  5 14:35:49 2016) [[sssd[krb5_child[32281]]]]
[pack_response_packet] (0x2000): response packet size: [4]
(Thu May  5 14:35:49 2016) [[sssd[krb5_child[32281]]]] [main] (0x0400):
krb5_child completed successfully


getent passwd works fine and shows me all the users not sure what could
have gone wrong...

Thanks,
Rakesh
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://listman.redhat.com/archives/freeipa-users/attachments/20160505/03439426/attachment.htm>


More information about the Freeipa-users mailing list