DLZ / ISC DHCP query

[Marty Lee]

Hi,

I’m seeing some strange behaviour on a system here, and while I’m looking
to find the root cause, I thought I’d post something here to see if anyone
else has thoughts. (Tried searching the archives, but the web server keeps
telling me that the piper mail archive page doesn’t exist.. hey ho).

Solaris 11; Sun/Oracle compilers;
* ISC DHCP 4.2.6 (4.3.0 doesn’t compile with Oracle compilers)
* Bind 9.9.5

Both compiled from source and in my normal config (std zone files),
all works ok, including dynamic DNS updates.

Single Solaris x86 box with DHCP and Bind running locally; no other DHCP
or Bind servers present!

I’m trying to move Bind to using MySQL through a DLZ (dlopen) shared
object which I’ve written myself.

With my new DLZ, standard lookups work fine from the database, and
I’ve checked throughly with dig against a standard zone file and a
DLZ database backed one.

Then I moved on to dynamic DNS updates from ISC DHCP…..

With a clean dhcp lease file, and the appropriate zone picked up with
the DLZ driver, I see the following events: (clearly my own debug messages,
but I think they show the sequence of events quite clearly).

27-Mar-2014 18:38:02.824 dlz_newversion: carlops.maui.co.uk
27-Mar-2014 18:38:02.824 dlz_mysql: execute(0) START TRANSACTION
27-Mar-2014 18:38:02.824 Connect to database dns @ localhost
27-Mar-2014 18:38:02.826 dlz_mysql: allowing update of name=Martys-iPad.carlops.maui.co.uk by dhcpupdate
27-Mar-2014 18:38:02.826 dlz_mysql: allowing update of name=Martys-iPad.carlops.maui.co.uk by dhcpupdate
27-Mar-2014 18:38:02.827 client 192.168.2.2#55500/key dhcpupdate: updating zone 'carlops.maui.co.uk/NONE': adding an RR at 'Martys-iPad.carlops.maui.co.uk' A
27-Mar-2014 18:38:02.828 dlz_mysql: adding rdataset Martys-iPad.carlops.maui.co.uk 'Martys-iPad.carlops.maui.co.uk. 3600 IN A 192.168.2.139'
27-Mar-2014 18:38:02.828 dlz_mysql: execute(0) INSERT INTO ZoneData (zone_id, name, type, data, ttl) VALUES (9, LOWER('Martys-iPad'), UPPER('A'), '192.168.2.139', 3600)
27-Mar-2014 18:38:02.828 client 192.168.2.2#55500/key dhcpupdate: updating zone 'carlops.maui.co.uk/NONE': adding an RR at 'Martys-iPad.carlops.maui.co.uk' TXT
27-Mar-2014 18:38:02.829 dlz_mysql: adding rdataset Martys-iPad.carlops.maui.co.uk 'Martys-iPad.carlops.maui.co.uk. 3600 IN TXT "31aaee999c17b074d5ffdcba7376571020"'
27-Mar-2014 18:38:02.829 dlz_mysql: execute(0) INSERT INTO ZoneData (zone_id, name, type, data, ttl) VALUES (9, LOWER('Martys-iPad'), UPPER('TXT'), '"31aaee999c17b074d5ffdcba7376571020"', 3600)
27-Mar-2014 18:38:02.832 dlz_mysql: subtracting rdataset carlops.maui.co.uk 'carlops.maui.co.uk. 14400 IN SOA carlops.maui.co.uk. dns.carlops.maui.co.uk. 95 86400 7200 86400 86400'
27-Mar-2014 18:38:02.832 dlz_mysql: adding rdataset carlops.maui.co.uk 'carlops.maui.co.uk. 14400 IN SOA carlops.maui.co.uk. dns.carlops.maui.co.uk. 96 86400 7200 86400 86400'
27-Mar-2014 18:38:02.832 dlz_mysql: execute(0) UPDATE Zones SET serial = 96 WHERE id = 9
27-Mar-2014 18:38:02.833 dlz_closeversion: carlops.maui.co.uk commit(1)
27-Mar-2014 18:38:02.850 dlz_mysql: execute(0) COMMIT
27-Mar-2014 18:38:02.850 dlz_mysql: committed transaction on zone carlops.maui.co.uk

so far everything looks ok.

Immediately after this set of events, I then get the following:

