WAN dropping - dhclient failing

[sfxdude]

Hi
I'm having some problems when the WAN drops. I use opnsense behind a cable modem in modem mode. The modem initially offers an address in the 192.168.100.x range before it has synced, which I have set to ignore. Eventually after sync, the modem passess through the DHCP offer from the upstream router.
However this fails sometimes, really not sure why, the logs are attached below. When it fails I lose internet until I force restart the dhclient or restart opnsense.

Code Select Expand

2022-04-27T01:44:30+01:00 firewall.lan dhclient[46125]: connection closed
2022-04-27T01:44:30+01:00 firewall.lan dhclient[46125]: exiting.
2022-04-27T01:44:34+01:00 firewall.lan dhclient[35471]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T01:44:35+01:00 firewall.lan dhclient[35471]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T01:44:36+01:00 firewall.lan dhclient[35471]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T01:44:37+01:00 firewall.lan dhclient[35471]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T01:44:38+01:00 firewall.lan dhclient[35471]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T01:44:40+01:00 firewall.lan dhclient[35471]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T01:44:44+01:00 firewall.lan dhclient[35471]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T01:44:51+01:00 firewall.lan dhclient[35471]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 1
2022-04-27T01:44:52+01:00 firewall.lan dhclient[35471]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 2
2022-04-27T01:44:54+01:00 firewall.lan dhclient[35471]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 3
2022-04-27T01:44:57+01:00 firewall.lan dhclient[35471]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 6
2022-04-27T01:45:03+01:00 firewall.lan dhclient[35471]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 16
2022-04-27T01:45:09+01:00 firewall.lan dhclient[35471]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T01:45:10+01:00 firewall.lan dhclient[35471]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T01:45:12+01:00 firewall.lan dhclient[35471]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T01:45:15+01:00 firewall.lan dhclient[35471]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T01:45:19+01:00 firewall.lan dhclient[35471]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 7
2022-04-27T01:45:21+01:00 firewall.lan dhclient[35471]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 1
2022-04-27T01:45:22+01:00 firewall.lan dhclient[35471]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 2
2022-04-27T01:45:24+01:00 firewall.lan dhclient[35471]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 4
2022-04-27T01:45:28+01:00 firewall.lan dhclient[35471]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 8
2022-04-27T01:45:36+01:00 firewall.lan dhclient[35471]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 10
2022-04-27T01:45:45+01:00 firewall.lan dhclient[35471]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T01:45:46+01:00 firewall.lan dhclient[35471]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 2
2022-04-27T01:45:46+01:00 firewall.lan dhclient[35471]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T01:45:48+01:00 firewall.lan dhclient[35471]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 5
2022-04-27T01:45:48+01:00 firewall.lan dhclient[35471]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T01:45:53+01:00 firewall.lan dhclient[35471]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 36
2022-04-27T01:46:01+01:00 firewall.lan dhclient[35471]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 2
2022-04-27T01:46:03+01:00 firewall.lan dhclient[35471]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 2
2022-04-27T01:46:04+01:00 firewall.lan dhclient[35471]: DHCPOFFER from 192.168.100.1 rejected.
2022-04-27T01:46:04+01:00 firewall.lan dhclient[35471]: DHCPOFFER from 192.168.100.1 rejected.
2022-04-27T01:46:05+01:00 firewall.lan dhclient[35471]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 2
2022-04-27T01:46:05+01:00 firewall.lan dhclient[35471]: DHCPOFFER from 192.168.100.1 rejected.
2022-04-27T01:46:07+01:00 firewall.lan dhclient[35471]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 5
2022-04-27T01:46:07+01:00 firewall.lan dhclient[35471]: DHCPOFFER from 192.168.100.1 rejected.
2022-04-27T01:46:12+01:00 firewall.lan dhclient[35471]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 5
2022-04-27T01:46:12+01:00 firewall.lan dhclient[35471]: DHCPOFFER from 192.168.100.1 rejected.
2022-04-27T01:46:17+01:00 firewall.lan dhclient[35471]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 5
2022-04-27T01:46:17+01:00 firewall.lan dhclient[35471]: DHCPOFFER from 192.168.100.1 rejected.
2022-04-27T01:46:22+01:00 firewall.lan dhclient[35471]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 8
2022-04-27T01:46:22+01:00 firewall.lan dhclient[35471]: DHCPOFFER from 192.168.100.1 rejected.
2022-04-27T01:46:30+01:00 firewall.lan dhclient[35471]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 9
2022-04-27T01:46:30+01:00 firewall.lan dhclient[35471]: DHCPOFFER from 192.168.100.1 rejected.
2022-04-27T01:46:34+01:00 firewall.lan dhclient[35471]: connection closed
2022-04-27T01:46:34+01:00 firewall.lan dhclient[35471]: exiting.
2022-04-27T01:46:36+01:00 firewall.lan dhclient[69198]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T01:46:36+01:00 firewall.lan dhclient[69198]: DHCPNACK from 192.168.100.1 rejected.
2022-04-27T01:46:37+01:00 firewall.lan dhclient[69198]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T01:46:37+01:00 firewall.lan dhclient[69198]: DHCPNACK from 192.168.100.1 rejected.
2022-04-27T01:46:38+01:00 firewall.lan dhclient[69198]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T01:46:38+01:00 firewall.lan dhclient[69198]: DHCPNACK from 192.168.100.1 rejected.
2022-04-27T01:46:39+01:00 firewall.lan dhclient[69198]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T01:46:39+01:00 firewall.lan dhclient[69198]: DHCPNACK from 192.168.100.1 rejected.
2022-04-27T01:46:40+01:00 firewall.lan dhclient[69198]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T01:46:40+01:00 firewall.lan dhclient[69198]: DHCPNACK from 192.168.100.1 rejected.
2022-04-27T01:46:41+01:00 firewall.lan dhclient[69198]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T01:46:41+01:00 firewall.lan dhclient[69198]: DHCPNACK from 192.168.100.1 rejected.
2022-04-27T01:46:43+01:00 firewall.lan dhclient[69198]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T01:46:43+01:00 firewall.lan dhclient[69198]: DHCPNACK from 192.168.100.1 rejected.
2022-04-27T01:46:48+01:00 firewall.lan dhclient[69198]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 1
2022-04-27T01:46:48+01:00 firewall.lan dhclient[69198]: DHCPOFFER from 192.168.100.1 rejected.
2022-04-27T01:46:49+01:00 firewall.lan dhclient[69198]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 2
2022-04-27T01:46:49+01:00 firewall.lan dhclient[69198]: DHCPOFFER from 192.168.100.1 rejected.
2022-04-27T01:46:51+01:00 firewall.lan dhclient[69198]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 2
2022-04-27T01:46:51+01:00 firewall.lan dhclient[69198]: DHCPOFFER from 192.168.100.1 rejected.
2022-04-27T01:46:53+01:00 firewall.lan dhclient[69198]: DHCPDISCOVER on igb5 to 255.255.255.255 port 67 interval 3
2022-04-27T01:46:53+01:00 firewall.lan dhclient[69198]: DHCPOFFER from 10.53.x.x
2022-04-27T01:46:55+01:00 firewall.lan dhclient[69198]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T01:46:55+01:00 firewall.lan dhclient[69198]: DHCPACK from 10.53.x.x
2022-04-27T01:46:55+01:00 firewall.lan dhclient[11197]: New IP Address (igb5): 82.24.x.x
2022-04-27T01:46:55+01:00 firewall.lan dhclient[12157]: New Subnet Mask (igb5): 255.255.252.0
2022-04-27T01:46:55+01:00 firewall.lan dhclient[13096]: New Broadcast Address (igb5): 82.24.x.x
2022-04-27T01:46:55+01:00 firewall.lan dhclient[14363]: New Routers (igb5): 82.24.x.x
2022-04-27T01:46:55+01:00 firewall.lan dhclient[17786]: route add default 82.24.x.x
2022-04-27T01:46:55+01:00 firewall.lan dhclient[18984]: Creating resolv.conf
2022-04-27T01:48:37+01:00 firewall.lan dhclient[80309]: dhclient already running, pid: 68376.
2022-04-27T01:48:37+01:00 firewall.lan dhclient[80309]: exiting.
2022-04-27T07:32:15+01:00 firewall.lan dhclient[69164]: DHCPREQUEST on igb5 to 255.255.255.255 port 67
2022-04-27T07:32:15+01:00 firewall.lan dhclient[69164]: DHCPACK from 10.53.x.x
2022-04-27T07:32:15+01:00 firewall.lan dhclient[80040]: New IP Address (igb5): 82.24.x.x
2022-04-27T07:32:15+01:00 firewall.lan dhclient[81571]: New Subnet Mask (igb5): 255.255.252.0
2022-04-27T07:32:15+01:00 firewall.lan dhclient[82716]: New Broadcast Address (igb5): 82.24.x.x
2022-04-27T07:32:15+01:00 firewall.lan dhclient[83675]: New Routers (igb5): 82.24.x.x
2022-04-27T07:32:15+01:00 firewall.lan dhclient[88152]: route add default 82.24.x.x
2022-04-27T07:32:15+01:00 firewall.lan dhclient[89626]: Creating resolv.conf
2022-04-27T07:32:16+01:00 firewall.lan dhclient[69164]: bound to 82.24.x.x -- renewal in 245159 seconds.

