Netgate 2100 after PHP problem no internet connection

NOCling · Jun 26, 2022, 9:41 PM

Hello everyone,

yesterday my VPN Remote Site doesn't respond anymore, IPsec down, no ping response.
Today i was there and check what's happened.

On LAN site i got a IP and can reach the Webgui, but the Upstream Gateway is down (dpinger up and running) no Internet connection and NUT stoped.

I got a Crashlog from the moment its got unresponsive:

[25-Jun-2022 11:20:08 Europe/Berlin] PHP Warning:  file_put_contents(/var/db/notifyqueue.messages): failed to open stream: Permission denied in /etc/inc/notices.inc on line 261
[25-Jun-2022 11:20:18 Europe/Berlin] PHP Warning:  file_put_contents(/var/db/notifyqueue.messages): failed to open stream: Permission denied in /etc/inc/notices.inc on line 261
[25-Jun-2022 11:20:28 Europe/Berlin] PHP Warning:  file_put_contents(/var/db/notifyqueue.messages): failed to open stream: Permission denied in /etc/inc/notices.inc on line 261
[25-Jun-2022 11:20:38 Europe/Berlin] PHP Warning:  file_put_contents(/var/db/notifyqueue.messages): failed to open stream: Permission denied in /etc/inc/notices.inc on line 261
[25-Jun-2022 11:20:48 Europe/Berlin] PHP Warning:  file_put_contents(/var/db/notifyqueue.messages): failed to open stream: Permission denied in /etc/inc/notices.inc on line 261
[25-Jun-2022 11:20:58 Europe/Berlin] PHP Warning:  file_put_contents(/var/db/notifyqueue.messages): failed to open stream: Permission denied in /etc/inc/notices.inc on line 261
[25-Jun-2022 11:21:08 Europe/Berlin] PHP Warning:  file_put_contents(/var/db/notifyqueue.messages): failed to open stream: Permission denied in /etc/inc/notices.inc on line 261
[25-Jun-2022 11:23:07 Europe/Berlin] PHP Warning:  file_put_contents(/var/db/notifyqueue.messages): failed to open stream: Permission denied in /etc/inc/notices.inc on line 261
[25-Jun-2022 11:23:17 Europe/Berlin] PHP Warning:  file_put_contents(/var/db/notifyqueue.messages): failed to open stream: Permission denied in /etc/inc/notices.inc on line 261
[25-Jun-2022 11:23:27 Europe/Berlin] PHP Warning:  file_put_contents(/var/db/notifyqueue.messages): failed to open stream: Permission denied in /etc/inc/notices.inc on line 261
[25-Jun-2022 11:23:37 Europe/Berlin] PHP Warning:  file_put_contents(/var/db/notifyqueue.messages): failed to open stream: Permission denied in /etc/inc/notices.inc on line 261
[25-Jun-2022 11:23:47 Europe/Berlin] PHP Warning:  file_put_contents(/var/db/notifyqueue.messages): failed to open stream: Permission denied in /etc/inc/notices.inc on line 261
[25-Jun-2022 11:23:57 Europe/Berlin] PHP Warning:  file_put_contents(/var/db/notifyqueue.messages): failed to open stream: Permission denied in /etc/inc/notices.inc on line 261
[25-Jun-2022 11:24:07 Europe/Berlin] PHP Warning:  file_put_contents(/var/db/notifyqueue.messages): failed to open stream: Permission denied in /etc/inc/notices.inc on line 261

Running:
22.05-RC (arm64) built on Fri Jun 17 06:34:30 UTC 2022
ipsec-profile-wizard 1.0_6
mailreport 3.6.3_3
nut sysutils 2.7.4_10
pfBlockerNG-devel 3.1.0_4
Status_Traffic_Totals 2.3.2_2
sudo 0.3_6
System_Patches 2.0_6

