There were error(s) loading the rules: pfctl: DIOCADDRULENV: Device busy

a.dresner · Jan 7, 2024, 8:10 PM

The entire error read:
Notices
pf_busy

PF was wedged/busy and has been reset. @ 2024-01-07 06:08:55
Filter Reload

There were error(s) loading the rules: pfctl: DIOCADDRULENV: Device busy - The line in question reads [0]: @ 2024-01-07 06:08:56

Pretty frustrating as I had been on site for 4 weeks and the day after I left to another continent, Netgate 6100 running 23.09.01 froze shortly after renewing an expiring certificate and then clearing the notices about that certificate. No other changes had been made to that 6100 in many months. Is this a one off issue or something more concerning?

Thank you

stephenw10 · Jan 8, 2024, 2:58 AM

Hmm, I don't think we've seen anything like that in 23.09.1.
Last thing that was similar was this: https://redmine.pfsense.org/issues/13408
But that was fixed a few versions back.

Anything else in the logs at that time?

Steve

a.dresner · Jan 8, 2024, 4:47 AM

@stephenw10 Be glad to show you the logs.. I forget how to get them when you wanna see beyond the 500 in the GUI, it's a particular URL right?

stephenw10 · Jan 8, 2024, 2:08 PM

You can set the number of lines it shows up to 2000.

You can get the full log files in /var/log. The system.log file or compressed rotated files from it should have it.

a.dresner · Jan 8, 2024, 9:57 PM

@stephenw10 Thanks! Here you go ... some time before and after the error. I don't have any IPSEC or OPENVPN tunnels anymore. only wireguard.

