dhcpcd icon indicating copy to clipboard operation
dhcpcd copied to clipboard

DHCP6 rebinding after restart of ppp0 fails.

Open noci2012 opened this issue 1 year ago • 7 comments

after restart of dhcpcd the PD is acquired.

Built on gentoo: [I] net-misc/dhcpcd Available versions: 9.5.1 10.0.6-r2 ~10.0.6-r3 10.0.8{gpkg} **9999*l {debug +embedded ipv6 privsep +udev} Installed versions: 10.0.8{gpkg}(11:15:57 06/25/24)(embedded ipv6 udev -debug -privsep) Homepage: https://github.com/NetworkConfiguration/dhcpcd/ https://roy.marples.name/projects/dhcpcd/ Description: A fully featured, yet light weight RFC2131 compliant DHCP client

Log excerpt:

Aug 29 19:57:33 firewall dhcpcd[3512]: ppp0: invalid state for DHCP6 type ADVERTISE6 (2)
Aug 29 19:57:49 firewall dhcpcd[3512]: ppp0: invalid state for DHCP6 type ADVERTISE6 (2)
Aug 29 19:58:19 firewall dhcpcd[3512]: ppp0: invalid state for DHCP6 type ADVERTISE6 (2)
Aug 29 19:59:15 firewall dhcpcd[3512]: ppp0: invalid state for DHCP6 type ADVERTISE6 (2)
Aug 29 20:01:02 firewall dhcpcd[3512]: ppp0: invalid state for DHCP6 type ADVERTISE6 (2)
Aug 29 20:04:05 firewall dhcpcd[1375]: sending commands to dhcpcd process
Aug 29 20:04:05 firewall dhcpcd[3512]: control command: dhcpcd -n ppp0
Aug 29 20:04:05 firewall dhcpcd[3512]: ppp0: soliciting a DHCPv6 lease
Aug 29 20:04:05 firewall dhcpcd[3512]: ppp0: IAID 00:00:00:01
Aug 29 20:04:05 firewall dhcpcd[3512]: ppp0: IA type 25 IAID 00:00:00:0c
Aug 29 20:04:05 firewall dhcpcd[3512]: ppp0: IA type 25 IAID 00:00:00:f2
Aug 29 20:04:07 firewall dhcpcd[3512]: ppp0: invalid state for DHCP6 type ADVERTISE6 (2)
Aug 29 20:04:08 firewall dhcpcd[3512]: ppp0: invalid state for DHCP6 type ADVERTISE6 (2)
Aug 29 20:04:11 firewall dhcpcd[3512]: ppp0: invalid state for DHCP6 type ADVERTISE6 (2)
Aug 29 20:04:15 firewall dhcpcd[3512]: ppp0: invalid state for DHCP6 type ADVERTISE6 (2)
Aug 29 20:04:24 firewall dhcpcd[3512]: ppp0: invalid state for DHCP6 type ADVERTISE6 (2)
Aug 29 20:04:43 firewall dhcpcd[3512]: ppp0: invalid state for DHCP6 type ADVERTISE6 (2)
Aug 29 20:04:52 firewall dhcpcd[3512]: ppp0: carrier lost
Aug 29 20:04:52 firewall dhcpcd[3512]: ppp0: removing interface
Aug 29 20:04:53 firewall dhcpcd[3512]: ppp0: waiting for carrier
Aug 29 20:04:53 firewall dhcpcd[3512]: ppp0: carrier acquired
Aug 29 20:04:53 firewall dhcpcd[3512]: ppp0: IAID 00:00:00:01
Aug 29 20:04:53 firewall dhcpcd[3512]: ppp0: IA type 25 IAID 00:00:00:0c
Aug 29 20:04:53 firewall dhcpcd[3512]: ppp0: IA type 25 IAID 00:00:00:f2
Aug 29 20:04:59 firewall dhcpcd[3512]: ppp0: carrier lost
Aug 29 20:04:59 firewall dhcpcd[3512]: ppp0: removing interface
Aug 29 20:05:29 firewall dhcpcd[3512]: ppp0: waiting for carrier
Aug 29 20:05:29 firewall dhcpcd[3512]: ppp0: carrier acquired
Aug 29 20:05:29 firewall dhcpcd[3512]: ppp0: IAID 00:00:00:01
Aug 29 20:05:29 firewall dhcpcd[3512]: ppp0: IA type 25 IAID 00:00:00:0c
Aug 29 20:05:29 firewall dhcpcd[3512]: ppp0: IA type 25 IAID 00:00:00:f2
Aug 29 20:05:29 firewall dhcpcd[2105]: sending commands to dhcpcd process
Aug 29 20:05:29 firewall dhcpcd[3512]: control command: dhcpcd -n ppp0
Aug 29 20:05:29 firewall dhcpcd[3512]: ppp0: soliciting a DHCPv6 lease
Aug 29 20:05:29 firewall dhcpcd[3512]: ppp0: IAID 00:00:00:01
Aug 29 20:05:29 firewall dhcpcd[3512]: ppp0: IA type 25 IAID 00:00:00:0c
Aug 29 20:05:29 firewall dhcpcd[3512]: ppp0: IA type 25 IAID 00:00:00:f2
Aug 29 20:05:30 firewall dhcpcd[2511]: sending commands to dhcpcd process
Aug 29 20:05:30 firewall dhcpcd[3512]: control command: dhcpcd -n ppp0
Aug 29 20:05:30 firewall dhcpcd[2517]: sending commands to dhcpcd process
Aug 29 20:05:30 firewall dhcpcd[3512]: ppp0: soliciting a DHCPv6 lease
Aug 29 20:05:30 firewall dhcpcd[3512]: ppp0: IAID 00:00:00:01
Aug 29 20:05:30 firewall dhcpcd[3512]: ppp0: IA type 25 IAID 00:00:00:0c
Aug 29 20:05:30 firewall dhcpcd[3512]: ppp0: IA type 25 IAID 00:00:00:f2
Aug 29 20:05:30 firewall dhcpcd[3512]: control command: dhcpcd ppp0
Aug 29 20:05:33 firewall dhcpcd[3512]: ppp0: invalid state for DHCP6 type ADVERTISE6 (2)
Aug 29 20:05:34 firewall dhcpcd[3512]: ppp0: invalid state for DHCP6 type ADVERTISE6 (2)
Aug 29 20:05:36 firewall dhcpcd[3512]: ppp0: invalid state for DHCP6 type ADVERTISE6 (2)
Aug 29 20:05:40 firewall dhcpcd[3512]: ppp0: invalid state for DHCP6 type ADVERTISE6 (2)
Aug 29 20:05:48 firewall dhcpcd[3512]: ppp0: invalid state for DHCP6 type ADVERTISE6 (2)
Aug 29 20:06:03 firewall dhcpcd[3512]: ppp0: invalid state for DHCP6 type ADVERTISE6 (2)
Aug 29 20:06:30 firewall dhcpcd[3512]: ppp0: invalid state for DHCP6 type ADVERTISE6 (2)
Aug 29 20:07:19 firewall dhcpcd[3512]: ppp0: invalid state for DHCP6 type ADVERTISE6 (2)
Aug 29 20:08:07 firewall dhcpcd[3512]: received SIGTERM, stopping
Aug 29 20:08:07 firewall dhcpcd[3512]: ppp0: removing interface
Aug 29 20:08:07 firewall dhcpcd[3512]: vlan10: removing interface
Aug 29 20:08:07 firewall dhcpcd[3512]: vlan4: removing interface
Aug 29 20:08:07 firewall dhcpcd[3512]: lo: removing interface
Aug 29 20:08:07 firewall dhcpcd[3512]: dhcpcd exited
Aug 29 20:08:07 firewall dhcpcd[2731]: dhcpcd-10.0.8 starting
Aug 29 20:08:07 firewall dhcpcd[2733]: dev: loaded udev
Aug 29 20:08:07 firewall dhcpcd[2733]: DUID 00:01:00:01:22:00:9c:ee:d4:3d:7e:f1:d0:79
Aug 29 20:08:07 firewall dhcpcd[2733]: ppp0: IAID 00:00:00:01
Aug 29 20:08:07 firewall dhcpcd[2733]: ppp0: IA type 25 IAID 00:00:00:0c
Aug 29 20:08:07 firewall dhcpcd[2733]: ppp0: IA type 25 IAID 00:00:00:f2
Aug 29 20:08:07 firewall dhcpcd[2733]: ppp0: (null): DHCPv6 REPLY missing Prefix
Aug 29 20:08:07 firewall dhcpcd[2733]: ppp0: rebinding prior DHCPv6 lease
Aug 29 20:08:07 firewall dhcpcd[2733]: lo: activating for delegation
Aug 29 20:08:07 firewall dhcpcd[2733]: lo: IAID 00:00:00:00
Aug 29 20:08:07 firewall dhcpcd[2733]: lo: ipv6_start: Operation not supported
Aug 29 20:08:07 firewall dhcpcd[2733]: vlan10: activating for delegation
Aug 29 20:08:07 firewall dhcpcd[2733]: vlan10: IAID ff:00:00:0a