27-Mar-2014 18:38:02.850 dlz_newversion: carlops.maui.co.uk
27-Mar-2014 18:38:02.850 dlz_mysql: execute(0) START TRANSACTION
27-Mar-2014 18:38:02.850 client 192.168.2.2#55500/key dhcpupdate: updating zone 'carlops.maui.co.uk/NONE': update unsuccessful: Martys-iPad.carlops.maui.co.uk: 'name not in use' prerequisite not satisfied (YXDOMAIN)
27-Mar-2014 18:38:02.850 dlz_closeversion: carlops.maui.co.uk commit(0)
27-Mar-2014 18:38:02.850 dlz_mysql: execute(0) ROLLBACK
27-Mar-2014 18:38:02.851 dlz_mysql: rolled back transaction on zone carlops.maui.co.uk
27-Mar-2014 18:38:02.851 dlz_newversion: carlops.maui.co.uk
27-Mar-2014 18:38:02.851 dlz_mysql: execute(0) START TRANSACTION
27-Mar-2014 18:38:02.852 dlz_mysql: allowing update of name=Martys-iPad.carlops.maui.co.uk by dhcpupdate
27-Mar-2014 18:38:02.852 dlz_mysql: allowing update of name=Martys-iPad.carlops.maui.co.uk by dhcpupdate
27-Mar-2014 18:38:02.852 client 192.168.2.2#55500/key dhcpupdate: updating zone 'carlops.maui.co.uk/NONE': deleting rrset at 'Martys-iPad.carlops.maui.co.uk' A
27-Mar-2014 18:38:02.852 dlz_mysql: subtracting rdataset Martys-iPad.carlops.maui.co.uk 'Martys-iPad.carlops.maui.co.uk. 3600 IN A 192.168.2.139'
27-Mar-2014 18:38:02.853 dlz_mysql: execute(0) DELETE FROM ZoneData WHERE zone_id = 9 AND LOWER(name) = LOWER('Martys-iPad') AND UPPER(type) = UPPER('A') AND data = '192.168.2.139' AND ttl = 3600
27-Mar-2014 18:38:02.853 client 192.168.2.2#55500/key dhcpupdate: updating zone 'carlops.maui.co.uk/NONE': adding an RR at 'Martys-iPad.carlops.maui.co.uk' A
27-Mar-2014 18:38:02.856 dlz_mysql: subtracting rdataset carlops.maui.co.uk 'carlops.maui.co.uk. 14400 IN SOA carlops.maui.co.uk. dns.carlops.maui.co.uk. 96 86400 7200 86400 86400'
27-Mar-2014 18:38:02.857 dlz_mysql: adding rdataset carlops.maui.co.uk 'carlops.maui.co.uk. 14400 IN SOA carlops.maui.co.uk. dns.carlops.maui.co.uk. 97 86400 7200 86400 86400'
27-Mar-2014 18:38:02.857 dlz_mysql: execute(0) UPDATE Zones SET serial = 97 WHERE id = 9
27-Mar-2014 18:38:02.858 dlz_closeversion: carlops.maui.co.uk commit(1)
27-Mar-2014 18:38:02.867 dlz_mysql: execute(0) COMMIT
27-Mar-2014 18:38:02.867 dlz_mysql: committed transaction on zone carlops.maui.co.uk


So it looks like the DHCP server requests a new dynamic IP address to be created; the DLZ performs the task and
updates the zone serial number as expected, but as soon as that has happened, the DHCP server finds the A record,
and then decides the address is in use and removes it… 'name not in use' prerequisite not satisfied (YXDOMAIN)

The MySQL database gets the A record for a split second, then it’s removed, leaving the ‘TXT’ record behind. If
I clear out the lease in the DHCP server file and re-present the device (my iPad), then it works ok on the second
attempt - i.e. it seems to need the ‘TXT’ record to be there for some reason.

I’ll go and play with the stock DLZ example zone for example.nil and see if that does the same,
but it looks like either the DHCP server is doing something weird, or I’ve missed some critical item of doing
dynamic DNS updates with DLZ.

(as a side note, I did wonder whether I should just hold the updates in memory and only commit them
to the db when the ‘commit’ message is passed…. that resulted in the same behaviour, but would have
been a logical solution had it been the problem).

I know other people have used DLZ and dlopen with external modules; anyone got any gems of insight??

I’ve got no problems working my way through the code to figure out what is going on, but obviously if
someone else can give me a head start, then it would be appreciated!

BTW, doing a manual Dynamic DNS update using nsupdate works fine - the A and TXT records are created
without any problem and the A record isn’t then deleted, so it’s something to do with the DHCP server
and it’s interaction with Bind.

Cheers

marty



-----
Marty Lee e: ma...@maui-systems.co.uk
Technical Director v: +44 845 869 2661
Maui Systems Ltd f: +44 871 433 8922
Scotland, UK w: http://www.maui-systems.co.uk

[Evan Hunt]

On Thu, Mar 27, 2014 at 06:58:35PM +0000, Marty Lee wrote:
> BTW, doing a manual Dynamic DNS update using nsupdate works fine - the A

