PHP Fatal Error

[munson]

Any idea what this error is about? Should I be concerned?

Php Error

[28-Feb-2023 17:35:03 America/Los_Angeles] PHP Fatal error: Uncaught TypeError: fwrite(): Argument #1 ($stream) must be of type resource, bool given in /etc/inc/config.lib.inc:172
Stack trace:
#0 /etc/inc/config.lib.inc(172): fwrite(false, 'a:41:{s:7:"vers...')
#1 /etc/inc/config.lib.inc(147): generate_config_cache(Array)
#2 /etc/inc/config.inc(141): parse_config()
#3 /etc/inc/gwlb.inc(25): require_once('/etc/inc/config...')
#4 /etc/inc/functions.inc(35): require_once('/etc/inc/gwlb.i...')
#5 /etc/inc/notices.inc(26): require_once('/etc/inc/functi...')
#6 /usr/local/pkg/nut/nut_email.php(24): require_once('/etc/inc/notice...')
#7 {main}
thrown in /etc/inc/config.lib.inc on line 172
[28-Feb-2023 17:35:03 America/Los_Angeles] PHP Fatal error: Uncaught ValueError: Path cannot be empty in /etc/inc/notices.inc:101
Stack trace:
#0 /etc/inc/notices.inc(101): fopen('', 'w')
#1 /etc/inc/config.lib.inc(1162): file_notice('phperror', 'PHP ERROR: Type...', 'PHP errors')
#2 [internal function]: pfSense_clear_globals()
#3 {main}
thrown in /etc/inc/notices.inc on line 101

[stephenw10]

Commonly that's associated with being unable to write out the notice.

Is/was the drive full?

Was it at boot?

If you remove it does it return?

Steve

[asv345h]

I received the same error yesterday. Drive is no where near full. I upgraded the OS to v23.01 five days ago though, and that was the last restart.

[stephenw10]

Actually identically the same error?

Is that the first time the UPS experienced some sort of incident?

Steve

[asv345h]

@stephenw10
Oops, line #6 is different. I've only seen this error this one time. Not the UPS, but what is 'notify_monitor'?

-rick

[04-Mar-2023 18:18:12 US/Eastern] PHP Fatal error:  Uncaught TypeError: fwrite(): Argument #1 ($stream) must be of type resource, bool given in /etc/inc/config.lib.inc:172
Stack trace:
#0 /etc/inc/config.lib.inc(172): fwrite(false, 'a:40:{s:7:"vers...')
#1 /etc/inc/config.lib.inc(147): generate_config_cache(Array)
#2 /etc/inc/config.inc(141): parse_config()
#3 /etc/inc/gwlb.inc(25): require_once('/etc/inc/config...')
#4 /etc/inc/functions.inc(35): require_once('/etc/inc/gwlb.i...')
#5 /etc/inc/notices.inc(26): require_once('/etc/inc/functi...')
#6 /usr/local/bin/notify_monitor.php(24): include_once('/etc/inc/notice...')
#7 {main}
  thrown in /etc/inc/config.lib.inc on line 172
[04-Mar-2023 18:18:12 US/Eastern] PHP Fatal error:  Uncaught ValueError: Path cannot be empty in /etc/inc/notices.inc:101
Stack trace:
#0 /etc/inc/notices.inc(101): fopen('', 'w')
#1 /etc/inc/config.lib.inc(1162): file_notice('phperror', 'PHP ERROR: Type...', 'PHP errors')
#2 [internal function]: pfSense_clear_globals()
#3 {main}
  thrown in /etc/inc/notices.inc on line 101

[stephenw10]

Ok, that looks like it was triggered by a gateway alarm. Do you see that logged at that time?

[jimp]

@asv345h said in PHP Fatal Error:

Oops, line #6 is different. I've only seen this error this one time. Not the UPS, but what is 'notify_monitor'?

notify_monitor.php is the script that runs in the background to send queued SMTP notifications

[asv345h]

