[Samba] Problems with bind9_dlz when rndc is reloaded

Thu Jan 12 13:45:06 UTC 2017

Using your log parameters, the shutting down message is not showed, but when I reload rndc a get the same effect. Everything is working fine until bond9_dlz needs to reload (and no restart) rndc. When this happens, I need to restart bind and everything works fine again.

I'm starting named with named -d 3 -u named and using /var/log/messages.

See log using your parameters:

# rndc reload
12-Jan-2017 11:34:35.313 general: received control channel command 'null'
12-Jan-2017 11:34:35.313 general: received control channel command 'reload'
12-Jan-2017 11:34:35.313 general: loading configuration from '/etc/named.conf'
12-Jan-2017 11:34:35.313 general: reading built-in trusted keys from file '/etc/named.iscdlv.key'
12-Jan-2017 11:34:35.313 general: initializing GeoIP Country (IPv4) (type 1) DB
12-Jan-2017 11:34:35.313 general: GEO-106FREE 20160607 Build 1 Copyright (c) 2016 MaxMind
12-Jan-2017 11:34:35.313 general: initializing GeoIP Country (IPv6) (type 12) DB
12-Jan-2017 11:34:35.313 general: GEO-106FREE 20160607 Build 1 Copy
12-Jan-2017 11:34:35.313 general: GeoIP City (IPv4) (type 2) DB not available
12-Jan-2017 11:34:35.313 general: GeoIP City (IPv4) (type 6) DB not available
12-Jan-2017 11:34:35.313 general: GeoIP City (IPv6) (type 30) DB not available
12-Jan-2017 11:34:35.313 general: GeoIP City (IPv6) (type 31) DB not available
12-Jan-2017 11:34:35.314 general: GeoIP Region (type 3) DB not available
12-Jan-2017 11:34:35.314 general: GeoIP Region (type 7) DB not available
12-Jan-2017 11:34:35.314 general: GeoIP ISP (type 4) DB not available
12-Jan-2017 11:34:35.314 general: GeoIP Org (type 5) DB not available
12-Jan-2017 11:34:35.314 general: GeoIP AS (type 9) DB not available
12-Jan-2017 11:34:35.314 general: GeoIP Domain (type 11) DB not available
12-Jan-2017 11:34:35.314 general: GeoIP NetSpeed (type 10) DB not available
12-Jan-2017 11:34:35.314 general: using default UDP/IPv4 port range: [1024, 65535]
12-Jan-2017 11:34:35.314 general: using default UDP/IPv6 port range: [1024, 65535]
12-Jan-2017 11:34:35.314 network: no IPv6 interfaces found
12-Jan-2017 11:34:35.315 general: sizing zone task pool based on 6 zones
12-Jan-2017 11:34:35.315 database: decrement_reference: delete from rbt: 0x7f8bb0f10380 .
12-Jan-2017 11:34:35.315 database: Loading 'AD DNS Zone' using driver dlopen
12-Jan-2017 11:34:35.315 database: samba_dlz: starting configure
12-Jan-2017 11:34:35.316 database: samba_dlz: Ignoring duplicate zone 'lovato.intranet' from 'DC=@,DC=lovato.intranet,CN=MicrosoftDNS,DC=DomainDnsZones,DC=lovato,DC=intranet'
12-Jan-2017 11:34:35.316 database: samba_dlz: Ignoring duplicate zone '_msdcs.lovato.intranet' from 'DC=@,DC=_msdcs.lovato.intranet,CN=MicrosoftDNS,DC=ForestDnsZones,DC=lovato,DC=intranet'
12-Jan-2017 11:34:35.317 security: using built-in DLV key for view _default
12-Jan-2017 11:34:35.317 general: managed-keys-zone: synchronizing trusted keys
12-Jan-2017 11:34:35.317 general: set_refreshkeytimer: managed-keys-zone : enter
12-Jan-2017 11:34:35.317 general: managed-keys-zone: next key refresh: 12-Jan-2017 12:12:03.711
12-Jan-2017 11:34:35.317 general: zone_settimer: managed-keys-zone : enter
12-Jan-2017 11:34:35.317 general: set_refreshkeytimer: managed-keys-zone : enter
12-Jan-2017 11:34:35.317 general: managed-keys-zone: next key refresh: 12-Jan-2017 12:12:03.317
12-Jan-2017 11:34:35.317 general: zone_settimer: managed-keys-zone : enter
12-Jan-2017 11:34:35.317 general: automatic empty zone: 10.IN-ADDR.ARPA

This is the destroy function used by bind9_dlz:

_PUBLIC_ void dlz_destroy(void *dbdata)
{
        struct dlz_bind9_data *state = talloc_get_type_abort(dbdata, struct dlz_bind9_data);
        state->log(ISC_LOG_INFO, "samba_dlz: shutting down");

        dlz_bind9_state_ref_count--;
        if (dlz_bind9_state_ref_count == 0) {
                talloc_unlink(state, state->samdb);
                talloc_free(state);
                dlz_bind9_state = NULL;
}

}

I found in others points of source code rndc reload command.

