NUT package (2.8.0 and below)
-
Just wanted to say thanks for this package. I am now using pfSense to monitor my CyberPower 1500 over USB, while my two unraid servers are network slave clients. Worked great after adding the NAT rule in the OP :-)
-
@cybrnook you are most welcome.
It’s really nice when people say thank you.
-
@dennypage said in NUT package:
@cybrnook you are most welcome.
It’s really nice when people say thank you.
Absolutely! It's my pleasure. Now just to figure out how to add multiple source IP's to the NAT rule, since I have 3 x clients I want to be able to phone home. Maybe it's just as simple as creating one NAT rule per IP :-) And see if you baked in "monuser" for Synology by default :-) since that will be my third.
EDIT: Synology was no problem. Just had to add monuser to the upsd.users with secret, and rename the UPS to "ups" in pfsense. Redid my Unraid systems with the same info, and it's all back online
-
Hi @dennypage - a big thank you from me as well! I came across a blog post today that detailed installing the NUT package on pfSense. Looking at the NUT compatibility list I saw that the the CyberPower UPS that I am using is actually supported. So I went ahead and hooked up the USB connection from the UPS to the firewall, installed the NUT package, and got everything setup and working inside pfSense. After that I also configured my Proxmox box and Synology NAS as slaves (thanks to everyone for all the great tips and advice in this thread!). Everything is working great so far. I went over two years with this same hardware not realizing that I could actually setup and utilize NUT -- very happy I found about the project today and the pfSense package.
I do have one basic quick question for everyone: When setting up NUT (e.g. slaves and on the master) how is the UPS critical battery threshold or shutdown time to determined (i.e. when connected devices are given the signal to shut down)? If this parameter adjustable in the configuration files (e.g. on the master) or is there a default value that's used? In other words, with the default out of the box NUT setup and configuration, will connected devices be given plenty of time to shut down? Thanks in advance for your help, I really appreciate it.
-
@tman222 By default, the level at which shutdown will occur is under control of the ups. The ups sends a "low battery" signal, and nut initiates a shutdown.
Generally the low battery signal is sufficient for single host systems, however if you find the ups runs out of battery before shutdown completes you can override the behavior. See the nut variables "battery.charge.low"
and "battery.runtime.low".Important note... some slaves, particularly Synology, take a long time to shutdown. After changing the runtime values, you will want to increase the "HOSTSYNC" variable. The default of 15 is far too short to allow a Synology to complete a shutdown.
Here is what I use on my server:
[Extra Arguments to driver]
override.battery.charge.low = 20
override.battery.runtime.low = 300[Additional configuration lines for upsmon.conf]
HOSTSYNC 120 -
@dennypage - thanks a bunch for this additional information. I was able to find a reference to the variables you mentioned and read up a bit:
https://networkupstools.org/docs/user-manual.chunked/apcs01.html
I had a one quick follow up question: Regarding the two variables you overrode (battery.charge.low and battery.runtime.low): Is it whichever of the two occurs first that then triggers the LB state and causes NUT to issues the shutdown signal? That is to say, in your case, when the battery drops to 20% charge OR has 300 seconds of run time remaining, the LB state is triggered and NUT begins shutdown process begins?
Thanks again for the help and clarification, I really appreciate it.
-
@tman222 said in NUT package:
Regarding the two variables you overrode (battery.charge.low and battery.runtime.low): Is it whichever of the two occurs first that then triggers the LB state and causes NUT to issues the shutdown signal? That is to say, in your case, when the battery drops to 20% charge OR has 300 seconds of run time remaining, the LB state is triggered and NUT begins shutdown process begins?
Thanks again for the help and clarification, I really appreciate it.
Yes, you are correct. 20% or 300 seconds, whichever happens first.
You're welcome!
-
@dennypage said in NUT package:
@kevindd992002 said in NUT package:
Doing a quick test yielded a "done and passed" result for the last test result field. However, when I tried doing a deep test, the CLI returned an OK message but the UPS did nothing. Does that mean that the command is not supported by my UPS? I'm still receiving low battery message notifications in my email regarding this UPS.
Have to try it with your other UPS, but my guess would be that the UPS is declining to initiate the deep test (which usually includes a battery calibration) because it has a low battery condition. Usually a deep test will not initiate on anything other than a completely full battery.
Best suggestion that I could make is to completely power off the UPS and restart it from the ground up. If that doesn't fix it, I would say that it's likely that the UPS or battery is defective.
I have yet to test this with my other working UPS but with the problematic UPS I also get this:
So I get input voltage out of range even though the input is around 228V now, both in the UPS display and using a voltmeter. So what gives? It looks like the UPS is transferring to battery even though it shouldn't?
-
@dennypage said in NUT package:
@kevindd992002 In your case it looks like a change of state for OpenVPN interfaces. I'm sorry I don't know much beyond this. If you want to explore more, I'd suggest asking in the General pfSense Questions or OpenVPN groups.
I'm not sure if the upsmon parent process died error was the one causing this, but my Synology NUT slave did not shutdown properly when there was a blackout earlier. I was not on-site so I'm just depending on the logs and email notifications I get. First of all, I got pfsense email notifications of the following:
- ups on battery -> Sat, 15 Jun 2019 12:05:24 +0800
- ups on line power -> Sat, 15 Jun 2019 12:17:22 +0800
- Bootup complete -> 13:14:05
And here are the pfsense ups logs:
Jun 14 18:55:20 upsmon 40927 UPS ups on battery Jun 14 19:07:23 upsmon 40927 UPS ups on line power Jun 14 19:07:33 upsmon 40927 UPS ups on battery Jun 14 19:10:15 upsmon 40927 UPS ups battery is low Jun 14 19:10:15 upsd 58260 Client local-monitor@::1 set FSD on UPS [ups] Jun 14 20:10:29 kernel ugen0.2: <American Power Conversion Back-UPS RS 1500G FW878.L4 .I USB FWL4> at usbus0 Jun 14 20:10:53 upsd 78154 Connected to UPS [ups]: usbhid-ups-ups Jun 14 20:10:56 upsd 24337 Connected to UPS [ups]: usbhid-ups-ups Jun 14 20:10:58 upsd 25161 User local-monitor@::1 logged into UPS [ups] Jun 14 20:11:17 upsd 25161 User local-monitor@::1 logged out from UPS [ups] Jun 14 20:11:18 upsd 31254 Connected to UPS [ups]: usbhid-ups-ups Jun 14 20:11:21 upsd 24874 Connected to UPS [ups]: usbhid-ups-ups Jun 14 20:11:23 upsd 25175 User local-monitor@::1 logged into UPS [ups] Jun 14 20:11:24 upsd 25175 User local-monitor@::1 logged out from UPS [ups] Jun 14 20:11:25 upsd 93544 Connected to UPS [ups]: usbhid-ups-ups Jun 14 20:11:28 upsd 84598 Connected to UPS [ups]: usbhid-ups-ups Jun 14 20:11:30 upsd 84882 User local-monitor@127.0.0.1 logged into UPS [ups] Jun 14 20:11:30 upsmon 55413 upsmon parent process died - shutdown impossible Jun 14 20:11:31 upsd 12323 Connected to UPS [ups]: usbhid-ups-ups Jun 14 20:11:33 upsd 13583 User local-monitor@::1 logged into UPS [ups] Jun 14 20:11:34 upsd 50344 Connected to UPS [ups]: usbhid-ups-ups Jun 14 20:11:36 upsd 52255 User local-monitor@::1 logged into UPS [ups] Jun 14 20:11:37 upsd 52255 User local-monitor@::1 logged out from UPS [ups] Jun 14 20:11:39 upsd 65039 Connected to UPS [ups]: usbhid-ups-ups Jun 14 20:11:40 upsd 65095 User local-monitor@::1 logged into UPS [ups] Jun 14 20:11:42 upsd 75747 Connected to UPS [ups]: usbhid-ups-ups Jun 14 20:11:44 upsd 75891 User local-monitor@::1 logged into UPS [ups] Jun 14 20:26:07 upsmon 73025 UPS ups on battery Jun 14 20:26:17 upsmon 73025 UPS ups on line power Jun 15 13:13:40 kernel ugen0.2: <American Power Conversion Back-UPS RS 1500G FW878.L4 .I USB FWL4> at usbus0 Jun 15 13:14:06 upsd 70280 Connected to UPS [ups]: usbhid-ups-ups Jun 15 13:14:10 upsd 99152 Connected to UPS [ups]: usbhid-ups-ups Jun 15 13:14:12 upsd 99790 User local-monitor@::1 logged into UPS [ups] Jun 15 13:14:26 upsd 99790 User local-monitor@::1 logged out from UPS [ups] Jun 15 13:14:28 upsd 12824 Connected to UPS [ups]: usbhid-ups-ups Jun 15 13:14:30 upsd 12827 User local-monitor@::1 logged into UPS [ups] Jun 15 13:14:31 upsd 24418 Connected to UPS [ups]: usbhid-ups-ups Jun 15 13:14:33 upsd 24437 User local-monitor@::1 logged into UPS [ups] Jun 15 13:14:54 upsd 24437 User local-monitor@::1 logged out from UPS [ups] Jun 15 13:14:56 upsd 74194 Connected to UPS [ups]: usbhid-ups-ups Jun 15 13:14:58 upsd 74325 User local-monitor@::1 logged into UPS [ups] Jun 15 13:14:59 upsd 90516 Connected to UPS [ups]: usbhid-ups-ups Jun 15 13:15:01 upsd 90761 User local-monitor@::1 logged into UPS [ups]
As you can see, there are no logs showing that the ups changed to battery power and that initiated a shutdown. I'm assuming that the battery just drained out and did not notify any clients to gracefully shutdown, hence the improper shutdown message I got from my Synology UPS.
Any ideas regarding this?
Also, is it normal that I can't find any logs for the monuser client (the Synology NAS) connecting and disconnecting to the pfsense NUT master? I see logs like that when a Windows machine NUT service is connecting to pfsense master but not when a Synology NAS does it. Don't get me wrong though, the Synology NAS connects to it just fine and shuts down properly until today, but I never got the monuser logs.
-
@kevindd992002 said in NUT package:
I have yet to test this with my other working UPS but with the problematic UPS I also get this:
So I get input voltage out of range even though the input is around 228V now, both in the UPS display and using a voltmeter. So what gives? It looks like the UPS is transferring to battery even though it shouldn't?
This in and of itself isn't problematic. Many of the UPSs I've worked with save the last reason state in perpetuity. This just means that it happened sometime in the past.
-
@kevindd992002 said in NUT package:
Jun 14 19:10:15 upsmon 40927 UPS ups battery is low
There are messaging in the log... but the timestamps don't match what you had for email. If you still have the emails, check in the body of the message for the timestamp as viewed by the pfSense box when the even happened.
As to the Synology, there probably isn't enough time for it to shutdown. See the conversation with @tman222 above about HOSTSYNC.
-
@dennypage said in NUT package:
@kevindd992002 said in NUT package:
I have yet to test this with my other working UPS but with the problematic UPS I also get this:
So I get input voltage out of range even though the input is around 228V now, both in the UPS display and using a voltmeter. So what gives? It looks like the UPS is transferring to battery even though it shouldn't?
This in and of itself isn't problematic. Many of the UPSs I've worked with save the last reason state in perpetuity. This just means that it happened sometime in the past.
Ok, that makes sense. But if it was the battery that's causing the problem, why would it show 100% charge and yet still give me a battery low message? Cosmetics issue perhaps?
@dennypage said in NUT package:
@kevindd992002 said in NUT package:
Jun 14 19:10:15 upsmon 40927 UPS ups battery is low
There are messaging in the log... but the timestamps don't match what you had for email. If you still have the emails, check in the body of the message for the timestamp as viewed by the pfSense box when the even happened.
As to the Synology, there probably isn't enough time for it to shutdown. See the conversation with @tman222 above about HOSTSYNC.
I should've said, the timestamp I gave you were the timestamps in the body of the emails, not the email timestamps themselves. And yes, there are messaging logs like you pointed out and I did receive separate (earlier) emails for those. For some reason, I cannot find the latest messaging logs for the events that I'm referring to but I did get email notifications about them.
As for the Synology issue, well it was shutting down and waking up correctly for the past few months until recently when this whole issue started. Could that still be because of HOSTSYNC? Also, you'd have to consider that I didn't see a message log saying that an auto shutdown was initiated at all. So naturally, the Synology NAS was not given the message to shut itself down. Here's another snippet of the logs showing more:
Jun 14 18:55:20 upsmon 40927 UPS ups on battery Jun 14 19:07:23 upsmon 40927 UPS ups on line power Jun 14 19:07:33 upsmon 40927 UPS ups on battery Jun 14 19:10:15 upsmon 40927 UPS ups battery is low Jun 14 19:10:15 upsd 58260 Client local-monitor@::1 set FSD on UPS [ups] Jun 14 19:10:15 upsmon 40927 Executing automatic power-fail shutdown Jun 14 19:10:15 upsmon 40927 Auto logout and shutdown proceeding Jun 14 20:10:54 upsmon 33616 Startup successful Jun 14 20:10:53 usbhid-ups 54715 Startup successful Jun 14 20:10:53 upsd 78154 listening on 192.168.55.1 port 3493 Jun 14 20:10:53 upsd 78154 listening on 192.168.10.1 port 3493 Jun 14 20:10:53 upsd 78154 listening on ::1 port 3493 Jun 14 20:10:53 upsd 78154 listening on 127.0.0.1 port 3493 Jun 14 20:10:53 upsd 78154 Connected to UPS [ups]: usbhid-ups-ups Jun 14 20:10:53 upsd 78876 Startup successful Jun 14 20:10:55 upsmon 74846 Startup successful Jun 14 20:10:56 usbhid-ups 5320 Startup successful Jun 14 20:10:56 upsd 24337 listening on 192.168.55.1 port 3493 Jun 14 20:10:56 upsd 24337 listening on 192.168.10.1 port 3493 Jun 14 20:10:56 upsd 24337 listening on ::1 port 3493 Jun 14 20:10:56 upsd 24337 listening on 127.0.0.1 port 3493 Jun 14 20:10:56 upsd 24337 Connected to UPS [ups]: usbhid-ups-ups Jun 14 20:10:56 upsd 25161 Startup successful Jun 14 20:10:58 upsd 25161 User local-monitor@::1 logged into UPS [ups] Jun 14 20:11:17 upsmon 75804 Signal 15: exiting Jun 14 20:11:17 upsd 25161 User local-monitor@::1 logged out from UPS [ups] Jun 14 20:11:17 upsd 25161 mainloop: Interrupted system call Jun 14 20:11:17 upsd 25161 Signal 15: exiting Jun 14 20:11:17 usbhid-ups 5320 Signal 15: exiting Jun 14 20:11:17 upsmon 86305 Startup successful Jun 14 20:11:18 usbhid-ups 15003 Startup successful Jun 14 20:11:18 upsd 31254 listening on 192.168.55.1 port 3493 Jun 14 20:11:18 upsd 31254 listening on 192.168.10.1 port 3493 Jun 14 20:11:18 upsd 31254 listening on ::1 port 3493 Jun 14 20:11:18 upsd 31254 listening on 127.0.0.1 port 3493 Jun 14 20:11:18 upsd 31254 Connected to UPS [ups]: usbhid-ups-ups Jun 14 20:11:18 upsd 32645 Startup successful Jun 14 20:11:20 upsmon 7910 Startup successful Jun 14 20:11:21 usbhid-ups 17613 Startup successful Jun 14 20:11:21 upsd 24874 listening on 192.168.55.1 port 3493 Jun 14 20:11:21 upsd 24874 listening on 192.168.10.1 port 3493 Jun 14 20:11:21 upsd 24874 listening on ::1 port 3493 Jun 14 20:11:21 upsd 24874 listening on 127.0.0.1 port 3493 Jun 14 20:11:21 upsd 24874 Connected to UPS [ups]: usbhid-ups-ups Jun 14 20:11:21 upsd 25175 Startup successful Jun 14 20:11:23 upsd 25175 User local-monitor@::1 logged into UPS [ups] Jun 14 20:11:24 upsmon 8776 Signal 15: exiting Jun 14 20:11:24 upsd 25175 User local-monitor@::1 logged out from UPS [ups] Jun 14 20:11:24 upsd 25175 mainloop: Interrupted system call Jun 14 20:11:24 upsd 25175 Signal 15: exiting Jun 14 20:11:24 usbhid-ups 17613 Signal 15: exiting Jun 14 20:11:24 upsmon 85759 Startup successful Jun 14 20:11:25 usbhid-ups 90634 Startup successful Jun 14 20:11:25 upsd 93544 listening on 192.168.55.1 port 3493 Jun 14 20:11:25 upsd 93544 listening on 192.168.10.1 port 3493 Jun 14 20:11:25 upsd 93544 listening on ::1 port 3493 Jun 14 20:11:25 upsd 93544 listening on 127.0.0.1 port 3493 Jun 14 20:11:25 upsd 93544 Connected to UPS [ups]: usbhid-ups-ups Jun 14 20:11:25 upsd 93726 Startup successful Jun 14 20:11:27 upsmon 54332 Startup successful Jun 14 20:11:28 usbhid-ups 82393 Startup successful Jun 14 20:11:28 upsd 84598 listening on 192.168.55.1 port 3493 Jun 14 20:11:28 upsd 84598 listening on 192.168.10.1 port 3493 Jun 14 20:11:28 upsd 84598 listening on ::1 port 3493 Jun 14 20:11:28 upsd 84598 listening on 127.0.0.1 port 3493 Jun 14 20:11:28 upsd 84598 Connected to UPS [ups]: usbhid-ups-ups Jun 14 20:11:28 upsd 84882 Startup successful Jun 14 20:11:30 upsd 84882 User local-monitor@127.0.0.1 logged into UPS [ups] Jun 14 20:11:30 upsmon 55413 upsmon parent process died - shutdown impossible Jun 14 20:11:30 upsmon 55413 Parent died - shutdown impossible Jun 14 20:11:30 upsd 84882 mainloop: Interrupted system call Jun 14 20:11:30 upsd 84882 Signal 15: exiting Jun 14 20:11:30 usbhid-ups 82393 Signal 15: exiting Jun 14 20:11:30 upsmon 50205 Startup successful Jun 14 20:11:31 usbhid-ups 96450 Startup successful Jun 14 20:11:31 upsd 12323 listening on 192.168.55.1 port 3493 Jun 14 20:11:31 upsd 12323 listening on 192.168.10.1 port 3493 Jun 14 20:11:31 upsd 12323 listening on ::1 port 3493 Jun 14 20:11:31 upsd 12323 listening on 127.0.0.1 port 3493 Jun 14 20:11:31 upsd 12323 Connected to UPS [ups]: usbhid-ups-ups Jun 14 20:11:31 upsd 13583 Startup successful Jun 14 20:11:33 upsd 13583 User local-monitor@::1 logged into UPS [ups] Jun 14 20:11:33 upsmon 23508 Startup successful Jun 14 20:11:34 usbhid-ups 29129 Startup successful Jun 14 20:11:34 upsd 50344 listening on 192.168.55.1 port 3493 Jun 14 20:11:34 upsd 50344 listening on 192.168.10.1 port 3493 Jun 14 20:11:34 upsd 50344 listening on ::1 port 3493 Jun 14 20:11:34 upsd 50344 listening on 127.0.0.1 port 3493 Jun 14 20:11:34 upsd 50344 Connected to UPS [ups]: usbhid-ups-ups Jun 14 20:11:34 upsd 52255 Startup successful Jun 14 20:11:36 upsd 52255 User local-monitor@::1 logged into UPS [ups] Jun 14 20:11:37 upsmon 23951 Signal 15: exiting Jun 14 20:11:37 upsd 52255 User local-monitor@::1 logged out from UPS [ups] Jun 14 20:11:37 upsd 52255 mainloop: Interrupted system call Jun 14 20:11:37 upsd 52255 Signal 15: exiting Jun 14 20:11:37 usbhid-ups 29129 Signal 15: exiting Jun 14 20:11:37 upsmon 55886 Startup successful Jun 14 20:11:38 usbhid-ups 64728 Startup successful Jun 14 20:11:39 upsd 65039 listening on 192.168.55.1 port 3493 Jun 14 20:11:39 upsd 65039 listening on 192.168.10.1 port 3493 Jun 14 20:11:39 upsd 65039 listening on ::1 port 3493 Jun 14 20:11:39 upsd 65039 listening on 127.0.0.1 port 3493 Jun 14 20:11:39 upsd 65039 Connected to UPS [ups]: usbhid-ups-ups Jun 14 20:11:39 upsd 65095 Startup successful Jun 14 20:11:40 upsd 65095 User local-monitor@::1 logged into UPS [ups] Jun 14 20:11:41 upsmon 72255 Startup successful Jun 14 20:11:41 usbhid-ups 74310 Startup successful Jun 14 20:11:42 upsd 75747 listening on 192.168.55.1 port 3493 Jun 14 20:11:42 upsd 75747 listening on 192.168.10.1 port 3493 Jun 14 20:11:42 upsd 75747 listening on ::1 port 3493 Jun 14 20:11:42 upsd 75747 listening on 127.0.0.1 port 3493 Jun 14 20:11:42 upsd 75747 Connected to UPS [ups]: usbhid-ups-ups Jun 14 20:11:42 upsd 75891 Startup successful Jun 14 20:11:44 upsd 75891 User local-monitor@::1 logged into UPS [ups] Jun 14 20:26:07 upsmon 73025 UPS ups on battery Jun 14 20:26:17 upsmon 73025 UPS ups on line power Jun 15 13:14:07 upsmon 57800 Startup successful Jun 15 13:14:07 usbhid-ups 59029 Startup successful Jun 15 13:14:06 upsd 70280 listening on 192.168.55.1 port 3493 Jun 15 13:14:06 upsd 70280 listening on 192.168.10.1 port 3493 Jun 15 13:14:06 upsd 70280 listening on ::1 port 3493 Jun 15 13:14:06 upsd 70280 listening on 127.0.0.1 port 3493 Jun 15 13:14:06 upsd 70280 Connected to UPS [ups]: usbhid-ups-ups Jun 15 13:14:06 upsd 70814 Startup successful Jun 15 13:14:08 upsmon 55711 Startup successful Jun 15 13:14:09 usbhid-ups 85269 Startup successful Jun 15 13:14:10 upsd 99152 listening on 192.168.55.1 port 3493 Jun 15 13:14:10 upsd 99152 listening on 192.168.10.1 port 3493 Jun 15 13:14:10 upsd 99152 listening on ::1 port 3493 Jun 15 13:14:10 upsd 99152 listening on 127.0.0.1 port 3493 Jun 15 13:14:10 upsd 99152 Connected to UPS [ups]: usbhid-ups-ups Jun 15 13:14:10 upsd 99790 Startup successful Jun 15 13:14:12 upsd 99790 User local-monitor@::1 logged into UPS [ups] Jun 15 13:14:26 upsmon 55752 Signal 15: exiting Jun 15 13:14:26 upsd 99790 User local-monitor@::1 logged out from UPS [ups] Jun 15 13:14:26 upsd 99790 mainloop: Interrupted system call Jun 15 13:14:26 upsd 99790 Signal 15: exiting Jun 15 13:14:26 usbhid-ups 85269 Signal 15: exiting Jun 15 13:14:27 upsmon 4336 Startup successful Jun 15 13:14:27 usbhid-ups 12301 Startup successful Jun 15 13:14:28 upsd 12824 listening on 192.168.55.1 port 3493 Jun 15 13:14:28 upsd 12824 listening on 192.168.10.1 port 3493 Jun 15 13:14:28 upsd 12824 listening on ::1 port 3493 Jun 15 13:14:28 upsd 12824 listening on 127.0.0.1 port 3493 Jun 15 13:14:28 upsd 12824 Connected to UPS [ups]: usbhid-ups-ups Jun 15 13:14:28 upsd 12827 Startup successful Jun 15 13:14:30 upsd 12827 User local-monitor@::1 logged into UPS [ups] Jun 15 13:14:30 upsmon 20757 Startup successful Jun 15 13:14:30 usbhid-ups 23572 Startup successful Jun 15 13:14:31 upsd 24418 listening on 192.168.55.1 port 3493 Jun 15 13:14:31 upsd 24418 listening on 192.168.10.1 port 3493 Jun 15 13:14:31 upsd 24418 listening on ::1 port 3493 Jun 15 13:14:31 upsd 24418 listening on 127.0.0.1 port 3493 Jun 15 13:14:31 upsd 24418 Connected to UPS [ups]: usbhid-ups-ups Jun 15 13:14:31 upsd 24437 Startup successful Jun 15 13:14:33 upsd 24437 User local-monitor@::1 logged into UPS [ups] Jun 15 13:14:54 upsmon 22016 Signal 15: exiting Jun 15 13:14:54 upsd 24437 User local-monitor@::1 logged out from UPS [ups] Jun 15 13:14:54 upsd 24437 mainloop: Interrupted system call Jun 15 13:14:54 upsd 24437 Signal 15: exiting Jun 15 13:14:54 usbhid-ups 23572 Signal 15: exiting Jun 15 13:14:55 upsmon 70818 Startup successful Jun 15 13:14:55 usbhid-ups 72602 Startup successful Jun 15 13:14:56 upsd 74194 listening on 192.168.55.1 port 3493 Jun 15 13:14:56 upsd 74194 listening on 192.168.10.1 port 3493 Jun 15 13:14:56 upsd 74194 listening on ::1 port 3493 Jun 15 13:14:56 upsd 74194 listening on 127.0.0.1 port 3493 Jun 15 13:14:56 upsd 74194 Connected to UPS [ups]: usbhid-ups-ups Jun 15 13:14:56 upsd 74325 Startup successful Jun 15 13:14:58 upsd 74325 User local-monitor@::1 logged into UPS [ups] Jun 15 13:14:58 upsmon 87512 Startup successful Jun 15 13:14:58 usbhid-ups 90187 Startup successful Jun 15 13:14:59 upsd 90516 listening on 192.168.55.1 port 3493 Jun 15 13:14:59 upsd 90516 listening on 192.168.10.1 port 3493 Jun 15 13:14:59 upsd 90516 listening on ::1 port 3493 Jun 15 13:14:59 upsd 90516 listening on 127.0.0.1 port 3493 Jun 15 13:14:59 upsd 90516 Connected to UPS [ups]: usbhid-ups-ups Jun 15 13:14:59 upsd 90761 Startup successful Jun 15 13:15:01 upsd 90761 User local-monitor@::1 logged into UPS [ups] Jun 15 18:25:18 upsmon 88045 Signal 15: exiting Jun 15 18:25:18 upsd 90761 User local-monitor@::1 logged out from UPS [ups] Jun 15 18:25:18 upsd 90761 mainloop: Interrupted system call Jun 15 18:25:18 upsd 90761 Signal 15: exiting Jun 15 18:25:18 upsmon 60536 Startup successful Jun 15 18:25:19 usbhid-ups 62298 Startup successful Jun 15 18:25:20 upsd 62515 listening on 192.168.55.1 port 3493 Jun 15 18:25:20 upsd 62515 listening on 192.168.10.1 port 3493 Jun 15 18:25:20 upsd 62515 listening on ::1 port 3493 Jun 15 18:25:20 upsd 62515 listening on 127.0.0.1 port 3493 Jun 15 18:25:20 upsd 62515 Connected to UPS [ups]: usbhid-ups-ups Jun 15 18:25:20 upsd 62558 Startup successful Jun 15 18:25:21 upsd 62558 User local-monitor@::1 logged into UPS [ups]
You can see that I had an auto shutdown even occur here:
Jun 14 19:10:15 upsmon 40927 Executing automatic power-fail shutdown Jun 14 19:10:15 upsmon 40927 Auto logout and shutdown proceeding
But I didn't get those logs for the June 15 event that I'm talking about.
-
@kevindd992002 said in NUT package:
Jun 14 18:55:20 upsmon 40927 UPS ups on battery
Jun 14 19:07:23 upsmon 40927 UPS ups on line power
Jun 14 19:07:33 upsmon 40927 UPS ups on battery
Jun 14 19:10:15 upsmon 40927 UPS ups battery is lowAlso possible that the UPS killed the mains before shutdown completed. You may want to up the battery runtime/charge low values.
You definitely want to have a higher HOSTSYNC to give the Synology time for shutdown.
-
@dennypage said in NUT package:
@kevindd992002 said in NUT package:
Jun 14 18:55:20 upsmon 40927 UPS ups on battery
Jun 14 19:07:23 upsmon 40927 UPS ups on line power
Jun 14 19:07:33 upsmon 40927 UPS ups on battery
Jun 14 19:10:15 upsmon 40927 UPS ups battery is lowAlso possible that the UPS killed the mains before shutdown completed. You may want to up the battery runtime/charge low values.
You definitely want to have a higher HOSTSYNC to give the Synology time for shutdown.
Regardless though, shouldn't I see an auto shutdown message when NUT reaches the cutoff charge level?
So 120 for HOSTSYNC would be recommended for Synology? What does that parameter really do anyway?
-
@kevindd992002 said in NUT package:
Regardless though, shouldn't I see an auto shutdown message when NUT reaches the cutoff charge level?
It shows a low battery situation, but the UPS could have cut the mains before pfSense had opportunity to perform a shutdown. Was the battery depleted from a prior event perhaps?
So 120 for HOSTSYNC would be recommended for Synology? What does that parameter really do anyway?
HOSTSYNC is how many seconds the master will wait for slaves to initiate their shutdown and disconnect from the master. See the documentation for upsmon.conf for more information.
-
@dennypage said in NUT package:
@kevindd992002 said in NUT package:
Regardless though, shouldn't I see an auto shutdown message when NUT reaches the cutoff charge level?
It shows a low battery situation, but the UPS could have cut the mains before pfSense had opportunity to perform a shutdown. Was the battery depleted from a prior event perhaps?
So 120 for HOSTSYNC would be recommended for Synology? What does that parameter really do anyway?
HOSTSYNC is how many seconds the master will wait for slaves to initiate their shutdown and disconnect from the master. See the documentation for upsmon.conf for more information.
What do you mean by "it shows a low battery situation"? I don't see that in the June 15 logs. Sorry I'm confused. The UPS started charging (on online power) since June 14 8:26PM so I'm pretty sure it's fully charged by the it notified me via email on June 15 12:00PM. I also asked my relatives which are on-site and they confirmed that electricity only went out once on June 15.
-
@kevindd992002 said in NUT package:
What do you mean by "it shows a low battery situation"? I don't see that in the June 15 logs. Sorry I'm confused. The UPS started charging (on online power) since June 14 8:26PM so I'm pretty sure it's fully charged by the it notified me via email on June 15 12:00PM. I also asked my relatives which are on-site and they confirmed that electricity only went out once on June 15.
Sorry, was reading low battery situation on the 14th.
Most likely guess regarding the 15th is that the UPS failed the mains before the system properly flushed the disk log.
Things I would suggest:
- If the battery is over three years old, replace it.
- If the battery has been through two hundred discharge cycles or more, replace it.
- Perform a battery health check (long self test).
- Perform a run-time calibration (note this counts as a cycle).
- Raise the values for charge.low and runtime.low.
If power outages are common, I would go very high on charge.low (50 or more). Remember that regardless of age, a battery will only last 200 discharge cycles or so, so the higher you set the value the longer your battery will last.
-
@dennypage said in NUT package:
@kevindd992002 said in NUT package:
What do you mean by "it shows a low battery situation"? I don't see that in the June 15 logs. Sorry I'm confused. The UPS started charging (on online power) since June 14 8:26PM so I'm pretty sure it's fully charged by the it notified me via email on June 15 12:00PM. I also asked my relatives which are on-site and they confirmed that electricity only went out once on June 15.
Sorry, was reading low battery situation on the 14th.
Most likely guess regarding the 15th is that the UPS failed the mains before the system properly flushed the disk log.
Things I would suggest:
- If the battery is over three years old, replace it.
- If the battery has been through two hundred discharge cycles or more, replace it.
- Perform a battery health check (long self test).
- Perform a run-time calibration (note this counts as a cycle).
- Raise the values for charge.low and runtime.low.
If power outages are common, I would go very high on charge.low (50 or more). Remember that regardless of age, a battery will only last 200 discharge cycles or so, so the higher you set the value the longer your battery will last.
The battery is less than a year old and I doubt it had already gone to two hundred discharge cycles. The power outages are more frequent than what I would like them to be, yes, but not very frequent to render the batteries useless in less than a year. But yeah, I'll probably do some tests first by changing the charge.low and runtime.low. I had multiple notifications again these past few days and I'm still encountering the same issue. Here's another example of my pfsense logs:
Jun 16 16:24:38 upsd 19563 User local-monitor@::1 logged into UPS [ups] Jun 16 16:25:33 upsd 19563 User local-monitor@::1 logged out from UPS [ups] Jun 16 16:28:35 kernel ugen0.2: <American Power Conversion Back-UPS RS 1500G FW878.L4 .I USB FWL4> at usbus0 Jun 16 16:29:05 upsd 58612 Connected to UPS [ups]: usbhid-ups-ups Jun 16 16:29:08 upsd 60154 Connected to UPS [ups]: usbhid-ups-ups Jun 16 16:29:10 upsd 61918 User local-monitor@::1 logged into UPS [ups] Jun 16 16:29:24 upsd 61918 User local-monitor@::1 logged out from UPS [ups] Jun 16 16:29:25 upsd 61474 Connected to UPS [ups]: usbhid-ups-ups Jun 16 16:29:28 upsd 73800 Connected to UPS [ups]: usbhid-ups-ups Jun 16 16:29:30 upsd 74128 User local-monitor@::1 logged into UPS [ups] Jun 16 16:29:55 upsd 74128 User local-monitor@::1 logged out from UPS [ups] Jun 16 16:29:56 upsd 24686 Connected to UPS [ups]: usbhid-ups-ups Jun 16 16:29:59 upsd 39315 Connected to UPS [ups]: usbhid-ups-ups Jun 16 16:30:01 upsd 39480 User local-monitor@::1 logged into UPS [ups] Jun 22 11:00:26 upsmon 37375 UPS ups on battery Jun 22 11:00:31 upsmon 37375 UPS ups on line power Jun 22 17:03:06 upsmon 37375 UPS ups on battery Jun 22 17:03:16 upsmon 37375 UPS ups on line power Jun 22 17:43:38 upsmon 37375 UPS ups on battery Jun 22 17:43:43 upsmon 37375 UPS ups on line power Jun 23 09:09:32 upsmon 37375 UPS ups on battery Jun 23 09:28:27 upsmon 37375 UPS ups battery is low Jun 23 09:28:27 upsd 39480 Client local-monitor@::1 set FSD on UPS [ups] Jun 23 12:48:03 kernel ugen0.2: <American Power Conversion Back-UPS RS 1500G FW878.L4 .I USB FWL4> at usbus0 Jun 23 12:48:28 upsd 80605 Connected to UPS [ups]: usbhid-ups-ups Jun 23 12:48:31 upsd 62181 Connected to UPS [ups]: usbhid-ups-ups Jun 23 12:48:33 upsd 63842 User local-monitor@::1 logged into UPS [ups] Jun 23 12:48:50 upsd 63842 User local-monitor@::1 logged out from UPS [ups] Jun 23 12:48:51 upsd 6953 Connected to UPS [ups]: usbhid-ups-ups Jun 23 12:48:54 upsd 29664 Connected to UPS [ups]: usbhid-ups-ups Jun 23 12:48:56 upsd 32261 User local-monitor@::1 logged into UPS [ups] Jun 23 12:49:01 upsd 32261 User local-monitor@::1 logged out from UPS [ups] Jun 23 12:49:02 upsd 99676 Connected to UPS [ups]: usbhid-ups-ups Jun 23 12:49:05 upsd 51055 Connected to UPS [ups]: usbhid-ups-ups Jun 23 12:49:06 upsd 52551 User local-monitor@127.0.0.1 logged into UPS [ups] Jun 23 12:49:06 upsmon 40995 upsmon parent process died - shutdown impossible Jun 23 12:49:07 upsd 3258 Connected to UPS [ups]: usbhid-ups-ups Jun 23 12:49:10 upsd 10461 Connected to UPS [ups]: usbhid-ups-ups Jun 23 12:49:11 upsd 11087 User local-monitor@127.0.0.1 logged into UPS [ups] Jun 23 12:49:11 upsmon 59547 upsmon parent process died - shutdown impossible Jun 23 12:49:12 upsd 6285 Connected to UPS [ups]: usbhid-ups-ups Jun 23 12:49:15 upsd 50671 Connected to UPS [ups]: usbhid-ups-ups Jun 23 12:49:17 upsd 50757 User local-monitor@::1 logged into UPS [ups] Jun 23 12:49:18 upsd 50757 User local-monitor@::1 logged out from UPS [ups] Jun 23 12:49:19 upsd 74517 Connected to UPS [ups]: usbhid-ups-ups Jun 23 12:49:21 upsd 74650 User local-monitor@::1 logged into UPS [ups] Jun 23 12:49:22 upsd 1480 Connected to UPS [ups]: usbhid-ups-ups Jun 23 12:49:24 upsd 2139 User local-monitor@::1 logged into UPS [ups] Jun 23 13:09:43 upsmon 81543 UPS ups on battery Jun 23 13:09:48 upsmon 81543 UPS ups on line power
Then I receive this in my email:
Sun, 23 Jun 2019 09:28:28 +0800
Auto logout and shutdown proceeding
But in the Synology NAS logs, I see an improper shutdown event for this time. So something's not right because the NAS is not shutting down properly even though I have HOSTSYNC set to 120 already.
Also, is it normal that I can't find any logs for the monuser client (the Synology NAS) connecting and disconnecting to the pfsense NUT master? I see logs like that when a Windows machine NUT service is connecting to pfsense master but not when a Synology NAS does it. Don't get me wrong though, the Synology NAS connects to it just fine and shuts down properly until today, but I never got the monuser logs.
EDIT:
Look at my Synology logs:
So it's interesting that I no longer see a Power supply event that the ups entered battery mode/returned to AC mode/etc. This explains why the NAS isn't shutting down properly. It's not receiving the appropriate signals from the NUT master even though I completely see it connected in the "Device Information" section like so:
What other things can I do to troubleshoot this then?
-
Any other ideas to try?
-
@kevindd992002 Sorry, I'm getting ready for a long distance move and haven't had much time lately.
The lack of entries in the pfSense system log regarding the remote client would indicate that the Synology isn't actually connecting to upsd on pfSense. You can do a reboot on your Synology to confirm. You should see log out/in messages in the pfSense system log each time.
Another way to confirm... stop the ups service on pfSense. The Synology should get upset and start sending emails complaining that the ups isn't available.
Lastly, if memory serves, there is a setting in the Synology that allows you to have the Synology shutdown with the server or after a given period of time. If it's not set to match the server then the Synology will ignore the FSD signal from the server.
I haven't had time to set up an experiment with my Synology to see if later versions of DSM have mucked up the nut implementation in some way.