#862 bigger sssd load: return (1, 11, Fast reply - offline)
Closed: Invalid None Opened 12 years ago by fhanzlik.

I use sssd with openldap db for authentication and account services, slapd run on same machine, which act as small mailserver (~600 accounts). Problem occurs, when sending mass e-mail for bigger group of local users - multiple getpwnam calls at same time from mail system causes successful result for only some part of them, and fail for remains, which ends as "User unknown" for these.

Same result I achieve when run command "id user1&id user2&id user3&..." for ~200 users - for lot of them id return "No such user".
Inspecting sssd logs it sees that sssd ldap backend switch for some time (>60 seconds) to offline mode, which is unacceptable. How I can avoid this?
In previous configuration (Fedora 10/openldap/pam_ldap+nss_ldap) were no problems.

part of sssd ldap domain log (sorry for its length):

(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_get_initgr_user] (9): Process user's groups
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_get_generic_send] (6): calling ldap_search_ext with [(&(memberuid=zplanicga)(objectclass=posixGroup)(cn=*)(gidNumber=*))][ou=users,dc=nekde,dc=cz].
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [objectClass]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [cn]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [userPassword]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [gidNumber]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [memberuid]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [modifyTimestamp]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [modifyTimestamp]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_get_generic_send] (8): ldap_search_ext called, msgid = 14559
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0x9fe6c48], connected[1], ops[0x9fef2f0], ldap[0x9e23798]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_parse_entry] (9): OriginalDN: [uid=llessek,ou=users,dc=nekde,dc=cz].
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0x9fe6c48], connected[1], ops[0x9fef2f0], ldap[0x9e23798]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_get_generic_done] (6): Search result: Success(0), (null)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_get_users_process] (6): Search for users, returned 1 results.
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_save_user] (9): Save user
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_save_user] (7): Adding original DN [uid=llessek,ou=users,dc=nekde,dc=cz] to attributes of [llessek].
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_save_user] (7): Original memberOf is not available for [llessek].
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_save_user] (7): Original USN value is not available for [llessek].
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_save_user] (7): User principal is not available for [llessek].
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_save_user] (6): Storing info for user llessek
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 1)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f39d68
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f39e30
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f39e30 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f39d68 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 2)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f06268
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f06330
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f06330 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f06268 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 2)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 2)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [userPrincipalName] from [llessek]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f066c0
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f07c20
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f07c20 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f066c0 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [shadowLastChange] from [llessek]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f06650
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f076e8
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f076e8 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f06650 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [shadowMin] from [llessek]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f076e8
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f07980
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f07980 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f076e8 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [shadowMax] from [llessek]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f39d68
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f07b58
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f07b58 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f39d68 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [shadowWarning] from [llessek]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f3a528
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f07c18
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f07c18 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f3a528 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [shadowInactive] from [llessek]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f39d68
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f3a528
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f3a528 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f39d68 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [shadowExpire] from [llessek]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f07c18
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f39d68
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f39d68 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f07c18 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [shadowFlag] from [llessek]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f07660
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f39ae8
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f39ae8 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f07660 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [krbLastPwdChange] from [llessek]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f07be0
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f07a00
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f07a00 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f07be0 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [krbPasswordExpiration] from [llessek]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f07be0
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f39ae8
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f39ae8 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f07be0 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [pwdAttribute] from [llessek]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f39ae8
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f39d68
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f39d68 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f39ae8 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [authorizedService] from [llessek]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f39ae8
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9e42968
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9e42968 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f39ae8 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [adAccountExpires] from [llessek]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9e41670
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9e42b10
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9e42b10 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9e41670 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [adUserAccountControl] from [llessek]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f05d08
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9e41670
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9e41670 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f05d08 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [nsAccountLock] from [llessek]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f06778
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f07420
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f07420 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f06778 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 2)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 1)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_save_users] (9): User 0 processed!
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_get_users_process] (9): Saving 1 Users - Done
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_id_op_done] (9): releasing operation connection
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [acctinfo_callback] (4): Request processed. Returned 0,0,Success
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0x9fe6c48], connected[1], ops[0x9fef2f0], ldap[0x9e23798]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_parse_entry] (9): OriginalDN: [uid=pbia,ou=users,dc=nekde,dc=cz].
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0x9fe6c48], connected[1], ops[0x9fef2f0], ldap[0x9e23798]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_get_generic_done] (6): Search result: Success(0), (null)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_get_users_process] (6): Search for users, returned 1 results.
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_save_user] (9): Save user
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_save_user] (7): Adding original DN [uid=pbia,ou=users,dc=nekde,dc=cz] to attributes of [pbia].
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_save_user] (7): Original memberOf is not available for [pbia].
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_save_user] (7): Original USN value is not available for [pbia].
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_save_user] (7): User principal is not available for [pbia].
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_save_user] (6): Storing info for user pbia
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 1)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f3a660
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9feff90
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9feff90 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f3a660 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_search_user_by_name] (6): Error: 2 (Adresář nebo soubor neexistuje)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 2)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9fef4d8
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9ff0468
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9ff0468 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9fef4d8 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_search_user_by_uid] (6): Error: 2 (Adresář nebo soubor neexistuje)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f53230
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f532f8
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f532f8 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f53230 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f08e10
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f53128
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f53128 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f08e10 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 2)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 1)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_save_users] (9): User 0 processed!
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_get_users_process] (9): Saving 1 Users - Done
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_id_op_done] (9): releasing operation connection
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [acctinfo_callback] (4): Request processed. Returned 0,0,Success
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0x9fe6c48], connected[1], ops[0x9fef2f0], ldap[0x9e23798]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_parse_entry] (9): OriginalDN: [uid=mstrnada,ou=users,dc=nekde,dc=cz].
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0x9fe6c48], connected[1], ops[0x9fef2f0], ldap[0x9e23798]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_get_generic_done] (6): Search result: Success(0), (null)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_get_initgr_user] (9): Receiving info for the user
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_get_initgr_user] (9): Storing the user
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_save_user] (9): Save user
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_save_user] (7): Adding original DN [uid=mstrnada,ou=users,dc=nekde,dc=cz] to attributes of [mstrnada].
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_save_user] (7): Original memberOf is not available for [mstrnada].
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_save_user] (7): Original USN value is not available for [mstrnada].
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_save_user] (7): User principal is not available for [mstrnada].
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_save_user] (6): Storing info for user mstrnada
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 1)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9e45fe8
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9fefd90
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9fefd90 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9e45fe8 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 2)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f39ac8
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f39b90
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f39b90 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f39ac8 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 2)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 2)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [userPrincipalName] from [mstrnada]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f37730
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f39dc8
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f39dc8 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f37730 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [shadowLastChange] from [mstrnada]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f07ec0
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f39cb8
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f39cb8 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f07ec0 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [shadowMin] from [mstrnada]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f53780
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f53108
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f53108 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f53780 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [shadowMax] from [mstrnada]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f53108
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f53780
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f53780 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f53108 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [shadowWarning] from [mstrnada]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f39938
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f53230
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f53230 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f39938 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [shadowInactive] from [mstrnada]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f53780
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f39900
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f39900 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f53780 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [shadowExpire] from [mstrnada]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f39900
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f53780
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f53780 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f39900 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [shadowFlag] from [mstrnada]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f53780
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f399a0
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f399a0 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f53780 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [krbLastPwdChange] from [mstrnada]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f53780
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f52de0
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f52de0 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f53780 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [krbPasswordExpiration] from [mstrnada]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f53780
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f53080
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f53080 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f53780 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [pwdAttribute] from [mstrnada]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f53080
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f53780
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f53780 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f53080 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [authorizedService] from [mstrnada]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9ff0330
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f375a8
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f375a8 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9ff0330 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [adAccountExpires] from [mstrnada]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f53440
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f39880
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f39880 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f53440 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [adUserAccountControl] from [mstrnada]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f52e60
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f08098
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f08098 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f52e60 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sysdb_remove_attrs] (8): Removing attribute [nsAccountLock] from [mstrnada]
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f53780
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f07fb0
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f07fb0 "ltdb_timeout"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f53780 "ltdb_callback"
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): cancel ldb transaction (nesting: 3)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 2)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 1)
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [sdap_get_initgr_user] (9): Commit change
(Tue May  3 11:35:24 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_initgr_user] (9): Process user's groups
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (6): calling ldap_search_ext with [(&(memberuid=mstrnada)(objectclass=posixGroup)(cn=*)(gidNumber=*))][ou=users,dc=nekde,dc=cz].
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [objectClass]
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [cn]
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [userPassword]
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [gidNumber]
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [memberuid]
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [modifyTimestamp]
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (7): Requesting attrs: [modifyTimestamp]
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_generic_send] (8): ldap_search_ext called, msgid = 14560
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0x9fe6c48], connected[1], ops[0x9ee0b30], ldap[0x9e23798]
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_parse_entry] (9): OriginalDN: [uid=jheinza,ou=users,dc=nekde,dc=cz].
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0x9fe6c48], connected[1], ops[0x9ee0b30], ldap[0x9e23798]
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_generic_done] (6): Search result: Success(0), (null)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_users_process] (6): Search for users, returned 1 results.
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_save_user] (9): Save user
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_save_user] (7): Adding original DN [uid=jheinza,ou=users,dc=nekde,dc=cz] to attributes of [jheinza].
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_save_user] (7): Original memberOf is not available for [jheinza].
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_save_user] (7): Original USN value is not available for [jheinza].
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_save_user] (7): User principal is not available for [jheinza].
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_save_user] (6): Storing info for user jheinza
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 1)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f53208
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f532d0
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f532d0 "ltdb_timeout"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f53208 "ltdb_callback"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sysdb_search_user_by_name] (6): Error: 2 (Adresář nebo soubor neexistuje)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 2)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f52ec0
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f52f88
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f52f88 "ltdb_timeout"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f52ec0 "ltdb_callback"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sysdb_search_user_by_uid] (6): Error: 2 (Adresář nebo soubor neexistuje)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f05de8
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f05eb0
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f05eb0 "ltdb_timeout"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f05de8 "ltdb_callback"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 3)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 3)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f06240
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f05ff8
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f05ff8 "ltdb_timeout"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f06240 "ltdb_callback"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 3)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 2)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 1)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_save_users] (9): User 0 processed!
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_users_process] (9): Saving 1 Users - Done
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_id_op_done] (9): releasing operation connection
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [acctinfo_callback] (4): Request processed. Returned 0,0,Success
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0x9fe6c48], connected[1], ops[0x9ee0b30], ldap[0x9e23798]
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_generic_done] (6): Search result: Success(0), (null)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f52f60
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f53028
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f53028 "ltdb_timeout"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f52f60 "ltdb_callback"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_initgr_common_store] (8): Updating memberships for jhalek
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_initgr_done] (9): Initgroups done
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_id_op_connect_step] (9): reusing cached connection
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_id_op_destroy] (9): releasing operation connection
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_id_op_done] (9): releasing operation connection
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [acctinfo_callback] (4): Request processed. Returned 0,0,Success
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0x9fe6c48], connected[1], ops[0x9ee0b30], ldap[0x9e23798]
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_generic_done] (6): Search result: Success(0), (null)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0xa030778
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0xa030098
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0xa030098 "ltdb_timeout"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0xa030778 "ltdb_callback"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_initgr_common_store] (8): Updating memberships for rdoubrava
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_initgr_done] (9): Initgroups done
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_id_op_connect_step] (9): reusing cached connection
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_id_op_destroy] (9): releasing operation connection
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_id_op_done] (9): releasing operation connection
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [acctinfo_callback] (4): Request processed. Returned 0,0,Success
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0x9fe6c48], connected[1], ops[0x9ee0b30], ldap[0x9e23798]
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_generic_done] (6): Search result: Success(0), (null)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9ee28c0
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0xa030098
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0xa030098 "ltdb_timeout"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9ee28c0 "ltdb_callback"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_initgr_common_store] (8): Updating memberships for bla\1
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_initgr_done] (9): Initgroups done
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_id_op_connect_step] (9): reusing cached connection
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_id_op_destroy] (9): releasing operation connection
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_id_op_done] (9): releasing operation connection
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [acctinfo_callback] (4): Request processed. Returned 0,0,Success
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0x9fe6c48], connected[1], ops[0x9ee0b30], ldap[0x9e23798]
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_generic_done] (6): Search result: Success(0), (null)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9ee28c0
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0xa030098
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0xa030098 "ltdb_timeout"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9ee28c0 "ltdb_callback"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_initgr_common_store] (8): Updating memberships for zplanicga
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_initgr_done] (9): Initgroups done
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_id_op_connect_step] (9): reusing cached connection
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_id_op_destroy] (9): releasing operation connection
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_id_op_done] (9): releasing operation connection
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [acctinfo_callback] (4): Request processed. Returned 0,0,Success
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0x9fe6c48], connected[1], ops[0x9ee0b30], ldap[0x9e23798]
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_generic_done] (6): Search result: Success(0), (null)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9ed80b8
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f115d8
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f115d8 "ltdb_timeout"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9ed80b8 "ltdb_callback"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_initgr_common_store] (8): Updating memberships for mstrnada
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_get_initgr_done] (9): Initgroups done
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_id_op_connect_step] (9): reusing cached connection
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_id_op_destroy] (9): releasing operation connection
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_id_op_done] (9): releasing operation connection
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [acctinfo_callback] (4): Request processed. Returned 0,0,Success
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0x9fe6c48], connected[1], ops[(nil)], ldap[0x9e23798]
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: ldap_result found nothing!
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [cleanup_users] (9): Cache expiration is set to 1 days
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [sysdb_search_users] (6): Search users with filter: (&(objectclass=user)(&(!(dataExpireTimestamp=0))(dataExpireTimestamp<=1304415325)(|(!(lastLogin=*))(lastLogin<=1304328925))))
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9ee1a48
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9ee28c0
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9ee28c0 "ltdb_timeout"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9ee1a48 "ltdb_callback"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [cleanup_users] (4): Found 12 expired user entries!
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [cleanup_users] (9): About to delete user hkulhanga
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0xa02f7e8
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9e895b8
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9e895b8 "ltdb_timeout"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0xa02f7e8 "ltdb_callback"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f9d1e0
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9feccb0
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9e460f8
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f52d58
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9feccb0 "ltdb_timeout"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f9d1e0 "ltdb_callback"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f52d58 "ltdb_timeout"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9e460f8 "ltdb_callback"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [cleanup_users] (9): About to delete user evlacina
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f52d58
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9ecd140
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9ecd140 "ltdb_timeout"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f52d58 "ltdb_callback"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f5bce8
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9e86748
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9e75078
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9ffac18
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9e86748 "ltdb_timeout"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f5bce8 "ltdb_callback"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9ffac18 "ltdb_timeout"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9e75078 "ltdb_callback"
(Tue May  3 11:35:25 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [cleanup_users] (9): About to delete user hkantoj
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0xa0301a0
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9ffc220
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9ffc220 "ltdb_timeout"
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0xa0301a0 "ltdb_callback"
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9fb97f0
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f12dd8
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9febbf8
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9e750f8
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f12dd8 "ltdb_timeout"
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9fb97f0 "ltdb_callback"
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9e750f8 "ltdb_timeout"
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9febbf8 "ltdb_callback"
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [cleanup_users] (9): About to delete user hkoziaga
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f39218
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9fefe48
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9fefe48 "ltdb_timeout"
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f39218 "ltdb_callback"
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f11530
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9fbd260
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9ee1080
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9ed8138
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9fbd260 "ltdb_timeout"
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f11530 "ltdb_callback"
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9ed8138 "ltdb_timeout"
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9ee1080 "ltdb_callback"
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [cleanup_users] (5): User vruzicga is still logged in or a dummy entry, keeping data
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [cleanup_users] (5): User lkucej is still logged in or a dummy entry, keeping data
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [cleanup_users] (5): User mpapeza is still logged in or a dummy entry, keeping data
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [cleanup_users] (9): About to delete user hcapga
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9fbd260
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f39218
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f39218 "ltdb_timeout"
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9fbd260 "ltdb_callback"
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f12dc8
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9fefe70
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9e45250
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9fef6d8
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9fefe70 "ltdb_timeout"
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f12dc8 "ltdb_callback"
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9fef6d8 "ltdb_timeout"
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9e45250 "ltdb_callback"
(Tue May  3 11:35:26 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [cleanup_users] (9): About to delete user hmarga
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f39218
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0xa021160
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0xa021160 "ltdb_timeout"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f39218 "ltdb_callback"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9e866e0
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f12d70
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9e88f98
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f52c10
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f12d70 "ltdb_timeout"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9e866e0 "ltdb_callback"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f52c10 "ltdb_timeout"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9e88f98 "ltdb_callback"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [cleanup_users] (5): User kpetrzal is still logged in or a dummy entry, keeping data
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [cleanup_users] (9): About to delete user fboucof
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9e866e0
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f12d70
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f12d70 "ltdb_timeout"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9e866e0 "ltdb_callback"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f113e8
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f12d70
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9ed8138
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9ffabb0
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f12d70 "ltdb_timeout"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f113e8 "ltdb_callback"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9ffabb0 "ltdb_timeout"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9ed8138 "ltdb_callback"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [cleanup_users] (5): User jnovak is still logged in or a dummy entry, keeping data
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [sysdb_search_groups] (6): Search groups with filter: (&(objectclass=group)(&(!(dataExpireTimestamp=0))(dataExpireTimestamp<=1304415327)))
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9ffabb0
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f12d70
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f12d70 "ltdb_timeout"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9ffabb0 "ltdb_callback"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [cleanup_groups] (4): Found 7 expired group entries!
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [sysdb_search_users] (6): Search users with filter: (&(objectclass=user)(|(memberOf=name=vruzicga,cn=groups,cn=default,cn=sysdb)(gidNumber=10319)))
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9febd20
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0xa0302e8
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0xa0302e8 "ltdb_timeout"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9febd20 "ltdb_callback"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [sysdb_search_users] (6): Search users with filter: (&(objectclass=user)(|(memberOf=name=lkucej,cn=groups,cn=default,cn=sysdb)(gidNumber=10283)))
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9e47d00
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9e76458
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9e76458 "ltdb_timeout"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9e47d00 "ltdb_callback"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [sysdb_search_users] (6): Search users with filter: (&(objectclass=user)(|(memberOf=name=mpapeza,cn=groups,cn=default,cn=sysdb)(gidNumber=10180)))
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9e76458
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9e47d00
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9e47d00 "ltdb_timeout"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9e76458 "ltdb_callback"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [sysdb_search_users] (6): Search users with filter: (&(objectclass=user)(|(memberOf=name=mrabasa,cn=groups,cn=default,cn=sysdb)(gidNumber=10415)))
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9e47d00
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9e76458
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9e76458 "ltdb_timeout"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9e47d00 "ltdb_callback"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [sysdb_search_users] (6): Search users with filter: (&(objectclass=user)(|(memberOf=name=kpetrzal,cn=groups,cn=default,cn=sysdb)(gidNumber=10036)))
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9e76458
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9e47d00
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9e47d00 "ltdb_timeout"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9e76458 "ltdb_callback"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [sysdb_search_users] (6): Search users with filter: (&(objectclass=user)(|(memberOf=name=llessek,cn=groups,cn=default,cn=sysdb)(gidNumber=10349)))
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9e47d00
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9e76458
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9e76458 "ltdb_timeout"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9e47d00 "ltdb_callback"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [sysdb_search_users] (6): Search users with filter: (&(objectclass=user)(|(memberOf=name=jnovak,cn=groups,cn=default,cn=sysdb)(gidNumber=10431)))
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9e76458
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9edaf38
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9edaf38 "ltdb_timeout"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9e76458 "ltdb_callback"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldap_id_cleanup_set_timer] (6): Scheduling next cleanup at 1304415326.854176
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [cleanup_users] (9): Cache expiration is set to 1 days
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [sysdb_search_users] (6): Search users with filter: (&(objectclass=user)(&(!(dataExpireTimestamp=0))(dataExpireTimestamp<=1304415327)(|(!(lastLogin=*))(lastLogin<=1304328927))))
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9e4a008
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9e44ec0
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9e44ec0 "ltdb_timeout"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9e4a008 "ltdb_callback"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [cleanup_users] (4): Found 9 expired user entries!
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [cleanup_users] (9): About to delete user hpospichana
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9ffc220
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0xa02f7e8
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0xa02f7e8 "ltdb_timeout"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9ffc220 "ltdb_callback"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9ee17f8
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f9d1e0
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0xa03acd0
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f52fa8
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f9d1e0 "ltdb_timeout"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9ee17f8 "ltdb_callback"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f52fa8 "ltdb_timeout"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0xa03acd0 "ltdb_callback"
(Tue May  3 11:35:27 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [cleanup_users] (9): About to delete user evymazana
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9ee2900
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f0dfb0
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f0dfb0 "ltdb_timeout"
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9ee2900 "ltdb_callback"
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9edac38
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f52ce0
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9ed81c0
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0xa0302d0
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f52ce0 "ltdb_timeout"
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9edac38 "ltdb_callback"
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0xa0302d0 "ltdb_timeout"
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9ed81c0 "ltdb_callback"
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [cleanup_users] (9): About to delete user hrandaga
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f535d8
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f0dfb0
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f0dfb0 "ltdb_timeout"
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f535d8 "ltdb_callback"
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f397c8
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9e86748
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9febf40
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f53038
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9e86748 "ltdb_timeout"
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f397c8 "ltdb_callback"
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f53038 "ltdb_timeout"
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9febf40 "ltdb_callback"
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [cleanup_users] (9): About to delete user lrandusa
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f53038
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9febf40
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9febf40 "ltdb_timeout"
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f53038 "ltdb_callback"
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): start ldb transaction (nesting: 0)
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f397c8
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9e76380
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9e750f0
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9ff03c8
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9e76380 "ltdb_timeout"
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f397c8 "ltdb_callback"
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9ff03c8 "ltdb_timeout"
(Tue May  3 11:35:28 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9e750f0 "ltdb_callback"
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): commit ldb transaction (nesting: 0)
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [cleanup_users] (5): User vruzicga is still logged in or a dummy entry, keeping data
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [cleanup_users] (5): User lkucej is still logged in or a dummy entry, keeping data
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [cleanup_users] (5): User mpapeza is still logged in or a dummy entry, keeping data
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [cleanup_users] (5): User kpetrzal is still logged in or a dummy entry, keeping data
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [cleanup_users] (5): User jnovak is still logged in or a dummy entry, keeping data
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sysdb_search_groups] (6): Search groups with filter: (&(objectclass=group)(&(!(dataExpireTimestamp=0))(dataExpireTimestamp<=1304415329)))
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9e750f0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9ffd978
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9ffd978 "ltdb_timeout"
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9e750f0 "ltdb_callback"
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [cleanup_groups] (4): Found 7 expired group entries!
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sysdb_search_users] (6): Search users with filter: (&(objectclass=user)(|(memberOf=name=vruzicga,cn=groups,cn=default,cn=sysdb)(gidNumber=10319)))
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f115d8
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9ffd978
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9ffd978 "ltdb_timeout"
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f115d8 "ltdb_callback"
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sysdb_search_users] (6): Search users with filter: (&(objectclass=user)(|(memberOf=name=lkucej,cn=groups,cn=default,cn=sysdb)(gidNumber=10283)))
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9eccf38
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9ffd978
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9ffd978 "ltdb_timeout"
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9eccf38 "ltdb_callback"
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sysdb_search_users] (6): Search users with filter: (&(objectclass=user)(|(memberOf=name=mpapeza,cn=groups,cn=default,cn=sysdb)(gidNumber=10180)))
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f115d8
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9ffd978
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9ffd978 "ltdb_timeout"
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f115d8 "ltdb_callback"
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sysdb_search_users] (6): Search users with filter: (&(objectclass=user)(|(memberOf=name=mrabasa,cn=groups,cn=default,cn=sysdb)(gidNumber=10415)))
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9eccf38
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9ffd978
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9ffd978 "ltdb_timeout"
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9eccf38 "ltdb_callback"
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sysdb_search_users] (6): Search users with filter: (&(objectclass=user)(|(memberOf=name=kpetrzal,cn=groups,cn=default,cn=sysdb)(gidNumber=10036)))
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9f115d8
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9ffd978
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9ffd978 "ltdb_timeout"
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9f115d8 "ltdb_callback"
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sysdb_search_users] (6): Search users with filter: (&(objectclass=user)(|(memberOf=name=llessek,cn=groups,cn=default,cn=sysdb)(gidNumber=10349)))
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9eccf38
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9ffd978
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9ffd978 "ltdb_timeout"
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9eccf38 "ltdb_callback"
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sysdb_search_users] (6): Search users with filter: (&(objectclass=user)(|(memberOf=name=jnovak,cn=groups,cn=default,cn=sysdb)(gidNumber=10431)))
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0x9eccf38
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0x9f115d8
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0x9f115d8 "ltdb_timeout"
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0x9eccf38 "ltdb_callback"
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldap_id_cleanup_set_timer] (6): Scheduling next cleanup at 1304415328.1444826
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sdap_handle_release] (8): Trace: sh[0x9ed01d0], connected[1], ops[(nil)], ldap[0x9e754e0], destructor_lock[0], release_memory[0]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [remove_connection_callback] (9): Successfully removed connection callback.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [fo_set_port_status] (4): Marking port 389 of server 'mail.nekde.cz' as 'not working'
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [fo_resolve_service_send] (4): Trying to resolve service 'LDAP'
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [get_server_status] (7): Status of server 'mail.nekde.cz' is 'working'
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [get_port_status] (7): Port status of port 389 for server 'mail.nekde.cz' is 'not working'
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [get_server_status] (7): Status of server 'mail.nekde.cz' is 'working'
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [get_port_status] (7): Port status of port 389 for server 'mail.nekde.cz' is 'not working'
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [fo_resolve_service_send] (1): No available servers for service 'LDAP'
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_mark_offline] (8): Going offline!
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_run_offline_cb] (3): Going offline. Running callbacks.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Backend returned: (1, 9, <NULL>) [Provider is Offline (Autentizační služba nemůže získat informace pro autentizaci)]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sending result [9][default]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sent result [9][default]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sdap_handle_release] (8): Trace: sh[0x9f0f038], connected[1], ops[(nil)], ldap[0x9ee0ed0], destructor_lock[0], release_memory[0]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [remove_connection_callback] (9): Successfully removed connection callback.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [fo_set_port_status] (4): Marking port 389 of server 'mail.nekde.cz' as 'not working'
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [fo_resolve_service_send] (4): Trying to resolve service 'LDAP'
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [get_server_status] (7): Status of server 'mail.nekde.cz' is 'working'
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [get_port_status] (7): Port status of port 389 for server 'mail.nekde.cz' is 'not working'
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [fo_resolve_service_send] (1): No available servers for service 'LDAP'
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_mark_offline] (8): Going offline!
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_run_offline_cb] (3): Going offline. Running callbacks.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Backend returned: (1, 9, <NULL>) [Provider is Offline (Autentizační služba nemůže získat informace pro autentizaci)]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sending result [9][default]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sent result [9][default]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sdap_handle_release] (8): Trace: sh[0x9ffd410], connected[1], ops[(nil)], ldap[0x9ee51e8], destructor_lock[0], release_memory[0]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [remove_connection_callback] (9): Successfully removed connection callback.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [fo_set_port_status] (4): Marking port 389 of server 'mail.nekde.cz' as 'not working'
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [fo_resolve_service_send] (4): Trying to resolve service 'LDAP'
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [get_server_status] (7): Status of server 'mail.nekde.cz' is 'working'
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [get_port_status] (7): Port status of port 389 for server 'mail.nekde.cz' is 'not working'
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [fo_resolve_service_send] (1): No available servers for service 'LDAP'
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_mark_offline] (8): Going offline!
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_run_offline_cb] (3): Going offline. Running callbacks.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Backend returned: (1, 9, <NULL>) [Provider is Offline (Autentizační služba nemůže získat informace pro autentizaci)]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sending result [9][default]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sent result [9][default]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sdap_handle_release] (8): Trace: sh[0x9f39278], connected[1], ops[(nil)], ldap[0x9f392b0], destructor_lock[0], release_memory[0]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [remove_connection_callback] (9): Successfully removed connection callback.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [fo_set_port_status] (4): Marking port 389 of server 'mail.nekde.cz' as 'not working'
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [fo_resolve_service_send] (4): Trying to resolve service 'LDAP'
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [get_server_status] (7): Status of server 'mail.nekde.cz' is 'working'
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [get_port_status] (7): Port status of port 389 for server 'mail.nekde.cz' is 'not working'
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [fo_resolve_service_send] (1): No available servers for service 'LDAP'
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_mark_offline] (8): Going offline!
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_run_offline_cb] (3): Going offline. Running callbacks.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Backend returned: (1, 9, <NULL>) [Provider is Offline (Autentizační služba nemůže získat informace pro autentizaci)]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sending result [9][default]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sent result [9][default]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [auth_bind_user_done] (9): Found ppolicy data, assuming LDAP password policies are active.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sdap_handle_release] (8): Trace: sh[0x9e86918], connected[1], ops[(nil)], ldap[0x9ee1378], destructor_lock[0], release_memory[0]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [remove_connection_callback] (9): Successfully removed connection callback.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_mark_offline] (8): Going offline!
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_run_offline_cb] (3): Going offline. Running callbacks.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Backend returned: (1, 9, <NULL>) [Provider is Offline (Autentizační služba nemůže získat informace pro autentizaci)]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sending result [9][default]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sent result [9][default]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldap_id_cleanup_timer] (4): Backend is marked offline, retry later!
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [ldap_id_cleanup_set_timer] (6): Scheduling next cleanup at 1304415330.538520
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 9D82CD0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [getAccountInfo]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_get_account_info] (4): Got request for [3][1][name=lmerinek]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [acctinfo_callback] (4): Request processed. Returned 1,11,Offline
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 9D82CD0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [getAccountInfo]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_get_account_info] (4): Got request for [3][1][name=pbia]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [acctinfo_callback] (4): Request processed. Returned 1,11,Offline
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 9D82CD0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [pamHandler]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler] (4): Got request with the following data
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): command: PAM_ACCT_MGMT
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): domain: default
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): user: jhalek
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): service: dovecot
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): tty: dovecot
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): ruser: jhalek
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): rhost: 88.102.93.192
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): authtok type: 0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): authtok size: 0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok type: 0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok size: 0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): priv: 0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): cli_pid: 14404
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_target_access_permit] (9): be_target_access_permit called, returning PAM_SUCCESS.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Backend returned: (0, 0, <NULL>) [Success]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sending result [0][default]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sent result [0][default]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 9D82CD0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [pamHandler]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler] (4): Got request with the following data
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): command: PAM_AUTHENTICATE
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): domain: default
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): user: rdoubrava
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): service: dovecot
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): tty: dovecot
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): ruser: rdoubrava
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): rhost: 77.104.254.75
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): authtok type: 1
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): authtok size: 9
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok type: 0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok size: 0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): priv: 0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): cli_pid: 14329
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sdap_pam_auth_handler] (4): Backend is marked offline, retry later!
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Backend returned: (1, 9, <NULL>) [Provider is Offline (Autentizační služba nemůže získat informace pro autentizaci)]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sending result [9][default]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sent result [9][default]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 9D82CD0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [pamHandler]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler] (4): Got request with the following data
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): command: PAM_AUTHENTICATE
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): domain: default
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): user: bla\1
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): service: dovecot
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): tty: dovecot
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): ruser: bla\1
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): rhost: 109.80.92.20
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): authtok type: 1
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): authtok size: 9
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok type: 0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok size: 0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): priv: 0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): cli_pid: 14387
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sdap_pam_auth_handler] (4): Backend is marked offline, retry later!
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Backend returned: (1, 9, <NULL>) [Provider is Offline (Autentizační služba nemůže získat informace pro autentizaci)]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sending result [9][default]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sent result [9][default]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 9D82CD0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [pamHandler]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler] (4): Got request with the following data
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): command: PAM_AUTHENTICATE
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): domain: default
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): user: zplanicga
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): service: dovecot
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): tty: dovecot
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): ruser: zplanicga
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): rhost: 90.180.154.142
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): authtok type: 1
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): authtok size: 9
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok type: 0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): newauthtok size: 0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): priv: 0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [pam_print_data] (4): cli_pid: 14331
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sdap_pam_auth_handler] (4): Backend is marked offline, retry later!
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Backend returned: (1, 9, <NULL>) [Provider is Offline (Autentizační služba nemůže získat informace pro autentizaci)]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sending result [9][default]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sent result [9][default]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 9D82CD0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [getAccountInfo]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_get_account_info] (4): Got request for [3][1][name=lrandusa]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [acctinfo_callback] (4): Request processed. Returned 1,11,Offline
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 9D82CD0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 9D82CD0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 9D82CD0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 9D82CD0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 9D82CD0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 9D82CD0
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 9D81798
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [getAccountInfo]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_get_account_info] (4): Got request for [4097][1][name=ohorek]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_get_account_info] (4): Request processed. Returned 1,11,Fast reply - offline
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 9D81798
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [getAccountInfo]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_get_account_info] (4): Got request for [4097][1][name=jkleina]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_get_account_info] (4): Request processed. Returned 1,11,Fast reply - offline
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 9D81798
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [getAccountInfo]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_get_account_info] (4): Got request for [4097][1][name=eivica]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_get_account_info] (4): Request processed. Returned 1,11,Fast reply - offline
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 9D81798
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_message_handler] (9): Received SBUS method [getAccountInfo]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_get_account_info] (4): Got request for [4097][1][name=rbrazdon]
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [be_get_account_info] (4): Request processed. Returned 1,11,Fast reply - offline
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): dbus conn: 9D81798
(Tue May  3 11:35:29 2011) [sssd[be[default]]] [sbus_dispatch] (9): Dispatching.

