dhcpcd-discuss

On Mon, 2019-10-21 at 00:04 +0200, Floris Bos wrote:
> On 10/19/19 1:14 PM, Floris Bos wrote:
> > There seems to be a problem in which a network interface is
> > sometimes 
> > not get assigned an IPv6 link local address if the network
> > interface 
> > goes quickly up -> down -> up again. 
> 
> Some more information:
> 
> 
> Played a bit with adding a couple more debug logging statements to
> the code.
> 
> 
> The problem seems to be that after the link local address is added,
> the 
> kernel eventually sends you a RTM_NEWADDR event.
> Upon receipt of the event you add the IPv6 address to your state-
> >addrs 
> list.
> After it gets removed the kernel eventually sends a RTM_DELADDR and
> you 
> remove it again from the list.
> 
> The problem is that those events arrive delayed, and we are hitting
> a 
> situation in which the RTM_NEWADDR event is not delivered until
> after 
> the address has been deleted. And RTM_DELADDR is even lagging
> further 
> behind.

Just an anecdote, but I have seen this on fedora running kernel 5.2.x
and later.

Using just the 'ip monitor' (or rtmon), the response delay can be in
the high single digit minutes range, then a group of them come through
at once.

Did not attempt to debug, just stopped using them.


> 
> Since state->addr still has the address in the list, 
> ipv6_tryaddlinklocal() thinks there is already a link local address,
> so 
> does no attempt to add one.
> 
> ==
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: interface added
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: executing 
> `/libexec/dhcpcd-run-hooks' PREINIT
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: executing 
> `/libexec/dhcpcd-run-hooks' NOCARRIER
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: waiting for carrier
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: carrier acquired
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: executing 
> `/libexec/dhcpcd-run-hooks' CARRIER
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: IAID 60:99:b3:1e
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: adding address 
> fe80::62c8:16be:6909:4f84
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: pltime infinity,
> vltime 
> infinity
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: delaying IPv6 router 
> solicitation for 1.0 seconds
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: delaying IPv4 for 0.9
> seconds
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: carrier lost
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: executing 
> `/libexec/dhcpcd-run-hooks' NOCARRIER
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: deleting address 
> fe80::62c8:16be:6909:4f84
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: cmd 20 addr 
> fe80::62c8:16be:6909:4f84 addrflags 192
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: carrier acquired
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: executing 
> `/libexec/dhcpcd-run-hooks' CARRIER
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: IAID 60:99:b3:1e
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: ipv6_tryaddlinklocal: 
> ipv6_iffindaddr() did not return null
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: delaying IPv6 router 
> solicitation for 0.9 seconds
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: delaying IPv4 for 0.4
> seconds
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: cmd 21 addr 
> fe80::62c8:16be:6909:4f84 addrflags 192
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: using ClientID 
> 01:fa:00:60:99:b3:1e
> Oct 20 22:44:00 raspberrypi dhcpcd[385]: usb0: soliciting a DHCP
> lease
> ==
> 
> 
> Yours sincerely,
> 
> 
> Floris Bos
> 
> 
>