dhcpcd receives IA_PD and configures interfaces, but times out anyway
Not sure whether it's a bug or a feature or just a misconfiguration...
Summary
I have a Linux router that receives IPv6 IA_PD prefix (/56), dhcpcd runs hooks as it's supposed to and generally everything works as intended, but logs show "timed out". Fortunately, dhcpcd does not exit after that, just keeps running in the background.
Is there a configuration option I'm missing?
Expected behavior
dhcpcd does not show "timed out" in logs.
Off-topic: That log message should be more verbose (what exactly timed out?).
Actual behavior
The "timed out" error message shows up in dhcpcd log, even though IA_PD has been received.
My setup
pppd connects via PPPoE to my ISP and runs dhcpcd -6 ppp1 via a hook. My ISP only provides IA_PD (no IA_NA or /128 address via DHCPv6). Configuration:
#/etc/dhcpcd.conf
# Arch stock config options here
ipv6only
noipv6rs
denyinterfaces ens4
interface ppp1
ipv6rs
iaid 1
ia_pd 1/::/56 ens4/2/64
OS: Arch Linux dhcpcd version: 10.2.4
Log (sensitive parts redacted):
lis 12 01:57:12 router dhcpcd[434]: dhcpcd-10.2.4 starting
lis 12 01:57:12 router dhcpcd[440]: DUID 00:01:03:04:xx:xx:xx:xx:xx:xx:00:00:00:00
lis 12 01:57:13 router dhcpcd[440]: ppp1: IAID 00:00:xx:xx
lis 12 01:57:13 router dhcpcd[440]: ppp1: rebinding prior DHCPv6 lease
lis 12 01:57:13 router dhcpcd[440]: ens4: activating for delegation
lis 12 01:57:13 router dhcpcd[440]: ens4: IAID 9d:1d:xx:xx
lis 12 01:57:13 router dhcpcd[440]: ppp1: soliciting an IPv6 router
lis 12 01:57:13 router dhcpcd[440]: ppp1: Router Advertisement from fe80::f21c:2dff:fe2a:85c2
lis 12 01:57:13 router dhcpcd[440]: lo: adding reject route to 2a01:110f:xxxx:xx00::/56
lis 12 01:57:13 router dhcpcd[440]: ppp1: adding default route via fe80::f21c:2dff:fe2a:85c2
lis 12 01:57:23 router dhcpcd[440]: ppp1: failed to rebind prior DHCPv6 delegation
lis 12 01:57:25 router dhcpcd[440]: ppp1: ADV 2a01:110f:xxxx:xx00::/56 from fe80::f21c:2dff:fe2a:85c2 (0)
lis 12 01:57:26 router dhcpcd[440]: ppp1: REPLY6 received from fe80::f21c:2dff:fe2a:85c2
lis 12 01:57:26 router dhcpcd[440]: ppp1: renew in 43200, rebind in 69120, expire in 86400 seconds
lis 12 01:57:26 router dhcpcd[440]: ppp1: delegated prefix 2a01:110f:xxxx:xx00::/56
lis 12 01:57:26 router dhcpcd[440]: ens4: adding address 2a01:110f:xxxx:xx02::1/64
lis 12 01:57:26 router dhcpcd[440]: ens4: adding route to 2a01:110f:xxxx:xx02::/64
lis 12 01:57:43 router dhcpcd[440]: timed out
It might be due to how you're starting dhcpcd.
Try changing your dhcpcd.conf from denyinterfaces ens4 to allowinterfaces ppp1 and the start dhcpcd without any interface specified on the command line.
It should detect when ppp1 connects and then start working rather than ppp1 saying to start dhcpcd. Let me know!
Well, I have made the proposed change and now I have two errors an one warning in my log instead of one error... Current config:
# Stock part here
# ...
ipv6only
noipv6rs
allowinterfaces ppp1
interface ppp1
ipv6rs
iaid 1
ia_pd 1/::/56 ens4/2/64 ens5/3/64
The log shows:
lis 23 01:58:47 router dhcpcd[287]: no valid interfaces found
# ERROR
lis 23 01:58:47 router dhcpcd[287]: no valid interfaces found
# WARNING
lis 23 01:58:47 router dhcpcd[287]: no interfaces have a carrier
lis 23 01:58:49 router dhcpcd[287]: ppp1: waiting for carrier
lis 23 01:58:49 router dhcpcd[287]: ppp1: carrier acquired
lis 23 01:58:49 router dhcpcd[287]: ppp1: IAID 00:00:00:01
lis 23 01:58:49 router dhcpcd[287]: ppp1: rebinding prior DHCPv6 lease
lis 23 01:58:49 router dhcpcd[287]: ens4: activating for delegation
lis 23 01:58:49 router dhcpcd[287]: ens4: IAID 9d:xx:xx:xx
lis 23 01:58:49 router dhcpcd[287]: ens5: activating for delegation
lis 23 01:58:49 router dhcpcd[287]: ens5: IAID 9d:xx:xx:xx
lis 23 01:58:49 router dhcpcd[287]: ppp1: soliciting an IPv6 router
lis 23 01:58:49 router dhcpcd[287]: ppp1: Router Advertisement from fe80::f21c:2dff:fe2a:85c3
lis 23 01:58:49 router dhcpcd[287]: lo: adding reject route to 2a01:110f:xxxx:xx00::/56
lis 23 01:58:49 router dhcpcd[287]: ppp1: adding default route via fe80::f21c:2dff:fe2a:85c3
lis 23 01:58:59 router dhcpcd[287]: ppp1: failed to rebind prior DHCPv6 delegation
# ERROR
lis 23 01:58:59 router dhcpcd[287]: ppp1: failed to rebind prior DHCPv6 delegation
lis 23 01:59:01 router dhcpcd[287]: ppp1: ADV 2a01:110f:xxxx:xx00::/56 from fe80::f21c:2dff:fe2a:85c3 (0)
lis 23 01:59:02 router dhcpcd[287]: ppp1: REPLY6 received from fe80::f21c:2dff:fe2a:85c3
lis 23 01:59:02 router dhcpcd[287]: ppp1: renew in 43200, rebind in 69120, expire in 86400 seconds
lis 23 01:59:02 router dhcpcd[287]: ppp1: delegated prefix 2a01:110f:xx:xx00::/56
lis 23 01:59:02 router dhcpcd[287]: ens4: adding address 2a01:110f:xxxx:xx02::1/64
lis 23 01:59:02 router dhcpcd[287]: ens5: adding address 2a01:110f:xxxx:xx03::1/64
lis 23 01:59:02 router dhcpcd[287]: ens4: adding route to 2a01:110f:xxxx:xx02::/64
lis 23 01:59:02 router dhcpcd[287]: ens5: adding route to 2a01:110f:xxxx:xx03::/64
This configuration seems to work exactly the same as the previous one (although during testing either ens4 or ens5 got second link-local address assigned - not the case any more after a reboot).
Although in my case the dhcpcd needs to run all the time anyway, in other scenarios it may be favourable to run it only when bringing up some interface - as was the case with my previous configuration. In my opinion that timeout is a bug - which seemed harmless, but it's hard for me to be certain.
Running dhcpcd post-connect should be a supported scenario. Expected behaviour then should be to not generate timeout errors.