NUT package (2.8.0 and below)

DavidIr · Mar 12, 2023, 10:08 AM

@dennypage I seem to have a similar but possibly different problem.

My UPS is an Eaton Eclipse ECO 650 connected by USB to my Netgate-3100 running 23.01-RELEASE (arm) with NUT 2.8.0_2.

Note: the setup worked perfectly before my update to 23.01 and 2.8.0 for over 6 months, there have been no powercuts/surges or hardware changes.

As with others I am seeing repeated log entries from upsmon.

Mar 12 09:57:09	upsmon	80760	Poll UPS [EatonUPS] failed - Driver not connected
Mar 12 09:57:04	upsmon	80760	Poll UPS [EatonUPS] failed - Driver not connected

If I filter my logs to upshid-ups I only see the following:

Mar 9 22:26:16	usbhid-ups	91631	Startup successful
Mar 9 22:26:09	usbhid-ups	70838	Signal 15: exiting
Mar 9 22:20:46	usbhid-ups	70838	Startup successful
Mar 9 22:20:41	usbhid-ups	47718	Signal 15: exiting
Mar 9 22:13:14	usbhid-ups	47718	Startup successful
Mar 9 22:10:05	usbhid-ups	75991	Signal 15: exiting
Mar 9 21:57:06	usbhid-ups	75991	Startup successful

If I filter the logs to upsd I see:

Mar 12 09:07:25	upsd	82791	Can't connect to UPS [EatonUPS] (usbhid-ups-EatonUPS): Connection refused
Mar 12 09:02:25	upsd	82791	Can't connect to UPS [EatonUPS] (usbhid-ups-EatonUPS): Connection refused
Mar 12 08:57:25	upsd	82791	Can't connect to UPS [EatonUPS] (usbhid-ups-EatonUPS): Connection refused
Mar 12 08:52:25	upsd	82791	Can't connect to UPS [EatonUPS] (usbhid-ups-EatonUPS): Connection refused
Mar 9 22:26:16	upsd	82791	Connected to UPS [EatonUPS]: usbhid-ups-EatonUPS
Mar 9 22:26:14	upsd	82791	User local-monitor@::1 logged into UPS [EatonUPS]
Mar 9 22:26:10	upsd	82791	Startup successful
Mar 9 22:26:10	upsd	82791	Can't connect to UPS [EatonUPS] (usbhid-ups-EatonUPS): No such file or directory
Mar 9 22:26:10	upsd	82791	not listening on 127.0.0.1 port 3493
Mar 9 22:26:10	upsd	82791	listening on ::1 port 3493
Mar 9 22:26:10	upsd	82791	listening on 127.0.0.1 port 3493
Mar 9 22:26:10	upsd	82791	not listening on 192.168.200.254 port 3493
Mar 9 22:26:10	upsd	82791	listening on pfsense.{internaldomainname} port 3493
Mar 9 22:26:09	upsd	62680	Signal 15: exiting
Mar 9 22:26:09	upsd	62680	mainloop: Interrupted system call
Mar 9 22:26:09	upsd	62680	User local-monitor@::1 logged out from UPS [EatonUPS]

This morning the failure occurred at 08:52 (from notification email):

8:52:27 UPS Notification from pfSense.irwazu.co.uk - Sun, 12 Mar 2023 08:52:27 +0000

Communications with UPS EatonUPS lost

My configuration is extra arguments to driver:

pollfreq=90

Additional configuration lines for upsmon.conf

RUN_AS_USER root

Additional configuration lines for ups.conf

user=root
pollinterval=15

Other than using the "interruptonly" option is there anything I can do to resolve or help debug the cause? Is this likely the same issue as for CyberPower UPSs you've already identified?

Full logs of a restart of the UPS service are as follows:

Mar 12 10:05:19	upsmon	69168	Communications with UPS EatonUPS established
Mar 12 10:05:16	upsd	70834	Connected to UPS [EatonUPS]: usbhid-ups-EatonUPS
Mar 12 10:05:15	usbhid-ups	80232	Startup successful
Mar 12 10:05:14	upsmon	69168	UPS EatonUPS is unavailable
Mar 12 10:05:14	upsmon	69168	Poll UPS [EatonUPS] failed - Driver not connected
Mar 12 10:05:14	upsd	70834	User local-monitor@::1 logged into UPS [EatonUPS]
Mar 12 10:05:10	upsd	70834	Startup successful
Mar 12 10:05:10	upsd	70834	Can't connect to UPS [EatonUPS] (usbhid-ups-EatonUPS): Connection refused
Mar 12 10:05:10	upsd	70834	not listening on 127.0.0.1 port 3493
Mar 12 10:05:10	upsd	70834	listening on ::1 port 3493
Mar 12 10:05:10	upsd	70834	listening on 127.0.0.1 port 3493
Mar 12 10:05:10	upsd	70834	not listening on 192.168.200.254 port 3493
Mar 12 10:05:10	upsd	70834	listening on pfsense.irwazu.co.uk port 3493
Mar 12 10:05:09	upsmon	69168	Communications with UPS EatonUPS lost
Mar 12 10:05:09	upsmon	69168	UPS [EatonUPS]: connect failed: Connection failure: Connection refused
Mar 12 10:05:09	upsmon	69168	Startup successful
Mar 12 10:05:08	upsd	82791	Signal 15: exiting
Mar 12 10:05:08	upsd	82791	mainloop: Interrupted system call
Mar 12 10:05:08	upsd	82791	User local-monitor@::1 logged out from UPS [EatonUPS]
Mar 12 10:05:08	upsmon	80760	Signal 15: exiting
Mar 12 10:05:07	upsmon	80760	Poll UPS [EatonUPS] failed - Driver not connected

dennypage · Mar 12, 2023, 10:22 PM

@davidir Your log messages do not show anything particularly unusual. Signal 15 indicates that the usbhid-ups process was terminated via a kill signal. This is usually triggered by a package restart such was when your DHCP WAN address changes.

Btw, not sure what you are intending to do with the poll interval settings. Given that you are using a usb connection, there is a good reason to be setting these, particularly pollinterval in ups.conf which may negatively affect your shutdown. Unless you have a very concrete problem that you are fixing, I would recommend that you remove both of them. As well as the RUN_AS_USER setting in upsmon.conf.

dennypage · Mar 12, 2023, 10:29 PM

I've received several requests for the dev build of usbhid-ups, so I thought I would upload the file here.

usbhid-ups.gz

For reference, the shasum and sha256sum checksums of the unzipped file are:

49ce9131502bfb8b789ee97b7fb3fc81fc9f8fff  usbhid-ups
999a2653559dbc50ecc8ba592a67587b1e307a1495f6e8ebbd3d8e90e3967133  usbhid-ups

If you use the file, please post and let me know if it resolves an issue for you.

PatRyan · Mar 14, 2023, 12:06 AM

@dennypage thank you very much for this. I loaded it up today and so far, it has continued to run for about 5 hours. I'll report back tomorrow to let you know if it hangs up overnight.

For other folks' information, I put the file Denny shared into /usr/local/libexec/nut replacing the file already there. (Be sure to make a copy of the original in case this doesn't work for you.) Make sure that the permissions are set to rwxr-xr-x (0755). Also I had to include "user=root" in the ups.conf section in pfSense.

Thanks again Denny.

dennypage · Mar 14, 2023, 12:07 AM

@patryan said in NUT package:

Thanks again Denny.

Welcome!

PatRyan · Mar 14, 2023, 4:03 PM

Update - No issues overnight still running fine and serving my network as a NUT Server. Updated to the latest 2.7.0 Devel build this morning and UPS service started up without a hiccup. Very pleased.

FYI, I have a CyberPower CP1500PFCLCD and it is connected to my pfSense box via the supplied USB cable.

OffstageRoller · Mar 14, 2023, 6:39 PM

@dennypage said in NUT package:

I've received several requests for the dev build of usbhid-ups, so I thought I would upload the file here.

usbhid-ups.gz

For reference, the shasum and sha256sum checksums of the unzipped file are:
49ce9131502bfb8b789ee97b7fb3fc81fc9f8fff  usbhid-ups
999a2653559dbc50ecc8ba592a67587b1e307a1495f6e8ebbd3d8e90e3967133  usbhid-ups
If you use the file, please post and let me know if it resolves an issue for you.

So far so good for me with a Trip Lite SMART1500LCD! It's only been an hour, but it has stayed connected and my logs are no longer getting spammed by disconnects/connects.

OffstageRoller · Mar 15, 2023, 1:17 AM