Jan 7 05:38:13	php-fpm	17629	/rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was ''
Jan 7 05:38:13	xinetd	64582	Starting reconfiguration
Jan 7 05:38:13	xinetd	64582	Swapping defaults
Jan 7 05:38:13	xinetd	64582	readjusting service 6969-udp
Jan 7 05:38:13	xinetd	64582	Reconfigured: new=0 old=1 dropped=0 (services)
Jan 7 05:39:23	rc.gateway_alarm	48978	>>> Gateway alarm: WG_VPN_HQ (Addr:10.100.92.1 Alarm:1 RTT:248.908ms RTTsd:35.048ms Loss:22%)
Jan 7 05:39:23	check_reload_status	446	updating dyndns WG_VPN_HQ
Jan 7 05:39:23	check_reload_status	446	Restarting IPsec tunnels
Jan 7 05:39:23	check_reload_status	446	Restarting OpenVPN tunnels/interfaces
Jan 7 05:39:23	check_reload_status	446	Reloading filter
Jan 7 05:39:24	php-fpm	406	/rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was ''
Jan 7 05:39:25	xinetd	64582	Starting reconfiguration
Jan 7 05:39:25	xinetd	64582	Swapping defaults
Jan 7 05:39:25	xinetd	64582	readjusting service 6969-udp
Jan 7 05:39:25	xinetd	64582	Reconfigured: new=0 old=1 dropped=0 (services)
Jan 7 05:41:00	rc.gateway_alarm	76323	>>> Gateway alarm: WG_VPN_HQ (Addr:10.100.92.1 Alarm:0 RTT:236.369ms RTTsd:9.695ms Loss:11%)
Jan 7 05:41:00	check_reload_status	446	updating dyndns WG_VPN_HQ
Jan 7 05:41:00	check_reload_status	446	Restarting IPsec tunnels
Jan 7 05:41:00	check_reload_status	446	Restarting OpenVPN tunnels/interfaces
Jan 7 05:41:00	check_reload_status	446	Reloading filter
Jan 7 05:41:01	php-fpm	88896	/rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was ''
Jan 7 05:41:01	xinetd	64582	Starting reconfiguration
Jan 7 05:41:01	xinetd	64582	Swapping defaults
Jan 7 05:41:01	xinetd	64582	readjusting service 6969-udp
Jan 7 05:41:01	xinetd	64582	Reconfigured: new=0 old=1 dropped=0 (services)
Jan 7 05:57:50	rc.gateway_alarm	60059	>>> Gateway alarm: WG_VPN_HQ (Addr:10.100.92.1 Alarm:1 RTT:250.866ms RTTsd:23.135ms Loss:21%)
Jan 7 05:57:50	check_reload_status	446	updating dyndns WG_VPN_HQ
Jan 7 05:57:50	check_reload_status	446	Restarting IPsec tunnels
Jan 7 05:57:50	check_reload_status	446	Restarting OpenVPN tunnels/interfaces
Jan 7 05:57:50	check_reload_status	446	Reloading filter
Jan 7 05:57:51	php-fpm	17629	/rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was ''
Jan 7 05:57:52	xinetd	64582	Starting reconfiguration
Jan 7 05:57:52	xinetd	64582	Swapping defaults
Jan 7 05:57:52	xinetd	64582	readjusting service 6969-udp
Jan 7 05:57:52	xinetd	64582	Reconfigured: new=0 old=1 dropped=0 (services)
Jan 7 05:59:10	rc.gateway_alarm	84513	>>> Gateway alarm: WG_VPN_HQ (Addr:10.100.92.1 Alarm:0 RTT:238.124ms RTTsd:16.477ms Loss:11%)
Jan 7 05:59:10	check_reload_status	446	updating dyndns WG_VPN_HQ
Jan 7 05:59:10	check_reload_status	446	Restarting IPsec tunnels
Jan 7 05:59:10	check_reload_status	446	Restarting OpenVPN tunnels/interfaces
Jan 7 05:59:10	check_reload_status	446	Reloading filter
Jan 7 05:59:11	php-fpm	406	/rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was ''
Jan 7 05:59:11	xinetd	64582	Starting reconfiguration
Jan 7 05:59:11	xinetd	64582	Swapping defaults
Jan 7 05:59:11	xinetd	64582	readjusting service 6969-udp
Jan 7 05:59:11	xinetd	64582	Reconfigured: new=0 old=1 dropped=0 (services)
Jan 7 06:08:52	rc.gateway_alarm	92876	>>> Gateway alarm: WG_VPN_HQ (Addr:10.100.92.1 Alarm:1 RTT:242.686ms RTTsd:17.076ms Loss:21%)
Jan 7 06:08:52	check_reload_status	446	updating dyndns WG_VPN_HQ
Jan 7 06:08:52	check_reload_status	446	Restarting IPsec tunnels
Jan 7 06:08:52	check_reload_status	446	Restarting OpenVPN tunnels/interfaces
Jan 7 06:08:52	check_reload_status	446	Reloading filter
Jan 7 06:08:53	php-fpm	88896	/rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was ''
Jan 7 06:08:53	xinetd	64582	Starting reconfiguration
Jan 7 06:08:53	xinetd	64582	Swapping defaults
Jan 7 06:08:53	xinetd	64582	readjusting service 6969-udp
Jan 7 06:08:53	xinetd	64582	Reconfigured: new=0 old=1 dropped=0 (services)
Jan 7 06:08:55	php-fpm	91599	/rc.filter_configure_sync: New alert found: PF was wedged/busy and has been reset.
Jan 7 06:08:55	php-fpm	91599	/rc.filter_configure_sync: New alert found: There were error(s) loading the rules: pfctl: DIOCADDRULENV: Device busy - The line in question reads [0]:
Jan 7 06:09:00	sshguard	98299	Exiting on signal.
Jan 7 06:09:00	sshguard	76217	Now monitoring attacks.
Jan 7 06:10:04	rc.gateway_alarm	48087	>>> Gateway alarm: WG_VPN_HQ (Addr:10.100.92.1 Alarm:0 RTT:248.487ms RTTsd:33.009ms Loss:16%)
Jan 7 06:10:04	check_reload_status	446	updating dyndns WG_VPN_HQ
Jan 7 06:10:04	check_reload_status	446	Restarting IPsec tunnels
Jan 7 06:10:04	check_reload_status	446	Restarting OpenVPN tunnels/interfaces
Jan 7 06:10:04	check_reload_status	446	Reloading filter
Jan 7 06:10:06	php-fpm	405	/rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was ''
Jan 7 06:10:06	xinetd	64582	Starting reconfiguration
Jan 7 06:10:06	xinetd	64582	Swapping defaults
Jan 7 06:10:06	xinetd	64582	readjusting service 6969-udp
Jan 7 06:10:06	xinetd	64582	Reconfigured: new=0 old=1 dropped=0 (services)
Jan 7 06:13:00	rc.gateway_alarm	27686	>>> Gateway alarm: WG_VPN_HQ (Addr:10.100.92.1 Alarm:1 RTT:252.683ms RTTsd:37.094ms Loss:21%)
Jan 7 06:13:00	check_reload_status	446	updating dyndns WG_VPN_HQ
Jan 7 06:13:00	check_reload_status	446	Restarting IPsec tunnels
Jan 7 06:13:00	check_reload_status	446	Restarting OpenVPN tunnels/interfaces
Jan 7 06:13:00	check_reload_status	446	Reloading filter
Jan 7 06:13:01	php-fpm	406	/rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was ''
Jan 7 06:13:01	xinetd	64582	Starting reconfiguration
Jan 7 06:13:01	xinetd	64582	Swapping defaults
Jan 7 06:13:01	xinetd	64582	readjusting service 6969-udp
Jan 7 06:13:01	xinetd	64582	Reconfigured: new=0 old=1 dropped=0 (services)
Jan 7 06:14:14	rc.gateway_alarm	87919	>>> Gateway alarm: WG_VPN_HQ (Addr:10.100.92.1 Alarm:0 RTT:235.090ms RTTsd:4.383ms Loss:14%)
Jan 7 06:14:14	check_reload_status	446	updating dyndns WG_VPN_HQ
Jan 7 06:14:14	check_reload_status	446	Restarting IPsec tunnels
Jan 7 06:14:14	check_reload_status	446	Restarting OpenVPN tunnels/interfaces
Jan 7 06:14:14	check_reload_status	446	Reloading filter
Jan 7 06:14:15	php-fpm	88896	/rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.*PROTO.*>'' returned exit code '1', the output was ''
Jan 7 06:14:16	xinetd	64582	Starting reconfiguration

