dhcpcd-discuss

On Thu, May 02, 2019 at 10:02:36PM +0100, Roy Marples wrote:
> On 02/05/2019 00:26, Matt Horan wrote:
> > Roy,
> > 
> > On Wed, May 01, 2019 at 10:16:34PM +0100, Roy Marples wrote:
> >> OK, I have this fixed I think!
> >> Patch attached.
> >>
> >> In a nutshell, the interface reports IFM_AVALID via SIOCGIFMEDIA but
> >> then doesn't set the link status in RTM_IFNFO.
> >>
> >> Let me know how that works for you.
> > 
> > Sadly, it seems not to have done the trick. See the attached dhcpcd.log
> > -- pretty much the same we were seeing before.
> 
> Darn.
> 
> I've comitted a swathe of patches to the dhcpcd-7 branch around this.
> Can you test that from the git repo please?
> https://roy.marples.name/git/dhcpcd.git/

Still no dice, but I did discover something.

This only happens (on both 7.1.1 and the dhcpcd-7 branch) when I have
ipv6rs (but no ip_na) in my dhcpcd.conf. I'm not sure if this is a valid
configuration, but it did work in the past.

Removing ipv6rs resolves the issue (just like disabling inet6 autoconf
in hostname.em0 and adding both ipv6rs and ip_na to dhcpcd.conf).

I've attached logs of both configurations.

Thanks,
Matt

-- 
Matt Horan matt@xxxxxxxxxxxxx https://matthoran.com/

May 02 19:04:26 [62435]: dhcpcd-7.2.1 starting
May 02 19:04:26 [62435]: em0: executing `/libexec/dhcpcd-run-hooks' PREINIT
May 02 19:04:26 [62435]: script_runreason: /libexec/dhcpcd-run-hooks: WEXITSTATUS 127
May 02 19:04:26 [62435]: em0: executing `/libexec/dhcpcd-run-hooks' CARRIER
May 02 19:04:26 [62435]: script_runreason: /libexec/dhcpcd-run-hooks: WEXITSTATUS 127
May 02 19:04:26 [62435]: em1: executing `/libexec/dhcpcd-run-hooks' PREINIT
May 02 19:04:26 [62435]: script_runreason: /libexec/dhcpcd-run-hooks: WEXITSTATUS 127
May 02 19:04:26 [62435]: em1: executing `/libexec/dhcpcd-run-hooks' CARRIER
May 02 19:04:26 [62435]: script_runreason: /libexec/dhcpcd-run-hooks: WEXITSTATUS 127
May 02 19:04:26 [62435]: DUID 00:01:00:01:24:53:c3:07:00:0d:b9:41:d8:74
May 02 19:04:26 [62435]: em0: IAID b9:41:d8:74
May 02 19:04:26 [62435]: em0: IA type 25 IAID 00:00:00:00
May 02 19:04:26 [62435]: em0: reading lease `/var/db/dhcpcd/em0.lease6'
May 02 19:04:26 [62435]: em0: rebinding prior DHCPv6 lease
May 02 19:04:26 [62435]: em0: delaying REBIND6 (xid 0xd2dd44), next in 0.7 seconds
May 02 19:04:26 [62435]: em1: IAID b9:41:d8:75
May 02 19:04:27 [62435]: em0: broadcasting REBIND6 (xid 0xd2dd44), next in 0.9 seconds
May 02 19:04:27 [62435]: em0: REPLY6 received from fe80::217:10ff:fe88:8be1
May 02 19:04:27 [62435]: em0: 2604:2000:1281:469::/64 will expire before renewal
May 02 19:04:27 [62435]: em0: 2604:2000:1281:469::/64: no valid lifetime
May 02 19:04:27 [62435]: em0: renew in 302400, rebind in 483840, expire in 604800 seconds
May 02 19:04:27 [62435]: lo0: adding reject route to 2604:2000:1281:22a8::/64 via ::1
May 02 19:04:27 [62435]: em0: writing lease `/var/db/dhcpcd/em0.lease6'
May 02 19:04:27 [62435]: em0: delegated prefix 2604:2000:1281:22a8::/64
May 02 19:04:27 [62435]: em1: adding address 2604:2000:1281:22a8::1/64
May 02 19:04:27 [62435]: em1: pltime 604800 seconds, vltime 604800 seconds
May 02 19:04:27 [62435]: em1: waiting for DHCPv6 DAD to complete
May 02 19:04:27 [62435]: em1: changing route to 2604:2000:1281:22a8::/64
May 02 19:04:27 [62435]: em0: executing `/libexec/dhcpcd-run-hooks' REBIND6
May 02 19:04:27 [62435]: script_runreason: /libexec/dhcpcd-run-hooks: WEXITSTATUS 127
May 02 19:04:27 [62435]: forking to background
May 02 19:04:27 [62435]: forked to background, child pid 86783
May 02 19:04:27 [86783]: em0: DHCPv6 reply received but already bound
May 02 19:04:28 [86783]: em1: DHCPv6 DAD completed
May 02 19:04:28 [86783]: em1: executing `/libexec/dhcpcd-run-hooks' DELEGATED6
May 02 19:04:28 [86783]: script_runreason: /libexec/dhcpcd-run-hooks: WEXITSTATUS 127

