[Dnsmasq-discuss] DHCPv6

Simon Kelley simon at thekelleys.org.uk
Tue Apr 9 10:18:15 BST 2013


On 08/04/13 21:38, Christof Meerwald wrote:
> On Mon, 08 Apr 2013 20:42:25 +0100, Simon Kelley wrote:
>> On 08/04/13 19:17, Christof Meerwald wrote:
>>> I am afraid I spoke too soon - behaviour seems to be a bit random.
>>>
>>> So, my dnsmasq configuration is available at
>>> http://svn.cmeerw.net/cfg/fruity.cmeerw.net/etc/dnsmasq.conf
> [...]
>>> Any ideas?
>>
>> There's at least one possible explanation that doesn't involve a dnsmasq
>> bug, and several that do. The first thing to do is to turn on verbose
>> DHCP logging by adding
>>
>> log-dhcp
>>
>> to the config. If we can get log dumps of the same events with that
>> switched on, it will be a lot easier to see what's going on.
>
> Ok, so it seems to depend a bit on the state in dnsmasq.leases. With a
> fresh dnsmasq.leases (just containing the duid) it seems to be working
> fine:
>
> Apr  8 20:15:34 localhost dnsmasq-dhcp[2749]: 5343413 available DHCP range: 2a01:348:236:feed::d000 -- 2a01:348:236:feed::dfff
> Apr  8 20:15:34 localhost dnsmasq-dhcp[2749]: 5343413 DHCPSOLICIT(eth0) 00:01:00:01:18:f3:5c:6c:00:26:9e:38:e5:fb
> Apr  8 20:15:34 localhost dnsmasq-dhcp[2749]: 5343413 DHCPADVERTISE(eth0) 2a01:348:236:feed::13 00:01:00:01:18:f3:5c:6c:00:26:9e:38:e5:fb
> Apr  8 20:15:34 localhost dnsmasq-dhcp[2749]: 5343413 requested options: 24:domain-search, 39:FQDN, 23:dns-server,
> Apr  8 20:15:34 localhost dnsmasq-dhcp[2749]: 5343413 requested options: 31:sntp-server
> Apr  8 20:15:34 localhost dnsmasq-dhcp[2749]: 5343413 tags: known, dhcpv6, eth0
> Apr  8 20:15:34 localhost dnsmasq-dhcp[2749]: 5343413 sent size: 14 option:  1 client-id  00:01:00:01:18:f3:5c:6c:00:26:9e:38:e5:fb
> Apr  8 20:15:34 localhost dnsmasq-dhcp[2749]: 5343413 sent size: 14 option:  2 server-id  00:01:00:01:18:f3:64:29:b8:27:eb:a5:5a:4f
> Apr  8 20:15:34 localhost dnsmasq-dhcp[2749]: 5343413 sent size: 40 option:  3 ia-na  IAID=2654529019 T1=3600 T2=6300
> Apr  8 20:15:34 localhost dnsmasq-dhcp[2749]: 5343413 nest size: 24 option:  5 iaaddr  2a01:348:236:feed::13 PL=7200 VL=7200
> Apr  8 20:15:34 localhost dnsmasq-dhcp[2749]: 5343413 sent size:  9 option: 13 status  0 success
> Apr  8 20:15:34 localhost dnsmasq-dhcp[2749]: 5343413 sent size:  1 option:  7 preference  0
> Apr  8 20:15:34 localhost dnsmasq-dhcp[2749]: 5343413 sent size: 16 option: 23 dns-server  2a01:348:236:feed::1
> Apr  8 20:15:35 localhost dnsmasq-dhcp[2749]: 11311546 available DHCP range: 2a01:348:236:feed::d000 -- 2a01:348:236:feed::dfff
> Apr  8 20:15:35 localhost dnsmasq-dhcp[2749]: 11311546 DHCPREQUEST(eth0) 00:01:00:01:18:f3:5c:6c:00:26:9e:38:e5:fb
> Apr  8 20:15:35 localhost dnsmasq-dhcp[2749]: 11311546 DHCPREPLY(eth0) 2a01:348:236:feed::13 00:01:00:01:18:f3:5c:6c:00:26:9e:38:e5:fb
> Apr  8 20:15:35 localhost dnsmasq-dhcp[2749]: 11311546 requested options: 24:domain-search, 39:FQDN, 23:dns-server,
> Apr  8 20:15:35 localhost dnsmasq-dhcp[2749]: 11311546 requested options: 31:sntp-server
> Apr  8 20:15:35 localhost dnsmasq-dhcp[2749]: 11311546 tags: known, dhcpv6, eth0
> Apr  8 20:15:35 localhost dnsmasq-dhcp[2749]: 11311546 sent size: 14 option:  1 client-id  00:01:00:01:18:f3:5c:6c:00:26:9e:38:e5:fb
> Apr  8 20:15:35 localhost dnsmasq-dhcp[2749]: 11311546 sent size: 14 option:  2 server-id  00:01:00:01:18:f3:64:29:b8:27:eb:a5:5a:4f
> Apr  8 20:15:35 localhost dnsmasq-dhcp[2749]: 11311546 sent size: 40 option:  3 ia-na  IAID=2654529019 T1=3600 T2=6300
> Apr  8 20:15:35 localhost dnsmasq-dhcp[2749]: 11311546 nest size: 24 option:  5 iaaddr  2a01:348:236:feed::13 PL=7200 VL=7200
> Apr  8 20:15:35 localhost dnsmasq-dhcp[2749]: 11311546 sent size:  9 option: 13 status  0 success
> Apr  8 20:15:35 localhost dnsmasq-dhcp[2749]: 11311546 sent size: 16 option: 23 dns-server  2a01:348:236:feed::1
>
> at this point dnsmasq has been stopped and the client has
> (unsuccessfully) tried to release the lease.
>
> dnsmasq has been restarted and the client tries again the get an IPv6
> address:
>
> Apr  8 20:17:44 localhost dnsmasq-dhcp[2763]: 10468696 available DHCP range: 2a01:348:236:feed::d000 -- 2a01:348:236:feed::dfff
> Apr  8 20:17:44 localhost dnsmasq-dhcp[2763]: 10468696 DHCPSOLICIT(eth0) 00:01:00:01:18:f3:5c:6c:00:26:9e:38:e5:fb
> Apr  8 20:17:44 localhost dnsmasq-dhcp[2763]: 10468696 DHCPADVERTISE(eth0) 2a01:348:236:feed::da3b 00:01:00:01:18:f3:5c:6c:00:26:9e:38:e5:fb
> Apr  8 20:17:44 localhost dnsmasq-dhcp[2763]: 10468696 requested options: 24:domain-search, 39:FQDN, 23:dns-server,
> Apr  8 20:17:44 localhost dnsmasq-dhcp[2763]: 10468696 requested options: 31:sntp-server
> Apr  8 20:17:44 localhost dnsmasq-dhcp[2763]: 10468696 tags: known, dhcpv6, eth0
> Apr  8 20:17:44 localhost dnsmasq-dhcp[2763]: 10468696 sent size: 14 option:  1 client-id  00:01:00:01:18:f3:5c:6c:00:26:9e:38:e5:fb
> Apr  8 20:17:44 localhost dnsmasq-dhcp[2763]: 10468696 sent size: 14 option:  2 server-id  00:01:00:01:18:f3:64:29:b8:27:eb:a5:5a:4f
> Apr  8 20:17:44 localhost dnsmasq-dhcp[2763]: 10468696 sent size: 40 option:  3 ia-na  IAID=2654529019 T1=5400 T2=9450
> Apr  8 20:17:44 localhost dnsmasq-dhcp[2763]: 10468696 nest size: 24 option:  5 iaaddr  2a01:348:236:feed::da3b PL=10800 VL=10800
> Apr  8 20:17:44 localhost dnsmasq-dhcp[2763]: 10468696 sent size:  9 option: 13 status  0 success
> Apr  8 20:17:44 localhost dnsmasq-dhcp[2763]: 10468696 sent size:  1 option:  7 preference  0
> Apr  8 20:17:44 localhost dnsmasq-dhcp[2763]: 10468696 sent size: 16 option: 23 dns-server  2a01:348:236:feed::1
> Apr  8 20:17:45 localhost dnsmasq-dhcp[2763]: 10612472 available DHCP range: 2a01:348:236:feed::d000 -- 2a01:348:236:feed::dfff
> Apr  8 20:17:45 localhost dnsmasq-dhcp[2763]: 10612472 DHCPREQUEST(eth0) 00:01:00:01:18:f3:5c:6c:00:26:9e:38:e5:fb
> Apr  8 20:17:45 localhost dnsmasq-dhcp[2763]: 10612472 DHCPREPLY(eth0) 2a01:348:236:feed::da3b 00:01:00:01:18:f3:5c:6c:00:26:9e:38:e5:fb
> Apr  8 20:17:45 localhost dnsmasq-dhcp[2763]: 10612472 requested options: 24:domain-search, 39:FQDN, 23:dns-server,
> Apr  8 20:17:45 localhost dnsmasq-dhcp[2763]: 10612472 requested options: 31:sntp-server
> Apr  8 20:17:45 localhost dnsmasq-dhcp[2763]: 10612472 tags: known, dhcpv6, eth0
> Apr  8 20:17:45 localhost dnsmasq-dhcp[2763]: 10612472 sent size: 14 option:  1 client-id  00:01:00:01:18:f3:5c:6c:00:26:9e:38:e5:fb
> Apr  8 20:17:45 localhost dnsmasq-dhcp[2763]: 10612472 sent size: 14 option:  2 server-id  00:01:00:01:18:f3:64:29:b8:27:eb:a5:5a:4f
> Apr  8 20:17:45 localhost dnsmasq-dhcp[2763]: 10612472 sent size: 40 option:  3 ia-na  IAID=2654529019 T1=3600 T2=6300
> Apr  8 20:17:45 localhost dnsmasq-dhcp[2763]: 10612472 nest size: 24 option:  5 iaaddr  2a01:348:236:feed::da3b PL=7200 VL=7200
> Apr  8 20:17:45 localhost dnsmasq-dhcp[2763]: 10612472 sent size:  9 option: 13 status  0 success
> Apr  8 20:17:45 localhost dnsmasq-dhcp[2763]: 10612472 sent size: 16 option: 23 dns-server  2a01:348:236:feed::1
>
> I think I then did a few more release/acquire IPv6 addresses after
> that. The dnsmasq.leases now contains:
>
> 1365463282 00:26:9e:38:e5:fb 192.168.174.13 twilight *
> duid 00:01:00:01:18:f3:64:29:b8:27:eb:a5:5a:4f
> 1365459684 2654529019 2a01:348:236:feed::da3c * 00:01:00:01:18:f3:5c:6c:00:26:9e:38:e5:fb
> 1365459335 2147483647 2a01:348:236:feed::13 * 00:01:00:01:13:5c:6c:00:26:9e8:f:38:e5:fb
> 1365459539 2147483647 2a01:348:236:feed::da3b * 00:01:00:01:18:f3:5c:6c:00:26:9e:38:e5:fb
>
> The IPv4 side looks fine, but the IPv6 entries look a bit strange now...
>
> Hope that helps...

