WAN flaps when cable disconnected



  • If I force it by disconnecting the WAN interface cable or if the DHCP renewal occurs the WAN interface goes up and down indefinitely until I reboot the device. I was having the same problem in the stable release, but figured I'd try the snapshot to see if it was resolved. It still seems to be an issue. I'm new to pfsense which logs should I post?



  • Can you post your system logs for this.
    I do not expect these issues as it should recover itself on up/down events.



  • Here's a snippet of the log:
    Dec 2 00:42:38 php-fpm[5525]: /rc.interfaces_wan_configure: The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf re0 > /tmp/re0_output 2> /tmp/re0_error_output' returned exit code '1', the output was ''
    Dec 2 00:42:39 kernel: arpresolve: can't allocate llinfo for 192.168.1.1 on re0
    Dec 2 00:42:39 php-fpm[9799]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 2 00:42:39 dhcpleases: Could not deliver signal HUP to process because its pidfile (/var/run/dnsmasq.pid) does not exist, No such process.
    Dec 2 00:42:40 check_reload_status: Linkup starting re0
    Dec 2 00:42:40 kernel: re0: link state changed to UP
    Dec 2 00:42:40 check_reload_status: rc.newwanip starting re0
    Dec 2 00:42:40 php-fpm[88597]: /rc.linkup: ROUTING: setting default route to 192.168.1.1
    Dec 2 00:42:41 php-fpm[9799]: /rc.linkup: DEVD Ethernet attached event for wan
    Dec 2 00:42:41 php-fpm[9799]: /rc.linkup: HOTPLUG: Configuring interface wan
    Dec 2 00:42:41 kernel: re0: link state changed to DOWN

    I've attached the rest of the repeats. I'm shutting down, but I'll be able to update tomorrow morning.

    system_log.txt



  • Can you please test with a next snapshot coming!
    I pushed fixes to avoid this so it should behave better.



  • Is this snapshot recent enough? https://snapshots.pfsense.org/FreeBSD_releng/10.1/i386/pfSense_HEAD/updates/pfSense-Full-Update-2.2-BETA-i386-20141201-1400.tgz. Or should I wait for a newer one?

    Thanks for the heads up,
      -Bob



  • Just catch the today one



  • After a slight detour by downloading the wrong arch  :-[ I think I'm up and working. I'm able to unplug the WAN ethernet cable and the system comes back when I plug it back in.

    This is the version info:
    2.2-BETA (i386)
    built on Wed Dec 03 22:28:13 CST 2014
    FreeBSD 10.1-RELEASE

    Thanks for fixing this and helping me out,
      -Bob



  • I'm having this same issue, with Dec 4th update.  If I yank the Ethernet cable or simply release the WAN connection (WAN is DHCP).

    Perfectly repeatable, happy to test provide further info.

    2.2-BETA (amd64)
    built on Thu Dec 04 07:06:21 CST 2014
    FreeBSD 10.1-RELEASE

    IPs replaced with ???

    Dec 4 09:51:00 kernel: arpresolve: can't allocate llinfo for ???.???.???.??? on re0
    Dec 4 09:51:00 kernel: arpresolve: can't allocate llinfo for ???.???.???.??? on re0
    Dec 4 09:51:00 kernel: arpresolve: can't allocate llinfo for ???.???.???.??? on re0
    Dec 4 09:51:00 kernel: arpresolve: can't allocate llinfo for ???.???.???.??? on re0
    Dec 4 09:51:00 kernel: arpresolve: can't allocate llinfo for ???.???.???.??? on re0
    Dec 4 09:51:00 kernel: re0: link state changed to DOWN
    Dec 4 09:51:00 check_reload_status: Linkup starting re0
    Dec 4 09:51:00 php-fpm[87600]: /rc.linkup: HOTPLUG: Configuring interface wan
    Dec 4 09:51:00 php-fpm[87600]: /rc.linkup: DEVD Ethernet attached event for wan
    Dec 4 09:50:59 php-fpm[94867]: /rc.start_packages: No pfBlocker action during boot process.
    Dec 4 09:50:59 check_reload_status: Syncing firewall
    Dec 4 09:50:59 check_reload_status: Syncing firewall
    Dec 4 09:50:59 kernel: Bump sched buckets to 256 (was 0)
    Dec 4 09:50:59 kernel: Bump sched buckets to 256 (was 0)
    Dec 4 09:50:59 php-fpm[94867]: /rc.start_packages: The command 'ln -s /usr/local/bin/perl /usr/bin/perl' returned exit code '1', the output was 'ln: /usr/bin/perl: File exists'
    Dec 4 09:50:59 php-fpm[53090]: /rc.linkup: DEVD Ethernet detached event for wan
    Dec 4 09:50:59 check_reload_status: updating dyndns wan
    Dec 4 09:50:59 php-fpm[94867]: /rc.start_packages: Restarting/Starting all packages.
    Dec 4 09:50:58 check_reload_status: Reloading filter
    Dec 4 09:50:58 check_reload_status: Starting packages
    Dec 4 09:50:58 php-fpm[94867]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - ???.???.???.??? -> ???.???.???.??? - Restarting packages.
    Dec 4 09:50:56 php-fpm[94867]: /rc.newwanip: Creating rrd update script
    Dec 4 09:50:56 php-fpm[94867]: /rc.newwanip: Resyncing OpenVPN instances for interface WAN.
    Dec 4 09:50:56 php-fpm[94867]: /rc.newwanip: ROUTING: setting default route to ???.???.???.???
    Dec 4 09:50:56 php-fpm[94867]: /rc.newwanip: rc.newwanip: on (IP address: ???.???.???.???) (interface: WAN[wan]) (real interface: re0).
    Dec 4 09:50:56 php-fpm[94867]: /rc.newwanip: rc.newwanip: Info: starting on re0.
    Dec 4 09:50:55 php-fpm[45185]: /rc.linkup: ROUTING: setting default route to ???.???.???.???
    Dec 4 09:50:55 check_reload_status: rc.newwanip starting re0
    Dec 4 09:50:55 kernel: arpresolve: can't allocate llinfo for ???.???.???.??? on re0
    Dec 4 09:50:54 kernel: re0: link state changed to UP
    Dec 4 09:50:54 check_reload_status: Linkup starting re0
    Dec 4 09:50:52 kernel: arpresolve: can't allocate llinfo for ???.???.???.??? on re0
    Dec 4 09:50:51 kernel: arpresolve: can't allocate llinfo for ???.???.???.??? on re0
    Dec 4 09:50:51 kernel: re0: link state changed to DOWN
    Dec 4 09:50:51 check_reload_status: Linkup starting re0
    Dec 4 09:50:50 php-fpm[45185]: /rc.linkup: HOTPLUG: Configuring interface wan
    Dec 4 09:50:50 php-fpm[45185]: /rc.linkup: DEVD Ethernet attached event for wan
    Dec 4 09:50:50 kernel: Bump sched buckets to 256 (was 0)
    Dec 4 09:50:50 kernel: Bump sched buckets to 256 (was 0)
    Dec 4 09:50:50 php-fpm[53090]: /rc.start_packages: No pfBlocker action during boot process.
    Dec 4 09:50:50 check_reload_status: Syncing firewall
    Dec 4 09:50:50 check_reload_status: Syncing firewall
    Dec 4 09:50:50 php-fpm[53090]: /rc.start_packages: The command 'ln -s /usr/local/bin/perl /usr/bin/perl' returned exit code '1', the output was 'ln: /usr/bin/perl: File exists'
    Dec 4 09:50:50 php-fpm[53090]: /rc.start_packages: Restarting/Starting all packages.
    Dec 4 09:50:49 php-fpm[10667]: /rc.linkup: DEVD Ethernet detached event for wan
    Dec 4 09:50:49 check_reload_status: updating dyndns wan
    Dec 4 09:50:49 check_reload_status: Reloading filter
    Dec 4 09:50:49 check_reload_status: Starting packages
    Dec 4 09:50:49 php-fpm[53090]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - ???.???.???.??? -> ???.???.???.??? - Restarting packages.
    Dec 4 09:50:47 php-fpm[53090]: /rc.newwanip: Creating rrd update script

    Dec 4 09:51:17 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:51:16 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:51:13 apinger: SIGHUP received, reloading configuration.
    Dec 4 09:51:10 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:51:09 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:51:08 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:51:05 apinger: SIGHUP received, reloading configuration.
    Dec 4 09:51:02 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:51:01 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:51:00 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:50:56 apinger: SIGHUP received, reloading configuration.
    Dec 4 09:50:54 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:50:53 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:50:52 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:50:51 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:50:47 apinger: SIGHUP received, reloading configuration.
    Dec 4 09:50:45 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:50:44 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:50:43 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:50:42 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:50:38 apinger: SIGHUP received, reloading configuration.
    Dec 4 09:50:36 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:50:35 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:50:34 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:50:33 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:50:29 apinger: SIGHUP received, reloading configuration.
    Dec 4 09:50:27 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:50:26 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:50:25 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:50:21 apinger: SIGHUP received, reloading configuration.
    Dec 4 09:50:19 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:50:18 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:50:17 apinger: Could not bind socket on address(???.???.???.???) for monitoring address ???.???.???.???(WAN) with error Can't assign requested address
    Dec 4 09:50:12 apinger: SIGHUP received, reloading configuration.
    Dec 4 09:50:12 apinger: ALARM: WAN(???.???.???.???) *** loss ***



  • Can you provide a clear way to reproduce this.
    From your logs seems there are mixed actions happening at the same time.



  • Either pull and reinsert the wan Ethernet cable, or just release and renew.  Either one will trigger the bouncing, only a restart will fix.



  • There's something more to it than that. What hardware is that? What is your config like on re0? The fact it does the same on 2.1.5 suggests it's possibly one of the broken Realteks (or one more broken than most of the others at least).



  • It does the same on an Intel card, I just swapped to re for testing.  I don't know if it does it in 2.1.5 also, this was a fresh install of 2.2 maybe 2-3 months ago.  WAN setup is stock pfsense from 2.2 DHCP.

    em1: <intel(r) 1000="" pro="" network="" connection="" 7.4.2="">port 0xe000-0xe01f mem 0xf7d20000-0xf7d3ffff,0xf7d00000-0xf7d1ffff irq 17 at device 0.1 on pci1
    MB = MSI MS-7817 latest BIOS.

    Dec 4 13:12:03 php-fpm[73487]: /rc.linkup: HOTPLUG: Configuring interface wan
    Dec 4 13:12:03 php-fpm[73487]: /rc.linkup: DEVD Ethernet attached event for wan
    Dec 4 13:12:02 kernel: em1: link state changed to DOWN
    Dec 4 13:12:02 check_reload_status: Linkup starting em1
    Dec 4 13:12:02 php-fpm[59827]: /rc.linkup: DEVD Ethernet detached event for wan
    Dec 4 13:12:02 check_reload_status: updating dyndns wan
    Dec 4 13:11:58 php-fpm[16280]: /rc.linkup: ROUTING: setting default route to 24.100.??.?
    Dec 4 13:11:58 check_reload_status: rc.newwanip starting em1
    Dec 4 13:11:57 kernel: em1: link state changed to UP
    Dec 4 13:11:57 check_reload_status: Linkup starting em1
    Dec 4 13:11:55 check_reload_status: Configuring interface wan
    Dec 4 13:11:55 php-fpm[7437]: /rc.newwanip: rc.newwanip: Failed to update wan IP, restarting…
    Dec 4 13:11:55 php-fpm[7437]: /rc.newwanip: rc.newwanip: on (IP address: ) (interface: WAN[wan]) (real interface: em1).
    Dec 4 13:11:55 php-fpm[7437]: /rc.newwanip: rc.newwanip: Info: starting on em1.
    Dec 4 13:11:55 kernel: em1: link state changed to DOWN
    Dec 4 13:11:55 check_reload_status: Linkup starting em1
    Dec 4 13:11:55 php-fpm[16280]: /rc.linkup: HOTPLUG: Configuring interface wan
    Dec 4 13:11:55 php-fpm[16280]: /rc.linkup: DEVD Ethernet attached event for wan
    Dec 4 13:11:54 php-fpm[73487]: /rc.linkup: DEVD Ethernet detached event for wan
    Dec 4 13:11:54 check_reload_status: updating dyndns wan
    Dec 4 13:11:50 php-fpm[7437]: /rc.linkup: ROUTING: setting default route to 24.100.??.?
    Dec 4 13:11:50 check_reload_status: rc.newwanip starting em1
    Dec 4 13:11:50 kernel: arpresolve: can't allocate llinfo for 24.100.??.? on em1
    Dec 4 13:11:49 kernel: arpresolve: can't allocate llinfo for 24.100.??.? on em1
    Dec 4 13:11:49 kernel: arpresolve: can't allocate llinfo for 24.100.??.? on em1
    Dec 4 13:11:49 kernel: arpresolve: can't allocate llinfo for 24.100.??.? on em1
    Dec 4 13:11:49 kernel: arpresolve: can't allocate llinfo for 24.100.??.? on em1
    Dec 4 13:11:49 kernel: arpresolve: can't allocate llinfo for 24.100.??.? on em1
    Dec 4 13:11:49 kernel: arpresolve: can't allocate llinfo for 24.100.??.? on em1
    Dec 4 13:11:48 check_reload_status: Linkup starting em1
    Dec 4 13:11:48 kernel: em1: link state changed to UP
    Dec 4 13:11:47 kernel: arpresolve: can't allocate llinfo for 24.100.??.? on em1
    Dec 4 13:11:47 kernel: arpresolve: can't allocate llinfo for 24.100.??.? on em1
    Dec 4 13:11:47 kernel: arpresolve: can't allocate llinfo for 24.100.??.? on em1
    Dec 4 13:11:46 kernel: arpresolve: can't allocate llinfo for 24.100.??.? on em1
    Dec 4 13:11:46 kernel: arpresolve: can't allocate llinfo for 24.100.??.? on em1
    Dec 4 13:11:45 check_reload_status: Linkup starting em1</intel(r)>



  • Ok that rules out the re NIC at least. It seems highly likely it's your modem at this stage. I'm guessing you're plugged straight from WAN NIC into the modem. What if you put a switch in between, so the link down never happens to the modem, what does that do?



  • Tested with a switch yesterday!

    If I pull just the WAN on pfsense, without touching the cable modem side, WAN port still bounces until pfsense reboot.



  • Plugged my laptop directly into the cable modem, works without issue.

    But I might have lied, this pfsense install might have been an upgrade from 2.1.5 and not a fresh install.  Sorry, to many different installs, I don't recall for-sure.

    I could blast it and confirm with a fresh install if that adds any value?



  • Unless you're getting in and changing source, or messing around with a lot of unstable packages, or making other changes under the hood, a clean install will be functionally equivalent to an upgraded system. It's pretty quick and easy to start from scratch and restore your config though. That's probably the next best bet, start on a clean install of the most recent 2.2 snapshot. First test a new config with the most basic setup possible - WAN on DHCP, LAN static, nothing else configured beyond defaults. Then see whether that still happens. Then you can restore your config backup after trying that.



  • I'm not doing anything special, no source changing or under the hood tweaks.

    I've tried everything under the sun and for some reason can't get the memstick image to boot, done this a zillion times successfully in the past.

    Anyhow, I bought several of these MSI MBs, all have given me trouble, might just toss it out the window and get a proper supermicro.

    Thanks for the help.  I will report back, but it might be a month as I start on an outage this Monday.



  • I did find a temp fix while on outage.  I changed the WAN configuration from auto detect (which was auto detecting 1000BT/full) to 1000BT/full static and the problem vanished.


Log in to reply