stephenw10 · Jan 9, 2024, 2:16 AM

And you've only seen that one time so far?

a.dresner · Jan 9, 2024, 2:16 AM

@stephenw10 Yes sir, just this single time. With that said, this is my only 6100 (I have 3) that has crashed and was replaced once.

stephenw10 · Jan 9, 2024, 12:38 PM

Hmm, nothing really logged there. I generally don't like to see xinetd running if possible but just one service running there isn't likely to be causing a problem. It's usually a sign that NAT refection with NAT+Proxy is enabled and that is almost never required.
Potentially it was just a timing issue with several processes trying to make changes to pf.

a.dresner · Jan 9, 2024, 10:21 PM

@stephenw10 Thank you, I cleaned up the NAT settings (set to Auto) and removed an old VLAN that I'm not using any longer. However I am still seeing this:
Jan 9 14:35:47 php-fpm 405 /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.PROTO.>'' returned exit code '1', the output was ''

Looking at my other 6100 logs, where I used to also have openvpn, and don't see this.

stephenw10 · Jan 9, 2024, 10:40 PM

Do you have any OpenVPN servers or clients defined at all?

a.dresner · Jan 9, 2024, 10:43 PM

@stephenw10 I have nothing configured under OpenVPN, I moved to Wireguard over a year ago.

stephenw10 · Jan 9, 2024, 10:52 PM

Hmm, maybe you have a manually defined gateway for an OpenVPN interface that no longer exists?

Do you see that error if you run /etc/rc.openvpn manually?

a.dresner · Jan 10, 2024, 5:42 AM

@stephenw10 Thank you sir, I ran /etc/rc.openvpn from a shell and nothing happened at the shell and I don't see anything in the general logs. But this sounds possible since I had a lot of OpenVPN settings at one time.

