[SSSD-users] sbus dispatch - Connection is not open for dispatching

Sterling Sahaydak sterling.sahaydak at pi-coral.com
Tue Apr 21 15:26:05 UTC 2015


I'm using sssd with pam, OpenLDAP and OpenLDAP proxy to Active Directory 
in a sub-domain (sj)

[root at ldap ~]# sssd --version
1.11.6


sssd.conf(sj) => slapd.conf(sj) => AD-sj


  and noticing a message in the sssd logs:


[sssd[be[LDAP]]] [sbus_dispatch] (0x0080): Connection is not open for 
dispatching


Shown in the log:  (servers are in the sub-domain sj)

ORIG - sssd.sj point to ldap.sj and AD-sj
================================================
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [be_resolve_server_process] 
(0x0200): Found address for server ad-sj.ad.example.com: [10.47.100.15] 
TTL 7200
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sdap_uri_callback] 
(0x0400): Constructed uri 'ldaps://ad-sj.ad.example.com'
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sss_ldap_init_send] 
(0x4000): Using file descriptor [18] for LDAP connection.
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sss_ldap_init_send] 
(0x0400): Setting 6 seconds timeout for connecting
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sbus_remove_watch] 
(0x2000): 0xab3a60/0xab2010
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sbus_remove_watch] 
(0x2000): 0xab3a60/0xab3cf0
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): 
dbus conn: 0xac0d30
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sbus_dispatch] (0x0080): 
Connection is not open for dispatching.
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [be_client_destructor] 
(0x0400): Removed SUDO client
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sbus_remove_watch] 
(0x2000): 0xac5610/0xac4650
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sbus_remove_watch] 
(0x2000): 0xac5610/0xac4600
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): 
dbus conn: 0xac5090
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sbus_dispatch] (0x0080): 
Connection is not open for dispatching.
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [be_client_destructor] 
(0x0400): Removed PAM client
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] 
[sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to 
[ldaps://ad-sj.ad.example.com:636/??base] with fd [18].
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sdap_get_rootdse_send] 
(0x4000): Getting rootdse
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x0400): calling ldap_search_ext with [(objectclass=*)][].
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [*]
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [altServer]
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [namingContexts]
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [supportedControl]
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [supportedExtension]
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [supportedFeatures]
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [supportedLDAPVersion]
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [supportedSASLMechanisms]
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [domainControllerFunctionality]
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [defaultNamingContext]
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [lastUSN]
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [highestCommittedUSN]
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x2000): ldap_search_ext called, msgid = 1
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sdap_id_op_destroy] 
(0x4000): releasing operation connection
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [be_ptask_destructor] 
(0x0400): Terminating periodic task [Cleanup of LDAP]
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sdap_handle_release] 
(0x2000): Trace: sh[0xad5450], connected[1], ops[(nil)], ldap[0xac5780], 
destructor_lock[0], release_memory[0]
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [remove_connection_callback] 
(0x4000): Successfully removed connection callback.
(Tue Apr 21 05:46:27 2015) [sssd[be[LDAP]]] [sbus_remove_watch] 
(0x2000): 0xab6360/0xa9da20

***This appears to be preventing additional ldap search requests to 
Active Directory for user information to be running as the logs 
basically stop.
***Unclear of what 'sbus_dispatch' is using to request information and 
if the requests are getting to the Active Directory server and/or the 
requests back from the Active Directory server are blocked or something 
else???

***Are there any ports or network info that sbus_dispatch is using that 
may be blocked or something with issues across sub-domains???

The AD-sj(primary) and AD-va(secondary) are in their own sub-domain(ad) 
and replicate each other.


Next, I pointed sssd.conf file from the above sub-domain(sj) to another 
OpenLDAP server in a different sub domain(va) along with a different 
Active Directory server in the same sub domain(va) and seeing this in 
the logs which appears to be correct and not seeing the error message 
"Connection is not open for dispatching" but instead below seeing 
"Dispatching" which is allowing ldap search requests to be running 
against Active Directory.

sssd.conf(sj) => slapd.conf(sj) => AD-va


