dhcpcd-discuss

On Tue, Mar 26, 2019 at 12:54:11AM +0000, Roy Marples wrote:
> On 25/03/2019 06:48, Remi Locherer wrote:
> > > > The log also shows another issue:
> > > > Renew does not work and dhcpcd needs to do a rebind. This is because the
> > > > DHCPv6 server from my ISP does not answer renew requests sent using unicast.
> > > > --> https://www.as13030.net/status.php#collapse_12863 : issues with PD
> 
> > Mar 25 06:57:12 blau dhcpcd[88652]: em2: unicasting RENEW6 (xid 0x38fce6), next in 10.3 seconds
> > Mar 25 06:57:22 blau dhcpcd[88652]: em2: unicasting RENEW6 (xid 0x38fce6), next in 20.2 seconds
> > Mar 25 06:57:42 blau dhcpcd[88652]: em2: unicasting RENEW6 (xid 0x38fce6), next in 40.8 seconds
> > Mar 25 06:58:23 blau dhcpcd[88652]: em2: unicasting RENEW6 (xid 0x38fce6), next in 77.6 seconds
> > Mar 25 06:59:41 blau dhcpcd[88652]: em2: unicasting RENEW6 (xid 0x38fce6), next in 151.3 seconds
> > Mar 25 07:02:12 blau dhcpcd[88652]: em2: unicasting RENEW6 (xid 0x38fce6), next in 309.1 seconds
> > Mar 25 07:07:12 blau dhcpcd[88652]: em2: failed to renew DHCPv6, rebinding
> 
> I've added a commit to dhcpcd which makes this work:
> 
> interface em2
> 	nooption dhcp6_unicast
> 
> This should stop dhcpcd from unicasting the renew request and will broadcast
> it instead.
> 
> https://roy.marples.name/git/dhcpcd.git/commit/?id=01c95afadf6231ae7dced05537f95995f086f573
> 
> Let me know if this fixes your problem with renew.
> Clearly, rebind is still an issue, but if renew works maybe that will go
> away.

With this renew works and all interfaces keep their IPv6 address. Thank you!

Something with 'script ""' seems not to work as expected.


