dhcpcd-discuss

Re: allowinterfaces cause ipv6 pd to ignore the FIRST interface

Peng Shao

Sat Jan 30 00:37:46 2016

Thank you so much for the quick reply. I just did the test again and I
would like to paste the log here so you may have a better idea what is
really going on.I also did test against dhcpcd-6.9.0 but it seemed to
suffer from the same issue. Earlier versions cannot be compiled due to some
error.

I am not quite so sure if it is a multi-NIC thing as even if I asked dhcpcd
to do delegation to only one interface it still ignores it. So in a summary
it will simply ignore the first NIC it sees, no matter if it is the only
one or not.

All the following tests are able to replicate every time. Also, would it be
possible an interface-name thing? My NICs are named under the persistent
rule, enp(bus numer)s(slot) instead of ethX thing. During the early report
I was a little too lazy to type those names in the email so I simply used
eth0, ... as the names for the NICs, thinking that it should be irrelevant
at all. But just in case...

Background: enp4s0 (WAN), enp6s0 (LAN, with cable plugged in), enp8s0,
enp9s0 (currently not in use with no cable plugged in, but they all have
static IPs)

Config 1.
~~~~~~~~~~~~~~~~~~~~~~~~~~~
debug
slaac private # My ISP only answers to me if I have this enabled, a little
weird.
allowinterfaces enp4s0
noipv6rs
interface enp4s0
ipv6rs
ia_na 1
ia_pd 2/::/56 enp6s0/1/64 enp8s0/2/64 enp9s0/3/64
~~~~~~~~~~~~~~~~~~~~~~~~~~~

