NUT package (2.8.0 and below)

dennypage

I don't think you are doing anything wrong per se. By default, the nut slave (pfSense) isn't going to initiate a shutdown until the master server declares a low battery condition. This is different than a low battery warning.

When the master declares a low battery condition, it will send a notification to all the slaves indicating that there is a pending loss of power. The slaves will each disconnect from the master and then initiate their own shutdown. Once all the slaves have disconnected, the master will initiate its own shutdown.

If you want to override how the master determines when to declare a low battery condition, see the section on "ignorelb" in the ups.conf man page.

bdf0506

@bdf0506:

@dennypage:

I have. The power kill logic is gone from the base os level. Still searching to find out when and why.

Ah, interesting. Sounds like it isn't an issue with my specific setup and it is a bug affecting anyone trying to use that functionality in the NUT package. Looking forward to seeing a fix for this whenever one can be found.

Hi, I wanted to see if there has been any progress on fixing this issue? Thanks.

dennypage

@bdf0506:

Hi, I wanted to see if there has been any progress on fixing this issue? Thanks.

Still working on it. Progress, but not ready for release yet. Should be this month.

dennypage

@bulldog5:

@dennypage:

@bulldog5:

I plugged the UPS into a 2K12 server and installed CPs PowerPanel software, let it run for few days and didn't get any LOWBATT messages, then plugged it into my FreeNAS server which is using driver 2.7.3, internal driver .39. and no LOWBATT messages.

So, something is not the same after the upgrade on pfsense because i dont see the LOWBATT message on 2 other boxes. Going to try mirroring the freenas NUT configs, (being doubtful that will matter) then going to have to find some time to reinstall pfsense to 2.3.2 and go from there).

When you put it back on the pfSense box did the LOWBATT messages immediately return?

No

Bulldog, did your issue get resolved?

cuco

@dennypage:

I don't think you are doing anything wrong per se. By default, the nut slave (pfSense) isn't going to initiate a shutdown until the master server declares a low battery condition. This is different than a low battery warning.

When the master declares a low battery condition, it will send a notification to all the slaves indicating that there is a pending loss of power. The slaves will each disconnect from the master and then initiate their own shutdown. Once all the slaves have disconnected, the master will initiate its own shutdown.

If you want to override how the master determines when to declare a low battery condition, see the section on "ignorelb" in the ups.conf man page.

After doing more research I found out, that not only my pfSense-Box wasn't shutting down. It was just the first one I tried. So there seemed to be a problem inside of nut, not inside of your plugin.

So I did more research, did deeper looks into the code and found a bug in the nut-driver. Posted the issue on GitHub: https://github.com/networkupstools/nut/issues/460 then I fixed it: https://github.com/networkupstools/nut/pull/461/commits/b82b9cf3b4695f3171b6250af431a6a3f7fc81c4 and did a pull request: https://github.com/networkupstools/nut/pull/461
It then has been reviewed and merged into nut https://github.com/networkupstools/nut/commit/bc6ca11be42281e6d7f36dc6cf2860c2fe950f66

And now my problem is gone :) So: You were right, I wasn't doing anything wrong per se.

But thank you for your hint with "ignorelb" as this will help me with another problem when using apcupsd and nut at the same time :)

dennypage

@cuco:

So I did more research, did deeper looks into the code and found a bug in the nut-driver. Posted the issue on GitHub: https://github.com/networkupstools/nut/issues/460 then I fixed it: https://github.com/networkupstools/nut/pull/461/commits/b82b9cf3b4695f3171b6250af431a6a3f7fc81c4 and did a pull request: https://github.com/networkupstools/nut/pull/461
It then has been reviewed and merged into nut https://github.com/networkupstools/nut/commit/bc6ca11be42281e6d7f36dc6cf2860c2fe950f66

Awesome!

bulldog5

@dennypage:

@bulldog5:

@dennypage:

@bulldog5:

I plugged the UPS into a 2K12 server and installed CPs PowerPanel software, let it run for few days and didn't get any LOWBATT messages, then plugged it into my FreeNAS server which is using driver 2.7.3, internal driver .39. and no LOWBATT messages.

