[Dnsmasq-discuss] clients of DHCPv6 with constructed IPv6 address range are not notified on address range change

Andrey Vakhitov andrey at vakhitov.net
Wed Oct 3 19:02:34 BST 2018


Hello Simon,

>>> FWIW the strategy in the code is to continue trying to ping putative
>>> addresses  more-or-less forever, with increasing backoff, _except_ 
>>> when a call to sendto()
>>> returns EHOSTUNREACH (no route to host) which causes the code to give up.
>> 
>> Is it possible that it collides with route changes happening during 
>> renumbering? Is it possible to keep pinging for some prolonged period 
>> (may be configurable, let's say 10 minutes) ?
>> 
>>> I confess I have no idea why it's like that,  and the git commit 
>>> messages don't
>>> really give much clue. Even more annoying, the original code logged 
>>> when giving up, but  that was subsequently removed, with equally 
>>> unsatisfactory commits.
>> 
>> Do you have a reference to appropriate changesets? Maybe I could make 
>> local patches and collect more information on this issue... Well, I'm 
>> leaving for a week right now, so I have to put it on hold for a week, 
>> but I'd continue investigation after that if I'd know there to put the traces ...

> Reversing this patch
> ...
> Will give you logging for the event of giving up on "no route to host"
> error. If we can establish that's what's happening, it should be possible to 
> tweak the strategy to fix the problem.

I've reactivated thepatch locally and observing it since 4 days. Todays night associated IPv6 names got lost again directly during IP prefix change process, the log shows it clearly (see log 1). So I would vote again for retrying during some extended timeframe even if the host isn't reachable.
Renumbering during previous 3 nights went smooth, see log 2 for example

----------------- log 1 ---------------------
Okt 03 04:50:57 rtr dhcpcd[6467]: wan0: unauthenticated RECONFIGURE6 from fe80::7eff:4dff:fe03:2c18
Okt 03 04:50:57 rtr dhcpcd[6467]: wan0: RECONFIGURE6 from fe80::7eff:4dff:fe03:2c18
Okt 03 04:50:57 rtr dhcpcd[6467]: wan0: broadcasting RENEW6 (xid 0x4a0693), next in 10.5 seconds
Okt 03 04:50:57 rtr dhcpcd[6467]: wan0: DHCPv6 REPLY: prefix mismatch
Okt 03 04:50:57 rtr dhcpcd[6467]: lan0: deleting address 2001:16b8:224c:d2fc::1/64
Okt 03 04:50:57 rtr dhcpcd[6467]: lo: deleting reject route to 2001:16b8:224c:d2fc::/62
Okt 03 04:50:57 rtr dhcpcd[6467]: lan0: deleting route to 2001:16b8:224c:d2fc::/64
Okt 03 04:50:57 rtr dhcpcd[6467]: dmz0: deleting address 2001:16b8:224c:d2fd::1/64
Okt 03 04:50:57 rtr dhcpcd[6467]: dmz0: deleting route to 2001:16b8:224c:d2fd::/64
Okt 03 04:50:57 rtr dhcpcd[6467]: wan0: soliciting a DHCPv6 lease
Okt 03 04:50:57 rtr dhcpcd[6467]: wan0: delaying SOLICIT6 (xid 0x88553e), next in 0.3 seconds
Okt 03 04:50:57 rtr dnsmasq-dhcp[11540]: router advertisement on 2001:16b8:224c:d2fd::, old prefix for dmz0
Okt 03 04:50:57 rtr dnsmasq-dhcp[11540]: router advertisement on 2001:16b8:224c:d2fc::, old prefix for lan0
Okt 03 04:50:57 rtr dnsmasq-dhcp[11540]: no address range available for DHCPv6 request via lan0
Okt 03 04:50:57 rtr dnsmasq-dhcp[11540]: no address range available for DHCPv6 request via lan0
Okt 03 04:50:57 rtr dnsmasq-dhcp[11540]: no address range available for DHCPv6 request via dmz0
Okt 03 04:50:57 rtr dhcpcd[6467]: wan0: broadcasting SOLICIT6 (xid 0x88553e), next in 0.9 seconds
Okt 03 04:50:57 rtr dhcpcd[6467]: wan0: SOL_MAX_RT 3600 -> 3600
Okt 03 04:50:57 rtr dhcpcd[6467]: wan0: INF_MAX_RT 3600 -> 3600
Okt 03 04:50:57 rtr dhcpcd[6467]: wan0: ADV 2001:16b8:2284:b9fc::/62 from fe80::7eff:4dff:fe03:2c18
Okt 03 04:50:57 rtr dhcpcd[6467]: wan0: broadcasting REQUEST6 (xid 0x3b716e), next in 1.0 seconds
Okt 03 04:50:57 rtr dhcpcd[6467]: wan0: REPLY6 received from fe80::7eff:4dff:fe03:2c18
Okt 03 04:50:57 rtr dhcpcd[6467]: wan0: 2001:16b8:224c:d2fc::/62: became stale
Okt 03 04:50:57 rtr dhcpcd[6467]: wan0: renew in 1800, rebind in 2880, expire in 7200 seconds
Okt 03 04:50:57 rtr dhcpcd[6467]: lo: adding reject route to 2001:16b8:2284:b9fc::/62
Okt 03 04:50:57 rtr dhcpcd[6467]: wan0: writing lease `/var/db/dhcpcd/wan0.lease6'
Okt 03 04:50:57 rtr dhcpcd[6467]: wan0: delegated prefix 2001:16b8:2284:b9fc::/62
Okt 03 04:50:57 rtr dhcpcd[6467]: lan0: adding address 2001:16b8:2284:b9fc::1/64
Okt 03 04:50:57 rtr dhcpcd[6467]: lan0: pltime 3600 seconds, vltime 7200 seconds
Okt 03 04:50:57 rtr dnsmasq-dhcp[11540]: router advertisement on 2001:16b8:2284:b9fc::, old prefix for lan0
Okt 03 04:50:57 rtr dnsmasq-dhcp[11540]: DHCPv6 stateless on 2001:16b8:2284:b9fc::, constructed for lan0
Okt 03 04:50:57 rtr dnsmasq-dhcp[11540]: DHCPv4-derived IPv6 names on 2001:16b8:2284:b9fc::, constructed for lan0
Okt 03 04:50:57 rtr dnsmasq-dhcp[11540]: router advertisement on 2001:16b8:2284:b9fc::, constructed for lan0
Okt 03 04:50:57 rtr dnsmasq-dhcp[11540]: SLAAC-HOSTUNREACH a00:3a::2001:16b8:2284:b9fc
Okt 03 04:50:57 rtr dnsmasq-dhcp[11540]: SLAAC-HOSTUNREACH a00:3a::2001:16b8:2284:b9fc
Okt 03 04:50:57 rtr dnsmasq-dhcp[11540]: SLAAC-HOSTUNREACH a00:3a::2001:16b8:2284:b9fc
Okt 03 04:50:57 rtr dnsmasq-dhcp[11540]: SLAAC-HOSTUNREACH a00:3a::2001:16b8:2284:b9fc
Okt 03 04:50:57 rtr dnsmasq-dhcp[11540]: SLAAC-HOSTUNREACH a00:3a::2001:16b8:2284:b9fc
Okt 03 04:50:57 rtr dhcpcd[6467]: lan0: waiting for DHCPv6 DAD to complete
Okt 03 04:50:57 rtr dhcpcd[6467]: dmz0: adding address 2001:16b8:2284:b9fd::1/64
Okt 03 04:50:57 rtr dhcpcd[6467]: dmz0: pltime 3600 seconds, vltime 7200 seconds
Okt 03 04:50:57 rtr dnsmasq-dhcp[11540]: router advertisement on 2001:16b8:2284:b9fd::, old prefix for dmz0
Okt 03 04:50:57 rtr dnsmasq-dhcp[11540]: DHCPv6 stateless on 2001:16b8:2284:b9fd::, constructed for dmz0
Okt 03 04:50:57 rtr dnsmasq-dhcp[11540]: DHCPv4-derived IPv6 names on 2001:16b8:2284:b9fd::, constructed for dmz0
Okt 03 04:50:57 rtr dnsmasq-dhcp[11540]: router advertisement on 2001:16b8:2284:b9fd::, constructed for dmz0
Okt 03 04:50:57 rtr dnsmasq-dhcp[11540]: SLAAC-HOSTUNREACH a00:3a::2001:16b8:2284:b9fd
Okt 03 04:50:57 rtr dhcpcd[6467]: dmz0: waiting for DHCPv6 DAD to complete
Okt 03 04:50:57 rtr dhcpcd[6467]: lan0: adding route to 2001:16b8:2284:b9fc::/64
Okt 03 04:50:57 rtr dhcpcd[6467]: dmz0: adding route to 2001:16b8:2284:b9fd::/64
Okt 03 04:50:57 rtr dhcpcd[6467]: wan0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' BOUND6
Okt 03 04:50:58 rtr dhcpcd[6467]: wan0: Router Advertisement DAD completed
Okt 03 04:50:58 rtr dhcpcd[6467]: wan0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' ROUTERADVERT
-----------------

----------------- log 2 ---------------------
Okt 02 04:26:13 rtr dhcpcd[15287]: wan0: unauthenticated RECONFIGURE6 from fe80::7eff:4dff:fe03:2c18
Okt 02 04:26:13 rtr dhcpcd[15287]: wan0: RECONFIGURE6 from fe80::7eff:4dff:fe03:2c18
Okt 02 04:26:13 rtr dhcpcd[15287]: wan0: broadcasting RENEW6 (xid 0x7c8262), next in 9.5 seconds
Okt 02 04:26:13 rtr dhcpcd[15287]: wan0: DHCPv6 REPLY: prefix mismatch
Okt 02 04:26:13 rtr dhcpcd[15287]: lan0: deleting address 2001:16b8:22c3:19fc::1/64
Okt 02 04:26:13 rtr dhcpcd[15287]: lo: deleting reject route to 2001:16b8:22c3:19fc::/62
Okt 02 04:26:13 rtr dhcpcd[15287]: lan0: deleting route to 2001:16b8:22c3:19fc::/64
Okt 02 04:26:13 rtr dhcpcd[15287]: dmz0: deleting address 2001:16b8:22c3:19fd::1/64
Okt 02 04:26:13 rtr dhcpcd[15287]: dmz0: deleting route to 2001:16b8:22c3:19fd::/64
Okt 02 04:26:13 rtr dhcpcd[15287]: wan0: soliciting a DHCPv6 lease
Okt 02 04:26:13 rtr dnsmasq-dhcp[11540]: router advertisement on 2001:16b8:22c3:19fd::, old prefix for dmz0
Okt 02 04:26:13 rtr dnsmasq-dhcp[11540]: router advertisement on 2001:16b8:22c3:19fc::, old prefix for lan0
Okt 02 04:26:13 rtr dhcpcd[15287]: wan0: delaying SOLICIT6 (xid 0xe758a9), next in 0.3 seconds
Okt 02 04:26:13 rtr dnsmasq-dhcp[11540]: no address range available for DHCPv6 request via lan0
Okt 02 04:26:13 rtr dnsmasq-dhcp[11540]: no address range available for DHCPv6 request via lan0
Okt 02 04:26:13 rtr dnsmasq-dhcp[11540]: no address range available for DHCPv6 request via dmz0
Okt 02 04:26:14 rtr dhcpcd[15287]: wan0: broadcasting SOLICIT6 (xid 0xe758a9), next in 1.0 seconds
Okt 02 04:26:14 rtr dhcpcd[15287]: wan0: SOL_MAX_RT 3600 -> 3600
Okt 02 04:26:14 rtr dhcpcd[15287]: wan0: INF_MAX_RT 3600 -> 3600
Okt 02 04:26:14 rtr dhcpcd[15287]: wan0: ADV 2001:16b8:2220:4ffc::/62 from fe80::7eff:4dff:fe03:2c18
Okt 02 04:26:14 rtr dhcpcd[15287]: wan0: broadcasting REQUEST6 (xid 0x5e613f), next in 1.0 seconds
Okt 02 04:26:14 rtr dhcpcd[15287]: wan0: REPLY6 received from fe80::7eff:4dff:fe03:2c18
Okt 02 04:26:14 rtr dhcpcd[15287]: wan0: 2001:16b8:22c3:19fc::/62: became stale
Okt 02 04:26:14 rtr dhcpcd[15287]: wan0: renew in 1800, rebind in 2880, expire in 7200 seconds
Okt 02 04:26:14 rtr dhcpcd[15287]: lo: adding reject route to 2001:16b8:2220:4ffc::/62
Okt 02 04:26:14 rtr dhcpcd[15287]: wan0: writing lease `/var/db/dhcpcd/wan0.lease6'
Okt 02 04:26:14 rtr dhcpcd[15287]: wan0: delegated prefix 2001:16b8:2220:4ffc::/62
Okt 02 04:26:14 rtr dhcpcd[15287]: lan0: adding address 2001:16b8:2220:4ffc::1/64
Okt 02 04:26:14 rtr dhcpcd[15287]: lan0: pltime 3600 seconds, vltime 7200 seconds
Okt 02 04:26:14 rtr dhcpcd[15287]: lan0: waiting for DHCPv6 DAD to complete
Okt 02 04:26:14 rtr dhcpcd[15287]: dmz0: adding address 2001:16b8:2220:4ffd::1/64
Okt 02 04:26:14 rtr dhcpcd[15287]: dmz0: pltime 3600 seconds, vltime 7200 seconds
Okt 02 04:26:14 rtr dhcpcd[15287]: dmz0: waiting for DHCPv6 DAD to complete
Okt 02 04:26:14 rtr dhcpcd[15287]: lan0: adding route to 2001:16b8:2220:4ffc::/64
Okt 02 04:26:14 rtr dnsmasq-dhcp[11540]: router advertisement on 2001:16b8:2220:4ffc::, old prefix for lan0
Okt 02 04:26:14 rtr dnsmasq-dhcp[11540]: DHCPv6 stateless on 2001:16b8:2220:4ffc::, constructed for lan0
Okt 02 04:26:14 rtr dnsmasq-dhcp[11540]: DHCPv4-derived IPv6 names on 2001:16b8:2220:4ffc::, constructed for lan0
Okt 02 04:26:14 rtr dnsmasq-dhcp[11540]: router advertisement on 2001:16b8:2220:4ffc::, constructed for lan0
Okt 02 04:26:14 rtr dnsmasq-dhcp[11540]: router advertisement on 2001:16b8:2220:4ffd::, old prefix for dmz0
Okt 02 04:26:14 rtr dnsmasq-dhcp[11540]: DHCPv6 stateless on 2001:16b8:2220:4ffd::, constructed for dmz0
Okt 02 04:26:14 rtr dnsmasq-dhcp[11540]: DHCPv4-derived IPv6 names on 2001:16b8:2220:4ffd::, constructed for dmz0
Okt 02 04:26:14 rtr dnsmasq-dhcp[11540]: router advertisement on 2001:16b8:2220:4ffd::, constructed for dmz0
Okt 02 04:26:14 rtr dhcpcd[15287]: dmz0: adding route to 2001:16b8:2220:4ffd::/64
Okt 02 04:26:14 rtr dhcpcd[15287]: wan0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' BOUND6
Okt 02 04:26:14 rtr dhcpcd[15287]: wan0: Router Advertisement DAD completed
Okt 02 04:26:14 rtr dhcpcd[15287]: wan0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' ROUTERADVERT
-----------------


Best Regards,
--
Andrey Vakhitov

E-Mail:  andrey at vakhitov.net            Stuttgart, Germany






More information about the Dnsmasq-discuss mailing list