[Freeipa-users] freeipa permission denied for user
Rakesh Rajasekharan
rakesh.rajasekharan at gmail.com
Thu May 5 15:06:32 UTC 2016
this was the caching issue followed the documentation
http://www.freeipa.org/page/Troubleshooting
apparently the hosts were earlier attempted to configure with another
master.
so, rm -f /var/lib/sss/db/* and sssd restart helped me get out of this
issue.
Thanks,
Rakesh
On Thu, May 5, 2016 at 8:13 PM, Rakesh Rajasekharan <
rakesh.rajasekharan at gmail.com> wrote:
> 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/d47b0f03/attachment.htm>
More information about the Freeipa-users
mailing list