May 02 19:00:22 [47045]: dhcpcd-7.2.1 starting
May 02 19:00:22 [47045]: em0: executing `/libexec/dhcpcd-run-hooks' PREINIT
May 02 19:00:22 [47045]: script_runreason: /libexec/dhcpcd-run-hooks: WEXITSTATUS 127
May 02 19:00:22 [47045]: em0: executing `/libexec/dhcpcd-run-hooks' CARRIER
May 02 19:00:22 [47045]: script_runreason: /libexec/dhcpcd-run-hooks: WEXITSTATUS 127
May 02 19:00:22 [47045]: em1: executing `/libexec/dhcpcd-run-hooks' PREINIT
May 02 19:00:22 [47045]: script_runreason: /libexec/dhcpcd-run-hooks: WEXITSTATUS 127
May 02 19:00:22 [47045]: em1: executing `/libexec/dhcpcd-run-hooks' CARRIER
May 02 19:00:22 [47045]: script_runreason: /libexec/dhcpcd-run-hooks: WEXITSTATUS 127
May 02 19:00:22 [47045]: DUID 00:01:00:01:24:53:c3:07:00:0d:b9:41:d8:74
May 02 19:00:22 [47045]: em0: IAID b9:41:d8:74
May 02 19:00:22 [47045]: em0: IA type 25 IAID 00:00:00:00
May 02 19:00:22 [47045]: em0: delaying IPv6 router solicitation for 0.2 seconds
May 02 19:00:22 [47045]: em0: reading lease `/var/db/dhcpcd/em0.lease6'
May 02 19:00:22 [47045]: em0: rebinding prior DHCPv6 lease
May 02 19:00:22 [47045]: em0: delaying REBIND6 (xid 0x6c9145), next in 0.9 seconds
May 02 19:00:22 [47045]: em1: IAID b9:41:d8:75
May 02 19:00:22 [47045]: em0: carrier lost
May 02 19:00:22 [47045]: em0: executing `/libexec/dhcpcd-run-hooks' NOCARRIER
May 02 19:00:22 [47045]: script_runreason: /libexec/dhcpcd-run-hooks: WEXITSTATUS 127
May 02 19:00:22 [47045]: em0: executing `/libexec/dhcpcd-run-hooks' EXPIRE6
May 02 19:00:22 [47045]: script_runreason: /libexec/dhcpcd-run-hooks: WEXITSTATUS 127
May 02 19:00:52 [47045]: timed out
May 02 19:00:52 [47045]: forking to background
May 02 19:00:52 [47045]: forked to background, child pid 1296