@offstageroller said in NUT package:

@dennypage said in NUT package:
I've received several requests for the dev build of usbhid-ups, so I thought I would upload the file here.

usbhid-ups.gz

For reference, the shasum and sha256sum checksums of the unzipped file are:
49ce9131502bfb8b789ee97b7fb3fc81fc9f8fff  usbhid-ups
999a2653559dbc50ecc8ba592a67587b1e307a1495f6e8ebbd3d8e90e3967133  usbhid-ups
If you use the file, please post and let me know if it resolves an issue for you.
So far so good for me with a Trip Lite SMART1500LCD! It's only been an hour, but it has stayed connected and my logs are no longer getting spammed by disconnects/connects.

I'm at about 8 hours now, with no issues to report. All is well again with my USB connection to my UPS!

knight-of-ni · Mar 15, 2023, 5:28 PM

Hey guys. Mind if I join the party?

I upgraded from from 2.6 CE to 23.01 plus today, to get support for the 2.5Gbps nics in my firewall.

Unfortunately after the upgrade, NUT started failing because it couldn't claim the USB device:

Can't claim USB device [051d:0003]@0/0: Other error

UPS is a APC Smart-UPS 1500.

Did a little searching, found it was a permission error, and eventually found this thread.

Looks like I found the right place.

I've gone back through this thread about a month and started reading.

Adding user=root to ups.conf got things going again. However, I'd call that a workaround. If I read right, looks like I need to wait for the next release of NUT for a real fix.

At the moment I am not using @dennypage's custom usbhid-ups. If my UPS does not stay online, I'll apply it and post results.

I'll be keeping an eye on this thread for new information.

dennypage · Mar 15, 2023, 6:03 PM

@knight-of-ni said in NUT package:

Adding user=root to ups.conf got things going again. However, I'd call that a workaround. If I read right, looks like I need to wait for the next release of NUT for a real fix.

While the next release of nut is expected to address the CyberPower issue, it will not address the APC issue. The APC issue is a usb quirk issue, and this requires a new version of the kernel in pfSense to permanently resolve. I don't expect that to happen soon.

See here for further details of the APC issue. I recommend using the /boot/loader.conf.local solution if you can take a reboot.

dem · Mar 16, 2023, 8:34 PM

@dennypage said in NUT package:

If you use the file, please post and let me know if it resolves an issue for you.

Your version of usbhid-ups has been working fine with my CyberPower for 48 hours now. Thanks.

jwfox5150 · Mar 22, 2023, 1:57 PM

@dennypage said in NUT package:

If you use the file, please post and let me know if it resolves an issue for you.

I was experiencing the same issue and using this version of usbhid-ups has resolved the issue. Many thanks, that was driving me NUTS (pun intended)

JeGr · Mar 25, 2023, 10:32 PM

@dennypage Quick question: is the NUT package somehow dependent on other services or is integrated into a service hook since 23.01? After upgrading I have NUT alert messages all over the place for things that are completely unrealted to the UPS.
E.g. resetting or reconfiguring a gateway, doing configurations on WAN or VPNs if the interface is assigned etc. all seem to trigger "problems" with NUT loosing and regaining connection to the UPS. UPS attached is an APC BackUPS via USB that ran well before without being trigger happy with notifications when interface/gateway/routing things are happening. Now just touching some of those things seem to trigger a connection loss from NUT. Really confusing

Cheers
\jens

dennypage · Mar 26, 2023, 1:39 PM

@jegr said in NUT package:

E.g. resetting or reconfiguring a gateway, doing configurations on WAN or VPNs if the interface is assigned etc. all seem to trigger "problems" with NUT loosing and regaining connection to the UPS.

pfSense restarts package services when WAN interfaces disconnect or reconnect. Yes, this is unnecessary for some services, such as NUT with a USB connection, but there is no way for pfSense to know which services actually need to be restarted. It's always been this way.

What you would expect to see is NUT restart once when the interface goes down, and once again when the interface comes back up. Whether or not you see NUT reporting a lost connection or not depends upon the order and speed of shutting down the various processes involved (usbhid-ups, upsd, upsmon).

JeGr · Mar 26, 2023, 1:39 PM

@dennypage said in NUT package:

pfSense restarts package services when WAN interfaces disconnect or reconnect. Yes, this is unnecessary for some services, such as NUT with a USB connection, but there is no way for pfSense to know which services actually need to be restarted. It's always been this way.