looking more specifically at the OpenVPN logs:

May 8 07:54:11 openvpn 45396 /sbin/ifconfig ovpns1 10.0.21.1 10.0.21.2 mtu 1500 netmask 255.255.255.0 up
May 8 07:54:11 openvpn 45396 /usr/local/sbin/ovpn-linkup ovpns1 1500 0 10.0.21.1 255.255.255.0 init
May 8 07:54:11 openvpn 45396 UDPv4 link local (bound): [AF_INET]77.154.17.160:1194
May 8 07:54:11 openvpn 45396 UDPv4 link remote: [AF_UNSPEC]
May 8 07:54:11 openvpn 45396 Initialization Sequence Completed
May 8 12:19:07 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]71.6.134.237:44342
May 8 15:12:42 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]185.200.116.82:57514
May 8 21:28:29 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]146.88.240.4:45635
May 8 23:24:32 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]205.210.31.50:53598
May 8 23:44:21 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]139.162.243.169:47215
May 9 01:17:22 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]167.94.138.106:10178
May 9 02:47:54 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]185.200.116.68:49366
May 9 14:34:56 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]89.248.168.36:44273
May 9 15:48:59 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]38.132.109.167:40381
May 9 18:01:54 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]198.235.24.251:52897
May 9 21:24:18 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]146.88.240.4:40052
May 10 03:59:19 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]38.132.109.164:51607
May 10 14:52:23 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]209.159.153.66:36429
May 10 15:07:49 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]185.200.116.86:59315
May 10 18:39:39 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]198.235.24.249:50765
May 10 21:29:04 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]146.88.240.4:46754
May 11 03:13:24 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]38.132.109.169:41486
May 11 15:14:22 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]185.200.116.67:46114
May 11 15:41:48 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]137.220.233.52:42501
May 11 21:31:28 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]146.88.240.4:46937
May 12 00:54:40 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]205.210.31.81:57090
May 12 02:04:50 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]209.159.153.66:36272
May 12 02:23:19 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]94.102.61.34:52550
May 12 02:44:31 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]38.132.109.166:52327
May 12 15:12:15 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]185.200.116.86:56789
May 12 15:56:30 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]199.195.248.205:32960
May 12 21:21:40 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]146.88.240.4:57996
May 12 23:44:22 openvpn 45396 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]205.210.31.226:56088
May 13 02:33:23 openvpn 45396 event_wait : Interrupted system call (fd=-1,code=4)
May 13 02:33:23 openvpn 45396 /usr/local/sbin/ovpn-linkdown ovpns1 1500 0 10.0.21.1 255.255.255.0 init
May 13 02:33:23 openvpn 45396 SIGTERM[hard,] received, process exiting
May 13 02:33:24 openvpn 60028 OpenVPN 2.6_git amd64-portbld-freebsd12.3 [SSL (OpenSSL)] [LZO] [LZ4] [MH/RECVDA] [AEAD] [DCO] built on Jun 4 2022
May 13 02:33:24 openvpn 60028 library versions: OpenSSL 1.1.1n-freebsd 15 Mar 2022, LZO 2.10
May 13 02:33:24 openvpn 60083 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
May 13 02:33:24 openvpn 60083 WARNING: experimental option --capath /var/etc/openvpn/server1/ca
May 13 02:33:24 openvpn 60083 TUN/TAP device ovpns1 exists previously, keep at program end
May 13 02:33:24 openvpn 60083 TUN/TAP device /dev/tun1 opened
May 13 02:33:24 openvpn 60083 /sbin/ifconfig ovpns1 10.0.21.1 10.0.21.2 mtu 1500 netmask 255.255.255.0 up
May 13 02:33:24 openvpn 60083 /usr/local/sbin/ovpn-linkup ovpns1 1500 0 10.0.21.1 255.255.255.0 init
May 13 02:33:24 openvpn 60083 UDPv4 link local (bound): [AF_INET]192.168.100.10:1194
May 13 02:33:24 openvpn 60083 UDPv4 link remote: [AF_UNSPEC]
May 13 02:33:24 openvpn 60083 Initialization Sequence Completed
May 13 02:33:46 openvpn 60083 event_wait : Interrupted system call (fd=-1,code=4)
May 13 02:33:46 openvpn 60083 /usr/local/sbin/ovpn-linkdown ovpns1 1500 0 10.0.21.1 255.255.255.0 init
May 13 02:33:46 openvpn 60083 SIGTERM[hard,] received, process exiting
May 13 02:33:47 openvpn 74832 OpenVPN 2.6_git amd64-portbld-freebsd12.3 [SSL (OpenSSL)] [LZO] [LZ4] [MH/RECVDA] [AEAD] [DCO] built on Jun 4 2022
May 13 02:33:47 openvpn 74832 library versions: OpenSSL 1.1.1n-freebsd 15 Mar 2022, LZO 2.10
May 13 02:33:47 openvpn 74970 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
May 13 02:33:47 openvpn 74970 WARNING: experimental option --capath /var/etc/openvpn/server1/ca
May 13 02:33:47 openvpn 74970 TUN/TAP device ovpns1 exists previously, keep at program end
May 13 02:33:47 openvpn 74970 TUN/TAP device /dev/tun1 opened
May 13 02:33:47 openvpn 74970 /sbin/ifconfig ovpns1 10.0.21.1 10.0.21.2 mtu 1500 netmask 255.255.255.0 up
May 13 02:33:47 openvpn 74970 /usr/local/sbin/ovpn-linkup ovpns1 1500 0 10.0.21.1 255.255.255.0 init
May 13 02:33:47 openvpn 74970 UDPv4 link local (bound): [AF_INET]77.154.17.160:1194
May 13 02:33:47 openvpn 74970 UDPv4 link remote: [AF_UNSPEC]
May 13 02:33:47 openvpn 74970 Initialization Sequence Completed
May 13 02:41:56 openvpn 74970 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]167.94.138.102:46606
May 13 03:21:15 openvpn 74970 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]38.132.109.112:51520
May 13 03:45:41 openvpn 74970 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]167.248.133.137:42977
May 13 15:05:27 openvpn 74970 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]185.200.118.41:58990
May 13 21:25:52 openvpn 74970 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]146.88.240.4:36818
May 13 21:57:47 openvpn 74970 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]205.210.31.163:52243
May 13 23:39:37 openvpn 74970 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]165.154.119.123:49481
May 14 03:42:15 openvpn 74970 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]185.200.118.39:40463
May 14 04:01:04 openvpn 74970 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]167.94.138.96:52973
May 14 08:06:11 openvpn 74970 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]45.83.67.253:19057
May 14 09:18:08 openvpn 74970 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]104.200.25.246:40505
May 14 15:34:44 openvpn 74970 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]185.200.118.48:42141
May 14 15:46:31 openvpn 74970 TLS Error: cannot locate HMAC in incoming packet from [AF_INET]198.235.24.81:54644
May 14 19:57:34 openvpn 74970 event_wait : Interrupted system call (fd=-1,code=4)
May 14 19:57:34 openvpn 74970 /usr/local/sbin/ovpn-linkdown ovpns1 1500 0 10.0.21.1 255.255.255.0 init
May 14 19:57:34 openvpn 74970 SIGTERM[hard,] received, process exiting

