WAN fails to keep DHCP address on cable modem reboot
-
I recently started having an issue where if I reboot the cable modem to clear the CM log or any other reason, pfs fails to keep the WAN dhcp address.
For example, after the modem restart, pfs obtains the correct gateway IP and DHCP IP. But then it drops it and keeps cycling like this in a loop. Gets the address, drops it, gets the address, drops it. The only way to "fix" it is to do a restart of the pfs box and then the WAN comes up with no issues. I normally have the WAN interface set to reject leases from 192.168.100.1 but that now has no effect on the issue because pfs is getting the proper WAN IP. This happens with my previous Arris CM8200 modem and my new Netgear Nighthawk CM1200 modem.
Any ideas?
-
@BlankSpace said in WAN fails to keep DHCP address on cable modem reboot:
pfs fails to keep the WAN dhcp address.
Hi,
This is an old theme with us, for some reason, this behavior is typical only of DOCSIS cable modems.
We’ve talked a lot about this behavior here on the forum, it’s worth following it up and reading about it.
Some special behavior with the CMTS and edgeQAM settings of DOCSIS systems and they affect users (subscribers), such as "Prerequisites for Cable DHCP Leasequery" / DHCP MAC Address Exclusion List / etc.
-
You have logs? dhcp and/or system, showing the failure?
Steve
-
Not at the moment but I will clear them and recreate the issue to get some logs.
-
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?