Result 1.
~~~~~~~~~~~~~~~~~~~~~~~~~~~
dhcpcd-6.10.1 starting
dev: loaded udev
enp4s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' PREINIT
enp4s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' CARRIER
DUID 00:01:00:01:1e:0b:f6:92:00:30:18:c7:ac:af
enp4s0: IAID 18:c7:ac:ad
enp4s0: IAID 00:00:00:01
enp4s0: IAID 00:00:00:02
enp4s0: delaying IPv6 router solicitation for 0.4 seconds
enp4s0: reading lease `/var/lib/dhcpcd/dhcpcd-enp4s0.lease6'
enp4s0: rebinding prior DHCPv6 lease
enp4s0: delaying REBIND6 (xid 0xa7d44d), next in 0.9 seconds
enp4s0: delaying IPv4 for 0.2 seconds
enp4s0: using hwaddr 00:30:18:c7:ac:ad
enp4s0: reading lease `/var/lib/dhcpcd/dhcpcd-enp4s0.lease'
enp4s0: rebinding lease of 74.69.187.43
enp4s0: sending REQUEST (xid 0x9296a5d3), next in 3.8 seconds
enp4s0: acknowledged 74.69.187.43 from 142.254.214.145
enp4s0: probing address 74.69.187.43/21
enp4s0: probing for 74.69.187.43
enp4s0: ARP probing 74.69.187.43 (1 of 3), next in 1.7 seconds
enp4s0: soliciting an IPv6 router
enp4s0: sending Router Solicitation
enp4s0: Router Advertisement from fe80::201:5cff:fe64:9246
enp4s0: adding default route via fe80::201:5cff:fe64:9246
enp4s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' ROUTERADVERT
enp4s0: broadcasting REBIND6 (xid 0xa7d44d), next in 1.1 seconds
enp4s0: REPLY6 received from fe80::201:5cff:fe64:9246
enp4s0: adding address 2604:6000:dfc0:27:11ea:f5cb:f9e4:113e/128
enp4s0: pltime 604797 seconds, vltime 604797 seconds
enp8s0: activating for delegation
enp8s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' PREINIT
enp8s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' NOCARRIER
enp8s0: waiting for carrier
enp9s0: activating for delegation
enp9s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' PREINIT
enp9s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' NOCARRIER
enp9s0: waiting for carrier
enp4s0: delegated prefix 2604:6000:d9c5:5400::/56
enp8s0: has no carrier, cannot delegate addresses
enp9s0: has no carrier, cannot delegate addresses
enp4s0: renew in 302398 seconds, rebind in 483837 seconds
enp4s0: adding reject route to 2604:6000:d9c5:5400::/56 via ::1
enp4s0: writing lease `/var/lib/dhcpcd/dhcpcd-enp4s0.lease6'
enp4s0: waiting for DHCPv6 DAD to complete
enp4s0: ARP probing 74.69.187.43 (2 of 3), next in 1.8 seconds
enp4s0: DHCPv6 DAD completed
enp4s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' REBIND6
forking to background
forked to background, child pid 367
~~~~~~~~~~~~~~~~~~~~~~~~~~
Comment: enp8s0 and enp9s0 work fine after I plug a cable into them,
nothing is shown for enp6s0 no matter what I do.


Config 2.
~~~~~~~~~~~~~~~~~~~~~~~~~

debug
slaac private

allowinterfaces enp4s0
noipv6rs

interface enp4s0
ipv6rs
ia_na 1
ia_pd 2/::/56 enp8s0/2/64 enp6s0/1/64  enp9s0/3/64
~~~~~~~~~~~~~~~~~~~~~~~~~


Result 2.
~~~~~~~~~~~~~~~~~~~~~~~~~
dhcpcd-6.10.1 starting
dev: loaded udev
enp4s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' PREINIT
enp4s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' CARRIER
DUID 00:01:00:01:1e:0b:f6:92:00:30:18:c7:ac:af
enp4s0: IAID 18:c7:ac:ad
enp4s0: IAID 00:00:00:01
enp4s0: IAID 00:00:00:02
enp4s0: delaying IPv6 router solicitation for 0.7 seconds
enp4s0: reading lease `/var/lib/dhcpcd/dhcpcd-enp4s0.lease6'
enp4s0: rebinding prior DHCPv6 lease
enp4s0: delaying REBIND6 (xid 0x29e520), next in 0.3 seconds
enp4s0: delaying IPv4 for 0.0 seconds
enp4s0: using hwaddr 00:30:18:c7:ac:ad
enp4s0: reading lease `/var/lib/dhcpcd/dhcpcd-enp4s0.lease'
enp4s0: rebinding lease of 74.69.187.43
enp4s0: sending REQUEST (xid 0x19a91b6d), next in 4.9 seconds
enp4s0: acknowledged 74.69.187.43 from 142.254.214.145
enp4s0: probing address 74.69.187.43/21
enp4s0: probing for 74.69.187.43
enp4s0: ARP probing 74.69.187.43 (1 of 3), next in 1.8 seconds
enp4s0: broadcasting REBIND6 (xid 0x29e520), next in 1.0 seconds
enp4s0: REPLY6 received from fe80::201:5cff:fe64:9246
enp4s0: adding address 2604:6000:dfc0:27:11ea:f5cb:f9e4:113e/128
enp4s0: pltime 604800 seconds, vltime 604800 seconds
enp6s0: activating for delegation
enp6s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' PREINIT
enp6s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' CARRIER
enp6s0: IAID 18:c7:ac:ae
enp6s0: adding delegated prefixes
enp6s0: adding address 2604:6000:d9c5:5401::1/64
enp6s0: pltime 604800 seconds, vltime 604800 seconds
enp4s0: adding reject route to 2604:6000:d9c5:5400::/56 via ::1
enp6s0: adding route to 2604:6000:d9c5:5401::/64
enp6s0: waiting for DHCPv6 DAD to complete
enp6s0: delaying IPv4 for 0.8 seconds
enp9s0: activating for delegation
enp9s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' PREINIT
enp9s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' NOCARRIER
enp9s0: waiting for carrier
enp4s0: delegated prefix 2604:6000:d9c5:5400::/56
enp6s0: adding address 2604:6000:d9c5:5401::1/64
enp6s0: pltime 604800 seconds, vltime 604800 seconds
enp6s0: waiting for DHCPv6 DAD to complete
enp9s0: has no carrier, cannot delegate addresses
enp4s0: renew in 302400 seconds, rebind in 483840 seconds
enp4s0: writing lease `/var/lib/dhcpcd/dhcpcd-enp4s0.lease6'
enp4s0: waiting for DHCPv6 DAD to complete
enp4s0: soliciting an IPv6 router
enp4s0: sending Router Solicitation
enp6s0: using hwaddr 00:30:18:c7:ac:ae
enp6s0: soliciting a DHCP lease
enp6s0: sending DISCOVER (xid 0x7dd4473), next in 4.0 seconds
enp4s0: Router Advertisement from fe80::201:5cff:fe64:9246
enp4s0: adding default route via fe80::201:5cff:fe64:9246
enp4s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' ROUTERADVERT
enp6s0: DHCPv6 DAD completed
enp6s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' DELEGATED6
enp4s0: DHCPv6 DAD completed
enp4s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' REBIND6
forking to background
forked to background, child pid 764
~~~~~~~~~~~~~~~~~~~~~~~
Comment: So as you can see, this time enp8s0 is gone....



Config 3.
~~~~~~~~~~~~~~~~~~~~~~~

debug
slaac private

allowinterfaces enp4s0
noipv6rs

interface enp4s0
ipv6rs
ia_na 1
ia_pd 2/::/56 enp8s0/2/64
~~~~~~~~~~~~~~~~~~~~~~~

