[Samba] Samba4 + Bind-9.9.5: client update domain/IN denied for some hosts

[Rowland Penny]

On 15/09/15 18:52, David Raison wrote:
> Good day,
>
> We're running a AD/DC setup using samba 4.1.17+dfsg-2, bind 9.9.5-9 and
> samba_dlz
> The clients are Windows7 SP1 Entreprise machines.
> We have roaming profiles set up and working.
>
> Starting around last Tuesday, one of the clients wouldn't allow users to
> log in with accounts that work fine on other clients.
>
> Now, there's not much to see in the logs. The smbd log doesn't show
> anything, but the syslog does have information from named with samba_dlz
> for this client, so I'm suspecting it might be related:
>
> Sep 15 12:20:30 kashyyyk named[25643]: samba_dlz: starting transaction
> on zone pdc.cij.lu
> Sep 15 12:20:30 kashyyyk named[25643]: client 10.0.101.130#62031: update
> 'pdc.cij.lu/IN' denied
> Sep 15 12:20:30 kashyyyk named[25643]: samba_dlz: cancelling transaction
> on zone pdc.cij.lu
> Sep 15 12:20:32 kashyyyk named[25643]: samba_dlz: starting transaction
> on zone pdc.cij.lu
> Sep 15 12:20:32 kashyyyk named[25643]: client 10.0.101.130#55277: update
> 'pdc.cij.lu/IN' denied
> Sep 15 12:20:32 kashyyyk named[25643]: samba_dlz: cancelling transaction
> on zone pdc.cij.lu
> Sep 15 12:20:32 kashyyyk named[25643]: samba_dlz: starting transaction
> on zone pdc.cij.lu
> Sep 15 12:20:32 kashyyyk named[25643]: client 10.0.101.130#58966: update
> 'pdc.cij.lu/IN' denied
> Sep 15 12:20:32 kashyyyk named[25643]: samba_dlz: cancelling transaction
> on zone pdc.cij.lu
> Sep 15 12:20:37 kashyyyk named[25643]: samba_dlz: starting transaction
> on zone pdc.cij.lu
> Sep 15 12:20:37 kashyyyk named[25643]: client 10.0.101.130#59517: update
> 'pdc.cij.lu/IN' denied
> Sep 15 12:20:37 kashyyyk named[25643]: samba_dlz: cancelling transaction
> on zone pdc.cij.lu
>
> There's no custom config in samba/private/named.conf, only the dlz config.
> The same request, when not denied, e.g. from another client, would look
> something like this:
>
>
> Sep 15 12:25:28 kashyyyk named[25643]: samba_dlz: allowing update of
> signer=validuser\$\@PDC.CIJ.LU name=WORKINGCLIENT.pdc.cij.lu tcpaddr=
> type=AAAA key=1060-ms-7.2-d168c4.7b676820-5b74-11e5-e6ad-6451064bd99e/160/0
> Sep 15 12:25:28 kashyyyk named[25643]: samba_dlz: allowing update of
> signer=validuser\$\@PDC.CIJ.LU name=WORKINGCLIENT.pdc.cij.lu tcpaddr=
> type=A key=1060-ms-7.2-d168c4.7b676820-5b74-11e5-e6ad-6451064bd99e/160/0
> Sep 15 12:25:28 kashyyyk named[25643]: samba_dlz: allowing update of
> signer=validuser\$\@PDC.CIJ.LU name=WORKINGCLIENT.pdc.cij.lu tcpaddr=
> type=A key=1060-ms-7.2-d168c4.7b676820-5b74-11e5-e6ad-6451064bd99e/160/0
> Sep 15 12:25:28 kashyyyk named[25643]: client 10.0.101.105#49508/key
> validuser\$\@PDC.CIJ.LU: updating zone 'pdc.cij.lu/NONE': deleting rrset
> at 'WORKINGCLIENT.pdc.cij.lu' AAAA
> Sep 15 12:25:28 kashyyyk named[25643]: client 10.0.101.105#49508/key
> validuser\$\@PDC.CIJ.LU: updating zone 'pdc.cij.lu/NONE': deleting rrset
> at 'WORKINGCLIENT.pdc.cij.lu' A
> Sep 15 12:25:28 kashyyyk named[25643]: samba_dlz: subtracted rdataset
> WORKINGCLIENT.pdc.cij.lu
> 'DIDACE.pdc.cij.lu.#0111200#011IN#011A#01110.0.101.105'
> Sep 15 12:25:28 kashyyyk named[25643]: client 10.0.101.105#49508/key
> validuser\$\@PDC.CIJ.LU: updating zone 'pdc.cij.lu/NONE': adding an RR
> at 'DIDACE.pdc.cij.lu'  A
> Sep 15 12:25:28 kashyyyk named[25643]: samba_dlz: added rdataset
> WORKINGCLIENT.pdc.cij.lu
> 'DIDACE.pdc.cij.lu.#0111200#011IN#011A#01110.0.101.105'
> Sep 15 12:25:28 kashyyyk named[25643]: samba_dlz: committed transaction
> on zone pdc.cij.lu
>
> I've tried several things that I found on-line, but I haven't been able
> to figure out why the host with IP address .130 would be denied. (I've
> only seen another host .101 denied once or twice)
> I have increased the log level today, but from remote, there's not much
> debugging info coming in unless someone reboots the machine with IP .130.
>
> Things I could try but haven't so far because I didn't have access to
> the machine's local Admin Account:
>
> * release and renew the lease from the Windows PC (I did release it on
> the DHCP server though, which didn't help)
> * re-register the client in the domain
>
>
> Here's some additional startup info on bind startup:
>
> Sep 15 19:16:19 kashyyyk named[10495]: starting BIND
> 9.9.5-9+deb8u1-Debian -f -u bind
> Sep 15 19:16:19 kashyyyk named[10495]: built with '--prefix=/usr'
> '--mandir=/usr/share/man' '--infodir=/usr/share/info'
> '--sysconfdir=/etc/bind' '--localstatedir=/var' '--enable-threads'
> '--enable-largefile' '--with-libtool' '--enable-shared'
> '--enable-static' '--with-openssl=/usr' '--with-gssapi=/usr'
> '--with-gnu-ld' '--with-geoip=/usr' '--with-atf=no' '--enable-ipv6'
> '--enable-rrl' '--enable-filter-aaaa' 'CFLAGS=-fno-strict-aliasing
> -fno-delete-null-pointer-checks -DDIG_SIGCHASE -O2'
> Sep 15 19:16:19 kashyyyk named[10495]: adjusted limit on open files from
> 4096 to 1048576
> Sep 15 19:16:19 kashyyyk named[10495]: found 8 CPUs, using 8 worker threads
> Sep 15 19:16:19 kashyyyk named[10495]: using 8 UDP listeners per interface
> Sep 15 19:16:19 kashyyyk named[10495]: using up to 4096 sockets
> Sep 15 19:16:19 kashyyyk named[10495]: loading configuration from
> '/etc/bind/named.conf'
> Sep 15 19:16:19 kashyyyk named[10495]: reading built-in trusted keys
> from file '/etc/bind/bind.keys'
> Sep 15 19:16:19 kashyyyk named[10495]: using default UDP/IPv4 port
> range: [1024, 65535]
> Sep 15 19:16:19 kashyyyk named[10495]: using default UDP/IPv6 port
> range: [1024, 65535]
> Sep 15 19:16:19 kashyyyk named[10495]: listening on IPv4 interface lo,
> 127.0.0.1#53
> Sep 15 19:16:19 kashyyyk named[10495]: listening on IPv4 interface eth0,
> 10.0.101.10#53
> Sep 15 19:16:19 kashyyyk named[10495]: listening on IPv4 interface
> virbr0, 192.168.122.1#53
> Sep 15 19:16:19 kashyyyk named[10495]: binding TCP socket: address in use
> Sep 15 19:16:19 kashyyyk named[10495]: generating session key for
> dynamic DNS
> Sep 15 19:16:19 kashyyyk named[10495]: sizing zone task pool based on 5
> zones
> Sep 15 19:16:19 kashyyyk named[10495]: Loading 'AD DNS Zone' using
> driver dlopen
> Sep 15 19:16:19 kashyyyk named[10495]: samba_dlz: started for DN
> DC=pdc,DC=cij,DC=lu
> Sep 15 19:16:19 kashyyyk named[10495]: samba_dlz: starting configure
> Sep 15 19:16:19 kashyyyk named[10495]: samba_dlz: configured writeable
> zone 'pdc.cij.lu'
> Sep 15 19:16:19 kashyyyk named[10495]: samba_dlz: configured writeable
> zone '_msdcs.pdc.cij.lu'
> Sep 15 19:16:19 kashyyyk named[10495]: using built-in root key for view
> _default
> Sep 15 19:16:19 kashyyyk named[10495]: set up managed keys zone for view
> _default, file 'managed-keys.bind'
> Sep 15 19:16:20 kashyyyk named[10495]: command channel listening on
> 127.0.0.1#953
> Sep 15 19:16:20 kashyyyk named[10495]: command channel listening on ::1#953
>
>
> Thanks for any help or advice on what else to try or which information
> to supply.
>
> Best regards,
> David Raison
>
>
>

Is this just one client ? it sounds like the machines kerberos ticket 
has expired.

I also noticed this: 'Sep 15 19:16:19 kashyyyk named[10495]: binding TCP 
socket: address in use'
It looks like something else is using TCP port 53

Rowland