Attachment 699028 Details for Bug 912470 – sssd log after reproducing issue (debug level 0xFFF0)

sssd log after reproducing issue (debug level 0xFFF0)

sssd_SECURITY.log (text/x-log), 69.58 KB, created by Miroslav Vadkerti on 2013-02-18 18:20:08 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Miroslav Vadkerti

Created: 2013-02-18 18:20:08 UTC

Size: 69.58 KB

patch

obsolete

>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A9BF50
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [getAccountInfo]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [be_get_account_info] (0x0100): Got request for [3][1][name=thrix]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xab3bd0
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xaa2650
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xaa2650 "ltdb_timeout"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xab3bd0 "ltdb_callback"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xacb3a0
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xacca50
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xab30a0
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xaacaa0
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xacca50 "ltdb_timeout"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xacb3a0 "ltdb_callback"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xaacaa0 "ltdb_timeout"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xab30a0 "ltdb_callback"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_initgr_send] (0x4000): Retrieving info for initgroups call
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_initgr_next_base] (0x0400): Searching for users with base [DC=security,DC=baseos,DC=qe]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(sAMAccountName=thrix)(objectclass=user))][DC=security,DC=baseos,DC=qe].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 9
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_process_result] (0x2000): Trace: sh[0xaaccd0], connected[1], ops[0xa9ea30], ldap[0xa9c3e0]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_parse_entry] (0x4000): OriginalDN: [CN=Miroslav MV. Vadkerti,CN=Users,DC=security,DC=baseos,DC=qe].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectClass]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [whenChanged]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [uSNChanged]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [name]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectGUID]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [userAccountControl]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [primaryGroupID]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectSid]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [accountExpires]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [sAMAccountName]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [userPrincipalName]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_process_result] (0x2000): Trace: sh[0xaaccd0], connected[1], ops[0xa9ea30], ldap[0xa9c3e0]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_process_result] (0x2000): Trace: sh[0xaaccd0], connected[1], ops[0xa9ea30], ldap[0xa9c3e0]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_process_result] (0x2000): Trace: sh[0xaaccd0], connected[1], ops[0xa9ea30], ldap[0xa9c3e0]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_process_result] (0x2000): Trace: sh[0xaaccd0], connected[1], ops[0xa9ea30], ldap[0xa9c3e0]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_initgr_user] (0x4000): Receiving info for the user
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): start ldb transaction (nesting: 0)
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_initgr_user] (0x4000): Storing the user
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_save_user] (0x4000): Save user
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_save_user] (0x1000): Mapping user [thrix] objectSID to unix ID
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_save_user] (0x2000): Adding originalDN [CN=Miroslav MV. Vadkerti,CN=Users,DC=security,DC=baseos,DC=qe] to attributes of [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_save_user] (0x1000): Original memberOf is not available for [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding original mod-Timestamp [20130213163343.0Z] to attributes of [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_save_user] (0x1000): Adding user principal [thrix@SECURITY.BASEOS.QE] to attributes of [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowLastChange is not available for [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowMin is not available for [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowMax is not available for [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowWarning is not available for [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowInactive is not available for [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowExpire is not available for [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowFlag is not available for [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): krbLastPwdChange is not available for [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): krbPasswordExpiration is not available for [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): pwdAttribute is not available for [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): authorizedService is not available for [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding adAccountExpires [9223372036854775807] to attributes of [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding adUserAccountControl [512] to attributes of [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): nsAccountLock is not available for [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): authorizedHost is not available for [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginDisabled is not available for [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginExpirationTime is not available for [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginAllowedTimeMap is not available for [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): sshPublicKey is not available for [thrix].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sysdb_attrs_get_aliases] (0x2000): Domain is case-insensitive; will add lowercased aliases
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_save_user] (0x0400): Storing info for user thrix
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): start ldb transaction (nesting: 1)
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xaae900
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xaaea20
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xaaea20 "ltdb_timeout"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xaae900 "ltdb_callback"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): start ldb transaction (nesting: 2)
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xaaea20
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xaae900
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xaae900 "ltdb_timeout"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xaaea20 "ltdb_callback"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): commit ldb transaction (nesting: 2)
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): start ldb transaction (nesting: 2)
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sysdb_remove_attrs] (0x2000): Removing attribute [userPassword] from [thrix]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xac7f60
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xaae900
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xaae900 "ltdb_timeout"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xac7f60 "ltdb_callback"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sysdb_remove_attrs] (0x2000): Removing attribute [homeDirectory] from [thrix]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xaae900
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xac7f60
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xac7f60 "ltdb_timeout"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xaae900 "ltdb_callback"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sysdb_remove_attrs] (0x2000): Removing attribute [loginShell] from [thrix]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xac7f60
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xaae900
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xaae900 "ltdb_timeout"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xac7f60 "ltdb_callback"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): commit ldb transaction (nesting: 2)
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): commit ldb transaction (nesting: 1)
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_initgr_user] (0x4000): Commit change
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): commit ldb transaction (nesting: 0)
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xabc640
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xabc760
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xabc760 "ltdb_timeout"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xabc640 "ltdb_callback"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_initgr_user] (0x4000): Process user's groups
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [no filter][CN=Miroslav MV. Vadkerti,CN=Users,DC=security,DC=baseos,DC=qe].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [tokenGroups]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 10
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_process_result] (0x2000): Trace: sh[0xaaccd0], connected[1], ops[0xab21a0], ldap[0xa9c3e0]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_process_result] (0x2000): Trace: sh[0xaaccd0], connected[1], ops[0xab21a0], ldap[0xa9c3e0]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_parse_entry] (0x4000): OriginalDN: [CN=Miroslav MV. Vadkerti,CN=Users,DC=security,DC=baseos,DC=qe].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [tokenGroups]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_process_result] (0x2000): Trace: sh[0xaaccd0], connected[1], ops[0xab21a0], ldap[0xa9c3e0]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): start ldb transaction (nesting: 0)
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_ad_tokengroups_initgroups_lookup_done] (0x1000): Processing membership SID [S-1-5-32-545]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_idmap_sid_to_unix] (0x0400): Object SID [S-1-5-32-545] is a built-in one.
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_ad_tokengroups_initgroups_lookup_done] (0x0400): Skipping built-in object.
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_ad_tokengroups_initgroups_lookup_done] (0x1000): Processing membership SID [S-1-5-21-1423704084-1338527952-1194901926-513]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_ad_tokengroups_initgroups_lookup_done] (0x1000): Processing membership GID [132600513]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xab3d80
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xab3ea0
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xab3ea0 "ltdb_timeout"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xab3d80 "ltdb_callback"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xabf450
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xac0270
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xac0270 "ltdb_timeout"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xabf450 "ltdb_callback"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_ad_tokengroups_initgroups_lookup_done] (0x1000): Updating memberships for [thrix]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): start ldb transaction (nesting: 1)
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): commit ldb transaction (nesting: 1)
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): commit ldb transaction (nesting: 0)
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_initgr_done] (0x4000): Initgroups done
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_get_initgr_done] (0x1000): Mapping primary group to unix ID
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_id_op_destroy] (0x4000): releasing operation connection
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_id_op_done] (0x4000): releasing operation connection
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sbus_add_timeout] (0x2000): 0xab2bb0
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_process_result] (0x2000): Trace: sh[0xaaccd0], connected[1], ops[(nil)], ldap[0xa9c3e0]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sbus_remove_timeout] (0x2000): 0xab2bb0
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A9B080
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A9BF50
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [pamHandler]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [be_pam_handler] (0x0100): Got request with the following data
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): command: PAM_AUTHENTICATE
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): domain: SECURITY
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): user: thrix
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): service: sshd
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): tty: ssh
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): ruser: 
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): rhost: localhost
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): authtok type: 1
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): authtok size: 9
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): newauthtok type: 0
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): newauthtok size: 0
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): priv: 1
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): cli_pid: 5652
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [krb5_pam_handler] (0x1000): Wait queue of user [thrix] is empty, running request immediately.
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xaae900
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xab21a0
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xab21a0 "ltdb_timeout"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xaae900 "ltdb_callback"
>
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [krb5_auth_send] (0x0100): Home directory for user [thrix] not known.
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [krb5_auth_send] (0x0100): No ccache file for user [thrix] found.
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [krb5_auth_send] (0x4000): Ccache_file is [not set] and is not active and TGT is not valid.
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD'
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [get_server_status] (0x1000): Status of server 'dc.security.baseos.qe' is 'working'
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc.security.baseos.qe' is 'working'
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 10 seconds
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [get_server_status] (0x1000): Status of server 'dc.security.baseos.qe' is 'working'
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [be_resolve_server_process] (0x1000): Saving the first resolved server
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [be_resolve_server_process] (0x0200): Found address for server dc.security.baseos.qe: [10.34.36.170] TTL 3600
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [krb5_find_ccache_step] (0x4000): Recreating  ccache file.
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [5654]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [child_handler_setup] (0x2000): Signal handler set up for pid [5654]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [write_pipe_handler] (0x0400): All data has been sent!
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [read_pipe_handler] (0x0400): EOF received, client finished
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [parse_krb5_child_response] (0x1000): child response [12][1][21].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [check_wait_queue] (0x1000): Wait queue for user [thrix] is empty.
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 12, <NULL>) [Success]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [be_pam_handler_callback] (0x0100): Sending result [12][SECURITY]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [be_pam_handler_callback] (0x0100): Sent result [12][SECURITY]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A9BF50
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [pamHandler]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [be_pam_handler] (0x0100): Got request with the following data
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): command: PAM_ACCT_MGMT
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): domain: SECURITY
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): user: thrix
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): service: sshd
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): tty: ssh
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): ruser: 
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): rhost: localhost
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): authtok type: 0
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): authtok size: 0
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): newauthtok type: 0
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): newauthtok size: 0
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): priv: 1
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): cli_pid: 5652
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [simple_access_check] (0x4000): User [thrix] found in allow list, access granted.
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 0, <NULL>) [Success]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [be_pam_handler_callback] (0x0400): SELinux provider doesn't exist, not sending the request to it.
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [be_pam_handler_callback] (0x0100): Sending result [0][SECURITY]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [be_pam_handler_callback] (0x0100): Sent result [0][SECURITY]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [child_sig_handler] (0x1000): Waiting for child [5654].
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [child_sig_handler] (0x0100): child [5654] finished successfully.
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sss_child_handler] (0x2000): waitpid failed [10]: No child processes
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A9BF50
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [pamHandler]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [be_pam_handler] (0x0100): Got request with the following data
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): command: PAM_SETCRED
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): domain: SECURITY
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): user: thrix
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): service: sshd
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): tty: ssh
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): ruser: 
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): rhost: localhost
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): authtok type: 0
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): authtok size: 0
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): newauthtok type: 0
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): newauthtok size: 0
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): priv: 1
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): cli_pid: 5652
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [be_pam_handler] (0x0100): Sending result [0][SECURITY]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A9BF50
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [pamHandler]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [be_pam_handler] (0x0100): Got request with the following data
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): command: PAM_OPEN_SESSION
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): domain: SECURITY
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): user: thrix
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): service: sshd
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): tty: ssh
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): ruser: 
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): rhost: localhost
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): authtok type: 0
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): authtok size: 0
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): newauthtok type: 0
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): newauthtok size: 0
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): priv: 1
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): cli_pid: 5652
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [be_pam_handler] (0x0100): Sending result [0][SECURITY]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A9BF50
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [pamHandler]
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [be_pam_handler] (0x0100): Got request with the following data
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): command: PAM_SETCRED
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): domain: SECURITY
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): user: thrix
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): service: sshd
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): tty: ssh
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): ruser: 
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): rhost: localhost
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): authtok type: 0
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): authtok size: 0
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): newauthtok type: 0
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): newauthtok size: 0
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): priv: 0
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): cli_pid: 5655
>(Mon Feb 18 19:17:31 2013) [sssd[be[SECURITY]]] [be_pam_handler] (0x0100): Sending result [0][SECURITY]
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A881D0
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [ping]
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A9BF50
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [pamHandler]
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [be_pam_handler] (0x0100): Got request with the following data
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): command: PAM_CHAUTHTOK_PRELIM
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): domain: SECURITY
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): user: thrix
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): service: passwd
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): tty: pts/1
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): ruser: 
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): rhost: 
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): authtok type: 1
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): authtok size: 9
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): newauthtok type: 0
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): newauthtok size: 0
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): priv: 0
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): cli_pid: 5656
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [krb5_pam_handler] (0x1000): Wait queue of user [thrix] is empty, running request immediately.
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xab21a0
>
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xaa2650
>
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xaa2650 "ltdb_timeout"
>
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xab21a0 "ltdb_callback"
>
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [krb5_auth_send] (0x0100): Home directory for user [thrix] not known.
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [krb5_auth_send] (0x0100): No ccache file for user [thrix] found.
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [krb5_auth_send] (0x4000): Ccache_file is [not set] and is not active and TGT is not valid.
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD'
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [get_server_status] (0x1000): Status of server 'dc.security.baseos.qe' is 'working'
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc.security.baseos.qe' is 'working'
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 10 seconds
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [get_server_status] (0x1000): Status of server 'dc.security.baseos.qe' is 'working'
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [be_resolve_server_process] (0x1000): Saving the first resolved server
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [be_resolve_server_process] (0x0200): Found address for server dc.security.baseos.qe: [10.34.36.170] TTL 3600
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [krb5_find_ccache_step] (0x4000): Recreating  ccache file.
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [5657]
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [child_handler_setup] (0x2000): Signal handler set up for pid [5657]
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [write_pipe_handler] (0x0400): All data has been sent!
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [read_pipe_handler] (0x0400): EOF received, client finished
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [check_wait_queue] (0x1000): Wait queue for user [thrix] is empty.
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 0, <NULL>) [Success]
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [be_pam_handler_callback] (0x0100): Sending result [0][SECURITY]
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [be_pam_handler_callback] (0x0100): Sent result [0][SECURITY]
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [child_sig_handler] (0x1000): Waiting for child [5657].
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [child_sig_handler] (0x0100): child [5657] finished successfully.
>(Mon Feb 18 19:17:34 2013) [sssd[be[SECURITY]]] [sss_child_handler] (0x2000): waitpid failed [10]: No child processes
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A9BF50
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [getAccountInfo]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [be_get_account_info] (0x0100): Got request for [3][1][name=thrix]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xacbb10
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xab21a0
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xab21a0 "ltdb_timeout"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xacbb10 "ltdb_callback"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xaacaa0
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xab3bd0
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xab30a0
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xab3150
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xab3bd0 "ltdb_timeout"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xaacaa0 "ltdb_callback"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xab3150 "ltdb_timeout"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xab30a0 "ltdb_callback"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_initgr_send] (0x4000): Retrieving info for initgroups call
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_initgr_next_base] (0x0400): Searching for users with base [DC=security,DC=baseos,DC=qe]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(sAMAccountName=thrix)(objectclass=user))][DC=security,DC=baseos,DC=qe].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 11
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_process_result] (0x2000): Trace: sh[0xaaccd0], connected[1], ops[0xa9ea30], ldap[0xa9c3e0]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_parse_entry] (0x4000): OriginalDN: [CN=Miroslav MV. Vadkerti,CN=Users,DC=security,DC=baseos,DC=qe].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectClass]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [whenChanged]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [uSNChanged]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [name]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectGUID]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [userAccountControl]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [primaryGroupID]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [objectSid]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [accountExpires]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [sAMAccountName]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [userPrincipalName]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_process_result] (0x2000): Trace: sh[0xaaccd0], connected[1], ops[0xa9ea30], ldap[0xa9c3e0]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_process_result] (0x2000): Trace: sh[0xaaccd0], connected[1], ops[0xa9ea30], ldap[0xa9c3e0]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_process_result] (0x2000): Trace: sh[0xaaccd0], connected[1], ops[0xa9ea30], ldap[0xa9c3e0]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_REFERENCE]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_process_result] (0x2000): Trace: sh[0xaaccd0], connected[1], ops[0xa9ea30], ldap[0xa9c3e0]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_initgr_user] (0x4000): Receiving info for the user
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): start ldb transaction (nesting: 0)
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_initgr_user] (0x4000): Storing the user
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_save_user] (0x4000): Save user
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_save_user] (0x1000): Mapping user [thrix] objectSID to unix ID
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_save_user] (0x2000): Adding originalDN [CN=Miroslav MV. Vadkerti,CN=Users,DC=security,DC=baseos,DC=qe] to attributes of [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_save_user] (0x1000): Original memberOf is not available for [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding original mod-Timestamp [20130213163343.0Z] to attributes of [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_save_user] (0x1000): Adding user principal [thrix@SECURITY.BASEOS.QE] to attributes of [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowLastChange is not available for [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowMin is not available for [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowMax is not available for [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowWarning is not available for [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowInactive is not available for [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowExpire is not available for [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowFlag is not available for [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): krbLastPwdChange is not available for [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): krbPasswordExpiration is not available for [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): pwdAttribute is not available for [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): authorizedService is not available for [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding adAccountExpires [9223372036854775807] to attributes of [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding adUserAccountControl [512] to attributes of [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): nsAccountLock is not available for [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): authorizedHost is not available for [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginDisabled is not available for [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginExpirationTime is not available for [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginAllowedTimeMap is not available for [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_attrs_add_ldap_attr] (0x2000): sshPublicKey is not available for [thrix].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sysdb_attrs_get_aliases] (0x2000): Domain is case-insensitive; will add lowercased aliases
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_save_user] (0x0400): Storing info for user thrix
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): start ldb transaction (nesting: 1)
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xaa2eb0
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xab3660
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xab3660 "ltdb_timeout"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xaa2eb0 "ltdb_callback"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): start ldb transaction (nesting: 2)
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xab3660
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xac2f00
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xac2f00 "ltdb_timeout"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xab3660 "ltdb_callback"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): commit ldb transaction (nesting: 2)
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): start ldb transaction (nesting: 2)
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sysdb_remove_attrs] (0x2000): Removing attribute [userPassword] from [thrix]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xab3660
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xac0ed0
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xac0ed0 "ltdb_timeout"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xab3660 "ltdb_callback"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sysdb_remove_attrs] (0x2000): Removing attribute [homeDirectory] from [thrix]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xac8400
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xab3660
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xab3660 "ltdb_timeout"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xac8400 "ltdb_callback"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sysdb_remove_attrs] (0x2000): Removing attribute [loginShell] from [thrix]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): start ldb transaction (nesting: 3)
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xac8400
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xac1e40
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xac1e40 "ltdb_timeout"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xac8400 "ltdb_callback"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3)
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): commit ldb transaction (nesting: 2)
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): commit ldb transaction (nesting: 1)
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_initgr_user] (0x4000): Commit change
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): commit ldb transaction (nesting: 0)
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xaa2df0
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xab3d80
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xab3d80 "ltdb_timeout"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xaa2df0 "ltdb_callback"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_initgr_user] (0x4000): Process user's groups
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [no filter][CN=Miroslav MV. Vadkerti,CN=Users,DC=security,DC=baseos,DC=qe].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [tokenGroups]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 12
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_process_result] (0x2000): Trace: sh[0xaaccd0], connected[1], ops[0xac9ba0], ldap[0xa9c3e0]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_process_result] (0x2000): Trace: sh[0xaaccd0], connected[1], ops[0xac9ba0], ldap[0xa9c3e0]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_parse_entry] (0x4000): OriginalDN: [CN=Miroslav MV. Vadkerti,CN=Users,DC=security,DC=baseos,DC=qe].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_parse_range] (0x2000): No sub-attributes for [tokenGroups]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_process_result] (0x2000): Trace: sh[0xaaccd0], connected[1], ops[0xac9ba0], ldap[0xa9c3e0]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): start ldb transaction (nesting: 0)
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_ad_tokengroups_initgroups_lookup_done] (0x1000): Processing membership SID [S-1-5-32-545]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_idmap_sid_to_unix] (0x0400): Object SID [S-1-5-32-545] is a built-in one.
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_ad_tokengroups_initgroups_lookup_done] (0x0400): Skipping built-in object.
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_ad_tokengroups_initgroups_lookup_done] (0x1000): Processing membership SID [S-1-5-21-1423704084-1338527952-1194901926-513]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_ad_tokengroups_initgroups_lookup_done] (0x1000): Processing membership GID [132600513]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xab3e90
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xacb650
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xacb650 "ltdb_timeout"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xab3e90 "ltdb_callback"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xac0dd0
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xab3df0
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xab3df0 "ltdb_timeout"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xac0dd0 "ltdb_callback"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_ad_tokengroups_initgroups_lookup_done] (0x1000): Updating memberships for [thrix]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): start ldb transaction (nesting: 1)
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): commit ldb transaction (nesting: 1)
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): commit ldb transaction (nesting: 0)
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_initgr_done] (0x4000): Initgroups done
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_get_initgr_done] (0x1000): Mapping primary group to unix ID
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_id_op_destroy] (0x4000): releasing operation connection
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_id_op_done] (0x4000): releasing operation connection
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sbus_add_timeout] (0x2000): 0xacacf0
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_process_result] (0x2000): Trace: sh[0xaaccd0], connected[1], ops[(nil)], ldap[0xa9c3e0]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing!
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sbus_remove_timeout] (0x2000): 0xacacf0
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A9B080
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A9BF50
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [pamHandler]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [be_pam_handler] (0x0100): Got request with the following data
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): command: PAM_CHAUTHTOK
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): domain: SECURITY
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): user: thrix
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): service: passwd
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): tty: pts/1
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): ruser: 
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): rhost: 
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): authtok type: 1
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): authtok size: 9
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): newauthtok type: 1
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): newauthtok size: 8
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): priv: 0
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): cli_pid: 5656
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [krb5_pam_handler] (0x1000): Wait queue of user [thrix] is empty, running request immediately.
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0xaad2a0
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xaaea20
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Destroying timer event 0xaaea20 "ltdb_timeout"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [ldb] (0x4000): Ending timer event 0xaad2a0 "ltdb_callback"
>
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [krb5_auth_send] (0x0100): Home directory for user [thrix] not known.
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [krb5_auth_send] (0x0100): No ccache file for user [thrix] found.
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [krb5_auth_send] (0x4000): Ccache_file is [not set] and is not active and TGT is not valid.
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD'
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [get_server_status] (0x1000): Status of server 'dc.security.baseos.qe' is 'working'
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [get_port_status] (0x1000): Port status of port 389 for server 'dc.security.baseos.qe' is 'working'
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 10 seconds
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [resolve_srv_send] (0x0200): The status of SRV lookup is resolved
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [get_server_status] (0x1000): Status of server 'dc.security.baseos.qe' is 'working'
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [be_resolve_server_process] (0x1000): Saving the first resolved server
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [be_resolve_server_process] (0x0200): Found address for server dc.security.baseos.qe: [10.34.36.170] TTL 3600
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [krb5_find_ccache_step] (0x4000): Recreating  ccache file.
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [5658]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [child_handler_setup] (0x2000): Signal handler set up for pid [5658]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [write_pipe_handler] (0x0400): All data has been sent!
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [read_pipe_handler] (0x0400): EOF received, client finished
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [parse_krb5_child_response] (0x1000): child response [20][1][27].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [parse_krb5_child_response] (0x1000): child response [20][6][8].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [check_wait_queue] (0x1000): Wait queue for user [thrix] is empty.
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 20, <NULL>) [Success]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [be_pam_handler_callback] (0x0100): Sending result [20][SECURITY]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [be_pam_handler_callback] (0x0100): Sent result [20][SECURITY]
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [child_sig_handler] (0x1000): Waiting for child [5658].
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [child_sig_handler] (0x0100): child [5658] finished successfully.
>(Mon Feb 18 19:17:39 2013) [sssd[be[SECURITY]]] [sss_child_handler] (0x2000): waitpid failed [10]: No child processes
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A9BF50
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [pamHandler]
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [be_pam_handler] (0x0100): Got request with the following data
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): command: PAM_CLOSE_SESSION
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): domain: SECURITY
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): user: thrix
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): service: sshd
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): tty: ssh
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): ruser: 
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): rhost: localhost
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): authtok type: 0
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): authtok size: 0
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): newauthtok type: 0
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): newauthtok size: 0
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): priv: 1
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): cli_pid: 5652
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [be_pam_handler] (0x0100): Sending result [0][SECURITY]
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A9BF50
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [pamHandler]
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [be_pam_handler] (0x0100): Got request with the following data
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): command: PAM_SETCRED
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): domain: SECURITY
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): user: thrix
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): service: sshd
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): tty: ssh
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): ruser: 
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): rhost: localhost
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): authtok type: 0
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): authtok size: 0
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): newauthtok type: 0
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): newauthtok size: 0
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): priv: 1
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [pam_print_data] (0x0100): cli_pid: 5652
>(Mon Feb 18 19:17:40 2013) [sssd[be[SECURITY]]] [be_pam_handler] (0x0100): Sending result [0][SECURITY]
>(Mon Feb 18 19:17:44 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A881D0
>(Mon Feb 18 19:17:44 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:17:44 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [ping]
>(Mon Feb 18 19:17:54 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A881D0
>(Mon Feb 18 19:17:54 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:17:54 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [ping]
>(Mon Feb 18 19:18:04 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A881D0
>(Mon Feb 18 19:18:04 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:18:04 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [ping]
>(Mon Feb 18 19:18:14 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A881D0
>(Mon Feb 18 19:18:14 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:18:14 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [ping]
>(Mon Feb 18 19:18:24 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A881D0
>(Mon Feb 18 19:18:24 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:18:24 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [ping]
>(Mon Feb 18 19:18:34 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A881D0
>(Mon Feb 18 19:18:34 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:18:34 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [ping]
>(Mon Feb 18 19:18:44 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A881D0
>(Mon Feb 18 19:18:44 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:18:44 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [ping]
>(Mon Feb 18 19:18:54 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A881D0
>(Mon Feb 18 19:18:54 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:18:54 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [ping]
>(Mon Feb 18 19:19:04 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A881D0
>(Mon Feb 18 19:19:04 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:19:04 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [ping]
>(Mon Feb 18 19:19:14 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A881D0
>(Mon Feb 18 19:19:14 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:19:14 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [ping]
>(Mon Feb 18 19:19:24 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A881D0
>(Mon Feb 18 19:19:24 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:19:24 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [ping]
>(Mon Feb 18 19:19:25 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): dbus conn: A881D0
>(Mon Feb 18 19:19:25 2013) [sssd[be[SECURITY]]] [sbus_dispatch] (0x4000): Dispatching.
>(Mon Feb 18 19:19:25 2013) [sssd[be[SECURITY]]] [sbus_message_handler] (0x4000): Received SBUS method [resetOffline]
>(Mon Feb 18 19:19:25 2013) [sssd[be[SECURITY]]] [check_if_online] (0x2000): Backend is already online, nothing to do.

Actions: View

Attachments on bug 912470: 699028