NUT package (2.8.0 and below)

kevindd992002

@kevindd992002 said in NUT package:

@dennypage These happen intermittently. As an example, here are the ups and usb logs for today when there was no power interruption of any kind:

Can't give you much guidance without the corresponding system logs. USB bus disconnects, WAN link changes, DHCP events, etc. can all cause a restart of NUT. You need to look at the entire system state of the system at the time of the event.

Would you want a copy of all system logs at that time frame? I'm not sure what to check specifically because I have two pfsense boxes with roughly the same settings but I only encounter it with one box that has the APC SUA750.

dennypage

@kevindd992002 said in NUT package:

@dennypage no I didn't. Is it required so that the overrides will work? I thought otherwise.

Yes. The description in the ignorelb section of the ups.conf man page tries to say this.

While the description in the documentation is somewhat vague, the code in drivers/dstate.c makes it clear:

void status_commit(void)
{
    while (ignorelb) {
        const char  *val, *low;

        val = dstate_getinfo("battery.charge");
        low = dstate_getinfo("battery.charge.low");

        if (val && low && (strtol(val, NULL, 10) < strtol(low, NULL, 10))) {
            snprintfcat(status_buf, sizeof(status_buf), " LB");
            upsdebugx(2, "%s: appending LB flag [charge '%s' below '%s']", __func__, val, low);
            break;
        }

        val = dstate_getinfo("battery.runtime");
        low = dstate_getinfo("battery.runtime.low");

        if (val && low && (strtol(val, NULL, 10) < strtol(low, NULL, 10))) {
            snprintfcat(status_buf, sizeof(status_buf), " LB");
            upsdebugx(2, "%s: appending LB flag [runtime '%s' below '%s']", __func__, val, low);
            break;
        }

        /* LB condition not detected */
        break;
    }

    if (alarm_active) {
        dstate_setinfo("ups.status", "ALARM %s", status_buf);
    } else {
        dstate_setinfo("ups.status", "%s", status_buf);
    }
}

battery.charge.low and battery.runtime.low are not used unless ignorelb is set. Probably not how I would have done it, but I don't own the code.

dennypage

@kevindd992002 Look at the system logs for the minute preceding the event. See what's going on. You should be able to identify a trigger. If you aren't having USB disconnects, then it's likely something like an interface flap or DHCP renewal.

kevindd992002

@dennypage

When NUT successfully shuts down my Synology NAS and pfsense itself, will the UPS shut down itself to conserve battery power and cut off output power to all its output terminals?
If so, when the power comes back it should automatically boot everything up as long as the devices connected to it are set to turn on when AC power comes back, right?

I did a test today:

battery.charge.low = 60 and battery.runtime.low = 396

From 100% UPS batt, unplugged input power from mains.
At around 70% UPS batt, plugged it back to mains. So far so good.
After 10 seconds, unplugged input power from mains again.
Waited for FSD to occur and it successfully shuts down both Synology and pfsense.
After pfsense shuts down, I didn't see the UPS shut itself down and the output power from the UPS was not cut (is there a delay or something?). So I decided to plug it back to mains. The Synology NAS started booting up but pfsense stayed shut down.
After 5 seconds on being on mains, the UPS just "resets" itself (output power cut off and then on again) so everything was reset also (including the Synology that was currently in booting state).

So is there something wrong with my setup here? All I have in the extra arguments field are these:

ignorelb
override.battery.charge.warning = 70
override.battery.charge.low = 60
override.battery.runtime.low = 396

I'm not sure if there's something wrong with the UPS itself or just an issue with how I have NUT configured. Please help. Thanks.

Gertjan

@kevindd992002 said in NUT package:

(5) I didn't see the UPS shut itself down and the output power from the UPS was not cut
..... The Synology NAS started booting up but pfsense stayed shut down.

Why would the Syno boot if there was no AC cut out and restore ?

the UPS just "resets" itself (output power cut off and then on again)

Interesting. I'm using several types of APC Backup Xxx myslef for many tears now, but admit I never tested these as you did. Most setups are : "shutdown - and a human will boot you again - no AC restore", but I do have an UPS protecting my pfSEnse (master) and a Syno (slave). I'll do the same test as you didi this week, and report back.

Note : my Syno doesn't return from AC. I will have to re activate it manually - or I or can "WOL" if needed using pfSense (manually or automated - by script ...).

kevindd992002

@Gertjan said in NUT package:

@kevindd992002 said in NUT package:

(5) I didn't see the UPS shut itself down and the output power from the UPS was not cut
..... The Synology NAS started booting up but pfsense stayed shut down.

Why would the Syno boot if there was no AC cut out and restore ?