That may very well be, but before 23.01 there were no problems with NUT overactively reporting down/ups at those times whereas now they pop up almost every time when someone is editing something on interfaces, routing gateways etc.
Just wanting to check if there's anything that has changed while converting stuff to PHP 8.1 or anything. Wouldn't be the first :)

dennypage · Mar 26, 2023, 5:32 PM

@jegr Nothing to do with PHP, it's actually a shell script.

If you go back through this thread you'll find mention of this issue five or more years ago. Some people see it a lot, some never see it. It just depends on how things happen on the box. If it is really bothering you, you could do a local patch for the rc script to add a sleep following the kill of upsmon. But only if it's really bothering you.

JeGr · Mar 26, 2023, 7:29 PM

@dennypage Nah, I can live with that :) But that only adds to another thing that packages should have more specific hooks like the XY interface instead of "any" interface, as theres no need otherwise. Or OpenVPN that gets restarted pretty often while listening on localhost so would be completely unphased by any changes. Also it'd be nice to have those notifications selectable and expandable so we can get more/specific notifications and disable others :)

But I'll push that in another thread. Thanks for getting back :)

Cheers
\jens

DavidIr · Mar 30, 2023, 5:30 PM

@dennypage said in NUT package:

I've received several requests for the dev build of usbhid-ups, so I thought I would upload the file here.

usbhid-ups.gz

For reference, the shasum and sha256sum checksums of the unzipped file are:
49ce9131502bfb8b789ee97b7fb3fc81fc9f8fff  usbhid-ups
999a2653559dbc50ecc8ba592a67587b1e307a1495f6e8ebbd3d8e90e3967133  usbhid-ups
If you use the file, please post and let me know if it resolves an issue for you.

I finally got round to loading this file onto my system, and unfortunately it does not seem to work at all. Now instead of failing randomly after a period of time I get the failure immediately after restarting the UPS service.


Mar 30 18:25:59	upsmon	34059	Poll UPS [EatonUPS] failed - Driver not connected
Mar 30 18:25:54	upsmon	34059	Poll UPS [EatonUPS] failed - Driver not connected
Mar 30 18:25:49	upsmon	34059	Poll UPS [EatonUPS] failed - Driver not connected
Mar 30 18:25:44	upsmon	34059	Poll UPS [EatonUPS] failed - Driver not connected
Mar 30 18:25:39	upsmon	34059	Poll UPS [EatonUPS] failed - Driver not connected
Mar 30 18:25:38	php-cgi	35430	notify_monitor.php: Message sent to my@email.net OK
Mar 30 18:25:34	upsmon	34059	Poll UPS [EatonUPS] failed - Driver not connected
Mar 30 18:25:29	upsmon	34059	UPS EatonUPS is unavailable
Mar 30 18:25:29	upsmon	34059	Poll UPS [EatonUPS] failed - Driver not connected
Mar 30 18:25:29	upsd	35561	User local-monitor@::1 logged into UPS [EatonUPS]
Mar 30 18:25:27	php-cgi	35430	notify_monitor.php: Message sent to my@email.net OK
Mar 30 18:25:25	upsd	35561	Startup successful

I think this log sequence shows from startup.

Any further suggestions for a solution to this? Are there any diagnostics I can do to be helpful?
Thank you.
David

PatRyan · Mar 30, 2023, 8:05 PM

@davidir did you check to be sure the file permissions are correct after uploading it? This file from Denny Page is working without a hitch for me with a CyberPower UPS. I don't know if there are any other quirks with an Eaton UPS.

dennypage · Mar 31, 2023, 7:24 AM

@davidir said in NUT package:

I think this log sequence shows from startup.
Any further suggestions for a solution to this?

What's missing from your log entries are the usbhid-ups entries. Those are what is needed to help further the investigation if you are having a problem with usbhid-ups.

You may want to confirm that it is installed correctly. Location and permissions should look like this:

[23.01-RELEASE][root@fw]/root: ls -l /usr/local/libexec/nut/usbhid-ups 
-rwxr-xr-x  1 root  wheel  250968 Jan 17 17:34 /usr/local/libexec/nut/usbhid-ups
[23.01-RELEASE][root@fw]/root:

Lastly, if you are still having an issue you may want to post your config.