Connection must have dropped at start of the logs (0144, I have nothing in the dhclient logs before this) and I rebooted opnsense at 0732. DHCP settings for the WAN interface are attached.

[TParker31]

Was this issue ever resolved?

I still have the same problem every time my WAN IP changes.

[sfxdude]

I'm not really sure. I just tried rebooting my modem and it behaved as expected (opnsense got a new external IP after rejecting the internal IP initially) so I'm not sure if this is due to some update or if the issue was unrelated.

[sfxdude]

Just rebooted my modem, exactly the same as last time, and the problem remains. Last few lines of the dhclient log file are as follows:

Code Select Expand

2022-06-14T16:36:32+01:00 firewall.lan dhclient[48130]: dhclient already running, pid: 31342.
2022-06-14T16:36:32+01:00 firewall.lan dhclient[48130]: exiting.
2022-06-14T16:37:07+01:00 firewall.lan dhclient[27026]: dhclient already running, pid: 31342.
2022-06-14T16:37:07+01:00 firewall.lan dhclient[27026]: exiting.
2022-06-14T16:37:42+01:00 firewall.lan dhclient[75539]: dhclient already running, pid: 31342.
2022-06-14T16:37:42+01:00 firewall.lan dhclient[75539]: exiting.

Absolutely nothing else in the dhclient log relating to this loss of WAN, and the WAN never comes back, presumably because the dhclient has crashed / failed somehow. Any help appreciated.

[TParker31]

Thanks for the follow up. At least someone else has the same issue. My assumption is most people's IP doesn't change that often. I've gone years with the same dynamic IP. But lately network upgrades have caused mine to change more frequently.

[sfxdude]

Not sure this has anything to do with dynamic IPs with me - my IP has not changed for several years.