Under Status Monitoring its only the Internet down, no Mbuf overload i run into with AES_GCM before.
NUT crashed before, restarting service didn't help, I need to reboot pfsense to got NUT running again.
Now i have to reboot pfSense to get Internet connection back online.

Here are the System Log a this time:

Jun 25 11:20:59	upsmon	84332	UPS qnapups is unavailable
Jun 25 11:20:59	upsd	90523	Connected to UPS [qnapups]: usbhid-ups-qnapups
Jun 25 11:20:59	upsmon	84332	Poll UPS [qnapups] failed - Driver not connected
Jun 25 11:20:58	usbhid-ups	67434	Startup successful
Jun 25 11:20:57	php	92261	nut_email.php: Message sent to mail OK
Jun 25 11:20:54	upsmon	84332	Communications with UPS qnapups lost
Jun 25 11:20:54	upsmon	84332	Poll UPS [qnapups] failed - Driver not connected
Jun 25 11:20:54	upsd	90523	User local-monitor@::1 logged into UPS [qnapups]
Jun 25 11:20:54	upsd	90523	Startup successful
Jun 25 11:20:54	upsd	90264	Can't connect to UPS [qnapups] (usbhid-ups-qnapups): Connection refused
Jun 25 11:20:54	upsd	90264	listening on 127.0.0.1 port 3493
Jun 25 11:20:54	upsd	90264	listening on ::1 port 3493
Jun 25 11:20:54	upsd	90264	listening on 192.168.166.1 port 3493
Jun 25 11:20:53	upsmon	83479	Startup successful
Jun 25 11:20:50	upsd	34808	Startup successful
Jun 25 11:20:50	upsd	34138	Connected to UPS [qnapups]: usbhid-ups-qnapups
Jun 25 11:20:50	upsd	34138	listening on 127.0.0.1 port 3493
Jun 25 11:20:50	upsd	34138	listening on ::1 port 3493
Jun 25 11:20:50	upsd	34138	listening on 192.168.166.1 port 3493
Jun 25 11:20:49	usbhid-ups	17736	Startup successful
Jun 25 11:20:49	upsmon	12517	Startup successful
Jun 25 11:20:49	php-fpm	3783	/rc.start_packages: Starting service nut
Jun 25 11:20:49	usbhid-ups	52131	Signal 15: exiting
Jun 25 11:20:49	upsd	4074	Signal 15: exiting
Jun 25 11:20:49	upsd	4074	mainloop: Interrupted system call
Jun 25 11:20:49	upsd	4074	User local-monitor@::1 logged out from UPS [qnapups]
Jun 25 11:20:49	upsmon	85361	Signal 15: exiting
Jun 25 11:20:49	php-fpm	3783	/rc.start_packages: Stopping service nut
Jun 25 11:20:49	php-fpm	3783	/rc.start_packages: Restarting/Starting all packages.
Jun 25 11:20:48	check_reload_status	768	Starting packages
Jun 25 11:20:48	php-fpm	35584	/rc.newwanip: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 192.168.100.124 -> 176.198.47.227 - Restarting packages.
Jun 25 11:20:46	php-fpm	35584	/rc.newwanip: Creating rrd update script
Jun 25 11:20:45	php-fpm	35584	/rc.newwanip: Resyncing OpenVPN instances for interface WAN.
Jun 25 11:20:45	check_reload_status	768	Reloading filter
Jun 25 11:20:45	check_reload_status	768	Reloading filter
Jun 25 11:20:45	php-fpm	35584	/rc.newwanip: Forcefully reloading IPsec
Jun 25 11:20:44	php-fpm	35584	/rc.newwanip: Dynamic DNS () There was an error trying to determine the public IP for interface - wan (mvneta0 ).
Jun 25 11:20:42	kernel		config_aqm Unable to configure flowset, flowset busy!
Jun 25 11:20:42	php-fpm	35584	/rc.newwanip: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
Jun 25 11:20:28	php	55087	[pfBlockerNG] filterlog daemon started
Jun 25 11:20:27	tail_pfb	54636	[pfBlockerNG] Firewall Filter Service started
Jun 25 11:20:27	lighttpd_pfb	52135	[pfBlockerNG] DNSBL Webserver started
Jun 25 11:20:27	php_pfb	49911	[pfBlockerNG] filterlog daemon stopped
Jun 25 11:20:27	tail_pfb	49513	[pfBlockerNG] Firewall Filter Service stopped
Jun 25 11:20:27	lighttpd_pfb	48259	[pfBlockerNG] DNSBL Webserver stopped
Jun 25 11:20:27	vnstatd	47068	Error: pidfile "/var/run/vnstat/vnstat.pid" lock failed (Resource temporarily unavailable), exiting.
Jun 25 11:20:26	vnstatd	43586	Monitoring (6): pfsync0 (1000 Mbit) pflog0 (1000 Mbit) mvneta1.167 (1000 Mbit) mvneta1 (1000 Mbit) mvneta0 (1000 Mbit) enc0 (1000 Mbit)
Jun 25 11:20:26	vnstatd	43586	vnStat daemon 2.9 started. (pid:43586 uid:0 gid:0)
Jun 25 11:20:26	vnstatd	99988	SIGTERM received, exiting.
Jun 25 11:20:24	php-fpm	35584	/rc.newwanip: IP Address has changed, killing states on former IP Address 192.168.100.124.
Jun 25 11:20:23	php-fpm	35584	/rc.newwanip: Removing static route for monitor 1.1.1.1 and adding a new route through 176.198.x.x
Jun 25 11:20:16	vnstatd	37513	Error: pidfile "/var/run/vnstat/vnstat.pid" lock failed (Resource temporarily unavailable), exiting.
Jun 25 11:20:11	php-fpm	51588	/rc.start_packages: Skipping STARTing packages process because previous/another instance is already running
Jun 25 11:20:10	check_reload_status	768	Starting packages
Jun 25 11:20:10	php-fpm	51588	/rc.newwanipv6: Netgate pfSense Plus package system has detected an IP change or dynamic WAN reconnection - 2a02:xxxx -> 2a02:xxxx - Restarting packages.
Jun 25 11:20:10	php-fpm	51588	/rc.newwanipv6: Creating rrd update script
Jun 25 11:20:10	php-fpm	51588	/rc.newwanipv6: Resyncing OpenVPN instances for interface WAN.
Jun 25 11:20:09	check_reload_status	768	Reloading filter