> and TXT records are created without any problem and the A record isn?t
> then deleted, so it?s something to do with the DHCP server and it?s
> interaction with Bind.

I'd run wireshark on the link between dhcp and bind9 to see what
the update packets look like. When you tested with nsupdate, did you
use prerequisites?

--
Evan Hunt -- ea...@isc.org
Internet Systems Consortium, Inc.

[Marty Lee]

Ok, finally managed to get a test rig set up with wireshark and have
now seen more about what’s going on & can see the pre-requisites going
over the wire.

Versions: ISC DHCPD 4.2.6, Bind 9.9.5

DHCPD sends a dynamic update with a pre-req that the name doesn’t exist
Bind replies with a fail, as the name does exist

DHCPD then sends a new dynamic update with a pre-req that the TXT record exists
Bind replies with a success, however:
- within the packet are 2 updates
- 1st is to remove the original ‘A’ record
- 2nd is to add the new ‘A’ record
- Bind calls the dlz ‘dlz_subrdataset’ but not the ‘dlz_addrdataset’ for the 2nd update record

End result, is that once the TXT record exists, Bind 9.9.5 just tries to delete the A
record from the update and doesn’t create the new one.

So - looks like something is up with the Bind code, so I’m off to have a look at that;
especially now I can play with all of this on a test network and it’s 100% repeatable.

Cheers

marty

[Marty Lee]

On 1 Apr 2014, at 09:52, Marty Lee <ma...@maui-systems.co.uk> wrote:

>
> Ok, finally managed to get a test rig set up with wireshark and have
> now seen more about what’s going on & can see the pre-requisites going
> over the wire.
>
> Versions: ISC DHCPD 4.2.6, Bind 9.9.5
>
> DHCPD sends a dynamic update with a pre-req that the name doesn’t exist
> Bind replies with a fail, as the name does exist
>
> DHCPD then sends a new dynamic update with a pre-req that the TXT record exists
> Bind replies with a success, however:
> - within the packet are 2 updates
> - 1st is to remove the original ‘A’ record
> - 2nd is to add the new ‘A’ record
> - Bind calls the dlz ‘dlz_subrdataset’ but not the ‘dlz_addrdataset’ for the 2nd update record
>
> End result, is that once the TXT record exists, Bind 9.9.5 just tries to delete the A
> record from the update and doesn’t create the new one.
>
> So - looks like something is up with the Bind code, so I’m off to have a look at that;
> especially now I can play with all of this on a test network and it’s 100% repeatable.

Bind (update.c) gets the update request and iterates through the records.
It processes the request to delete the A record, then processes the ‘add’ record;
so far so good - I had thought it might just be doing record 1 and ignoring the
rest.

The code for the ‘add record’ calls ‘add_rr_prepare_action’, which queries the
DNS data to see if the record already exists, and if it does, there is a
comment : ‘the update should be silently ignored’.

Looking at the DLZ methodology, the process flow is:

- newversion
- add/subtract records
- closeversion (commit flag)

which maps nicely to a database transaction; new version starts the transaction
and has a user supplied ‘version’ parameter, in which I can pass a structure to
identify the db connection in use.

Adds/subtracts have the ‘version’ parameter, so get processed with the same
db connection that started the transaction, so integrity is fine.

When closeversion is called, I can take the ‘version' parameter and then
call ‘ROLLBACK’ or ‘COMMIT’ as appropriate.

The problem is the following:

* transaction gets started
* the delete is processed within the scope of the transaction
* the ‘add’ is processed but the add_rr_prepare_action function calls a
DNS lookup outside of the scope of the transaction, so the database
record still exists as the transaction is still open.
The ‘add_rr_prepare_action’ function assumes it can silently ignore
the add as the record exists.
* The commit then happens, and the ‘delete’ is now applied to the database.

End result, is that the new ‘A’ record is never added.

I would question the fact that the code silently skips adds without
even a debug level message - or maybe it’s just because that small
piece of very significant debug information would have led me straight
to the issue!

Anyway, now I understand why Bind is ignoring that ‘add’, I can look at
my DLZ and the interfaces supplied, to see if there is anything I can
do from the DLZ, or whether I need to track a transaction through some
other mechanism than the database, and get add/delete to apply directly
to the DB records.

My guess, is that the ‘version’ from the transaction should be passed
through to dlz_lookup as an optional parameter; if set, then any lookups
could then be done in the scope of the transaction, and thus return
correct information. I just need to track down how to make that happen,
or maybe, if it’s already there and I just haven’t found it yet.

Hopefully this explanation of what’s going on gets logged on the Bind
mail archive, and the next poor soul that tries to play with DLZ and
Dynamic DNS will find it…

Cheers

marty