Possible bug: Spoofed WAN MAC plus L2TP service causes WAN interface link flap
-
I'm not entirely sure where this would sit but given the issue is caused by a L2 protocol, thought it might belong here.
I've encountered what might be a bug in a specific, niche setup. If a MAC address is spoofed on the WAN interface, and is used with an L2TP service (such as the Andrews and Arnold one in the UK, the WAN link flaps every 5-10 seconds.
This has been tested on a box which has Intel I226 NICs (igc) AND Intel X710s (ixl). The issue is replicated on both boxes.
Rebooting or rerooting brings everything back up and it works, however the L2TP uptime counter is blank. If I edit ANY interface, it starts link flapping again.
Has anyone else come across this before? If so, is there a resolution? Posting here before on Redmine in case it's not a bug/is known.
System log below from interface assign to present. WAN IP is the 10.224.10.1/24 address - I was testing this on my bench hence is connected to a dedicated, separate VLAN.
Oct 16 11:19:33 reroot 92963 rerooted by root Oct 16 11:52:02 syslogd kernel boot file is /boot/kernel/kernel Oct 16 11:52:02 kernel pflog0: promiscuous mode disabled Oct 16 11:52:02 kernel Trying to mount root from zfs:pfSense/ROOT/default []... Oct 16 11:52:02 kernel CPU: Intel(R) Core(TM) i7-7700 CPU @ 3.60GHz (3599.99-MHz K8-class CPU) Oct 16 11:52:02 kernel Origin="GenuineIntel" Id=0x906e9 Family=0x6 Model=0x9e Stepping=9 Oct 16 11:52:02 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> Oct 16 11:52:02 kernel Features2=0x7ffafbff<SSE3,PCLMULQDQ,DTES64,MON,DS_CPL,VMX,SMX,EST,TM2,SSSE3,SDBG,FMA,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,TSCDLT,AESNI,XSAVE,OSXSAVE,AVX,F16C,RDRAND> Oct 16 11:52:02 kernel AMD Features=0x2c100800<SYSCALL,NX,Page1GB,RDTSCP,LM> Oct 16 11:52:02 kernel AMD Features2=0x121<LAHF,ABM,Prefetch> Oct 16 11:52:02 kernel Structured Extended Features=0x29c6fbf<FSGSBASE,TSCADJ,SGX,BMI1,HLE,AVX2,SMEP,BMI2,ERMS,INVPCID,RTM,NFPUSG,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PROCTRACE> Oct 16 11:52:02 kernel Structured Extended Features3=0xbc002e00<MCUOPT,MD_CLEAR,TSXFA,IBPB,STIBP,L1DFL,ARCH_CAP,SSBD> Oct 16 11:52:02 kernel XSAVE Features=0xf<XSAVEOPT,XSAVEC,XINUSE,XSAVES> Oct 16 11:52:02 kernel IA32_ARCH_CAPS=0xc04<RSBA> Oct 16 11:52:02 kernel VT-x: PAT,HLT,MTF,PAUSE,EPT,UG,VPID Oct 16 11:52:02 kernel TSC: P-state invariant, performance statistics Oct 16 11:52:02 kernel done. Oct 16 11:52:02 ppp 93884 Multi-link PPP daemon for FreeBSD Oct 16 11:52:02 ppp 93884 process 93884 started, version 5.9 Oct 16 11:52:02 ppp 93884 web: web is not running Oct 16 11:52:02 ppp 93884 [opt1] Bundle: Interface ng0 created Oct 16 11:52:02 ppp 93884 [opt1_link0] Link: OPEN event Oct 16 11:52:02 kernel ng0: changing name to 'l2tp0' Oct 16 11:52:02 ppp 93884 [opt1_link0] LCP: Open event Oct 16 11:52:02 ppp 93884 [opt1_link0] LCP: state change Initial --> Starting Oct 16 11:52:02 ppp 93884 [opt1_link0] LCP: LayerStart Oct 16 11:52:02 ppp 93884 L2TP: Initiating control connection 0x90082643310 10.224.10.8 0 <-> 90.155.53.19 1701 Oct 16 11:52:05 check_reload_status 65942 Linkup starting ixl7 Oct 16 11:52:05 kernel ixl7: link state changed to DOWN Oct 16 11:52:06 php-fpm 59748 /rc.linkup: DHCP Client not running on wan (ixl7), reconfiguring dhclient. Oct 16 11:52:06 php-fpm 59748 /rc.linkup: The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf -p /var/run/dhclient.ixl7.pid ixl7 > /tmp/ixl7_output 2> /tmp/ixl7_error_output' returned exit code '1', the output was '' Oct 16 11:52:09 check_reload_status 65942 Linkup starting ixl7 Oct 16 11:52:09 kernel ixl7: Link is up, 1 Gbps Full Duplex, Requested FEC: None, Negotiated FEC: None, Autoneg: True, Flow Control: None Oct 16 11:52:09 kernel ixl7: link state changed to UP Oct 16 11:52:11 check_reload_status 65942 rc.newwanip starting ixl7 Oct 16 11:52:11 php-cgi 71010 rc.bootup: calling interface_dhcpv6_configure. Oct 16 11:52:11 php-cgi 71010 rc.bootup: Accept router advertisements on interface ixl7 Oct 16 11:52:11 php-cgi 71010 rc.bootup: Starting DHCP6 client for interfaces ixl7 in DHCP6 without RA mode Oct 16 11:52:11 php-cgi 71010 rc.bootup: Starting rtsold process on wan(ixl7) Oct 16 11:52:11 ppp 93884 L2TP: Control connection 0x90082643310 10.224.10.8 12490 <-> 90.155.53.19 1701 connected Oct 16 11:52:11 ppp 93884 [opt1_link0] L2TP: Incoming call #5390000 via control connection 0x90082643310 initiated Oct 16 11:52:12 php-fpm 59748 /rc.newwanip: rc.newwanip: Info: starting on ixl7. Oct 16 11:52:12 php-fpm 59748 /rc.newwanip: rc.newwanip: on (IP address: 10.224.10.8) (interface: WAN[wan]) (real interface: ixl7). Oct 16 11:52:12 kernel ixl7: link state changed to DOWN Oct 16 11:52:12 check_reload_status 65942 Linkup starting ixl7 Oct 16 11:52:12 php-fpm 59748 /rc.newwanip: The command '/sbin/ifconfig 'l2tp0' inet6 fe80::b696:91ff:fe2c:e9a0%ixl7 delete' returned exit code '1', the output was 'ifconfig: ioctl (SIOCDIFADDR): Can't assign requested address' Oct 16 11:52:12 ppp 11038 Multi-link PPP daemon for FreeBSD Oct 16 11:52:12 ppp 11038 process 11038 started, version 5.9 Oct 16 11:52:12 ppp 11038 waiting for process 93884 to die... Oct 16 11:52:12 ppp 93884 caught fatal signal TERM Oct 16 11:52:12 ppp 93884 [opt1] IFACE: Close event Oct 16 11:52:12 ppp 93884 [opt1] IPCP: Close event Oct 16 11:52:13 php-fpm 59748 /rc.newwanip: Gateway, none 'available' for inet, use the first one configured. 'WAN_DHCP' Oct 16 11:52:13 php-fpm 59748 /rc.newwanip: Default gateway setting Interface WAN_DHCP Gateway as default. Oct 16 11:52:13 php-fpm 59748 /rc.newwanip: Gateway, none 'available' for inet6, use the first one configured. 'WAN_DHCP6' Oct 16 11:52:14 ppp 11038 waiting for process 93884 to die... Oct 16 11:52:15 ppp 11038 waiting for process 93884 to die... Oct 16 11:52:15 ppp 93884 [opt1] Bundle: Shutdown Oct 16 11:52:15 ppp 93884 [opt1_link0] Link: Shutdown Oct 16 11:52:15 rtsold 19285 <rtsock_input_ifannounce> interface l2tp0 removed Oct 16 11:52:15 ppp 93884 process 93884 terminated Oct 16 11:52:15 rc.gateway_alarm 22429 >>> Gateway alarm: WAN_DHCP (Addr:10.224.10.1 Alarm:1 RTT:0ms RTTsd:0ms Loss:100%) Oct 16 11:52:15 check_reload_status 65942 updating dyndns WAN_DHCP Oct 16 11:52:15 check_reload_status 65942 Restarting IPsec tunnels Oct 16 11:52:15 check_reload_status 65942 Restarting OpenVPN tunnels/interfaces Oct 16 11:52:15 check_reload_status 65942 Reloading filter Oct 16 11:52:15 php-cgi 71010 rc.bootup: Resyncing OpenVPN instances. Oct 16 11:52:15 kernel pflog0: promiscuous mode enabled Oct 16 11:52:15 kernel . Oct 16 11:52:15 kernel done. Oct 16 11:52:15 kernel done. Oct 16 11:52:16 ppp 11038 web: web is not running Oct 16 11:52:16 ppp 11038 [opt1] Bundle: Interface ng0 created Oct 16 11:52:16 rtsold 19285 <rtsock_input_ifannounce> interface ng0 removed Oct 16 11:52:16 kernel ng0: changing name to 'l2tp0' Oct 16 11:52:16 ppp 11038 [opt1_link0] Link: OPEN event Oct 16 11:52:16 ppp 11038 [opt1_link0] LCP: Open event Oct 16 11:52:16 ppp 11038 [opt1_link0] LCP: state change Initial --> Starting Oct 16 11:52:16 ppp 11038 [opt1_link0] LCP: LayerStart Oct 16 11:52:16 ppp 11038 L2TP: Initiating control connection 0xc4722a55310 10.224.10.8 0 <-> 90.155.53.19 1701 Oct 16 11:52:17 rc.gateway_alarm 64046 >>> Gateway alarm: WAN_DHCP (Addr:10.224.10.1 Alarm:1 RTT:0ms RTTsd:0ms Loss:100%) Oct 16 11:52:17 check_reload_status 65942 updating dyndns WAN_DHCP Oct 16 11:52:17 check_reload_status 65942 Restarting IPsec tunnels Oct 16 11:52:17 check_reload_status 65942 Restarting OpenVPN tunnels/interfaces Oct 16 11:52:17 check_reload_status 65942 Reloading filter Oct 16 11:52:17 php-cgi 71010 rc.bootup: Gateway, none 'available' for inet, use the first one configured. 'WAN_DHCP' Oct 16 11:52:17 php-cgi 71010 rc.bootup: Gateway, none 'available' for inet6, use the first one configured. 'WAN_DHCP6' Oct 16 11:52:17 kernel ixl7: Link is up, 1 Gbps Full Duplex, Requested FEC: None, Negotiated FEC: None, Autoneg: True, Flow Control: None Oct 16 11:52:17 kernel ixl7: link state changed to UP Oct 16 11:52:17 check_reload_status 65942 Linkup starting ixl7 Oct 16 11:52:17 php-cgi 71010 rc.bootup: Unbound start waiting on dhcp6c. Oct 16 11:52:18 php-cgi 71010 rc.bootup: Unbound start waiting on dhcp6c. Oct 16 11:52:19 php-cgi 71010 rc.bootup: Unbound start waiting on dhcp6c. Oct 16 11:52:20 ppp 11038 L2TP: Control connection 0xc4722a55310 10.224.10.8 29987 <-> 90.155.53.19 1701 connected Oct 16 11:52:20 ppp 11038 [opt1_link0] L2TP: Incoming call #8170000 via control connection 0xc4722a55310 initiated Oct 16 11:52:20 ppp 11038 [opt1_link0] L2TP: Call #8170000 connected Oct 16 11:52:20 ppp 11038 [opt1_link0] Link: UP event Oct 16 11:52:20 ppp 11038 [opt1_link0] LCP: Up event Oct 16 11:52:20 ppp 11038 [opt1_link0] LCP: state change Starting --> Req-Sent Oct 16 11:52:20 ppp 11038 [opt1_link0] LCP: SendConfigReq #1 Oct 16 11:52:20 ppp 11038 [opt1_link0] ACFCOMP Oct 16 11:52:20 ppp 11038 [opt1_link0] PROTOCOMP Oct 16 11:52:20 ppp 11038 [opt1_link0] MRU 1500 Oct 16 11:52:20 ppp 11038 [opt1_link0] MAGICNUM 0x1cb5dcb6 Oct 16 11:52:20 ppp 11038 [opt1_link0] LCP: rec'd Configure Request #0 (Req-Sent) Oct 16 11:52:20 ppp 11038 [opt1_link0] MAGICNUM 0x45da3c13 Oct 16 11:52:20 ppp 11038 [opt1_link0] MRU 1460 Oct 16 11:52:20 ppp 11038 [opt1_link0] AUTHPROTO CHAP MD5 Oct 16 11:52:20 ppp 11038 [opt1_link0] LCP: SendConfigAck #0 Oct 16 11:52:20 ppp 11038 [opt1_link0] MAGICNUM 0x45da3c13 Oct 16 11:52:20 ppp 11038 [opt1_link0] MRU 1460 Oct 16 11:52:20 ppp 11038 [opt1_link0] AUTHPROTO CHAP MD5 Oct 16 11:52:20 ppp 11038 [opt1_link0] LCP: state change Req-Sent --> Ack-Sent Oct 16 11:52:20 ppp 11038 [opt1_link0] LCP: rec'd Configure Ack #1 (Ack-Sent) Oct 16 11:52:20 ppp 11038 [opt1_link0] ACFCOMP Oct 16 11:52:20 ppp 11038 [opt1_link0] PROTOCOMP Oct 16 11:52:20 ppp 11038 [opt1_link0] MRU 1500 Oct 16 11:52:20 ppp 11038 [opt1_link0] MAGICNUM 0x1cb5dcb6 Oct 16 11:52:20 ppp 11038 [opt1_link0] LCP: state change Ack-Sent --> Opened Oct 16 11:52:20 ppp 11038 [opt1_link0] LCP: auth: peer wants CHAP, I want nothing Oct 16 11:52:20 ppp 11038 [opt1_link0] LCP: LayerUp Oct 16 11:52:20 ppp 11038 [opt1_link0] CHAP: rec'd CHALLENGE #0 len: 31 Oct 16 11:52:20 ppp 11038 [opt1_link0] Name: "B.Careless" Oct 16 11:52:20 ppp 11038 [opt1_link0] CHAP: Using authname "(AAISP Username)" Oct 16 11:52:20 ppp 11038 [opt1_link0] CHAP: sending RESPONSE #0 len: 29 Oct 16 11:52:20 ppp 11038 [opt1_link0] CHAP: rec'd SUCCESS #0 len: 20 Oct 16 11:52:20 ppp 11038 [opt1_link0] MESG: IP55560 10000000 Oct 16 11:52:20 ppp 11038 [opt1_link0] LCP: authorization successful Oct 16 11:52:20 ppp 11038 [opt1_link0] Link: Matched action 'bundle "opt1" ""' Oct 16 11:52:20 ppp 11038 [opt1_link0] Link: Join bundle "opt1" Oct 16 11:52:20 ppp 11038 [opt1] Bundle: Status update: up 1 link, total bandwidth 64000 bps Oct 16 11:52:20 ppp 11038 [opt1] IPCP: Open event Oct 16 11:52:20 ppp 11038 [opt1] IPCP: state change Initial --> Starting Oct 16 11:52:20 ppp 11038 [opt1] IPCP: LayerStart Oct 16 11:52:20 ppp 11038 [opt1] IPCP: Up event Oct 16 11:52:20 ppp 11038 [opt1] IPCP: state change Starting --> Req-Sent Oct 16 11:52:20 ppp 11038 [opt1] IPCP: SendConfigReq #1 Oct 16 11:52:20 ppp 11038 [opt1] IPADDR 0.0.0.0 Oct 16 11:52:20 ppp 11038 [opt1] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid Oct 16 11:52:20 ppp 11038 [opt1] PRIDNS 0.0.0.0 Oct 16 11:52:20 ppp 11038 [opt1] SECDNS 0.0.0.0 Oct 16 11:52:20 ppp 11038 [opt1] IPCP: rec'd Configure Request #0 (Req-Sent) Oct 16 11:52:20 ppp 11038 [opt1] IPADDR 81.187.81.187 Oct 16 11:52:20 ppp 11038 [opt1] 81.187.81.187 is OK Oct 16 11:52:20 ppp 11038 [opt1] IPCP: SendConfigAck #0 Oct 16 11:52:20 ppp 11038 [opt1] IPADDR 81.187.81.187 Oct 16 11:52:20 ppp 11038 [opt1] IPCP: state change Req-Sent --> Ack-Sent Oct 16 11:52:20 ppp 11038 [opt1] IPCP: rec'd Configure Reject #1 (Ack-Sent) Oct 16 11:52:20 ppp 11038 [opt1] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid Oct 16 11:52:20 ppp 11038 [opt1] IPCP: SendConfigReq #2 Oct 16 11:52:20 ppp 11038 [opt1] IPADDR 0.0.0.0 Oct 16 11:52:20 ppp 11038 [opt1] PRIDNS 0.0.0.0 Oct 16 11:52:20 ppp 11038 [opt1] SECDNS 0.0.0.0 Oct 16 11:52:20 ppp 11038 [opt1] IPCP: rec'd Configure Nak #2 (Ack-Sent) Oct 16 11:52:20 ppp 11038 [opt1] IPADDR (AAISP Interface WAN IP) Oct 16 11:52:20 ppp 11038 [opt1] (AAISP Interface WAN IP) is OK Oct 16 11:52:20 ppp 11038 [opt1] PRIDNS 217.169.20.20 Oct 16 11:52:20 ppp 11038 [opt1] SECDNS 217.169.20.21 Oct 16 11:52:20 ppp 11038 [opt1] IPCP: SendConfigReq #3 Oct 16 11:52:20 ppp 11038 [opt1] IPADDR (AAISP Interface WAN IP) Oct 16 11:52:20 ppp 11038 [opt1] PRIDNS 217.169.20.20 Oct 16 11:52:20 ppp 11038 [opt1] SECDNS 217.169.20.21 Oct 16 11:52:20 ppp 11038 [opt1] IPCP: rec'd Configure Ack #3 (Ack-Sent) Oct 16 11:52:20 ppp 11038 [opt1] IPADDR (AAISP Interface WAN IP) Oct 16 11:52:20 ppp 11038 [opt1] PRIDNS 217.169.20.20 Oct 16 11:52:20 ppp 11038 [opt1] SECDNS 217.169.20.21 Oct 16 11:52:20 ppp 11038 [opt1] IPCP: state change Ack-Sent --> Opened Oct 16 11:52:20 ppp 11038 [opt1] IPCP: LayerUp Oct 16 11:52:20 ppp 11038 [opt1] (AAISP Interface WAN IP) -> 81.187.81.187 Oct 16 11:52:20 check_reload_status 65942 Rewriting resolv.conf Oct 16 11:52:20 php-cgi 71010 rc.bootup: Unbound start waiting on dhcp6c. Oct 16 11:52:20 rc.gateway_alarm 24095 >>> Gateway alarm: WAN_DHCP (Addr:10.224.10.1 Alarm:1 RTT:2349.492ms RTTsd:1486.364ms Loss:0%) Oct 16 11:52:20 check_reload_status 65942 updating dyndns WAN_DHCP Oct 16 11:52:20 check_reload_status 65942 Restarting IPsec tunnels Oct 16 11:52:20 check_reload_status 65942 Restarting OpenVPN tunnels/interfaces Oct 16 11:52:20 check_reload_status 65942 Reloading filter Oct 16 11:52:21 check_reload_status 65942 rc.newwanip starting l2tp0 Oct 16 11:52:21 ppp 11038 [opt1] IFACE: Up event Oct 16 11:52:21 ppp 11038 [opt1] IFACE: Rename interface ng0 to l2tp0 Oct 16 11:52:21 ppp 11038 [opt1] IFACE: Add description "OPT1" Oct 16 11:52:21 ppp 11038 [opt1_link0] rec'd unexpected protocol IPV6CP, rejecting Oct 16 11:52:21 ppp 11038 [opt1_link0] rec'd unexpected protocol IPV6CP, rejecting Oct 16 11:52:21 php-cgi 71010 rc.bootup: Unbound start waiting on dhcp6c. Oct 16 11:52:22 php-fpm 59748 /rc.newwanip: rc.newwanip: Info: starting on l2tp0. Oct 16 11:52:22 php-fpm 59748 /rc.newwanip: rc.newwanip: on (IP address: (AAISP Interface WAN IP)) (interface: OPT1[opt1]) (real interface: l2tp0). Oct 16 11:52:22 php-cgi 71010 rc.bootup: Unbound start waiting on dhcp6c. Oct 16 11:52:23 php-fpm 59748 /rc.newwanip: Gateway, NONE AVAILABLE Oct 16 11:52:23 php-fpm 59748 /rc.newwanip: Gateway, none 'available' for inet6, use the first one configured. 'WAN_DHCP6' Oct 16 11:52:23 php-fpm 59748 /rc.newwanip: Resyncing OpenVPN instances for interface OPT1. Oct 16 11:52:23 php-fpm 59748 /rc.newwanip: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/wan-traffic.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/wan-traffic.rrd: illegal attempt to update using time 1697457143 when last update time is 1697457331 (minimum one second step)' Oct 16 11:52:23 php-fpm 59748 /rc.newwanip: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/wan-packets.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/wan-packets.rrd: illegal attempt to update using time 1697457143 when last update time is 1697457331 (minimum one second step)' Oct 16 11:52:23 php-fpm 59748 /rc.newwanip: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/lan-traffic.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/lan-traffic.rrd: illegal attempt to update using time 1697457143 when last update time is 1697457331 (minimum one second step)' Oct 16 11:52:23 php-fpm 59748 /rc.newwanip: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/lan-packets.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/lan-packets.rrd: illegal attempt to update using time 1697457143 when last update time is 1697457331 (minimum one second step)' Oct 16 11:52:23 php-fpm 59748 /rc.newwanip: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/opt1-traffic.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/opt1-traffic.rrd: illegal attempt to update using time 1697457143 when last update time is 1697457292 (minimum one second step)' Oct 16 11:52:23 php-fpm 59748 /rc.newwanip: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/opt1-packets.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/opt1-packets.rrd: illegal attempt to update using time 1697457143 when last update time is 1697457292 (minimum one second step)' Oct 16 11:52:23 php-fpm 59748 /rc.newwanip: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/ipsec-traffic.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/ipsec-traffic.rrd: illegal attempt to update using time 1697457143 when last update time is 1697457331 (minimum one second step)' Oct 16 11:52:23 php-fpm 59748 /rc.newwanip: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/ipsec-packets.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/ipsec-packets.rrd: illegal attempt to update using time 1697457143 when last update time is 1697457331 (minimum one second step)' Oct 16 11:52:23 php-fpm 59748 /rc.newwanip: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/system-states.rrd N:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/system-states.rrd: illegal attempt to update using time 1697457143 when last update time is 1697457331 (minimum one second step)' Oct 16 11:52:23 php-fpm 59748 /rc.newwanip: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/system-processor.rrd N:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/system-processor.rrd: illegal attempt to update using time 1697457143 when last update time is 1697457332 (minimum one second step)' Oct 16 11:52:23 php-fpm 59748 /rc.newwanip: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/system-memory.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/system-memory.rrd: illegal attempt to update using time 1697457143 when last update time is 1697457332 (minimum one second step)' Oct 16 11:52:23 php-fpm 59748 /rc.newwanip: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/system-mbuf.rrd N:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/system-mbuf.rrd: illegal attempt to update using time 1697457143 when last update time is 1697457332 (minimum one second step)' Oct 16 11:52:23 php-fpm 59748 /rc.newwanip: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/system-sensors.rrd N:U:U:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/system-sensors.rrd: found extra data on update argument: U:U:U:U:U:U:U:U' Oct 16 11:52:23 php-fpm 59748 /rc.newwanip: Creating rrd update script Oct 16 11:52:23 php-cgi 71010 rc.bootup: Unbound start waiting on dhcp6c. Oct 16 11:52:24 php-cgi 71010 rc.bootup: Unbound start waiting on dhcp6c. Oct 16 11:52:25 php-fpm 59748 /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - (AAISP Interface WAN IP) -> (AAISP Interface WAN IP) - Restarting packages. Oct 16 11:52:25 check_reload_status 65942 Starting packages Oct 16 11:52:26 php-cgi 71010 rc.bootup: Unbound start waiting on dhcp6c. Oct 16 11:52:26 php-fpm 49909 /rc.start_packages: Restarting/Starting all packages. Oct 16 11:52:27 php-cgi 71010 rc.bootup: Unbound start waiting on dhcp6c. Oct 16 11:52:28 php-cgi 71010 rc.bootup: sync unbound done. Oct 16 11:52:28 kernel done. Oct 16 11:52:28 kernel done. Oct 16 11:20:09 kernel done. Oct 16 11:20:09 php-cgi 71010 rc.bootup: NTPD is starting up. Oct 16 11:20:09 kernel done. Oct 16 11:20:10 kernel done. Oct 16 11:20:10 kernel done. Oct 16 11:20:10 check_reload_status 65942 Updating all dyndns Oct 16 11:20:10 php-cgi 71010 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).' Oct 16 11:20:10 kernel .done. Oct 16 11:20:15 php-cgi 71010 rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/wan-traffic.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/wan-traffic.rrd: illegal attempt to update using time 1697455215 when last update time is 1697457331 (minimum one second step)' Oct 16 11:20:15 php-cgi 71010 rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/wan-packets.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/wan-packets.rrd: illegal attempt to update using time 1697455215 when last update time is 1697457331 (minimum one second step)' Oct 16 11:20:15 php-cgi 71010 rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/lan-traffic.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/lan-traffic.rrd: illegal attempt to update using time 1697455215 when last update time is 1697457331 (minimum one second step)' Oct 16 11:20:15 php-cgi 71010 rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/lan-packets.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/lan-packets.rrd: illegal attempt to update using time 1697455215 when last update time is 1697457331 (minimum one second step)' Oct 16 11:20:15 php-cgi 71010 rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/opt1-traffic.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/opt1-traffic.rrd: illegal attempt to update using time 1697455215 when last update time is 1697457292 (minimum one second step)' Oct 16 11:20:15 php-cgi 71010 rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/opt1-packets.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/opt1-packets.rrd: illegal attempt to update using time 1697455215 when last update time is 1697457292 (minimum one second step)' Oct 16 11:20:15 php-cgi 71010 rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/ipsec-traffic.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/ipsec-traffic.rrd: illegal attempt to update using time 1697455215 when last update time is 1697457331 (minimum one second step)' Oct 16 11:20:15 php-cgi 71010 rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/ipsec-packets.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/ipsec-packets.rrd: illegal attempt to update using time 1697455215 when last update time is 1697457331 (minimum one second step)' Oct 16 11:20:15 php-cgi 71010 rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/system-states.rrd N:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/system-states.rrd: illegal attempt to update using time 1697455215 when last update time is 1697457331 (minimum one second step)' Oct 16 11:20:15 php-cgi 71010 rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/system-processor.rrd N:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/system-processor.rrd: illegal attempt to update using time 1697455215 when last update time is 1697457332 (minimum one second step)' Oct 16 11:20:15 php-cgi 71010 rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/system-memory.rrd N:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/system-memory.rrd: illegal attempt to update using time 1697455215 when last update time is 1697457332 (minimum one second step)' Oct 16 11:20:15 php-cgi 71010 rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/system-mbuf.rrd N:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/system-mbuf.rrd: illegal attempt to update using time 1697455215 when last update time is 1697457332 (minimum one second step)' Oct 16 11:20:15 php-cgi 71010 rc.bootup: The command '/usr/bin/nice -n20 /usr/local/bin/rrdtool update /var/db/rrd/system-sensors.rrd N:U:U:U:U:U:U:U:U:U:U' returned exit code '1', the output was 'ERROR: /var/db/rrd/system-sensors.rrd: found extra data on update argument: U:U:U:U:U:U:U:U' Oct 16 11:20:15 php-cgi 71010 rc.bootup: Creating rrd update script Oct 16 11:20:15 kernel done. Oct 16 11:20:15 syslogd exiting on signal 15 Oct 16 11:20:15 syslogd kernel boot file is /boot/kernel/kernel Oct 16 11:20:15 php-fpm 49909 /rc.start_packages: Restarting/Starting all packages. Oct 16 11:20:15 root 6072 Bootup complete Oct 16 11:20:16 login 26911 login on ttyv0 as root Oct 16 11:20:16 sshguard 29679 Now monitoring attacks. Oct 16 11:21:19 php-fpm 49909 /index.php: Successful login for user 'admin' from: 172.16.11.132 (Local Database)
Copyright 2025 Rubicon Communications LLC (Netgate). All rights reserved.