Maybe I need to compile or use some parameters in my bind or samba config to not destroy bind_dlz...

Regards,

________________________________
De: mathias dufresne <infractory at gmail.com>
Enviado: quinta-feira, 12 de janeiro de 2017 10:35:27
Para: Roger Lovato
Cc: samba at lists.samba.org
Assunto: Re: [Samba] Problems with bind9_dlz when rndc is reloaded

I've added logs (dirty and quickly):
logging {
  channel "request" {
    file "/var/named/named.run" size 10m;
    print-time yes;
    print-category yes;
    severity debug;
  };
  category default { request; };
  category security { request; };
};

Reload DNS service using systemctl once, twice, then restart Bind, reload it using rndc and no complain about log file and DNS service on that machine is still up and running well.

How have you configured your logs?
How are set the rights on your log files, especially the one named "named.run"?

Why only one DC? Computers are expensive in some way but virtual machine are not and Samba run very well into VMs. Qemu/KVM grants you the possibility to transform some running Linux box into a hypervisor very easily...

Regarding logs in your last mail it seems the samba tool "samba_dnsupdate" is ran also when samba is shutting down (or you didn't told me exactly what you did ;)
This "samba_dnsupdate" is a very helpful tool given by Samba Team to automagically add and remove DNS records related to a DC.

I think this tool is clever enough to check what it has to do before doing things. So if some DNS update requests are launched during Samba is stopping, some DNS records should be missing. If they weren't missing I expect that tool won't try to push updates.

Could you try to launch "samba_dnsupdate" when your Samba and your Bind are both running well and tell us what happened?

2017-01-12 12:46 GMT+01:00 Roger Lovato <rogerlovato at outlook.com<mailto:rogerlovato at outlook.com>>:

Mathias,

Thanks for your reply.

Please, try to start your bind with some debug level and run commando "rndc reload" and see the end of the log. I saw samba source code and found the destroy dns function in dlz_bind9.c and called by turture blz_bind9.c.

When dlz_bind9.c is shutting down, I get this error when I try to update dns.

update failed: NOTAUTH Failed nsupdate: 2 update(nsupdate): SRV _ldap._tcp.ForestDnsZones.intranet.dominio movd-gcp-003.intranet.dominio 389 Calling nsupdate for SRV _ldap._tcp.ForestDnsZones.intranet.dominio movd-gcp-003.intranet.dominio 389 (add) Outgoing update query: ;; ->>HEADER<<- opcode: UPDATE, status: NOERROR, id: 0 ;; flags:; ZONE: 0, PREREQ: 0, UPDATE: 0, ADDITIONAL: 0 ;; UPDATE SECTION: _ldap._tcp.ForestDnsZones.intranet.dominio. 900 IN SRV 0 100 389 movd-gcp-003.intranet.dominio.

Many other people also told me this does not happen until they test or put a second DC server on the network and find out the problem.

tks

________________________________
De: mathias dufresne <infractory at gmail.com<mailto:infractory at gmail.com>>
Enviado: quinta-feira, 12 de janeiro de 2017 08:58:27
Para: Roger Lovato
Cc: samba at lists.samba.org<mailto:samba at lists.samba.org>
Assunto: Re: [Samba] Problems with bind9_dlz when rndc is reloaded

Hi Roger,

I'm using Samba as AD DC in version 4.5.0 on Centos 7 with Bind9_DLZ DNS backend, Bind is 9.9.4 and I don't have that issue.
I tried reload my bind using systemctl at first and no issue, then I tried "rdnc reload" to be sure rndc was used, still no issue.

By no issue I don't mean log are clean, I mean the DNS service is working well (tested using dig commands).

In my logs I have the very same complaints about "duplicate zone" which are ignored.
In my logs I don't have complaints about permissions on named.run. Perhaps you should have a look on that.

Cheers,

mathias

2017-01-10 23:39 GMT+01:00 Roger Lovato via samba <samba at lists.samba.org<mailto:samba at lists.samba.org>>:
Hi guys,

I'm facing a problems with samba4 + bind9_dlz that consuming my time for several days.

Everything is working fine until samba4 need to update dns when I'm work with more than one DC server. When samba (or bind) need to reload all zones, the module bind9_dlz is shutting down and then all my environment stops and I need to restart the bind to up again.

See my log:

...

Jan 10 22:32:41 movd-gcp-002 named[9728]: Loading 'lovato.intranet' using driver dlopen
Jan 10 22:32:41 movd-gcp-002 named[9728]: samba_dlz: starting configure
Jan 10 22:32:41 movd-gcp-002 named[9728]: samba_dlz: Ignoring duplicate zone 'lovato.intranet' from 'DC=@,DC=lovato.intranet,CN=MicrosoftDNS,DC=DomainDnsZones,DC=lovato,DC=intranet'
Jan 10 22:32:41 movd-gcp-002 named[9728]: samba_dlz: Ignoring duplicate zone '_msdcs.lovato.intranet' from 'DC=@,DC=_msdcs.lovato.intranet,CN=MicrosoftDNS,DC=ForestDnsZones,DC=lovato,DC=intranet'
Jan 10 22:32:41 movd-gcp-002 named[9728]: isc_log_open 'named.run' failed: permission denied
Jan 10 22:32:41 movd-gcp-002 named[9728]: zone lovato.intranet/NONE: (other) removed
Jan 10 22:32:41 movd-gcp-002 named[9728]: zone _msdcs.lovato.intranet/NONE: (other) removed
Jan 10 22:32:41 movd-gcp-002 named[9728]: reloading configuration succeeded
Jan 10 22:32:41 movd-gcp-002 named[9728]: reloading zones succeeded
Jan 10 22:32:41 movd-gcp-002 named[9728]: samba_dlz: shutting down
Jan 10 22:32:41 movd-gcp-002 named[9728]: all zones loaded
Jan 10 22:32:41 movd-gcp-002 named[9728]: running
server reload successful

Bind standing up, but all dynamic zones stops and samba cannot update dns names anymore.

This is curious is because this happens only when rndc is reloaded. I think that happens because the SAMBA dynamic zones are not cleaned and that causes shutting down.

Jan 10 22:32:41 movd-gcp-002 named[9728]: samba_dlz: Ignoring duplicate zone '_msdcs.lovato.intranet' from 'DC=@,DC=_msdcs.lovato.intranet,CN=MicrosoftDNS,DC=ForestDnsZones,DC=lovato,DC=intranet'

If I restart bind, I think all zones, including dynamic zones, are cleaned and bind starts normally.

See log:

...

Jan 10 22:38:10 movd-gcp-002 named[10014]: Loading 'lovato.intranet' using driver dlopen
Jan 10 22:38:10 movd-gcp-002 named[10014]: samba_dlz: GENSEC backend 'gssapi_spnego' registered
Jan 10 22:38:10 movd-gcp-002 named[10014]: samba_dlz: GENSEC backend 'gssapi_krb5' registered
Jan 10 22:38:10 movd-gcp-002 named[10014]: samba_dlz: GENSEC backend 'gssapi_krb5_sasl' registered
Jan 10 22:38:10 movd-gcp-002 named[10014]: samba_dlz: GENSEC backend 'spnego' registered
Jan 10 22:38:10 movd-gcp-002 named[10014]: samba_dlz: GENSEC backend 'schannel' registered
Jan 10 22:38:10 movd-gcp-002 named[10014]: samba_dlz: GENSEC backend 'naclrpc_as_system' registered
Jan 10 22:38:10 movd-gcp-002 named[10014]: samba_dlz: GENSEC backend 'sasl-EXTERNAL' registered
Jan 10 22:38:10 movd-gcp-002 named[10014]: samba_dlz: GENSEC backend 'ntlmssp' registered
Jan 10 22:38:10 movd-gcp-002 named[10014]: samba_dlz: GENSEC backend 'ntlmssp_resume_ccache' registered
Jan 10 22:38:10 movd-gcp-002 named[10014]: samba_dlz: GENSEC backend 'http_basic' registered
Jan 10 22:38:10 movd-gcp-002 named[10014]: samba_dlz: GENSEC backend 'http_ntlm' registered
Jan 10 22:38:10 movd-gcp-002 named[10014]: samba_dlz: GENSEC backend 'krb5' registered
Jan 10 22:38:10 movd-gcp-002 named[10014]: samba_dlz: GENSEC backend 'fake_gssapi_krb5' registered
Jan 10 22:38:11 movd-gcp-002 named[10014]: samba_dlz: started for DN DC=lovato,DC=intranet
Jan 10 22:38:11 movd-gcp-002 named[10014]: samba_dlz: starting configure
Jan 10 22:38:11 movd-gcp-002 named[10014]: samba_dlz: configured writeable zone 'lovato.intranet'
Jan 10 22:38:11 movd-gcp-002 named[10014]: samba_dlz: configured writeable zone '_msdcs.lovato.intranet'
Jan 10 22:38:11 movd-gcp-002 named[10014]: set up managed keys zone for view _default, file '/var/named/dynamic/managed-keys.bind'
Jan 10 22:38:11 movd-gcp-002 named[10014]: command channel listening on 127.0.0.1#953
Jan 10 22:38:11 movd-gcp-002 named[10014]: command channel listening on ::1#953
Jan 10 22:38:11 movd-gcp-002 named[10014]: isc_log_open 'named.run' failed: permission denied
Jan 10 22:38:11 movd-gcp-002 named[10014]: managed-keys-zone: loaded serial 3
Jan 10 22:38:11 movd-gcp-002 named[10014]: zone 0.0.127.in-addr.arpa/IN: loaded serial 2013050101
Jan 10 22:38:11 movd-gcp-002 named[10014]: zone localhost/IN: loaded serial 2013050101<tel:(201)%20305-0101>
Jan 10 22:38:11 movd-gcp-002 named[10014]: all zones loaded
Jan 10 22:38:11 movd-gcp-002 named[10014]: running

I've seen many other people with the same problem, but nobody posted any solution.

Can someone help me?

Regards.
--
To unsubscribe from this list go to the following URL and read the
instructions:  https://lists.samba.org/mailman/options/samba