Result 3.
~~~~~~~~~~~~~~~~~~~~~~~
dhcpcd-6.10.1 starting
dev: loaded udev
enp4s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' PREINIT
enp4s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' CARRIER
DUID 00:01:00:01:1e:0b:f6:92:00:30:18:c7:ac:af
enp4s0: IAID 18:c7:ac:ad
enp4s0: IAID 00:00:00:01
enp4s0: IAID 00:00:00:02
enp4s0: delaying IPv6 router solicitation for 0.2 seconds
enp4s0: reading lease `/var/lib/dhcpcd/dhcpcd-enp4s0.lease6'
enp4s0: rebinding prior DHCPv6 lease
enp4s0: delaying REBIND6 (xid 0x0ffe8d), next in 0.7 seconds
enp4s0: delaying IPv4 for 0.2 seconds
enp4s0: soliciting an IPv6 router
enp4s0: sending Router Solicitation
enp4s0: using hwaddr 00:30:18:c7:ac:ad
enp4s0: reading lease `/var/lib/dhcpcd/dhcpcd-enp4s0.lease'
enp4s0: rebinding lease of 74.69.187.43
enp4s0: sending REQUEST (xid 0xfd97b571), next in 3.3 seconds
enp4s0: acknowledged 74.69.187.43 from 142.254.214.145
enp4s0: probing address 74.69.187.43/21
enp4s0: probing for 74.69.187.43
enp4s0: ARP probing 74.69.187.43 (1 of 3), next in 1.9 seconds
enp4s0: broadcasting REBIND6 (xid 0x0ffe8d), next in 1.1 seconds
enp4s0: REPLY6 received from fe80::201:5cff:fe64:9246
enp4s0: adding address 2604:6000:dfc0:27:11ea:f5cb:f9e4:113e/128
enp4s0: pltime 604800 seconds, vltime 604800 seconds
enp4s0: delegated prefix 2604:6000:d9c5:5400::/56
enp4s0: renew in 302400 seconds, rebind in 483840 seconds
enp4s0: adding reject route to 2604:6000:d9c5:5400::/56 via ::1
enp4s0: writing lease `/var/lib/dhcpcd/dhcpcd-enp4s0.lease6'
enp4s0: waiting for DHCPv6 DAD to complete
enp4s0: ARP probing 74.69.187.43 (2 of 3), next in 1.9 seconds
enp4s0: DHCPv6 DAD completed
enp4s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' REBIND6
forking to background
forked to background, child pid 1050
~~~~~~~~~~~~~~~~~~~~~~~
Comment: As you can see, enp8s0 is still ignore completely. Using enp6s0 as
the only PD interface still shows nothing



I then did another test with a "dummy" interface inserted immediately
2/::/56, notice that enp5s0 does NOT exist on my machine

Config 4.
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
debug
slaac private

allowinterfaces enp4s0
noipv6rs

interface enp4s0
ipv6rs
ia_na 1
ia_pd 2/::/56 enp5s0/5/64 enp8s0/2/64 enp6s0/1/64  enp9s0/3/64
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

Result 4.
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

dhcpcd-6.10.1 starting
dev: loaded udev
enp4s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' PREINIT
enp4s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' CARRIER
DUID 00:01:00:01:1e:0b:f6:92:00:30:18:c7:ac:af
enp4s0: IAID 18:c7:ac:ad
enp4s0: IAID 00:00:00:01
enp4s0: IAID 00:00:00:02
enp4s0: delaying IPv6 router solicitation for 0.7 seconds
enp4s0: reading lease `/var/lib/dhcpcd/dhcpcd-enp4s0.lease6'
enp4s0: rebinding prior DHCPv6 lease
enp4s0: delaying REBIND6 (xid 0x3e2583), next in 0.6 seconds
enp4s0: delaying IPv4 for 0.6 seconds
enp4s0: reading lease `/var/lib/dhcpcd/dhcpcd-enp4s0.lease'
enp4s0: rebinding lease of 67.252.94.24
enp4s0: sending REQUEST (xid 0xf0400b98), next in 4.5 seconds
enp4s0: invalid UDP packet from 74.125.201.188
enp4s0: broadcasting REBIND6 (xid 0x3e2583), next in 1.1 seconds
enp4s0: REPLY6 received from fe80::201:5cff:fe64:9246
enp4s0: adding address 2604:6000:dfc0:27:11ea:f5cb:f9e4:113e/128
enp4s0: pltime 604800 seconds, vltime 604800 seconds
enp6s0: activating for delegation
enp6s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' PREINIT
enp6s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' CARRIER
enp6s0: IAID 18:c7:ac:ae
enp6s0: adding delegated prefixes
enp6s0: adding address 2604:6000:d9c5:5401::1/64
enp6s0: pltime 604800 seconds, vltime 604800 seconds
enp4s0: adding reject route to 2604:6000:d9c5:5400::/56 via ::1
enp6s0: adding route to 2604:6000:d9c5:5401::/64
enp6s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' DELEGATED6
enp6s0: delaying IPv4 for 0.3 seconds
enp8s0: activating for delegation
enp8s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' PREINIT
enp8s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' NOCARRIER
enp8s0: waiting for carrier
enp9s0: activating for delegation
enp9s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' PREINIT
enp9s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' NOCARRIER
enp9s0: waiting for carrier
vlan100: activating for delegation
vlan100: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' PREINIT
vlan100: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' NOCARRIER
vlan100: waiting for carrier
enp4s0: delegated prefix 2604:6000:d9c5:5400::/56
enp6s0: adding address 2604:6000:d9c5:5401::1/64
enp6s0: pltime 604800 seconds, vltime 604800 seconds
enp6s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' DELEGATED6
enp8s0: has no carrier, cannot delegate addresses
enp9s0: has no carrier, cannot delegate addresses
vlan100: has no carrier, cannot delegate addresses
enp4s0: renew in 302400 seconds, rebind in 483840 seconds
enp4s0: writing lease `/var/lib/dhcpcd/dhcpcd-enp4s0.lease6'
enp4s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' REBIND6
forking to background
forked to background, child pid 1562
~~~~~~~~~~~~~~~~~~~~~~~~~~~
Everything works as expected except of course the dummy variable. To make
sure that it is not a trivial "argument parsing" bug I did another test
with enp100s0, which does not exist of course


