Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Failure to renew with "ps_root_recvmsg: Network is unreachable" #440

Open
JognSmit opened this issue Jan 22, 2025 · 4 comments
Open

Failure to renew with "ps_root_recvmsg: Network is unreachable" #440

JognSmit opened this issue Jan 22, 2025 · 4 comments
Labels

Comments

@JognSmit
Copy link

JognSmit commented Jan 22, 2025

dhcpcd 10.1.0

I have 2 interfaces. eno5 is connected to fiber provider and eno8.2 to starlink.
Once in a while, "something" happens dhcpcd during renewal process of eno5 address
drops default route through it, which is followed by a number of "ps_root_recvmsg: Network is unreachable"
messages and failure to get a new lease.
Insisting on renewing lease by running dhcpcd -n eno5 resolves problem

2025-01-22T12:26:13.832108-08:00 router dhcpcd[974484]: eno8.2: renewing lease of 100.xx.xxx.xxx
2025-01-22T12:26:13.832984-08:00 router dhcpcd[974484]: eno8.2: sending REQUEST (xid 0x788daebc), next in 4.2 seconds
2025-01-22T12:26:13.833329-08:00 router dhcpcd[974484]: eno8.2: acknowledged 100.xx.xxx.xxx from 100.64.0.1
2025-01-22T12:26:13.833561-08:00 router dhcpcd[974484]: eno8.2: leased 100.xx.xxx.xxx for 300 seconds
2025-01-22T12:26:13.833915-08:00 router dhcpcd[974484]: eno8.2: renew in 150 seconds, rebind in 262 seconds
2025-01-22T12:26:13.834133-08:00 router dhcpcd[974484]: eno8.2: writing lease: /var/lib/dhcpcd/eno8.2.lease
2025-01-22T12:26:13.834336-08:00 router dhcpcd[974484]: eno8.2: adding IP address 100.xx.xxx.xxx/10 broadcast 100.127.255.255
2025-01-22T12:26:13.834547-08:00 router dhcpcd[974484]: eno8.2: executing: /usr/lib/dhcpcd/dhcpcd-run-hooks RENEW
2025-01-22T12:28:43.455886-08:00 router dhcpcd[974484]: eno5: renewing lease of 47.yyy.yyy.78
2025-01-22T12:28:43.456488-08:00 router dhcpcd[974484]: eno5: sending REQUEST (xid 0xcc8b9d2d), next in 4.4 seconds
2025-01-22T12:28:43.834049-08:00 router dhcpcd[974484]: eno8.2: renewing lease of 100.xx.xxx.xxx
2025-01-22T12:28:43.840894-08:00 router dhcpcd[974484]: eno8.2: sending REQUEST (xid 0x56b9244), next in 3.0 seconds
2025-01-22T12:28:43.841049-08:00 router dhcpcd[974484]: eno8.2: acknowledged 100.xx.xxx.xxx from 100.64.0.1
2025-01-22T12:28:43.841186-08:00 router dhcpcd[974484]: eno8.2: leased 100.xx.xxx.xxx for 300 seconds
2025-01-22T12:28:43.841315-08:00 router dhcpcd[974484]: eno8.2: renew in 150 seconds, rebind in 262 seconds
2025-01-22T12:28:43.841448-08:00 router dhcpcd[974484]: eno8.2: writing lease: /var/lib/dhcpcd/eno8.2.lease
2025-01-22T12:28:43.841591-08:00 router dhcpcd[974484]: eno8.2: adding IP address 100.xx.xxx.xxx/10 broadcast 100.127.255.255
2025-01-22T12:28:43.841714-08:00 router dhcpcd[974484]: eno5: deleting route to 47.yyy.yyy.0/23
2025-01-22T12:28:43.841889-08:00 router dhcpcd[974484]: eno5: deleting default route via 47.yyy.yyy.1
2025-01-22T12:28:43.842030-08:00 router dhcpcd[974484]: eno8.2: executing: /usr/lib/dhcpcd/dhcpcd-run-hooks RENEW
2025-01-22T12:28:47.831178-08:00 router dhcpcd[974484]: eno5: sending REQUEST (xid 0xcc8b9d2d), next in 7.9 seconds
2025-01-22T12:28:47.831530-08:00 router dhcpcd[974484]: ps_root_recvmsg: Network is unreachable
2025-01-22T12:28:55.695001-08:00 router dhcpcd[974484]: eno5: sending REQUEST (xid 0xcc8b9d2d), next in 15.7 seconds
2025-01-22T12:28:55.695600-08:00 router dhcpcd[974484]: ps_root_recvmsg: Network is unreachable
2025-01-22T12:29:11.354362-08:00 router dhcpcd[974484]: eno5: sending REQUEST (xid 0xcc8b9d2d), next in 31.5 seconds
2025-01-22T12:29:11.354965-08:00 router dhcpcd[974484]: ps_root_recvmsg: Network is unreachable
2025-01-22T12:29:42.858769-08:00 router dhcpcd[974484]: eno5: sending REQUEST (xid 0xcc8b9d2d), next in 63.8 seconds
2025-01-22T12:29:42.859655-08:00 router dhcpcd[974484]: ps_root_recvmsg: Network is unreachable
2025-01-22T12:29:43.462247-08:00 router dhcpcd[974484]: control command: dhcpcd -n eno5
2025-01-22T12:29:43.463884-08:00 router dhcpcd[974484]: eno5: executing: /usr/lib/dhcpcd/dhcpcd-run-hooks RECONFIGURE
2025-01-22T12:29:43.476871-08:00 router dhcpcd[974484]: eno5: IAID ef:0c:9f:dc
2025-01-22T12:29:43.477024-08:00 router dhcpcd[974484]: eno5: delaying IPv4 for 0.3 seconds
2025-01-22T12:29:43.764028-08:00 router dhcpcd[974484]: eno5: reading lease: /var/lib/dhcpcd/eno5.lease
2025-01-22T12:29:43.764338-08:00 router dhcpcd[974484]: eno5: rebinding lease of 47.yyy.yyy.78
2025-01-22T12:29:43.764462-08:00 router dhcpcd[974484]: eno5: sending REQUEST (xid 0x164683cc), next in 3.6 seconds
2025-01-22T12:29:43.764784-08:00 router dhcpcd[974484]: eno5: spawned BPF BOOTP on PID 1473641
2025-01-22T12:29:44.054601-08:00 router dhcpcd[974484]: eno5: acknowledged 47.yyy.yyy.78 from 74.42.148.118
2025-01-22T12:29:44.054879-08:00 router dhcpcd[974484]: eno5: leased 47.yyy.yyy.78 for 1800 seconds
2025-01-22T12:29:44.055092-08:00 router dhcpcd[974484]: eno5: renew in 900 seconds, rebind in 1575 seconds
2025-01-22T12:29:44.055273-08:00 router dhcpcd[974484]: eno5: writing lease: /var/lib/dhcpcd/eno5.lease
2025-01-22T12:29:44.055444-08:00 router dhcpcd[974484]: eno5: adding IP address 47.yyy.yyy.78/23 broadcast 47.yyy.zzz.255
2025-01-22T12:29:44.055566-08:00 router dhcpcd[974484]: eno5: adding route to 47.yyy.yyy.0/23
2025-01-22T12:29:44.055694-08:00 router dhcpcd[974484]: eno5: adding default route via 47.yyy.yyy.1
2025-01-22T12:29:44.055809-08:00 router dhcpcd[974484]: eno5: executing: /usr/lib/dhcpcd/dhcpcd-run-hooks RENEW
2025-01-22T12:29:44.094381-08:00 router dhcpcd[974484]: eno5: BPF BOOTP exited from PID 1473641

