[SSSD-users] timeout and offline mode behaviour

Joschi Brauchle joschi.brauchle at tum.de
Wed Jun 4 07:41:28 UTC 2014


On 06/03/2014 08:25 AM, Joschi Brauchle wrote:
> On 06/02/2014 05:39 PM, Simo Sorce wrote:
>> On Mon, 2014-06-02 at 10:34 +0200, Joschi Brauchle wrote:
>>> These are some of the details:
>>> 1) The LDAP server has a local 192.168.x.x IP, which is resolvable
>>> globally.
>>
>> IPs in the 129.168 are not resolvable globally, they are private
>> addresses and routing is not allowed outside private networks.
>
> What I meant is that the DNS hostname of the LDAP server
> 'gemini.lnt.ei.tum.de' is globally resolvable to its private
> '192.168.109.3' IP address. Unfortunately, this DNS setup cannot be
> changed..
>
> So I finally have a "debug_level = 9" log output from a lockup:
> ----------------------------
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]] [sbus_message_handler]
> (0x4000): Received SBUS method [getAccountInfo]
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]] [be_get_account_info]
> (0x0100): Got request for [4097][1][idnumber=10011]
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]] [be_get_account_info]
> (0x0100): Request processed. Returned 1,11,Fast reply - offline
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]] [sdap_id_op_connect_step]
> (0x4000): beginning to connect
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]] [fo_resolve_service_send]
> (0x0100): Trying to resolve service 'LDAP'
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]] [get_server_status]
> (0x1000): Status of server 'gemini.lnt.ei.tum.de' is 'name resolved'
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]] [get_port_status]
> (0x1000): Port status of port 636 for server 'gemini.lnt.ei.tum.de' is
> 'not working'
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]] [get_port_status]
> (0x0100): Reseting the status of port 636 for server 'gemini.lnt.ei.tum.de'
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]]
> [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to
> 10 seconds
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]] [get_server_status]
> (0x1000): Status of server 'gemini.lnt.ei.tum.de' is 'name resolved'
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]]
> [be_resolve_server_process] (0x1000): Saving the first resolved server
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]]
> [be_resolve_server_process] (0x0200): Found address for server
> gemini.lnt.ei.tum.de: [192.168.109.3] TTL 7200
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]] [sss_ldap_init_send]
> (0x4000): Using file descriptor [21] for LDAP connection.
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]] [sss_ldap_init_send]
> (0x0400): Setting 6 seconds timeout for connecting
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]] [sbus_dispatch] (0x4000):
> dbus conn: 18E8420
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]] [sbus_dispatch] (0x4000):
> Dispatching.
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]] [sbus_message_handler]
> (0x4000): Received SBUS method [getAccountInfo]
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]] [be_get_account_info]
> (0x0100): Got request for [4097][1][name=brauchle]
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]] [sdap_id_op_connect_step]
> (0x4000): waiting for connection to complete
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]] [sbus_dispatch] (0x4000):
> dbus conn: 18E8420
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]] [sbus_dispatch] (0x4000):
> Dispatching.
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]] [sbus_message_handler]
> (0x4000): Received SBUS method [getAccountInfo]
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]] [be_get_account_info]
> (0x0100): Got request for [4097][1][idnumber=10011]
> (Tue Jun  3 08:16:42 2014) [sssd[be[default]]] [sdap_id_op_connect_step]
> (0x4000): waiting for connection to complete
> (Tue Jun  3 08:16:47 2014) [sssd[be[default]]] [sbus_dispatch] (0x4000):
> dbus conn: 18BFD50
> (Tue Jun  3 08:16:47 2014) [sssd[be[default]]] [sbus_dispatch] (0x4000):
> Dispatching.
> (Tue Jun  3 08:16:47 2014) [sssd[be[default]]] [sbus_message_handler]
> (0x4000): Received SBUS method [ping]
> (Tue Jun  3 08:16:48 2014) [sssd[be[default]]]
> [sdap_async_sys_connect_timeout] (0x0100): The LDAP connection timed out
> (Tue Jun  3 08:16:48 2014) [sssd[be[default]]]
> [sss_ldap_init_sys_connect_done] (0x0020): sdap_async_sys_connect
> request failed.
> (Tue Jun  3 08:16:48 2014) [sssd[be[default]]] [sdap_sys_connect_done]
> (0x0020): sdap_async_connect_call request failed.
> (Tue Jun  3 08:16:48 2014) [sssd[be[default]]] [sdap_handle_release]
> (0x2000): Trace: sh[0x191fdb0], connected[0], ops[(nil)], ldap[(nil)],
> destructor_lock[0], release_memory[0]
> (Tue Jun  3 08:16:48 2014) [sssd[be[default]]] [fo_set_port_status]
> (0x0100): Marking port 636 of server 'gemini.lnt.ei.tum.de' as 'not
> working'
> (Tue Jun  3 08:16:48 2014) [sssd[be[default]]] [fo_resolve_service_send]
> (0x0100): Trying to resolve service 'LDAP'
> (Tue Jun  3 08:16:48 2014) [sssd[be[default]]] [get_server_status]
> (0x1000): Status of server 'gemini.lnt.ei.tum.de' is 'name resolved'
> (Tue Jun  3 08:16:48 2014) [sssd[be[default]]] [get_port_status]
> (0x1000): Port status of port 636 for server 'gemini.lnt.ei.tum.de' is
> 'not working'
> (Tue Jun  3 08:16:48 2014) [sssd[be[default]]] [fo_resolve_service_send]
> (0x0020): No available servers for service 'LDAP'
> (Tue Jun  3 08:16:48 2014) [sssd[be[default]]] [be_resolve_server_done]
> (0x1000): Server resolution failed: 5
> (Tue Jun  3 08:16:48 2014) [sssd[be[default]]] [sdap_id_op_connect_done]
> (0x0020): Failed to connect, going offline (5 [Input/output error])
> (Tue Jun  3 08:16:48 2014) [sssd[be[default]]] [be_mark_offline]
> (0x2000): Going offline!
> (Tue Jun  3 08:16:48 2014) [sssd[be[default]]] [be_run_offline_cb]
> (0x0080): Going offline. Running callbacks.
> (Tue Jun  3 08:16:48 2014) [sssd[be[default]]] [sdap_id_op_connect_done]
> (0x4000): notify offline to op #1
> (Tue Jun  3 08:16:48 2014) [sssd[be[default]]] [sdap_id_op_connect_done]
> (0x4000): notify offline to op #2
> (Tue Jun  3 08:16:48 2014) [sssd[be[default]]] [acctinfo_callback]
> (0x0100): Request processed. Returned 1,11,Offline
> (Tue Jun  3 08:16:48 2014) [sssd[be[default]]] [sdap_id_op_connect_done]
> (0x4000): notify offline to op #3
> (Tue Jun  3 08:16:48 2014) [sssd[be[default]]] [acctinfo_callback]
> (0x0100): Request processed. Returned 1,11,Offline
> (Tue Jun  3 08:16:48 2014) [sssd[be[default]]]
> [sdap_id_release_conn_data] (0x4000): releasing unused connection
> ----------------------------
>
> As the logs are showing, the system was completely unresponsive for
> about 5 seconds form 08:16:42 to 08:16:47 when the LDAP connection timed
> out.
>
> I am currently NOT connected to my home '192.168.109.0/24' network, but
> this is my current network config:
> ----------------------------
> # ifconfig
> wlan0     Link encap:Ethernet  HWaddr ...
>            inet addr:192.168.1.11  Bcast:192.168.1.255  Mask:255.255.255.0
> # route
> Kernel IP routing table
> Destination     Gateway         Genmask         Flags Metric Ref    Use
> Iface
> default         SL2141I.home    0.0.0.0         UG    0      0        0
> wlan0
> 192.168.1.0     *               255.255.255.0   U     9      0        0
> wlan0
> ----------------------------
>
> Pinging the LDAP server 'gemini.lnt.ei.tum.de' results in:
> ----------------------------
> # ping gemini.lnt.ei.tum.de
> PING gemini.lnt.ei.tum.de (192.168.109.3) 56(84) bytes of data.
>  From 62.53.2.254 icmp_seq=1 Destination Net Unreachable
> ----------------------------
>
> So why does the LDAP connection not terminate immediately with the same
> 'destination net unreachable' status but time out instead?

Could anyone comment if this is correct behavior or a bug?

It seems strange to me that the IP stack immediately says the LDAP 
server is unreachable whereas SSSD/openLDAP times out while trying to 
reach it...

Is this possibly the same problem as discussed in the earlier part of 
this thread with openLDAP?

-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/pkcs7-signature
Size: 4739 bytes
Desc: S/MIME Cryptographic Signature
URL: <https://lists.fedorahosted.org/pipermail/sssd-users/attachments/20140604/92958280/attachment-0001.p7s>


More information about the sssd-users mailing list