noci2012 avatar Aug 29 '24 18:08 noci2012

dhcpcd -n ppp0 was used to try to force a rebind. in the end a restart of the process was done. after which it immediately started. process running is:

2733 ? S 0:00 dhcpcd: [manager]

noci2012 avatar Aug 29 '24 18:08 noci2012

Please upgrade to dhcpcd-10.0.10 where a lot of PPP issues have been resolved. Also, why are you delegating to the loopback interface? That makes no sense to me.

rsmarples avatar Sep 03 '24 09:09 rsmarples

@rsmarples : those addresses should be handled on the firewall, I have a fixed /48 prefix the remaining interfaes of VLAN's have a statc assignment. Hence assignment to lo. (dhcp v6 is used for further config of clients).

10.0.10 wasn't available then, 9999 did not compile.

ISP provides the prefix through DHCPv6-PD there is no SLAAC etc. Without requesting DHCPv6-PD the IPv6 will not be forwarded by the ISP. (So failure in renewal or not starting correctly will kill the the link sooner or later for IPv6).

noci2012 avatar Dec 20 '24 20:12 noci2012

I've just run into this, and have installed 10.1.0. Hopefully it will fix it.

ryancdotorg avatar Dec 26 '24 18:12 ryancdotorg

Still seeing this in 10.1.0.