Thank in advance, Franta Hanzlik


Sorry, I now see as this maybe same problem as #633 issue.

https://fedorahosted.org/sssd/ticket/633

PS: please, is possible set anywhere something as notification when there any response on ticket appears? (receiving responding e-mail, probably). In my profile at fedoraproject.org I cannot find such option.

Thank in advance, Franta Hanzlik

Replying to [comment:1 fhanzlik]:

PS: please, is possible set anywhere something as notification when there any response on ticket appears? (receiving responding e-mail, probably). In my profile at fedoraproject.org I cannot find such option.

You can add your FAS account name to the CC list of the bug and you will get emails whenever they are updated. I have added you to the CC list of ticket #633.

What we think is happening here is that at some point during the processing of all of these users, the load on your LDAP server is increasing to the point where it cannot reply within the six second timeout that SSSD sets by default.

There are two ways you can go about mitigating this issue through config file tuning:

  1. Increase the value of {{{ldap_search_timeout}}} in {{{[domain/default]}}} to something more reasonable for your environment.
  2. Alternately, if it is very common in your environment for large numbers of users to be looked up simultaneously, you may find that it works better to enable enumeration mode by setting {{{enumerate = true}}} in {{{[domain/default]}}}. This will pre-cache all users and groups in the SSSD, so that you need not go out to LDAP on each initial request.

component: SSSD => LDAP Provider
milestone: NEEDS_TRIAGE => SSSD 1.7.0

Since there is a good workaround and it is a corner case moving to 1.9.

milestone: SSSD 1.8.0 => SSSD 1.9.0

Fields changed

blockedby: =>
blocking: =>
milestone: SSSD 1.9.0 => SSSD Deferred
rhbz: =>

Fields changed

rhbz: => 0

Fields changed

changelog: =>
design: =>
design_review: => 0
feature_milestone: =>
fedora_test_page: =>
mark: => 0
review: => 1
selected: =>
sensitive: => 0

There is really no information to fix this ticket and it was filed against an ancient version. Please file a new one if you are still experiencing the bug.

resolution: => worksforme
status: new => closed

Metadata Update from @fhanzlik:
- Issue set to the milestone: SSSD Patches welcome

7 years ago

SSSD is moving from Pagure to Github. This means that new issues and pull requests
will be accepted only in SSSD's github repository.

This issue has been cloned to Github and is available here:
- https://github.com/SSSD/sssd/issues/1904

If you want to receive further updates on the issue, please navigate to the github issue
and click on subscribe button.

Thank you for understanding. We apologize for all inconvenience.

Login to comment on this ticket.

Metadata