WAN fails to keep DHCP address on cable modem reboot
-
There's alot going on in the DHCP log but you can see igb3 is my WAN and this is basically what it keeps doing while it gets and drops the WAN DHCP...
Sep 13 17:04:53 dhclient 57131 bound to XX.XX.91.65 -- renewal in 227767 seconds. Sep 13 17:04:53 dhclient Creating resolv.conf Sep 13 17:04:53 dhclient Adding new routes to interface: igb3 Sep 13 17:04:53 dhclient New Routers (igb3): XX.XX.91.1 Sep 13 17:04:53 dhclient New Broadcast Address (igb3): 255.255.255.255 Sep 13 17:04:53 dhclient New Subnet Mask (igb3): 255.255.255.0 Sep 13 17:04:53 dhclient New IP Address (igb3): XX.XX.91.65 Sep 13 17:04:53 dhclient ifconfig igb3 inet XX.XX.91.65 netmask 255.255.255.0 broadcast 255.255.255.255 Sep 13 17:04:53 dhclient Starting add_new_address() Sep 13 17:04:53 dhclient REBOOT Sep 13 17:04:53 dhclient 57131 DHCPACK from 10.164.0.1 Sep 13 17:04:53 dhclient 57131 DHCPREQUEST on igb3 to 255.255.255.255 port 67 Sep 13 17:04:53 dhclient 57131 DHCPREQUEST on igb3 to 255.255.255.255 port 67 Sep 13 17:04:53 dhclient PREINIT Sep 13 17:04:47 dhclient 41003 exiting. Sep 13 17:04:47 dhclient 41003 connection closed Sep 13 17:04:47 dhcpd Server starting service. Sep 13 17:04:47 dhcpd Sending on Socket/fallback/fallback-net Sep 13 17:04:47 dhcpd Sending on BPF/igb1/ac:16:2d:a0:42:65/192.168.201.0/29 Sep 13 17:04:47 dhcpd Listening on BPF/igb1/ac:16:2d:a0:42:65/192.168.201.0/29 Sep 13 17:04:47 dhcpd Sending on BPF/igb2.300/ac:16:2d:a0:42:66/192.168.202.0/24 Sep 13 17:04:47 dhcpd Listening on BPF/igb2.300/ac:16:2d:a0:42:66/192.168.202.0/24 Sep 13 17:04:47 dhcpd Sending on BPF/igb2.400/ac:16:2d:a0:42:66/192.168.203.0/24 Sep 13 17:04:47 dhcpd Listening on BPF/igb2.400/ac:16:2d:a0:42:66/192.168.203.0/24 Sep 13 17:04:47 dhcpd Sending on BPF/igb2.500/ac:16:2d:a0:42:66/192.168.204.0/24 Sep 13 17:04:47 dhcpd Listening on BPF/igb2.500/ac:16:2d:a0:42:66/192.168.204.0/24 Sep 13 17:04:47 dhcpd Sending on BPF/igb0.1/ac:16:2d:a0:42:64/192.168.0.0/24 Sep 13 17:04:47 dhcpd Listening on BPF/igb0.1/ac:16:2d:a0:42:64/192.168.0.0/24 Sep 13 17:04:47 dhcpd Sending on BPF/igb2.900/ac:16:2d:a0:42:66/192.168.253.0/24 Sep 13 17:04:47 dhcpd Listening on BPF/igb2.900/ac:16:2d:a0:42:66/192.168.253.0/24 Sep 13 17:04:47 dhcpd Wrote 92 leases to leases file. Sep 13 17:04:47 dhcpd Wrote 0 new dynamic host decls to leases file. Sep 13 17:04:47 dhcpd Wrote 0 deleted host decls to leases file. Sep 13 17:04:47 dhcpd For info, please visit https://www.isc.org/software/dhcp/ Sep 13 17:04:47 dhcpd All rights reserved. Sep 13 17:04:47 dhcpd PID file: /var/run/dhcpd.pid Sep 13 17:04:47 dhcpd Copyright 2004-2018 Internet Systems Consortium. Sep 13 17:04:47 dhcpd Database file: /var/db/dhcpd.leases Sep 13 17:04:47 dhcpd Internet Systems Consortium DHCP Server 4.4.1 Sep 13 17:04:47 dhcpd Config file: /etc/dhcpd.conf Sep 13 17:04:47 dhcpd For info, please visit https://www.isc.org/software/dhcp/ Sep 13 17:04:47 dhcpd All rights reserved. Sep 13 17:04:47 dhcpd Copyright 2004-2018 Internet Systems Consortium. Sep 13 17:04:47 dhcpd Internet Systems Consortium DHCP Server 4.4.1 Sep 13 17:04:46 dhcpd Server starting service. Sep 13 17:04:46 dhcpd Sending on Socket/fallback/fallback-net Sep 13 17:04:46 dhcpd Sending on BPF/igb1/ac:16:2d:a0:42:65/192.168.201.0/29 Sep 13 17:04:46 dhcpd Listening on BPF/igb1/ac:16:2d:a0:42:65/192.168.201.0/29 Sep 13 17:04:46 dhcpd Sending on BPF/igb2.300/ac:16:2d:a0:42:66/192.168.202.0/24 Sep 13 17:04:46 dhcpd Listening on BPF/igb2.300/ac:16:2d:a0:42:66/192.168.202.0/24 Sep 13 17:04:46 dhcpd Sending on BPF/igb2.400/ac:16:2d:a0:42:66/192.168.203.0/24 Sep 13 17:04:46 dhcpd Listening on BPF/igb2.400/ac:16:2d:a0:42:66/192.168.203.0/24 Sep 13 17:04:46 dhcpd Sending on BPF/igb2.500/ac:16:2d:a0:42:66/192.168.204.0/24 Sep 13 17:04:46 dhcpd Listening on BPF/igb2.500/ac:16:2d:a0:42:66/192.168.204.0/24 Sep 13 17:04:46 dhcpd Sending on BPF/igb0.1/ac:16:2d:a0:42:64/192.168.0.0/24 Sep 13 17:04:46 dhcpd Listening on BPF/igb0.1/ac:16:2d:a0:42:64/192.168.0.0/24 Sep 13 17:04:46 dhcpd Sending on BPF/igb2.900/ac:16:2d:a0:42:66/192.168.253.0/24 Sep 13 17:04:46 dhcpd Listening on BPF/igb2.900/ac:16:2d:a0:42:66/192.168.253.0/24 Sep 13 17:04:46 dhcpd Wrote 92 leases to leases file. Sep 13 17:04:46 dhcpd Wrote 0 new dynamic host decls to leases file. Sep 13 17:04:46 dhcpd Wrote 0 deleted host decls to leases file. Sep 13 17:04:46 dhcpd For info, please visit https://www.isc.org/software/dhcp/ Sep 13 17:04:46 dhcpd All rights reserved. Sep 13 17:04:46 dhcpd PID file: /var/run/dhcpd.pid Sep 13 17:04:46 dhcpd Copyright 2004-2018 Internet Systems Consortium. Sep 13 17:04:46 dhcpd Database file: /var/db/dhcpd.leases Sep 13 17:04:46 dhcpd Internet Systems Consortium DHCP Server 4.4.1 Sep 13 17:04:46 dhcpd Config file: /etc/dhcpd.conf Sep 13 17:04:46 dhcpd For info, please visit https://www.isc.org/software/dhcp/ Sep 13 17:04:46 dhcpd All rights reserved. Sep 13 17:04:46 dhcpd Copyright 2004-2018 Internet Systems Consortium. Sep 13 17:04:46 dhcpd Internet Systems Consortium DHCP Server 4.4.1 Sep 13 17:04:42 dhclient 48494 bound to XX.XX.91.65 -- renewal in 227773 seconds. Sep 13 17:04:42 dhclient Creating resolv.conf Sep 13 17:04:42 dhclient /sbin/route add default XX.XX.91.1 Sep 13 17:04:42 dhclient Adding new routes to interface: igb3 Sep 13 17:04:42 dhclient New Routers (igb3): XX.XX.91.1 Sep 13 17:04:42 dhclient New Broadcast Address (igb3): 255.255.255.255 Sep 13 17:04:42 dhclient New Subnet Mask (igb3): 255.255.255.0 Sep 13 17:04:42 dhclient New IP Address (igb3): XX.XX.91.65 Sep 13 17:04:42 dhclient ifconfig igb3 inet XX.XX.91.65 netmask 255.255.255.0 broadcast 255.255.255.255 Sep 13 17:04:42 dhclient Starting add_new_address() Sep 13 17:04:42 dhclient REBOOT Sep 13 17:04:42 dhclient 48494 DHCPACK from 10.164.0.1 Sep 13 17:04:42 dhclient 48494 DHCPREQUEST on igb3 to 255.255.255.255 port 67 Sep 13 17:04:42 dhclient PREINIT Sep 13 17:04:37 dhclient 48260 exiting. Sep 13 17:04:37 dhclient 48260 connection closed Sep 13 17:04:37 dhcpd Server starting service. Sep 13 17:04:37 dhcpd Sending on Socket/fallback/fallback-net Sep 13 17:04:37 dhcpd Sending on BPF/igb1/ac:16:2d:a0:42:65/192.168.201.0/29 Sep 13 17:04:37 dhcpd Listening on BPF/igb1/ac:16:2d:a0:42:65/192.168.201.0/29 Sep 13 17:04:37 dhcpd Sending on BPF/igb2.300/ac:16:2d:a0:42:66/192.168.202.0/24 Sep 13 17:04:37 dhcpd Listening on BPF/igb2.300/ac:16:2d:a0:42:66/192.168.202.0/24 Sep 13 17:04:37 dhcpd Sending on BPF/igb2.400/ac:16:2d:a0:42:66/192.168.203.0/24 Sep 13 17:04:37 dhcpd Listening on BPF/igb2.400/ac:16:2d:a0:42:66/192.168.203.0/24 Sep 13 17:04:37 dhcpd Sending on BPF/igb2.500/ac:16:2d:a0:42:66/192.168.204.0/24 Sep 13 17:04:37 dhcpd Listening on BPF/igb2.500/ac:16:2d:a0:42:66/192.168.204.0/24 Sep 13 17:04:37 dhcpd Sending on BPF/igb0.1/ac:16:2d:a0:42:64/192.168.0.0/24 Sep 13 17:04:37 dhcpd Listening on BPF/igb0.1/ac:16:2d:a0:42:64/192.168.0.0/24 Sep 13 17:04:37 dhcpd Sending on BPF/igb2.900/ac:16:2d:a0:42:66/192.168.253.0/24 Sep 13 17:04:37 dhcpd Listening on BPF/igb2.900/ac:16:2d:a0:42:66/192.168.253.0/24 Sep 13 17:04:37 dhcpd Wrote 92 leases to leases file. Sep 13 17:04:37 dhcpd Wrote 0 new dynamic host decls to leases file. Sep 13 17:04:37 dhcpd Wrote 0 deleted host decls to leases file. Sep 13 17:04:37 dhcpd For info, please visit https://www.isc.org/software/dhcp/ Sep 13 17:04:37 dhcpd All rights reserved. Sep 13 17:04:37 dhcpd PID file: /var/run/dhcpd.pid Sep 13 17:04:37 dhcpd Copyright 2004-2018 Internet Systems Consortium. Sep 13 17:04:37 dhcpd Database file: /var/db/dhcpd.leases Sep 13 17:04:37 dhcpd Internet Systems Consortium DHCP Server 4.4.1 Sep 13 17:04:37 dhcpd Config file: /etc/dhcpd.conf``` -
This is what the system log looks like:
Sep 13 17:05:23 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:22 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:22 php-fpm 81635 /rc.start_packages: Skipping STARTing packages process because previous/another instance is already running Sep 13 17:05:22 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:22 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:22 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:21 check_reload_status Starting packages Sep 13 17:05:21 php-fpm 81635 /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - XX.XX.91.65 -> XX.XX.91.65 - Restarting packages. Sep 13 17:05:21 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:21 php-fpm 341 /rc.start_packages: Skipping STARTing packages process because previous/another instance is already running Sep 13 17:05:21 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:21 php-fpm 17728 /rc.dyndns.update: Gateway, switch to: Sep 13 17:05:21 kernel igb3: link state changed to DOWN Sep 13 17:05:21 check_reload_status Linkup starting igb3 Sep 13 17:05:21 php-fpm 342 /rc.linkup: HOTPLUG: Configuring interface wan Sep 13 17:05:21 php-fpm 342 /rc.linkup: DEVD Ethernet attached event for wan Sep 13 17:05:21 kernel config_aqm Unable to configure flowset, flowset busy! Sep 13 17:05:21 kernel config_aqm Unable to configure flowset, flowset busy! Sep 13 17:05:20 check_reload_status Starting packages Sep 13 17:05:20 php-fpm 17728 /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - -> 192.168.94.1 - Restarting packages. Sep 13 17:05:20 check_reload_status Reloading filter Sep 13 17:05:20 php-fpm 17728 /rc.newwanip: rc.newwanip called with empty interface. Sep 13 17:05:20 php-fpm 17728 /rc.newwanip: rc.newwanip: on (IP address: 192.168.94.1) (interface: []) (real interface: ovpns1). Sep 13 17:05:20 php-fpm 17728 /rc.newwanip: rc.newwanip: Info: starting on ovpns1. Sep 13 17:05:20 php-fpm 58507 /rc.linkup: DEVD Ethernet detached event for wan Sep 13 17:05:20 check_reload_status updating dyndns wan Sep 13 17:05:19 check_reload_status rc.newwanip starting ovpns1 Sep 13 17:05:19 php-fpm 81635 /rc.newwanip: Creating rrd update script Sep 13 17:05:19 check_reload_status Reloading filter Sep 13 17:05:19 php-fpm 81635 OpenVPN PID written: 59986 Sep 13 17:05:19 kernel ovpns1: link state changed to UP Sep 13 17:05:19 check_reload_status Reloading filter Sep 13 17:05:19 kernel ovpns1: link state changed to DOWN Sep 13 17:05:19 php-fpm 81635 OpenVPN terminate old pid: 36255 Sep 13 17:05:18 php-fpm 81635 /rc.newwanip: Resyncing OpenVPN instances for interface WAN. Sep 13 17:05:18 kernel config_aqm Unable to configure flowset, flowset busy! Sep 13 17:05:18 kernel config_aqm Unable to configure flowset, flowset busy! Sep 13 17:05:17 php-fpm 17728 /rc.linkup: The command '/usr/local/sbin/unbound -c /var/unbound/unbound.conf' returned exit code '1', the output was '[1600031117] unbound[63691:0] error: bind: address already in use [1600031117] unbound[63691:0] fatal error: could not open ports' Sep 13 17:05:17 vnstatd 56478 Error: pidfile "/var/run/vnstat/vnstat.pid" lock failed (Resource temporarily unavailable), exiting. Sep 13 17:05:17 php-fpm 74546 /rc.start_packages: [Snort] Seems preprocessor and/or decoder rules are missing, enabling autogeneration of them in conf file. Sep 13 17:05:17 php-fpm 74546 /rc.start_packages: Restarting/Starting all packages. Sep 13 17:05:17 php-fpm 3293 /rc.newwanip: Default gateway setting Interface WAN_DHCP Gateway as default. Sep 13 17:05:17 php-fpm 3293 /rc.newwanip: Gateway, switch to: WAN_DHCP Sep 13 17:05:17 php-fpm 3293 /rc.newwanip: 3293MONITOR: WAN_DHCP is available now, adding to routing group Failover XX.XX.91.1|XX.XX.91.65|WAN_DHCP|181.088ms|170.287ms|0.0%|none Sep 13 17:05:16 check_reload_status Starting packages Sep 13 17:05:16 php-fpm 74546 /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - -> 192.168.94.1 - Restarting packages. Sep 13 17:05:16 check_reload_status Reloading filter Sep 13 17:05:16 php-fpm 74546 /rc.newwanip: rc.newwanip called with empty interface. Sep 13 17:05:16 php-fpm 74546 /rc.newwanip: rc.newwanip: on (IP address: 192.168.94.1) (interface: []) (real interface: ovpns1). Sep 13 17:05:16 php-fpm 74546 /rc.newwanip: rc.newwanip: Info: starting on ovpns1. Sep 13 17:05:15 check_reload_status rc.newwanip starting ovpns1 Sep 13 17:05:15 php-fpm 13778 OpenVPN PID written: 36255 Sep 13 17:05:15 kernel ovpns1: link state changed to UP Sep 13 17:05:15 php-fpm 3293 /rc.newwanip: rc.newwanip: on (IP address: XX.XX.91.65) (interface: WAN[wan]) (real interface: igb3). Sep 13 17:05:15 php-fpm 3293 /rc.newwanip: rc.newwanip: Info: starting on igb3. Sep 13 17:05:15 check_reload_status Reloading filter Sep 13 17:05:15 kernel ovpns1: link state changed to DOWN Sep 13 17:05:15 php-fpm 13778 OpenVPN terminate old pid: 23890 Sep 13 17:05:14 php-fpm 13778 /rc.openvpn: OpenVPN: Resync server1 Mobile VPN Clients Sep 13 17:05:14 php-fpm 13778 /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use WAN_DHCP. Sep 13 17:05:14 check_reload_status Restarting ipsec tunnels Sep 13 17:05:14 php-fpm 17728 /rc.linkup: Default gateway setting Interface WAN2_DHCP Gateway as default. Sep 13 17:05:14 php-fpm 17728 /rc.linkup: Gateway, switch to: WAN2_DHCP Sep 13 17:05:14 php-fpm 17728 /rc.linkup: MONITOR: WAN_DHCP is down, omitting from routing group Failover XX.XX.91.1|XX.XX.91.65|WAN_DHCP|7.899ms|0.762ms|50%|down Sep 13 17:05:14 check_reload_status rc.newwanip starting igb3 Sep 13 17:05:14 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:14 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:13 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:13 check_reload_status Reloading filter Sep 13 17:05:13 check_reload_status Restarting OpenVPN tunnels/interfaces Sep 13 17:05:13 check_reload_status Restarting ipsec tunnels Sep 13 17:05:13 check_reload_status updating dyndns WAN_DHCP Sep 13 17:05:13 rc.gateway_alarm 98935 >>> Gateway alarm: WAN_DHCP (Addr:XX.XX.91.1 Alarm:1 RTT:7.899ms RTTsd:.762ms Loss:41%) Sep 13 17:05:13 kernel igb3: link state changed to UP Sep 13 17:05:13 check_reload_status Linkup starting igb3 Sep 13 17:05:13 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:13 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:12 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:12 vnstatd 94333 Monitoring (16): re0 (1000 Mbit) pfsync0 (1000 Mbit) pflog0 (1000 Mbit) ovpns1 (1000 Mbit) igb3 (1000 Mbit) igb2.900 (1000 Mbit) igb2.800 (1000 Mbit) igb2.500 (1000 Mbit) igb2.400 (1000 Mbit) igb2.300 (1000 Mbit) igb2 (1000 Mbit) igb1 (1000 Mbit) igb0.600 (1000 Mbit) igb0.1 (1000 Mbit) igb0 (1000 Mbit) enc0 (1000 Mbit) Sep 13 17:05:12 vnstatd 94333 vnStat daemon 2.4 started. (pid:94333 uid:0 gid:0) Sep 13 17:05:12 vnstatd 94917 Error: pidfile "/var/run/vnstat/vnstat.pid" lock failed (Resource temporarily unavailable), exiting. Sep 13 17:05:12 vnstatd 59802 SIGTERM received, exiting. Sep 13 17:05:12 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:12 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:11 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:11 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:11 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:10 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:10 php-fpm 342 /rc.start_packages: Skipping STARTing packages process because previous/another instance is already running Sep 13 17:05:10 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:10 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:09 php-fpm 58507 /rc.start_packages: Skipping STARTing packages process because previous/another instance is already running Sep 13 17:05:09 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:09 check_reload_status Starting packages Sep 13 17:05:09 php-fpm 342 /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - XX.XX.91.65 -> XX.XX.91.65 - Restarting packages. Sep 13 17:05:09 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:09 php-fpm 3293 /rc.filter_configure_sync: Gateway, switch to: Sep 13 17:05:09 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:09 check_reload_status Linkup starting igb3 Sep 13 17:05:09 kernel igb3: link state changed to DOWN Sep 13 17:05:09 php-fpm 74546 /rc.dyndns.update: Default gateway setting Interface WAN_DHCP Gateway as default. Sep 13 17:05:09 php-fpm 74546 /rc.dyndns.update: Gateway, switch to: WAN_DHCP Sep 13 17:05:09 php-fpm 17728 /rc.linkup: HOTPLUG: Configuring interface wan Sep 13 17:05:09 php-fpm 17728 /rc.linkup: DEVD Ethernet attached event for wan Sep 13 17:05:08 check_reload_status Starting packages Sep 13 17:05:08 php-fpm 74546 /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - -> 192.168.94.1 - Restarting packages. Sep 13 17:05:08 check_reload_status Reloading filter Sep 13 17:05:08 php-fpm 74546 /rc.newwanip: rc.newwanip called with empty interface. Sep 13 17:05:08 php-fpm 74546 /rc.newwanip: rc.newwanip: on (IP address: 192.168.94.1) (interface: []) (real interface: ovpns1). Sep 13 17:05:08 php-fpm 74546 /rc.newwanip: rc.newwanip: Info: starting on ovpns1. Sep 13 17:05:08 php-fpm 58507 /rc.linkup: DEVD Ethernet detached event for wan Sep 13 17:05:08 check_reload_status updating dyndns wan Sep 13 17:05:07 check_reload_status rc.newwanip starting ovpns1 Sep 13 17:05:07 php-fpm 342 /rc.newwanip: Creating rrd update script Sep 13 17:05:07 check_reload_status Reloading filter Sep 13 17:05:07 php-fpm 342 OpenVPN PID written: 23890 Sep 13 17:05:07 kernel ovpns1: link state changed to UP Sep 13 17:05:07 check_reload_status Reloading filter Sep 13 17:05:07 kernel ovpns1: link state changed to DOWN Sep 13 17:05:07 php-fpm 342 OpenVPN terminate old pid: 19176 Sep 13 17:05:07 php-fpm 341 /rc.start_packages: Skipping STARTing packages process because previous/another instance is already running Sep 13 17:05:06 php-fpm 342 /rc.newwanip: Resyncing OpenVPN instances for interface WAN. Sep 13 17:05:06 kernel config_aqm Unable to configure flowset, flowset busy! Sep 13 17:05:06 php-fpm 81635 /rc.newwanip: Default gateway setting Interface WAN_DHCP Gateway as default. Sep 13 17:05:06 php-fpm 81635 /rc.newwanip: Gateway, switch to: WAN_DHCP Sep 13 17:05:06 php-fpm 81635 /rc.newwanip: 81635MONITOR: WAN_DHCP is available now, adding to routing group Failover XX.XX.91.1|XX.XX.91.65|WAN_DHCP|8.419ms|0.018ms|0.0%|none Sep 13 17:05:06 check_reload_status Starting packages Sep 13 17:05:06 php-fpm 341 /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - -> 192.168.94.1 - Restarting packages. Sep 13 17:05:06 check_reload_status Reloading filter Sep 13 17:05:06 php-fpm 341 /rc.newwanip: rc.newwanip called with empty interface. Sep 13 17:05:06 php-fpm 341 /rc.newwanip: rc.newwanip: on (IP address: 192.168.94.1) (interface: []) (real interface: ovpns1). Sep 13 17:05:06 php-fpm 341 /rc.newwanip: rc.newwanip: Info: starting on ovpns1. Sep 13 17:05:04 check_reload_status rc.newwanip starting ovpns1 Sep 13 17:05:04 php-fpm 74546 OpenVPN PID written: 19176 Sep 13 17:05:04 kernel ovpns1: link state changed to UP Sep 13 17:05:04 php-fpm 81635 /rc.newwanip: rc.newwanip: on (IP address: XX.XX.91.65) (interface: WAN[wan]) (real interface: igb3). Sep 13 17:05:04 php-fpm 81635 /rc.newwanip: rc.newwanip: Info: starting on igb3. Sep 13 17:05:04 check_reload_status Reloading filter Sep 13 17:05:04 kernel ovpns1: link state changed to DOWN Sep 13 17:05:04 php-fpm 74546 OpenVPN terminate old pid: 69251 Sep 13 17:05:04 php-fpm 74546 /rc.openvpn: OpenVPN: Resync server1 Mobile VPN Clients Sep 13 17:05:04 php-fpm 74546 /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use WAN_DHCP. Sep 13 17:05:03 check_reload_status Restarting ipsec tunnels Sep 13 17:05:03 php-fpm 3293 /rc.linkup: Default gateway setting Interface WAN2_DHCP Gateway as default. Sep 13 17:05:03 php-fpm 3293 /rc.linkup: Gateway, switch to: WAN2_DHCP Sep 13 17:05:03 php-fpm 3293 /rc.linkup: MONITOR: WAN_DHCP is down, omitting from routing group Failover XX.XX.91.1|XX.XX.91.65|WAN_DHCP|33.94ms|50.375ms|50%|down Sep 13 17:05:03 check_reload_status rc.newwanip starting igb3 Sep 13 17:05:03 php-fpm 81635 /rc.start_packages: Skipping STARTing packages process because previous/another instance is already running Sep 13 17:05:03 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:03 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:02 check_reload_status Reloading filter Sep 13 17:05:02 check_reload_status Restarting OpenVPN tunnels/interfaces Sep 13 17:05:02 check_reload_status Restarting ipsec tunnels Sep 13 17:05:02 check_reload_status updating dyndns WAN_DHCP Sep 13 17:05:02 rc.gateway_alarm 83092 >>> Gateway alarm: WAN_DHCP (Addr:XX.XX.91.1 Alarm:1 RTT:33.940ms RTTsd:50.375ms Loss:45%) Sep 13 17:05:02 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:02 check_reload_status Linkup starting igb3 Sep 13 17:05:02 kernel igb3: link state changed to UP Sep 13 17:05:02 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:02 vnstatd 79078 Error: pidfile "/var/run/vnstat/vnstat.pid" lock failed (Resource temporarily unavailable), exiting. Sep 13 17:05:02 php-fpm 13778 /rc.start_packages: [Snort] Seems preprocessor and/or decoder rules are missing, enabling autogeneration of them in conf file. Sep 13 17:05:02 check_reload_status Starting packages Sep 13 17:05:02 php-fpm 81635 /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 192.168.100.10 -> XX.XX.91.65 - Restarting packages. Sep 13 17:05:02 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:02 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:02 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:02 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:02 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:02 php-fpm 13778 /rc.start_packages: Restarting/Starting all packages. Sep 13 17:05:02 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:01 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:01 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:01 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:01 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:01 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:01 kernel arpresolve: can't allocate llinfo for XX.XX.91.1 on igb3 Sep 13 17:05:01 check_reload_status Starting packages -
@BlankSpace said in WAN fails to keep DHCP address on cable modem reboot:
Sep 13 17:05:09 kernel igb3: link state changed to DOWN
It looks to be actually losing link. Do you see the link LEDs go out on the connection when that happens?
Try the obvious stuff if so, swap out the cable. try re-assigning the WAN to a different port. See if the fault follows it.
If it's a link negotiation issue try putting a switch in between pfSense and the modem.
Steve
-
On the Arris cable modems, the link seems to go down each time and then the CM reboots and its a cycle. Since I purchased Netgear CM, it does not reboot each time, but the pfs WAN keeps cycling like that infinitely. If I do a restart on pfs, everything comes up normal.
-
But you do see the actual Ethernet link go down?
That's what the logs indicate is happening but it's always good to check the link LEDs.
Same advice applies though.
Steve
-
Just checked it and yes the link goes down, the led light goes out each time it recycles.
-
Then;
Swap the cable.
Reassign the port.
Put a switch in between.See if any of that makes any difference.
Steve
-
I've swapped patch cables but they're all new 3' Commscope CAT6A cables that I have and I've changed physical interface assignments but it still does it. I'll try putting a switch on between when I can fiddle with it again. Wife works from home all day so I have limited time to play with stuff.
-
@BlankSpace said in WAN fails to keep DHCP address on cable modem reboot:
I've changed physical interface assignments
You have already tried to set automatic speed negotiation to fixed.
(of course according to the pfSense interface and modem interface)Sometimes it helps
-
@DaddyGo said in WAN fails to keep DHCP address on cable modem reboot:
@BlankSpace said in WAN fails to keep DHCP address on cable modem reboot:
I've changed physical interface assignments
You have already tried to set automatic speed negotiation to fixed.
(of course according to the pfSense interface and modem interface)Sometimes it helps
Do you mean set it to automatic or set it to something manual? I believe it is already set to automatic by default.
-
If it's a link negotiation issue (it keeps re-negotiating) setting it fixed may remove that. But the other end must also support a fixed speed/duplex link for that to work.
Steve
-
It is set to auto, I have not tried to manually set it to 1000 Full. I will try it once I have an open window to do some tinkering.
-
@BlankSpace said in WAN fails to keep DHCP address on cable modem reboot:
I believe it is already set to automatic by default.
these are usually automatic by default...
your two devices (modem / pfSense eth.ports) probably there are different - different eth. controllers (Intel, Realtek, etc.)
these controllers often have a trial with speed matching - especially Realtek stuff and thus are placed in a speed matching loop
-
I forced the speed at 1000 and duplex at full, bounced the WAN interface and it came back up and grabbed the IP with no issues. This may be the solution...
-
Nice. You still get the expected throughput?
-
Well, I am not sure. I thought it looked like my RTT and RTTsd increased a little and then I did some speedtests from the pfs command line and they were all over the place. So it is possible my throughput suffered, or just busy cable at this time of the night. I will need to try some speedtests at different times to confirm.
However, since it seemed to solve the problem by adjusting the negotiation, what other workarounds would there be if indeed my throughput suffered from forcing negotiation?
-
If you set a fixed speed at one end you would usually have to set it fixed at both ends. Otherwise the other side might default to 100Mb half or something.
Putting a switch in between would also remove negotiation issues between those two specific devices as both then negotiate with the switch instead.Steve
-
Ah, yes I forgot about that option. Any reason it only happens if the interface is disabled or loses the link with the cable modem when the modem reboots? When I restart pfs there are no issues.
-
Hmm, well that might imply it negotiates differently when the modem comes up.
If your modem really is just a modem and doesn't have a switch IC then I would expect to see a speed/duplex mismatch if you set pfSense to fixed. That usually kills throughput as you get loads or errors on the interface.
Adding a switch in between would be a better test in that situation.
Steve
-
I had two modems that did this, the first was the cable company provided Arris CM8200. The Arris modems would actually go into a boot loop everytime pfs dropped the IP and tried to renegotiate. They would actually lose signal on the cable end and just keep looping until pfs was restarted.
Then I purchased my own Netgear Nighthawk CM1200. The Netgear has 4 ports but it is not a switch per se, it is for link aggregation and multiple IP address.
I just tested speed this morning when manually forcing 1000/full and it did indeed go down, by alot, each time I did the speedtest.
I do have some spare switches laying around that I will try. It's not really too big of an issue because I can always restart pfs and in 60 seconds its back up anyway. But sometimes I want to quickly bounce the cable modem to clear the logs and not have to restart pfs.
Copyright 2025 Rubicon Communications LLC (Netgate). All rights reserved.