[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