-
@kevindd992002 Are these happening at start up? Or are they happening sporadically?
-
@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:
ups logs:
Nov 27 13:38:48 upsd 41381 User local-monitor@::1 logged into UPS [ups] Nov 27 13:38:47 upsd 41381 User monuser@192.168.10.10 logged into UPS [ups] Nov 27 13:38:47 upsd 41381 Connected to UPS [ups]: usbhid-ups-ups Nov 27 13:38:46 upsd 41166 Can't connect to UPS [ups] (usbhid-ups-ups): Connection refused Nov 27 13:38:43 upsd 37228 Can't connect to UPS [ups] (usbhid-ups-ups): Connection refused Nov 27 13:38:42 upsd 57752 User local-monitor@::1 logged out from UPS [ups] Nov 27 13:38:07 upsd 57752 User monuser@192.168.10.10 logged into UPS [ups] Nov 27 13:38:03 upsd 57752 User local-monitor@::1 logged into UPS [ups] Nov 27 13:38:03 upsd 57752 Connected to UPS [ups]: usbhid-ups-ups Nov 27 13:38:01 upsd 57439 Can't connect to UPS [ups] (usbhid-ups-ups): Connection refused Nov 27 13:37:58 upsd 53471 Can't connect to UPS [ups] (usbhid-ups-ups): No such file or directory Nov 27 13:37:57 upsd 12981 User local-monitor@::1 logged out from UPS [ups]
usb logs:
Nov 27 13:38:47 upsd 41381 Connected to UPS [ups]: usbhid-ups-ups Nov 27 13:38:46 upsd 41166 Can't connect to UPS [ups] (usbhid-ups-ups): Connection refused Nov 27 13:38:43 upsd 37228 Can't connect to UPS [ups] (usbhid-ups-ups): Connection refused Nov 27 13:38:03 upsd 57752 Connected to UPS [ups]: usbhid-ups-ups Nov 27 13:38:01 upsd 57439 Can't connect to UPS [ups] (usbhid-ups-ups): Connection refused Nov 27 13:37:58 upsd 53471 Can't connect to UPS [ups] (usbhid-ups-ups): No such file or directory
-
I tested my new UPS again and had these results:
If you check under UPS details, my battery.charge.low is set to 60% and battery.runtime.low is set to 396s. I unplugged the UPS from the wall outlet to recreate a blackout and I was expecting NUT to issue an FSD when either charge.low or runtime.low is reached, whichever comes first. But if you check the UPS Status, the actual charge is at 47% already and the runtime at 300s, yet I'm not still seeing it sending an FSD to the slaves.
The FSD was sent until the UPS' built-in "low battery" meter is reached and my Synology was notified to shutdown. Why is this?
-
@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.
-
@kevindd992002 Did you have ignorelb set?
-
@dennypage no I didn't. Is it required so that the overrides will work? I thought otherwise.
-
@dennypage said in NUT package:
@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.
-
@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.
-
@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.
-
- 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 = 396I'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.
-
@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 ...).
-
@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?
-
@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.
-
@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.
-
@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?
-
Also, why does the pfsense NUT package not contain the latest version of NUT?
-
@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.
-
@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?
-
@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?
-
@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.