So, during that time I was doing some maintenance and had pulled the WAN cable so there were plenty of gateway alarms firing. I also don't have SMTP notification turned on. Here's a combined log of the relevant events around that time. The gateway logs are missing because I had not yet enabled them for remote logging.

-rick

"2023-03-04T18:18:08.000-05:00","apcupsd-ups[69397]: Startup successful"
"2023-03-04T18:18:08.000-05:00","upsmon[68380]: Communications with UPS APC_UPS lost"
"2023-03-04T18:18:08.000-05:00","upsmon[68380]: UPS [APC_UPS]: connect failed: Connection failure: Connection refused"
"2023-03-04T18:18:08.000-05:00","upsmon[68380]: Startup successful"
"2023-03-04T18:18:08.000-05:00","php-fpm[4765]: /rc.start_packages: Starting service nut"
"2023-03-04T18:18:08.000-05:00","php-fpm[4765]: /rc.start_packages: Restarting/Starting all packages."
"2023-03-04T18:18:09.000-05:00","upsd[98528]: Startup successful"
"2023-03-04T18:18:09.000-05:00","upsd[98528]: Connected to UPS [APC_UPS]: apcupsd-ups-APC_UPS"
"2023-03-04T18:18:09.000-05:00","upsd[98528]: listening on ::1 port 3493"
"2023-03-04T18:18:09.000-05:00","upsd[98528]: listening on 127.0.0.1 port 3493"
"2023-03-04T18:18:11.000-05:00","upsmon[68380]: upsmon parent: read"
"2023-03-04T18:18:12.000-05:00","php-cgi[17145]: #6 /usr/local/bin/notify_monitor.php(24): include_once('/etc/inc/notice...')"
"2023-03-04T18:18:12.000-05:00","php-cgi[17145]: #5 /etc/inc/notices.inc(26): require_once('/etc/inc/functi...')"
"2023-03-04T18:18:12.000-05:00","php-cgi[17145]: #7 {main}"
"2023-03-04T18:18:12.000-05:00","php-cgi[17145]:   thrown"
"2023-03-04T18:18:12.000-05:00","php-cgi[17145]: #3 /etc/inc/gwlb.inc(25): require_once('/etc/inc/config...')"
"2023-03-04T18:18:12.000-05:00","php-cgi[17145]: #0 /etc/inc/config.lib.inc(172): fwrite(false, 'a:40:{s:7:""vers...')"
"2023-03-04T18:18:12.000-05:00","php-cgi[17145]: #1 /etc/inc/config.lib.inc(147): generate_config_cache(Array)"
"2023-03-04T18:18:12.000-05:00","php-cgi[17145]: Stack trace:"
"2023-03-04T18:18:12.000-05:00","php-cgi[17145]: #4 /etc/inc/functions.inc(35): require_once('/etc/inc/gwlb.i...')"
"2023-03-04T18:18:12.000-05:00","php-cgi[17145]: notify_monitor.php: PHP ERROR: Type: 1, File: /etc/inc/config.lib.inc, Line: 172, Message: Uncaught TypeError: fwrite(): Argument #1 ($stream) must be of type resource, bool given in /etc/inc/config.lib.inc:172"
"2023-03-04T18:18:12.000-05:00","php-cgi[17145]: #2 /etc/inc/config.inc(141): parse_config()"
"2023-03-04T18:18:12.000-05:00","apcupsd-ups[2771]: Startup successful"
"2023-03-04T18:18:12.000-05:00","upsmon[936]: UPS [APC_UPS]: connect failed: Connection failure: Connection refused"
"2023-03-04T18:18:12.000-05:00","upsmon[936]: Communications with UPS APC_UPS lost"
"2023-03-04T18:18:12.000-05:00","upsmon[936]: Startup successful"
"2023-03-04T18:18:13.000-05:00","check_reload_status[399]: Syncing firewall"
"2023-03-04T18:18:13.000-05:00","php-fpm[4765]: /rc.start_packages: Beginning configuration backup to https://acb.netgate.com/save"
"2023-03-04T18:18:13.000-05:00","php-fpm[4765]: /rc.start_packages: Configuration Change: (system): syslog-ng: Settings saved"
"2023-03-04T18:18:13.000-05:00","upsd[33956]: Startup successful"
"2023-03-04T18:18:13.000-05:00","upsd[33956]: Connected to UPS [APC_UPS]: apcupsd-ups-APC_UPS"
"2023-03-04T18:18:13.000-05:00","upsd[33956]: listening on 127.0.0.1 port 3493"
"2023-03-04T18:18:13.000-05:00","upsd[33956]: listening on ::1 port 3493"
"2023-03-04T18:18:17.000-05:00","upsmon[936]: Communications with UPS APC_UPS established"
"2023-03-04T18:18:17.000-05:00","upsd[33956]: User local-monitor@::1 logged into UPS [APC_UPS]"