That's what I don't understand too. As soon as I plugged back the mains to the UPS, thing started to act weird. This is why I was asking how much time is the delay between pfsense shutdown and UPS shutdown? I need to wait for this time before I plug the UPS back to mains.

the UPS just "resets" itself (output power cut off and then on again)

Interesting. I'm using several types of APC Backup Xxx myslef for many tears now, but admit I never tested these as you did. Most setups are : "shutdown - and a human will boot you again - no AC restore", but I do have an UPS protecting my pfSEnse (master) and a Syno (slave). I'll do the same test as you didi this week, and report back.

Note : my Syno doesn't return from AC. I will have to re activate it manually - or I or can "WOL" if needed using pfSense (manually or automated - by script ...).

Yes, please report back. Why don't you like using the "Restart automatically after a power failure" feature in your Syno?

Gertjan

@kevindd992002 said in NUT package:

Why don't you like using the "Restart automatically after a power failure" feature in your Syno?

Because when the power goes down, I like to wait with putting my devices to on. The "Power on" situation is often as bad or even worse as the "power down" moment, with my UPS in bad shape.

dennypage

@kevindd992002 Yes, there is a delay. How this works varies by UPS make/model. Some also have a restart lockout/delay. See the NUT documentation, the NUT mailing list, and your UPS documentation for information. Don’t expect to find easy/obvious answers for this as there are a lot of differences in behavior amongst the hundreds of UPS models that NUT supports.

FWIW, You are better off asking questions about general NUT And UPS behaviors on the NUT mailing list rather than in the pfSense forum.

kevindd992002

@dennypage said in NUT package:

@kevindd992002 Yes, there is a delay. How this works varies by UPS make/model. Some also have a restart lockout/delay. See the NUT documentation, the NUT mailing list, and your UPS documentation for information. Don’t expect to find easy/obvious answers for this as there are a lot of differences in behavior amongst the hundreds of UPS models that NUT supports.

FWIW, You are better off asking questions about general NUT And UPS behaviors on the NUT mailing list rather than in the pfSense forum.

Ok, thanks.

Also, I tried recreating a shutdown sequence by issuing a /usr/local/sbin/upsmon -c fsd command in pfsense (so as to preserve battery lifetime while testing all these) but the weird thing is that my Syno doesn't seem to get a hold of the FSD event. My pfsense master and UPS shuts down properly though. As soon as I issue the FSD, the /var/log/messages in my Syno says this:

2019-12-31T02:05:03+08:00 Synology synoups: [UPS] Check Boot Status.
2019-12-31T02:05:03+08:00 Synology synoups: WARNING: UPS is On-Line

But when I recreate the shutdown sequence by unplugging the mains, all goes well and the Syno picks up the OB LB FSD event properly. Does this mean that Syno needs to see that the UPS is in OB LB state to issue a shutdown even if it sees an FSD event already?

kevindd992002

Also, why does the pfsense NUT package not contain the latest version of NUT?

dennypage

@kevindd992002 said in NUT package:

Also, why does the pfsense NUT package not contain the latest version of NUT?

The pfSense NUT package itself does not contain NUT. Instead, it has a dependency on the FreeBSD NUT package. The FreeBSD NUT package contains NUT 2.7.4, which is the latest stable version of NUT.

If you are asking why the FreeBSD NUT package is still at update 8, it is because the changes in 9-13 have no operational effect with pfSense. Where the examples go and the like just don't matter with pfSense. Eventually the package updates will be pulled in as part of general housekeeping, but there is no reason to do it otherwise.

kevindd992002

@dennypage said in NUT package:

@kevindd992002 said in NUT package:

Also, why does the pfsense NUT package not contain the latest version of NUT?

The pfSense NUT package itself does not contain NUT. Instead, it has a dependency on the FreeBSD NUT package. The FreeBSD NUT package contains NUT 2.7.4, which is the latest stable version of NUT.

If you are asking why the FreeBSD NUT package is still at update 8, it is because the changes in 9-13 have no operational effect with pfSense. Where the examples go and the like just don't matter with pfSense. Eventually the package updates will be pulled in as part of general housekeeping, but there is no reason to do it otherwise.

Ok, makes sense. Thanks.

Do you have any thoughts on my fsd question above?

kevindd992002

@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: exiting

Do you have any ideas as to why it suddenly stopped?

dennypage

@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.

DannyBoy2k

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

flu

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?

DurUser

@flu I think I have seen the same thing happen.

dennypage

@DannyBoy2k You are most welcome. Glad it was so easy!

And very impressed that you went through the entire thread.

dennypage

@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).

flu

@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?