PD prefix not deconfigured upon dhcpcd release action
Hello,
I'd like to report the following behavior from dhcpcd.
dhcpcd is facing my ISP. Two days ago, I encountered a situation of a connectivity failure with that ISP. It was detected by the "manager" script controlling dhcpcd, which instructed dhcpcd to release/exit (dhcpcd -k) and restart 20 secs later (dhcpcd -b -f xxxx).
Here is the issue : despite dhcpcd advertising (in logs) it deconfigured the old IPv6 prefix from the LAN interface (br0), it actually did not happen at the OS level. After dhcpcd restarted, 'ip address show dev br0' was showing addresses from both the obsolete prefix 2a01:cb04:a67:4fe2::/64 and the new one 2a01:cb04:a46:cd97::/64.
As a result, radvd was serving both and LAN devices were facing IPv6 connectivity issues.
Any clue about what could be the reason for this behavior ? Unfortunately, I was not monitoring netlink messages when this happened.
Note that I cannot reproduce this exact scenario at will. In the below logs, you see the delegated v6 prefix and IPv4 address both changed after dhcpcd was restarted. It means some kind of maintenance/change was carried out in the ISP's network since when I trigger a failure myself, I'm assigned the same prefix and IP address (even with lease file deleted prior to starting dhcpcd).
Thank you.
dhcpcd logs and config below.
Dec 28 00:59:14 [950]: eno1.832: Router Advertisement from fe80::ba0:bab
Dec 28 00:59:14 [950]: eno1.832: executing: /usr/local/libexec/dhcpcd-run-hooks ROUTERADVERT
Dec 28 01:03:44 [950]: received SIGALRM, releasing
Dec 28 01:03:44 [950]: eno1.832: removing interface
Dec 28 01:03:44 [950]: br0: deleting address 2a01:cb04:a67:4fe2::1/64
Dec 28 01:03:44 [950]: br0: deleting route to 2a01:cb04:a67:4fe2::/64
Dec 28 01:03:44 [950]: eno1.832: multicasting RELEASE6 (xid 0xe5eac3), next in 1.0 seconds
Dec 28 01:03:44 [950]: lo: deleting reject route to 2a01:cb04:a67:4f00::/56
Dec 28 01:03:44 [950]: eno1.832: executing: /usr/local/libexec/dhcpcd-run-hooks RELEASE6
Dec 28 01:03:44 [950]: eno1.832: deleting default route via fe80::ba0:bab
Dec 28 01:03:44 [950]: eno1.832: executing: /usr/local/libexec/dhcpcd-run-hooks ROUTERADVERT
Dec 28 01:03:44 [950]: eno1.832: releasing lease of 92.169.17.68
Dec 28 01:03:44 [950]: eno1.832: sending RELEASE with xid 0x5e05aa63
Dec 28 01:03:44 [950]: eno1.832: deleting IP address 92.169.17.68/22
Dec 28 01:03:44 [950]: eno1.832: deleting route to 92.169.16.0/22
Dec 28 01:03:44 [950]: eno1.832: deleting default route via 92.169.16.1
Dec 28 01:03:44 [950]: eno1.832: executing: /usr/local/libexec/dhcpcd-run-hooks STOP
Dec 28 01:03:44 [950]: eno1.832: executing: /usr/local/libexec/dhcpcd-run-hooks STOPPED
Dec 28 01:03:44 [950]: br0: removing interface
Dec 28 01:03:44 [950]: br0: executing: /usr/local/libexec/dhcpcd-run-hooks STOPPED
Dec 28 01:03:44 [950]: dhcpcd exited
Dec 28 01:04:04 [111426]: no such user dhcpcd
Dec 28 01:04:04 [111426]: dhcpcd-10.0.3 starting
Dec 28 01:04:04 [111428]: spawned manager process on PID 111428
Dec 28 01:04:04 [111428]: DUID #removed#
Dec 28 01:04:04 [111428]: eno1.832: executing: /usr/local/libexec/dhcpcd-run-hooks PREINIT
Dec 28 01:04:04 [111428]: eno1.832: executing: /usr/local/libexec/dhcpcd-run-hooks CARRIER
Dec 28 01:04:04 [111428]: eno1.832: IAID #removed#
Dec 28 01:04:04 [111428]: eno1.832: delaying IPv6 router solicitation for 1.0 seconds
Dec 28 01:04:04 [111428]: eno1.832: reading lease: /var/db/dhcpcd/eno1.832.lease6
Dec 28 01:04:04 [111428]: eno1.832: soliciting a DHCPv6 lease
Dec 28 01:04:04 [111428]: eno1.832: delaying SOLICIT6 (xid 0x69bb49), next in 1.0 seconds
Dec 28 01:04:04 [111428]: br0: activating for delegation
Dec 28 01:04:04 [111428]: br0: executing: /usr/local/libexec/dhcpcd-run-hooks PREINIT
Dec 28 01:04:04 [111428]: br0: executing: /usr/local/libexec/dhcpcd-run-hooks CARRIER
Dec 28 01:04:04 [111428]: br0: IAID #removed#
Dec 28 01:04:04 [111428]: eno1.832: delaying IPv4 for 1.6 seconds
Dec 28 01:04:05 [111428]: eno1.832: soliciting an IPv6 router
Dec 28 01:04:05 [111428]: eno1.832: sending Router Solicitation
Dec 28 01:04:05 [111428]: eno1.832: multicasting SOLICIT6 (xid 0x69bb49), next in 1.0 seconds
Dec 28 01:04:05 [111428]: eno1.832: validated using 0x00001110
Dec 28 01:04:05 [111428]: eno1.832: ADV 2a01:cb04:a46:cd00::/56 from fe80::ba0:bab
Dec 28 01:04:05 [111428]: eno1.832: multicasting REQUEST6 (xid 0x9a84fc), next in 1.1 seconds
Dec 28 01:04:05 [111428]: eno1.832: validated using 0x00001110
Dec 28 01:04:05 [111428]: eno1.832: REPLY6 received from fe80::ba0:bab
Dec 28 01:04:05 [111428]: eno1.832: renew in 72877, rebind in 483840, expire in 604800 seconds
Dec 28 01:04:05 [111428]: lo: adding reject route to 2a01:cb04:a46:cd00::/56
Dec 28 01:04:05 [111428]: eno1.832: writing lease: /var/db/dhcpcd/eno1.832.lease6
Dec 28 01:04:05 [111428]: eno1.832: delegated prefix 2a01:cb04:a46:cd00::/56
Dec 28 01:04:05 [111428]: br0: adding address 2a01:cb04:a46:cd97::1/64
Dec 28 01:04:05 [111428]: br0: pltime 604800 seconds, vltime 604800 seconds
Dec 28 01:04:05 [111428]: br0: waiting for DHCPv6 DAD to complete
Dec 28 01:04:05 [111428]: br0: adding route to 2a01:cb04:a46:cd97::/64
Dec 28 01:04:05 [111428]: eno1.832: executing: /usr/local/libexec/dhcpcd-run-hooks BOUND6
Dec 28 01:04:05 [111428]: eno1.832: Router Advertisement from fe80::ba0:bab
Dec 28 01:04:05 [111428]: eno1.832: adding default route via fe80::ba0:bab
Dec 28 01:04:05 [111428]: eno1.832: executing: /usr/local/libexec/dhcpcd-run-hooks ROUTERADVERT
Dec 28 01:04:05 [111428]: eno1.832: No DHCPv6 instruction in RA
Dec 28 01:04:06 [111428]: eno1.832: using ClientID #removed#
Dec 28 01:04:06 [111428]: eno1.832: reading lease: /var/db/dhcpcd/eno1.832.lease
Dec 28 01:04:06 [111428]: eno1.832: soliciting a DHCP lease
Dec 28 01:04:06 [111428]: eno1.832: sending DISCOVER (xid 0xc1765503), next in 3.9 seconds
Dec 28 01:04:06 [111428]: eno1.832: validated using 0x00001110
Dec 28 01:04:06 [111428]: eno1.832: offered 86.247.218.206 from 80.10.252.73
Dec 28 01:04:06 [111428]: eno1.832: sending REQUEST (xid 0xc1765503), next in 4.1 seconds
Dec 28 01:04:06 [111428]: eno1.832: validated using 0x00001110
Dec 28 01:04:06 [111428]: eno1.832: acknowledged 86.247.218.206 from 80.10.252.73
Dec 28 01:04:06 [111428]: eno1.832: leased 86.247.218.206 for 604800 seconds
Dec 28 01:04:06 [111428]: eno1.832: renew in 72877 seconds, rebind in 483840 seconds
Dec 28 01:04:06 [111428]: eno1.832: writing lease: /var/db/dhcpcd/eno1.832.lease
Dec 28 01:04:06 [111428]: eno1.832: adding IP address 86.247.218.206/21 broadcast 86.247.223.255
Dec 28 01:04:06 [111428]: eno1.832: adding route to 86.247.216.0/21
Dec 28 01:04:06 [111428]: eno1.832: adding default route via 86.247.216.1
Dec 28 01:04:06 [111428]: eno1.832: executing: /usr/local/libexec/dhcpcd-run-hooks BOUND
Dec 28 01:04:07 [111428]: br0: DHCPv6 DAD completed
Dec 28 01:04:07 [111428]: br0: executing: /usr/local/libexec/dhcpcd-run-hooks DELEGATED6
Dec 28 01:26:56 [111428]: eno1.832: Router Advertisement from fe80::ba0:bab
Dec 28 01:26:56 [111428]: eno1.832: executing: /usr/local/libexec/dhcpcd-run-hooks ROUTERADVERT
Config :
noipv4ll
nohook hostname resolv.conf timesyncd.conf
allowinterfaces eno1.832
debug
logfile /var/log/dhcpcd.log
noauthrequired
noarp
noipv6rs
interface eno1.832
iaid #removed#
ipv6rs
ia_pd #removed# br0//64
clientid
userclass FSVDSL_livebox.Internet.softathome.Livebox4
vendclass 1038 sagem
vendorclassid sagem
broadcast
option subnet_mask routers domain_name_servers domain_name broadcast_address dhcp_lease_time dhcp_renewal_time dhcp_rebinding_time domain_search sip_server 125 auth
option dhcp6_vivso dhcp6_name_servers dhcp6_domain_search dhcp6_auth
nooption 33 57
authprotocol token 0x123/0x456
authtoken 0x456 "" forever 64:68:63:70:6c:69:76:65:62:6f:78:66:72:32:35:30
authtoken 0x123 "" forever 1a:09:00:00:05:58:01:03:41:#removed#
interface br0
nolink
Wondering whether it could be related to privacy extensions. The corresponding IP address is not deleted on br0 when dhcpcd releases the prefix. As a result, radvd may still advertise it.
use_tempaddr is set to 0 on all interfaces. Looks like this parameter doesn't control whether a temporary address is generated or not, only whether it shall be used or not.
Should dhcpcd delete such an address when it releases a prefix ?
Set net.ipv6.conf.${IFACE}.autoconf=0 as a workaround.
@rsmarples This matches what I often encounter upon reboot. Since the PD is not released, I sometimes fail to get a prefix after rebooting.