WAN does not renew after reboot

[stephenw10]

Check the logs when you do that. What is actually happening? I imagine it relinks the WAN and pulls a new lease.

As long as the connected wifi bridge passes at layer 2 DHCP should work.

[RyanM]

@stephenw10 which log should I look at?

[stephenw10]

The dhcp and system logs.

[RyanM]

system.log since the last boot:

Feb  4 11:39:29 router syslogd: kernel boot file is /boot/kernel/kernel
Feb  4 11:39:29 router kernel: pflog0: promiscuous mode disabled
Feb  4 11:39:29 router kernel: Waiting (max 60 seconds) for system process `vnlru' to stop... done
Feb  4 11:39:29 router kernel: Waiting (max 60 seconds) for system process `syncer' to stop...
Feb  4 11:39:29 router kernel: Syncing disks, vnodes remaining... 0 0 0 0 0 done
Feb  4 11:39:29 router kernel: Waiting (max 60 seconds) for system thread `bufdaemon' to stop... done
Feb  4 11:39:29 router kernel: Waiting (max 60 seconds) for system thread `bufspacedaemon-0' to stop... done
Feb  4 11:39:29 router kernel: Waiting (max 60 seconds) for system thread `bufspacedaemon-1' to stop... done
Feb  4 11:39:29 router kernel: All buffers synced.
Feb  4 11:39:29 router kernel: Uptime: 23m21s
Feb  4 11:39:29 router kernel: ---<<BOOT>>---
Feb  4 11:39:29 router kernel: Copyright (c) 1992-2020 The FreeBSD Project.
Feb  4 11:39:29 router kernel: Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
Feb  4 11:39:29 router kernel:  The Regents of the University of California. All rights reserved.
Feb  4 11:39:29 router kernel: FreeBSD is a registered trademark of The FreeBSD Foundation.
Feb  4 11:39:29 router kernel: FreeBSD 12.2-STABLE fd0f54f44b5c(RELENG_2_5_0) pfSense amd64
Feb  4 11:39:29 router kernel: FreeBSD clang version 10.0.1 (git@github.com:llvm/llvm-project.git llvmorg-10.0.1-0-gef32c611aa2)
Feb  4 11:39:29 router kernel: VT(vga): resolution 640x480
Feb  4 11:39:29 router kernel: CPU: Intel(R) Celeron(R) CPU  J3060  @ 1.60GHz (1600.04-MHz K8-class CPU)
Feb  4 11:39:29 router kernel:   Origin="GenuineIntel"  Id=0x406c4  Family=0x6  Model=0x4c  Stepping=4
Feb  4 11:39:29 router kernel:   Features=0xbfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE>
Feb  4 11:39:29 router kernel:   Features2=0x43d8e3bf<SSE3,PCLMULQDQ,DTES64,MON,DS_CPL,VMX,EST,TM2,SSSE3,CX16,xTPR,PDCM,SSE4.1,SSE4.2,MOVBE,POPCNT,TSCDLT,AESNI,RDRAND>
Feb  4 11:39:29 router kernel:   AMD Features=0x28100800<SYSCALL,NX,RDTSCP,LM>
Feb  4 11:39:29 router kernel:   AMD Features2=0x101<LAHF,Prefetch>
Feb  4 11:39:29 router kernel:   Structured Extended Features=0x2282<TSCADJ,SMEP,ERMS,NFPUSG>
Feb  4 11:39:29 router kernel:   Structured Extended Features3=0xc000000<IBPB,STIBP>
Feb  4 11:39:29 router kernel:   VT-x: PAT,HLT,MTF,PAUSE,EPT,UG,VPID
Feb  4 11:39:29 router kernel:   TSC: P-state invariant, performance statistics
Feb  4 11:39:29 router kernel: real memory  = 4294967296 (4096 MB)
Feb  4 11:39:29 router kernel: avail memory = 3994320896 (3809 MB)
Feb  4 11:39:29 router kernel: Event timer "LAPIC" quality 600
Feb  4 11:39:29 router kernel: ACPI APIC Table: <COREv4 COREBOOT>
Feb  4 11:39:29 router kernel: WARNING: L1 data cache covers fewer APIC IDs than a core (0 < 1)
Feb  4 11:39:29 router kernel: FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs
Feb  4 11:39:29 router kernel: FreeBSD/SMP: 1 package(s) x 2 core(s)
Feb  4 11:39:29 router kernel: arc4random: no preloaded entropy cache
Feb  4 11:39:29 router kernel: ioapic0 <Version 2.0> irqs 0-114 on motherboard
Feb  4 11:39:29 router kernel: Launching APs: 1
Feb  4 11:39:29 router kernel: Timecounter "TSC" frequency 1600039940 Hz quality 1000
Feb  4 11:39:29 router kernel: ipw_bss: You need to read the LICENSE file in /usr/share/doc/legal/intel_ipw.LICENSE.
Feb  4 11:39:29 router kernel: ipw_bss: If you agree with the license, set legal.intel_ipw.license_ack=1 in /boot/loader.conf.
Feb  4 11:39:29 router kernel: module_register_init: MOD_LOAD (ipw_bss_fw, 0xffffffff8073dd40, 0) error 1
Feb  4 11:39:29 router kernel: ipw_ibss: You need to read the LICENSE file in /usr/share/doc/legal/intel_ipw.LICENSE.
Feb  4 11:39:29 router kernel: ipw_ibss: If you agree with the license, set legal.intel_ipw.license_ack=1 in /boot/loader.conf.
Feb  4 11:39:29 router kernel: module_register_init: MOD_LOAD (ipw_ibss_fw, 0xffffffff8073ddf0, 0) error 1
Feb  4 11:39:29 router kernel: ipw_monitor: You need to read the LICENSE file in /usr/share/doc/legal/intel_ipw.LICENSE.
Feb  4 11:39:29 router kernel: ipw_monitor: If you agree with the license, set legal.intel_ipw.license_ack=1 in /boot/loader.conf.
Feb  4 11:39:29 router kernel: module_register_init: MOD_LOAD (ipw_monitor_fw, 0xffffffff8073dea0, 0) error 1
Feb  4 11:39:29 router kernel: iwi_bss: You need to read the LICENSE file in /usr/share/doc/legal/intel_iwi.LICENSE.
Feb  4 11:39:29 router kernel: iwi_bss: If you agree with the license, set legal.intel_iwi.license_ack=1 in /boot/loader.conf.
Feb  4 11:39:29 router kernel: module_register_init: MOD_LOAD (iwi_bss_fw, 0xffffffff80765730, 0) error 1
Feb  4 11:39:29 router kernel: iwi_ibss: You need to read the LICENSE file in /usr/share/doc/legal/intel_iwi.LICENSE.
Feb  4 11:39:29 router kernel: iwi_ibss: If you agree with the license, set legal.intel_iwi.license_ack=1 in /boot/loader.conf.
Feb  4 11:39:29 router kernel: module_register_init: MOD_LOAD (iwi_ibss_fw, 0xffffffff807657e0, 0) error 1
Feb  4 11:39:29 router kernel: iwi_monitor: You need to read the LICENSE file in /usr/share/doc/legal/intel_iwi.LICENSE.
Feb  4 11:39:29 router kernel: iwi_monitor: If you agree with the license, set legal.intel_iwi.license_ack=1 in /boot/loader.conf.
Feb  4 11:39:29 router kernel: module_register_init: MOD_LOAD (iwi_monitor_fw, 0xffffffff80765890, 0) error 1
Feb  4 11:39:29 router kernel: wlan: mac acl policy registered
Feb  4 11:39:29 router kernel: random: entropy device external interface
Feb  4 11:39:29 router kernel: module_register_init: MOD_LOAD (vesa, 0xffffffff8140c3e0, 0) error 19
Feb  4 11:39:29 router kernel: kbd0 at kbdmux0
Feb  4 11:39:29 router kernel: random: registering fast source Intel Secure Key RNG
Feb  4 11:39:29 router kernel: random: fast provider: "Intel Secure Key RNG"
Feb  4 11:39:29 router kernel: [ath_hal] loaded
Feb  4 11:39:29 router kernel: 000.000054 [4336] netmap_init               netmap: loaded module
Feb  4 11:39:29 router kernel: mlx5en: Mellanox Ethernet driver 3.5.2 (September 2019)
Feb  4 11:39:29 router kernel: nexus0
Feb  4 11:39:29 router kernel: vtvga0: <VT VGA driver> on motherboard
Feb  4 11:39:29 router kernel: cryptosoft0: <software crypto> on motherboard
Feb  4 11:39:29 router kernel: padlock0: No ACE support.
Feb  4 11:39:29 router kernel: acpi0: <COREv4 COREBOOT> on motherboard
Feb  4 11:39:29 router kernel: acpi0: Power Button (fixed)
Feb  4 11:39:29 router kernel: cpu0: <ACPI CPU> on acpi0
Feb  4 11:39:29 router kernel: atrtc0: <AT realtime clock> port 0x70-0x77 on acpi0
Feb  4 11:39:29 router kernel: atrtc0: registered as a time-of-day clock, resolution 1.000000s
Feb  4 11:39:29 router kernel: Event timer "RTC" frequency 32768 Hz quality 0
Feb  4 11:39:29 router kernel: attimer0: <AT timer> port 0x40-0x43,0x50-0x53 irq 0 on acpi0
Feb  4 11:39:29 router kernel: Timecounter "i8254" frequency 1193182 Hz quality 0
Feb  4 11:39:29 router kernel: Event timer "i8254" frequency 1193182 Hz quality 100
Feb  4 11:39:29 router kernel: Timecounter "ACPI-safe" frequency 3579545 Hz quality 850
Feb  4 11:39:29 router kernel: acpi_timer0: <24-bit timer at 3.579545MHz> port 0x408-0x40b on acpi0
Feb  4 11:39:29 router kernel: pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
Feb  4 11:39:29 router kernel: pci0: <ACPI PCI bus> on pcib0
Feb  4 11:39:29 router kernel: vgapci0: <VGA-compatible display> port 0x3000-0x303f mem 0xd0000000-0xd0ffffff,0xc0000000-0xcfffffff at device 2.0 on pci0
Feb  4 11:39:29 router kernel: vgapci0: Boot video device
Feb  4 11:39:29 router kernel: ahci0: <AHCI SATA controller> port 0x3040-0x305f mem 0xd1222000-0xd12227ff irq 19 at device 19.0 on pci0
Feb  4 11:39:29 router kernel: ahci0: AHCI v1.31 with 2 6Gbps ports, Port Multiplier not supported
Feb  4 11:39:29 router kernel: ahcich0: <AHCI channel> at channel 0 on ahci0
Feb  4 11:39:29 router kernel: ahcich1: <AHCI channel> at channel 1 on ahci0
Feb  4 11:39:29 router kernel: xhci0: <Intel Braswell USB 3.0 controller> mem 0xd1200000-0xd120ffff irq 20 at device 20.0 on pci0
Feb  4 11:39:29 router kernel: xhci0: 32 bytes context size, 64-bit DMA
Feb  4 11:39:29 router kernel: usbus0 on xhci0
Feb  4 11:39:29 router kernel: usbus0: 5.0Gbps Super Speed USB v3.0
Feb  4 11:39:29 router kernel: pci0: <base peripheral, DMA controller> at device 24.0 (no driver attached)
Feb  4 11:39:29 router kernel: pci0: <serial bus> at device 24.1 (no driver attached)
Feb  4 11:39:29 router kernel: pci0: <serial bus> at device 24.2 (no driver attached)
Feb  4 11:39:29 router kernel: hdac0: <Intel Braswell HDA Controller> mem 0xd1214000-0xd1217fff irq 22 at device 27.0 on pci0
Feb  4 11:39:29 router kernel: pcib1: <PCI-PCI bridge> irq 16 at device 28.0 on pci0
Feb  4 11:39:29 router kernel: pci1: <PCI bus> on pcib1
Feb  4 11:39:29 router kernel: igb0: <Intel(R) PRO/1000 PCI-Express Network Driver> port 0x1000-0x101f mem 0xd1000000-0xd101ffff,0xd1020000-0xd1023fff irq 16 at device 0.0 on pci1
Feb  4 11:39:29 router kernel: igb0: Using 1024 TX descriptors and 1024 RX descriptors
Feb  4 11:39:29 router kernel: igb0: Using 2 RX queues 2 TX queues
Feb  4 11:39:29 router kernel: igb0: Using MSI-X interrupts with 3 vectors
Feb  4 11:39:29 router kernel: igb0: Ethernet address: 00:e0:67:2a:73:e0
Feb  4 11:39:29 router kernel: igb0: netmap queues/slots: TX 2/1024, RX 2/1024
Feb  4 11:39:29 router kernel: pcib2: <PCI-PCI bridge> irq 17 at device 28.1 on pci0
Feb  4 11:39:29 router kernel: pci2: <PCI bus> on pcib2
Feb  4 11:39:29 router kernel: igb1: <Intel(R) PRO/1000 PCI-Express Network Driver> port 0x2000-0x201f mem 0xd1100000-0xd111ffff,0xd1120000-0xd1123fff irq 16 at device 0.0 on pci2
Feb  4 11:39:29 router kernel: igb1: Using 1024 TX descriptors and 1024 RX descriptors
Feb  4 11:39:29 router kernel: igb1: Using 2 RX queues 2 TX queues
Feb  4 11:39:29 router kernel: igb1: Using MSI-X interrupts with 3 vectors
Feb  4 11:39:29 router kernel: igb1: Ethernet address: 00:e0:67:2a:73:e1
Feb  4 11:39:29 router kernel: igb1: netmap queues/slots: TX 2/1024, RX 2/1024
Feb  4 11:39:29 router kernel: pci0: <base peripheral, DMA controller> at device 30.0 (no driver attached)
Feb  4 11:39:29 router kernel: isab0: <PCI-ISA bridge> at device 31.0 on pci0
Feb  4 11:39:29 router kernel: isa0: <ISA bus> on isab0
Feb  4 11:39:29 router kernel: acpi_button0: <Power Button> on acpi0
Feb  4 11:39:29 router kernel: uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
Feb  4 11:39:29 router kernel: orm0: <ISA Option ROM> at iomem 0xee800-0xeffff pnpid ORM0000 on isa0
Feb  4 11:39:29 router kernel: est0: <Enhanced SpeedStep Frequency Control> on cpu0
Feb  4 11:39:29 router kernel: ZFS NOTICE: Prefetch is disabled by default if less than 4GB of RAM is present;
Feb  4 11:39:29 router kernel:             to enable, add "vfs.zfs.prefetch_disable=0" to /boot/loader.conf.
Feb  4 11:39:29 router kernel: ZFS filesystem version: 5
Feb  4 11:39:29 router kernel: ZFS storage pool version: features support (5000)
Feb  4 11:39:29 router kernel: Timecounters tick every 1.000 msec
Feb  4 11:39:29 router kernel: arc4random: no preloaded entropy cache
Feb  4 11:39:29 router kernel: hdacc0: <Realtek ALC662 rev1 HDA CODEC> at cad 0 on hdac0
Feb  4 11:39:29 router kernel: hdaa0: <Realtek ALC662 rev1 Audio Function Group> at nid 1 on hdacc0
Feb  4 11:39:29 router kernel: pcm0: <Realtek ALC662 rev1 (Analog 5.1+HP/2.0)> at nid 20,22,21,27 and 24,26 on hdaa0
Feb  4 11:39:29 router kernel: pcm1: <Realtek ALC662 rev1 (Rear Digital)> at nid 30 on hdaa0
Feb  4 11:39:29 router kernel: pcm2: <Realtek ALC662 rev1 (Front Analog Mic)> at nid 25 on hdaa0
Feb  4 11:39:29 router kernel: hdacc1: <Intel Braswell HDA CODEC> at cad 2 on hdac0
Feb  4 11:39:29 router kernel: hdaa1: <Intel Braswell Audio Function Group> at nid 1 on hdacc1
Feb  4 11:39:29 router kernel: hdaa1: hdaa_audio_as_parse: Duplicate pin 0 (6) in association 1! Disabling association.
Feb  4 11:39:29 router kernel: hdaa1: hdaa_audio_as_parse: Duplicate pin 0 (7) in association 1! Disabling association.
Feb  4 11:39:29 router kernel: Trying to mount root from zfs:pfSense/ROOT/default []...
Feb  4 11:39:29 router kernel: Root mount waiting for: CAM usbus0
Feb  4 11:39:29 router kernel: ugen0.1: <0x8086 XHCI root HUB> at usbus0
Feb  4 11:39:29 router kernel: uhub0: <0x8086 XHCI root HUB, class 9/0, rev 3.00/1.00, addr 1> on usbus0
Feb  4 11:39:29 router kernel: uhub0: 13 ports with 13 removable, self powered
Feb  4 11:39:29 router kernel: Root mount waiting for: CAM usbus0
Feb  4 11:39:29 router kernel: ugen0.2: <vendor 0x1a40 USB 2.0 Hub MTT> at usbus0
Feb  4 11:39:29 router kernel: uhub1 on uhub0
Feb  4 11:39:29 router kernel: uhub1: <vendor 0x1a40 USB 2.0 Hub MTT, class 9/0, rev 2.00/1.00, addr 1> on usbus0
Feb  4 11:39:29 router kernel: uhub1: MTT enabled
Feb  4 11:39:29 router kernel: Root mount waiting for: CAM usbus0
Feb  4 11:39:29 router kernel: uhub1: 4 ports with 4 removable, self powered
Feb  4 11:39:29 router kernel: Root mount waiting for: CAM
Feb  4 11:39:29 router kernel: Root mount waiting for: CAM
Feb  4 11:39:29 router kernel: Root mount waiting for: CAM
Feb  4 11:39:29 router kernel: Root mount waiting for: CAM
Feb  4 11:39:29 router kernel: Root mount waiting for: CAM
Feb  4 11:39:29 router kernel: Root mount waiting for: CAM
Feb  4 11:39:29 router kernel: Root mount waiting for: CAM
Feb  4 11:39:29 router kernel: ada0 at ahcich0 bus 0 scbus0 target 0 lun 0
Feb  4 11:39:29 router kernel: ada0: <Protectli 64GB mSATA SBFM61.3> ACS-4 ATA SATA 3.x device
Feb  4 11:39:29 router kernel: ada0: Serial Number A46207191B8900572407
Feb  4 11:39:29 router kernel: ada0: 600.000MB/s transfers (SATA 3.x, UDMA6, PIO 8192bytes)
Feb  4 11:39:29 router kernel: ada0: Command Queueing enabled
Feb  4 11:39:29 router kernel: ada0: 61057MB (125045424 512 byte sectors)
Feb  4 11:39:29 router kernel: random: unblocking device.
Feb  4 11:39:29 router kernel: CPU: Intel(R) Celeron(R) CPU  J3060  @ 1.60GHz (1600.04-MHz K8-class CPU)
Feb  4 11:39:29 router kernel:   Origin="GenuineIntel"  Id=0x406c4  Family=0x6  Model=0x4c  Stepping=4
Feb  4 11:39:29 router kernel:   Features=0xbfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE>
Feb  4 11:39:29 router kernel:   Features2=0x43d8e3bf<SSE3,PCLMULQDQ,DTES64,MON,DS_CPL,VMX,EST,TM2,SSSE3,CX16,xTPR,PDCM,SSE4.1,SSE4.2,MOVBE,POPCNT,TSCDLT,AESNI,RDRAND>
Feb  4 11:39:29 router kernel:   AMD Features=0x28100800<SYSCALL,NX,RDTSCP,LM>
Feb  4 11:39:29 router kernel:   AMD Features2=0x101<LAHF,Prefetch>
Feb  4 11:39:29 router kernel:   Structured Extended Features=0x2282<TSCADJ,SMEP,ERMS,NFPUSG>
Feb  4 11:39:29 router kernel:   Structured Extended Features3=0xc000400<MD_CLEAR,IBPB,STIBP>
Feb  4 11:39:29 router kernel:   VT-x: PAT,HLT,MTF,PAUSE,EPT,UG,VPID
Feb  4 11:39:29 router kernel:   TSC: P-state invariant, performance statistics
Feb  4 11:39:29 router kernel: ig4iic0: <Intel Braswell Serial I/O I2C Port 1> mem 0xd121d000-0xd121dfff,0xd121e000-0xd121efff irq 19 at device 24.1 on pci0
Feb  4 11:39:29 router kernel: ig4iic0: Using MSI
Feb  4 11:39:29 router kernel: iicbus0: <Philips I2C bus> on ig4iic0
Feb  4 11:39:29 router kernel: ig4iic1: <Intel Braswell Serial I/O I2C Port 2> mem 0xd121f000-0xd121ffff,0xd1220000-0xd1220fff irq 18 at device 24.2 on pci0
Feb  4 11:39:29 router kernel: ig4iic1: Using MSI
Feb  4 11:39:29 router kernel: iicbus1: <Philips I2C bus> on ig4iic1
Feb  4 11:39:29 router kernel: lo0: link state changed to UP
Feb  4 11:39:30 router sshd[7864]: Server listening on :: port 22.
Feb  4 11:39:30 router sshd[7864]: Server listening on 0.0.0.0 port 22.
Feb  4 11:39:41 router php[392]: rc.bootup: The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf igb0 > /tmp/igb0_output 2> /tmp/igb0_error_output' returned exit code '1', the output was ''
Feb  4 11:39:41 router kernel: done.
Feb  4 11:39:41 router php[392]: rc.bootup: Resyncing OpenVPN instances.
Feb  4 11:39:41 router kernel: done.
Feb  4 11:39:41 router kernel: pflog0: promiscuous mode enabled
Feb  4 11:39:42 router php[392]: rc.bootup: Gateway, none 'available' for inet, use the first one configured. ''
Feb  4 11:39:42 router kernel: .done.
Feb  4 11:39:42 router kernel: done.
Feb  4 11:39:42 router php[392]: rc.bootup: Gateway, none 'available' for inet6, use the first one configured. ''
Feb  4 11:39:42 router kernel: done.
Feb  4 11:39:42 router php[392]: rc.bootup: sync unbound done.
Feb  4 11:39:42 router kernel: done.
Feb  4 11:39:43 router kernel: done.
Feb  4 11:39:43 router php[392]: rc.bootup: NTPD is starting up.
Feb  4 11:39:43 router kernel: done.
Feb  4 11:39:43 router kernel: done.
Feb  4 11:39:43 router check_reload_status[374]: Updating all dyndns
Feb  4 11:39:44 router kernel: ....
Feb  4 11:39:44 router check_reload_status[374]: Linkup starting igb0
Feb  4 11:39:44 router kernel:
Feb  4 11:39:44 router kernel: igb0: link state changed to UP
Feb  4 11:39:44 router php[392]: rc.bootup: The command '/usr/local/sbin/strongswanrc stop' returned exit code '1', the output was 'strongswan not running? (check /var/run/daemon-charon.pid).'
Feb  4 11:39:45 router check_reload_status[374]: Linkup starting igb1
Feb  4 11:39:45 router kernel: igb1: link state changed to UP
Feb  4 11:39:48 router php[392]: rc.bootup: Creating rrd update script
Feb  4 11:39:48 router kernel: done.
Feb  4 11:39:48 router root[86666]: /etc/rc.d/hostid: WARNING: hostid: unable to figure out a UUID from DMI data, generating a new one
Feb  4 11:39:51 router syslogd: exiting on signal 15
Feb  4 11:39:51 router syslogd: kernel boot file is /boot/kernel/kernel
Feb  4 11:39:51 router kernel: done.
Feb  4 11:39:51 router php-fpm[345]: /rc.start_packages: Restarting/Starting all packages.
Feb  4 11:39:51 router root[10534]: Bootup complete
Feb  4 11:39:52 router login[14916]: login on ttyv0 as root
Feb  4 12:08:05 router php-fpm[345]: /index.php: Successful login for user 'admin' from: 192.168.1.100 (Local Database)
Feb  4 12:08:11 router sshd[68729]: Accepted publickey for rmccullough from 192.168.1.100 port 55833 ssh2: RSA SHA256:P7JW/dxUNDodWSlM+LIzypz1ziIzoYUDbN04rA99a3o
Feb  4 12:08:50 router check_reload_status[374]: rc.newwanip starting igb0
Feb  4 12:08:52 router php-fpm[80083]: /rc.newwanip: rc.newwanip: Info: starting on igb0.
Feb  4 12:08:52 router php-fpm[80083]: /rc.newwanip: rc.newwanip: on (IP address: 192.168.86.241) (interface: WAN[wan]) (real interface: igb0).
Feb  4 12:08:52 router check_reload_status[374]: Reloading filter
Feb  4 12:11:07 router check_reload_status[374]: Syncing firewall
Feb  4 12:11:07 router php-fpm[345]: /interfaces.php: Beginning configuration backup to https://acb.netgate.com/save
Feb  4 12:11:07 router php-fpm[345]: /interfaces.php: End of configuration backup to https://acb.netgate.com/save (success).
Feb  4 12:11:13 router php-fpm[345]: /interfaces.php: Shutting down Router Advertisment daemon cleanly
Feb  4 12:11:13 router check_reload_status[374]: rc.newwanip starting igb0
Feb  4 12:11:13 router php-fpm[345]: /interfaces.php: Default gateway setting Interface WAN_DHCP Gateway as default.
Feb  4 12:11:13 router php-fpm[345]: /interfaces.php: Gateway, none 'available' for inet6, use the first one configured. ''
Feb  4 12:11:13 router check_reload_status[374]: Restarting ipsec tunnels
Feb  4 12:11:14 router php-fpm[80083]: /rc.newwanip: rc.newwanip: Info: starting on igb0.
Feb  4 12:11:14 router php-fpm[80083]: /rc.newwanip: rc.newwanip: on (IP address: 192.168.86.241) (interface: WAN[wan]) (real interface: igb0).
Feb  4 12:11:14 router check_reload_status[374]: Reloading filter
Feb  4 12:11:18 router check_reload_status[374]: updating dyndns wan
Feb  4 12:11:20 router check_reload_status[374]: Reloading filter
Feb  4 12:11:20 router php-fpm[345]: /interfaces.php: Creating rrd update script
Feb  4 12:12:14 router sshd[64915]: Accepted publickey for rmccullough from 192.168.1.100 port 55956 ssh2: RSA SHA256:P7JW/dxUNDodWSlM+LIzypz1ziIzoYUDbN04rA99a3o
Feb  4 12:12:48 router sshd[68955]: Timeout, client not responding from user rmccullough 192.168.1.100 port 55833
Feb  4 12:51:19 router check_reload_status[374]: Linkup starting igb1
Feb  4 12:51:19 router kernel: igb1: link state changed to DOWN
Feb  4 12:51:20 router php-fpm[345]: /rc.linkup: DEVD Ethernet detached event for lan
Feb  4 12:51:20 router check_reload_status[374]: Reloading filter
Feb  4 12:51:22 router check_reload_status[374]: Linkup starting igb1
Feb  4 12:51:22 router kernel: igb1: link state changed to UP
Feb  4 12:51:23 router php-fpm[344]: /rc.linkup: DEVD Ethernet attached event for lan
Feb  4 12:51:23 router php-fpm[344]: /rc.linkup: HOTPLUG: Configuring interface lan
Feb  4 12:51:23 router php-fpm[344]: /rc.linkup: Gateway, none 'available' for inet6, use the first one configured. ''
Feb  4 12:51:23 router check_reload_status[374]: Restarting ipsec tunnels
Feb  4 12:51:28 router check_reload_status[374]: updating dyndns lan
Feb  4 12:51:28 router check_reload_status[374]: Reloading filter
Feb  4 12:51:52 router sshd[65253]: Timeout, client not responding from user rmccullough 192.168.1.100 port 55956
Feb  4 13:01:19 router check_reload_status[374]: Linkup starting igb1
Feb  4 13:01:19 router kernel: igb1: link state changed to DOWN
Feb  4 13:01:20 router php-fpm[80083]: /rc.linkup: DEVD Ethernet detached event for lan
Feb  4 13:01:20 router check_reload_status[374]: Reloading filter
Feb  4 13:01:24 router check_reload_status[374]: Linkup starting igb1
Feb  4 13:01:24 router kernel: igb1: link state changed to UP
Feb  4 13:01:25 router php-fpm[344]: /rc.linkup: DEVD Ethernet attached event for lan
Feb  4 13:01:25 router php-fpm[344]: /rc.linkup: HOTPLUG: Configuring interface lan
Feb  4 13:01:26 router php-fpm[344]: /rc.linkup: Gateway, none 'available' for inet6, use the first one configured. ''
Feb  4 13:01:26 router check_reload_status[374]: Restarting ipsec tunnels
Feb  4 13:01:30 router check_reload_status[374]: updating dyndns lan
Feb  4 13:01:30 router check_reload_status[374]: Reloading filter
Feb  4 13:02:07 router sshd[81950]: Accepted publickey for rmccullough from 192.168.1.100 port 62887 ssh2: RSA SHA256:P7JW/dxUNDodWSlM+LIzypz1ziIzoYUDbN04rA99a3o
Feb  4 13:02:54 router check_reload_status[374]: Syncing firewall
Feb  4 13:02:54 router php-fpm[80083]: /pkg_mgr_install.php: Beginning configuration backup to https://acb.netgate.com/save
Feb  4 13:02:57 router php-fpm[80083]: /pkg_mgr_install.php: End of configuration backup to https://acb.netgate.com/save (success).
Feb  4 13:03:07 router pkg-static[38878]: sudo-1.9.7 installed
Feb  4 13:03:07 router php[55709]: /etc/rc.packages: Beginning package installation for sudo .
Feb  4 13:03:07 router check_reload_status[374]: Syncing firewall
Feb  4 13:03:07 router php[55709]: /etc/rc.packages: Beginning configuration backup to https://acb.netgate.com/save
Feb  4 13:03:10 router php[55709]: /etc/rc.packages: End of configuration backup to https://acb.netgate.com/save (success).
Feb  4 13:03:10 router check_reload_status[374]: Syncing firewall
Feb  4 13:03:10 router php[55709]: /etc/rc.packages: Beginning configuration backup to https://acb.netgate.com/save
Feb  4 13:03:13 router php[55709]: /etc/rc.packages: End of configuration backup to https://acb.netgate.com/save (success).
Feb  4 13:03:13 router php[55709]: /etc/rc.packages: Successfully installed package: sudo.
Feb  4 13:03:13 router pkg-static[38878]: pfSense-pkg-sudo-0.3_6 installed
Feb  4 13:03:15 router check_reload_status[374]: Reloading filter
Feb  4 13:03:15 router check_reload_status[374]: Starting packages
Feb  4 13:03:16 router php-fpm[344]: /rc.start_packages: Restarting/Starting all packages.
Feb  4 13:03:20 router sshd[82599]: Received disconnect from 192.168.1.100 port 62887:11: disconnected by user
Feb  4 13:03:20 router sshd[82599]: Disconnected from user rmccullough 192.168.1.100 port 62887
Feb  4 13:03:20 router sshd[93362]: Accepted publickey for rmccullough from 192.168.1.100 port 62917 ssh2: RSA SHA256:P7JW/dxUNDodWSlM+LIzypz1ziIzoYUDbN04rA99a3o
Feb  4 13:03:36 router sudo[20632]: rmccullough : TTY=pts/0 ; PWD=/var/log ; USER=root ; COMMAND=/bin/cat system.log

[RyanM]

dhcp.log since last boot:

Feb  4 11:39:29 router dhclient[6882]: Cannot open or create pidfile: No such file or directory
Feb  4 11:39:43 router dhcpd[56120]: Internet Systems Consortium DHCP Server 4.4.2-P1
Feb  4 11:39:43 router dhcpd[56120]: Copyright 2004-2021 Internet Systems Consortium.
Feb  4 11:39:43 router dhcpd[56120]: All rights reserved.
Feb  4 11:39:43 router dhcpd[56120]: For info, please visit https://www.isc.org/software/dhcp/
Feb  4 11:39:43 router dhcpd[56120]: Config file: /etc/dhcpd.conf
Feb  4 11:39:43 router dhcpd[56120]: Database file: /var/db/dhcpd.leases
Feb  4 11:39:43 router dhcpd[56120]: PID file: /var/run/dhcpd.pid
Feb  4 11:39:43 router dhcpd[56120]: Internet Systems Consortium DHCP Server 4.4.2-P1
Feb  4 11:39:43 router dhcpd[56120]: Copyright 2004-2021 Internet Systems Consortium.
Feb  4 11:39:43 router dhcpd[56120]: All rights reserved.
Feb  4 11:39:43 router dhcpd[56120]: For info, please visit https://www.isc.org/software/dhcp/
Feb  4 11:39:43 router dhcpd[56120]: Wrote 0 class decls to leases file.
Feb  4 11:39:43 router dhcpd[56120]: Wrote 2 leases to leases file.
Feb  4 11:39:43 router dhcpd[56120]: Listening on BPF/igb1/00:e0:67:2a:73:e1/192.168.1.0/24
Feb  4 11:39:43 router dhcpd[56120]: Sending on   BPF/igb1/00:e0:67:2a:73:e1/192.168.1.0/24
Feb  4 11:39:43 router dhcpd[56120]: Sending on   Socket/fallback/fallback-net
Feb  4 11:39:43 router dhcpd[56120]: Server starting service.
Feb  4 11:39:45 router dhcpd[56120]: reuse_lease: lease age 1437 (secs) under 25% threshold, reply with unaltered, existing lease for 192.168.1.100
Feb  4 11:39:45 router dhcpd[56120]: DHCPDISCOVER from c4:34:6b:7b:3c:45 (DESKTOP-C3FT4J9) via igb1
Feb  4 11:39:45 router dhcpd[56120]: DHCPOFFER on 192.168.1.100 to c4:34:6b:7b:3c:45 (DESKTOP-C3FT4J9) via igb1
Feb  4 11:39:45 router dhcpd[56120]: send_packet: Network is down
Feb  4 11:39:45 router dhcpd[56120]: dhcp.c:4164: Failed to send 300 byte long packet over igb1 interface.
Feb  4 11:39:50 router dhcpd[56120]: reuse_lease: lease age 1442 (secs) under 25% threshold, reply with unaltered, existing lease for 192.168.1.100
Feb  4 11:39:50 router dhcpd[56120]: DHCPDISCOVER from c4:34:6b:7b:3c:45 (DESKTOP-C3FT4J9) via igb1
Feb  4 11:39:50 router dhcpd[56120]: DHCPOFFER on 192.168.1.100 to c4:34:6b:7b:3c:45 (DESKTOP-C3FT4J9) via igb1
Feb  4 11:39:50 router dhcpd[56120]: reuse_lease: lease age 1442 (secs) under 25% threshold, reply with unaltered, existing lease for 192.168.1.100
Feb  4 11:39:50 router dhcpd[56120]: DHCPREQUEST for 192.168.1.100 (192.168.1.1) from c4:34:6b:7b:3c:45 (DESKTOP-C3FT4J9) via igb1
Feb  4 11:39:50 router dhcpd[56120]: DHCPACK on 192.168.1.100 to c4:34:6b:7b:3c:45 (DESKTOP-C3FT4J9) via igb1
Feb  4 12:08:50 router dhclient[92418]: Cannot open or create pidfile: No such file or directory
Feb  4 12:08:50 router dhclient[92626]: PREINIT
Feb  4 12:08:50 router dhclient[92418]: DHCPREQUEST on igb0 to 255.255.255.255 port 67
Feb  4 12:08:50 router dhclient[92418]: DHCPACK from 192.168.86.1
Feb  4 12:08:50 router dhclient[93585]: REBOOT
Feb  4 12:08:50 router dhclient[94220]: Starting add_new_address()
Feb  4 12:08:50 router dhclient[94449]: ifconfig igb0 inet 192.168.86.241 netmask 255.255.255.0 broadcast 192.168.86.255
Feb  4 12:08:50 router dhclient[94803]: New IP Address (igb0): 192.168.86.241
Feb  4 12:08:50 router dhclient[94964]: New Subnet Mask (igb0): 255.255.255.0
Feb  4 12:08:50 router dhclient[94994]: New Broadcast Address (igb0): 192.168.86.255
Feb  4 12:08:50 router dhclient[95336]: New Routers (igb0): 192.168.86.1
Feb  4 12:08:50 router dhclient[95413]: Adding new routes to interface: igb0
Feb  4 12:08:50 router dhclient[95557]: Creating resolv.conf
Feb  4 12:08:50 router dhclient[92418]: bound to 192.168.86.241 -- renewal in 43200 seconds.
Feb  4 12:11:11 router dhclient[93241]: connection closed
Feb  4 12:11:11 router dhclient[93241]: exiting.
Feb  4 12:11:13 router dhclient[31635]: Cannot open or create pidfile: No such file or directory
Feb  4 12:11:13 router dhclient[32181]: PREINIT
Feb  4 12:11:13 router dhclient[31635]: DHCPREQUEST on igb0 to 255.255.255.255 port 67
Feb  4 12:11:13 router dhclient[31635]: DHCPACK from 192.168.86.1
Feb  4 12:11:13 router dhclient[32933]: REBOOT
Feb  4 12:11:13 router dhclient[33429]: Starting add_new_address()
Feb  4 12:11:13 router dhclient[33433]: ifconfig igb0 inet 192.168.86.241 netmask 255.255.255.0 broadcast 192.168.86.255
Feb  4 12:11:13 router dhclient[33864]: New IP Address (igb0): 192.168.86.241
Feb  4 12:11:13 router dhclient[34070]: New Subnet Mask (igb0): 255.255.255.0
Feb  4 12:11:13 router dhclient[34073]: New Broadcast Address (igb0): 192.168.86.255
Feb  4 12:11:13 router dhclient[34083]: New Routers (igb0): 192.168.86.1
Feb  4 12:11:13 router dhclient[34362]: Adding new routes to interface: igb0
Feb  4 12:11:13 router dhclient[34542]: Creating resolv.conf
Feb  4 12:11:13 router dhclient[31635]: bound to 192.168.86.241 -- renewal in 43200 seconds.
Feb  4 12:11:17 router dhcpd[90751]: Internet Systems Consortium DHCP Server 4.4.2-P1
Feb  4 12:11:17 router dhcpd[90751]: Copyright 2004-2021 Internet Systems Consortium.
Feb  4 12:11:17 router dhcpd[90751]: All rights reserved.
Feb  4 12:11:17 router dhcpd[90751]: For info, please visit https://www.isc.org/software/dhcp/
Feb  4 12:11:17 router dhcpd[90751]: Config file: /etc/dhcpd.conf
Feb  4 12:11:17 router dhcpd[90751]: Database file: /var/db/dhcpd.leases
Feb  4 12:11:17 router dhcpd[90751]: PID file: /var/run/dhcpd.pid
Feb  4 12:11:17 router dhcpd[90751]: Internet Systems Consortium DHCP Server 4.4.2-P1
Feb  4 12:11:17 router dhcpd[90751]: Copyright 2004-2021 Internet Systems Consortium.
Feb  4 12:11:17 router dhcpd[90751]: All rights reserved.
Feb  4 12:11:17 router dhcpd[90751]: For info, please visit https://www.isc.org/software/dhcp/
Feb  4 12:11:17 router dhcpd[90751]: Wrote 0 class decls to leases file.
Feb  4 12:11:17 router dhcpd[90751]: Wrote 2 leases to leases file.
Feb  4 12:11:17 router dhcpd[90751]: Listening on BPF/igb1/00:e0:67:2a:73:e1/192.168.1.0/24
Feb  4 12:11:17 router dhcpd[90751]: Sending on   BPF/igb1/00:e0:67:2a:73:e1/192.168.1.0/24
Feb  4 12:11:17 router dhcpd[90751]: Sending on   Socket/fallback/fallback-net
Feb  4 12:11:17 router dhcpd[90751]: Server starting service.
Feb  4 12:12:05 router dhcpd[90751]: DHCPRELEASE of 192.168.1.100 from c4:34:6b:7b:3c:45 (DESKTOP-C3FT4J9) via igb1 (found)
Feb  4 12:12:07 router dhcpd[90751]: DHCPDISCOVER from c4:34:6b:7b:3c:45 via igb1
Feb  4 12:12:08 router dhcpd[90751]: DHCPOFFER on 192.168.1.100 to c4:34:6b:7b:3c:45 (DESKTOP-C3FT4J9) via igb1
Feb  4 12:12:08 router dhcpd[90751]: DHCPREQUEST for 192.168.1.100 (192.168.1.1) from c4:34:6b:7b:3c:45 (DESKTOP-C3FT4J9) via igb1
Feb  4 12:12:08 router dhcpd[90751]: DHCPACK on 192.168.1.100 to c4:34:6b:7b:3c:45 (DESKTOP-C3FT4J9) via igb1
Feb  4 12:51:17 router dhcpd[90751]: DHCPREQUEST for 192.168.1.100 from c4:34:6b:7b:3c:45 (DESKTOP-C3FT4J9) via igb1
Feb  4 12:51:17 router dhcpd[90751]: DHCPACK on 192.168.1.100 to c4:34:6b:7b:3c:45 (DESKTOP-C3FT4J9) via igb1
Feb  4 12:51:27 router dhcpd[42633]: Internet Systems Consortium DHCP Server 4.4.2-P1
Feb  4 12:51:27 router dhcpd[42633]: Copyright 2004-2021 Internet Systems Consortium.
Feb  4 12:51:27 router dhcpd[42633]: All rights reserved.
Feb  4 12:51:27 router dhcpd[42633]: For info, please visit https://www.isc.org/software/dhcp/
Feb  4 12:51:27 router dhcpd[42633]: Config file: /etc/dhcpd.conf
Feb  4 12:51:27 router dhcpd[42633]: Database file: /var/db/dhcpd.leases
Feb  4 12:51:27 router dhcpd[42633]: PID file: /var/run/dhcpd.pid
Feb  4 12:51:27 router dhcpd[42633]: Internet Systems Consortium DHCP Server 4.4.2-P1
Feb  4 12:51:27 router dhcpd[42633]: Copyright 2004-2021 Internet Systems Consortium.
Feb  4 12:51:27 router dhcpd[42633]: All rights reserved.
Feb  4 12:51:27 router dhcpd[42633]: For info, please visit https://www.isc.org/software/dhcp/
Feb  4 12:51:27 router dhcpd[42633]: Wrote 0 class decls to leases file.
Feb  4 12:51:27 router dhcpd[42633]: Wrote 2 leases to leases file.
Feb  4 12:51:27 router dhcpd[42633]: Listening on BPF/igb1/00:e0:67:2a:73:e1/192.168.1.0/24
Feb  4 12:51:27 router dhcpd[42633]: Sending on   BPF/igb1/00:e0:67:2a:73:e1/192.168.1.0/24
Feb  4 12:51:27 router dhcpd[42633]: Sending on   Socket/fallback/fallback-net
Feb  4 12:51:27 router dhcpd[42633]: Server starting service.
Feb  4 13:01:24 router dhcpd[42633]: reuse_lease: lease age 607 (secs) under 25% threshold, reply with unaltered, existing lease for 192.168.1.100
Feb  4 13:01:24 router dhcpd[42633]: DHCPREQUEST for 192.168.1.100 from c4:34:6b:7b:3c:45 (DESKTOP-C3FT4J9) via igb1
Feb  4 13:01:24 router dhcpd[42633]: DHCPACK on 192.168.1.100 to c4:34:6b:7b:3c:45 (DESKTOP-C3FT4J9) via igb1
Feb  4 13:01:24 router dhcpd[42633]: send_packet: Network is down
Feb  4 13:01:24 router dhcpd[42633]: dhcp.c:4164: Failed to send 300 byte long packet over igb1 interface.
Feb  4 13:01:25 router dhcpd[42633]: reuse_lease: lease age 608 (secs) under 25% threshold, reply with unaltered, existing lease for 192.168.1.100
Feb  4 13:01:25 router dhcpd[42633]: DHCPREQUEST for 192.168.1.100 from c4:34:6b:7b:3c:45 (DESKTOP-C3FT4J9) via igb1
Feb  4 13:01:25 router dhcpd[42633]: DHCPACK on 192.168.1.100 to c4:34:6b:7b:3c:45 (DESKTOP-C3FT4J9) via igb1
Feb  4 13:01:29 router dhcpd[16802]: Internet Systems Consortium DHCP Server 4.4.2-P1
Feb  4 13:01:29 router dhcpd[16802]: Copyright 2004-2021 Internet Systems Consortium.
Feb  4 13:01:29 router dhcpd[16802]: All rights reserved.
Feb  4 13:01:29 router dhcpd[16802]: For info, please visit https://www.isc.org/software/dhcp/
Feb  4 13:01:29 router dhcpd[16802]: Config file: /etc/dhcpd.conf
Feb  4 13:01:29 router dhcpd[16802]: Database file: /var/db/dhcpd.leases
Feb  4 13:01:29 router dhcpd[16802]: PID file: /var/run/dhcpd.pid
Feb  4 13:01:29 router dhcpd[16802]: Internet Systems Consortium DHCP Server 4.4.2-P1
Feb  4 13:01:29 router dhcpd[16802]: Copyright 2004-2021 Internet Systems Consortium.
Feb  4 13:01:29 router dhcpd[16802]: All rights reserved.
Feb  4 13:01:29 router dhcpd[16802]: For info, please visit https://www.isc.org/software/dhcp/
Feb  4 13:01:29 router dhcpd[16802]: Wrote 0 class decls to leases file.
Feb  4 13:01:29 router dhcpd[16802]: Wrote 2 leases to leases file.
Feb  4 13:01:29 router dhcpd[16802]: Listening on BPF/igb1/00:e0:67:2a:73:e1/192.168.1.0/24
Feb  4 13:01:29 router dhcpd[16802]: Sending on   BPF/igb1/00:e0:67:2a:73:e1/192.168.1.0/24
Feb  4 13:01:29 router dhcpd[16802]: Sending on   Socket/fallback/fallback-net
Feb  4 13:01:29 router dhcpd[16802]: Server starting service.

[bingo600]

@ryanm

The below log "smell's a lot like my issue.
Seems like IGB0 (Wan ethernet is not ready) when the DHCP client runs.
And the DHCP client exits ....

***  Boot
Feb  4 11:39:29 router syslogd: kernel boot file is /boot/kernel/kernel
..
..
*** DHCP client exits (Prob because IGB0 is not ready)
Feb  4 11:39:41 router php[392]: rc.bootup: The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf igb0 > /tmp/igb0_output 2> /tmp/igb0_error_output' returned exit code '1', the output was ''
..
..
*** IGBo Becomes ready
Feb  4 11:39:44 router check_reload_status[374]: Linkup starting igb0
Feb  4 11:39:44 router kernel:
Feb  4 11:39:44 router kernel: igb0: link state changed to UP
..
..

******* Here it seems you are loggin in , and "kicking wan DHCP"

Feb  4 11:39:52 router login[14916]: login on ttyv0 as root
Feb  4 12:08:05 router php-fpm[345]: /index.php: Successful login for user 'admin' from: 192.168.1.100 (Local Database)
Feb  4 12:08:11 router sshd[68729]: Accepted publickey for rmccullough from 192.168.1.100 port 55833 ssh2: RSA SHA256:P7JW/dxUNDodWSlM+LIzypz1ziIzoYUDbN04rA99a3o
Feb  4 12:08:50 router check_reload_status[374]: rc.newwanip starting igb0
Feb  4 12:08:52 router php-fpm[80083]: /rc.newwanip: rc.newwanip: Info: starting on igb0.
Feb  4 12:08:52 router php-fpm[80083]: /rc.newwanip: rc.newwanip: on (IP address: 192.168.86.241) (interface: WAN[wan]) (real interface: igb0).
Feb  4 12:08:52 router check_reload_status[374]: Reloading filter
Feb  4 12:11:07 router check_reload_status[374]: Syncing firewall
Feb  4 12:11:07 router php-fpm[345]: /interfaces.php: Beginning configuration backup to https://acb.netgate.com/save
Feb  4 12:11:07 router php-fpm[345]: /interfaces.php: End of configuration backup to https://acb.netgate.com/save (success).
Feb  4 12:11:13 router php-fpm[345]: /interfaces.php: Shutting down Router Advertisment daemon cleanly
Feb  4 12:11:13 router check_reload_status[374]: rc.newwanip starting igb0
Feb  4 12:11:13 router php-fpm[345]: /interfaces.php: Default gateway setting Interface WAN_DHCP Gateway as default.
Feb  4 12:11:13 router php-fpm[345]: /interfaces.php: Gateway, none 'available' for inet6, use the first one configured. ''
Feb  4 12:11:13 router check_reload_status[374]: Restarting ipsec tunnels
Feb  4 12:11:14 router php-fpm[80083]: /rc.newwanip: rc.newwanip: Info: starting on igb0.
Feb  4 12:11:14 router php-fpm[80083]: /rc.newwanip: rc.newwanip: on (IP address: 192.168.86.241) (interface: WAN[wan]) (real interface: igb0).
...
...

My issue was only present when there was a power failure.

Where my ISP router was slower to start than the pfSense , so the Wan interface on the ISP router wasn't ready , when pfSense wanted an ip address.

I "cheated" , and set a static address instead.

/Bingo

[RyanM]

@bingo600 Not sure I can use a static IP for my ISP back home. I could try it here though and see what happens. No power issue in my scenario. I reboot the router and it doesn't pull an IP from my Google WiFi network. Will try plugging directly into the modem, but not sure it will make a difference.

[stephenw10]

How exactly is it connected? Just to the main router or via some wifi bridge/extension?

[Patch]

@bingo600 said in WAN does not renew after reboot:

My issue was only present when there was a power failure.
Where my ISP router was slower to start than the pfSense , so the Wan interface on the ISP router wasn't ready , when pfSense wanted an ip address.

Agree
I think the problem is if pfsense can not contact the ISP DHCP on the WAN interface, it assumes it has a lease and never tries to contact the ISP DHCP server again. This leave pfsense in an erroneous state.

The only solution for which involves external user intervention to force a WAN lease negotiation.

[bingo600]

@ryanm said in WAN does not renew after reboot:

@bingo600 Not sure I can use a static IP for my ISP back home. I could try it here though and see what happens. No power issue in my scenario. I reboot the router and it doesn't pull an IP from my Google WiFi network. Will try plugging directly into the modem, but not sure it will make a difference.

As stephen mentions:
Please explain how , ant to what - Your pfSense Wan (IGB0) is connected.

Also .. Can you cheat ?

Do you have a "dummy switch" you could insert between the pfSense wan , and the ISP device ?? (Just those two connections)

Purpose :
To make IGB0 interface "available/UP" at pfSense boot.
If the interface is UP , then the DHCP Client task might not EXIT.
And you might be able to adjust DHCP timing, to fit the possible delay.
But from the log it seems we're talking a few seconds, no adjustment might be needed.

My issue could be solved worked around.
By physically disconnect the WAN PDS , wait a few secs , and connect it again. Would trigger the DHCP Client task once again.

Does that work for you too ?
Please try & report

That was not an acceptable solution for me , but it gave some insight in what happened ...

@stephenw10
Why is the DHCP WAN Client task not looping forever , even if the WAN IF is physically down , that might solve the issue.

Or a "configurable" DHCP WAN Client "Sleep #secs" before executing DHCP Client.

/Bingo

[Patch]

@bingo600 said in WAN does not renew after reboot:

Why is the DHCP WAN Client task not looping forever

Imo that is the only real solution.

Faults upstream can happen at any time and be of any duration. Pfsense should be forever polling to detect the recovered wan interface with out requiring someone physically visit the site and manually force a renegotiation.

Thinking back I have had to manually recover from this in two circumstances

1. Power recovery to nbn (cable to Ethernet modem) simultaneously with power to pfsense router. The modem synching slower than pfsense boot up.

2. Upstream ISP outage. Wan DHCP comes back online but pfsense is no longer polling it.

Both required manual user intervention.

[stephenw10]

@bingo600 said in WAN does not renew after reboot:

Why is the DHCP WAN Client task not looping forever , even if the WAN IF is physically down

That's pretty much what it's supposed to do. It won't run on an interface that is down but should run as soon as it comes up. That's what happens when you replug the WAN.

[Patch]

@stephenw10 said in WAN does not renew after reboot:

That's what happens when you replug the WAN.

From a user perspective, the problem is the interface gets it self in a state where the user needs to unplug then replug in the WAN Ethernet cable.

Perhaps the edge case I'm encountering is the Ethernet line on my modem can be up when the WAN DHCP is not accessible. A situation which if persists results in pfsense establishing a lease on the WAN line without an IPv4 gateway address (supplied by the ISP DHCP). Isolating pfsense from the internet.

In Australia there is effectively two ISP further exacerbating the issue. The link to the exchange is owned and run by NBN, the subsequent link and DHCP is owned by the ISP the user chooses. As a result he cable modem being up is not synonymous with the ISP WAN DHCP being accessible.

[stephenw10]

Mmm, the interesting thing here is that in the vast majority of cases dhcp pulls a lease as expected. If it fails to find a dhcp server it just keeps trying. If you boot without the WAN connected it will pull as lease as soon as it's connected.
So it looks like what's happening here must be some timing issue. For whatever reason the WAN is not linked when rc.bootup tries to initialise it so it fails. But it then becomes linked without triggering a new dhclient process on WAN. I would guess because bootup is still running rc.linkup is not called.

@RyanM When you generated that log was it only pfSense that was rebooted? The upstream router was not? Yet it still hadn't linked by that point?

Steve

[Gertjan]

@ryanm

dhcp.log :

At 11:39:41

Feb  4 11:39:41 router php[392]: rc.bootup: The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf igb0 > /tmp/igb0_output 2> /tmp/igb0_error_output' returned exit code '1', the output was ''

but it fails (probably : WAN (and LAN for that matter) are not ready yet ; no interface 'WAN' bind to. dhclient fails.

edit :
Or something like :
/etc/inc/interfaces.inc : line 40 :

	pfSense_interface_flags($interface, IFF_UP);

this line fires for "WAN" but it takes several (5 ... ) seconds to take effect, to late for dhclient.
edit end.

Or, 5 seconds later, igb0 (WAN) and igb1 (LAN) are coming up :
At 11:39:44 (3 seconds later) :

Feb  4 11:39:44 router check_reload_status[374]: Linkup starting igb0
Feb  4 11:39:44 router kernel:
Feb  4 11:39:44 router kernel: igb0: link state changed to UP
....
Feb  4 11:39:45 router check_reload_status[374]: Linkup starting igb1
Feb  4 11:39:45 router kernel: igb1: link state changed to UP

My theory : dhclient has been fired up just to early. And for the rest of the duration of "rc.bootup" interface LINK events are not acted upon ( ? ).

At Feb 4 11:39:51 (7 seconds later) :

Feb  4 11:39:51 router root[10534]: Bootup complete

Let's give 'dhclient' a second chance, at the end of the main bootup script, as it was just a couple of seconds to early with launching dhclient.
Install this lightweight pfSense package :

The command to copy paste :

/sbin/dhclient -c /var/etc/dhclient_wan.conf igb0 > /tmp/igb0_output 2> /tmp/igb0_error_output

[stephenw10]

Yes, I would expect that to work.

It's interesting that you are hitting this at all though. There is something unusual happening in the link timing,

Steve

[Patch]

@stephenw10 said in WAN does not renew after reboot:

The dhcp and system logs.

Happened again for me so I collected some data just in case it helps identify the problem

Summary

• pfsense 2.5.2-RELEASE (amd64)
• My ISP reports My network terminal device had been online for about 1.5 hours ie since about 18:55
• No internet connection confirmed from about 20:15
• Internet connection restored by pfsense -> Status -> interfaces -> WAN interface -> Release WAN

Prior to fix

After WAN interface -> Release WAN

pfsense -> Status -> System logs -> System -> General (redacted - MyWanIP, MyWanGateway, MyWanBroadcast.255)
Log - System - after Release WAN - Redacted.txt

pfsense -> Status -> System logs -> System -> DHCP (redacted - MyWanIP, MyWanGateway, MyWanBroadcast.255)
Log - DHCP - After Release WAN - Redacted.txt

[Gertjan]

@patch said in WAN does not renew after reboot:

pfsense -> Status -> System logs -> System -> General (redacted - MyWanIP, MyWanGateway, MyWanBroadcast.255)
Log - System - after Release WAN - Redacted.txt
pfsense -> Status -> System logs -> System -> DHCP (redacted - MyWanIP, MyWanGateway, MyWanBroadcast.255)
Log - DHCP - After Release WAN - Redacted.txt

The system log :
In less then 10 minutes your have more then 10 WAN cable disconnect / connect event :

Change that cable (bad cable or bad plugs ?), or change (swap with LAN) the WAN NIC - or use another or new NIC for WAN.

This might also explain why it takes 'ages' to "software activate" the interface, just before the dhcp client is launched. It takes to much time to active.

Feb 8 20:28:36 dhclient 17482 bound to MyWanIP -- renewal in 900 seconds.

The ISP gives you a 900 seconds lease. That means the renewal will take place every 7 and a half minute.
This isn't wrong, it works, but creates a lot of IP re negotiation. IMHO : that's not ok - but you can't do anything about that.
Your are using 4G/5G or Wifi or comparable as a ISP access ?
"normal" DHCP lease duration is more like a day or several days.

[Patch]

@gertjan
I believe there was an upstream fault which was restored about 1.5 hours (I don't know the exact time) before I notices the loss of internet connection and fixed it.

I don't have control of the up stream fault behaviour. However I would like pfsense to restore the connection when the up stream fault is resolved.

So my concern is why did pfsense not try to establish a WAN DHCP connection after 19:11 but instead required me to manually trigger a DHCP "Release WAN" at 20:28

As to why the ISP fault behaviour maybe atypical, I effectively have two ISP (but that's how it is done in Australia)

• User chooses an ISP. ISP determines users WAN IP address and gateway address (so I assume controls the WAN DHCP)

• The physical connection from the ISP to user is provided by NBN (National Broadband Network) including providing the network terminal device on the users premises. In my case a HFC (hybrid fibre cable) connection so the NBN modem converts coax to Ethernet.

• I connect from the Ethernet port on the NBN modem to my pfsense router.

As a result with up stream faults, the network terminal device may recover at a different time the the Wan DHCP server.

So while I can't really exclude a cable or NIC fault with equipment I own, I'm not convinced that is actually the problem here.

• My ISP stats show my NTD has been up since 19:22 (after the time pfsense tried to access the DHCP server). My connection has had 34 flaps (HFC is not a good technical design as faults on the shared cable result in short service outages to all customers sharing that cable, we have had some rain today so probably explaining the high flaps).

• pfsense logs show not attempt to re-establish Wan DHCP for over an hour and stopped near the time the NTD came online again.

• the fault was cleared by manually forcing a "Release Wan" in pfsense (no cables were touched)

But perhaps I'm wrong again.

[Gertjan]

@patch said in WAN does not renew after reboot:

WAN DHCP connection after 19:11

Look at 19:10 : you WAN physical connection went down.
No more need for DHCPclient to stay in memory : the interface (WAN) isn't there any more.

The gateway alarm also start to signal the lost of the WAN :

Feb 8 19:11:00 rc.gateway_alarm 94104 >>> Gateway alarm: WAN_DHCP (Addr:MyWanGateway Alarm:1 RTT:13.200ms RTTsd:1.154ms Loss:33%)

Id did no saw it coming back up untill the end : Feb 8 20:29:37

Normally, when it comes up again, a 'LINK' event is launched.
This starts the dhcpclient (because it's the WAN interface).
On of he actions during the 'LINK' event is : activating the interface. But for some reasons, this takes (to much) time / more then normal. The DHCP clients fails ....
Again : didn't saw this happing in your latest system log. For me, WAN (igb0) never came back after 9:11.

Again : this could be cable/plug issue. Or a NIC issue (both side).
Or the upstream device that loves to take the connection down for whatever reason.