Fields changed

description: This issue is reproducible with sssd-1.14.1-3.fc24.x86_64 and a plain install of Active Directory DNS.

When Dynamic DNS is successful, the logs are somewhat misleading about success as it appears nsupdate gets called multiple times and fails after the first time. debug_level 5 logging shows the following messages

{{{
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [be_nsupdate_timer_schedule] (0x0200): Timer already scheduled
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [check_ipv6_addr] (0x0200): Link local IPv6 address fe80::e85d:dc8d:ff8e:efcb
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'sssd-f24.ad.jstephen' in DNS
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve AAAA record of 'sssd-f24.ad.jstephen' in DNS
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [resolv_gethostbyname_next] (0x0100): No more hosts databases to retry
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [nsupdate_msg_create_common] (0x0200): Creating update message for realm [(null)].
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [be_nsupdate_args] (0x0200): nsupdate auth type: GSS-TSIG
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [child_sig_handler] (0x0100): child [23928] finished successfully.
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [be_nsupdate_done] (0x0200): nsupdate child status: 0

(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [nsupdate_msg_create_common] (0x0200): Creating update message for realm [(null)].
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [be_nsupdate_args] (0x0200): nsupdate auth type: GSS-TSIG
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [child_sig_handler] (0x0020): child [23932] failed with status [2].
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [nsupdate_child_handler] (0x0040): Dynamic DNS child failed with status [512]
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [be_nsupdate_done] (0x0040): nsupdate child execution failed [1432158238]: Dynamic DNS update failed

(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [sdap_dyndns_update_ptr_done] (0x0080): nsupdate failed, retrying
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [nsupdate_msg_create_common] (0x0200): Creating update message for realm [AD.JSTEPHEN].
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [be_nsupdate_args] (0x0200): nsupdate auth type: GSS-TSIG
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [child_sig_handler] (0x0020): child [23936] failed with status [2].
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [nsupdate_child_handler] (0x0040): Dynamic DNS child failed with status [512]
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [be_nsupdate_done] (0x0040): nsupdate child execution failed [1432158238]: Dynamic DNS update failed
}}}

It only shows failure if someone does a grep for 'Dynamic' in the domain log

It would be nice if we can make the success messages more obvious, or determine why nsupdate fails in subsequent calls. => This issue is reproducible with sssd-1.14.1-3.fc24.x86_64 and a plain install of Active Directory DNS on Windows Server 2012

When Dynamic DNS is successful, the logs are somewhat misleading about success as it appears nsupdate gets called multiple times and fails after the first time. debug_level 5 logging shows the following messages

{{{
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [be_nsupdate_timer_schedule] (0x0200): Timer already scheduled
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [check_ipv6_addr] (0x0200): Link local IPv6 address fe80::e85d:dc8d:ff8e:efcb
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve A record of 'sssd-f24.ad.jstephen' in DNS
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [resolv_gethostbyname_dns_query] (0x0100): Trying to resolve AAAA record of 'sssd-f24.ad.jstephen' in DNS
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [resolv_gethostbyname_next] (0x0200): No more address families to retry
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [resolv_gethostbyname_next] (0x0100): No more hosts databases to retry
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [nsupdate_msg_create_common] (0x0200): Creating update message for realm [(null)].
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [be_nsupdate_args] (0x0200): nsupdate auth type: GSS-TSIG
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [child_sig_handler] (0x0100): child [23928] finished successfully.
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [be_nsupdate_done] (0x0200): nsupdate child status: 0

(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [nsupdate_msg_create_common] (0x0200): Creating update message for realm [(null)].
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [be_nsupdate_args] (0x0200): nsupdate auth type: GSS-TSIG
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [child_sig_handler] (0x0020): child [23932] failed with status [2].
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [nsupdate_child_handler] (0x0040): Dynamic DNS child failed with status [512]
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [be_nsupdate_done] (0x0040): nsupdate child execution failed [1432158238]: Dynamic DNS update failed

(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [sdap_dyndns_update_ptr_done] (0x0080): nsupdate failed, retrying
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [nsupdate_msg_create_common] (0x0200): Creating update message for realm [AD.JSTEPHEN].
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [be_nsupdate_args] (0x0200): nsupdate auth type: GSS-TSIG
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [child_sig_handler] (0x0020): child [23936] failed with status [2].
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [nsupdate_child_handler] (0x0040): Dynamic DNS child failed with status [512]
(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [be_nsupdate_done] (0x0040): nsupdate child execution failed [1432158238]: Dynamic DNS update failed
}}}

It only shows failure if someone does a grep for 'Dynamic' in the domain log

It would be nice if we can make the success messages more obvious, or determine why nsupdate fails in subsequent calls.

Hmm, but in this case the DNS update did not succeed even after the reply, right?

One bug I see here is that we print a NULL string:

(Fri Oct 14 16:02:57 2016) [sssd[be[AD.JSTEPHEN]]] [nsupdate_msg_create_common] (0x0200): Creating update message for realm [(null)].

I think we should explicitly say this update uses autodetected (by nsupdate) realm instead of NULL. But do you think we can improve the messages even further? We're open to patches of course, so I'm moving the ticket to the "Patches welcome" milestone.

milestone: NEEDS_TRIAGE => SSSD Patches welcome

Fields changed

rhbz: => 0

• master: d694d4f

milestone: SSSD Patches welcome => SSSD 1.15.1
resolution: => fixed
status: new => closed

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/4253

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.