It helps a lot, but there must be other stuff going on here that we 
don't have logs for. The crucial thing to look for is the IAID: that's 
logged in the ia-na options which dnsmasq is sending, and it appears as 
the second field in the leases file.

How all this is _meant_ to work is somewhat hazy: it's really not well 
motivated in the relevant standards, and there's precious little prior 
art to look at. However the basic idea is that client-id (final field in 
the leases file) is unique per machine, and the IAID represents an 
interface within the machine.  An address is therefore leased not to a 
CLID, but a {CLID, IAID} pair.

The first transaction leases 2a01:348:236:feed::13 to 
{00:01:00:01:18:f3:5c:6c:00:26:9e:38:e5:fb, 2654529019}, which is fine.

The second transaction is again for 
{00:01:00:01:18:f3:5c:6c:00:26:9e:38:e5:fb, 2654529019} but it doesn't 
offer the ::13 address, instead picking a dynamically-allocated address, 
2a01:348:236:feed::da3b.

The mystery of why that should be is solved if we look in the leases 
file: by the end of the sequence  2a01:348:236:feed::13 is leased to the 
same CLID, but a _different_ IAID, 
{00:01:00:01:13:5c:6c:00:26:9e8:f:38:e5:fb, 2147483647}. Since the IAID 
is different, this is a different owner, so dnsmasq can't offer it to
{00:01:00:01:18:f3:5c:6c:00:26:9e:38:e5:fb, 2654529019} and offers a 
dynamic address instead.

The question is where the 2147483647 IAID is coming from: my guess would 
be a second, backgrounded instance of the DHCPv6 client which is still 
running. More useful, but less likely, is that you client has two 
interfaces onto the same subnet: that's a legitimate situation in which 
there would have to be two IAIDs, one for each interface, to ensure that 
they get treated separately and each is leased a different address.

Cheers,

Simon.

>
>
> Christof
>




More information about the Dnsmasq-discuss mailing list