ipv4 WAN DHCP renews, loss of internet, unknown dhcp option value 0x52

[JasonWallace]

Running OPNsense 23.7.1_3-amd64.

Dual WAN setup.

WAN_MTS_DHCP is FTTP, DHCP. The ISP has set the lease time at 10 minutes. This is the one with the issue.
WAN_SHAW_DHCP is Cable modem DCHP. The ISP set the lease time to 48 hours, no issues here.

Every 24 hours at the same time WAN_MTS_DHCP becomes unusable for a few minutes. This happens during the dhcp renewal, the IP and gateway don't change.


Of interest in the system log file for this renewal time only is the error: unknown dhcp option value 0x52
All of the other renewals at 5 min don't have this error. I suspect this error then causes the connection to no longer be usable until it can renew again.

Log entries below, it occured at 13:45:36-05:00

System log entries:

Code Select Expand


<13>1 2023-08-23T13:16:57-05:00 OPNsense.wallacemanor dhclient 90739 - [meta sequenceId="2"] Creating resolv.conf
<13>1 2023-08-23T13:17:00-05:00 OPNsense.wallacemanor send_telemetry.py 94583 - [meta sequenceId="3"] telemetry data collected 1 records in 0.02 seconds @2023-08-23 18:16:30.112420
<13>1 2023-08-23T13:21:00-05:00 OPNsense.wallacemanor send_telemetry.py 24392 - [meta sequenceId="1"] telemetry data collected 1 records in 0.02 seconds @2023-08-23 18:20:53.370728
<13>1 2023-08-23T13:21:57-05:00 OPNsense.wallacemanor dhclient 14227 - [meta sequenceId="2"] Creating resolv.conf
<13>1 2023-08-23T13:22:00-05:00 OPNsense.wallacemanor send_telemetry.py 64045 - [meta sequenceId="3"] telemetry data collected 1 records in 0.02 seconds @2023-08-23 18:21:28.719045
<13>1 2023-08-23T13:26:57-05:00 OPNsense.wallacemanor dhclient 86446 - [meta sequenceId="1"] Creating resolv.conf
<13>1 2023-08-23T13:28:00-05:00 OPNsense.wallacemanor send_telemetry.py 20817 - [meta sequenceId="1"] telemetry data collected 1 records in 0.02 seconds @2023-08-23 18:27:43.847688
<13>1 2023-08-23T13:31:57-05:00 OPNsense.wallacemanor dhclient 52426 - [meta sequenceId="1"] Creating resolv.conf
<13>1 2023-08-23T13:33:00-05:00 OPNsense.wallacemanor send_telemetry.py 4797 - [meta sequenceId="1"] telemetry data collected 1 records in 0.02 seconds @2023-08-23 18:32:43.727757
<13>1 2023-08-23T13:34:00-05:00 OPNsense.wallacemanor send_telemetry.py 29824 - [meta sequenceId="2"] telemetry data collected 3 records in 0.02 seconds @2023-08-23 18:33:07.500776
<13>1 2023-08-23T13:36:58-05:00 OPNsense.wallacemanor dhclient 27783 - [meta sequenceId="1"] Creating resolv.conf
<13>1 2023-08-23T13:37:00-05:00 OPNsense.wallacemanor send_telemetry.py 32450 - [meta sequenceId="2"] telemetry data collected 1 records in 0.02 seconds @2023-08-23 18:36:23.084067
<13>1 2023-08-23T13:41:58-05:00 OPNsense.wallacemanor dhclient 48610 - [meta sequenceId="1"] Creating resolv.conf
<13>1 2023-08-23T13:44:00-05:00 OPNsense.wallacemanor send_telemetry.py 21680 - [meta sequenceId="1"] telemetry data collected 1 records in 0.02 seconds @2023-08-23 18:43:35.180707
<27>1 2023-08-23T13:45:36-05:00 OPNsense.wallacemanor dhclient 50343 - [meta sequenceId="1"] unknown dhcp option value 0x52
<13>1 2023-08-23T13:45:36-05:00 OPNsense.wallacemanor dhclient 66904 - [meta sequenceId="2"] Creating resolv.conf
<13>1 2023-08-23T13:45:45-05:00 OPNsense.wallacemanor opnsense 82037 - [meta sequenceId="3"] /usr/local/etc/rc.routing_configure: ROUTING: entering configure using defaults
<13>1 2023-08-23T13:45:45-05:00 OPNsense.wallacemanor opnsense 82037 - [meta sequenceId="4"] /usr/local/etc/rc.routing_configure: ROUTING: configuring inet default gateway on opt2
<13>1 2023-08-23T13:45:45-05:00 OPNsense.wallacemanor opnsense 82037 - [meta sequenceId="5"] /usr/local/etc/rc.routing_configure: ROUTING: keeping current inet default gateway '142.161.<removed>'
<13>1 2023-08-23T13:46:00-05:00 OPNsense.wallacemanor send_telemetry.py 93735 - [meta sequenceId="6"] telemetry data collected 2 records in 0.02 seconds @2023-08-23 18:45:59.098543
<13>1 2023-08-23T13:46:19-05:00 OPNsense.wallacemanor opnsense 19845 - [meta sequenceId="7"] /usr/local/etc/rc.routing_configure: ROUTING: entering configure using defaults
<13>1 2023-08-23T13:46:19-05:00 OPNsense.wallacemanor opnsense 19845 - [meta sequenceId="8"] /usr/local/etc/rc.routing_configure: ROUTING: ignoring down gateways: WAN_MTS_DHCP
<13>1 2023-08-23T13:46:19-05:00 OPNsense.wallacemanor opnsense 19845 - [meta sequenceId="9"] /usr/local/etc/rc.routing_configure: ROUTING: configuring inet default gateway on opt1
<13>1 2023-08-23T13:46:19-05:00 OPNsense.wallacemanor opnsense 19845 - [meta sequenceId="10"] /usr/local/etc/rc.routing_configure: ROUTING: setting inet default route to 24.77.<removed>
<13>1 2023-08-23T13:47:00-05:00 OPNsense.wallacemanor send_telemetry.py 16802 - [meta sequenceId="11"] telemetry data collected 2 records in 0.02 seconds @2023-08-23 18:45:59.098543
<13>1 2023-08-23T13:47:10-05:00 OPNsense.wallacemanor opnsense 43418 - [meta sequenceId="12"] /usr/local/etc/rc.routing_configure: ROUTING: entering configure using defaults
<13>1 2023-08-23T13:47:10-05:00 OPNsense.wallacemanor opnsense 43418 - [meta sequenceId="13"] /usr/local/etc/rc.routing_configure: ROUTING: configuring inet default gateway on opt2
<13>1 2023-08-23T13:47:10-05:00 OPNsense.wallacemanor opnsense 43418 - [meta sequenceId="14"] /usr/local/etc/rc.routing_configure: ROUTING: setting inet default route to 142.161.<removed>
<13>1 2023-08-23T13:47:17-05:00 OPNsense.wallacemanor dhclient 60872 - [meta sequenceId="15"] Creating resolv.conf
<13>1 2023-08-23T13:47:21-05:00 OPNsense.wallacemanor opnsense 65721 - [meta sequenceId="16"] /usr/local/etc/rc.routing_configure: ROUTING: entering configure using defaults
<13>1 2023-08-23T13:47:21-05:00 OPNsense.wallacemanor opnsense 65721 - [meta sequenceId="17"] /usr/local/etc/rc.routing_configure: ROUTING: configuring inet default gateway on opt2
<13>1 2023-08-23T13:47:21-05:00 OPNsense.wallacemanor opnsense 65721 - [meta sequenceId="18"] /usr/local/etc/rc.routing_configure: ROUTING: keeping current inet default gateway '142.161.<removed>'
<13>1 2023-08-23T13:51:00-05:00 OPNsense.wallacemanor send_telemetry.py 45205 - [meta sequenceId="1"] telemetry data collected 1 records in 0.02 seconds @2023-08-23 18:50:52.628503
<13>1 2023-08-23T13:52:00-05:00 OPNsense.wallacemanor send_telemetry.py 70388 - [meta sequenceId="2"] telemetry data collected 21 records in 0.02 seconds @2023-08-23 18:51:55.425587
<13>1 2023-08-23T13:52:17-05:00 OPNsense.wallacemanor dhclient 93970 - [meta sequenceId="3"] Creating resolv.conf
<13>1 2023-08-23T13:53:00-05:00 OPNsense.wallacemanor send_telemetry.py 28448 - [meta sequenceId="4"] telemetry data collected 6 records in 0.02 seconds @2023-08-23 18:52:12.366204