stephenw10 · Jan 10, 2024, 3:48 PM

Those are all very old. Those errors look like connection attempts from unknown clients. Unlikely to have caused this issue. Especially if running that did not reproduce the pf error in the general system log.

a.dresner · Jan 11, 2024, 4:51 AM

@stephenw10 sorry, I'm jet lagged and didn't even look at the dates. Ugh..

Here are the general logs after running that command at the shell:

Jan 10 21:27:45 php-fpm 406 /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.PROTO.>'' returned exit code '1', the output was ''
Jan 10 21:27:45 xinetd 63604 Starting reconfiguration
Jan 10 21:27:45 xinetd 63604 Swapping defaults
Jan 10 21:27:45 xinetd 63604 readjusting service 6969-udp
Jan 10 21:27:45 xinetd 63604 Reconfigured: new=0 old=1 dropped=0 (services)
Jan 10 21:28:39 rc.gateway_alarm 80695 >>> Gateway alarm: WG_VPN_HQ (Addr:10.100.92.1 Alarm:0 RTT:250.432ms RTTsd:20.860ms Loss:14%)
Jan 10 21:28:39 check_reload_status 446 updating dyndns WG_VPN_HQ
Jan 10 21:28:39 check_reload_status 446 Restarting IPsec tunnels
Jan 10 21:28:39 check_reload_status 446 Restarting OpenVPN tunnels/interfaces
Jan 10 21:28:39 check_reload_status 446 Reloading filter
Jan 10 21:28:40 php-fpm 405 /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.PROTO.>'' returned exit code '1', the output was ''
Jan 10 21:28:40 xinetd 63604 Starting reconfiguration
Jan 10 21:28:40 xinetd 63604 Swapping defaults
Jan 10 21:28:40 xinetd 63604 readjusting service 6969-udp
Jan 10 21:28:40 xinetd 63604 Reconfigured: new=0 old=1 dropped=0 (services)
Jan 10 21:40:13 rc.gateway_alarm 93364 >>> Gateway alarm: WG_VPN_HQ (Addr:10.100.92.1 Alarm:1 RTT:259.768ms RTTsd:29.231ms Loss:21%)
Jan 10 21:40:13 check_reload_status 446 updating dyndns WG_VPN_HQ
Jan 10 21:40:13 check_reload_status 446 Restarting IPsec tunnels
Jan 10 21:40:13 check_reload_status 446 Restarting OpenVPN tunnels/interfaces
Jan 10 21:40:13 check_reload_status 446 Reloading filter
Jan 10 21:40:15 php-fpm 28 /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.PROTO.>'' returned exit code '1', the output was ''
Jan 10 21:40:15 xinetd 63604 Starting reconfiguration
Jan 10 21:40:15 xinetd 63604 Swapping defaults
Jan 10 21:40:15 xinetd 63604 readjusting service 6969-udp
Jan 10 21:40:15 xinetd 63604 Reconfigured: new=0 old=1 dropped=0 (services)
Jan 10 21:40:57 rc.gateway_alarm 5473 >>> Gateway alarm: WG_VPN_HQ (Addr:10.100.92.1 Alarm:0 RTT:259.393ms RTTsd:31.093ms Loss:15%)
Jan 10 21:40:57 check_reload_status 446 updating dyndns WG_VPN_HQ
Jan 10 21:40:57 check_reload_status 446 Restarting IPsec tunnels
Jan 10 21:40:57 check_reload_status 446 Restarting OpenVPN tunnels/interfaces
Jan 10 21:40:57 check_reload_status 446 Reloading filter
Jan 10 21:40:58 php-fpm 406 /rc.openvpn: The command '/sbin/route -n6 get 'default' 2>/dev/null | /usr/bin/egrep 'flags: <.PROTO.>'' returned exit code '1', the output was ''
Jan 10 21:40:58 xinetd 63604 Starting reconfiguration
Jan 10 21:40:58 xinetd 63604 Swapping defaults
Jan 10 21:40:58 xinetd 63604 readjusting service 6969-udp
Jan 10 21:40:58 xinetd 63604 Reconfigured: new=0 old=1 dropped=0 (services)
Jan 10 21:41:00 sshguard 68209 Exiting on signal.
Jan 10 21:41:00 sshguard 76061 Now monitoring attacks.
Jan 10 21:47:35 php-fpm 28 /status_logs.php: Session timed out for user 'admin' from: 192.168.1.143 (Local Database)
Jan 10 21:47:45 php-fpm 28 /status_logs.php: Successful login for user 'admin' from: 192.168.1.143 (Local Database)
Jan 10 21:48:50 sshd 5970 Received disconnect from 192.168.1.143 port 64050:11: Normal Shutdown
Jan 10 21:48:50 sshd 5970 Disconnected from user admin 192.168.1.143 port 64050
Jan 10 21:49:21 sshd 55624 Accepted keyboard-interactive/pam for admin from 192.168.1.143 port 54238 ssh2

