dhcpcd-discuss

On 10/02/2020 20:44, nighthawk wrote:
> Hi!
>
> I compiled 8.1.6 (which oddly reports itself as 8.99.0?!) but that
> version does not work with the virtual interfaces at all. Not even
> static IPv4 addresses are being assigned.
>
> Here's a log of the dhcpcd8 startup (sorry for the spam, I don't know
> what might be relevant and what's not):
>
> Feb 10 20:56:27 opiprime dhcpcd[18269]: no such user _dhcpcd

So at a guess you just checked out the git sources and built it?
By default you get the master branch and not the dhcpcd-8 branch.

The master branch defaults to privilege separation - but aside from spamming no 
such user _dhcpcd it's still expected to work.

> Feb 10 20:56:27 opiprime dhcpcd[18269]: no such user _dhcpcd
> Feb 10 20:56:27 opiprime dhcpcd[18269]: if_learnaddrs: if_addrflags6:
> No such process
> Feb 10 20:56:27 opiprime dhcpcd[18269]: if_learnaddrs: if_addrflags6:
> No such process
> Feb 10 20:56:27 opiprime dhcpcd[18273]: if_learnaddrs: if_addrflags6:
> No such process
> Feb 10 20:56:27 opiprime dhcpcd[18269]: if_learnaddrs: if_addrflags6:
> No such process
> Feb 10 20:56:27 opiprime dhcpcd[18273]: if_learnaddrs: if_addrflags6:
> No such process
> Feb 10 20:56:27 opiprime dhcpcd[18273]: if_learnaddrs: if_addrflags6:
> No such process
> Feb 10 20:56:27 opiprime dhcpcd[18269]: DUID
> 00:01:00:01:25:d3:37:53:02:01:c6:ee:53:be
> Feb 10 20:56:27 opiprime dhcpcd[18269]: eth0: IAID c6:ee:53:be
> Feb 10 20:56:27 opiprime dhcpcd[18269]: eth0: IA type 25 IAID c6:ee:53:bf
> Feb 10 20:56:27 opiprime dhcpcd[18273]: DUID
> 00:01:00:01:25:d3:37:53:02:01:c6:ee:53:be
> Feb 10 20:56:27 opiprime dhcpcd[18269]: eth0: adding address
> fe80::da3c:82d1:967f:14e7
> Feb 10 20:56:27 opiprime dhcpcd[18273]: eth0: IAID c6:ee:53:be
> Feb 10 20:56:27 opiprime dhcpcd[18273]: eth0: IA type 25 IAID c6:ee:53:bf
> Feb 10 20:56:27 opiprime dhcpcd[18273]: eth0: adding address
> fe80::da3c:82d1:967f:14e7
> Feb 10 20:56:27 opiprime dhcpcd[18269]: eth0: soliciting an IPv6 router
> Feb 10 20:56:27 opiprime dhcpcd[18273]: eth0: soliciting an IPv6 router
> Feb 10 20:56:28 opiprime dhcpcd[18269]: eth0: probing address 192.168.0.11/23
> Feb 10 20:56:28 opiprime dhcpcd[18273]: eth0: probing address 192.168.0.11/23
> Feb 10 20:56:28 opiprime dhcpcd[18269]: ipv6nd_recvmsg: No such process
> Feb 10 20:56:28 opiprime dhcpcd[18273]: ipv6nd_recvmsg: No such process
> Feb 10 20:56:28 opiprime dhcpcd[18269]: eth0: soliciting a DHCPv6 lease
> Feb 10 20:56:28 opiprime dhcpcd[18273]: eth0: soliciting a DHCPv6 lease
> Feb 10 20:56:29 opiprime dhcpcd[18269]: eth0: Router Advertisement
> from fe80::ce35:40ff:fe35:95d4
> Feb 10 20:56:29 opiprime dhcpcd[18273]: eth0: Router Advertisement
> from fe80::ce35:40ff:fe35:95d4
> Feb 10 20:56:29 opiprime dhcpcd[18269]: eth0: adding address
> 2a02:xxxx:2731:40c0:4990:5522:e582:4f27/64
> Feb 10 20:56:29 opiprime dhcpcd[18273]: eth0: adding address
> 2a02:xxxx:2731:40c0:4990:5522:e582:4f27/64
> Feb 10 20:56:29 opiprime dhcpcd[18269]: eth0: adding route to
> 2a02:xxxx:2731:40c0::/64
> Feb 10 20:56:29 opiprime dhcpcd[18273]: eth0: adding route to
> 2a02:xxxx:2731:40c0::/64
> Feb 10 20:56:29 opiprime dhcpcd[18273]: eth0: adding default route via
> fe80::ce35:40ff:fe35:95d4
> Feb 10 20:56:29 opiprime dhcpcd[18269]: eth0: adding default route via
> fe80::ce35:40ff:fe35:95d4
> Feb 10 20:56:29 opiprime dhcpcd[18269]: eth0: ADV
> 2a02:xxxx:2731:40c0:201:c6ff:feee:53be/128 from
> fe80::ce35:40ff:fe35:95d4
> Feb 10 20:56:29 opiprime dhcpcd[18269]: eth0: REPLY6 received from
> fe80::ce35:40ff:fe35:95d4
> Feb 10 20:56:29 opiprime dhcpcd[18269]: eth0: adding address
> 2a02:xxxx:2731:40c0:201:c6ff:feee:53be/128
> Feb 10 20:56:29 opiprime dhcpcd[18273]: eth0: ADV
> 2a02:xxxx:2731:40c0:201:c6ff:feee:53be/128 from
> fe80::ce35:40ff:fe35:95d4
> Feb 10 20:56:29 opiprime dhcpcd[18269]: eth0: renew in 15, rebind in
> 22, expire in 60 seconds
> Feb 10 20:56:29 opiprime dhcpcd[18269]: lo: adding reject route to
> 2a02:xxxx:2731:40d8::/62
> Feb 10 20:56:29 opiprime dhcpcd[18269]: eth0: delegated prefix
> 2a02:xxxx:2731:40d8::/62
> Feb 10 20:56:29 opiprime dhcpcd[18273]: eth0: REPLY6 received from
> fe80::ce35:40ff:fe35:95d4
> Feb 10 20:56:29 opiprime dhcpcd[18273]: eth0: adding address
> 2a02:xxxx:2731:40c0:201:c6ff:feee:53be/128
> Feb 10 20:56:29 opiprime dhcpcd[18273]: eth0: renew in 15, rebind in
> 22, expire in 60 seconds
> Feb 10 20:56:29 opiprime dhcpcd[18273]: lo: adding reject route to
> 2a02:xxxx:2731:40d8::/62
> Feb 10 20:56:29 opiprime dhcpcd[18273]: eth0: delegated prefix
> 2a02:xxxx:2731:40d8::/62
> Feb 10 20:56:30 opiprime dhcpcd[18269]: forked to background, child pid 18273