So, something is not the same after the upgrade on pfsense because i dont see the LOWBATT message on 2 other boxes. Going to try mirroring the freenas NUT configs, (being doubtful that will matter) then going to have to find some time to reinstall pfsense to 2.3.2 and go from there).

When you put it back on the pfSense box did the LOWBATT messages immediately return?

No

Bulldog, did your issue get resolved?

Hi, it seems that adjusting the following has kept it quiet. Thanks again.
battery.charge.low: 20
battery.charge.warning: 25

dennypage

@bulldog5:

Hi, it seems that adjusting the following has kept it quiet. Thanks again.
battery.charge.low: 20
battery.charge.warning: 25

Cool. You are quite welcome. Thanks for letting me know.

dennypage

Just FYI, the PR for the dummy driver has gone in. The shutdown issue will have to be addressed in a follow-on release. This issue will need an enhancement in the core so it may have to wait until 2.4 is release.

wishyou

@dennypage:

I have. The power kill logic is gone from the base os level. Still searching to find out when and why.

Being a long time NUT user with pfSense this made me curious. Is this a new problem recently?
I've been adding stuff to rc.shutdown for "ages" to get proper shutdown-killpower-restart loops with a couple of APC serial ups-es:


#Final shutdown stuff, UPS
if /usr/local/sbin/upsmon -K; then

    # Warning message
	echo "POWERDOWNFLAG detected - Power cycling the UPS loads..."

    # Do shutdown
    /usr/local/sbin/upsdrvctl shutdown

    #Might be needed for power races
    # /bin/sleep 180
    # /sbin/reboot
fi

dennypage

The problem pre dates the current generation of the NUT package, but I'm not sure how far back it goes.

What needs to be done is pretty much the same thing you are doing with your patch to rc.shutdown, except that I need to genericize it so that it can be used with other packages such as apcupsd.

wishyou

OK, thanks for the update
And nice to know that I didn't misunderstand anything with my fix, although it would be nice not having to remember the manual rc.shutdown patch every time pfSense is updated.

Thanks, keep up the good work!

bdf0506

I upgraded NUT on pfSense to latest 2.7.4_5, and ever since I did that, it seems there is a high uptick in UPS communication errors. It's possible that it's another environmental condition that is going on here, but wanted to see if anyone else has had issues. PfSense is running on a small physical box, and it is directly connected via USB to a CyberPower EC650.

I've been getting flooded with emails as a result of this (yes, I know that I can turn them off). But it points to something else that is going on. Here is a dump of the ups related events for a small window on 9/4. In the last 24 hours, I have 232 events that are the Permission denied error.

One thing I did notice, if you look in /usr/local/etc/nut, all the *.conf files have perms of 640, but all the *.conf.sample files have perms of 644. Not sure if that matters or not, and also not sure if that's "new" or not.

Sep  4 19:36:09 upsmon[32699]: Communications with UPS ups established
Sep  4 19:36:09 upsmon[32699]: Communications with UPS ups established
Sep  4 19:36:09 upsd[73255]: User monuser@::1 logged into UPS [ups]
Sep  4 19:36:09 upsd[73255]: User monuser@::1 logged into UPS [ups]
Sep  4 19:36:04 upsmon[32699]: Communications with UPS ups lost
Sep  4 19:36:04 upsmon[32699]: Communications with UPS ups lost
Sep  4 19:36:04 upsmon[32699]: Poll UPS [ups] failed - Write error: Permission denied
Sep  4 19:36:04 upsmon[32699]: Poll UPS [ups] failed - Write error: Permission denied
Sep  4 19:32:48 upsmon[32699]: Communications with UPS ups established
Sep  4 19:32:48 upsmon[32699]: Communications with UPS ups established
Sep  4 19:32:48 upsd[73255]: User monuser@::1 logged into UPS [ups]
Sep  4 19:32:48 upsd[73255]: User monuser@::1 logged into UPS [ups]
Sep  4 19:32:43 upsmon[32699]: Communications with UPS ups lost
Sep  4 19:32:43 upsmon[32699]: Communications with UPS ups lost
Sep  4 19:32:43 upsmon[32699]: Poll UPS [ups] failed - Write error: Permission denied
Sep  4 19:32:43 upsmon[32699]: Poll UPS [ups] failed - Write error: Permission denied
Sep  4 19:30:12 upsmon[32699]: Communications with UPS ups established
Sep  4 19:30:12 upsmon[32699]: Communications with UPS ups established
Sep  4 19:30:12 upsd[73255]: User monuser@::1 logged into UPS [ups]
Sep  4 19:30:12 upsd[73255]: User monuser@::1 logged into UPS [ups]
Sep  4 19:30:07 upsmon[32699]: Communications with UPS ups lost
Sep  4 19:30:07 upsmon[32699]: Communications with UPS ups lost
Sep  4 19:30:07 upsmon[32699]: Poll UPS [ups] failed - Write error: Permission denied
Sep  4 19:30:07 upsmon[32699]: Poll UPS [ups] failed - Write error: Permission denied