ryancdotorg avatar Jan 06 '25 18:01 ryancdotorg

When the connection restarted:

Dec 29 17:49:17 router dhcpcd[78669]: wan0: removing interface
Dec 29 17:49:20 router dhcpcd[78669]: ps_root_dispatch: No such file or directory
Dec 29 17:49:20 router dhcpcd[78669]: wan0: IAID 00:00:00:00
Dec 29 17:49:20 router dhcpcd[78669]: wan0: IA type 25 IAID 00:00:00:01

rebind attempt

Jan  6 18:12:08 router dhcpcd[78669]: control command: dhcpcd -n wan0
Jan  6 18:12:08 router dhcpcd[78669]: wan0: soliciting a DHCPv6 lease
Jan  6 18:12:08 router dhcpcd[78669]: wan0: IAID 00:00:00:00
Jan  6 18:12:08 router dhcpcd[78669]: wan0: IA type 25 IAID 00:00:00:01
Jan  6 18:12:08 router dhcpcd[78669]: wan0: invalid state for DHCP6 type ADVERTISE6 (2)
Jan  6 18:12:09 router dhcpcd[78669]: wan0: invalid state for DHCP6 type ADVERTISE6 (2)

This seems similar? https://github.com/NetworkConfiguration/dhcpcd/issues/76

ryancdotorg avatar Jan 06 '25 18:01 ryancdotorg

Seems to be a different issue from #76.

The "invalid state" is 0, and the patch to make dhcpcd continue if flags is -1 doesn't work because flags is 128.

ryancdotorg avatar Jan 06 '25 18:01 ryancdotorg