Router Locking Up (maybe due to excessive lan traffic?)
-
@Ximulate said in Router Locking Up (maybe due to excessive lan traffic?):
Firewall Maximum States at default: 401000
I would increase that to 1000000 and see if that helps.
-
@stephenw10 Nothing stands out to me, other than the DCHP category only lists the LAN and IOT_VLAN but not the other VLANs (DHCP server is enabled on the these VLANs.) On the other graphs, there aren't any noticeable "bumps" or "drops"; mostly steady with slight variations.
The network went offline again yesterday, but I wasn't here. I can't seem to find the system logs for that time range. I will try to grab fresh logs the next time this happens & recheck the monitoring graph.
I see in the gateway logs both gateways w high latency about the same time. I'm not sure that the drop out is (always) the ISP or if its the monitoring IP. I've tried using the default. I'm currently using 8.8.8.8 & 149.112.112.11 (Quad9). I've tried others.
Gateway Logs:
Feb 17 22:53:50 dpinger 53300 GW_Primary 8.8.8.8: Clear latency 35721us stddev 16944us loss 0% Feb 17 22:50:00 dpinger 53300 GW_Primary 8.8.8.8: Alarm latency 22209us stddev 1963us loss 43% Feb 17 17:57:19 dpinger 53300 GW_Primary 8.8.8.8: Clear latency 32731us stddev 40305us loss 0% Feb 17 17:56:58 dpinger 53300 GW_Primary 8.8.8.8: Alarm latency 398332us stddev 1181964us loss 4% Feb 17 17:56:14 dpinger 53300 GW_Primary 8.8.8.8: Alarm latency 2573290us stddev 2060988us loss 25% Feb 17 17:56:09 dpinger 53300 GW_Primary 8.8.8.8: sendto error: 65 Feb 17 17:56:09 dpinger 53300 GW_Primary 8.8.8.8: Alarm latency 0us stddev 0us loss 100% Feb 17 17:56:06 dpinger 53300 GW_Primary 8.8.8.8: sendto error: 50 Feb 17 17:56:04 dpinger 54007 send_interval 2500ms loss_interval 5000ms time_period 60000ms report_interval 0ms data_len 1 alert_interval 5000ms latency_alarm 350ms loss_alarm 15% alarm_hold 50000ms dest_addr 149.112.112.11 bind_addr 48.AA.BB.CC identifier "GW_Cellular " Feb 17 17:56:04 dpinger 53300 GW_Primary 8.8.8.8: sendto error: 50 Feb 17 17:56:04 dpinger 53300 send_interval 2500ms loss_interval 2500ms time_period 60000ms report_interval 0ms data_len 1 alert_interval 5000ms latency_alarm 850ms loss_alarm 35% alarm_hold 50000ms dest_addr 8.8.8.8 bind_addr 38.XX.XX.Y identifier "GW_Primary " Feb 17 17:56:04 dpinger 94618 exiting on signal 15 Feb 17 17:56:03 dpinger 94969 exiting on signal 15 Feb 17 17:56:01 dpinger 94618 GW_Primary 8.8.8.8: sendto error: 50 Feb 17 17:55:59 dpinger 94969 GW_Cellular 149.112.112.11: Alarm latency 456753us stddev 391604us loss 0% Feb 17 17:55:59 dpinger 94618 GW_Primary 8.8.8.8: sendto error: 50 Feb 17 17:55:59 dpinger 94618 GW_Primary 8.8.8.8: Alarm latency 0us stddev 0us loss 100% Feb 17 17:55:56 dpinger 94618 GW_Primary 8.8.8.8: sendto error: 50 Feb 17 17:55:54 dpinger 94969 send_interval 2500ms loss_interval 5000ms time_period 60000ms report_interval 0ms data_len 1 alert_interval 5000ms latency_alarm 350ms loss_alarm 15% alarm_hold 50000ms dest_addr 149.112.112.11 bind_addr 48.AA.BB.C C identifier "GW_Cellular " Feb 17 17:55:54 dpinger 94618 GW_Primary 8.8.8.8: sendto error: 50 Feb 17 17:55:54 dpinger 94618 send_interval 2500ms loss_interval 2500ms time_period 60000ms report_interval 0ms data_len 1 alert_interval 5000ms latency_alarm 850ms loss_alarm 35% alarm_hold 50000ms dest_addr 8.8.8.8 bind_addr 38.XX.XX.Y identifier "GW_Primary " Feb 17 17:00:35 dpinger 65140 GW_Primary 8.8.8.8: Alarm latency 30353us stddev 8826us loss 39% Feb 17 17:00:22 dpinger 65677 GW_Cellular 149.112.112.11: Alarm latency 43422us stddev 12471us loss 18%
-
@NollipfSense Done
-
I've had 2 single-core-lockup hangs (i.e. VM CPU goes to 25% and sticks there on a 4-core host) that I know of since upgrading to 2.7.2 from 2.6.1.
It's not possible to SSH or portal into the machine during such an event; I have to reset it and then things start working again.
What logs could I collect to try to catch the culprit next time? (Are they built in?)
-
If you can connect to the console then run:
top -HaSP
and see what is using that core. -
@stephenw10 Unfortunately console is also nonresponsive, it's a whole-system lockup. I'm hoping I can enable some sort of continuous/circular log to capture state, but there's every chance it'd get wiped out as well.
-
Logging the serial console output can show something in that situation if it's an option.
Try running
ctl+t
at the console. That can respond when nothing else does. -
For what its worth, I have not had any lock-ups since setting the Firewall Maximum States to 1000000.
I did have some type of issue today where pages couldn't be found. Log into the router, all looked fine and then reloaded the pages just fine. Seems like a DNS issue (pfSense is the network DNS server.) As mentioned in a previous thread, my issue may have been multiple issues. Keeping my fingers crossed.
-
Quick update, but I've had at least 2 failures in the last several days. I did grab the logs for those, but I've been snowed under so haven't had time to really look through them. I just got a call from my alarm company complaining about a communications fail. The alarm is actually set-up to use the cellular as its primary, and fail over to my wISP (the opposite of the rest of my network.) Weirdly, the both WAN connections look good & I don't see any issues in the gateway log. The only thing I see in the system log for this is below.
no more Feb 25 16:06:09 php-fpm 401 /index.php: Successful login for user [heres when I login to check] Feb 25 16:02:41 php 93682 [pfBlockerNG] No changes to Firewall rules, skipping Filter Reload Feb 25 16:00:01 php 93682 [pfBlockerNG] Starting cron process. Feb 25 12:30:27 php-cgi 99361 rc.update_urltables: /etc/rc.update_urltables: pfB_DNSBLIP_v4 does not need updating. Feb 25 12:30:27 php-cgi 99361 rc.update_urltables: /etc/rc.update_urltables: pfB_ASN_v4 does not need updating. Feb 25 12:30:27 php-cgi 99361 rc.update_urltables: /etc/rc.update_urltables: pfB_PRI5_v4 does not need updating. Feb 25 12:30:27 php-cgi 99361 rc.update_urltables: /etc/rc.update_urltables: pfB_PRI1_v4 does not need updating. Feb 25 12:30:27 php-cgi 99361 rc.update_urltables: /etc/rc.update_urltables: pfB_NAmerica_v4 does not need updating. Feb 25 12:30:27 php-cgi 99361 rc.update_urltables: /etc/rc.update_urltables: Starting URL table alias updates Feb 25 12:30:01 php-cgi 99361 rc.update_urltables: /etc/rc.update_urltables: Sleeping for 26 seconds. Feb 25 12:30:01 php-cgi 99361 rc.update_urltables: /etc/rc.update_urltables: Starting up. Feb 25 12:23:08 check_reload_status 432 Reloading filter Feb 25 12:23:06 check_reload_status 432 Syncing firewall
-
No errors there. Did you see any blocked traffic from the alarm? States from it without replies?
-
I guess I should enable logs for the alarm panel vLAN (Done!)
This morning was interesting. About 8am, the TV would not stream. I was able to log into the router GUI. The primary WAN was down. Based on the logs, it looks like it was down since about 2:20 am. The cellular was up & the alarm was not complaining about its connection. I rebooted the router from the GUI, and things got interesting...
Once the router was up, I was momentary able to log into the GUI. Both WANs were up & the TV was streaming. However, I could not get my android phone online. The phone kept reporting "no internet access" and was using its 5G cell connection. I tried turning off the cell radio, but the phone continued to say "no internet access" and could not get an IP from the LAN.
I then tried to log into the router GUI, but the browser could not find the IP address of the router as if it didn't have an IP address. Took me awhile to get around to it, but ended up power cycling the router about 08:40 am.
Feb 25 02:23:54 router dpinger[5712]: GW_Cellular 8.8.8.8: Alarm latency 52000us stddev 10646us loss 22% Feb 25 02:25:34 router dpinger[5712]: GW_Cellular 8.8.8.8: Clear latency 54922us stddev 5096us loss 0% Feb 25 06:30:36 router dpinger[4790]: GW_Primary 38.123.321.124: Alarm latency 44057us stddev 72469us loss 43% Feb 25 08:03:19 router dpinger[70215]: send_interval 2500ms loss_interval 2500ms time_period 60000ms report_interval 0ms data_len 1 alert_interval 5000ms latency_alarm 850ms loss_alarm 35% alarm_hold 50000ms dest_addr 38.123.321.124 bind_addr 38.123.321.125 identifier "GW_Primary " Feb 25 08:03:19 router dpinger[70215]: GW_Primary 38.123.321.124: sendto error: 50 Feb 25 08:03:19 router dpinger[70706]: send_interval 2500ms loss_interval 5000ms time_period 60000ms report_interval 0ms data_len 1 alert_interval 5000ms latency_alarm 350ms loss_alarm 15% alarm_hold 50000ms dest_addr 8.8.8.8 bind_addr 192.0.0.2 identifier "GW_Cellular " Feb 25 08:03:22 router dpinger[70215]: GW_Primary 38.123.321.124: sendto error: 50 Feb 25 08:03:24 router dpinger[70215]: GW_Primary 38.123.321.124: Alarm latency 0us stddev 0us loss 100% Feb 25 08:03:24 router dpinger[70215]: GW_Primary 38.123.321.124: sendto error: 50 Feb 25 08:03:27 router dpinger[70215]: GW_Primary 38.123.321.124: sendto error: 50 Feb 25 08:03:29 router dpinger[70706]: exiting on signal 15 Feb 25 08:03:29 router dpinger[70215]: exiting on signal 15 Feb 25 08:03:29 router dpinger[16399]: send_interval 2500ms loss_interval 2500ms time_period 60000ms report_interval 0ms data_len 1 alert_interval 5000ms latency_alarm 850ms loss_alarm 35% alarm_hold 50000ms dest_addr 38.123.321.124 bind_addr 38.123.321.125 identifier "GW_Primary " Feb 25 08:03:29 router dpinger[16399]: GW_Primary 38.123.321.124: sendto error: 50 Feb 25 08:03:29 router dpinger[16970]: send_interval 2500ms loss_interval 5000ms time_period 60000ms report_interval 0ms data_len 1 alert_interval 5000ms latency_alarm 350ms loss_alarm 15% alarm_hold 50000ms dest_addr 8.8.8.8 bind_addr 192.0.0.2 identifier "GW_Cellular " Feb 25 08:03:32 router dpinger[16399]: GW_Primary 38.123.321.124: sendto error: 64 Feb 25 08:03:34 router dpinger[16399]: GW_Primary 38.123.321.124: Alarm latency 1273851us stddev 1251379us loss 0% Feb 25 08:04:24 router dpinger[16399]: GW_Primary 38.123.321.124: Clear latency 147203us stddev 525521us loss 0% Feb 25 08:15:41 router dpinger[16970]: GW_Cellular 8.8.8.8: Alarm latency 77525us stddev 11889us loss 22% *** Power Cycled*** Feb 25 08:40:52 router dpinger[86619]: send_interval 2500ms loss_interval 2500ms time_period 60000ms report_interval 0ms data_len 1 alert_interval 5000ms latency_alarm 850ms loss_alarm 35% alarm_hold 50000ms dest_addr 38.123.321.124 bind_addr 38.123.321.125 identifier "GW_Primary " Feb 25 08:40:52 router dpinger[86619]: GW_Primary 38.123.321.124: sendto error: 50 Feb 25 08:40:52 router dpinger[87080]: send_interval 2500ms loss_interval 5000ms time_period 60000ms report_interval 0ms data_len 1 alert_interval 5000ms latency_alarm 350ms loss_alarm 15% alarm_hold 50000ms dest_addr 8.8.8.8 bind_addr 192.0.0.2 identifier "GW_Cellular " Feb 25 08:40:55 router dpinger[86619]: GW_Primary 38.123.321.124: sendto error: 50 Feb 25 08:40:57 router dpinger[86619]: GW_Primary 38.123.321.124: Alarm latency 0us stddev 0us loss 100% Feb 25 08:40:57 router dpinger[86619]: GW_Primary 38.123.321.124: sendto error: 50 Feb 25 08:41:00 router dpinger[86619]: GW_Primary 38.123.321.124: sendto error: 50 Feb 25 08:41:02 router dpinger[87080]: exiting on signal 15 Feb 25 08:41:02 router dpinger[86619]: exiting on signal 15 Feb 25 08:41:02 router dpinger[9795]: send_interval 2500ms loss_interval 2500ms time_period 60000ms report_interval 0ms data_len 1 alert_interval 5000ms latency_alarm 850ms loss_alarm 35% alarm_hold 50000ms dest_addr 38.123.321.124 bind_addr 38.123.321.125 identifier "GW_Primary " Feb 25 08:41:02 router dpinger[9795]: GW_Primary 38.123.321.124: sendto error: 50 Feb 25 08:41:02 router dpinger[10415]: send_interval 2500ms loss_interval 5000ms time_period 60000ms report_interval 0ms data_len 1 alert_interval 5000ms latency_alarm 350ms loss_alarm 15% alarm_hold 50000ms dest_addr 8.8.8.8 bind_addr 192.0.0.2 identifier "GW_Cellular " Feb 25 08:41:04 router dpinger[9795]: GW_Primary 38.123.321.124: sendto error: 64 Feb 25 08:41:07 router dpinger[9795]: GW_Primary 38.123.321.124: Alarm latency 1292257us stddev 1253494us loss 0% Feb 25 08:41:56 router dpinger[9795]: GW_Primary 38.123.321.124: Clear latency 126200us stddev 528078us loss 0%
-
Feb 25 02:25:36 router php-fpm[401]: /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Feb 25 02:25:36 router php-fpm[401]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed IP addresses. Reloading endpoints that may use GW_Cellular. Feb 25 06:30:36 router rc.gateway_alarm[34968]: >>> Gateway alarm: GW_Primary (Addr:38.123.321.124 Alarm:1 RTT:44.057ms RTTsd:72.469ms Loss:43%) Feb 25 06:30:36 router check_reload_status[432]: updating dyndns GW_Primary Feb 25 06:30:36 router check_reload_status[432]: Restarting IPsec tunnels Feb 25 06:30:36 router check_reload_status[432]: Restarting OpenVPN tunnels/interfaces Feb 25 06:30:36 router check_reload_status[432]: Reloading filter Feb 25 06:30:38 router php-fpm[45361]: /rc.openvpn: MONITOR: GW_Primary has packet loss, omitting from routing group GWG_Failover Feb 25 06:30:38 router php-fpm[45361]: 38.123.321.124|38.123.321.125|GW_Primary|46.86ms|74.748ms|47%|down|highloss Feb 25 06:30:38 router php-fpm[45361]: /rc.openvpn: Gateway, switch to: GW_Cellular Feb 25 06:30:38 router php-fpm[45361]: /rc.openvpn: Default gateway setting Gateway for Cellular Modem as default. Feb 25 06:30:38 router php-fpm[400]: /rc.dyndns.update: Gateway, switch to: GW_Cellular Feb 25 06:30:38 router php-fpm[45361]: /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Feb 25 06:30:38 router php-fpm[45361]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed IP addresses. Reloading endpoints that may use GW_Primary. Feb 25 06:30:39 router php-fpm[400]: /rc.dyndns.update: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry. Feb 25 08:00:01 router php[8815]: [pfBlockerNG] Starting cron process. Feb 25 08:00:22 router php-fpm[401]: /index.php: Successful login for user 'user123' from: 10.101.11.204 (Local Database) Feb 25 08:01:08 router php-fpm[5542]: /diag_reboot.php: Stopping all packages. Feb 25 08:01:08 router lighttpd_pfb[68202]: [pfBlockerNG] DNSBL Webserver stopped Feb 25 08:01:08 router tail_pfb[70585]: [pfBlockerNG] Firewall Filter Service stopped Feb 25 08:01:08 router php_pfb[71442]: [pfBlockerNG] filterlog daemon stopped Feb 25 08:01:10 router reboot[76235]: rebooted by root Feb 25 08:01:11 router syslogd: exiting on signal 15 Feb 25 08:03:10 router syslogd: kernel boot file is /boot/kernel/kernel Feb 25 08:03:10 router kernel: ---<<BOOT>>--- Feb 25 08:03:10 router kernel: Copyright (c) 1992-2023 The FreeBSD Project. Feb 25 08:03:10 router kernel: Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994 Feb 25 08:03:10 router kernel: The Regents of the University of California. All rights reserved. Feb 25 08:03:10 router kernel: FreeBSD is a registered trademark of The FreeBSD Foundation. Feb 25 08:03:10 router kernel: FreeBSD 14.0-CURRENT amd64 1400094 #1 RELENG_2_7_2-n255948-8d2b56da39c: Wed Dec 6 20:45:47 UTC 2023 Feb 25 08:03:10 router kernel: root@freebsd:/var/jenkins/workspace/pfSense-CE-snapshots-2_7_2-main/obj/amd64/StdASW5b/var/jenkins/workspace/pfSense-CE-snapshots-2_7_2-main/sources/FreeBSD-src-RELENG_2_7_2/amd64.amd64/sys/pfSense amd64 Feb 25 08:03:10 router kernel: FreeBSD clang version 16.0.6 (https://github.com/llvm/llvm-project.git llvmorg-16.0.6-0-g7cbf1a259152) Feb 25 08:03:10 router kernel: VT(vga): resolution 640x480 Feb 25 08:03:10 router kernel: CPU: AMD GX-412TC SOC (998.14-MHz K8-class CPU) Feb 25 08:03:10 router kernel: Origin="AuthenticAMD" Id=0x730f01 Family=0x16 Model=0x30 Stepping=1 Feb 25 08:03:10 router kernel: Features=0x178bfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CLFLUSH,MMX,FXSR,SSE,SSE2,HTT> Feb 25 08:03:10 router kernel: Features2=0x3ed8220b<SSE3,PCLMULQDQ,MON,SSSE3,CX16,SSE4.1,SSE4.2,MOVBE,POPCNT,AESNI,XSAVE,OSXSAVE,AVX,F16C> Feb 25 08:03:10 router kernel: AMD Features=0x2e500800<SYSCALL,NX,MMX+,FFXSR,Page1GB,RDTSCP,LM> Feb 25 08:03:10 router kernel: AMD Features2=0x1d4037ff<LAHF,CMP,SVM,ExtAPIC,CR8,ABM,SSE4A,MAS,Prefetch,OSVW,IBS,SKINIT,WDT,Topology,PNXC,DBE,PTSC,PL2I> Feb 25 08:03:10 router kernel: Structured Extended Features=0x8<BMI1> Feb 25 08:03:10 router kernel: XSAVE Features=0x1<XSAVEOPT> Feb 25 08:03:10 router kernel: SVM: NP,NRIP,AFlush,DAssist,NAsids=8 Feb 25 08:03:10 router kernel: TSC: P-state invariant, performance statistics Feb 25 08:03:10 router kernel: real memory = 4815060992 (4592 MB) Feb 25 08:03:10 router kernel: avail memory = 4071268352 (3882 MB) Feb 25 08:03:10 router kernel: Event timer "LAPIC" quality 100 Feb 25 08:03:10 router kernel: ACPI APIC Table: <CORE COREBOOT> Feb 25 08:03:10 router kernel: FreeBSD/SMP: Multiprocessor System Detected: 4 CPUs Feb 25 08:03:10 router kernel: FreeBSD/SMP: 1 package(s) x 4 core(s) Feb 25 08:03:10 router kernel: random: unblocking device. Feb 25 08:03:10 router kernel: ioapic1: MADT APIC ID 5 != hw id 0 Feb 25 08:03:10 router kernel: ioapic0 <Version 2.1> irqs 0-23 Feb 25 08:03:10 router kernel: ioapic1 <Version 2.1> irqs 24-55 Feb 25 08:03:10 router kernel: Launching APs: 1 2 3 Feb 25 08:03:10 router kernel: TCP_ratelimit: Is now initialized Feb 25 08:03:10 router kernel: random: entropy device external interface Feb 25 08:03:10 router kernel: wlan: mac acl policy registered Feb 25 08:03:10 router kernel: ipw_bss: You need to read the LICENSE file in /usr/share/doc/legal/intel_ipw.LICENSE. Feb 25 08:03:10 router kernel: ipw_bss: If you agree with the license, set legal.intel_ipw.license_ack=1 in /boot/loader.conf. Feb 25 08:03:10 router kernel: module_register_init: MOD_LOAD (ipw_bss_fw, 0xffffffff807475a0, 0) error 1 Feb 25 08:03:10 router kernel: ipw_ibss: You need to read the LICENSE file in /usr/share/doc/legal/intel_ipw.LICENSE. Feb 25 08:03:10 router kernel: ipw_ibss: If you agree with the license, set legal.intel_ipw.license_ack=1 in /boot/loader.conf. Feb 25 08:03:10 router kernel: module_register_init: MOD_LOAD (ipw_ibss_fw, 0xffffffff80747650, 0) error 1 Feb 25 08:03:10 router kernel: ipw_monitor: You need to read the LICENSE file in /usr/share/doc/legal/intel_ipw.LICENSE. Feb 25 08:03:10 router kernel: ipw_monitor: If you agree with the license, set legal.intel_ipw.license_ack=1 in /boot/loader.conf. Feb 25 08:03:10 router kernel: module_register_init: MOD_LOAD (ipw_monitor_fw, 0xffffffff80747700, 0) error 1 Feb 25 08:03:10 router kernel: iwi_bss: You need to read the LICENSE file in /usr/share/doc/legal/intel_iwi.LICENSE. Feb 25 08:03:10 router kernel: iwi_bss: If you agree with the license, set legal.intel_iwi.license_ack=1 in /boot/loader.conf. Feb 25 08:03:10 router kernel: module_register_init: MOD_LOAD (iwi_bss_fw, 0xffffffff80765180, 0) error 1 Feb 25 08:03:10 router kernel: iwi_ibss: You need to read the LICENSE file in /usr/share/doc/legal/intel_iwi.LICENSE. Feb 25 08:03:10 router kernel: iwi_ibss: If you agree with the license, set legal.intel_iwi.license_ack=1 in /boot/loader.conf. Feb 25 08:03:10 router kernel: module_register_init: MOD_LOAD (iwi_ibss_fw, 0xffffffff80765230, 0) error 1 Feb 25 08:03:10 router kernel: iwi_monitor: You need to read the LICENSE file in /usr/share/doc/legal/intel_iwi.LICENSE. Feb 25 08:03:10 router kernel: iwi_monitor: If you agree with the license, set legal.intel_iwi.license_ack=1 in /boot/loader.conf. Feb 25 08:03:10 router kernel: module_register_init: MOD_LOAD (iwi_monitor_fw, 0xffffffff807652e0, 0) error 1 Feb 25 08:03:10 router kernel: kbd0 at kbdmux0 Feb 25 08:03:10 router kernel: WARNING: Device "spkr" is Giant locked and may be deleted before FreeBSD 14.0. Feb 25 08:03:10 router kernel: netgate0: <Netgate APU> Feb 25 08:03:10 router kernel: vtvga0: <VT VGA driver> Feb 25 08:03:10 router kernel: smbios0: <System Management BIOS> at iomem 0xf4870-0xf488e Feb 25 08:03:10 router kernel: smbios0: Version: 2.7 Feb 25 08:03:10 router kernel: acpi0: <CORE COREBOOT> Feb 25 08:03:10 router kernel: acpi0: Power Button (fixed) Feb 25 08:03:10 router kernel: cpu0: <ACPI CPU> on acpi0 Feb 25 08:03:10 router kernel: atrtc0: <AT realtime clock> port 0x70-0x71 irq 8 on acpi0 Feb 25 08:03:10 router kernel: atrtc0: registered as a time-of-day clock, resolution 1.000000s Feb 25 08:03:10 router kernel: Event timer "RTC" frequency 32768 Hz quality 0 Feb 25 08:03:10 router kernel: attimer0: <AT timer> port 0x40-0x43 irq 0 on acpi0 Feb 25 08:03:10 router kernel: Timecounter "i8254" frequency 1193182 Hz quality 0 Feb 25 08:03:10 router kernel: Event timer "i8254" frequency 1193182 Hz quality 100 Feb 25 08:03:10 router kernel: apei0: <ACPI Platform Error Interface> on acpi0 Feb 25 08:03:10 router kernel: hpet0: <High Precision Event Timer> iomem 0xfed00000-0xfed003ff on acpi0 Feb 25 08:03:10 router kernel: Timecounter "HPET" frequency 14318180 Hz quality 950 Feb 25 08:03:10 router kernel: Timecounter "ACPI-fast" frequency 3579545 Hz quality 900 Feb 25 08:03:10 router kernel: acpi_timer0: <32-bit timer at 3.579545MHz> port 0x818-0x81b on acpi0 Feb 25 08:03:10 router kernel: acpi_button0: <Power Button> on acpi0 Feb 25 08:03:10 router kernel: pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0 Feb 25 08:03:10 router kernel: pci0: <ACPI PCI bus> on pcib0 Feb 25 08:03:10 router kernel: pcib1: <ACPI PCI-PCI bridge> at device 2.2 on pci0 Feb 25 08:03:10 router kernel: pcib1: failed to allocate initial I/O port window: 0x1000-0x1fff Feb 25 08:03:10 router kernel: pci1: <ACPI PCI bus> on pcib1 Feb 25 08:03:10 router kernel: igb0: <Intel(R) I210 Flashless (Copper)> port 0x2000-0x201f mem 0xfe600000-0xfe61ffff,0xfe620000-0xfe623fff at device 0.0 on pci1 Feb 25 08:03:10 router kernel: igb0: NVM V0.6 imgtype5 Feb 25 08:03:10 router kernel: igb0: Using 1024 TX descriptors and 1024 RX descriptors Feb 25 08:03:10 router kernel: igb0: Using 4 RX queues 4 TX queues Feb 25 08:03:10 router kernel: igb0: Using MSI-X interrupts with 5 vectors Feb 25 08:03:10 router kernel: igb0: Ethernet address: 00:0d:b9:45:16:90 Feb 25 08:03:10 router kernel: igb0: netmap queues/slots: TX 4/1024, RX 4/1024 Feb 25 08:03:10 router kernel: pcib2: <ACPI PCI-PCI bridge> at device 2.3 on pci0 Feb 25 08:03:10 router kernel: pcib2: failed to allocate initial I/O port window: 0x2000-0x2fff Feb 25 08:03:10 router kernel: pci2: <ACPI PCI bus> on pcib2 Feb 25 08:03:10 router kernel: igb1: <Intel(R) I210 Flashless (Copper)> port 0x3000-0x301f mem 0xfe700000-0xfe71ffff,0xfe720000-0xfe723fff at device 0.0 on pci2 Feb 25 08:03:10 router kernel: igb1: NVM V0.6 imgtype5 Feb 25 08:03:10 router kernel: igb1: Using 1024 TX descriptors and 1024 RX descriptors Feb 25 08:03:10 router kernel: igb1: Using 4 RX queues 4 TX queues Feb 25 08:03:10 router kernel: igb1: Using MSI-X interrupts with 5 vectors Feb 25 08:03:10 router kernel: igb1: Ethernet address: 00:0d:b9:45:16:91 Feb 25 08:03:10 router kernel: igb1: netmap queues/slots: TX 4/1024, RX 4/1024 Feb 25 08:03:10 router kernel: pcib3: <ACPI PCI-PCI bridge> at device 2.4 on pci0 Feb 25 08:03:10 router kernel: pcib3: failed to allocate initial I/O port window: 0x3000-0x3fff Feb 25 08:03:10 router kernel: pci3: <ACPI PCI bus> on pcib3 Feb 25 08:03:10 router kernel: igb2: <Intel(R) I210 Flashless (Copper)> port 0x5000-0x501f mem 0xfe800000-0xfe81ffff,0xfe820000-0xfe823fff at device 0.0 on pci3 Feb 25 08:03:10 router kernel: igb2: NVM V0.6 imgtype5 Feb 25 08:03:10 router kernel: igb2: Using 1024 TX descriptors and 1024 RX descriptors Feb 25 08:03:10 router kernel: igb2: Using 4 RX queues 4 TX queues Feb 25 08:03:10 router kernel: igb2: Using MSI-X interrupts with 5 vectors Feb 25 08:03:10 router kernel: igb2: Ethernet address: 00:0d:b9:45:16:92 Feb 25 08:03:10 router kernel: igb2: netmap queues/slots: TX 4/1024, RX 4/1024 Feb 25 08:03:10 router kernel: pci0: <encrypt/decrypt> at device 8.0 (no driver attached) Feb 25 08:03:10 router kernel: xhci0: <AMD FCH USB 3.0 controller> mem 0xfeb22000-0xfeb23fff at device 16.0 on pci0 Feb 25 08:03:10 router kernel: xhci0: 32 bytes context size, 64-bit DMA Feb 25 08:03:10 router kernel: usbus0 on xhci0 Feb 25 08:03:10 router kernel: usbus0: 5.0Gbps Super Speed USB v3.0 Feb 25 08:03:10 router kernel: ahci0: <AMD Hudson-2 AHCI SATA controller> port 0x4010-0x4017,0x4020-0x4023,0x4018-0x401f,0x4024-0x4027,0x4000-0x400f mem 0xfeb25000-0xfeb253ff at device 17.0 on pci0 Feb 25 08:03:10 router kernel: ahci0: AHCI v1.30 with 2 6Gbps ports, Port Multiplier supported with FBS Feb 25 08:03:10 router kernel: ahcich0: <AHCI channel> at channel 0 on ahci0 Feb 25 08:03:10 router kernel: ahcich1: <AHCI channel> at channel 1 on ahci0 Feb 25 08:03:10 router kernel: ehci0: <AMD FCH USB 2.0 controller> mem 0xfeb25400-0xfeb254ff at device 19.0 on pci0 Feb 25 08:03:10 router kernel: usbus1: EHCI version 1.0 Feb 25 08:03:10 router kernel: usbus1 on ehci0 Feb 25 08:03:10 router kernel: usbus1: 480Mbps High Speed USB v2.0 Feb 25 08:03:10 router kernel: isab0: <PCI-ISA bridge> at device 20.3 on pci0 Feb 25 08:03:10 router kernel: isa0: <ISA bus> on isab0 Feb 25 08:03:10 router kernel: sdhci_pci0: <Generic SD HCI> mem 0xfeb25500-0xfeb255ff at device 20.7 on pci0 Feb 25 08:03:10 router kernel: sdhci_pci0: 1 slot(s) allocated Feb 25 08:03:10 router kernel: uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0 Feb 25 08:03:10 router kernel: uart0: console (115200,n,8,1) Feb 25 08:03:10 router kernel: orm0: <ISA Option ROM> at iomem 0xef000-0xeffff pnpid ORM0000 on isa0 Feb 25 08:03:10 router kernel: uart1: <16550 or compatible> at port 0x2f8 irq 3 on isa0 Feb 25 08:03:10 router kernel: hwpstate0: <Cool`n'Quiet 2.0> on cpu0 Feb 25 08:03:10 router kernel: Timecounter "TSC" frequency 998128016 Hz quality 1000 Feb 25 08:03:10 router kernel: Timecounters tick every 1.000 msec Feb 25 08:03:10 router kernel: ZFS filesystem version: 5 Feb 25 08:03:10 router kernel: ZFS storage pool version: features support (5000) Feb 25 08:03:10 router kernel: Trying to mount root from zfs:zroot/ROOT/default []... Feb 25 08:03:10 router kernel: ugen0.1: <AMD XHCI root HUB> at usbus0 Feb 25 08:03:10 router kernel: ugen1.1: <AMD EHCI root HUB> at usbus1 Feb 25 08:03:10 router kernel: uhub0 on usbus0 Feb 25 08:03:10 router kernel: uhub0: <AMD XHCI root HUB, class 9/0, rev 3.00/1.00, addr 1> on usbus0 Feb 25 08:03:10 router kernel: uhub1 on usbus1 Feb 25 08:03:10 router kernel: uhub1: <AMD EHCI root HUB, class 9/0, rev 2.00/1.00, addr 1> on usbus1 Feb 25 08:03:10 router kernel: uhub0: 4 ports with 4 removable, self powered Feb 25 08:03:10 router kernel: ugen0.2: <OR1500PFCRT2U CRBA101.3B4> at usbus0 Feb 25 08:03:10 router kernel: uhub1: 2 ports with 2 removable, self powered Feb 25 08:03:10 router kernel: ugen1.2: <vendor 0x0438 product 0x7900> at usbus1 Feb 25 08:03:10 router kernel: uhub2 on uhub1 Feb 25 08:03:10 router kernel: uhub2: <vendor 0x0438 product 0x7900, class 9/0, rev 2.00/0.18, addr 2> on usbus1 Feb 25 08:03:10 router kernel: Root mount waiting for: CAM usbus1 Feb 25 08:03:10 router kernel: uhub2: 4 ports with 4 removable, self powered Feb 25 08:03:10 router kernel: Root mount waiting for: CAM Feb 25 08:03:10 router kernel: Root mount waiting for: CAM Feb 25 08:03:10 router kernel: Root mount waiting for: CAM Feb 25 08:03:10 router kernel: Root mount waiting for: CAM Feb 25 08:03:10 router kernel: Root mount waiting for: CAM Feb 25 08:03:10 router kernel: Root mount waiting for: CAM Feb 25 08:03:10 router kernel: Root mount waiting for: CAM Feb 25 08:03:10 router kernel: ada0 at ahcich0 bus 0 scbus0 target 0 lun 0 Feb 25 08:03:10 router kernel: ada0: <SATA SSD SBFM01.0> ACS-4 ATA SATA 3.x device Feb 25 08:03:10 router kernel: ada0: Serial Number B6B60773070000011017 Feb 25 08:03:10 router kernel: ada0: 600.000MB/s transfers (SATA 3.x, UDMA6, PIO 8192bytes) Feb 25 08:03:10 router kernel: ada0: Command Queueing enabled Feb 25 08:03:10 router kernel: ada0: 15272MB (31277232 512 byte sectors) Feb 25 08:03:10 router kernel: CPU: AMD GX-412TC SOC (998.13-MHz K8-class CPU) Feb 25 08:03:10 router kernel: Origin="AuthenticAMD" Id=0x730f01 Family=0x16 Model=0x30 Stepping=1 Feb 25 08:03:10 router kernel: Features=0x178bfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CLFLUSH,MMX,FXSR,SSE,SSE2,HTT> Feb 25 08:03:10 router kernel: Features2=0x3ed8220b<SSE3,PCLMULQDQ,MON,SSSE3,CX16,SSE4.1,SSE4.2,MOVBE,POPCNT,AESNI,XSAVE,OSXSAVE,AVX,F16C> Feb 25 08:03:10 router kernel: AMD Features=0x2e500800<SYSCALL,NX,MMX+,FFXSR,Page1GB,RDTSCP,LM> Feb 25 08:03:10 router kernel: AMD Features2=0x1d4037ff<LAHF,CMP,SVM,ExtAPIC,CR8,ABM,SSE4A,MAS,Prefetch,OSVW,IBS,SKINIT,WDT,Topology,PNXC,DBE,PTSC,PL2I> Feb 25 08:03:10 router kernel: Structured Extended Features=0x8<BMI1> Feb 25 08:03:10 router kernel: XSAVE Features=0x1<XSAVEOPT> Feb 25 08:03:10 router kernel: SVM: NP,NRIP,AFlush,DAssist,NAsids=8 Feb 25 08:03:10 router kernel: TSC: P-state invariant, performance statistics Feb 25 08:03:10 router kernel: intsmb0: <AMD FCH SMBus Controller> at device 20.0 on pci0 Feb 25 08:03:10 router kernel: smbus0: <System Management Bus> on intsmb0 Feb 25 08:03:10 router kernel: aesni0: <AES-CBC,AES-CCM,AES-GCM,AES-ICM,AES-XTS> Feb 25 08:03:10 router kernel: amdtemp0: <AMD CPU On-Die Thermal Sensors> on hostb5 Feb 25 08:03:10 router kernel: lo0: link state changed to UP Feb 25 08:03:10 router kernel: Feb 25 08:03:10 router kernel: vlan0: changing name to 'igb2.31' Feb 25 08:03:10 router kernel: vlan1: changing name to 'igb2.111' Feb 25 08:03:10 router kernel: vlan2: changing name to 'igb2.251' Feb 25 08:03:10 router kernel: vlan3: changing name to 'igb2.1' Feb 25 08:03:10 router kernel: vlan4: changing name to 'igb2.101' Feb 25 08:03:10 router kernel: vlan5: changing name to 'igb2.11' Feb 25 08:03:10 router kernel: [fib_algo] inet.0 (bsearch4#28) rebuild_fd_flm: switching algo to radix4_lockless Feb 25 08:03:10 router kernel: done. Feb 25 08:03:10 router kernel: done. Feb 25 08:03:14 router check_reload_status[432]: Linkup starting igb2 Feb 25 08:03:14 router kernel: Feb 25 08:03:14 router kernel: igb2: link state changed to UP Feb 25 08:03:14 router kernel: igb2.1: link state changed to UP Feb 25 08:03:14 router kernel: igb2.101: link state changed to UP Feb 25 08:03:14 router kernel: igb2.251: link state changed to UP Feb 25 08:03:14 router kernel: igb2.111: link state changed to UP Feb 25 08:03:14 router kernel: igb2.11: link state changed to UP Feb 25 08:03:14 router kernel: igb2.31: link state changed to UP Feb 25 08:03:14 router check_reload_status[432]: Linkup starting igb2.1 Feb 25 08:03:14 router check_reload_status[432]: Linkup starting igb2.101 Feb 25 08:03:14 router check_reload_status[432]: Linkup starting igb2.251 Feb 25 08:03:14 router check_reload_status[432]: Linkup starting igb2.111 Feb 25 08:03:14 router check_reload_status[432]: Linkup starting igb2.11 Feb 25 08:03:14 router check_reload_status[432]: Linkup starting igb2.31 Feb 25 08:03:15 router check_reload_status[432]: Linkup starting igb1 Feb 25 08:03:15 router kernel: igb1: link state changed to UP Feb 25 08:03:16 router check_reload_status[432]: rc.newwanip starting igb1 Feb 25 08:03:17 router php-fpm[401]: /rc.linkup: Ignoring link event during boot sequence. Feb 25 08:03:17 router php-fpm[400]: /rc.linkup: Ignoring link event during boot sequence. Feb 25 08:03:17 router php-fpm[41043]: /rc.linkup: Ignoring link event during boot sequence. Feb 25 08:03:17 router php-fpm[400]: /rc.linkup: Ignoring link event during boot sequence. Feb 25 08:03:17 router php-fpm[401]: /rc.linkup: Ignoring link event during boot sequence. Feb 25 08:03:17 router php-fpm[41043]: /rc.linkup: Ignoring link event during boot sequence. Feb 25 08:03:17 router php-fpm[400]: /rc.linkup: Ignoring link event during boot sequence. Feb 25 08:03:17 router php-fpm[400]: /rc.newwanip: rc.newwanip: Info: starting on igb1. Feb 25 08:03:17 router php-fpm[400]: /rc.newwanip: rc.newwanip: on (IP address: 192.0.0.2) (interface: WANSEC[opt6]) (real interface: igb1). Feb 25 08:03:19 router check_reload_status[432]: starting sshd Feb 25 08:03:19 router php-cgi[467]: rc.bootup: Resyncing OpenVPN instances. Feb 25 08:03:19 router kernel: Feb 25 08:03:19 router kernel: tun1: changing name to 'ovpns1' Feb 25 08:03:19 router php-cgi[467]: rc.bootup: Gateway, switch to: GW_Primary Feb 25 08:03:19 router php-cgi[467]: rc.bootup: Default gateway setting Gateway for wireless ISP as default. Feb 25 08:03:19 router php-fpm[400]: /rc.newwanip: Removing static route for monitor 8.8.8.8 and adding a new route through 192.0.0.1 Feb 25 08:03:19 router kernel: ovpns1: link state changed to UP Feb 25 08:03:19 router check_reload_status[432]: rc.newwanip starting ovpns1 Feb 25 08:03:20 router kernel: pflog0: promiscuous mode enabled Feb 25 08:03:20 router sshd[88922]: Server listening on :: port 22. Feb 25 08:03:20 router sshd[88922]: Server listening on 0.0.0.0 port 22. Feb 25 08:03:20 router sshguard[89856]: Now monitoring attacks. Feb 25 08:03:20 router php-fpm[401]: /rc.newwanip: rc.newwanip: Info: starting on ovpns1. Feb 25 08:03:20 router php-fpm[401]: /rc.newwanip: rc.newwanip: on (IP address: 10.102.11.1) (interface: []) (real interface: ovpns1). Feb 25 08:03:22 router php-cgi[467]: rc.bootup: Gateway, switch to: GW_Cellular Feb 25 08:03:22 router php-cgi[467]: rc.bootup: Default gateway setting Gateway for Cellular Modem as default. Feb 25 08:03:23 router kernel: . Feb 25 08:03:24 router rc.gateway_alarm[58028]: >>> Gateway alarm: GW_Primary (Addr:38.123.321.124 Alarm:1 RTT:0ms RTTsd:0ms Loss:100%) Feb 25 08:03:24 router check_reload_status[432]: updating dyndns GW_Primary Feb 25 08:03:24 router check_reload_status[432]: Restarting IPsec tunnels Feb 25 08:03:24 router check_reload_status[432]: Restarting OpenVPN tunnels/interfaces Feb 25 08:03:24 router check_reload_status[432]: Reloading filter Feb 25 08:03:26 router kernel: Feb 25 08:03:26 router kernel: load_dn_sched dn_sched FIFO loaded Feb 25 08:03:26 router kernel: load_dn_sched dn_sched QFQ loaded Feb 25 08:03:26 router kernel: load_dn_sched dn_sched RR loaded Feb 25 08:03:26 router kernel: load_dn_sched dn_sched WF2Q+ loaded Feb 25 08:03:26 router kernel: load_dn_sched dn_sched PRIO loaded Feb 25 08:03:26 router kernel: load_dn_sched dn_sched FQ_CODEL loaded Feb 25 08:03:26 router kernel: load_dn_sched dn_sched FQ_PIE loaded Feb 25 08:03:26 router kernel: load_dn_aqm dn_aqm CODEL loaded Feb 25 08:03:26 router kernel: load_dn_aqm dn_aqm PIE loaded Feb 25 08:03:26 router kernel: .. Feb 25 08:03:27 router php-fpm[401]: /rc.dyndns.update: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry. Feb 25 08:03:29 router kernel: . Feb 25 08:03:29 router php-cgi[467]: rc.bootup: GW States: One or more gateways is down, flushing all states: GW_Primary Feb 25 08:03:29 router php-cgi[467]: rc.bootup: Removing static route for monitor 8.8.8.8 and adding a new route through 192.0.0.1 Feb 25 08:03:29 router kernel: done. Feb 25 08:03:29 router kernel: done. Feb 25 08:03:30 router check_reload_status[432]: Linkup starting igb0 Feb 25 08:03:30 router kernel: Feb 25 08:03:30 router kernel: igb0: link state changed to UP Feb 25 08:03:31 router php-fpm[41043]: /rc.linkup: Ignoring link event during boot sequence. Feb 25 08:03:32 router php-cgi[467]: rc.bootup: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Feb 25 08:03:34 router rc.gateway_alarm[9004]: >>> Gateway alarm: GW_Primary (Addr:38.123.321.124 Alarm:1 RTT:1273.851ms RTTsd:1251.379ms Loss:0%) Feb 25 08:03:34 router check_reload_status[432]: updating dyndns GW_Primary Feb 25 08:03:34 router check_reload_status[432]: Restarting IPsec tunnels Feb 25 08:03:34 router check_reload_status[432]: Restarting OpenVPN tunnels/interfaces Feb 25 08:03:34 router check_reload_status[432]: Reloading filter Feb 25 08:03:37 router php-fpm[41043]: /rc.dyndns.update: MONITOR: GW_Primary is available now, adding to routing group GWG_Failover Feb 25 08:03:37 router php-fpm[41043]: 38.123.321.124|38.123.321.125|GW_Primary|641.452ms|1087.613ms|0.0%|online|delay Feb 25 08:03:37 router php-fpm[41043]: /rc.dyndns.update: Gateway, switch to: GW_Primary Feb 25 08:03:37 router php-fpm[41043]: /rc.dyndns.update: Default gateway setting Gateway for wireless ISP as default. Feb 25 08:03:37 router php-cgi[467]: rc.bootup: Gateway, switch to: GW_Primary Feb 25 08:03:37 router php-cgi[467]: rc.bootup: Default gateway setting Gateway for wireless ISP as default. Feb 25 08:03:38 router php-fpm[41043]: /rc.dyndns.update: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry. Feb 25 08:03:41 router php-cgi[467]: rc.bootup: sync unbound done. Feb 25 08:03:41 router kernel: done. Feb 25 08:03:41 router kernel: done. Feb 25 08:03:48 router kernel: done. Feb 25 08:03:48 router php-cgi[467]: rc.bootup: NTPD is starting up. Feb 25 08:03:48 router kernel: done. Feb 25 08:03:50 router kernel: done. Feb 25 08:03:50 router check_reload_status[432]: Updating all dyndns Feb 25 08:03:50 router kernel: done. Feb 25 08:03:51 router kernel: . Feb 25 08:03:53 router php-fpm[400]: /rc.dyndns.update: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry. Feb 25 08:03:55 router kernel: . Feb 25 08:03:55 router kernel: .. Feb 25 08:03:57 router kernel: . Feb 25 08:03:57 router php-cgi[467]: 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 25 08:03:57 router kernel: done. Feb 25 08:04:02 router php-cgi[467]: rc.bootup: Creating rrd update script Feb 25 08:04:02 router kernel: done. Feb 25 08:04:03 router syslogd: exiting on signal 15 Feb 25 08:04:03 router syslogd: kernel boot file is /boot/kernel/kernel Feb 25 08:04:04 router kernel: done. Feb 25 08:04:06 router php-fpm[401]: /rc.start_packages: Restarting/Starting all packages. Feb 25 08:04:09 router lighttpd_pfb[67675]: [pfBlockerNG] DNSBL Webserver stopped Feb 25 08:04:09 router lighttpd_pfb[68949]: [pfBlockerNG] DNSBL Webserver started Feb 25 08:04:10 router php[73788]: [pfBlockerNG] DNSBL parser daemon started Feb 25 08:04:18 router php-fpm[401]: [pfBlockerNG] Starting firewall filter daemon Feb 25 08:04:18 router root[76224]: Bootup complete Feb 25 08:04:18 router tail_pfb[77682]: [pfBlockerNG] Firewall Filter Service stopped Feb 25 08:04:18 router php_pfb[79222]: [pfBlockerNG] filterlog daemon stopped Feb 25 08:04:18 router tail_pfb[79971]: [pfBlockerNG] Firewall Filter Service stopped Feb 25 08:04:18 router php_pfb[81821]: [pfBlockerNG] filterlog daemon stopped Feb 25 08:04:19 router lighttpd_pfb[83391]: [pfBlockerNG] DNSBL Webserver stopped Feb 25 08:04:19 router lighttpd_pfb[87357]: [pfBlockerNG] DNSBL Webserver started Feb 25 08:04:19 router tail_pfb[89074]: [pfBlockerNG] Firewall Filter Service started Feb 25 08:04:19 router tail_pfb[90128]: [pfBlockerNG] Firewall Filter Service started Feb 25 08:04:20 router login[94089]: login on ttyv0 as root Feb 25 08:04:20 router login[95127]: login on ttyu0 as root Feb 25 08:04:20 router sshguard[96889]: Now monitoring attacks. Feb 25 08:04:22 router php_pfb[91330]: [pfBlockerNG] filterlog daemon started Feb 25 08:04:23 router php_pfb[89252]: [pfBlockerNG] filterlog daemon started Feb 25 08:04:23 router php[90773]: [pfBlockerNG] DNSBL parser daemon started Feb 25 08:04:24 router rc.gateway_alarm[19443]: >>> Gateway alarm: GW_Primary (Addr:38.123.321.124 Alarm:0 RTT:147.203ms RTTsd:525.521ms Loss:0%) Feb 25 08:04:24 router check_reload_status[432]: updating dyndns GW_Primary Feb 25 08:04:24 router check_reload_status[432]: Restarting IPsec tunnels Feb 25 08:04:24 router check_reload_status[432]: Restarting OpenVPN tunnels/interfaces Feb 25 08:04:24 router check_reload_status[432]: Reloading filter Feb 25 08:04:26 router php-fpm[401]: /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Feb 25 08:04:26 router php-fpm[401]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed IP addresses. Reloading endpoints that may use GW_Primary. Feb 25 08:04:28 router php-fpm[400]: /rc.dyndns.update: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry. Feb 25 08:09:07 router php-fpm[76179]: /index.php: Successful login for user 'user123' from: 10.101.11.204 (Local Database) Feb 25 08:15:41 router rc.gateway_alarm[72715]: >>> Gateway alarm: GW_Cellular (Addr:8.8.8.8 Alarm:1 RTT:77.525ms RTTsd:11.889ms Loss:22%) Feb 25 08:15:41 router check_reload_status[432]: updating dyndns GW_Cellular Feb 25 08:15:41 router check_reload_status[432]: Restarting IPsec tunnels Feb 25 08:15:41 router check_reload_status[432]: Restarting OpenVPN tunnels/interfaces Feb 25 08:15:41 router check_reload_status[432]: Reloading filter Feb 25 08:15:42 router php-fpm[401]: /rc.openvpn: MONITOR: GW_Cellular has packet loss, omitting from routing group GWG_Failover Feb 25 08:15:42 router php-fpm[401]: 8.8.8.8|192.0.0.2|GW_Cellular|77.525ms|11.889ms|22%|down|highloss Feb 25 08:15:43 router php-fpm[401]: /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was '' Feb 25 08:15:43 router php-fpm[401]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed IP addresses. Reloading endpoints that may use GW_Cellular. Feb 25 08:18:00 router sshguard[96889]: Exiting on signal. Feb 25 08:18:00 router sshguard[39737]: Now monitoring attacks. Feb 25 08:28:00 router sshguard[39737]: Exiting on signal. Feb 25 08:28:00 router sshguard[66470]: Now monitoring attacks. Feb 25 08:33:00 router sshguard[66470]: Exiting on signal. Feb 25 08:33:00 router sshguard[87854]: Now monitoring attacks. Feb 25 08:37:00 router sshguard[87854]: Exiting on signal. Feb 25 08:37:00 router sshguard[67547]: Now monitoring attacks. Feb 25 08:40:42 router syslogd: kernel boot file is /boot/kernel/kernel Feb 25 08:40:42 router kernel: ---<<BOOT>>---
-
DHCP logs:
Feb 25 08:00:57 router dhcpd[16204]: DHCPREQUEST for 10.31.11.236 (10.31.11.1) from 68:27:19:3e:b1:53 via igb2.31 Feb 25 08:00:57 router dhcpd[16204]: DHCPACK on 10.31.11.236 to 68:27:19:3e:b1:53 via igb2.31 Feb 25 08:01:00 router dhcpd[16204]: DHCPREQUEST for 10.111.11.134 from 00:05:cd:5a:43:44 (0005CD5A4344) via igb2.111 Feb 25 08:01:00 router dhcpd[16204]: DHCPACK on 10.111.11.134 to 00:05:cd:5a:43:44 (0005CD5A4344) via igb2.111 Feb 25 08:01:01 router dhcpd[16204]: DHCPDISCOVER from 00:1e:c0:7f:84:8b via igb2.31 Feb 25 08:01:01 router dhcpd[16204]: DHCPOFFER on 10.31.11.241 to 00:1e:c0:7f:84:8b via igb2.31 Feb 25 08:01:01 router dhcpd[16204]: DHCPREQUEST for 10.31.11.241 (10.31.11.1) from 00:1e:c0:7f:84:8b via igb2.31 Feb 25 08:01:01 router dhcpd[16204]: DHCPACK on 10.31.11.241 to 00:1e:c0:7f:84:8b via igb2.31
Rebooted:
Feb 25 08:03:15 router dhclient[31285]: PREINIT Feb 25 08:03:15 router dhclient[20807]: DHCPREQUEST on igb1 to 255.255.255.255 port 67 Feb 25 08:03:15 router dhclient[20807]: DHCPACK from 192.168.225.1 Feb 25 08:03:15 router dhclient[20807]: unknown dhcp option value 0x78 Feb 25 08:03:15 router dhclient[32362]: REBOOT Feb 25 08:03:15 router dhclient[33631]: Starting add_new_address() Feb 25 08:03:15 router dhclient[33858]: ifconfig igb1 inet 192.0.0.2 netmask 255.255.255.224 broadcast 192.0.0.31 Feb 25 08:03:16 router dhclient[34940]: New IP Address (igb1): 192.0.0.2 Feb 25 08:03:16 router dhclient[35854]: New Subnet Mask (igb1): 255.255.255.224 Feb 25 08:03:16 router dhclient[36318]: New Broadcast Address (igb1): 192.0.0.31 Feb 25 08:03:16 router dhclient[36763]: New Routers (igb1): 192.0.0.1 Feb 25 08:03:16 router dhclient[37940]: Adding new routes to interface: igb1 Feb 25 08:03:16 router dhclient[38724]: Creating resolv.conf Feb 25 08:03:16 router dhclient[20807]: bound to 192.0.0.2 -- renewal in 1800 seconds. Feb 25 08:03:50 router dhcpd[23002]: Internet Systems Consortium DHCP Server 4.4.3-P1 Feb 25 08:03:50 router dhcpd[23002]: Copyright 2004-2022 Internet Systems Consortium. Feb 25 08:03:50 router dhcpd[23002]: All rights reserved. Feb 25 08:03:50 router dhcpd[23002]: For info, please visit https://www.isc.org/software/dhcp/ Feb 25 08:03:50 router dhcpd[23002]: Config file: /etc/dhcpd.conf Feb 25 08:03:50 router dhcpd[23002]: Database file: /var/db/dhcpd.leases Feb 25 08:03:50 router dhcpd[23002]: PID file: /var/run/dhcpd.pid Feb 25 08:03:50 router dhcpd[23002]: Internet Systems Consortium DHCP Server 4.4.3-P1 Feb 25 08:03:50 router dhcpd[23002]: Copyright 2004-2022 Internet Systems Consortium. Feb 25 08:03:50 router dhcpd[23002]: All rights reserved. Feb 25 08:03:50 router dhcpd[23002]: For info, please visit https://www.isc.org/software/dhcp/ Feb 25 08:03:50 router dhcpd[23002]: Wrote 0 class decls to leases file. Feb 25 08:03:50 router dhcpd[23002]: Wrote 0 deleted host decls to leases file. Feb 25 08:03:50 router dhcpd[23002]: Wrote 0 new dynamic host decls to leases file. Feb 25 08:03:50 router dhcpd[23002]: Wrote 129 leases to leases file. Feb 25 08:03:50 router dhcpd[23002]: Listening on BPF/igb2.101/00:0d:b9:45:16:92/10.101.11.0/24 Feb 25 08:03:50 router dhcpd[23002]: Sending on BPF/igb2.101/00:0d:b9:45:16:92/10.101.11.0/24 Feb 25 08:03:50 router dhcpd[23002]: Listening on BPF/igb2.251/00:0d:b9:45:16:92/10.251.11.0/24 Feb 25 08:03:50 router dhcpd[23002]: Sending on BPF/igb2.251/00:0d:b9:45:16:92/10.251.11.0/24 Feb 25 08:03:50 router dhcpd[23002]: Listening on BPF/igb2.111/00:0d:b9:45:16:92/10.111.11.0/24 Feb 25 08:03:50 router dhcpd[23002]: Sending on BPF/igb2.111/00:0d:b9:45:16:92/10.111.11.0/24 Feb 25 08:03:50 router dhcpd[23002]: Listening on BPF/igb2.31/00:0d:b9:45:16:92/10.31.11.0/24 Feb 25 08:03:50 router dhcpd[23002]: Sending on BPF/igb2.31/00:0d:b9:45:16:92/10.31.11.0/24 Feb 25 08:03:50 router dhcpd[23002]: Listening on BPF/igb2.11/00:0d:b9:45:16:92/10.11.11.0/24 Feb 25 08:03:50 router dhcpd[23002]: Sending on BPF/igb2.11/00:0d:b9:45:16:92/10.11.11.0/24 Feb 25 08:03:50 router dhcpd[23002]: Listening on BPF/igb2/00:0d:b9:45:16:92/10.0.11.0/24 Feb 25 08:03:50 router dhcpd[23002]: Sending on BPF/igb2/00:0d:b9:45:16:92/10.0.11.0/24 Feb 25 08:03:50 router dhcpd[23002]: Sending on Socket/fallback/fallback-net Feb 25 08:03:50 router dhcpd[23002]: Server starting service. Feb 25 08:03:50 router dhcpd[23002]: reuse_lease: lease age 327 (secs) under 25% threshold, reply with unaltered, existing lease for 10.111.11.139 Feb 25 08:03:50 router dhcpd[23002]: DHCPDISCOVER from a8:b5:7c:27:0b:92 (RokuFamTV) via igb2.111 Feb 25 08:03:50 router dhcpd[23002]: DHCPOFFER on 10.111.11.139 to a8:b5:7c:27:0b:92 (RokuFamTV) via igb2.111 Feb 25 08:03:50 router dhcpd[23002]: reuse_lease: lease age 327 (secs) under 25% threshold, reply with unaltered, existing lease for 10.111.11.139 Feb 25 08:03:50 router dhcpd[23002]: DHCPREQUEST for 10.111.11.139 (10.111.11.1) from a8:b5:7c:27:0b:92 (RokuFamTV) via igb2.111 Feb 25 08:03:50 router dhcpd[23002]: DHCPACK on 10.111.11.139 to a8:b5:7c:27:0b:92 (RokuFamTV) via igb2.111 Feb 25 08:03:50 router dhcpd[23002]: DHCPDISCOVER from b4:fb:e4:28:6f:94 via igb2 Feb 25 08:03:50 router dhcpd[23002]: DHCPOFFER on 10.0.11.31 to b4:fb:e4:28:6f:94 via igb2 Feb 25 08:03:50 router dhcpd[23002]: DHCPREQUEST for 10.0.11.31 (10.0.11.1) from b4:fb:e4:28:6f:94 via igb2 Feb 25 08:03:50 router dhcpd[23002]: DHCPACK on 10.0.11.31 to b4:fb:e4:28:6f:94 via igb2 and lots of this, different devices Feb 25 08:15:00 router dhcpd[23002]: DHCPREQUEST for 10.31.11.186 from f0:b0:40:75:26:62 via igb2.31 Feb 25 08:15:00 router dhcpd[23002]: DHCPACK on 10.31.11.186 to f0:b0:40:75:26:62 via igb2.31 Feb 25 08:15:29 router dhcpd[23002]: DHCPDISCOVER from 40:a9:cf:41:59:77 via igb2.31 Feb 25 08:15:29 router dhcpd[23002]: DHCPOFFER on 10.31.11.52 to 40:a9:cf:41:59:77 via igb2.31 Feb 25 08:15:29 router dhcpd[23002]: DHCPREQUEST for 10.31.11.52 (10.31.11.1) from 40:a9:cf:41:59:77 via igb2.31 Feb 25 08:15:29 router dhcpd[23002]: DHCPACK on 10.31.11.52 to 40:a9:cf:41:59:77 via igb2.31 Feb 25 08:15:53 router dhcpd[23002]: reuse_lease: lease age 1050 (secs) under 25% threshold, reply with unaltered, existing lease for 10.111.11.111 Feb 25 08:15:53 router dhcpd[23002]: DHCPREQUEST for 10.111.11.111 from 9c:29:76:1d:b9:06 (PC-MW) via igb2.111
goes on & on, turned the DHCP logs several times until power cycled
-
@Ximulate said in Router Locking Up (maybe due to excessive lan traffic?):
Feb 25 08:03:15 router dhclient[20807]: DHCPREQUEST on igb1 to 255.255.255.255 port 67
Feb 25 08:03:15 router dhclient[20807]: DHCPACK from 192.168.225.1
Feb 25 08:03:15 router dhclient[20807]: unknown dhcp option value 0x78
Feb 25 08:03:15 router dhclient[32362]: REBOOT
Feb 25 08:03:15 router dhclient[33631]: Starting add_new_address()
Feb 25 08:03:15 router dhclient[33858]: ifconfig igb1 inet 192.0.0.2 netmask 255.255.255.224 broadcast 192.0.0.31
Feb 25 08:03:16 router dhclient[34940]: New IP Address (igb1): 192.0.0.2
Feb 25 08:03:16 router dhclient[35854]: New Subnet Mask (igb1): 255.255.255.224
Feb 25 08:03:16 router dhclient[36318]: New Broadcast Address (igb1): 192.0.0.31
Feb 25 08:03:16 router dhclient[36763]: New Routers (igb1): 192.0.0.1
Feb 25 08:03:16 router dhclient[37940]: Adding new routes to interface: igb1The only potential problem I see there is the two completely different subnets shown there for the igb1 WAN. That implies it may be pulling an IP from a different DHCP server at some point.
-
@stephenw10 OK, I may have just found something.
192.168.255.1 is the new cell modem web interface. I vaguly recall when setting up, I couldn't access the modem's use interface & at some point in the trouble shooting I added a VIP 192.168.255.2 which I guess worked. I removed that VIP just now, & instead of getting the modem user interface I'm getting the wISP AirOS config portal.
I guess I'm going to try to change the default address used by the modem. I'm still not sure where the 192.0.0.X is coming from.
-
So I changed the default IP for the modem's user interface. I still had to add a VIP to the secondary WAN interface to access the modem's interface.
After rebooting, I noticed the gateway for the cell modem is 192.0.0.1 but its now offline.
Edit: After several minutes (say 5), the gateway IP updated to what looks like a proper address & is reporting online. -
Ok so it could be the cell modem serving it's own subnet via DHCP if it loses cell signal. You might have to reject leases from it to prevent that.
192.0.0.1 could be really what the ISP is using even if they probably shouldn't! -
Thanks I added 192.0.0.1 to "Reject leases from" in the interface. For kicks, I decided to reboot the cell modem. Though the Primary WAN was up, connectivity if the network went to pot. Here's the logs, filtered for "192.0"
Feb 26 15:41:12 php-fpm 37729 /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 0.0.0.0 -> 192.0.0.2 - Restarting packages. Feb 26 15:40:37 php-fpm 14962 8.8.8.8|192.0.0.2|GW_Cellular|306.312ms|389.629ms|0.0%|online|delay Feb 26 15:40:26 php-fpm 37729 /rc.newwanip: Removing static route for monitor 8.8.8.8 and adding a new route through 192.0.0.1 Feb 26 15:39:43 php-fpm 401 /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 0.0.0.0 -> 192.0.0.2 - Restarting packages. Feb 26 15:39:41 php-fpm 37729 /rc.newwanip: rc.newwanip: on (IP address: 192.0.0.2) (interface: WANSEC[opt6]) (real interface: igb1). Feb 26 15:39:07 kernel arpresolve: can't allocate llinfo for 192.0.0.1 on igb1 Feb 26 15:38:59 rc.gateway_alarm 72234 >>> Gateway alarm: GW_Cellular (Addr:192.0.0.1 Alarm:down RTT:0ms RTTsd:0ms Loss:100%) Feb 26 15:38:59 php-fpm 401 /rc.newwanip: dpinger: status socket /var/run/dpinger_GW_Cellular~192.0.0.2~8.8.8.8.sock not found Feb 26 15:38:59 php-fpm 37729 /rc.dyndns.update: dpinger: status socket /var/run/dpinger_GW_Cellular~192.0.0.2~8.8.8.8.sock not found Feb 26 15:38:59 php-fpm 36581 /rc.filter_configure_sync: dpinger: status socket /var/run/dpinger_GW_Cellular~192.0.0.2~8.8.8.8.sock not found Feb 26 15:38:58 php-fpm 401 /rc.newwanip: Removing static route for monitor 8.8.8.8 and adding a new route through 192.0.0.1 Feb 26 15:38:19 php-fpm 36581 /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 0.0.0.0 -> 192.0.0.2 - Restarting packages. Feb 26 15:38:16 php-fpm 401 /rc.newwanip: rc.newwanip: on (IP address: 192.0.0.2) (interface: WANSEC[opt6]) (real interface: igb1). Feb 26 15:37:34 php-fpm 36581 /rc.newwanip: The command '/usr/local/bin/dpinger -S -r 0 -i GW_Cellular -B 192.0.0.2 -p /var/run/dpinger_GW_Cellular~192.0.0.2~8.8.8.8.pid -u /var/run/dpinger_GW_Cellular~192.0.0.2~8.8.8.8.sock -C "/etc/rc.gateway_alarm" -d 1 -s 2500 -l 5000 -t 60000 -A 5000 -D 350 -L 15 8.8.8.8 >/dev/null' returned exit code '1', the output was '' Feb 26 15:37:34 rc.gateway_alarm 12798 >>> Gateway alarm: GW_Cellular (Addr:192.0.0.1 Alarm:down RTT:0ms RTTsd:0ms Loss:100%) Feb 26 15:36:50 php-fpm 36581 /rc.newwanip: rc.newwanip: on (IP address: 192.0.0.2) (interface: WANSEC[opt6]) (real interface: igb1). Feb 26 15:36:50 php-fpm 54361 /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 192.168.5.145 -> 192.0.0.2 - Restarting packages. Feb 26 15:36:07 rc.gateway_alarm 92783 >>> Gateway alarm: GW_Cellular (Addr:192.0.0.1 Alarm:down RTT:0ms RTTsd:0ms Loss:100%) Feb 26 15:36:07 php-fpm 54361 /rc.newwanip: dpinger: cannot connect to status socket /var/run/dpinger_GW_Cellular~192.0.0.2~8.8.8.8.sock - No such file or directory (2) Feb 26 15:36:05 php-fpm 54361 /rc.newwanip: Removing static route for monitor 8.8.8.8 and adding a new route through 192.0.0.1 Feb 26 15:35:58 php-fpm 54361 8.8.8.8|192.0.0.2|GW_Cellular|51.916ms|16.283ms|54%|down|highloss Feb 26 15:35:28 php-fpm 54361 /rc.newwanip: rc.newwanip: on (IP address: 192.0.0.2) (interface: WANSEC[opt6]) (real interface: igb1). Feb 26 15:34:45 rc.gateway_alarm 10879 >>> Gateway alarm: GW_Cellular (Addr:192.0.0.1 Alarm:down RTT:0ms RTTsd:0ms Loss:100%) Feb 26 15:34:40 php-fpm 54361 /rc.newwanip: Removing static route for monitor 8.8.8.8 and adding a new route through 192.0.0.1
-
If anything I would expect 192.0.0.X to be the real connection and 192.168.225.1 to be something local. However that isn't the modem subnet it's gui seems to be using.
So if that fails I'd try refusing leases from 192.168.225.1 instead.
-
I reached out to the cellular modem manufacturer, who was helpful. Apparently some of my modem config was wrong, so that now appears to be straighten out. However, I'm continuing to experience issues.
https://wirelessjoint.com/viewtopic.php?t=4191Reviewing the logs from the last two lock-ups, I see the following happening several minutes beforehand. I was not in this morning, but saw my blink cams & several other devices went offline. A few hours later, the alarm monitoring company called to report a com failure (which means the alarm was able to communicate for some time after the issue started.) Also in the logs I've noticed that both gateways report packetloss/offline within a few seconds of each other.
Mar 2 09:43:43 router unbound[12219]: [12219:1] error: ssl handshake failed crypto error:0A000416:SSL routines::sslv3 alert certificate unknown Mar 2 09:43:43 router unbound[12219]: [12219:1] notice: ssl handshake failed 10.111.11.118 port 53295 Mar 2 09:44:22 router unbound[12219]: [12219:3] error: ssl handshake failed crypto error:0A000416:SSL routines::sslv3 alert certificate unknown Mar 2 09:44:22 router unbound[12219]: [12219:3] notice: ssl handshake failed 10.111.11.115 port 62052 Mar 2 09:44:22 router unbound[12219]: [12219:2] error: ssl handshake failed crypto error:0A000416:SSL routines::sslv3 alert certificate unknown Mar 2 09:44:22 router unbound[12219]: [12219:2] notice: ssl handshake failed 10.111.11.115 port 62053 Mar 2 09:45:08 router filterdns[36239]: merge_config: configuration reload Mar 2 09:45:08 router filterdns[36239]: Adding Action: pf table: networkABC host: abc.duckdns.org Mar 2 09:45:08 router filterdns[36239]: Adding Action: pf table: network123 host: 123.duckdns.org [More of the above, then] Mar 2 09:46:08 router filterdns[36239]: failed to resolve host ntp.org will retry later again. Mar 2 09:46:08 router filterdns[36239]: failed to resolve host abc.duckdns.org will retry later again. Mar 2 09:46:08 router filterdns[36239]: failed to resolve host 123.duckdns.org will retry later again.