bdf0506

@bdf0506:

I upgraded NUT on pfSense to latest 2.7.4_5, and ever since I did that, it seems there is a high uptick in UPS communication errors. It's possible that it's another environmental condition that is going on here, but wanted to see if anyone else has had issues. PfSense is running on a small physical box, and it is directly connected via USB to a CyberPower EC650.

I've been getting flooded with emails as a result of this (yes, I know that I can turn them off). But it points to something else that is going on. Here is a dump of the ups related events for a small window on 9/4. In the last 24 hours, I have 232 events that are the Permission denied error.

One thing I did notice, if you look in /usr/local/etc/nut, all the *.conf files have perms of 640, but all the *.conf.sample files have perms of 644. Not sure if that matters or not, and also not sure if that's "new" or not.
Sep  4 19:36:09 upsmon[32699]: Communications with UPS ups established
Sep  4 19:36:09 upsmon[32699]: Communications with UPS ups established
Sep  4 19:36:09 upsd[73255]: User monuser@::1 logged into UPS [ups]
Sep  4 19:36:09 upsd[73255]: User monuser@::1 logged into UPS [ups]
Sep  4 19:36:04 upsmon[32699]: Communications with UPS ups lost
Sep  4 19:36:04 upsmon[32699]: Communications with UPS ups lost
Sep  4 19:36:04 upsmon[32699]: Poll UPS [ups] failed - Write error: Permission denied
Sep  4 19:36:04 upsmon[32699]: Poll UPS [ups] failed - Write error: Permission denied
Sep  4 19:32:48 upsmon[32699]: Communications with UPS ups established
Sep  4 19:32:48 upsmon[32699]: Communications with UPS ups established
Sep  4 19:32:48 upsd[73255]: User monuser@::1 logged into UPS [ups]
Sep  4 19:32:48 upsd[73255]: User monuser@::1 logged into UPS [ups]
Sep  4 19:32:43 upsmon[32699]: Communications with UPS ups lost
Sep  4 19:32:43 upsmon[32699]: Communications with UPS ups lost
Sep  4 19:32:43 upsmon[32699]: Poll UPS [ups] failed - Write error: Permission denied
Sep  4 19:32:43 upsmon[32699]: Poll UPS [ups] failed - Write error: Permission denied
Sep  4 19:30:12 upsmon[32699]: Communications with UPS ups established
Sep  4 19:30:12 upsmon[32699]: Communications with UPS ups established
Sep  4 19:30:12 upsd[73255]: User monuser@::1 logged into UPS [ups]
Sep  4 19:30:12 upsd[73255]: User monuser@::1 logged into UPS [ups]
Sep  4 19:30:07 upsmon[32699]: Communications with UPS ups lost
Sep  4 19:30:07 upsmon[32699]: Communications with UPS ups lost
Sep  4 19:30:07 upsmon[32699]: Poll UPS [ups] failed - Write error: Permission denied
Sep  4 19:30:07 upsmon[32699]: Poll UPS [ups] failed - Write error: Permission denied

Okay, this isn't a NUT issue.

I dove deeper into the logging before these errors hit, and I see each time a log line like this:

Sep  4 19:32:37 dpinger: Mobility_Server 192.168.35.21: Alarm latency 266us stddev 32us loss 21%

After that line, bad things were happening. I'm surprised I wasn't having other network issues - I probably was, just unknown to me.

Sep  4 19:32:48 php-cgi: nut_email.php: Message sent to <redacted>@gmail.com OK
Sep  4 19:32:48 php-cgi: nut_email.php: Message sent to <redacted>@gmail.com OK
Sep  4 19:32:48 upsmon[32699]: Communications with UPS ups established
Sep  4 19:32:48 upsmon[32699]: Communications with UPS ups established
Sep  4 19:32:48 upsd[73255]: User monuser@::1 logged into UPS [ups]
Sep  4 19:32:48 upsd[73255]: User monuser@::1 logged into UPS [ups]
Sep  4 19:32:43 php-cgi: nut_email.php: Message sent to <redacted>@gmail.com OK
Sep  4 19:32:43 php-cgi: nut_email.php: Message sent to <redacted>@gmail.com OK
Sep  4 19:32:43 upsmon[32699]: Communications with UPS ups lost
Sep  4 19:32:43 upsmon[32699]: Communications with UPS ups lost
Sep  4 19:32:43 upsmon[32699]: Poll UPS [ups] failed - Write error: Permission denied
Sep  4 19:32:43 upsmon[32699]: Poll UPS [ups] failed - Write error: Permission denied
Sep  4 19:32:38 php-fpm[30305]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use Mobility_Server.
Sep  4 19:32:38 php-fpm[30305]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use Mobility_Server.
Sep  4 19:32:37 check_reload_status: Reloading filter
Sep  4 19:32:37 check_reload_status: Reloading filter
Sep  4 19:32:37 check_reload_status: Restarting OpenVPN tunnels/interfaces
Sep  4 19:32:37 check_reload_status: Restarting OpenVPN tunnels/interfaces
Sep  4 19:32:37 check_reload_status: Restarting ipsec tunnels
Sep  4 19:32:37 check_reload_status: Restarting ipsec tunnels
Sep  4 19:32:37 check_reload_status: updating dyndns Mobility_Server
Sep  4 19:32:37 check_reload_status: updating dyndns Mobility_Server
Sep  4 19:32:37 dpinger: Mobility_Server 192.168.35.21: Alarm latency 266us stddev 32us loss 21%</redacted></redacted></redacted></redacted>

The fix was to go into the gateways, and disable the gateway checking on 192.168.35.21. I still don't know what was causing that in the first place, but that's not something that needs to be addressed in the NUT forum.

pigbrother

dennypage, thanks for your great job!

My old Back-UPS RS 1000 connected to pfsense working great, but once or few times a day shows the following in the log\email:
Sep 6 10:47:16 upsmon 42126 UPS Back-UPS_RS_1000 on battery
Sep 6 10:47:21 upsmon 42126 UPS Back-UPS_RS_1000 on line power.

Time is always random, but event duration is always 5 seconds exactly.

My settings:
ups.conf

[Back-UPS_RS_1000]
driver=usbhid-ups
port=auto
ignorelb
override.battery.charge.low = 30
override.battery.runtime.low = 300

upsmon.conf

MONITOR Back-UPS_RS_1000 1 monuser 7504xxxxxxxxxxxx master
SHUTDOWNCMD "/sbin/shutdown -p +0"
POWERDOWNFLAG /etc/killpower
NOTIFYCMD /usr/local/pkg/nut/nut_email.php
NOTIFYFLAG ONLINE   SYSLOG+WALL+EXEC
NOTIFYFLAG ONBATT   SYSLOG+WALL+EXEC
NOTIFYFLAG LOWBATT  SYSLOG+WALL+EXEC
NOTIFYFLAG FSD	  SYSLOG+WALL+EXEC
NOTIFYFLAG COMMOK   SYSLOG+WALL+EXEC
NOTIFYFLAG COMMBAD  SYSLOG+WALL+EXEC
NOTIFYFLAG SHUTDOWN SYSLOG+WALL+EXEC
NOTIFYFLAG REPLBATT SYSLOG+WALL+EXEC
NOTIFYFLAG NOCOMM   SYSLOG+WALL+EXEC
NOTIFYFLAG NOPARENT SYSLOG+WALL+EXEC
RUN_AS_USER root

