[Pkg-sssd-devel] Bug#855136: Scheduled events (e.g. LDAP connection retries) are affected by clock adjustments

[Victor Tapia]

Package: sssd
Version: 1.15.0-3

Problem description:

When SSSD fails to connect to a provider (LDAP, for instance) it creates
a timed event with tevent_add_timer() in order to retry in ~1 min.
Tevent relies on CLOCK_REALTIME, using absolute epoch time, so when the
time changes (e.g. NTP sync) the scheduled event is affected.


Reproducer:

1. Modify the /etc/hosts file to force a failed resolution and restart sssd

(Tue Oct 25 09:37:14 2016) [sssd[be[openstacklocal]]]
[resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of
'ldap' in DNS
(Tue Oct 25 09:37:14 2016) [sssd[be[openstacklocal]]]
[resolv_gethostbyname_done] (0x0040): querying hosts database failed
[5]: Input/output error
(Tue Oct 25 09:37:14 2016) [sssd[be[openstacklocal]]]
[fo_resolve_service_done] (0x0020): Failed to resolve server 'ldap':
Could not contact DNS servers
...
(Tue Oct 25 09:37:14 2016) [sssd[be[openstacklocal]]]
[check_online_callback] (0x0100): Backend returned: (1, 0, <NULL>)
[Provider is Offline]

2. Within the ~1 minute window, change the date (date --set) to a
previous time (2 hour in my example). Note: if /etc/resolv.conf or a
network interface is modified, SSSD providers will restart, but the
scheduled retry will be kept.

(Tue Oct 25 07:41:46 2016) [sssd[be[openstacklocal]]]
[recreate_ares_channel] (0x0100): Initializing new c-ares channel
(Tue Oct 25 07:41:46 2016) [sssd[be[openstacklocal]]]
[recreate_ares_channel] (0x0100): Destroying the old c-ares channel
(Tue Oct 25 07:41:46 2016) [sssd[be[openstacklocal]]]
[set_server_common_status] (0x0100): Marking server 'ldap' as 'name not
resolved'
(Tue Oct 25 07:41:46 2016) [sssd[be[openstacklocal]]]
[fo_set_port_status] (0x0100): Marking port 389 of server 'ldap' as
'neutral'
(Tue Oct 25 07:41:46 2016) [sssd[be[openstacklocal]]]
[fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP'
...
(Tue Oct 25 07:41:46 2016) [sssd[be[openstacklocal]]]
[fo_resolve_service_done] (0x0020): Failed to resolve server 'ldap':
Could not contact DNS servers
(Tue Oct 25 07:41:46 2016) [sssd[be[openstacklocal]]]
[set_server_common_status] (0x0100): Marking server 'ldap' as 'not working'
...
(Tue Oct 25 07:41:46 2016) [sssd[be[openstacklocal]]]
[check_online_callback] (0x0100): Backend returned: (1, 0, <NULL>)
[Provider is Offline]

3. Once it gets to the programmed date (2 hours later), it retries:

(Tue Oct 25 09:38:25 2016) [sssd[be[openstacklocal]]]
[set_server_common_status] (0x0100): Marking server 'ldap' as 'name not
resolved'
(Tue Oct 25 09:38:25 2016) [sssd[be[openstacklocal]]]
[fo_set_port_status] (0x0100): Marking port 389 of server 'ldap' as
'neutral'
(Tue Oct 25 09:38:25 2016) [sssd[be[openstacklocal]]]
[fo_resolve_service_send] (0x0100): Trying to resolve service 'LDAP'
...
(Tue Oct 25 09:38:25 2016) [sssd[be[openstacklocal]]]
[fo_resolve_service_done] (0x0020): Failed to resolve server 'ldap':
Could not contact DNS servers
(Tue Oct 25 09:38:25 2016) [sssd[be[openstacklocal]]]
[set_server_common_status] (0x0100): Marking server 'ldap' as 'not working'
...
(Tue Oct 25 09:38:25 2016) [sssd[be[openstacklocal]]]
[check_online_callback] (0x0100): Backend returned: (1, 0, <NULL>)
[Provider is Offline]



Thanks,

Victor