This is really nuts.
So dhcpcd will now fork right away and the parent process just waits until the 
child finishes.
What's interesting here is that this hasn't happened - the parent process is 
ALSO running the core dhcpcd code. I suspect this is the reason for a lot of the 
errors reported here.

I don't know why it's doing this ..... but I've just pushed a fix which might 
help. I can't replicate your error with your config though.

Can you please updating to the latest code, build it and run this:
dhcpcd -dB

Ctrl-C the process once done.
Post the new log here please.

> fe80::ce35:40ff:fe35:95d4
> Feb 10 20:59:10 opiprime dhcpcd[20110]: eth0: 2a02:xxxx:2731:40d8::/62
> will expire before renewal
> Feb 10 20:59:10 opiprime dhcpcd[20110]: eth0:
> 2a02:xxxx:2731:40d8::/62: no valid lifetime
> Feb 10 20:59:10 opiprime dhcpcd[20110]: eth0.20: deleting address
> 2a02:xxxx:2731:40d9::1/64

Here's the actual error.
Looking at the code, the prefix was given with a the REPLY with a vltime of 
zero, so it will be deleted.
But this doesn't make sense because it will "will expire before renewal" which 
means it must have had a vltime in the loop.

Without seeing the actual DHCP6 packet we can only speculate what the DHCPv6 
server is doing.

Could you please add the debug command to dhcpcd.conf and post more indepth logs 
please?

Roy