Config 5.
~~~~~~~~~~~~~~~~~~~~~~~~~~~
debug
slaac private

allowinterfaces enp4s0
noipv6rs

interface enp4s0
ipv6rs
ia_na 1
ia_pd 2/::/56 enp100s0/5/64 enp8s0/2/64 enp6s0/1/64  enp9s0/3/64
~~~~~~~~~~~~~~~~~~~~~~~~~~~

This time dhcpcd seemed to realize something was wrong with the dummy
interface:

Result 5.
~~~~~~~~~~~~~~~~~~~~~~~~~~
dhcpcd-6.10.1 starting
dev: loaded udev
enp4s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' PREINIT
enp4s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' CARRIER
DUID 00:01:00:01:1e:0b:f6:92:00:30:18:c7:ac:af
enp4s0: IAID 18:c7:ac:ad
enp4s0: IAID 00:00:00:01
enp4s0: IAID 00:00:00:02
enp4s0: delaying IPv6 router solicitation for 0.3 seconds
enp4s0: reading lease `/var/lib/dhcpcd/dhcpcd-enp4s0.lease6'
enp4s0: rebinding prior DHCPv6 lease
enp4s0: delaying REBIND6 (xid 0xa70150), next in 0.8 seconds
enp4s0: delaying IPv4 for 0.5 seconds
enp4s0: soliciting an IPv6 router
enp4s0: sending Router Solicitation
enp4s0: reading lease `/var/lib/dhcpcd/dhcpcd-enp4s0.lease'
enp4s0: rebinding lease of 67.252.94.24
enp4s0: sending REQUEST (xid 0x647c15d6), next in 3.7 seconds
enp4s0: acknowledged 67.252.94.24 from 142.254.214.145
enp4s0: leased 67.252.94.24 for 70755 seconds
enp4s0: renew in 35377 seconds, rebind in 61910 seconds
enp4s0: writing lease `/var/lib/dhcpcd/dhcpcd-enp4s0.lease'
enp4s0: IP address 67.252.94.24/23 already exists
enp4s0: changing route to 67.252.94.0/23
enp4s0: changing default route via 67.252.94.1
enp4s0: ARP announcing 67.252.94.24 (1 of 2), next in 2.0 seconds
enp4s0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' BOUND
forking to background
forked to background, child pid 1903
~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Comment: It stopped once it ran into enp100s0 whose pcie bus number is a
little absurdly large. So I feel like dhcpcd does not "ignore" the first
NIC completely, but for some reason it either does nothing for it and skips
it, or if it is something weird it will spits an error....

Thanks and let me know if you need any further testing.

Peng


On Fri, Jan 29, 2016 at 6:36 PM, Roy Marples <roy@xxxxxxxxxxxx> wrote:

> Hi
>
> On 2016-01-29 09:38, Peng Shao wrote:
>
>> Hi yes I am using 6.10.1 (the latest one). Thanks for the quick reply!
>>
>
> I wasn't able to replicate your exact issue, but my trunk code is not
> working with multiple interfaces to delegate to for some reason.
> Hopefully it's related and I can look at it more over the weekend.
>
> Roy
>

References:
allowinterfaces cause ipv6 pd to ignore the FIRST interfacePeng Shao
Re: allowinterfaces cause ipv6 pd to ignore the FIRST interfaceRoy Marples
Re: allowinterfaces cause ipv6 pd to ignore the FIRST interfacePeng Shao
Re: allowinterfaces cause ipv6 pd to ignore the FIRST interfaceRoy Marples
Archive administrator: postmaster@marples.name