On 11/05/2014 08:16 PM, Orion Poplawski wrote: > Just recently we're seeing some very strange behavior on our system. > Periodically we will see a sssd process start to have an ever greater number > of connections to our ldap server until the server runs out of file > descriptors. This seems to be happening with a particular user, who is having > trouble logging in at times, particularly with email (dovecot). We see > entries like the following on our sever: > > [05/Nov/2014:17:14:51 -0700] conn=1786153 op=0 EXT > oid="1.3.6.1.4.1.1466.20037" name="startTLS" > [05/Nov/2014:17:14:51 -0700] conn=1786153 op=0 RESULT err=0 tag=120 nentries=0 > etime=0 > [05/Nov/2014:17:14:51 -0700] conn=1786153 SSL 128-bit AES > [05/Nov/2014:17:14:51 -0700] conn=1786153 op=1 BIND > dn="uid=user,ou=People,dc=domain,dc=com" method=128 version=3 > [05/Nov/2014:17:14:56 -0700] conn=1786153 op=2 ABANDON targetop=NOTFOUND msgid=2 > [05/Nov/2014:17:14:56 -0700] conn=1786153 op=3 UNBIND > [05/Nov/2014:17:14:56 -0700] conn=1786153 op=3 fd=1022 closed - U1 > > I don't yet have debug info from the sssd process. Any ideas from the above? > > Restarting the sssd process seems to clear things up for a while. > > - Orion > I tried turning on some error log tracing to see if that helps: [11/Nov/2014:16:33:55 -0700] - new connection on 66 [11/Nov/2014:16:33:55 -0700] - => ids_sasl_server_new (SERVER.DOMAIN.com) [11/Nov/2014:16:33:55 -0700] - ids_sasl_getopt: plugin= option=log_level [11/Nov/2014:16:33:55 -0700] - ids_sasl_getopt: plugin= option=auto_transition [11/Nov/2014:16:33:55 -0700] - <= ids_sasl_server_new [11/Nov/2014:16:33:55 -0700] - --> pagedresults_is_timedout [11/Nov/2014:16:33:55 -0700] - <-- pagedresults_is_timedout: - [11/Nov/2014:16:33:55 -0700] - --> pagedresults_is_timedout [11/Nov/2014:16:33:55 -0700] - <-- pagedresults_is_timedout: - [11/Nov/2014:16:33:55 -0700] - activity on 66r [11/Nov/2014:16:33:55 -0700] - read activity on 66 [11/Nov/2014:16:33:55 -0700] - add_pb [11/Nov/2014:16:33:55 -0700] - --> pagedresults_is_timedout [11/Nov/2014:16:33:55 -0700] - <-- pagedresults_is_timedout: - [11/Nov/2014:16:33:55 -0700] - get_pb [11/Nov/2014:16:33:55 -0700] - conn 2843 activity level = 0 [11/Nov/2014:16:33:55 -0700] - --> pagedresults_in_use [11/Nov/2014:16:33:55 -0700] - <-- pagedresults_in_use: 0 [11/Nov/2014:16:33:55 -0700] - do_extended [11/Nov/2014:16:33:55 -0700] - => get_ldapmessage_controls [11/Nov/2014:16:33:55 -0700] - <= get_ldapmessage_controls no controls [11/Nov/2014:16:33:55 -0700] - listener got signaled [11/Nov/2014:16:33:55 -0700] - => send_ldap_result 0::Start TLS request accepted.Server willing to negotiate SSL. [11/Nov/2014:16:33:55 -0700] - --> pagedresults_is_timedout [11/Nov/2014:16:33:55 -0700] - <= send_ldap_result [11/Nov/2014:16:33:55 -0700] - <-- pagedresults_is_timedout: - [11/Nov/2014:16:33:55 -0700] - --> pagedresults_is_timedout [11/Nov/2014:16:33:55 -0700] - <-- pagedresults_is_timedout: - [11/Nov/2014:16:33:55 -0700] - activity on 66r [11/Nov/2014:16:33:55 -0700] - read activity on 66 [11/Nov/2014:16:33:55 -0700] - add_pb [11/Nov/2014:16:33:55 -0700] - --> pagedresults_is_timedout [11/Nov/2014:16:33:55 -0700] - <-- pagedresults_is_timedout: - [11/Nov/2014:16:33:55 -0700] - get_pb [11/Nov/2014:16:33:55 -0700] - => slapi_reslimit_get_integer_limit() conn=0x9465f290, handle=8 [11/Nov/2014:16:33:55 -0700] - <= slapi_reslimit_get_integer_limit() returning NO VALUE [11/Nov/2014:16:33:55 -0700] - do_bind [11/Nov/2014:16:33:55 -0700] - listener got signaled [11/Nov/2014:16:33:55 -0700] - --> pagedresults_is_timedout [11/Nov/2014:16:33:55 -0700] - <-- pagedresults_is_timedout: - [11/Nov/2014:16:33:55 -0700] - --> pagedresults_is_timedout [11/Nov/2014:16:33:55 -0700] - <-- pagedresults_is_timedout: - [11/Nov/2014:16:33:55 -0700] - BIND dn="uid=USER,ou=People,dc=DOMAIN,dc=com" method=128 version=3 [11/Nov/2014:16:33:55 -0700] - => get_ldapmessage_controls [11/Nov/2014:16:33:55 -0700] - => slapi_control_present (looking for 2.16.840.1.113730.3.4.2) [11/Nov/2014:16:33:55 -0700] - <= slapi_control_present 0 (NOT FOUND) [11/Nov/2014:16:33:55 -0700] - => slapi_control_present (looking for 1.3.6.1.4.1.42.2.27.8.5.1) [11/Nov/2014:16:33:55 -0700] - <= slapi_control_present 1 (FOUND) [11/Nov/2014:16:33:55 -0700] - <= get_ldapmessage_controls 1 controls [11/Nov/2014:16:33:55 -0700] - => slapi_control_present (looking for 2.16.840.1.113730.3.4.16) [11/Nov/2014:16:33:55 -0700] - <= slapi_control_present 0 (NOT FOUND) [11/Nov/2014:16:33:55 -0700] - do_bind: version 3 method 0x80 dn uid=USER,ou=People,dc=DOMAIN,dc=com [11/Nov/2014:16:33:55 -0700] - Calling plugin 'Legacy replication preoperation plugin' #6 type 401 [11/Nov/2014:16:33:55 -0700] - Calling plugin 'Multimaster replication preoperation plugin' #9 type 401 [11/Nov/2014:16:33:55 -0700] - => slapi_control_present (looking for 2.16.840.1.113730.3.4.12) [11/Nov/2014:16:33:55 -0700] - <= slapi_control_present 0 (NO CONTROLS) [11/Nov/2014:16:33:55 -0700] - => slapi_control_present (looking for 2.16.840.1.113730.3.4.18) [11/Nov/2014:16:33:55 -0700] - <= slapi_control_present 0 (NO CONTROLS) [11/Nov/2014:16:33:55 -0700] - => slapi_reslimit_get_integer_limit() conn=0x0, handle=6 [11/Nov/2014:16:33:55 -0700] - <= slapi_reslimit_get_integer_limit() returning NO VALUE [11/Nov/2014:16:33:55 -0700] - => slapi_reslimit_get_integer_limit() conn=0x0, handle=5 [11/Nov/2014:16:33:55 -0700] - <= slapi_reslimit_get_integer_limit() returning NO VALUE [11/Nov/2014:16:33:55 -0700] - => compute_limits: sizelimit=-1, timelimit=-1 [11/Nov/2014:16:33:55 -0700] - Calling plugin 'Account Usability Plugin' #1 type 403 [11/Nov/2014:16:33:55 -0700] account-usability-plugin - --> auc_pre_search [11/Nov/2014:16:33:55 -0700] account-usability-plugin - <-- auc_pre_op [11/Nov/2014:16:33:55 -0700] - Calling plugin 'ACL preoperation' #2 type 403 [11/Nov/2014:16:33:55 -0700] - Calling plugin 'deref' #4 type 403 [11/Nov/2014:16:33:55 -0700] deref-plugin - --> deref_pre_search [11/Nov/2014:16:33:55 -0700] deref-plugin - <-- deref_pre_op [11/Nov/2014:16:33:55 -0700] - Calling plugin 'Legacy replication preoperation plugin' #6 type 403 [11/Nov/2014:16:33:55 -0700] - Calling plugin 'Multimaster replication preoperation plugin' #9 type 403 [11/Nov/2014:16:33:55 -0700] - => slapi_reslimit_get_integer_limit() conn=0x0, handle=0 [11/Nov/2014:16:33:55 -0700] - <= slapi_reslimit_get_integer_limit() returning NO VALUE [11/Nov/2014:16:33:55 -0700] - => find_entry_internal (dn=uid=USER,ou=people,dc=DOMAIN,dc=com) lock 0 [11/Nov/2014:16:33:55 -0700] - => dn2entry_ext "uid=USER,ou=people,dc=DOMAIN,dc=com" [11/Nov/2014:16:33:55 -0700] - <= dn2entry_ext 7f7d300101a0 [11/Nov/2014:16:33:55 -0700] - <= find_entry_internal_dn found (uid=USER,ou=people,dc=DOMAIN,dc=com) [11/Nov/2014:16:33:55 -0700] - <= find_entry_internal [11/Nov/2014:16:33:55 -0700] - candidate list has 1 ids [11/Nov/2014:16:33:55 -0700] id2entry - => id2entry(19) [11/Nov/2014:16:33:55 -0700] id2entry - <= id2entry 7f7d300101a0, dn "uid=USER,ou=people,dc=DOMAIN,dc=com" (cache) [11/Nov/2014:16:33:55 -0700] id2entry - <= id2entry( 19 ) 7f7d300101a0 (disk) [11/Nov/2014:16:33:55 -0700] - => send_ldap_search_entry (uid=USER,ou=People,dc=DOMAIN,dc=com) [11/Nov/2014:16:33:55 -0700] - Calling plugin 'Account Usability Plugin' #1 type 410 [11/Nov/2014:16:33:55 -0700] - Calling plugin 'deref' #4 type 410 [11/Nov/2014:16:33:55 -0700] - Calling plugin 'Legacy replication preoperation plugin' #6 type 410 [11/Nov/2014:16:33:55 -0700] - <= send_ldap_search_entry [11/Nov/2014:16:33:55 -0700] - => send_ldap_result 0:: [11/Nov/2014:16:33:55 -0700] - <= send_ldap_result [11/Nov/2014:16:33:55 -0700] - --> cos_cache_vattr_get [11/Nov/2014:16:33:55 -0700] - --> cos_cache_getref [11/Nov/2014:16:33:55 -0700] - <-- cos_cache_getref [11/Nov/2014:16:33:55 -0700] - --> cos_cache_query_attr [11/Nov/2014:16:33:55 -0700] - --> cos_cache_find_attr [11/Nov/2014:16:33:55 -0700] - <-- cos_cache_find_attr [11/Nov/2014:16:33:55 -0700] - <-- cos_cache_query_attr [11/Nov/2014:16:33:55 -0700] - --> cos_cache_release [11/Nov/2014:16:33:55 -0700] - <-- cos_cache_release [11/Nov/2014:16:33:55 -0700] - <-- cos_cache_vattr_get [11/Nov/2014:16:33:55 -0700] - => find_entry_internal (dn=uid=USER,ou=People,dc=DOMAIN,dc=com) lock 0 [11/Nov/2014:16:33:55 -0700] - => dn2entry_ext "uid=USER,ou=People,dc=DOMAIN,dc=com" [11/Nov/2014:16:33:55 -0700] - <= dn2entry_ext 7f7d300101a0 [11/Nov/2014:16:33:55 -0700] - <= find_entry_internal_dn found (uid=USER,ou=People,dc=DOMAIN,dc=com) [11/Nov/2014:16:33:55 -0700] - <= find_entry_internal [11/Nov/2014:16:33:55 -0700] - => slapi_pw_find value: "PASSWORD" [11/Nov/2014:16:33:55 -0700] - <= slapi_pw_find matched "PASSWORD_HASH" using scheme "SSHA" [11/Nov/2014:16:33:55 -0700] - => reslimit_update_from_entry() conn=0x9465f290, entry=0x48011630 [11/Nov/2014:16:33:55 -0700] - reslimit_update_from_entry(): setting limit for handle 0 (based on nsLookThroughLimit) [11/Nov/2014:16:33:55 -0700] - reslimit_update_from_entry(): setting limit for handle 1 (based on nsIDListScanLimit) [11/Nov/2014:16:33:55 -0700] - reslimit_update_from_entry(): setting limit for handle 2 (based on nsPagedLookThroughLimit) [11/Nov/2014:16:33:55 -0700] - reslimit_update_from_entry(): setting limit for handle 3 (based on nsPagedIDListScanLimit) [11/Nov/2014:16:33:55 -0700] - reslimit_update_from_entry(): setting limit for handle 4 (based on nsRangeSearchLookThroughLimit) [11/Nov/2014:16:33:55 -0700] - reslimit_update_from_entry(): setting limit for handle 5 (based on nsSizeLimit) [11/Nov/2014:16:33:55 -0700] - reslimit_update_from_entry(): setting limit for handle 6 (based on nsTimeLimit) [11/Nov/2014:16:33:55 -0700] - reslimit_update_from_entry(): setting limit for handle 7 (based on nsPagedSizeLimit) [11/Nov/2014:16:33:55 -0700] - reslimit_update_from_entry(): setting limit for handle 8 (based on nsIdleTimeout) [11/Nov/2014:16:33:55 -0700] - <= reslimit_update_from_entry() returning status 0 [11/Nov/2014:16:33:55 -0700] - => slapi_reslimit_get_integer_limit() conn=0x9465f290, handle=8 [11/Nov/2014:16:33:55 -0700] - <= slapi_reslimit_get_integer_limit() returning NO VALUE [11/Nov/2014:16:33:55 -0700] - => slapi_pwpolicy_make_response_control[11/Nov/2014:16:33:55 -0700] - <= slapi_pwpolicy_make_response_control[11/Nov/2014:16:33:55 -0700] - => slapi_add_pwd_control [11/Nov/2014:16:33:55 -0700] - Calling plugin 'Multimaster replication postoperation plugin' #5 type 501 [11/Nov/2014:16:33:55 -0700] - --> pagedresults_is_timedout [11/Nov/2014:16:33:55 -0700] - <-- pagedresults_is_timedout: - [11/Nov/2014:16:33:55 -0700] - --> pagedresults_is_timedout [11/Nov/2014:16:33:55 -0700] - <-- pagedresults_is_timedout: - [11/Nov/2014:16:33:55 -0700] - --> pagedresults_is_timedout [11/Nov/2014:16:33:55 -0700] - <-- pagedresults_is_timedout: - [11/Nov/2014:16:33:55 -0700] - --> pagedresults_is_timedout [11/Nov/2014:16:33:55 -0700] - <-- pagedresults_is_timedout: - [11/Nov/2014:16:33:55 -0700] - --> pagedresults_is_timedout [11/Nov/2014:16:33:55 -0700] - <-- pagedresults_is_timedout: - [11/Nov/2014:16:33:55 -0700] - --> pagedresults_is_timedout [11/Nov/2014:16:33:55 -0700] - <-- pagedresults_is_timedout: - [11/Nov/2014:16:33:56 -0700] - conn 2836 leaving turbo mode due to 4 [11/Nov/2014:16:33:56 -0700] - listener got signaled sssd_default.log:(Tue Nov 11 16:33:55 2014) [sssd[be[default]]] [find_password_expiration_attributes] (0x4000): No password policy requested. sssd_default.log:(Tue Nov 11 16:33:55 2014) [sssd[be[default]]] [simple_bind_send] (0x0100): Executing simple bind as: uid=USER,ou=People,dc=DOMAIN,dc=com sssd_default.log:(Tue Nov 11 16:33:55 2014) [sssd[be[default]]] [simple_bind_send] (0x2000): ldap simple bind sent, msgid = 2 sssd_default.log:(Tue Nov 11 16:33:55 2014) [sssd[be[default]]] [sdap_process_result] (0x2000): Trace: sh[0x7f9292dfc200], connected[1], ops[0x7f9292dff790], ldap[0x7f9292dfad00] sssd_default.log:(Tue Nov 11 16:33:55 2014) [sssd[be[default]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! sssd_default.log:(Tue Nov 11 16:33:56 2014) [sssd[be[default]]] [sbus_dispatch] (0x4000): dbus conn: 0x7f9292cf6f80 sssd_default.log:(Tue Nov 11 16:33:56 2014) [sssd[be[default]]] [sbus_dispatch] (0x4000): Dispatching. sssd_default.log:(Tue Nov 11 16:33:56 2014) [sssd[be[default]]] [sbus_message_handler] (0x4000): Received SBUS method [ping] sssd_default.log:(Tue Nov 11 16:33:56 2014) [sssd[be[default]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit sssd_default.log:(Tue Nov 11 16:33:56 2014) [sssd[be[default]]] [sbus_handler_got_caller_id] (0x4000): Received SBUS method [ping] and sssd keeps making new connections: (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP' (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [get_server_status] (0x1000): Status of server 'ldap.cora.DOMAIN.com' is 'working' (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [get_port_status] (0x1000): Port status of port 389 for server 'ldap.cora.DOMAIN.com' is 'working' (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [get_server_status] (0x1000): Status of server 'ldap.cora.DOMAIN.com' is 'working' (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [be_resolve_server_process] (0x0200): Found address for server ldap.cora.DOMAIN.com: [10.10.10.1] TTL 21600 (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [sdap_uri_callback] (0x0400): Constructed uri 'ldap://ldap.cora.DOMAIN.com/' (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [sss_ldap_init_send] (0x4000): Using file descriptor [22] for LDAP connection. (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://ldap.cora.DOMAIN.com:389/??base] with fd [22]. (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [sdap_sys_connect_done] (0x0100): Executing START TLS (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [sdap_process_result] (0x2000): Trace: sh[0x7f9292d286d0], connected[1], ops[0x7f9292dfb250], ldap[0x7f9292de3290] (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_EXTENDED] (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [sdap_connect_done] (0x0080): START TLS result: Success(0), Start TLS request accepted.Server willing to negotiate SSL. (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'ldap.cora.DOMAIN.com' as 'working' (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [set_server_common_status] (0x0100): Marking server 'ldap.cora.DOMAIN.com' as 'working' (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server 'ldap.cora.DOMAIN.com' as 'working' (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7f9292e3e8a0 (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7f9292e3e9d0 (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [ldb] (0x4000): Running timer event 0x7f9292e3e8a0 "ltdb_callback" (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [ldb] (0x4000): Destroying timer event 0x7f9292e3e9d0 "ltdb_timeout" (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [ldb] (0x4000): Ending timer event 0x7f9292e3e8a0 "ltdb_callback" (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [find_password_expiration_attributes] (0x4000): No password policy requested. (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [simple_bind_send] (0x0100): Executing simple bind as: uid=USER,ou=People,dc=DOMAIN,dc=com (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [simple_bind_send] (0x2000): ldap simple bind sent, msgid = 2 (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [sdap_process_result] (0x2000): Trace: sh[0x7f9292d286d0], connected[1], ops[0x7f9292df92a0], ldap[0x7f9292de3290] (Tue Nov 11 16:34:00 2014) [sssd[be[default]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP' (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [get_server_status] (0x1000): Status of server 'ldap.cora.DOMAIN.com' is 'working' (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [get_port_status] (0x1000): Port status of port 389 for server 'ldap.cora.DOMAIN.com' is 'working' (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 6 seconds (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [get_server_status] (0x1000): Status of server 'ldap.cora.DOMAIN.com' is 'working' (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [be_resolve_server_process] (0x0200): Found address for server ldap.cora.DOMAIN.com: [10.10.10.1] TTL 21600 (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [sdap_uri_callback] (0x0400): Constructed uri 'ldap://ldap.cora.DOMAIN.com/' (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [sss_ldap_init_send] (0x4000): Using file descriptor [23] for LDAP connection. (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [sss_ldap_init_send] (0x0400): Setting 6 seconds timeout for connecting (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://ldap.cora.DOMAIN.com:389/??base] with fd [23]. (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [sdap_sys_connect_done] (0x0100): Executing START TLS (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [sdap_process_result] (0x2000): Trace: sh[0x7f9292dfbed0], connected[1], ops[0x7f9292e38950], ldap[0x7f9292dff310] (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_EXTENDED] (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [sdap_connect_done] (0x0080): START TLS result: Success(0), Start TLS request accepted.Server willing to negotiate SSL. (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [fo_set_port_status] (0x0100): Marking port 389 of server 'ldap.cora.DOMAIN.com' as 'working' (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [set_server_common_status] (0x0100): Marking server 'ldap.cora.DOMAIN.com' as 'working' (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [fo_set_port_status] (0x0400): Marking port 389 of duplicate server 'ldap.cora.DOMAIN.com' as 'working' (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7f9292e6ae30 (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7f9292e6aef0 (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [ldb] (0x4000): Running timer event 0x7f9292e6ae30 "ltdb_callback" (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [ldb] (0x4000): Destroying timer event 0x7f9292e6aef0 "ltdb_timeout" (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [ldb] (0x4000): Ending timer event 0x7f9292e6ae30 "ltdb_callback" (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [find_password_expiration_attributes] (0x4000): No password policy requested. (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [simple_bind_send] (0x0100): Executing simple bind as: uid=USER,ou=People,dc=DOMAIN,dc=com (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [simple_bind_send] (0x2000): ldap simple bind sent, msgid = 2 (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [sdap_process_result] (0x2000): Trace: sh[0x7f9292dfbed0], connected[1], ops[0x7f9292d26dd0], ldap[0x7f9292dff310] (Tue Nov 11 16:34:05 2014) [sssd[be[default]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! (Tue Nov 11 16:34:06 2014) [sssd[be[default]]] [sbus_dispatch] (0x4000): dbus conn: 0x7f9292cf6f80 (Tue Nov 11 16:34:06 2014) [sssd[be[default]]] [sbus_dispatch] (0x4000): Dispatching. (Tue Nov 11 16:34:06 2014) [sssd[be[default]]] [sbus_message_handler] (0x4000): Received SBUS method [ping] (Tue Nov 11 16:34:06 2014) [sssd[be[default]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Tue Nov 11 16:34:06 2014) [sssd[be[default]]] [sbus_handler_got_caller_id] (0x4000): Received SBUS method [ping] -- Orion Poplawski Technical Manager 303-415-9701 x222 NWRA, Boulder/CoRA Office FAX: 303-415-9702 3380 Mitchell Lane orion@xxxxxxxx Boulder, CO 80301 http://www.nwra.com -- 389 users mailing list 389-users@xxxxxxxxxxxxxxxxxxxxxxx https://admin.fedoraproject.org/mailman/listinfo/389-users