The WAN Int is set to refuse DHCP leases from 192.168.100.1 which cable modem IP if not provisioned.
But here it seems to have accepted an IP from the range.
Strange
Anyone an idea?

rcoleman-netgate · Jun 26, 2022, 10:01 PM

@nocling What's the storage situation like? Is the storage device full?

NOCling · Jun 26, 2022, 10:16 PM

No at the Moment 4% of 22 ZFS used.

rcoleman-netgate · Jun 26, 2022, 10:18 PM

@nocling Personally I would backup the config, reinstall 22.01, then upgrade to the RC and then restore your config.

p1erre · Jun 27, 2022, 8:37 AM

I had the same issue on my Netgate 6100. I was playing around with some tunning, after reboot I got this kernel panic. Tried to restore a backup but this crashed the system, fails to boot now. I'll wait for the final 22.05 version and will request the image for a fresh install.

NOCling · Jun 27, 2022, 4:19 PM

Now I install the latest 22.05 and try it out.
I will do a fresh install if the error comes back.

jimp · Jun 27, 2022, 4:31 PM

The permission denied error is from the NUT package trying to send notifications from an unprivileged user.

See https://redmine.pfsense.org/issues/12281

Those errors are almost certainly not related directly, but may be indirectly related. By that I mean some power/UPS event triggered those failed notifications -- that event may be the cause of your problem, not the notification errors.