Mar 26 06:08:16 blau dhcpcd[9558]: dhcpcd-7.1.1 starting
Mar 26 06:08:16 blau dhcpcd[9558]: em1: executing `""' PREINIT
Mar 26 06:08:16 blau dhcpcd[9558]: script_runreason: "": WEXITSTATUS 127
Mar 26 06:08:16 blau dhcpcd[9558]: em1: executing `""' CARRIER
Mar 26 06:08:16 blau dhcpcd[9558]: script_runreason: "": WEXITSTATUS 127
Mar 26 06:08:16 blau dhcpcd[9558]: em2: executing `""' PREINIT
Mar 26 06:08:16 blau dhcpcd[9558]: script_runreason: "": WEXITSTATUS 127
Mar 26 06:08:16 blau dhcpcd[9558]: em2: executing `""' CARRIER
Mar 26 06:08:16 blau dhcpcd[9558]: script_runreason: "": WEXITSTATUS 127
Mar 26 06:08:16 blau dhcpcd[9558]: vlan2: executing `""' PREINIT
Mar 26 06:08:16 blau dhcpcd[9558]: script_runreason: "": WEXITSTATUS 127
Mar 26 06:08:16 blau dhcpcd[9558]: vlan2: executing `""' CARRIER
Mar 26 06:08:16 blau dhcpcd[9558]: script_runreason: "": WEXITSTATUS 127
Mar 26 06:08:16 blau dhcpcd[9558]: vlan5: executing `""' PREINIT
Mar 26 06:08:16 blau dhcpcd[9558]: script_runreason: "": WEXITSTATUS 127
Mar 26 06:08:16 blau dhcpcd[9558]: vlan5: executing `""' CARRIER
Mar 26 06:08:16 blau dhcpcd[9558]: script_runreason: "": WEXITSTATUS 127
Mar 26 06:08:16 blau dhcpcd[9558]: DUID 00:01:00:01:20:e6:6a:2e:00:0d:b9:46:e8:b5
Mar 26 06:08:16 blau dhcpcd[9558]: em1: IAID b9:46:e8:b5
Mar 26 06:08:16 blau dhcpcd[9558]: em2: IAID b9:46:e8:b6
Mar 26 06:08:16 blau dhcpcd[9558]: em2: IA type 25 IAID 00:00:00:01
Mar 26 06:08:16 blau dhcpcd[9558]: em2: reading lease `/var/db/dhcpcd/em2.lease6'
Mar 26 06:08:16 blau dhcpcd[9558]: em2: accepted reconfigure key
Mar 26 06:08:16 blau dhcpcd[9558]: em2: rebinding prior DHCPv6 lease
Mar 26 06:08:16 blau dhcpcd[9558]: em2: delaying REBIND6 (xid 0x074d2a), next in 0.8 seconds
Mar 26 06:08:16 blau dhcpcd[9558]: vlan2: IAID ff:00:00:02
Mar 26 06:08:16 blau dhcpcd[9558]: vlan5: IAID ff:00:00:05
Mar 26 06:08:17 blau dhcpcd[9558]: em2: broadcasting REBIND6 (xid 0x074d2a), next in 1.0 seconds
Mar 26 06:08:18 blau dhcpcd[9558]: em2: fe80::c671:feff:fef4:d0ff: DHCPv6 REPLY missing Prefix
Mar 26 06:08:18 blau dhcpcd[9558]: em2: no useable IA found in lease
Mar 26 06:08:18 blau dhcpcd[9558]: em2: soliciting a DHCPv6 lease
Mar 26 06:08:18 blau dhcpcd[9558]: em2: delaying SOLICIT6 (xid 0x0282a8), next in 0.6 seconds
Mar 26 06:08:18 blau dhcpcd[9558]: em2: broadcasting SOLICIT6 (xid 0x0282a8), next in 1.0 seconds
Mar 26 06:08:18 blau dhcpcd[9558]: em2: ADV 2a02:168:69f1::/48 from fe80::c671:feff:fef4:d0ff
Mar 26 06:08:18 blau dhcpcd[9558]: em2: broadcasting REQUEST6 (xid 0x283432), next in 1.1 seconds
Mar 26 06:08:18 blau dhcpcd[9558]: em2: wrong xid 0x074d2a (expecting 0x283432) from fe80::c671:feff:fef4:d0ff
Mar 26 06:08:18 blau dhcpcd[9558]: em2: accepted reconfigure key
Mar 26 06:08:18 blau dhcpcd[9558]: em2: REPLY6 received from fe80::c671:feff:fef4:d0ff
Mar 26 06:08:18 blau dhcpcd[9558]: em2: renew in 1200, rebind in 1800, expire in 86400 seconds
Mar 26 06:08:18 blau dhcpcd[9558]: lo0: adding reject route to 2a02:168:69f1::/48 via ::1
Mar 26 06:08:18 blau dhcpcd[9558]: em2: writing lease `/var/db/dhcpcd/em2.lease6'
Mar 26 06:08:18 blau dhcpcd[9558]: em2: delegated prefix 2a02:168:69f1::/48
Mar 26 06:08:18 blau dhcpcd[9558]: em1: adding address 2a02:168:69f1:1::1/64
Mar 26 06:08:18 blau dhcpcd[9558]: em1: pltime 3600 seconds, vltime 86400 seconds
Mar 26 06:08:18 blau dhcpcd[9558]: em1: waiting for DHCPv6 DAD to complete
Mar 26 06:08:18 blau dhcpcd[9558]: vlan2: adding address 2a02:168:69f1:2::1/64
Mar 26 06:08:18 blau dhcpcd[9558]: vlan2: pltime 3600 seconds, vltime 86400 seconds
Mar 26 06:08:18 blau dhcpcd[9558]: vlan2: waiting for DHCPv6 DAD to complete
Mar 26 06:08:18 blau dhcpcd[9558]: vlan5: adding address 2a02:168:69f1:5::1/64
Mar 26 06:08:18 blau dhcpcd[9558]: vlan5: pltime 3600 seconds, vltime 86400 seconds
Mar 26 06:08:18 blau dhcpcd[9558]: vlan5: waiting for DHCPv6 DAD to complete
Mar 26 06:08:18 blau dhcpcd[9558]: em1: adding route to 2a02:168:69f1:1::/64
Mar 26 06:08:18 blau dhcpcd[9558]: vlan2: adding route to 2a02:168:69f1:2::/64
Mar 26 06:08:18 blau dhcpcd[9558]: vlan5: adding route to 2a02:168:69f1:5::/64
Mar 26 06:08:18 blau dhcpcd[9558]: em2: executing `""' BOUND6
Mar 26 06:08:18 blau dhcpcd[9558]: script_runreason: "": WEXITSTATUS 127
Mar 26 06:08:18 blau dhcpcd[9558]: forking to background
Mar 26 06:08:18 blau dhcpcd[9558]: forked to background, child pid 80362
Mar 26 06:08:19 blau dhcpcd[80362]: em2: wrong xid 0x0282a8 (expecting 0x283432) from fe80::c671:feff:fef4:d0ff
Mar 26 06:08:19 blau dhcpcd[80362]: em1: DHCPv6 DAD completed
Mar 26 06:08:19 blau dhcpcd[80362]: em1: executing `""' DELEGATED6
Mar 26 06:08:19 blau dhcpcd[80362]: script_runreason: "": WEXITSTATUS 127
Mar 26 06:08:19 blau dhcpcd[80362]: vlan2: DHCPv6 DAD completed
Mar 26 06:08:19 blau dhcpcd[80362]: vlan2: executing `""' DELEGATED6
Mar 26 06:08:19 blau dhcpcd[80362]: script_runreason: "": WEXITSTATUS 127
Mar 26 06:08:19 blau dhcpcd[80362]: vlan5: DHCPv6 DAD completed
Mar 26 06:08:19 blau dhcpcd[80362]: vlan5: executing `""' DELEGATED6
Mar 26 06:08:19 blau dhcpcd[80362]: script_runreason: "": WEXITSTATUS 127
Mar 26 06:28:19 blau dhcpcd[80362]: em2: broadcasting RENEW6 (xid 0x635ab3), next in 10.7 seconds
Mar 26 06:28:19 blau dhcpcd[80362]: em2: REPLY6 received from fe80::c671:feff:fef4:d0ff
Mar 26 06:28:19 blau dhcpcd[80362]: em2: renew in 1200, rebind in 1800, expire in 86400 seconds
Mar 26 06:28:19 blau dhcpcd[80362]: em2: writing lease `/var/db/dhcpcd/em2.lease6'
Mar 26 06:28:19 blau dhcpcd[80362]: em2: delegated prefix 2a02:168:69f1::/48
Mar 26 06:28:19 blau dhcpcd[80362]: em1: adding address 2a02:168:69f1:1::1/64
Mar 26 06:28:19 blau dhcpcd[80362]: em1: pltime 3600 seconds, vltime 86400 seconds
Mar 26 06:28:19 blau dhcpcd[80362]: em1: executing `""' DELEGATED6
Mar 26 06:28:19 blau dhcpcd[80362]: script_runreason: "": WEXITSTATUS 127
Mar 26 06:28:19 blau dhcpcd[80362]: vlan2: adding address 2a02:168:69f1:2::1/64
Mar 26 06:28:19 blau dhcpcd[80362]: vlan2: pltime 3600 seconds, vltime 86400 seconds
Mar 26 06:28:19 blau dhcpcd[80362]: vlan2: executing `""' DELEGATED6
Mar 26 06:28:19 blau dhcpcd[80362]: script_runreason: "": WEXITSTATUS 127
Mar 26 06:28:19 blau dhcpcd[80362]: vlan5: adding address 2a02:168:69f1:5::1/64
Mar 26 06:28:19 blau dhcpcd[80362]: vlan5: pltime 3600 seconds, vltime 86400 seconds
Mar 26 06:28:19 blau dhcpcd[80362]: vlan5: executing `""' DELEGATED6
Mar 26 06:28:19 blau dhcpcd[80362]: script_runreason: "": WEXITSTATUS 127
Mar 26 06:28:19 blau dhcpcd[80362]: em2: executing `""' RENEW6
Mar 26 06:28:19 blau dhcpcd[80362]: script_runreason: "": WEXITSTATUS 127
Mar 26 06:48:19 blau dhcpcd[80362]: em2: broadcasting RENEW6 (xid 0xc0cfdf), next in 10.8 seconds
Mar 26 06:48:19 blau dhcpcd[80362]: em2: REPLY6 received from fe80::c671:feff:fef4:d0ff
Mar 26 06:48:19 blau dhcpcd[80362]: em2: renew in 1200, rebind in 1800, expire in 86400 seconds
Mar 26 06:48:19 blau dhcpcd[80362]: em2: writing lease `/var/db/dhcpcd/em2.lease6'
Mar 26 06:48:19 blau dhcpcd[80362]: em2: delegated prefix 2a02:168:69f1::/48
Mar 26 06:48:19 blau dhcpcd[80362]: em1: adding address 2a02:168:69f1:1::1/64
Mar 26 06:48:19 blau dhcpcd[80362]: em1: pltime 3600 seconds, vltime 86400 seconds
Mar 26 06:48:19 blau dhcpcd[80362]: em1: executing `""' DELEGATED6
Mar 26 06:48:19 blau dhcpcd[80362]: script_runreason: "": WEXITSTATUS 127
Mar 26 06:48:19 blau dhcpcd[80362]: vlan2: adding address 2a02:168:69f1:2::1/64
Mar 26 06:48:19 blau dhcpcd[80362]: vlan2: pltime 3600 seconds, vltime 86400 seconds
Mar 26 06:48:19 blau dhcpcd[80362]: vlan2: executing `""' DELEGATED6
Mar 26 06:48:19 blau dhcpcd[80362]: script_runreason: "": WEXITSTATUS 127
Mar 26 06:48:19 blau dhcpcd[80362]: vlan5: adding address 2a02:168:69f1:5::1/64
Mar 26 06:48:19 blau dhcpcd[80362]: vlan5: pltime 3600 seconds, vltime 86400 seconds
Mar 26 06:48:19 blau dhcpcd[80362]: vlan5: executing `""' DELEGATED6
Mar 26 06:48:19 blau dhcpcd[80362]: script_runreason: "": WEXITSTATUS 127
Mar 26 06:48:19 blau dhcpcd[80362]: em2: executing `""' RENEW6
Mar 26 06:48:19 blau dhcpcd[80362]: script_runreason: "": WEXITSTATUS 127