-
@dennypage, I noticed that the nut service is stopped on my pfsense box just today and I manually started it. Here are the ups logs:
Jan 22 13:16:46 upsd 45400 User monuser@192.168.20.22 logged into UPS [ups] Jan 22 13:16:43 upsd 45400 User local-monitor@::1 logged into UPS [ups] Jan 22 13:16:41 upsd 45400 Startup successful Jan 22 13:16:41 upsd 45398 Connected to UPS [ups]: usbhid-ups-ups Jan 22 13:16:41 upsd 45398 listening on 127.0.0.1 port 3493 Jan 22 13:16:41 upsd 45398 listening on ::1 port 3493 Jan 22 13:16:41 upsd 45398 listening on 192.168.20.1 port 3493 Jan 22 13:16:41 usbhid-ups 45330 Startup successful Jan 22 13:16:40 upsmon 44373 Startup successful Jan 22 04:20:28 upsd 99366 User monuser@192.168.20.22 logged into UPS [ups] Jan 22 04:20:23 upsd 99366 Startup successful Jan 22 04:20:23 upsd 99032 Connected to UPS [ups]: usbhid-ups-ups Jan 22 04:20:23 upsd 99032 listening on 127.0.0.1 port 3493 Jan 22 04:20:23 upsd 99032 listening on ::1 port 3493 Jan 22 04:20:23 upsd 99032 listening on 192.168.20.1 port 3493 Jan 22 04:20:22 usbhid-ups 95162 Startup successful Jan 22 04:20:22 upsd 87824 User local-monitor@::1 logged into UPS [ups] Jan 22 04:20:20 upsd 87824 Startup successful Jan 22 04:20:20 upsd 87506 Connected to UPS [ups]: usbhid-ups-ups Jan 22 04:20:20 upsd 87506 listening on 127.0.0.1 port 3493 Jan 22 04:20:20 upsd 87506 listening on ::1 port 3493 Jan 22 04:20:20 upsd 87506 listening on 192.168.20.1 port 3493 Jan 22 04:20:19 usbhid-ups 81258 Startup successful Jan 22 04:20:19 upsmon 71993 Startup successful Jan 22 04:20:19 usbhid-ups 2862 Signal 15: exiting Jan 22 04:20:18 upsd 28531 Signal 15: exiting Jan 22 04:20:18 upsd 28531 mainloop: Interrupted system call Jan 22 04:20:18 upsd 28531 User local-monitor@::1 logged out from UPS [ups] Jan 22 04:20:18 upsmon 98185 Signal 15: exiting Jan 22 04:13:59 upsd 28531 User local-monitor@::1 logged into UPS [ups] Jan 22 04:13:58 upsd 28531 User monuser@192.168.20.22 logged into UPS [ups] Jan 22 04:13:55 upsd 28531 Startup successful Jan 22 04:13:55 upsd 27776 Connected to UPS [ups]: usbhid-ups-ups Jan 22 04:13:55 upsd 27776 listening on 127.0.0.1 port 3493 Jan 22 04:13:55 upsd 27776 listening on ::1 port 3493 Jan 22 04:13:55 upsd 27776 listening on 192.168.20.1 port 3493 Jan 22 04:13:54 usbhid-ups 2862 Startup successful Jan 22 04:13:54 upsmon 97914 Startup successful Jan 22 04:13:52 upsd 90454 Startup successful Jan 22 04:13:52 upsd 90156 Connected to UPS [ups]: usbhid-ups-ups Jan 22 04:13:52 upsd 90156 listening on 127.0.0.1 port 3493 Jan 22 04:13:52 upsd 90156 listening on ::1 port 3493 Jan 22 04:13:52 upsd 90156 listening on 192.168.20.1 port 3493 Jan 22 04:13:51 usbhid-ups 89839 Startup successful Jan 22 04:13:51 upsmon 83244 Startup successful Jan 22 04:13:51 usbhid-ups 71212 Signal 15: exiting Jan 22 04:13:51 upsd 3561 Signal 15: exiting Jan 22 04:13:51 upsd 3561 mainloop: Interrupted system call Jan 22 04:13:51 upsd 3561 User local-monitor@::1 logged out from UPS [ups] Jan 22 04:13:51 upsmon 69440 Signal 15: exiting Jan 22 03:59:08 upsd 3561 User monuser@192.168.20.22 logged into UPS [ups] Jan 22 03:59:08 upsd 3561 User local-monitor@::1 logged into UPS [ups] Jan 22 03:59:06 upsd 3561 Startup successful Jan 22 03:59:06 upsd 2944 Connected to UPS [ups]: usbhid-ups-ups Jan 22 03:59:06 upsd 2944 listening on 127.0.0.1 port 3493 Jan 22 03:59:06 upsd 2944 listening on ::1 port 3493 Jan 22 03:59:06 upsd 2944 listening on 192.168.20.1 port 3493 Jan 22 03:59:05 usbhid-ups 71212 Startup successful Jan 22 03:59:05 upsmon 69088 Startup successful Jan 22 03:59:05 upsd 59887 User local-monitor@::1 logged into UPS [ups] Jan 22 03:59:03 upsd 59887 Startup successful Jan 22 03:59:03 upsd 59792 Connected to UPS [ups]: usbhid-ups-ups Jan 22 03:59:03 upsd 59792 listening on 127.0.0.1 port 3493 Jan 22 03:59:03 upsd 59792 listening on ::1 port 3493 Jan 22 03:59:03 upsd 59792 listening on 192.168.20.1 port 3493 Jan 22 03:59:02 usbhid-ups 59385 Startup successful Jan 22 03:59:02 upsmon 53529 Startup successful Jan 22 03:59:01 usbhid-ups 14878 Signal 15: exiting Jan 22 03:59:01 upsd 15286 Signal 15: exiting Jan 22 03:59:01 upsd 15286 mainloop: Interrupted system call Jan 22 03:59:01 upsd 15286 User local-monitor@::1 logged out from UPS [ups] Jan 22 03:59:01 upsmon 14537 Signal 15: exitingDo you have any ideas as to why it suddenly stopped?
-
@kevindd992002 It looks like it was restarted. Possibly as a result of an interface flap. For answers to these kinds of questions, you need to evaluate the entire system log surrounding an event, not just entries that have the string "ups" in them.
-
I just wanted to say a big thanks to @dennypage for all the information provided here. Anticipating a battle in getting my new SG-3100 and CyberPower CP685AVRG talking to each other, I found this thread while Googling for information. I read all of this thread and the start of the NUT documentation on configuration, but found the actual process a total non-event.
I only had to plug in the USB cable, install the nut package, reboot for good measure (because I think I read there might be a permissions issue for something if I didn't?), and then set the one dropdown to Local USB and hit Save. Boom! Up and running! Too easy.
Having gone through this thread, I have a really clear picture of the options available to me, how to debug processes, and how I might setup other systems to use the pfsense as a master, if needed, including setting up the Synology I haven't used in ages. This thread is a treasure trove of information. Thanks!
~Dan
-
I have email alert activated for nut.
Nut is sending messages like "Communications with UPS UPS lost" and "UPS UPS is unavailable" every time something is changed on any interface. Like editing a interface, restarting a OpenVPN server or even when just the PPPoe lost the DSL connection or is reconnecting.
But the UPS is connected directly to pfsense through a serial port so it is not actually not losing connection.All these "false positive" error messages make it hard to get alarmed should there really be an issue with the UPS sometime.
Is it possible to fix this behaviour?
-
@flu I think I have seen the same thing happen.
-
@DannyBoy2k You are most welcome. Glad it was so easy!
And very impressed that you went through the entire thread.
-
@flu Yes, this happens because when an interface flaps, pfSense restarts all add-on services. The reason for this is that pfSense itself does not have direct knowledge of what dependencies the services have on interfaces (if any).
-
@dennypage
many thanks for the explanation.
I guess the nut package could be changed so that it does not send messages like "Communications with UPS UPS lost" and "UPS UPS is unavailable" every time it gets restarted by pfsense? -
@flu The email comes from NUT itself, rather than the pfSense NUT package. And from NUT's point of view, the connection to the UPS is actually being lost. This will be triggered by something that affects the USB or serial connectivity being restarted or reloaded underneath NUT. NUT doesn't know why the connection failed, it just knows that it failed so it sends the email. You should be able to see the order of events in the system log if you want to understand more about what is happening.
-
@dennypage So here's what I noticed recently in my system logs after receiving UPS communication lost and established emails:
Feb 19 04:33:53 php-cgi nut_email.php: Message sent to kevindd992002@yahoo.com OK Feb 19 04:33:49 php-cgi nut_email.php: Message sent to kevindd992002@yahoo.com OK Feb 19 04:33:46 upsmon 43175 Communications with UPS ups established Feb 19 04:33:44 upsd 86349 UPS [ups] data is no longer stale Feb 19 04:33:41 upsmon 43175 Communications with UPS ups lost Feb 19 04:33:41 upsmon 43175 Poll UPS [ups] failed - Data stale Feb 19 04:33:41 kernel ugen0.2: <EATON 5E> at usbus0 Feb 19 04:33:38 kernel ugen0.2: <EATON 5E> at usbus0 (disconnected) Feb 19 04:33:37 upsd 86349 Data for UPS [ups] is stale - check driverWhat does "data is stale" even mean? And why does this happen intermittently?
-
@kevindd992002 said in NUT package:
What does "data is stale" even mean? And why does this happen intermittently?
Probably because :
Feb 19 04:33:38 kernel ugen0.2: <EATON 5E> at usbus0 (disconnected)
Feb 19 04:33:37 upsd 86349 Data for UPS [ups] is stale - check driverwhich says to me that the link between the driver (NUT ?) and the UPS device (cable, whatever) isn't "stable".
-
@Gertjan said in NUT package:
@kevindd992002 said in NUT package:
What does "data is stale" even mean? And why does this happen intermittently?
Probably because :
Feb 19 04:33:38 kernel ugen0.2: <EATON 5E> at usbus0 (disconnected)
Feb 19 04:33:37 upsd 86349 Data for UPS [ups] is stale - check driverwhich says to me that the link between the driver (NUT ?) and the UPS device (cable, whatever) isn't "stable".
Right but it's just weird that it happens randomly. It's not the UPS and cable because those were replaced already. I also tried using another usb port on the apu2c4 to no avail. There are only 2 usb ports available. Maybe the hub itself? How can you tell for sure though?
-
@kevindd992002 It's either the host end or the UPS end. On the host end, it can be hardware (bridge controller) or software (kernel driver). On the UPS end it would just be a flakey USB implementation.
What I generally recommend to people having these types of issues:
- Try a different port on the host that uses a different bridge chip. Favor ports that are USB 2 as USB 3 ports usually have more problems.
- If you have a USB hub between the host and the UPS, try removing it.
- If you don't have a USB hub between the host and the UPS, try adding one.
- Try a different USB hub that uses a different bridge chip.
- Try a different UPS model.
- Try a different host model.
Regarding the apu2c4, you might find this an interesting read.
Bonne chance
-
@dennypage I'm seeing the following log entries under 2.4.5, anything to be concerned about?
Apr 16 07:09:28 upsmon 92379 Communications with UPS UPS established Apr 16 07:09:28 upsd 33793 User local-monitor@127.0.0.1 logged into UPS [UPS] Apr 16 07:09:23 upsmon 92379 Communications with UPS UPS lost Apr 16 07:09:23 upsmon 92379 Poll UPS [UPS] failed - Write error: Permission denied Apr 16 07:09:21 nginx 2020/04/16 07:09:21 [crit] 11971#100993: *62736 SSL_write() failed (13: Permission denied) while processing HTTP/2 connection, client: 192.168.20.115, server: 0.0.0.0:4433 Apr 16 07:08:43 upsmon 92379 Communications with UPS UPS established Apr 16 07:08:43 upsd 33793 User local-monitor@127.0.0.1 logged into UPS [UPS] Apr 16 07:08:38 upsmon 92379 Communications with UPS UPS lost Apr 16 07:08:38 upsmon 92379 Poll UPS [UPS] failed - Write error: Permission denied -
@q54e3w Can you provide information on your NUT configuration please?
-
UPS is a network connected Eaton 9PX with Network Card 2.
UPS Type: Remote SNMP
UPS Name: UPS
Notifications: EnabledDriver Settings
Remote IP: 192.168.10.42
Extra args:
mibs = pw
pollfreq = 15
ignorelbAdvanced Settings
FINALDELAY 180
Addition configuration lines for ups.conf = LISTEN 192.168.10.1
Additional ups.users
[remoteuser]
password = mysupersecretpassword
upsmon slaveThis provides the following status
UPS Status
Name: UPS@localhost
Summary status: On line
Runtime (H:M:S): 5:17:00
UPS Load:
36.00%
Battery charge:
100.00%
Battery voltage: 52.00
Input frequency: 60.00 -
@q54e3w said in NUT package:
Poll UPS [UPS] failed - Write error: Permission denied
Is there anything that precedes this entry in the log? Perhaps something similar to this?
-
@dennypage said in NUT package:
Is there anything that precedes this entry in the log? Perhaps something similar to this?
No, no other errors or messages from upsd/upsmon above or below that one. First sign of trouble is the Poll UPS failed.
-
@q54e3w said in NUT package:
@dennypage said in NUT package:
Is there anything that precedes this entry in the log? Perhaps something similar to this?
No, no other errors or messages from upsd/upsmon above or below that one. First sign of trouble is the Poll UPS failed.
I wasn’t asking about other upsd/upsmon messages, rather I was asking about messages associated with links flapping, DHCP activities, etc. Similar to the logs in the link above.
-
ahhhh, gotcha. There was another issue with UPnP that I resolved and thats when I noticed these entries. I'll keep an eye on it but as I haven't seen a repeat maybe it was related. Thank you.
Copyright 2025 Rubicon Communications LLC (Netgate). All rights reserved.