stephenw10 · Jan 11, 2024, 1:16 PM

Hmm, no pf error then.

Without any openvpn config there shouldn't be anything triggered by running rc.openvpn.

I wonder if you still have any conf files remaining in /var/etc/openvpn?

a.dresner · Mar 8, 2024, 4:59 AM

@stephenw10 doesn't look like it

[23.09.1-RELEASE][admin@]/: cd /var/etc/openvpn
/var/etc/openvpn: No such file or directory.
[23.09.1-RELEASE][admin@]/:

clawsonn · Mar 8, 2024, 4:59 AM

FYI
This week I just hit a similar issue where the PF machine ( Netgate pfSense Plus 23.09-RELEASE (amd64) ) was no longer smoothly pushing packets through and there was significant packet loss. After logging into webgui the notifications greeted with the following (date and time removed):

pf_busy

PF was wedged/busy and has been reset. @ -DATE TIME-
PF was wedged/busy and has been reset. @ -DATE TIME-

Filter Reload

There were error(s) loading the rules: pfctl: DIOCADDRULENV: Device busy - The line in question reads [0]: @ -DATE TIME-
There were error(s) loading the rules: pfctl: DIOCADDRULENV: Device busy - The line in question reads [0]: @ -DATE TIME-
There were error(s) loading the rules: pfctl: SIOCGIFGROUP: Device not configured - The line in question reads [0]: @ -DATE TIME-