test 1 - sssd.sj point to ldap.va and ad-va   (pointing sssd in the sj 
sub-domain to the va sub-domain)
==============================================================
(Tue Apr 21 06:31:44 2015) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): 
dbus conn: 0x873c70
(Tue Apr 21 06:31:44 2015) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): 
dbus conn: 0x877680
(Tue Apr 21 06:31:44 2015) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): 
Dispatching.
(Tue Apr 21 06:31:44 2015) [sssd[be[LDAP]]] [sbus_message_handler] 
(0x4000): Received SBUS method [RegisterService]
(Tue Apr 21 06:31:44 2015) [sssd[be[LDAP]]] [sbus_get_sender_id_send] 
(0x2000): Not a sysbus message, quit
(Tue Apr 21 06:31:44 2015) [sssd[be[LDAP]]] [sbus_handler_got_caller_id] 
(0x4000): Received SBUS method [RegisterService]
(Tue Apr 21 06:31:44 2015) [sssd[be[LDAP]]] [client_registration] 
(0x0100): Cancel DP ID timeout [0x877fa0]
(Tue Apr 21 06:31:44 2015) [sssd[be[LDAP]]] [client_registration] 
(0x0100): Added Frontend client [SUDO]
(Tue Apr 21 06:31:44 2015) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): 
dbus conn: 0x877680
(Tue Apr 21 06:31:44 2015) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): 
Dispatching.
(Tue Apr 21 06:31:44 2015) [sssd[be[LDAP]]] [sbus_message_handler] 
(0x4000): Received SBUS method [getDomains]
(Tue Apr 21 06:31:44 2015) [sssd[be[LDAP]]] [sbus_get_sender_id_send] 
(0x2000): Not a sysbus message, quit
(Tue Apr 21 06:31:44 2015) [sssd[be[LDAP]]] [sbus_handler_got_caller_id] 
(0x4000): Received SBUS method [getDomains]
(Tue Apr 21 06:31:44 2015) [sssd[be[LDAP]]] [be_get_subdomains] 
(0x2000): Undefined backend target.
(Tue Apr 21 06:31:44 2015) [sssd[be[LDAP]]] [sbus_dispatch] (0x4000): 
dbus conn: 0x877680
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] 
[sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to 
[ldaps://ad-va.ad.example.com:636/??base] with fd [16].
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_get_rootdse_send] 
(0x4000): Getting rootdse
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x0400): calling ldap_search_ext with [(objectclass=*)][].
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [*]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [altServer]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [namingContexts]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [supportedControl]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [supportedExtension]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [supportedFeatures]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [supportedLDAPVersion]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [supportedSASLMechanisms]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [domainControllerFunctionality]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [defaultNamingContext]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [lastUSN]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x1000): Requesting attrs: [highestCommittedUSN]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_step] 
(0x2000): ldap_search_ext called, msgid = 1
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_process_result] 
(0x2000): Trace: sh[0x86ef80], connected[1], ops[0x92ee20], 
ldap[0x8722d0]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_process_message] 
(0x4000): Message type: [LDAP_RES_SEARCH_ENTRY]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_entry] (0x4000): 
OriginalDN: [].
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [currentTime]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [subschemaSubentry]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [dsServiceName]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [namingContexts]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [defaultNamingContext]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [schemaNamingContext]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [configurationNamingContext]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [rootDomainNamingContext]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [supportedControl]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [supportedLDAPVersion]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [supportedLDAPPolicies]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [highestCommittedUSN]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [supportedSASLMechanisms]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [dnsHostName]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [ldapServiceName]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [serverName]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [supportedCapabilities]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [isSynchronized]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [isGlobalCatalogReady]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [supportedExtension]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [domainFunctionality]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [forestFunctionality]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_parse_range] (0x2000): 
No sub-attributes for [domainControllerFunctionality]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_process_result] 
(0x2000): Trace: sh[0x86ef80], connected[1], ops[0x92ee20], 
ldap[0x8722d0]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_process_message] 
(0x4000): Message type: [LDAP_RES_SEARCH_RESULT]
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_get_generic_ext_done] 
(0x0400): Search result: Success(0), no errmsg set
(Tue Apr 21 06:31:45 2015) [sssd[be[LDAP]]] [sdap_get_rootdse_done] 
(0x2000): Got rootdse



-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.fedorahosted.org/pipermail/sssd-users/attachments/20150421/ea84337b/attachment-0001.html>


More information about the sssd-users mailing list