I had hoped to see something odd in /var/db/dhclient.leases.re0 with regards to dhcp option 82, but the contents don't have anyting.
contents of WAN_MTS_DHCP's /var/db/dhclient.leases.re0:

Code Select Expand


lease {
  interface "re0";
  fixed-address 142.161.<removed>;
  option subnet-mask 255.255.248.0;
  option routers 142.161.<removed>;
  option domain-name-servers 216.130.71.71,216.130.71.72;
  option dhcp-lease-time 600;
  option dhcp-message-type 5;
  option dhcp-server-identifier 192.168.100.254;
  renew 3 2023/8/23 18:36:57;
  rebind 3 2023/8/23 18:40:42;
  expire 3 2023/8/23 18:41:57;
}
lease {
  interface "re0";
  fixed-address 142.161.<removed>;
  option subnet-mask 255.255.248.0;
  option routers 142.161.<removed>;
  option domain-name-servers 216.130.71.71,216.130.71.72;
  option dhcp-lease-time 600;
  option dhcp-message-type 5;
  option dhcp-server-identifier 192.168.100.254;
  renew 3 2023/8/23 18:41:58;
  rebind 3 2023/8/23 18:45:43;
  expire 3 2023/8/23 18:46:58;
}
lease {
  interface "re0";
  fixed-address 142.161.<removed>;
  option subnet-mask 255.255.248.0;
  option routers 142.161.<removed>;
  option domain-name-servers 216.130.71.71,216.130.71.72;
  option dhcp-lease-time 600;
  option dhcp-message-type 5;
  option dhcp-server-identifier 192.168.100.254;
  renew 3 2023/8/23 18:46:58;
  rebind 3 2023/8/23 18:50:43;
  expire 3 2023/8/23 18:51:58;
}
lease {
  interface "re0";
  fixed-address 142.161.<removed>;
  option subnet-mask 255.255.248.0;
  option routers 142.161.<removed>;
  option domain-name-servers 216.130.71.71,216.130.71.72;
  option dhcp-lease-time 600;
  option dhcp-message-type 5;
  option dhcp-server-identifier 192.168.100.254;
  renew 3 2023/8/23 18:52:17;
  rebind 3 2023/8/23 18:56:02;
  expire 3 2023/8/23 18:57:17;
}


