[Samba] Issue with DHCP Updating DNS Records on AD DC

Mon Jul 1 16:00:48 UTC 2019

On 01/07/2019 16:36, Ross Harms via samba wrote:
> Greetings,
>
> I am in the process of replacing my MicroFocus (Novell) eDirectory system
> with a Samba-based Active Directory system.  I've got three domain
> controllers built, and they seem to be humming along nicely. Server OS is
> Ubuntu 18.04 patched current.  I started off with the Samba 4.7 packages
> included in the default Ubuntu repository, but have since upgraded to Samba
> 4.10 using packages from Louis Van Belle's repository. I'm using Bind9 as
> my DNS backend via BIND9_DLZ, and that all seems to be working as it
> should.
>
> The place I'm getting hung up is with dynamic dns updates from DHCP. I
> followed this set of instructions
> <https://wiki.samba.org/index.php/Configure_DHCP_to_update_DNS_records_with_BIND9>
> from
> the Samba wiki, but haven't been able to get it working successfully.  DHCP
> itself works fine, but it's not updating DNS.  When I look in syslog, this
> is an example of what I see
>
> Jul  1 10:15:57 dc1 dhcpd[1273]: Commit: IP: 10.42.4.11 DHCID:
> a4:31:35:b8:e0:15 Name: AHS-MAD-iPod-02
> Jul  1 10:15:57 dc1 dhcpd[1273]: execute_statement argv[0] =
> /usr/local/bin/dhcp-dyndns.sh
> Jul  1 10:15:57 dc1 dhcpd[1273]: execute_statement argv[1] = add
> Jul  1 10:15:57 dc1 dhcpd[1273]: execute_statement argv[2] = 10.42.4.11
> Jul  1 10:15:57 dc1 dhcpd[1273]: execute_statement argv[3] =
> a4:31:35:b8:e0:15
> Jul  1 10:15:57 dc1 dhcpd[1273]: execute_statement argv[4] = AHS-MAD-iPod-02
> Jul  1 10:15:57 dc1 dhcpd: 01-07-19 10:15:57 [dyndns] : Getting new ticket,
> old one has expired
> Jul  1 10:15:57 dc1 sh[1273]: kinit: Pre-authentication failed: Permission
> denied while getting initial credentials
> Jul  1 10:15:57 dc1 dhcpd: 01-07-19 10:15:57 [dyndns] : dhcpd kinit for
> dynamic DNS failed
> Jul  1 10:15:57 dc1 dhcpd[1273]: execute: /usr/local/bin/dhcp-dyndns.sh
> exit status 256
>
> So, as far as I can tell, dhcpd is providing the correct variable info, and
> the dhcp-dyndns script is attempting to run, but it's having Kerberos
> trouble.  If I check /tmp/ I don't see that the dhcp-dyndns.cc file ever
> creates, which explains why it bombs out when the script tries to verify
> it.  If I log in as root and manually run the kinit line, the
> dhcp-dyndns.cc file creates properly.  If I run a klist against that
> created file, it shows the ticket as existing and being valid.  But, the
> next time the script runs, I get the same result.  It says the ticket is
> expired (even though it's not), attempts to kinit a new one, fails, and the
> script quits there.
>
> Fairly sure it's a permissions issue somewhere, but I can't seem to figure
> out where.  I have made, and double checked, the changes to the AppArmor
> profile for dhcpd.  I adjusted it further to
>
>   /usr/bin/kinit rwix,
>   /usr/bin/klist rix,
>
> to see if that would clear it up, but no such luck.
>
> Appreciate any help that you can offer.
>
First, proof it works:

Jul  1 08:01:06 dc4 dhcpd[2018]: DHCPREQUEST for 192.168.0.142 from 
cc:4e:ec:e9:c8:d3 via eth0
Jul  1 08:01:06 dc4 dhcpd[2018]: DHCPACK on 192.168.0.142 to 
cc:4e:ec:e9:c8:d3 via eth0
Jul  1 08:03:58 dc4 dhcpd[2018]: Commit: IP: 192.168.0.88 DHCID: 
ec:08:6b:0c:cb:c2 Name: devstation
Jul  1 08:03:58 dc4 dhcpd[2018]: execute_statement argv[0] = 
/usr/local/bin/dhcp-dyndns.sh
Jul  1 08:03:58 dc4 dhcpd[2018]: execute_statement argv[1] = add
Jul  1 08:03:58 dc4 dhcpd[2018]: execute_statement argv[2] = 192.168.0.88
Jul  1 08:03:58 dc4 dhcpd[2018]: execute_statement argv[3] = 
ec:08:6b:0c:cb:c2
Jul  1 08:03:58 dc4 dhcpd[2018]: execute_statement argv[4] = devstation
Jul  1 08:03:58 dc4 named[1688]: samba_dlz: starting transaction on zone 
samdom.example.com
Jul  1 08:03:58 dc4 named[1688]: samba_dlz: allowing update of 
signer=dhcpduser\@SAMDOM.EXAMPLE.COM name=devstation.samdom.example.com 
tcpaddr=127.0.0.1 type=A key=1995416775.sig-dc4.samdom.example.com/160/0
Jul  1 08:03:58 dc4 named[1688]: samba_dlz: allowing update of 
signer=dhcpduser\@SAMDOM.EXAMPLE.COM name=devstation.samdom.example.com 
tcpaddr=127.0.0.1 type=A key=1995416775.sig-dc4.samdom.example.com/160/0
Jul  1 08:03:58 dc4 named[1688]: client 127.0.0.1#57059/key 
dhcpduser\@SAMDOM.EXAMPLE.COM: updating zone 'samdom.example.com/NONE': 
deleting rrset at 'devstation.samdom.example.com' A
Jul  1 08:03:58 dc4 named[1688]: samba_dlz: subtracted rdataset 
devstation.samdom.example.com 
'devstation.samdom.example.com.#0113600#011IN#011A#011192.168.0.88'
Jul  1 08:03:58 dc4 named[1688]: client 127.0.0.1#57059/key 
dhcpduser\@SAMDOM.EXAMPLE.COM: updating zone 'samdom.example.com/NONE': 
adding an RR at 'devstation.samdom.example.com' A 192.168.0.88
Jul  1 08:03:58 dc4 named[1688]: samba_dlz: added rdataset 
devstation.samdom.example.com 
'devstation.samdom.example.com.#0113600#011IN#011A#011192.168.0.88'
Jul  1 08:03:58 dc4 named[1688]: samba_dlz: committed transaction on 
zone samdom.example.com
Jul  1 08:03:58 dc4 named[1688]: samba_dlz: starting transaction on zone 
0.168.192.in-addr.arpa
Jul  1 08:03:58 dc4 named[1688]: samba_dlz: allowing update of 
signer=dhcpduser\@SAMDOM.EXAMPLE.COM name=88.0.168.192.in-addr.arpa 
tcpaddr=127.0.0.1 type=PTR key=4135370354.sig-dc4.samdom.example.com/160/0
Jul  1 08:03:58 dc4 named[1688]: samba_dlz: allowing update of 
signer=dhcpduser\@SAMDOM.EXAMPLE.COM name=88.0.168.192.in-addr.arpa 
tcpaddr=127.0.0.1 type=PTR key=4135370354.sig-dc4.samdom.example.com/160/0
Jul  1 08:03:58 dc4 named[1688]: client 127.0.0.1#37351/key 
dhcpduser\@SAMDOM.EXAMPLE.COM: updating zone 
'0.168.192.in-addr.arpa/NONE': deleting rrset at 
'88.0.168.192.in-addr.arpa' PTR
Jul  1 08:03:58 dc4 named[1688]: samba_dlz: subtracted rdataset 
88.0.168.192.in-addr.arpa 
'88.0.168.192.in-addr.arpa.#0113600#011IN#011PTR#011devstation.samdom.example.com.'
Jul  1 08:03:58 dc4 named[1688]: client 127.0.0.1#37351/key 
dhcpduser\@SAMDOM.EXAMPLE.COM: updating zone 
'0.168.192.in-addr.arpa/NONE': adding an RR at 
'88.0.168.192.in-addr.arpa' PTR devstation.samdom.example.com.
Jul  1 08:03:58 dc4 named[1688]: samba_dlz: added rdataset 
88.0.168.192.in-addr.arpa 
'88.0.168.192.in-addr.arpa.#0113600#011IN#011PTR#011devstation.samdom.example.com.'
Jul  1 08:03:58 dc4 named[1688]: samba_dlz: committed transaction on 
zone 0.168.192.in-addr.arpa
Jul  1 08:03:58 dc4 root: DHCP-DNS Update succeeded
Jul  1 08:03:58 dc4 root: Successfully modified Computer devstation in AD
Jul  1 08:03:59 dc4 dhcpd[2018]: DHCPREQUEST for 192.168.0.88 from 
ec:08:6b:0c:cb:c2 (devstation) via eth0
Jul  1 08:03:59 dc4 dhcpd[2018]: DHCPACK on 192.168.0.88 to 
ec:08:6b:0c:cb:c2 (devstation) via eth0

OK, I would turn off Apparmor and if everything now works, you will know 
what to fix ;-)

If it still doesn't work, check who 'dhcpd' is run by on Ubuntu and 
check that '/etc/dhcpduser.keytab' is owned by the correct user.

Still not working, go here: https://github.com/thctlo/samba4

Download the 'samba-collect-debug-info.sh' script and run it on the DC 
running the dhcp update script, then post the output here.

Rowland