[stephenw10]

Ok, you may not be running Nut but you are running apcupsd. I assume you have email notifications set? If you disable it the errors stop?

[asv345h]

@stephenw10
No, just running nut. I have a server running apcupsd and have pfsense running nut in "remote apcupsd" mode.

I don't use email notifications. However, the "Disable SNMP Notifications" is NOT checked and the config fields are all blank. Should disable be checked?

So, this is the only error of this type that I have seen in my 10+ years of running pfsense and I thought it might be a bug.

[stephenw10]

It is a bug of some sort. We just need to narrow down where it is. So, yes, try disabling the notifications and see if that stops the error reappearing.

[asv345h]

@stephenw10
Alright, I post back if error returns. Thanks for the help.

-rick

[jimp]

For the error to happen there, an fopen function has to fail to open a file for writing in /tmp/.

It's not clear why, though, since it could be one of several things, including (but not limited to):

• /tmp is full
• If /tmp is a RAM disk, there may not be sufficient RAM to create a new file in the FS
• If /tmp is on an SSD/MMC/HDD, the filesystem holding /tmp has a problem (e.g. UFS and needs fsck run several times, or ZFS and needs a scrub)
• If /tmp is on an SSD/MMC/HDD, the disk or controller may have stopped responding to commands (disk or controller physical issue, maybe controller driver issue, etc.)

The problem here is that if it is a disk issue the logs may not be helpful unless you pipe syslog to a remote network host. If there is a problem with the disk it can't log that to the disk when a problem occurs. It might print a message to the console, though, but it depends on what happened.

I've tried a few different ways to see if multiple processes competing to write the same file all at once could trigger this kind of error but so far I haven't had any luck drawing it out.

[asv345h]

@jimp
My hardware is a ng-6100 with pfsense pre-installed. Looks like plenty of space at the moment.

I stream syslog to a remote server and have the logs. I searched for "/tmp" but got no hits. A search for "mmc" only found this: kernel: mmc0: <MMC/SD bus> on sdhci_pci0, but that was 4 days after the exception. Is there another search term I should try?

-rick

[stephenw10]

Mmm, nothing obviously wrong there. Seems like it's unable to write the file for some other reason.

[wralb]

I'm seeing the exact same error from time to time as @asv345h since upgrading to 23.01 . I'm also running an ng-6100 running 23.01 (for info, I have a APC UPS plugged in to a USB port). Everything was fine for a year before the upgrade.

Here is an example:

FreeBSD 14.0-CURRENT #0 plus-RELENG_23_01-n256037-6e914874a5e: Fri Feb 10 20:30:29 UTC 2023     root@freebsd:/var/jenkins/workspace/pfSense-Plus-snapshots-23_01-main/obj/amd64/VDZvZksF/var/jenkins/workspace/pfSense-Plus-snapshots-23_01-main/sources/FreeBS

Crash report details:

PHP Errors:
[07-Mar-2023 11:26:53 Europe/London] PHP Fatal error:  Uncaught TypeError: fwrite(): Argument #1 ($stream) must be of type resource, bool given in /etc/inc/config.lib.inc:172
Stack trace:
#0 /etc/inc/config.lib.inc(172): fwrite(false, 'a:44:{s:7:"vers...')
#1 /etc/inc/config.lib.inc(147): generate_config_cache(Array)
#2 /etc/inc/config.inc(141): parse_config()
#3 /etc/inc/gwlb.inc(25): require_once('/etc/inc/config...')
#4 /etc/inc/functions.inc(35): require_once('/etc/inc/gwlb.i...')
#5 /etc/inc/notices.inc(26): require_once('/etc/inc/functi...')
#6 /usr/local/bin/notify_monitor.php(24): include_once('/etc/inc/notice...')
#7 {main}
  thrown in /etc/inc/config.lib.inc on line 172
[07-Mar-2023 11:26:53 Europe/London] PHP Fatal error:  Uncaught ValueError: Path cannot be empty in /etc/inc/notices.inc:101
Stack trace:
#0 /etc/inc/notices.inc(101): fopen('', 'w')
#1 /etc/inc/config.lib.inc(1162): file_notice('phperror', 'PHP ERROR: Type...', 'PHP errors')
#2 [internal function]: pfSense_clear_globals()
#3 {main}
  thrown in /etc/inc/notices.inc on line 101

The timing of the error correlates closely with a gateway event:

Mar  7 11:26:36 pfsense dpinger[88905]: exiting on signal 15
Mar  7 11:26:36 pfsense dpinger[90399]: send_interval 500ms  loss_interval 2000ms  time_period 60000ms  report_interval 0ms  data_len 1  alert_interval 1000ms  latency_alarm 1000ms  loss_alarm 50%  dest_addr 86.25.176.1  bind_addr 86.25.183.166  identifier "WAN_DHCP "
Mar  7 11:26:39 pfsense dpinger[90399]: exiting on signal 15
Mar  7 11:26:39 pfsense dpinger[16144]: send_interval 500ms  loss_interval 2000ms  time_period 60000ms  report_interval 0ms  data_len 1  alert_interval 1000ms  latency_alarm 1000ms  loss_alarm 50%  dest_addr 86.25.176.1  bind_addr 86.25.183.166  identifier "WAN_DHCP "
Mar  7 11:26:46 pfsense dpinger[16144]: exiting on signal 15
Mar  7 11:26:46 pfsense dpinger[57987]: send_interval 500ms  loss_interval 2000ms  time_period 60000ms  report_interval 0ms  data_len 1  alert_interval 1000ms  latency_alarm 1000ms  loss_alarm 50%  dest_addr 86.25.176.1  bind_addr 86.25.183.166  identifier "WAN_DHCP "

File system is ZFS with plenty of space and /tmp showing 480KB of 6.5GB used.

[Overlord]

I have the same issue on all of my pfSense boxes - after the Upgrade to 23.01

[stephenw10]

The exact same pair of php errors?

This? https://redmine.pfsense.org/issues/14061

Is there some common config all your installs share?

[akghetto]

Any update on this error? I started getting it tonight.

My main drive is defintely not full...

[23.01-RELEASE][admin@host.domain]/root: df -h
Filesystem                     Size    Used   Avail Capacity  Mounted on
/dev/ufsid/59b7f3af0adccc14    100G    2.6G     89G     3%    /
devfs                          1.0K    1.0K      0B   100%    /dev
tmpfs                          4.0M    196K    3.8M     5%    /var/run
devfs                          1.0K    1.0K      0B   100%    /var/dhcpd/dev

//edit: nevermind... found patch c5faa351c1ef6d4555478a7f50b3a16ece7e0b2a on redmine. Sorry for the thread bump.

[jacksnack2]

Same issue here. Seen this error twice after upgrading to 2.7.0 on July 1st.

I also see references to Nut Package (which is installed).

I applied the patch as referenced above, I'll report back with results.