config is:

allowinterfaces eno8.2 eno5
debug
#hostname
duid
vendorclassid
option domain_name_servers, domain_name, domain_search
option classless_static_routes
option interface_mtu
option host_name
nogateway
noipv6rs
noipv4ll
option rapid_commit
require dhcp_server_identifier
nohook resolv.conf
interface eno5
        gateway
        noarp
@JognSmit JognSmit changed the title Failure to renew Failure to renew with "ps_root_recvmsg: Network is unreachable" Jan 22, 2025
@rsmarples
Copy link
Member

Here's the interesting section:

2025-01-22T12:28:43.834049-08:00 router dhcpcd[974484]: eno8.2: renewing lease of 100.xx.xxx.xxx
2025-01-22T12:28:43.840894-08:00 router dhcpcd[974484]: eno8.2: sending REQUEST (xid 0x56b9244), next in 3.0 seconds
2025-01-22T12:28:43.841049-08:00 router dhcpcd[974484]: eno8.2: acknowledged 100.xx.xxx.xxx from 100.64.0.1
2025-01-22T12:28:43.841186-08:00 router dhcpcd[974484]: eno8.2: leased 100.xx.xxx.xxx for 300 seconds
2025-01-22T12:28:43.841315-08:00 router dhcpcd[974484]: eno8.2: renew in 150 seconds, rebind in 262 seconds
2025-01-22T12:28:43.841448-08:00 router dhcpcd[974484]: eno8.2: writing lease: /var/lib/dhcpcd/eno8.2.lease
2025-01-22T12:28:43.841591-08:00 router dhcpcd[974484]: eno8.2: adding IP address 100.xx.xxx.xxx/10 broadcast 100.127.255.255
2025-01-22T12:28:43.841714-08:00 router dhcpcd[974484]: eno5: deleting route to 47.yyy.yyy.0/23
2025-01-22T12:28:43.841889-08:00 router dhcpcd[974484]: eno5: deleting default route via 47.yyy.yyy.1
2025-01-22T12:28:43.842030-08:00 router dhcpcd[974484]: eno8.2: executing: /usr/lib/dhcpcd/dhcpcd-run-hooks RENEW
2025-01-22T12:28:47.831178-08:00 router dhcpcd[974484]: eno5: sending REQUEST (xid 0xcc8b9d2d), next in 7.9 seconds
2025-01-22T12:28:47.831530-08:00 router dhcpcd[974484]: ps_root_recvmsg: Network is unreachable

eno8.2 starts a renew and when the lease is applied the subnet and default routs are deleted from eno5 for reasons unknown - that is the bug.
This causes a renew failure on eno5. eno5 should recover when T2 is reached as that will trigger a REBIND which the OP shows works when done manually. However this results in a window of 600 seconds without a useable config which isn't ideal.

@rsmarples rsmarples added the bug label Jan 26, 2025
@JognSmit
Copy link
Author

is there a way that I can collect more information that will clarify situation ? I had hopes that enabling debug will be more informative in order to understand what happens.

@rsmarples
Copy link
Member

It’s pretty clear what is happening, just not the why. Is one of the interfaces a VLAN and is it on the other interface or a different one?

@JognSmit
Copy link
Author

different interfaces.
one with vlan (eno8.2) connected via switch to starlink
eno5 going directly to ONT

by "clarify" i meant to see "why". some magical extra-extra-debug setting that dumps some decision making log messages...

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants