WAN link going down



  • Hello,

    After my upgrade to 2.2 i'm experiencing my WAN link going down from time to time.
    I can see this in the system log:

    Feb 3 14:13:48 	kernel: ovpns1: link state changed to DOWN
    Feb 3 14:13:48 	php-fpm[84313]: /rc.openvpn: OpenVPN: Resync server1 OpenVPN Server
    Feb 3 14:13:48 	php-fpm[84313]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use WAN_DHCP.
    Feb 3 14:13:48 	php-fpm[44636]: /rc.dyndns.update: DynDNS (*****) There was an error trying to determine the public IP for interface - wan(sk0). Probably interface is not a WAN interface.
    Feb 3 14:13:47 	check_reload_status: Reloading filter
    Feb 3 14:13:47 	check_reload_status: Restarting OpenVPN tunnels/interfaces
    Feb 3 14:13:47 	check_reload_status: Restarting ipsec tunnels
    Feb 3 14:13:47 	check_reload_status: updating dyndns WAN_DHCP
    Feb 3 14:13:46 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 3 14:13:42 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 3 14:13:42 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 3 14:13:42 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 3 14:13:42 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 3 14:13:40 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 3 14:13:39 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 3 14:13:38 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 3 14:13:38 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 3 14:13:38 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 3 14:13:37 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 3 14:13:35 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 3 14:13:34 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 3 14:13:33 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 3 14:13:33 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 3 14:13:33 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 3 14:13:28 	php-fpm[16093]: /rc.linkup: DEVD Ethernet detached event for wan
    Feb 3 14:13:27 	kernel: sk0: link state changed to DOWN
    Feb 3 14:13:27 	check_reload_status: Linkup starting sk0
    
    Feb 3 14:13:58 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 3 14:13:58 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 3 14:13:56 	LCDd: Connect from host 127.0.0.1:23439 on socket 12
    Feb 3 14:13:56 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 3 14:13:55 	php: lcdproc: Start client procedure. Error counter: (0)
    Feb 3 14:13:55 	LCDd: Listening for queries on 127.0.0.1:13666
    Feb 3 14:13:55 	LCDd: Using Configuration File: /usr/local/etc/LCDd.conf
    Feb 3 14:13:55 	LCDd: LCDd version 0.5.6 starting
    Feb 3 14:13:54 	LCDd: Server shutting down on SIGTERM
    Feb 3 14:13:53 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 3 14:13:53 	check_reload_status: Syncing firewall
    Feb 3 14:13:53 	check_reload_status: Syncing firewall
    Feb 3 14:13:53 	LCDd: sock_send: socket write error
    Feb 3 14:13:53 	LCDd: sock_send: socket write error
    Feb 3 14:13:53 	LCDd: sock_send: socket write error
    Feb 3 14:13:53 	LCDd: sock_send: socket write error
    Feb 3 14:13:53 	LCDd: sock_send: socket write error
    Feb 3 14:13:53 	LCDd: sock_send: socket write error
    Feb 3 14:13:53 	LCDd: sock_send: socket write error
    Feb 3 14:13:53 	LCDd: Client on socket 12 disconnected
    Feb 3 14:13:52 	php-fpm[44636]: /rc.filter_configure_sync: Could not find IPv6 gateway for interface (wan).
    Feb 3 14:13:52 	php-fpm[44636]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Feb 3 14:13:52 	php-fpm[44636]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Feb 3 14:13:52 	php-fpm[44636]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Feb 3 14:13:52 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 3 14:13:52 	php-fpm[90562]: /rc.start_packages: Reloading Squid for configuration sync
    Feb 3 14:13:51 	php-fpm[90562]: /rc.start_packages: Restarting/Starting all packages.
    Feb 3 14:13:50 	check_reload_status: Starting packages
    Feb 3 14:13:50 	php-fpm[90562]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - -> 192.168.10.1 - Restarting packages.
    Feb 3 14:13:50 	check_reload_status: Reloading filter
    Feb 3 14:13:50 	php-fpm[90562]: /rc.newwanip: rc.newwanip: on (IP address: 192.168.10.1) (interface: []) (real interface: ovpns1).
    Feb 3 14:13:50 	php-fpm[90562]: /rc.newwanip: rc.newwanip: Info: starting on ovpns1.
    Feb 3 14:13:50 	php-fpm[84313]: /rc.filter_configure_sync: Could not find IPv6 gateway for interface (wan).
    Feb 3 14:13:50 	php-fpm[84313]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Feb 3 14:13:50 	php-fpm[84313]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Feb 3 14:13:50 	php-fpm[84313]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Feb 3 14:13:49 	check_reload_status: rc.newwanip starting ovpns1
    Feb 3 14:13:49 	kernel: ovpns1: link state changed to UP
    Feb 3 14:13:48 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 3 14:13:48 	check_reload_status: Reloading filter
    Feb 3 14:13:48 	kernel: ovpns1: link state changed to DOWN
    

    84.192.192.1 is the gateway for my WAN link, maybe the problem is apinger ?
    Disabling the WAN link and enabling it back solves the problem, rebooting also solves the problem.

    Can somebody maybe point me in the right direction ?

    HW: Firebox x750e
    BIOS: 8_1
    Packages: Snort and squid, lightsquid / LcdProc


  • Netgate Administrator

    This:

    kernel: sk0: link state changed to DOWN
    

    Indicates that the link is actually going down not just being marked down by apinger. Are you using the modified sk(4) driver? There have been a number of reports of them not working well under various conditions. Are you seeing errors in the boot log like this?:
    https://forum.pfsense.org/index.php?topic=20095.msg485091#msg485091

    Steve



  • I'll check this when i get home, i also see inthe gateway logs that apinger couldn't get the gateway.
    But that is probably cause and effect, if the link is down then the gateway can't be located.

    Thank in advance steve !



  • Nope, i can't see any problems in the boot log.
    I'm also not using the modified sk(4) drivers, it's just a default installation

    Copyright (c) 1992-2014 The FreeBSD Project.
    Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
            The Regents of the University of California. All rights reserved.
    FreeBSD is a registered trademark of The FreeBSD Foundation.
    FreeBSD 10.1-RELEASE-p4 #0 36d7dec(releng/10.1)-dirty: Thu Jan 22 15:12:38 CST 2015
        root@pfsense-22-i386-builder:/usr/obj.i386/usr/pfSensesrc/src/sys/pfSense_SMP.10 i386
    FreeBSD clang version 3.4.1 (tags/RELEASE_34/dot1-final 208032) 20140512
    CPU: Intel(R) Pentium(R) M processor 2.00GHz (2000.11-MHz 686-class CPU)
      Origin = "GenuineIntel"  Id = 0x6d8  Family = 0x6  Model = 0xd  Stepping = 8
      Features=0xafe9fbff <fpu,vme,de,pse,tsc,msr,pae,mce,cx8,apic,sep,mtrr,pge,mca,cmov,pat,clflush,dts,acpi,mmx,fxsr,sse,sse2,ss,tm,pbe>Features2=0x180 <est,tm2>AMD Features=0x100000 <nx>real memory  = 2139029504 (2039 MB)
    avail memory = 2064244736 (1968 MB)
    Event timer "LAPIC" quality 400
    ACPI APIC Table: <intelr awrdacpi="">ioapic0 <version 2.0="">irqs 0-23 on motherboard
    wlan: mac acl policy registered
    kbd1 at kbdmux0
    random: <software, yarrow="">initialized
    cryptosoft0: <software crypto="">on motherboard
    padlock0: No ACE support.
    acpi0: <intelr awrdacpi="">on motherboard
    acpi0: Power Button (fixed)
    acpi0: reservation of a2, 1e (4) failed
    acpi0: reservation of e0, 10 (4) failed
    acpi0: reservation of 0, a0000 (3) failed
    acpi0: reservation of 100000, 7f6f0000 (3) failed
    cpu0: <acpi cpu="">on acpi0
    attimer0: <at timer="">port 0x40-0x43 irq 0 on acpi0
    Timecounter "i8254" frequency 1193182 Hz quality 0
    Event timer "i8254" frequency 1193182 Hz quality 100
    atrtc0: <at realtime="" clock="">port 0x70-0x73 irq 8 on acpi0
    Event timer "RTC" frequency 32768 Hz quality 0
    Timecounter "ACPI-fast" frequency 3579545 Hz quality 900
    acpi_timer0: <24-bit timer at 3.579545MHz> port 0x408-0x40b on acpi0
    acpi_button0: <power button="">on acpi0
    pcib0: <acpi host-pci="" bridge="">port 0xcf8-0xcff on acpi0
    pci0: <acpi pci="" bus="">on pcib0
    vgapci0: <vga-compatible display="">port 0xea00-0xea07 mem 0xd0500000-0xd057ffff,0xc0000000-0xcfffffff,0xd0580000-0xd05bffff irq 16 at device 2.0 on pci0
    agp0: <intel 82915gm="" (915gm="" gmch)="" svga="" controller="">on vgapci0
    agp0: aperture size is 256M, detected 7932k stolen memory
    vgapci0: Boot video device
    pcib1: <acpi pci-pci="" bridge="">irq 16 at device 28.0 on pci0
    pci1: <acpi pci="" bus="">on pcib1
    mskc0: <marvell yukon="" 88e8053="" gigabit="" ethernet="">port 0x8000-0x80ff mem 0xd0020000-0xd0023fff irq 16 at device 0.0 on pci1
    msk0: <marvell technology="" group="" ltd.="" yukon="" ec="" id="" 0xb6="" rev="" 0x02="">on mskc0
    miibus0: <mii bus="">on msk0
    e1000phy0: <marvell 88e1111="" gigabit="" phy="">PHY 0 on miibus0
    e1000phy0:  none, 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-master, 1000baseT-FDX, 1000baseT-FDX-master, auto, auto-flow
    pcib2: <acpi pci-pci="" bridge="">irq 17 at device 28.1 on pci0
    pci2: <acpi pci="" bus="">on pcib2
    mskc1: <marvell yukon="" 88e8053="" gigabit="" ethernet="">port 0x9000-0x90ff mem 0xd0120000-0xd0123fff irq 17 at device 0.0 on pci2
    msk1: <marvell technology="" group="" ltd.="" yukon="" ec="" id="" 0xb6="" rev="" 0x02="">on mskc1
    miibus1: <mii bus="">on msk1
    e1000phy1: <marvell 88e1111="" gigabit="" phy="">PHY 0 on miibus1
    e1000phy1:  none, 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-master, 1000baseT-FDX, 1000baseT-FDX-master, auto, auto-flow
    pcib3: <acpi pci-pci="" bridge="">irq 18 at device 28.2 on pci0
    pci3: <acpi pci="" bus="">on pcib3
    mskc2: <marvell yukon="" 88e8053="" gigabit="" ethernet="">port 0xa000-0xa0ff mem 0xd0220000-0xd0223fff irq 18 at device 0.0 on pci3
    msk2: <marvell technology="" group="" ltd.="" yukon="" ec="" id="" 0xb6="" rev="" 0x02="">on mskc2
    miibus2: <mii bus="">on msk2
    e1000phy2: <marvell 88e1111="" gigabit="" phy="">PHY 0 on miibus2
    e1000phy2:  none, 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-master, 1000baseT-FDX, 1000baseT-FDX-master, auto, auto-flow
    pcib4: <acpi pci-pci="" bridge="">irq 19 at device 28.3 on pci0
    pci4: <acpi pci="" bus="">on pcib4
    mskc3: <marvell yukon="" 88e8053="" gigabit="" ethernet="">port 0xb000-0xb0ff mem 0xd0320000-0xd0323fff irq 19 at device 0.0 on pci4
    msk3: <marvell technology="" group="" ltd.="" yukon="" ec="" id="" 0xb6="" rev="" 0x02="">on mskc3
    miibus3: <mii bus="">on msk3
    e1000phy3: <marvell 88e1111="" gigabit="" phy="">PHY 0 on miibus3
    e1000phy3:  none, 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-master, 1000baseT-FDX, 1000baseT-FDX-master, auto, auto-flow
    uhci0: <intel 82801fb="" fr="" fw="" frw="" (ich6)="" usb="" controller="" usb-a="">port 0xeb00-0xeb1f irq 23 at device 29.0 on pci0
    usbus0 on uhci0
    uhci1: <intel 82801fb="" fr="" fw="" frw="" (ich6)="" usb="" controller="" usb-b="">port 0xed00-0xed1f irq 19 at device 29.1 on pci0
    usbus1 on uhci1
    uhci2: <intel 82801fb="" fr="" fw="" frw="" (ich6)="" usb="" controller="" usb-c="">port 0xe800-0xe81f irq 18 at device 29.2 on pci0
    usbus2 on uhci2
    uhci3: <intel 82801fb="" fr="" fw="" frw="" (ich6)="" usb="" controller="" usb-d="">port 0xe900-0xe91f irq 16 at device 29.3 on pci0
    usbus3 on uhci3
    ehci0: <intel 82801fb="" (ich6)="" usb="" 2.0="" controller="">mem 0xd05c0000-0xd05c03ff irq 23 at device 29.7 on pci0
    usbus4: EHCI version 1.0
    usbus4 on ehci0
    pcib5: <acpi pci-pci="" bridge="">at device 30.0 on pci0
    pci5: <acpi pci="" bus="">on pcib5
    skc0: <marvell gigabit="" ethernet="">port 0xc000-0xc0ff mem 0xd042c000-0xd042ffff irq 16 at device 0.0 on pci5
    skc0: Marvell Yukon Lite Gigabit Ethernet rev. (0x9)
    sk0: <marvell semiconductor,="" inc.="" yukon="">on skc0
    miibus4: <mii bus="">on sk0
    e1000phy4: <marvell 88e1011="" gigabit="" phy="">PHY 0 on miibus4
    e1000phy4:  none, 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-master, 1000baseT-FDX, 1000baseT-FDX-master, auto
    skc1: <marvell gigabit="" ethernet="">port 0xc400-0xc4ff mem 0xd0420000-0xd0423fff irq 17 at device 1.0 on pci5
    skc1: Marvell Yukon Lite Gigabit Ethernet rev. (0x9)
    sk1: <marvell semiconductor,="" inc.="" yukon="">on skc1
    miibus5: <mii bus="">on sk1
    e1000phy5: <marvell 88e1011="" gigabit="" phy="">PHY 0 on miibus5
    e1000phy5:  none, 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-master, 1000baseT-FDX, 1000baseT-FDX-master, auto
    skc2: <marvell gigabit="" ethernet="">port 0xc800-0xc8ff mem 0xd0424000-0xd0427fff irq 18 at device 2.0 on pci5
    skc2: Marvell Yukon Lite Gigabit Ethernet rev. (0x9)
    sk2: <marvell semiconductor,="" inc.="" yukon="">on skc2
    miibus6: <mii bus="">on sk2
    e1000phy6: <marvell 88e1011="" gigabit="" phy="">PHY 0 on miibus6
    e1000phy6:  none, 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-master, 1000baseT-FDX, 1000baseT-FDX-master, auto
    skc3: <marvell gigabit="" ethernet="">port 0xcc00-0xccff mem 0xd0428000-0xd042bfff irq 19 at device 3.0 on pci5
    skc3: Marvell Yukon Lite Gigabit Ethernet rev. (0x9)
    sk3: <marvell semiconductor,="" inc.="" yukon="">on skc3
    miibus7: <mii bus="">on sk3
    e1000phy7: <marvell 88e1011="" gigabit="" phy="">PHY 0 on miibus7
    e1000phy7:  none, 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-master, 1000baseT-FDX, 1000baseT-FDX-master, auto
    pci5: <encrypt decrypt,="" network="" computer="" crypto="">at device 4.0 (no driver attached)
    isab0: <pci-isa bridge="">at device 31.0 on pci0
    isa0: <isa bus="">on isab0
    atapci0: <intel ich6="" udma100="" controller="">port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0xf000-0xf00f at device 31.1 on pci0
    ata0: <ata channel="">at channel 0 on atapci0
    ata1: <ata channel="">at channel 1 on atapci0
    acpi_tz0: <thermal zone="">on acpi0
    uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
    uart0: console (115200,n,8,1)
    uart1: <16550 or compatible> port 0x2f8-0x2ff irq 3 on acpi0
    ppc0: <parallel port="">port 0x378-0x37f,0x778-0x77b irq 7 on acpi0
    ppc0: Generic chipset (NIBBLE-only) in COMPATIBLE mode
    ppbus0: <parallel port="" bus="">on ppc0
    lpt0: <printer>on ppbus0
    lpt0: Interrupt-driven port
    ppi0: <parallel i="" o="">on ppbus0
    pmtimer0 on isa0
    orm0: <isa option="" rom="">at iomem 0xc0000-0xce7ff pnpid ORM0000 on isa0
    sc0: <system console="">at flags 0x100 on isa0
    sc0: VGA <16 virtual consoles, flags=0x300>
    vga0: <generic isa="" vga="">at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
    atkbdc0: <keyboard controller="" (i8042)="">at port 0x60,0x64 on isa0
    atkbd0: <at keyboard="">irq 1 on atkbdc0
    kbd0 at atkbd0
    atkbd0: [GIANT-LOCKED]
    est0: <enhanced speedstep="" frequency="" control="">on cpu0
    est: CPU supports Enhanced Speedstep, but is not recognized.
    est: cpu_vendor GenuineIntel, msr 6120f2906000f29
    device_attach: est0 attach returned 6
    p4tcc0: <cpu frequency="" thermal="" control="">on cpu0
    Timecounters tick every 1.000 msec
    IPsec: Initialized Security Association Processing.
    random: unblocking device.
    usbus0: 12Mbps Full Speed USB v1.0
    usbus1: 12Mbps Full Speed USB v1.0
    usbus2: 12Mbps Full Speed USB v1.0
    usbus3: 12Mbps Full Speed USB v1.0
    ugen0.1: <intel>at usbus0
    uhub0: <intel 1="" 9="" uhci="" root="" hub,="" class="" 0,="" rev="" 1.00="" 1.00,="" addr="">on usbus0
    ugen1.1: <intel>at usbus1
    uhub1: <intel 1="" 9="" uhci="" root="" hub,="" class="" 0,="" rev="" 1.00="" 1.00,="" addr="">on usbus1
    ugen2.1: <intel>at usbus2
    uhub2: <intel 1="" 9="" uhci="" root="" hub,="" class="" 0,="" rev="" 1.00="" 1.00,="" addr="">on usbus2
    ugen3.1: <intel>at usbus3
    uhub3: <intel 1="" 9="" uhci="" root="" hub,="" class="" 0,="" rev="" 1.00="" 1.00,="" addr="">on usbus3
    usbus4: 480Mbps High Speed USB v2.0
    ugen4.1: <intel>at usbus4
    uhub4: <intel 1="" 9="" ehci="" root="" hub,="" class="" 0,="" rev="" 2.00="" 1.00,="" addr="">on usbus4
    ata0: DMA limited to UDMA33, controller found non-ATA66 cable
    ada0 at ata0 bus 0 scbus0 target 0 lun 0
    ada0: <wdc wd800beve-00uyt0="" 01.04a01="">ATA-7 device
    ada0: Serial Number WD-WXEX08TJ6328
    ada0: 33.300MB/s transfers (UDMA2, PIO 8192bytes)
    ada0: 76319MB (156301488 512 byte sectors: 16H 63S/T 16383C)
    ada0: Previously was known as ad0
    Timecounter "TSC" frequency 2000113799 Hz quality 800
    Root mount waiting for: usbus4 usbus3 usbus2 usbus1 usbus0
    uhub0: 2 ports with 2 removable, self powered
    uhub1: 2 ports with 2 removable, self powered
    uhub2: 2 ports with 2 removable, self powered
    uhub3: 2 ports with 2 removable, self powered
    Root mount waiting for: usbus4
    Root mount waiting for: usbus4
    Root mount waiting for: usbus4
    uhub4: 8 ports with 8 removable, self powered
    Trying to mount root from ufs:/dev/ad0s1a [rw]...</wdc></intel></intel></intel></intel></intel></intel></intel></intel></intel></intel></cpu></enhanced></at></keyboard></generic></system></isa></parallel></printer></parallel></parallel></thermal></ata></ata></intel></isa></pci-isa></encrypt></marvell></mii></marvell></marvell></marvell></mii></marvell></marvell></marvell></mii></marvell></marvell></marvell></mii></marvell></marvell></acpi></acpi></intel></intel></intel></intel></intel></marvell></mii></marvell></marvell></acpi></acpi></marvell></mii></marvell></marvell></acpi></acpi></marvell></mii></marvell></marvell></acpi></acpi></marvell></mii></marvell></marvell></acpi></acpi></intel></vga-compatible></acpi></acpi></power></at></at></acpi></intelr></software></software,></version></intelr></nx></est,tm2></fpu,vme,de,pse,tsc,msr,pae,mce,cx8,apic,sep,mtrr,pge,mca,cmov,pat,clflush,dts,acpi,mmx,fxsr,sse,sse2,ss,tm,pbe> 
    

  • Netgate Administrator

    That's good because I'm not sure there's much we can do with the drivers!  ;)

    Try disabling apinger for the gateway in System > Routing, edit gateway.

    In 2.2 there is an option to get more info from apinger by enabling 'gateway monitoring debug logging' in System > Advanced, Miscellaneous tab. Try that if disabling apinger makes any difference.

    Steve



  • @stephenw10:

    That's good because I'm not sure there's much we can do with the drivers!  ;)

    Try disabling apinger for the gateway in System > Routing, edit gateway.

    In 2.2 there is an option to get more info from apinger by enabling 'gateway monitoring debug logging' in System > Advanced, Miscellaneous tab. Try that if disabling apinger makes any difference.

    Steve

    Ok  ;D
    I'll try disabling apinger first and see how it goes the next days.
    Its happens always after the Firewall is online for 2 days.

    Greetz
    Tim



  • Ow yeah, I'm also getting these messages…
    On a disabled interface and no cable plugged in.

    They are on the same interface card though (sk..)
    I only use sk0 and sk1 for now.

    Feb 3 18:02:08 	php-fpm[61051]: /rc.linkup: Linkup detected on disabled interface...Ignoring
    Feb 3 18:02:08 	php-fpm[61051]: /rc.linkup: Linkup detected on disabled interface...Ignoring
    Feb 3 18:02:07 	check_reload_status: Linkup starting sk3
    Feb 3 18:02:07 	kernel: sk3: link state changed to DOWN
    Feb 3 18:02:07 	kernel: sk2: link state changed to DOWN
    Feb 3 18:02:07 	check_reload_status: Linkup starting sk2
    

  • Netgate Administrator

    Is that at any time or just at boot?



  • @stephenw10:

    Is that at any time or just at boot?

    At the end of the boot cycle  :)
    I also see that WOL isn't working anymore.. strange


  • Banned

    WOL is a known x86 issue with a patch on Redmine, completely unrelated.



  • I also see that WOL isn't working anymore.. strange

    I guess you are using 32-bit pfSense 2.2 - that is effected by the gen_subnetv4_max issue, fixed by:
    https://github.com/pfsense/pfsense/commit/7094c303b7d46c9f7b24c3f1bd4432187832e85c

    Things that try to calculate the max IP address of a subnet are effected - WOL is one of them.

    You can apply that small fix and WOL should work again.



  • @phil.davis:

    I also see that WOL isn't working anymore.. strange

    I guess you are using 32-bit pfSense 2.2 - that is effected by the gen_subnetv4_max issue, fixed by:
    https://github.com/pfsense/pfsense/commit/7094c303b7d46c9f7b24c3f1bd4432187832e85c

    Things that try to calculate the max IP address of a subnet are effected - WOL is one of them.

    You can apply that small fix and WOL should work again.

    Thank you !
    I was guessing in that direction, because when using WOL in the terminal it worked  :)



  • Spoke too soon.

    The WAN link is still losing its connection.

    Feb 4 13:37:17 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 4 13:37:17 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 4 13:37:13 	kernel: arpresolve: can't allocate llinfo for 84.192.192.1 on sk0
    Feb 4 13:37:06 	php-fpm[5814]: /rc.linkup: DEVD Ethernet detached event for wan
    Feb 4 13:37:05 	kernel: sk0: link state changed to DOWN
    Feb 4 13:37:05 	check_reload_status: Linkup starting sk0
    Feb 4 13:36:10 	php-fpm[26356]: /rc.filter_configure_sync: Could not find IPv6 gateway for interface (wan).
    Feb 4 13:36:08 	check_reload_status: Reloading filter
    Feb 4 13:36:08 	php-fpm[26356]: /rc.newwanip: rc.newwanip: on (IP address: 192.168.1.254) (interface: LAN[lan]) (real interface: sk1).
    Feb 4 13:36:08 	php-fpm[26356]: /rc.newwanip: rc.newwanip: Info: starting on sk1.
    Feb 4 13:36:07 	check_reload_status: rc.newwanip starting sk1
    Feb 4 13:36:07 	php-fpm[26356]: /rc.linkup: Hotplug event detected for LAN(lan) but ignoring since interface is configured with static IP (192.168.1.254 )
    Feb 4 13:36:06 	kernel: sk1: link state changed to UP
    Feb 4 13:36:06 	check_reload_status: Linkup starting sk1
    Feb 4 13:36:01 	php-fpm[26356]: /rc.linkup: Hotplug event detected for LAN(lan) but ignoring since interface is configured with static IP (192.168.1.254 )
    Feb 4 13:36:00 	kernel: sk1: link state changed to DOWN
    

    Firewall Logs

    
    block/1000000104
    	Feb 4 13:40:18 	Direction=OUT lo0 	Default deny rule IPv4 (1000000104)		Icon Reverse Resolve with DNS Icon Easy Rule: Add to Block List 74.125.24.139:80		Icon Reverse Resolve with DNS Icon Easy Rule: Pass this traffic 84.192.215.xxx:46001		TCP:FA
    block/1000000104
    	Feb 4 13:40:18 	Direction=OUT lo0 	Default deny rule IPv4 (1000000104)		Icon Reverse Resolve with DNS Icon Easy Rule: Add to Block List 74.125.24.139:80		Icon Reverse Resolve with DNS Icon Easy Rule: Pass this traffic 84.192.215.xxx:46001		TCP:FA
    block/1000000104
    	Feb 4 13:40:17 	Direction=OUT lo0 	Default deny rule IPv4 (1000000104)		Icon Reverse Resolve with DNS Icon Easy Rule: Add to Block List 74.125.24.139:80		Icon Reverse Resolve with DNS Icon Easy Rule: Pass this traffic 84.192.215.xxx:46001		TCP:FA
    pass/1422181121
    	Feb 4 13:24:22 	ovpns1 	USER_RULE OpenVPN OpenVPN Server wizard (1422181121)		Icon Reverse Resolve with DNS Icon Easy Rule: Add to Block List 192.168.10.10		Icon Reverse Resolve with DNS Icon Easy Rule: Pass this traffic 192.168.1.120		ICMP
    pass/1422181121
    	Feb 4 13:24:11 	ovpns1 	USER_RULE OpenVPN OpenVPN Server wizard (1422181121)		Icon Reverse Resolve with DNS Icon Easy Rule: Add to Block List 192.168.10.10:55720		Icon Reverse Resolve with DNS Icon Easy Rule: Pass this traffic 192.168.1.254:443		TCP:S
    


  • I don't know if there is a relation , but tonight i noticed something strange in the logs.

    My WAN ip changed to a private range… (twice)
    I'm also seeing openvpn and LCDProc errors...

    wtf !

    
    Feb 11 01:10:30 fw1 snort[39066]: invalid appid in appStatRecord (186)
    Feb 11 01:28:21 fw1 check_reload_status: updating dyndns WAN_DHCP
    Feb 11 01:28:21 fw1 check_reload_status: Restarting ipsec tunnels
    Feb 11 01:28:21 fw1 check_reload_status: Restarting OpenVPN tunnels/interfaces
    Feb 11 01:28:21 fw1 check_reload_status: Reloading filter
    Feb 11 01:28:22 fw1 php-fpm[89141]: /rc.dyndns.update: phpDynDNS (***-ip.biz): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
    Feb 11 01:28:22 fw1 php-fpm[76014]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use WAN_DHCP.
    Feb 11 01:28:22 fw1 php-fpm[76014]: /rc.openvpn: OpenVPN: Resync server1 OpenVPN Server
    Feb 11 01:28:22 fw1 kernel: ovpns1: link state changed to DOWN
    Feb 11 01:28:22 fw1 check_reload_status: Reloading filter
    Feb 11 01:28:23 fw1 kernel: ovpns1: link state changed to UP
    Feb 11 01:28:23 fw1 check_reload_status: rc.newwanip starting ovpns1
    Feb 11 01:28:24 fw1 php-fpm[89141]: /rc.newwanip: rc.newwanip: Info: starting on ovpns1.
    Feb 11 01:28:24 fw1 php-fpm[89141]: /rc.newwanip: rc.newwanip: on (IP address: 192.168.10.1) (interface: []) (real interface: ovpns1).
    Feb 11 01:28:24 fw1 check_reload_status: Reloading filter
    Feb 11 01:28:24 fw1 php-fpm[89141]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection -  ->  192.168.10.1 - Restarting packages.
    Feb 11 01:28:24 fw1 check_reload_status: Starting packages
    Feb 11 01:28:24 fw1 php-fpm[76014]: /rc.filter_configure_sync: Could not find IPv6 gateway for interface (wan).
    Feb 11 01:28:25 fw1 php-fpm[89141]: /rc.start_packages: Restarting/Starting all packages.
    Feb 11 01:28:25 fw1 php-fpm[89141]: /rc.start_packages: Reloading Squid for configuration sync
    Feb 11 01:28:26 fw1 check_reload_status: Syncing firewall
    Feb 11 01:28:26 fw1 check_reload_status: Syncing firewall
    Feb 11 01:28:27 fw1 php-fpm[79907]: /rc.filter_configure_sync: Could not find IPv6 gateway for interface (wan).
    Feb 11 01:28:28 fw1 php: lcdproc: Start client procedure. Error counter: (0)
    Feb 11 01:28:39 fw1 php: lcdproc: Failed to connect to LCDd process Operation timed out (60)
    Feb 11 01:28:39 fw1 php: lcdproc: Start client procedure. Error counter: (1)
    Feb 11 01:28:50 fw1 php: lcdproc: Failed to connect to LCDd process Operation timed out (60)
    Feb 11 01:28:50 fw1 php: lcdproc: Start client procedure. Error counter: (2)
    Feb 11 01:29:01 fw1 php: lcdproc: Failed to connect to LCDd process Operation timed out (60)
    Feb 11 01:29:01 fw1 php: lcdproc: Start client procedure. Error counter: (3)
    Feb 11 01:29:12 fw1 php: lcdproc: Failed to connect to LCDd process Operation timed out (60)
    Feb 11 01:29:12 fw1 php: lcdproc: Too many errors, the client ends.
    Feb 11 01:33:20 fw1 kernel: pid 71053 (ntpd), uid 0: exited on signal 11 (core dumped)
    Feb 11 01:55:12 fw1 snort[39066]: invalid appid in appStatRecord (498)
    Feb 11 02:00:31 fw1 php: snort_check_for_rule_updates.php: [Snort] Rules download error: Resolving timed out after 30622 milliseconds
    Feb 11 02:00:31 fw1 php: snort_check_for_rule_updates.php: [Snort] Will retry in 15 seconds...
    Feb 11 02:01:17 fw1 php: snort_check_for_rule_updates.php: [Snort] Rules download error: Resolving timed out after 30630 milliseconds
    Feb 11 02:01:17 fw1 php: snort_check_for_rule_updates.php: [Snort] Will retry in 15 seconds...
    Feb 11 02:02:03 fw1 php: snort_check_for_rule_updates.php: [Snort] Rules download error: Resolving timed out after 30797 milliseconds
    Feb 11 02:02:03 fw1 php: snort_check_for_rule_updates.php: [Snort] Will retry in 15 seconds...
    Feb 11 02:02:49 fw1 php: snort_check_for_rule_updates.php: [Snort] Rules download error: Resolving timed out after 30628 milliseconds
    Feb 11 02:02:49 fw1 php: snort_check_for_rule_updates.php: [Snort] Will retry in 15 seconds...
    Feb 11 02:03:04 fw1 php: snort_check_for_rule_updates.php: File 'snortrules-snapshot-2970.tar.gz.md5' download attempts: 4 ...
    Feb 11 02:03:04 fw1 php: snort_check_for_rule_updates.php: [Snort] Snort VRT rules md5 download failed...
    Feb 11 02:03:04 fw1 php: snort_check_for_rule_updates.php: [Snort] Server returned error code 0...
    Feb 11 02:03:34 fw1 php: snort_check_for_rule_updates.php: [Snort] Rules download error: Resolving timed out after 30759 milliseconds
    Feb 11 02:03:34 fw1 php: snort_check_for_rule_updates.php: [Snort] Will retry in 15 seconds...
    Feb 11 02:04:20 fw1 php: snort_check_for_rule_updates.php: [Snort] Rules download error: Resolving timed out after 30773 milliseconds
    Feb 11 02:04:20 fw1 php: snort_check_for_rule_updates.php: [Snort] Will retry in 15 seconds...
    Feb 11 02:05:06 fw1 php: snort_check_for_rule_updates.php: [Snort] Rules download error: Resolving timed out after 30740 milliseconds
    Feb 11 02:05:06 fw1 php: snort_check_for_rule_updates.php: [Snort] Will retry in 15 seconds...
    Feb 11 02:05:52 fw1 php: snort_check_for_rule_updates.php: [Snort] Rules download error: Resolving timed out after 30696 milliseconds
    Feb 11 02:05:52 fw1 php: snort_check_for_rule_updates.php: [Snort] Will retry in 15 seconds...
    Feb 11 02:06:07 fw1 php: snort_check_for_rule_updates.php: File 'snort-openappid.tar.gz.md5' download attempts: 4 ...
    Feb 11 02:06:07 fw1 php: snort_check_for_rule_updates.php: [Snort] Snort OpenAppID detectors md5 download failed...
    Feb 11 02:06:07 fw1 php: snort_check_for_rule_updates.php: [Snort] Server returned error code 0...
    Feb 11 02:06:37 fw1 php: snort_check_for_rule_updates.php: [Snort] Rules download error: Resolving timed out after 30597 milliseconds
    Feb 11 02:06:37 fw1 php: snort_check_for_rule_updates.php: [Snort] Will retry in 15 seconds...
    Feb 11 02:07:23 fw1 php: snort_check_for_rule_updates.php: [Snort] Rules download error: Resolving timed out after 30771 milliseconds
    Feb 11 02:07:23 fw1 php: snort_check_for_rule_updates.php: [Snort] Will retry in 15 seconds...
    Feb 11 02:08:09 fw1 php: snort_check_for_rule_updates.php: [Snort] Rules download error: Resolving timed out after 30889 milliseconds
    Feb 11 02:08:09 fw1 php: snort_check_for_rule_updates.php: [Snort] Will retry in 15 seconds...
    Feb 11 02:08:54 fw1 php: snort_check_for_rule_updates.php: [Snort] Rules download error: Resolving timed out after 30633 milliseconds
    Feb 11 02:08:54 fw1 php: snort_check_for_rule_updates.php: [Snort] Will retry in 15 seconds...
    Feb 11 02:09:09 fw1 php: snort_check_for_rule_updates.php: File 'community-rules.tar.gz.md5' download attempts: 4 ...
    Feb 11 02:09:09 fw1 php: snort_check_for_rule_updates.php: [Snort] Snort GPLv2 Community Rules md5 download failed...
    Feb 11 02:09:09 fw1 php: snort_check_for_rule_updates.php: [Snort] Server returned error code 0...
    Feb 11 02:09:40 fw1 php: snort_check_for_rule_updates.php: [Snort] Rules download error: Resolving timed out after 30721 milliseconds
    Feb 11 02:09:40 fw1 php: snort_check_for_rule_updates.php: [Snort] Will retry in 15 seconds...
    Feb 11 02:10:26 fw1 php: snort_check_for_rule_updates.php: [Snort] Rules download error: Resolving timed out after 30805 milliseconds
    Feb 11 02:10:26 fw1 php: snort_check_for_rule_updates.php: [Snort] Will retry in 15 seconds...
    Feb 11 02:11:12 fw1 php: snort_check_for_rule_updates.php: [Snort] Rules download error: Resolving timed out after 30806 milliseconds
    Feb 11 02:11:12 fw1 php: snort_check_for_rule_updates.php: [Snort] Will retry in 15 seconds...
    Feb 11 02:11:58 fw1 php: snort_check_for_rule_updates.php: [Snort] Rules download error: Resolving timed out after 30717 milliseconds
    Feb 11 02:11:58 fw1 php: snort_check_for_rule_updates.php: [Snort] Will retry in 15 seconds...
    Feb 11 02:12:13 fw1 php: snort_check_for_rule_updates.php: File 'emerging.rules.tar.gz.md5' download attempts: 4 ...
    Feb 11 02:12:13 fw1 php: snort_check_for_rule_updates.php: [Snort] Emerging Threats Open rules md5 download failed...
    Feb 11 02:12:13 fw1 php: snort_check_for_rule_updates.php: [Snort] Server returned error code 0...
    Feb 11 02:12:13 fw1 php: snort_check_for_rule_updates.php: [Snort] The Rules update has finished.
    Feb 11 02:12:13 fw1 check_reload_status: Syncing firewall
    Feb 11 02:12:14 fw1 kernel: pid 65763 (php), uid 0: exited on signal 11 (core dumped)
    Feb 11 02:13:09 fw1 check_reload_status: rc.newwanip starting sk0
    Feb 11 02:13:10 fw1 php-fpm[87333]: /rc.newwanip: rc.newwanip: Info: starting on sk0.
    Feb 11 02:13:10 fw1 php-fpm[87333]: /rc.newwanip: rc.newwanip: on (IP address: 192.168.100.10) (interface: WAN[wan]) (real interface: sk0).
    Feb 11 02:13:10 fw1 php-fpm[87333]: /rc.newwanip: IP has changed, killing states on former IP 84.192.***.***.
    Feb 11 02:13:11 fw1 php-fpm[87333]: /rc.newwanip: Could not find IPv6 gateway for interface (wan).
    Feb 11 02:13:12 fw1 php-fpm[87333]: /rc.newwanip: ROUTING: setting default route to 192.168.100.1
    Feb 11 02:13:12 fw1 php-fpm[87333]: /rc.newwanip: Removing static route for monitor 84.192.***.***and adding a new route through 192.168.100.1
    Feb 11 02:13:32 fw1 check_reload_status: updating dyndns WAN_DHCP
    Feb 11 02:13:32 fw1 check_reload_status: Restarting ipsec tunnels
    Feb 11 02:13:32 fw1 check_reload_status: Restarting OpenVPN tunnels/interfaces
    Feb 11 02:13:32 fw1 check_reload_status: Reloading filter
    Feb 11 02:13:33 fw1 php-fpm[15216]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use WAN_DHCP.
    Feb 11 02:13:33 fw1 php-fpm[15216]: /rc.openvpn: OpenVPN: Resync server1 OpenVPN Server
    Feb 11 02:13:33 fw1 kernel: ovpns1: link state changed to DOWN
    Feb 11 02:13:33 fw1 check_reload_status: Reloading filter
    Feb 11 02:13:34 fw1 kernel: ovpns1: link state changed to UP
    Feb 11 02:13:34 fw1 check_reload_status: rc.newwanip starting ovpns1
    Feb 11 02:13:35 fw1 php-fpm[15216]: /rc.filter_configure_sync: Could not find IPv6 
    
    Feb 11 02:13:39 fw1 check_reload_status: Syncing firewall
    Feb 11 02:13:39 fw1 php-fpm[19772]: /rc.newwanip: rc.newwanip: on (IP address: 192.168.10.1) (interface: []) (real interface: ovpns1).
    Feb 11 02:13:39 fw1 check_reload_status: Reloading filter
    Feb 11 02:13:39 fw1 php-fpm[19772]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection -  ->  192.168.10.1 - Restarting packages.
    Feb 11 02:13:39 fw1 check_reload_status: Starting packages
    Feb 11 02:13:39 fw1 check_reload_status: Syncing firewall
    Feb 11 02:13:39 fw1 php-fpm[87333]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 84.192.***.***->  192.168.100.10 - Restarting packages.
    Feb 11 02:13:40 fw1 php-fpm[70546]: /rc.start_packages: Restarting/Starting all packages.
    Feb 11 02:13:40 fw1 php-fpm[70546]: /rc.start_packages: Reloading Squid for configuration sync
    Feb 11 02:13:41 fw1 check_reload_status: Reloading filter
    Feb 11 02:13:41 fw1 php: lcdproc: Start client procedure. Error counter: (0)
    Feb 11 02:13:41 fw1 check_reload_status: Syncing firewall
    Feb 11 02:13:42 fw1 php-fpm[19772]: /rc.filter_configure_sync: Could not find IPv6 gateway for interface (wan).
    Feb 11 02:13:44 fw1 php-fpm[87333]: /rc.filter_configure_sync: Could not find IPv6 gateway for interface (wan).
    Feb 11 02:13:44 fw1 php: lcdproc: Start client procedure. Error counter: (0)
    Feb 11 02:13:55 fw1 php: lcdproc: Failed to connect to LCDd process Operation timed out (60)
    Feb 11 02:13:55 fw1 php: lcdproc: Start client procedure. Error counter: (1)
    Feb 11 02:14:06 fw1 php: lcdproc: Failed to connect to LCDd process Operation timed out (60)
    Feb 11 02:14:06 fw1 php: lcdproc: Start client procedure. Error counter: (2)
    Feb 11 02:14:11 fw1 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 on sk0
    Feb 11 02:14:12 fw1 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 on sk0
    Feb 11 02:14:13 fw1 check_reload_status: rc.newwanip starting sk0
    Feb 11 02:14:14 fw1 php-fpm[80275]: /rc.newwanip: rc.newwanip: Info: starting on sk0.
    Feb 11 02:14:14 fw1 php-fpm[80275]: /rc.newwanip: rc.newwanip: on (IP address: 192.168.100.10) (interface: WAN[wan]) (real interface: sk0).
    Feb 11 02:14:15 fw1 php-fpm[80275]: /rc.newwanip: Could not find IPv6 gateway for interface (wan).
    Feb 11 02:14:16 fw1 php-fpm[80275]: /rc.newwanip: ROUTING: setting default route to 192.168.100.1
    Feb 11 02:14:16 fw1 php-fpm[80275]: /rc.newwanip: Removing static route for monitor 84.192.***.*** and adding a new route through 192.168.100.1
    Feb 11 02:14:17 fw1 php-fpm[80275]: /rc.newwanip: Dyndns debug information (tiet.no-ip.biz): Could not resolve checkip.dyndns.org to IP using interface IP 192.168.100.10.
    Feb 11 02:14:17 fw1 php-fpm[80275]: /rc.newwanip: DynDNS (*****-ip.biz) There was an error trying to determine the public IP for interface - wan(sk0). Probably interface is not a WAN interface.
    Feb 11 02:14:17 fw1 php: lcdproc: Failed to connect to LCDd process Operation timed out (60)
    Feb 11 02:14:17 fw1 php: lcdproc: Start client procedure. Error counter: (3)
    Feb 11 02:14:18 fw1 php-fpm[80275]: /rc.newwanip: Resyncing OpenVPN instances for interface WAN.
    Feb 11 02:14:18 fw1 kernel: ovpns1: link state changed to DOWN
    Feb 11 02:14:18 fw1 check_reload_status: Reloading filter
    Feb 11 02:14:18 fw1 check_reload_status: Reloading filter
    Feb 11 02:14:18 fw1 php-fpm[80275]: /rc.newwanip: Creating rrd update script
    Feb 11 02:14:18 fw1 kernel: ovpns1: link state changed to UP
    Feb 11 02:14:18 fw1 check_reload_status: rc.newwanip starting ovpns1
    Feb 11 02:14:20 fw1 php-fpm[35317]: /rc.filter_configure_sync: Could not find IPv6 gateway for interface (wan).
    Feb 11 02:14:20 fw1 php-fpm[80275]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 192.168.100.10 ->  192.168.100.10 - Restarting packages.
    Feb 11 02:14:20 fw1 check_reload_status: Starting packages
    Feb 11 02:14:20 fw1 php-fpm[80275]: /rc.newwanip: rc.newwanip: Info: starting on ovpns1.
    Feb 11 02:14:20 fw1 php-fpm[80275]: /rc.newwanip: rc.newwanip: on (IP address: 192.168.10.1) (interface: []) (real interface: ovpns1).
    Feb 11 02:14:20 fw1 check_reload_status: Reloading filter
    Feb 11 02:14:20 fw1 php-fpm[80275]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection -  ->  192.168.10.1 - Restarting packages.
    Feb 11 02:14:20 fw1 check_reload_status: Starting packages
    Feb 11 02:14:22 fw1 php-fpm[80275]: /rc.start_packages: Restarting/Starting all packages.
    Feb 11 02:14:22 fw1 php-fpm[35317]: /rc.start_packages: Skipping STARTing packages process because previous/another instance is already running
    Feb 11 02:14:22 fw1 php-fpm[80275]: /rc.start_packages: Reloading Squid for configuration sync
    Feb 11 02:14:23 fw1 php-fpm[67206]: /rc.filter_configure_sync: Could not find IPv6 gateway for interface (wan).
    Feb 11 02:14:23 fw1 check_reload_status: Syncing firewall
    Feb 11 02:14:23 fw1 check_reload_status: Syncing firewall
    Feb 11 02:14:25 fw1 php: lcdproc: Start client procedure. Error counter: (0)
    Feb 11 02:14:36 fw1 php: lcdproc: Failed to connect to LCDd process Operation timed out (60)
    Feb 11 02:14:36 fw1 php: lcdproc: Start client procedure. Error counter: (1)
    Feb 11 02:14:47 fw1 php: lcdproc: Failed to connect to LCDd process Operation timed out (60)
    Feb 11 02:14:47 fw1 php: lcdproc: Start client procedure. Error counter: (2)
    Feb 11 02:14:58 fw1 php: lcdproc: Failed to connect to LCDd process Operation timed out (60)
    Feb 11 02:14:58 fw1 php: lcdproc: Start client procedure. Error counter: (3)
    Feb 11 02:15:09 fw1 php: lcdproc: Failed to connect to LCDd process Operation timed out (60)
    Feb 11 02:15:09 fw1 php: lcdproc: Too many errors, the client ends.
    Feb 11 02:15:14 fw1 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 on sk0
    Feb 11 02:15:15 fw1 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 on sk0
    Feb 11 02:15:16 fw1 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 on sk0
    Feb 11 02:15:17 fw1 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 on sk0
    Feb 11 02:15:18 fw1 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 on sk0
    Feb 11 02:15:19 fw1 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 on sk0
    Feb 11 02:15:20 fw1 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 on sk0
    Feb 11 02:15:20 fw1 check_reload_status: rc.newwanip starting sk0
    Feb 11 02:15:21 fw1 kernel: arpresolve: can't allocate llinfo for 192.168.100.1 on sk0
    Feb 11 02:15:21 fw1 php-fpm[67206]: /rc.newwanip: rc.newwanip: Info: starting on sk0.
    Feb 11 02:15:21 fw1 php-fpm[67206]: /rc.newwanip: rc.newwanip: on (IP address: 84.192.***.***) (interface: WAN[wan]) (real interface: sk0).
    Feb 11 02:15:21 fw1 php-fpm[67206]: /rc.newwanip: IP has changed, killing states on former IP 192.168.100.10.
    Feb 11 02:15:23 fw1 php-fpm[67206]: /rc.newwanip: Could not find IPv6 gateway for interface (wan).
    Feb 11 02:15:23 fw1 php-fpm[67206]: /rc.newwanip: ROUTING: setting default route to 84.192.***.***
    Feb 11 02:15:25 fw1 php-fpm[67206]: /rc.newwanip: phpDynDNS (*****-ip.biz): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
    Feb 11 02:15:26 fw1 php-fpm[67206]: /rc.newwanip: Resyncing OpenVPN instances for interface WAN.
    Feb 11 02:15:26 fw1 kernel: ovpns1: link state changed to DOWN
    Feb 11 02:15:26 fw1 check_reload_status: Reloading filter
    Feb 11 02:15:26 fw1 check_reload_status: Reloading filter
    Feb 11 02:15:26 fw1 php-fpm[67206]: /rc.newwanip: Creating rrd update script
    Feb 11 02:15:26 fw1 kernel: ovpns1: link state changed to UP
    Feb 11 02:15:26 fw1 check_reload_status: rc.newwanip starting ovpns1
    Feb 11 02:15:28 fw1 php-fpm[56235]: /rc.filter_configure_sync: Could not find IPv6 gateway for interface (wan).
    Feb 11 02:15:28 fw1 php-fpm[67206]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 192.168.100.10 ->  84.192.***.*** - Restarting packages.
    Feb 11 02:15:28 fw1 check_reload_status: Starting packages
    Feb 11 02:15:28 fw1 php-fpm[67206]: /rc.newwanip: rc.newwanip: Info: starting on ovpns1.
    Feb 11 02:15:28 fw1 php-fpm[67206]: /rc.newwanip: rc.newwanip: on (IP address: 192.168.10.1) (interface: []) (real interface: ovpns1).
    Feb 11 02:15:28 fw1 check_reload_status: Reloading filter
    Feb 11 02:15:28 fw1 php-fpm[67206]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection -  ->  192.168.10.1 - Restarting packages.
    Feb 11 02:15:28 fw1 check_reload_status: Starting packages
    Feb 11 02:15:29 fw1 php-fpm[67206]: /rc.start_packages: Restarting/Starting all packages.
    Feb 11 02:15:29 fw1 php-fpm[56235]: /rc.start_packages: Skipping STARTing packages process because previous/another instance is already running
    Feb 11 02:15:30 fw1 php-fpm[67206]: /rc.start_packages: Reloading Squid for configuration sync
    Feb 11 02:15:30 fw1 php-fpm[86166]: /rc.filter_configure_sync: Could not find IPv6 gateway for interface (wan).
    Feb 11 02:15:31 fw1 check_reload_status: Syncing firewall
    Feb 11 02:15:31 fw1 check_reload_status: Syncing firewall
    Feb 11 02:15:32 fw1 php: lcdproc: Start client procedure. Error counter: (0)
    Feb 11 02:15:43 fw1 php: lcdproc: Failed to connect to LCDd process Operation timed out (60)
    Feb 11 02:15:43 fw1 php: lcdproc: Start client procedure. Error counter: (1)
    Feb 11 02:15:54 fw1 php: lcdproc: Failed to connect to LCDd process Operation timed out (60)
    Feb 11 02:15:54 fw1 php: lcdproc: Start client procedure. Error counter: (2)
    Feb 11 02:16:05 fw1 php: lcdproc: Failed to connect to LCDd process Operation timed out (60)
    Feb 11 02:16:05 fw1 php: lcdproc: Start client procedure. Error counter: (3)
    Feb 11 02:16:16 fw1 php: lcdproc: Failed to connect to LCDd process Operation timed out (60)
    Feb 11 02:16:16 fw1 php: lcdproc: Too many errors, the client ends.
    Feb 11 07:04:06 fw1 php-fpm[73586]: /index.php: Session timed out for user 'admin' 
    
    

  • Netgate Administrator

    A private IP on your WAN is usually caused by a cable modem that's lost its upstream connection.  Could that be happening here. Is the private address being assigned in any of your internal subnets?

    Steve


  • Netgate

    Is your modem rebooting?  That might explain both symptoms.



  • Don't know , but that makes sense in a way…  :)
    On the other hand it's giving me 2 different IP's.


  • Netgate Administrator

    You mean 192.168.10.1 and 192.168.100.10?
    You aren't using either of those subnets (/24) internally?

    Steve



  • Nope :-)

    The 192.168.10.0/24 range is used by openvpn for vpn access


  • Netgate Administrator

    Ok, so you could have something handing out address in that subnet. The 100.1 address is totally spurious, not used as a tunnel address etc?

    Steve



  • Nope not used.

    But the WAN link seems stable for now.
    I made some changes in the System general settings and they seem to work.


  • Netgate Administrator

    What did you change?

    Steve



  • I have the same issue and posted some logs in another thread yesterday. I've seen a few posts like this recently do possibly something needs tweaking. I'll add a link to my logs tomorrow when I get back to my desk. I've tried setting static address, disabling monitoring but every 3-7 days my line drops and needs s reboot of wan or box to resolve.

    Edit: here's the link to my logs… https://forum.pfsense.org/index.php?topic=88236.msg491251#msg491251



  • In System -> general settings i added 127.0.0.1 as first dns server without any gateway
    then on the second line:
    8.8.8.8 with the gateway from my provider 84.192.192.1
    on the third:
    8.8.4.4 with 84.192.192.1

    the option to automatically find the gateway seems to f*ck the wan link sometimes…

    I didn't make any changes otherwise to the network config.

    Only updated LCDProc and used your guide to set it up because it kept crashing badly.


  • Netgate Administrator

    Interesting, thanks.



  • Hi,

    Are you sure this is resolved? I find it strange that changing dns settings solves this.

    Looking at your IP gateway, we're using the same internet provider and I'm having the same issue. (only updated yesterday, noticed the link going down today)

    I had a similar issue a few years back: https://forum.pfsense.org/index.php?topic=51420.0

    It was solved by using the 2.1 release. But now the problem returned after updating to 2.2.

    I'll keep an eye on it (it only happened once now) and will collect logs in case it returns.

    Regards,
    Kristof.



  • Okay, just had this happen again, here's the logs from that time.

    All VPNs going down..

    Feb 25 13:53:01 pfsense kernel: ovpns23: link state changed to DOWN
    Feb 25 13:53:01 pfsense php-fpm[89891]: /rc.newwanip: rc.newwanip: Info: starting on ovpns19.
    Feb 25 13:53:01 pfsense php-fpm[89891]: /rc.newwanip: rc.newwanip: on (IP address: 192.168.250.17) (interface: []) (real interface: ovpns19).
    Feb 25 13:53:01 pfsense php-fpm[89891]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection -  ->  192.168.250.17 - Restarting packages.
    Feb 25 13:53:01 pfsense check_reload_status: Starting packages
    Feb 25 13:53:02 pfsense php-fpm[21603]: /rc.openvpn: OpenVPN: Resync server24 [CUST26] S2S
    Feb 25 13:53:02 pfsense kernel: ovpns23: link state changed to UP
    Feb 25 13:53:02 pfsense check_reload_status: rc.newwanip starting ovpns23
    Feb 25 13:53:02 pfsense kernel: ovpns24: link state changed to DOWN
    Feb 25 13:53:02 pfsense check_reload_status: Reloading filter
    

    Our WAN interface.. (em1)

    Feb 25 13:53:02 pfsense kernel: em1: Watchdog timeout -- resetting
    Feb 25 13:53:02 pfsense kernel: em1: Queue(0) tdh = 801, hw tdt = 770
    Feb 25 13:53:02 pfsense kernel: em1: TX(0) desc avail = 31,Next TX to Clean = 801
    

    The rest of the VPNs going down. (we've got 30 or so)

    Feb 25 13:53:02 pfsense php-fpm[21603]: /rc.openvpn: OpenVPN: Resync server25 [CUST25] S2S
    Feb 25 13:53:02 pfsense kernel: ovpns24: link state changed to UP
    Feb 25 13:53:02 pfsense check_reload_status: rc.newwanip starting ovpns24
    Feb 25 13:53:02 pfsense kernel: ovpns25: link state changed to DOWN
    Feb 25 13:53:02 pfsense kernel: em1: link state changed to DOWN
    Feb 25 13:53:02 pfsense check_reload_status: Linkup starting em1
    Feb 25 13:53:02 pfsense php-fpm[21603]: /rc.openvpn: OpenVPN: Resync server26 [CUST26] S2S
    Feb 25 13:53:02 pfsense kernel: ovpns25: link state changed to UP
    Feb 25 13:53:02 pfsense check_reload_status: rc.newwanip starting ovpns25
    Feb 25 13:53:02 pfsense kernel: ovpns26: link state changed to DOWN
    Feb 25 13:53:03 pfsense php-fpm[21603]: /rc.linkup: DEVD Ethernet detached event for wan
    Feb 25 13:53:04 pfsense kernel: arpresolve: can't allocate llinfo for 81.82.192.1 on em1
    Feb 25 13:53:04 pfsense kernel: arpresolve: can't allocate llinfo for 81.82.192.1 on em1
    Feb 25 13:53:04 pfsense kernel: arpresolve: can't allocate llinfo for 81.82.192.1 on em1
    Feb 25 13:53:04 pfsense kernel: arpresolve: can't allocate llinfo for 81.82.192.1 on em1
    

    And then it continues with the can't allocate llinfo.

    I tried disconnecting and re-connecting the network cable: no result.
    I tried rebooting the cable modem: no result.

    It did try getting a new DHCP address:

    
    $ tcpdump -i em1 -n
    14:04:25.808903 IP 81.82.209.44.68 > 255.255.255.255.67: BOOTP/DHCP, Request from 00:0d:88:cc:fa:2f, length 300
    14:04:27.003202 IP 81.82.209.44.68 > 255.255.255.255.67: BOOTP/DHCP, Request from 00:0d:88:cc:fa:2f, length 300
    14:04:31.003925 IP 81.82.209.44.68 > 255.255.255.255.67: BOOTP/DHCP, Request from 00:0d:88:cc:fa:2f, length 300
    14:04:40.009358 IP 0.0.0.0.68 > 255.255.255.255.67: BOOTP/DHCP, Request from 00:0d:88:cc:fa:2f, length 300
    14:04:41.009469 IP 0.0.0.0.68 > 255.255.255.255.67: BOOTP/DHCP, Request from 00:0d:88:cc:fa:2f, length 300
    14:04:42.000206 IP 0.0.0.0.68 > 255.255.255.255.67: BOOTP/DHCP, Request from 00:0d:88:cc:fa:2f, length 300
    14:04:44.001156 IP 0.0.0.0.68 > 255.255.255.255.67: BOOTP/DHCP, Request from 00:0d:88:cc:fa:2f, length 300
    

    But that's it, never got any.

    Final step we took (because it was taking us +5 minutes already) was reboot the pfsense. After the reboot connection was good..

    I will probably take a 2.1.5 to temporarily switch this one out (luckily it's in our building) but will leave the 2.2 in place so I can switch easily.

    So I there's anything I can/should try, let me know, no problem.

    Regards,
    Kristof



  • Id love to share with you a solution but Im seeing exactly the same thing here and can confirm its not fixed for me by manipulating DNS as TieT suggested fixed his. My issue is triggered by my ISP WAN dhcp address expiring every seven days. Rebooting the firewall is the easiest way to fix it, I spent a couple of hours last time it went down capturing packets and what not and it appears in my situation to be related to DHCP queries not syncing. It could be specific to my ISP and I'll keep capturing and investigating if/when it continues. Thanks for sharing your logs.



  • I've put my 2.1.5 back in place. let's see how this goes. (I'm pretty sure this will stay up)

    I also suspect it has something to do with the dhcp renewal.

    2.1 solved it in 2012 for me :-) - https://forum.pfsense.org/index.php?topic=51420.0


  • Netgate Administrator

    Feb 25 13:53:02 pfsense kernel: em1: Watchdog timeout -- resetting
    

    That is a pretty bad sign.

    You might try looking at sysctl dev.em.1
    There may be some error couters there that show something nasty happened.

    Steve



  • Ok, put a switch in between modem<->pfsense , recorded the current state of sysctl dev.em.1 (attached)

    Currently it's good  :o (lol)  but if the problem returns I'll redo the sysctl dev.em.1 and won't reboot. (I'll just use a 2.1.5 device so can grab any logs needed of the 2.2)

    Thanks, I'll keep you posted.

    Kristof

    devem1.txt



  • I'm getting the same issue.

    Seems my external IPv4, which is set by DHCP, is randomly disconnecting while the IPv6 address is fine.

    No clue what's the cause, but I'm running the latest version on a Nano USB.



  • Ok, not resolved yet :(

    My current configuration is Modem <-> Switch <-> pfsense.

    I did see some bad things in the sysctl.em.1 :

    dev.em.1.mac_stats.collision_count: 0
    dev.em.1.mac_stats.symbol_errors: 4294967295
    dev.em.1.mac_stats.sequence_errors: 0
    dev.em.1.mac_stats.missed_packets: 28403
    

    My log was already full (I will make it bigger or use remote syslog) but I did see this:

    .. first a ton of these messages:
    Feb 28 11:21:04 pfsense kernel: arpresolve: can't allocate llinfo for 81.82.192.1 on em1
    Feb 28 11:21:04 pfsense kernel: arpresolve: can't allocate llinfo for 81.82.192.1 on em1
    Feb 28 11:21:04 pfsense kernel: arpresolve: can't allocate llinfo for 81.82.192.1 on em1
    Feb 28 11:21:05 pfsense kernel: em1: Watchdog timeout -- resetting
    Feb 28 11:21:05 pfsense kernel: em1: Queue(0) tdh = 0, hw tdt = 993
    Feb 28 11:21:05 pfsense kernel: em1: TX(0) desc avail = 31,Next TX to Clean = 0
    Feb 28 11:21:05 pfsense kernel: em1: link state changed to DOWN
    Feb 28 11:21:05 pfsense check_reload_status: Linkup starting em1
    Feb 28 11:21:06 pfsense php-fpm[43360]: /rc.linkup: DEVD Ethernet detached event for wan
    Feb 28 11:21:06 pfsense kernel: arpresolve: can't allocate llinfo for 81.82.192.1 on em1
    Feb 28 11:21:06 pfsense kernel: arpresolve: can't allocate llinfo for 81.82.192.1 on em1
    Feb 28 11:21:09 pfsense check_reload_status: Linkup starting em1
    Feb 28 11:21:09 pfsense kernel: em1: link state changed to UP
    Feb 28 11:21:10 pfsense kernel: arpresolve: can't allocate llinfo for 81.82.192.1 on em1
    Feb 28 11:21:10 pfsense kernel: arpresolve: can't allocate llinfo for 81.82.192.1 on em1
    Feb 28 11:21:11 pfsense php-fpm[43360]: /rc.linkup: Shutting down Router Advertisment daemon cleanly
    Feb 28 11:21:11 pfsense php-fpm[54180]: /rc.linkup: DEVD Ethernet attached event for wan
    Feb 28 11:21:11 pfsense php-fpm[54180]: /rc.linkup: HOTPLUG: Configuring interface wan
    Feb 28 11:21:13 pfsense kernel: arpresolve: can't allocate llinfo for 81.82.192.1 on em1
    Feb 28 11:21:13 pfsense kernel: arpresolve: can't allocate llinfo for 81.82.192.1 on em1
    Feb 28 11:21:14 pfsense kernel: arpresolve: can't allocate llinfo for 81.82.192.1 on em1
    .. and then more of these
    

    This only happens on 2.2, the same configuration with 2.1.5, no problem. It took about 30 hours before it occured the first time.

    Anything else I might try to resolve/further pinpoint this?

    Regards,
    Kristof.


  • Netgate

    New hardware?



  • @Derelict:

    New hardware?

    No, only diiference: 2.1.5 -> 2.2.


  • Netgate

    @man:

    arpresolve: can't allocate llinfo for %d.%d.%d.%d The route for the ref-
        erenced host points to a device upon which ARP is required, but ARP was
        unable to allocate a routing table entry in which to store the host's MAC
        address.  This usually points to a misconfigured routing table.  It can
        also occur if the kernel cannot allocate memory.

    What's in netstat -rn when it's failing?



  • Just resolved my issue by disabling the local DNS resolution. Changed it to just use Google's DNS servers instead (8.8.8.8, 8.8.4.4) and it's working fine.

    Not sure if it's the exact same issue as what everyone else has had, but that's what did it for me.



  • Test it for a few days, it worked for me for a few days, but then the gateway was lost again.
    It seems when I create a vpn to my fw the issue begins…

    @JWTech:

    Just resolved my issue by disabling the local DNS resolution. Changed it to just use Google's DNS servers instead (8.8.8.8, 8.8.4.4) and it's working fine.

    Not sure if it's the exact same issue as what everyone else has had, but that's what did it for me.



  • @Derelict:

    @man:

    arpresolve: can't allocate llinfo for %d.%d.%d.%d The route for the ref-
        erenced host points to a device upon which ARP is required, but ARP was
        unable to allocate a routing table entry in which to store the host's MAC
        address.  This usually points to a misconfigured routing table.  It can
        also occur if the kernel cannot allocate memory.

    What's in netstat -rn when it's failing?

    Tnx for the suggestion, will try this and the sysctl dev.em.1 on next problem.

    I'm waiting for it to occur again (it can take several hours but it might as well take 48 hours) and report back.

    Kristof


  • Netgate Administrator

    I find it odd that in both cases here the actual physical link is going down. If that was a modem issue I would expect the switch to as least show a different result. I guess in a watchdog time-out scenario the link is probably brought down when the NIC is reset.  Hmmm.

    Steve


Locked