The machine was rebooted and appears to functioning normal again.

When I have the time I will try to pull and review logs.

a.dresner · Mar 26, 2024, 7:25 AM

@clawsonn My situation has not improved. My notices:

pf_busy
• PF was wedged/busy and has been reset. @ 2024-01-25 04:54:20
• PF was wedged/busy and has been reset. @ 2024-01-28 20:04:22
• PF was wedged/busy and has been reset. @ 2024-01-30 02:24:22
• PF was wedged/busy and has been reset. @ 2024-03-06 07:54:55
• PF was wedged/busy and has been reset. @ 2024-03-15 08:14:59
• PF was wedged/busy and has been reset. @ 2024-03-21 09:15:02
• PF was wedged/busy and has been reset. @ 2024-03-23 20:45:03
• PF was wedged/busy and has been reset. @ 2024-03-24 06:50:04
Filter Reload
• There were error(s) loading the rules: pfctl: DIOCADDRULENV: Device busy - The line in question reads [0]: @ 2024-01-25 04:54:21
• There were error(s) loading the rules: pfctl: DIOCADDRULENV: Device busy - The line in question reads [0]: @ 2024-01-28 20:04:23
• There were error(s) loading the rules: pfctl: DIOCADDRULENV: Device busy - The line in question reads [0]: @ 2024-01-30 02:24:23
• There were error(s) loading the rules: pfctl: DIOCADDRULENV: Device busy - The line in question reads [0]: @ 2024-03-06 07:54:56
• There were error(s) loading the rules: pfctl: DIOCADDRULENV: Device busy - The line in question reads [0]: @ 2024-03-15 08:15:00
• There were error(s) loading the rules: pfctl: DIOCADDRULENV: Device busy - The line in question reads [0]: @ 2024-03-21 09:15:03
• There were error(s) loading the rules: pfctl: DIOCADDRULENV: Device busy - The line in question reads [0]: @ 2024-03-23 20:45:04
• There were error(s) loading the rules: pfctl: DIOCADDRULENV: Device busy - The line in question reads [0]: @ 2024-03-24 06:50:05

This should not be happening.

a.dresner · Mar 26, 2024, 7:29 AM

@stephenw10 Would be great if you could take a look at this, its happening quite consistently now