I realize that is UPS problem but apart from that it works fine.
Are there any NUT tweaks to avoid such behavior?

dennypage

@pigbrother:

dennypage, thanks for your great job!

My old Back-UPS RS 1000 connected to pfsense working great, but once or few times a day shows the following in the log\email:
Sep 6 10:47:16 upsmon 42126 UPS Back-UPS_RS_1000 on battery
Sep 6 10:47:21 upsmon 42126 UPS Back-UPS_RS_1000 on line power.

Time is always random, but event duration is always 5 seconds exactly.

…

I realize that is UPS problem but apart from that it works fine.
Are there any NUT tweaks to avoid such behavior?

You're welcome!

The event itself may be very brief in duration, but is logged as 5 seconds due to the polling interval. There are several reasons that a momentary transfer to battery can happen depending upon the UPS.

Some UPSs allow the variables which control transfer to be changed. The complete list of variables supported by NUT can be found here. To see what your UPS actually supports, use the upsc command. For transfer items, look for variables "input sensitivity" or "input.transfer…"

Be careful with these. :)

pigbrother

My UPS variables:

battery.charge: 100
battery.charge.low: 30
battery.charge.warning: 50
battery.date: 2001/09/25
battery.mfr.date: 2016/10/10
battery.runtime: 5798
battery.runtime.low: 300
battery.type: PbAc
battery.voltage: 26.9
battery.voltage.nominal: 24.0
device.mfr: American Power Conversion
device.model: Back-UPS RS 1000
device.serial:xxxxxxxxxx
device.type: ups
driver.flag.ignorelb: enabled
driver.name: usbhid-ups
driver.parameter.pollfreq: 30
driver.parameter.pollinterval: 2
driver.parameter.port: auto
driver.parameter.synchronous: no
driver.version: 2.7.4
driver.version.data: APC HID 0.96
driver.version.internal: 0.41
input.sensitivity: medium
input.transfer.high: 264
input.transfer.low: 194
input.transfer.reason: input voltage out of range
input.voltage: 228.0
input.voltage.nominal: 230
ups.beeper.status: enabled
ups.delay.shutdown: 20
ups.firmware: 7.g8 .I
ups.firmware.aux: g8
ups.load: 5
ups.mfr: American Power Conversion
ups.mfr.date: 2004/07/28
ups.model: Back-UPS RS 1000
ups.productid: 0002
ups.realpower.nominal: 600
ups.serial: xxxxxxxxxxxx
ups.status: OL
ups.test.result: No test initiated
ups.timer.reboot: 0
ups.timer.shutdown: -1
ups.vendorid: 051d

input.transfer.reason: input voltage out of range - probably is the event reason?

I believe that
input.transfer.high:264 and input.transfer.low:194
are just voltage threshold? Am I right?

Should I try change input.sensitivity to low? If so - where to put it in NUT settings page?

doktornotor

Why would you be doing any such thing? The UPS is doing its job, just leave it alone.

dennypage

@pigbrother:

nput.transfer.reason: input voltage out of range - probably is the event reason?

I believe that
input.transfer.high:264 and input.transfer.low:194
are just voltage threshold? Am I right?

Should I try change input.sensitivity to low? If so - where to put it in NUT settings page?

Yes, those are the voltage levels that will trigger transfer.

Setting UPS variables is not something that you do in your NUT config. You set them in the UPS using the upsrw command.

As Dok notes, the UPS is doing it's job, protecting the attached systems from excessive power fluctuations. You might want to investigate the source of the voltage problem before turning down the sensitivity. Consulting with the UPS manufacturer might be a good idea as well.

pigbrother

dennypaged, oktornotor, thanks for answers.
Agreed, the UPS is doing it's job. I'm just trying to avoid annoying mail reports (at the night time especially).
Another SMART UPSes connected to same power input do not have any complains about power conditions.