[franco]

https://www.juniper.net/documentation/us/en/software/junos/security-services/topics/concept/port-security-dhcp-option-82.html

suggests you shouldn't see this option, see: "4. The switching device strips the option 82 information from the response packet."

Given that you actually see the option being given to you (step 5) would mean that something is really wrong during that time in the ISP's network and connectivity to the server might not be possible.

A pending renew should not remove route or address until the renew goes through.

This also suggests it's an ISP issue: https://forum.opnsense.org/index.php?topic=28391.0


Cheers,
Franco

[JasonWallace]

Chances of getting one of our national ISP's (Canada) to fix this are slim to none.

I checked the /var/db/dhclient.leases.re1 entry for the second WAN connection (one that works) and it has an option-82 entry in it.

Seems a byproduct of placing their equipment in "bridge mode".

I though I would add a supersede option-82 to the DHCP advanced settings on the flakey WAN. In an attempt to create an ignore for it. It didn't like nothing after the option-82. I even copied the values from the working WAN into it... it took it.

It went from bad to worse then. No traffic was flowing through that WAN connection. Removing the supersede option-82 didn't seem to fix it. And soon afterwards the working second WAN was no longer working.

Sadly my Opnsense box which has been working fairly well for the past 6 months is now powered off and collecting dust until I can circle back to it.