NUT 2.8.1-3 "Can't claim USB device [051d:0002]@0/0: Entity not found" using usbhid-ups

[ErikDB87]

Hi all,

Yesterday, I bought a UPS for the first time in my life, and was eager to dive into NUT. But not all is working as expected... I saw a similar thread started on 18 October, but it didn't help me. (I also spent a handful of hours searching the web for solutions, and of course read the manual and FAQ - "queequeg".)

I tried shutting my UPS (APC "Back-UPS BX750MI FW:295202G -302202G") down with sudo upsdrvctl shutdown, but no response. Digging around, I found a few things that raised my suspicion, but I can't figure it out...

I followed this fine gentleman's guide (but tweaked it a bit - I don't know why he uses master and slave for example?): https://technotim.live/posts/NUT-server-guide/.
I must add that I created a few users and user groups during installation and configuration, following the documentation. But in the end, I lost oversight, and everything didn't work. So it's entirely possible there's a permissions issue somewhere. But I don't have any idea where...

Because of the trial-and-error approach, in the .conf files (shown below), a lot of stuff is commented out. I assume I can delete it, but I also assume the # should be adequate? Anyway, I keep it in the output below for clarity.

I'll just paste various outputs here, I hope that's a reasonable approach?

Thanks in advance for anyone's help!

Kind regards,

Erik

erik@MinipcLG2:/$ sudo upsdrvctl shutdown apcupskelder
Network UPS Tools - UPS driver controller 2.8.1
Network UPS Tools - Generic HID driver 0.52 (2.8.1)
USB communication driver (libusb 1.0) 0.46
select with socket: Invalid argument
Can't claim USB device [051d:0002]@0/0: Entity not found
upsnotify: failed to notify about state 4: no notification tech defined, will not spam more about it
Driver failed to start (exit status=1)

erik@MinipcLG2:/$ sudo nut-scanner -U
Scanning USB bus.
[nutdev1]
        driver = "usbhid-ups"
        port = "auto"
        vendorid = "051D"
        productid = "0002"
        product = "Back-UPS BX750MI  FW:295202G -302202G"
        serial = "9B2416A22014"
        vendor = "American Power Conversion"
        bus = "001"
        device = "004"
        busport = "002"
        ###NOTMATCHED-YET###bcdDevice = "0106"

erik@MinipcLG2:/etc/nut$ sudo usbhid-ups -a apcupskelder
sudo: usbhid-ups: opdracht niet gevonden

This seems strange? But after some googling, I found the below alternative - although I would expect it to work without /lib/nut/):

erik@MinipcLG2:/$ sudo /lib/nut/usbhid-ups -a apcupskelder
Network UPS Tools - Generic HID driver 0.52 (2.8.1)
USB communication driver (libusb 1.0) 0.46
Duplicate driver instance detected (PID file /run/nut/usbhid-ups-apcupskelder.pid exists)! Terminating other driver!

Bericht aan allen van root@MinipcLG2 (somewhere) (Wed Oct 30 10:27:32 2024):

Communications with UPS apcupskelder@localhost lost


Bericht aan allen van root@MinipcLG2 (somewhere) (Wed Oct 30 10:27:32 2024):

Communications with UPS apcupskelder@localhost lost

HIDParse: LogMax is less than LogMin. Vendor HID report descriptor may be incorrect; interpreting LogMax -1 as 255 in ReportID: 0x0c
HIDParse: LogMax is less than LogMin. Vendor HID report descriptor may be incorrect; interpreting LogMax -1 as 255 in ReportID: 0x22
HIDParse: LogMax is less than LogMin. Vendor HID report descriptor may be incorrect; interpreting LogMax -1 as 255 in ReportID: 0x40
Using subdriver: APC HID 0.100

Bericht aan allen van root@MinipcLG2 (somewhere) (Wed Oct 30 10:27:40 2024):

Communications with UPS apcupskelder@localhost established


Bericht aan allen van root@MinipcLG2 (somewhere) (Wed Oct 30 10:27:48 2024):

Communications with UPS apcupskelder@localhost lost


Bericht aan allen van root@MinipcLG2 (somewhere) (Wed Oct 30 10:27:56 2024):

Communications with UPS apcupskelder@localhost established

erik@MinipcLG2:/$ cat /etc/group | grep nut
users:x:100:nutuser,nutmon
nut:x:130:
nutuser:x:1002:
nutgroup:x:1003:nutuser
nutmon:x:1004:
nutmongroep:x:1005:nutmon

erik@MinipcLG2:/$ lsusb
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 001 Device 003: ID 0403:6001 Future Technology Devices International, Ltd FT232 Serial (UART) IC
Bus 001 Device 004: ID 051d:0002 American Power Conversion Uninterruptible Power Supply
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub

erik@MinipcLG2:/$ ls -l /dev/bus/usb/001/004
crw-rw-r-- 1 root nut 189, 3 okt 30 10:31 /dev/bus/usb/001/004

erik@MinipcLG2:/$ cat /etc/os-release
NAME="Linux Mint"
VERSION="22 (Wilma)"
ID=linuxmint
ID_LIKE="ubuntu debian"
PRETTY_NAME="Linux Mint 22"
VERSION_ID="22"
HOME_URL="https://www.linuxmint.com/"
SUPPORT_URL="https://forums.linuxmint.com/"
BUG_REPORT_URL="http://linuxmint-troubleshooting-guide.readthedocs.io/en/latest/"
PRIVACY_POLICY_URL="https://www.linuxmint.com/"
VERSION_CODENAME=wilma
UBUNTU_CODENAME=noble

erik@MinipcLG2:/$ hostnamectl
 Static hostname: MinipcLG2
       Icon name: computer-desktop
         Chassis: desktop 🖥️
      Machine ID: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
         Boot ID: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
Operating System: Linux Mint 22
          Kernel: Linux 6.8.0-47-generic
    Architecture: x86-64
 Hardware Vendor: HP
  Hardware Model: HP EliteDesk 800 G2 DM 65W
Firmware Version: N21 Ver. 02.10
   Firmware Date: Sun 2016-01-24
    Firmware Age: 8y 9month 6d

erik@MinipcLG2:/$ uname -r
6.8.0-47-generic

erik@MinipcLG2:/$ sudo apt list nut*
Bezig met oplijsten... Klaar
nut-cgi/noble,now 2.8.1-3.1ubuntu2 amd64 [geïnstalleerd]
nut-client/noble,now 2.8.1-3.1ubuntu2 amd64 [geïnstalleerd]
nut-doc/noble 2.8.1-3.1ubuntu2 all
nut-i2c/noble 2.8.1-3.1ubuntu2 amd64
nut-ipmi/noble 2.8.1-3.1ubuntu2 amd64
nut-modbus/noble 2.8.1-3.1ubuntu2 amd64
nut-monitor/noble 2.8.1-3.1ubuntu2 all
nut-powerman-pdu/noble 2.8.1-3.1ubuntu2 amd64
nut-server/noble,now 2.8.1-3.1ubuntu2 amd64 [geïnstalleerd]
nut-snmp/noble 2.8.1-3.1ubuntu2 amd64
nut-xml/noble 2.8.1-3.1ubuntu2 amd64
nut/noble,now 2.8.1-3.1ubuntu2 all [geïnstalleerd]
nutcracker/noble 0.5.0+dfsg-2 amd64
nutsqlite/noble 2.0.6-4 all
nuttcp/noble 6.1.2-4build1 amd64

erik@MinipcLG2:/$ sudo /lib/nut/usbhid-ups -DDD -a apcupskelder
Network UPS Tools - Generic HID driver 0.52 (2.8.1)
USB communication driver (libusb 1.0) 0.46
   0.000000     [D3] do_global_args: var='pollinterval' val='1'
   0.000024     [D1] testval_reloadable: setting 'pollinterval' exists and differs: new value '1' vs. '2'
   0.000057     [D3] do_global_args: var='maxretry' val='3'
   0.000083     [D3] main_arg: var='driver' val='usbhid-ups'
   0.000108     [D3] main_arg: var='port' val='auto'
   0.000136     [D3] main_arg: var='desc' val='Back-UPS BX750MI  FW:295202G -302202G'
   0.000152     [D3] main_arg: var='vendorid' val='051d'
   0.000179     [D3] main_arg: var='productid' val='0002'
   0.000203     [D3] main_arg: var='serial' val='9B2416A22014'
   0.000248     [D1] Network UPS Tools version 2.8.1 (release/snapshot of 2.8.1) built with gcc (Ubuntu 13.2.0-23ubuntu2) 13.2.0 and configured with flags: --build=x86_64-linux-gnu --prefix=/usr --includedir=${prefix}/include --mandir=${prefix}/share/man --infodir=${prefix}/share/info --sysconfdir=/etc --localstatedir=/var --disable-option-checking --disable-silent-rules --libdir=${prefix}/lib/x86_64-linux-gnu --runstatedir=/run --disable-maintainer-mode --disable-dependency-tracking --prefix= --sysconfdir=/etc/nut --includedir=/usr/include --mandir=/usr/share/man --libdir=${prefix}/lib/x86_64-linux-gnu --libexecdir=/usr/libexec --with-ssl --with-nss --with-cgi --with-dev --enable-static --with-statepath=/run/nut --with-altpidpath=/run/nut --with-drvpath=/lib/nut --with-cgipath=/usr/lib/cgi-bin/nut --with-htmlpath=/usr/share/nut/www --with-pidpath=/run/nut --datadir=/usr/share/nut --with-pkgconfig-dir=/usr/lib/x86_64-linux-gnu/pkgconfig --with-user=nut --with-group=nut --with-udev-dir=/lib/udev --with-systemdsystemunitdir=/lib/systemd/system --with-systemdshutdowndir=/lib/systemd/system-shutdown --with-systemdtmpfilesdir=/usr/lib/tmpfiles.d --with-python=python3 --with-python3=/usr/bin/python3 --with-doc=man,html-single,html-chunked,pdf
   0.000352     [D1] debug level is '3'
   0.002200     [D1] Succeeded to become_user(nut): now UID=121 GID=130
   0.002266     [D1] upsdrv_initups (non-SHUT)...
   0.002285     [D2] Initializing an USB-connected UPS with library libusb-1.0.27 (API: 0x100010a) (NUT subdriver name='USB communication driver (libusb 1.0)' ver='0.46')
   0.008020     [D2] Checking device 1 of 4 (1D6B/0003)
   0.008045     [D1] Failed to open device (1D6B/0003), skipping: Access denied (insufficient permissions)
   0.008052     [D2] Checking device 2 of 4 (0403/6001)
   0.008064     [D1] Failed to open device (0403/6001), skipping: Access denied (insufficient permissions)
   0.008079     [D2] Checking device 3 of 4 (051D/0002)
   0.010003     [D2] - VendorID: 051d
   0.010014     [D2] - ProductID: 0002
   0.010018     [D2] - Manufacturer: American Power Conversion
   0.010022     [D2] - Product: Back-UPS BX750MI  FW:295202G -302202G
   0.010026     [D2] - Serial Number: 9B2416A22014
   0.010030     [D2] - Bus: 001
   0.010034     [D2] - Bus Port: 002
   0.010038     [D2] - Device: 004
   0.010042     [D2] - Device release number: 0106
   0.010046     [D2] Trying to match device
   0.010058     [D2] match_function_subdriver (non-SHUT mode): matching a device...
   0.010068     [D3] match_function_regex: matching a device...
   0.010145     [D2] Device matches
   0.010155     [D2] Reading first configuration descriptor
   0.010172     [D3] libusb_kernel_driver_active() returned 0: Success
   0.010186     [D2] failed to claim USB device: Resource busy
   0.010198     [D2] Kernel driver already detached
   0.010210     [D2] failed to claim USB device: Resource busy
   0.010225     [D2] Kernel driver already detached
   0.010237     [D2] failed to claim USB device: Resource busy
   0.010249     [D2] Kernel driver already detached
   0.010263     [D2] failed to claim USB device: Resource busy
   0.010275     [D2] Kernel driver already detached
   0.010286     Can't claim USB device [051d:0002]@0/0: Entity not found
   0.010300     upsnotify: failed to notify about state 4: no notification tech defined, will not spam more about it

erik@MinipcLG2:/etc/nut$ sudo cat /etc/nut/hosts.conf
MONITOR apcupskelder@localhost "APC-UPS kelder"

erik@MinipcLG2:/etc/nut$ sudo cat /etc/nut/nut.conf
MODE=netserver

erik@MinipcLG2:/etc/nut$ sudo cat /etc/nut/ups.conf
pollinterval = 1
maxretry = 3


[apcupskelder]
        driver = usbhid-ups
        port = auto
        desc = "Back-UPS BX750MI  FW:295202G -302202G"
        vendorid = 051d
        productid = 0002
        serial = 9B2416A22014
#        vendor = "American Power Conversion"
#        bus = 001
#        device = 005
#        busport = 002
        ###NOTMATCHED-YET###bcdDevice = "0106"

erik@MinipcLG2:/etc/nut$ sudo cat /etc/nut/upsd.conf
LISTEN 0.0.0.0 3493

erik@MinipcLG2:/etc/nut$ sudo cat /etc/nut/upsd.users
#[bespieder]
[monuser]
  password  = indUStr*a
#  bekijker primary
#  admin master
  admin primary

erik@MinipcLG2:/etc/nut$ sudo cat /etc/nut/upsmon.conf
#RUN_AS_USER nutgebruiker
RUN_AS_USER root
#MONITOR apcupskelder@localhost 1 bekijker indUStr*a primary
#MONITOR apcupskelder@localhost 1 admin indUStr*a master
MONITOR apcupskelder@localhost 1 admin indUStr*a primary


MINSUPPLIES 1
SHUTDOWNCMD "/sbin/shutdown -h +0"
NOTIFYCMD /usr/sbin/upssched
POLLFREQ 2
POLLFREQALERT 1
HOSTSYNC 15
DEADTIME 15
POWERDOWNFLAG /etc/nut/killpower

NOTIFYMSG ONLINE    "UPS %s on line power"
NOTIFYMSG ONBATT    "UPS %s on battery"
NOTIFYMSG LOWBATT   "UPS %s battery is low"
NOTIFYMSG FSD       "UPS %s: forced shutdown in progress"
NOTIFYMSG COMMOK    "Communications with UPS %s established"
NOTIFYMSG COMMBAD   "Communications with UPS %s lost"
NOTIFYMSG SHUTDOWN  "Auto logout and shutdown proceeding"
NOTIFYMSG REPLBATT  "UPS %s battery needs to be replaced"
NOTIFYMSG NOCOMM    "UPS %s is unavailable"
NOTIFYMSG NOPARENT  "upsmon parent process died - shutdown impossible"

NOTIFYFLAG ONLINE   SYSLOG+WALL+EXEC
NOTIFYFLAG ONBATT   SYSLOG+WALL+EXEC
NOTIFYFLAG LOWBATT  SYSLOG+WALL
NOTIFYFLAG FSD      SYSLOG+WALL+EXEC
NOTIFYFLAG COMMOK   SYSLOG+WALL+EXEC
NOTIFYFLAG COMMBAD  SYSLOG+WALL+EXEC
NOTIFYFLAG SHUTDOWN SYSLOG+WALL+EXEC
NOTIFYFLAG REPLBATT SYSLOG+WALL
NOTIFYFLAG NOCOMM   SYSLOG+WALL+EXEC
NOTIFYFLAG NOPARENT SYSLOG+WALL

RBWARNTIME 43200

NOCOMMWARNTIME 600

FINALDELAY 5

[ErikDB87]

I thought removing and installing the package again might solve the problem. I also removed /etc/nut.

But somehow, the directory /etc/nut is created again, but the config files in it are not...?

So I did this:

sudo apt remove nut nut-client nut-server
sudo reboot
sudo apt autoremove
sudo reboot
sudo rm -r /etc/nut
sudo apt install nut nut-client nut-server

And now:

erik@MinipcLG2:/etc/nut$ ls -pal
totaal 16
drwxr-xr-x   2 root root  4096 nov  2 16:29 ./
drwxr-xr-x 182 root root 12288 nov  2 16:29 ../

Somehow, I made it worse... But I don't understand how installing the packages again fails to install these files...?

EDIT
Some googling almost fixed this: https://ubuntuforums.org/showthread.php?t=2487834

But hosts.conf is still missing...

[jimklimov]

I believe some answers around this general issue are in the mailing list.

As for packaging, NUT team does not impact it directly, so it is technically a distro matter. That said, probably different packages defined for NUT there which deliver files which might need configuration files, all deliver the /etc/nut directory. There may be some package which also delivers *.conf.sample files which are just that - well-commented samples (to copy into *.conf and adapt to your setup). Packaging can not divine your device details, IP addresses, etc. to recreate your customized config files.

[ErikDB87]

Of course I didn't expect my amended config files to appear. :) But the standard ones - which were installed when I first installed NUT, didn't reappear... I manually added hosts.conf using sudo nano hosts.conf.

Anyway, I had hoped this reinstall would have reset all the permissions. But I was wrong...

But it looks like I'm where I started out; so maybe no harm no foul?

[jimklimov]

Probably no foul. As you edited ups.conf, NDE could have picked up the device definition and created the [email protected] instance again, so the manually-started driver conflicts with it again.

Re-check if the unit does exist and does not complain (like on the mailing list) - if so, go on to upsd (nut-server) and upsc client (to check it works) and finally upsmon for notifications and safe shutdown.

[ErikDB87]

I'm not sure I fully understand what you mean... I'm not really a Linux master :)

But here are some outputs:

erik@MinipcLG2:/etc/nut$ systemctl status [email protected]
● [email protected] - Network UPS Tools - device driver for NUT device 'apcupskelder'
     Loaded: loaded (/usr/lib/systemd/system/[email protected]; enabled; preset: enabled)
    Drop-In: /etc/systemd/system/[email protected]
             └─nut-driver-enumerator-generated-checksum.conf, nut-driver-enumerator-generated.conf
     Active: active (running) since Sat 2024-11-02 20:27:55 CET; 48s ago
    Process: 11894 ExecStartPre=/usr/bin/systemd-tmpfiles --create /usr/lib/tmpfiles.d/nut-common-tmpfiles.conf (code=exited, status=0/SUCCESS)
    Process: 11896 ExecStart=/bin/sh -c NUTDEV="`/usr/libexec/nut-driver-enumerator.sh --get-device-for-service apcupskelder`" && [ -n "$NUTDEV" ] || { echo "FATAL: Could not find a NUT device section for service unit apcupskelder" >&2 ; exit 1 ; } ; exec /sbin/upsdrvctl  start "$NUTDEV" (code=exited, status=0/SUCCESS)
   Main PID: 11934 (usbhid-ups)
      Tasks: 1 (limit: 9284)
     Memory: 608.0K (peak: 2.6M)
        CPU: 99ms
     CGroup: /system.slice/system-nut\x2ddriver.slice/[email protected]
             └─11934 /lib/nut/usbhid-ups -a apcupskelder

nov 02 20:27:55 MinipcLG2 nut-driver@apcupskelder[11923]: HIDParse: LogMax is less than LogMin. Vendor HID report descriptor may be incorrect; interpreting LogMax -1 as 255 in ReportID: 0x22
nov 02 20:27:55 MinipcLG2 nut-driver@apcupskelder[11923]: HIDParse: LogMax is less than LogMin. Vendor HID report descriptor may be incorrect; interpreting LogMax -1 as 255 in ReportID: 0x40
nov 02 20:27:55 MinipcLG2 nut-driver@apcupskelder[11923]: Using subdriver: APC HID 0.100
nov 02 20:27:55 MinipcLG2 nut-driver@apcupskelder[11923]: Network UPS Tools - Generic HID driver 0.52 (2.8.1)
nov 02 20:27:55 MinipcLG2 nut-driver@apcupskelder[11923]: USB communication driver (libusb 1.0) 0.46
nov 02 20:27:55 MinipcLG2 usbhid-ups[11934]: Startup successful
nov 02 20:27:55 MinipcLG2 usbhid-ups[11934]: upsnotify: failed to notify about state 2: no notification tech defined, will not spam more about it
nov 02 20:27:55 MinipcLG2 nut-driver@apcupskelder[11896]: Network UPS Tools - UPS driver controller 2.8.1
nov 02 20:27:55 MinipcLG2 systemd[1]: Started [email protected] - Network UPS Tools - device driver for NUT device 'apcupskelder'.
nov 02 20:27:56 MinipcLG2 usbhid-ups[11934]: sock_connect: enabling asynchronous mode (auto)

erik@MinipcLG2:/etc/nut$ systemctl status nut-server.service
● nut-server.service - Network UPS Tools - power devices information server
     Loaded: loaded (/usr/lib/systemd/system/nut-server.service; enabled; preset: enabled)
     Active: active (running) since Sat 2024-11-02 20:27:35 CET; 3min 24s ago
    Process: 11815 ExecStartPre=/usr/bin/systemd-tmpfiles --create /usr/lib/tmpfiles.d/nut-common-tmpfiles.conf (code=exited, status=0/SUCCESS)
   Main PID: 11818 (upsd)
      Tasks: 1 (limit: 9284)
     Memory: 464.0K (peak: 1.5M)
        CPU: 65ms
     CGroup: /system.slice/nut-server.service
             └─11818 /lib/nut/upsd -F

nov 02 20:27:35 MinipcLG2 nut-server[11818]: Running as foreground process, not saving a PID file
nov 02 20:27:35 MinipcLG2 nut-server[11818]: upsnotify: failed to notify about state 2: no notification tech defined, will not spam more about it
nov 02 20:27:35 MinipcLG2 upsd[11818]: Running as foreground process, not saving a PID file
nov 02 20:27:35 MinipcLG2 upsd[11818]: upsnotify: failed to notify about state 2: no notification tech defined, will not spam more about it
nov 02 20:27:35 MinipcLG2 nut-server[11818]: Can't connect to UPS [apcupskelder] (usbhid-ups-apcupskelder): No such file or directory
nov 02 20:27:35 MinipcLG2 upsd[11818]: Can't connect to UPS [apcupskelder] (usbhid-ups-apcupskelder): No such file or directory
nov 02 20:27:37 MinipcLG2 nut-server[11818]: Connected to UPS [apcupskelder]: usbhid-ups-apcupskelder
nov 02 20:27:37 MinipcLG2 upsd[11818]: Connected to UPS [apcupskelder]: usbhid-ups-apcupskelder
nov 02 20:27:56 MinipcLG2 nut-server[11818]: Connected to UPS [apcupskelder]: usbhid-ups-apcupskelder
nov 02 20:27:56 MinipcLG2 upsd[11818]: Connected to UPS [apcupskelder]: usbhid-ups-apcupskelder

erik@MinipcLG2:/etc/nut$ systemctl status upsd
● nut-server.service - Network UPS Tools - power devices information server
     Loaded: loaded (/usr/lib/systemd/system/nut-server.service; enabled; preset: enabled)
     Active: active (running) since Sat 2024-11-02 20:27:35 CET; 3min 49s ago
    Process: 11815 ExecStartPre=/usr/bin/systemd-tmpfiles --create /usr/lib/tmpfiles.d/nut-common-tmpfiles.conf (code=exited, status=0/SUCCESS)
   Main PID: 11818 (upsd)
      Tasks: 1 (limit: 9284)
     Memory: 464.0K (peak: 1.5M)
        CPU: 71ms
     CGroup: /system.slice/nut-server.service
             └─11818 /lib/nut/upsd -F

nov 02 20:27:35 MinipcLG2 nut-server[11818]: Running as foreground process, not saving a PID file
nov 02 20:27:35 MinipcLG2 nut-server[11818]: upsnotify: failed to notify about state 2: no notification tech defined, will not spam more about it
nov 02 20:27:35 MinipcLG2 upsd[11818]: Running as foreground process, not saving a PID file
nov 02 20:27:35 MinipcLG2 upsd[11818]: upsnotify: failed to notify about state 2: no notification tech defined, will not spam more about it
nov 02 20:27:35 MinipcLG2 nut-server[11818]: Can't connect to UPS [apcupskelder] (usbhid-ups-apcupskelder): No such file or directory
nov 02 20:27:35 MinipcLG2 upsd[11818]: Can't connect to UPS [apcupskelder] (usbhid-ups-apcupskelder): No such file or directory
nov 02 20:27:37 MinipcLG2 nut-server[11818]: Connected to UPS [apcupskelder]: usbhid-ups-apcupskelder
nov 02 20:27:37 MinipcLG2 upsd[11818]: Connected to UPS [apcupskelder]: usbhid-ups-apcupskelder
nov 02 20:27:56 MinipcLG2 nut-server[11818]: Connected to UPS [apcupskelder]: usbhid-ups-apcupskelder
nov 02 20:27:56 MinipcLG2 upsd[11818]: Connected to UPS [apcupskelder]: usbhid-ups-apcupskelder

erik@MinipcLG2:~$ systemctl status upsc
Unit upsc.service could not be found.

erik@MinipcLG2:/etc/nut$ systemctl status upsmon
● nut-monitor.service - Network UPS Tools - power device monitor and shutdown controller
     Loaded: loaded (/usr/lib/systemd/system/nut-monitor.service; enabled; preset: enabled)
     Active: active (running) since Sat 2024-11-02 20:27:35 CET; 4min 10s ago
    Process: 11836 ExecStartPre=/usr/bin/systemd-tmpfiles --create /usr/lib/tmpfiles.d/nut-common-tmpfiles.conf (code=exited, status=0/SUCCESS)
   Main PID: 11839 (upsmon)
      Tasks: 2 (limit: 9284)
     Memory: 888.0K (peak: 2.0M)
        CPU: 86ms
     CGroup: /system.slice/nut-monitor.service
             ├─11839 /lib/nut/upsmon -F
             └─11842 /lib/nut/upsmon -F

nov 02 20:27:35 MinipcLG2 nut-monitor[11839]: Using power down flag file /etc/nut/killpower
nov 02 20:27:35 MinipcLG2 nut-monitor[11842]: Init SSL without certificate database
nov 02 20:27:35 MinipcLG2 nut-monitor[11842]: upsnotify: failed to notify about state 2: no notification tech defined, will not spam more about it
nov 02 20:27:35 MinipcLG2 nut-monitor[11842]: Login on UPS [apcupskelder@localhost] failed - got [ERR ACCESS-DENIED]
nov 02 20:27:52 MinipcLG2 nut-monitor[11842]: Poll UPS [apcupskelder@localhost] failed - Driver not connected
nov 02 20:27:52 MinipcLG2 nut-monitor[11842]: Communications with UPS apcupskelder@localhost lost
nov 02 20:27:52 MinipcLG2 nut-monitor[11925]: Network UPS Tools upsmon 2.8.1
nov 02 20:27:54 MinipcLG2 nut-monitor[11842]: Poll UPS [apcupskelder@localhost] failed - Driver not connected
nov 02 20:27:56 MinipcLG2 nut-monitor[11842]: Communications with UPS apcupskelder@localhost established
nov 02 20:27:56 MinipcLG2 nut-monitor[11936]: Network UPS Tools upsmon 2.8.1

There seem to be some problems with usbhid-ups-apcupskelder...

[jimklimov]

Looks great actually: [email protected] initialized around 20:27:55, and at 20:27:56 accepted a socket connection. That's the same moment logged by nut-server.service (aliased as upsd to match the program name):

nov 02 20:27:56 MinipcLG2 upsd[11818]: Connected to UPS [apcupskelder]: usbhid-ups-apcupskelder

upsc is not a service, it is a command-line client. You should just run

:; upsc apcupskelder

(if on the same machine as upsd) and it should report a number of key: value pairs for some driver settings and all device readings it found.

WARNING: The nut-monitor.service (aliased as upsmon) did have a hiccup:

Login on UPS ***@***.*** failed - got [ERR ACCESS-DENIED]

This usually means either mismatch between /etc/nut/upsd.users and the credentials in MONITOR line of upsmon.conf, or bad permissions so one of the daemons can not read its config (or too open permissions so it can refuse to trust that file, whose passwords anyone can know).

I am a bit puzzled about upsnotify: failed to notify about state 2: no notification tech defined, will not spam more about it lines (daemon should have noticed it run under systemd, but that is not too consequential).

[ErikDB87]

upsc is not a service, it is a command-line client. You should just run\n\n:; upsc apcupskelder\n(if on the same machine as upsd) and it should report a number of key: value pairs for some driver settings and all device readings it found.

Indeed:

erik@MinipcLG2:~$ upsc apcupskelder
Init SSL without certificate database
battery.charge: 100
battery.charge.low: 10
battery.mfr.date: 2001/01/01
battery.runtime: 3920
battery.runtime.low: 120
battery.type: PbAc
battery.voltage: 13.6
battery.voltage.nominal: 12.0
device.mfr: American Power Conversion
device.model: Back-UPS BX750MI
device.serial: 9B2416A22014
device.type: ups
driver.debug: 0
driver.flag.allow_killpower: 0
driver.name: usbhid-ups
driver.parameter.pollfreq: 30
driver.parameter.pollinterval: 1
driver.parameter.port: auto
driver.parameter.productid: 0002
driver.parameter.serial: 9B2416A22014
driver.parameter.synchronous: auto
driver.parameter.vendorid: 051d
driver.state: quiet
driver.version: 2.8.1
driver.version.data: APC HID 0.100
driver.version.internal: 0.52
driver.version.usb: libusb-1.0.27 (API: 0x100010a)
input.sensitivity: low
input.transfer.high: 295
input.transfer.low: 145
input.voltage: 230.0
input.voltage.nominal: 230
ups.beeper.status: enabled
ups.delay.shutdown: 20
ups.firmware: 295202G -302202G
ups.load: 0
ups.mfr: American Power Conversion
ups.mfr.date: 2024/04/23
ups.model: Back-UPS BX750MI
ups.productid: 0002
ups.realpower.nominal: 410
ups.serial: 9B2416A22014
ups.status: OL
ups.test.result: Done and passed
ups.timer.reboot: 0
ups.timer.shutdown: -1
ups.vendorid: 051d 

WARNING: The nut-monitor.service (aliased as upsmon) did have a hiccup:\n\nLogin on UPS @.*** failed - got [ERR ACCESS-DENIED]\nThis usually means either mismatch between /etc/nut/upsd.users and the credentials in MONITOR line of upsmon.conf, or bad permissions so one of the daemons can not read its config (or too open permissions so it can refuse to trust that file, whose passwords anyone can know).

I had hoped a fresh install would have reset all the permissions... Do you have any idea which commands might fix the permissions issues?

[jimklimov]

Looking at your earlier post, the upsd.users you've posted seems very wrong. Please check the sample at https://github.com/networkupstools/nut/blob/master/conf/upsd.users.sample about syntax and expected contents. Also maybe change the passwords in the final configuration, just in case ;)

Also note, with an APC BX###MI device, #2565 and related issues and PRs may be relevant. That fix is not part of a released version yet though, so if you'd end up needing it before a release is cut and gets through distro packaging queues - a custom build would be required, e.g. per https://github.com/networkupstools/nut/wiki/Building-NUT-for-in%E2%80%90place-upgrades-or-non%E2%80%90disruptive-tests

[jimklimov]

As for file permissions, can you post ls -la /etc/nut output?

[ErikDB87]

Looking at your earlier post, the upsd.users you've posted seems very wrong. Please check the sample at https://github.com/networkupstools/nut/blob/master/conf/upsd.users.sample about syntax and expected contents. Also maybe change the passwords in the final configuration, just in case ;)

I see... Shame on me for following the guide, and not reading the readme. I did that eventually for a few other conf files, but not this one...

I assume this would be better?

[admin]
  password  = indUStr*a
  actions = FSD
  instcmds = ALL

?

(I'll have access to the Linux server later today; I'll run ls -la /etc/nut then as well.)

[jimklimov]

Well, coming from legacy long ago, before my time, that upsd.users lists two separate user concepts. I don't remember if I've ever tried mixing both into one user entry:

• User that can subscribe to the data server for monitoring and stay with a persistent session, with an upsmon <ROLE> line - that's the one you need to define and use in a MONITOR line of upsmon.conf
• User who can set variables or send commands, "all" or a selection of some - optional, for NUT clients like upsrw, upscmd or CGI upsset, etc.

[ErikDB87]

Well, coming from legacy long ago, before my time, that upsd.users lists two separate user concepts. I don't remember if I mixed both into one user entry:

• User that can subscribe to the data server for monitoring and stay with a persistent session, with an upsmon <ROLE> line - that's the one you need to define and use in a MONITOR line of upsmon.conf
• User who can set variables or send commands, "all" or a selection of some - optional, for NUT clients like upsrw, upscmd or CGI upsset, etc.

So it should be:

[admin]
  password  = indUStr*a
  actions = FSD
  instcmds = ALL
  upsmon primary

?

[jimklimov]

Maybe, if it does work to mix it like that. If something still complains, separate this into two users for two use-cases, e.g.:

[admin]
  password  = indUStr*a
  actions = FSD
  instcmds = ALL

[upsmon]
  password  = indUStr*a
  upsmon primary

(and then use MONITOR apcupskelder@localhost 1 upsmon indUStr*a primary in upsmon.conf).

[ErikDB87]

Thanks for all your time and effort, @jimklimov! Although we're not out of the woods yet, I'm afraid...

Now /etc/nut/upsd.users reads as follows:

[admin]
  password  = indUStr*a
  actions = FSD
  instcmds = ALL

[upsmon]
  password  = indUStr*a
  upsmon primary

(Although I don't understand where this admin user is used...? Since he's not mentioned anywhere?)

/etc/nut/upsmon.conf now reads:

RUN_AS_USER nut
MONITOR apcupskelder@localhost 1 admin indUStr*a primary
MONITOR apcupskelder@localhost 1 upsmon indUStr*a primary


MINSUPPLIES 1
SHUTDOWNCMD "/sbin/shutdown -h +0"
NOTIFYCMD /usr/sbin/upssched
POLLFREQ 2
POLLFREQALERT 1
HOSTSYNC 15
DEADTIME 15
POWERDOWNFLAG /etc/nut/killpower

NOTIFYMSG ONLINE    "UPS %s on line power"
NOTIFYMSG ONBATT    "UPS %s on battery"
NOTIFYMSG LOWBATT   "UPS %s battery is low"
NOTIFYMSG FSD       "UPS %s: forced shutdown in progress"
NOTIFYMSG COMMOK    "Communications with UPS %s established"
NOTIFYMSG COMMBAD   "Communications with UPS %s lost"
NOTIFYMSG SHUTDOWN  "Auto logout and shutdown proceeding"
NOTIFYMSG REPLBATT  "UPS %s battery needs to be replaced"
NOTIFYMSG NOCOMM    "UPS %s is unavailable"
NOTIFYMSG NOPARENT  "upsmon parent process died - shutdown impossible"

NOTIFYFLAG ONLINE   SYSLOG+WALL+EXEC
NOTIFYFLAG ONBATT   SYSLOG+WALL+EXEC
NOTIFYFLAG LOWBATT  SYSLOG+WALL
NOTIFYFLAG FSD      SYSLOG+WALL+EXEC
NOTIFYFLAG COMMOK   SYSLOG+WALL+EXEC
NOTIFYFLAG COMMBAD  SYSLOG+WALL+EXEC
NOTIFYFLAG SHUTDOWN SYSLOG+WALL+EXEC
NOTIFYFLAG REPLBATT SYSLOG+WALL
NOTIFYFLAG NOCOMM   SYSLOG+WALL+EXEC
NOTIFYFLAG NOPARENT SYSLOG+WALL

RBWARNTIME 43200

NOCOMMWARNTIME 600

FINALDELAY 5

Now:

erik@MinipcLG2:~$ systemctl status upsmon
● nut-monitor.service - Network UPS Tools - power device monitor and shutdown controller
     Loaded: loaded (/usr/lib/systemd/system/nut-monitor.service; enabled; preset: enabled)
     Active: active (running) since Wed 2024-11-06 14:40:27 CET; 11min ago
    Process: 1387 ExecStartPre=/usr/bin/systemd-tmpfiles --create /usr/lib/tmpfiles.d/nut-common-tmpfiles.conf (code=exited, status=0/SUCCESS)
   Main PID: 1391 (upsmon)
      Tasks: 2 (limit: 9284)
     Memory: 2.5M (peak: 2.8M)
        CPU: 74ms
     CGroup: /system.slice/nut-monitor.service
             ├─1391 /lib/nut/upsmon -F
             └─1395 /lib/nut/upsmon -F

nov 06 14:40:27 MinipcLG2 systemd[1]: Starting nut-monitor.service - Network UPS Tools - power device monitor and shutdown controller...
nov 06 14:40:27 MinipcLG2 systemd[1]: Started nut-monitor.service - Network UPS Tools - power device monitor and shutdown controller.
nov 06 14:40:27 MinipcLG2 nut-monitor[1391]: fopen /run/nut/upsmon.pid: No such file or directory
nov 06 14:40:27 MinipcLG2 nut-monitor[1391]: Could not find PID file to see if previous upsmon instance is already running!
nov 06 14:40:27 MinipcLG2 nut-monitor[1391]: UPS: apcupskelder@localhost (primary) (power value 1)
nov 06 14:40:27 MinipcLG2 nut-monitor[1391]: Using power down flag file /etc/nut/killpower
nov 06 14:40:27 MinipcLG2 nut-monitor[1395]: Init SSL without certificate database
nov 06 14:40:27 MinipcLG2 nut-monitor[1395]: upsnotify: failed to notify about state 2: no notification tech defined, will not spam more about it

Unfortunately, even after a Linux reboot, still:

erik@MinipcLG2:~$ sudo upsdrvctl shutdown
Network UPS Tools - UPS driver controller 2.8.1
Network UPS Tools - Generic HID driver 0.52 (2.8.1)
USB communication driver (libusb 1.0) 0.46
select with socket: Invalid argument
Can't claim USB device [051d:0002]@0/0: Entity not found
upsnotify: failed to notify about state 4: no notification tech defined, will not spam more about it
Driver failed to start (exit status=1)

As requested:

erik@MinipcLG2:~$ ls -la /etc/nut
totaal 112
drwxr-xr-x   2 root nut   4096 nov  6 14:48 .
drwxr-xr-x 182 root root 12288 nov  6 03:30 ..
-rw-r--r--   1 root root    48 nov  2 18:01 hosts.conf
-rw-r-----   1 root nut     15 nov  2 16:42 nut.conf
-rw-r-----   1 root root  4156 nov  2 16:41 nut.example.conf
-rw-r-----   1 root root  4201 nov  2 16:41 upsched.example.conf
-rw-r-----   1 root nut    385 nov  2 18:01 ups.conf
-rw-r-----   1 root nut     20 nov  2 18:02 upsd.conf
-rw-r-----   1 root root  8247 nov  2 16:41 upsd.example.conf
-rw-r-----   1 root nut    116 nov  6 14:35 upsd.users
-rw-r-----   1 root root  9845 nov  2 16:41 ups.example.conf
-rw-r-----   1 root nut   1381 nov  6 14:35 upsmon.conf
-rw-r-----   1 root root 24344 nov  2 16:41 upsmon.example.conf
-rw-r--r--   1 root root  1120 nov  2 18:03 upssched-cmd.sh
-rw-r-----   1 root nut    745 nov  2 18:03 upssched.conf

---

EDIT
I don't understand how, but once, I got this:

erik@MinipcLG2:/etc/nut$ sudo upsdrvctl shutdown
Network UPS Tools - UPS driver controller 2.8.1
Network UPS Tools - Generic HID driver 0.52 (2.8.1)
USB communication driver (libusb 1.0) 0.46
Can't open /run/nut/usbhid-ups-apcupskelder: No such file or directory
HIDParse: LogMax is less than LogMin. Vendor HID report descriptor may be incorrect; interpreting LogMax -1 as 255 in ReportID: 0x0c
HIDParse: LogMax is less than LogMin. Vendor HID report descriptor may be incorrect; interpreting LogMax -1 as 255 in ReportID: 0x22
HIDParse: LogMax is less than LogMin. Vendor HID report descriptor may be incorrect; interpreting LogMax -1 as 255 in ReportID: 0x40
Using subdriver: APC HID 0.100
Initiating UPS shutdown
upsnotify: failed to notify about state 4: no notification tech defined, will not spam more about it

But trying it again, resulted in failure again:

erik@MinipcLG2:/etc/nut$ sudo upsdrvctl shutdown
Network UPS Tools - UPS driver controller 2.8.1
Network UPS Tools - Generic HID driver 0.52 (2.8.1)
USB communication driver (libusb 1.0) 0.46
select with socket: Invalid argument
Can't claim USB device [051d:0002]@0/0: Entity not found
upsnotify: failed to notify about state 4: no notification tech defined, will not spam more about it
Driver failed to start (exit status=1)

Puzzling...

[jimklimov]

Looks cool about getting the driver and upsmon to play together, finally.

I think sudo upsdrvctl shutdown suffers from a similar conflict with a running driver. Would it show more clues if you try passing debug verbosity to this copy of the driver - sudo upsdrvctl -DDDDDD -d shutdown ?

I think with #1917 in NUT v2.8.1 the driver program should have tried to communicate with the previous instance over its local socket (same as communications with upsd), so the originally running program would remain connected to the UPS and pass it the shutdown command(s). Maybe select with socket: Invalid argument is about inability to find or use that local socket, so it tries from scratch (and for some reason does not try to kill off the earlier copy of the driver program - e.g. if it did not leave PID files)?

[jimklimov]

Also note, that if you get sudo upsdrvctl shutdown to work, it would immediately (or close to that) power off the UPS, without telling the OS to shut down.

You may be after upsmon -c fsd instead, so it would initiate the shutdown, and if the OS integration works well, that would call sudo upsdrvctl shutdown in the endgame (when NUT daemons are all down, along with other services), with no conflict for a running driver.

[jimklimov]

Alternately, you can try sending commands to the UPS (using the admin account created earlier and upscmd client) directly.

[ErikDB87]

Would it show more clues if you try passing debug verbosity to this copy of the driver - sudo upsdrvctl -DDDDDD -d shutdown ?

erik@MinipcLG2:~$ sudo upsdrvctl -DDDDDD -d shutdown
Network UPS Tools - UPS driver controller 2.8.1
   0.000000     [D1] upsdrvctl commanding all drivers (1 found): (null)
   0.000009     [D1] Shutdown UPS: apcupskelder
   0.000015     [D2] exec:  /lib/nut/usbhid-ups -a apcupskelder -k
   0.000106     [D2] Starting driver with debug but without explicit backgrounding: will not wait for it to fork and detach, continuing...
   0.000127     [D1] upsdrvctl: successfully finished
   0.000131     [D1] Completed the job of upsdrvctl tool, cleaning up and exiting now
   0.000136     [D1] Completed the job of upsdrvctl tool, clean-up finished, exiting now

The UPS didn't power cylce.

You may be after upsmon -c fsd instead, so it would initiate the shutdown, and if the OS integration works well, that would call sudo upsdrvctl shutdown in the endgame (when NUT daemons are all down, along with other services), with no conflict for a running driver.

erik@MinipcLG2:~$ sudo upsmon -DDDDD -c fsd
Network UPS Tools upsmon 2.8.1
   0.000000     [D1] Signaled old daemon OK

The Linux box shut down, but the UPS didn't power cycle...

Alternately, you can try sending commands to the UPS (using the admin account created earlier and upscmd client) directly.

You mean like so:

erik@MinipcLG2:/etc/nut$ upscmd -u admin -p indUStr*a apcupskelder shutdown.reboot
OK

?

Unfortunately, again no power cycle.

(I've got a table lamp lit, so a power loss should be visible.)

[jimklimov]

Looking at current code for the driver, the command sequence in

nut/drivers/usbhid-ups.c

Lines 969 to 993 in d244d73

	void upsdrv_shutdown(void)
	{
	upsdebugx(1, "upsdrv_shutdown...");
	/* Try to shutdown with delay */
	if (instcmd("shutdown.return", NULL) == STAT_INSTCMD_HANDLED) {
	/* Shutdown successful */
	return;
	}
	/* If the above doesn't work, try shutdown.reboot */
	if (instcmd("shutdown.reboot", NULL) == STAT_INSTCMD_HANDLED) {
	/* Shutdown successful */
	return;
	}
	/* If the above doesn't work, try load.off.delay */
	if (instcmd("load.off.delay", NULL) == STAT_INSTCMD_HANDLED) {
	/* Shutdown successful */
	return;
	}
	upslogx(LOG_ERR, "Shutdown failed!");
	set_exit_flag(-1);
	}

is hard-coded to try several options (whichever works). Can you see if your UPS picks up the others?

[ErikDB87]

Can you see if your UPS picks up the others?

I assume you mean the other options mentioned in that Java code?

erik@MinipcLG2:/etc/nut$ sudo upscmd -u admin -p indUStr*a apcupskelder shutdown.return
Unexpected response from upsd: ERR CMD-NOT-SUPPORTED
erik@MinipcLG2:/etc/nut$ sudo upscmd -u admin -p indUStr*a apcupskelder shutdown.reboot
OK
erik@MinipcLG2:/etc/nut$ sudo upscmd -u admin -p indUStr*a apcupskelder load.off.delay
OK

No power cycle...

I also tried:

erik@MinipcLG2:/etc/nut$ sudo upscmd -u admin -p indUStr*a apcupskelder load.off
OK

But no effect on the lamp.

FYI:

erik@MinipcLG2:/etc/nut$ upscmd -l apcupskelder
Instant commands supported on UPS [apcupskelder]:

beeper.disable - Disable the UPS beeper
beeper.enable - Enable the UPS beeper
beeper.mute - Temporarily mute the UPS beeper
beeper.off - Obsolete (use beeper.disable or beeper.mute)
beeper.on - Obsolete (use beeper.enable)
driver.killpower - Tell the driver daemon to initiate UPS shutdown; should be unlocked with driver.flag.allow_killpower option or variable setting
driver.reload - Reload running driver configuration from the file system (only works for changes in some options)
driver.reload-or-error - Reload running driver configuration from the file system (only works for changes in some options); return an error if something changed and could not be applied live (so the caller can restart it with new options)
driver.reload-or-exit - Reload running driver configuration from the file system (only works for changes in some options); exit the running driver if something changed and could not be applied live (so service management framework can restart it with new options)
load.off - Turn off the load immediately
load.off.delay - Turn off the load with a delay (seconds)
shutdown.reboot - Shut down the load briefly while rebooting the UPS
shutdown.stop - Stop a shutdown in progress
test.battery.start.deep - Start a deep battery test
test.battery.start.quick - Start a quick battery test
test.battery.stop - Stop the battery test

[jimklimov]

"OK" there means the command was accepted by the driver. Please try upscmd -w ... to wait for the result, maybe it would report more details.

It may also be that the device model/firmware does not actually support that command, or we poke a wrong USB endpoint for that (e.g. worked for other related devices but not this one).

[jimklimov]

And that's plain old C code ;)

[ErikDB87]

"OK" there means the command was accepted by the driver. Please try upscmd -w ... to wait for the result, maybe it would report more details.

erik@MinipcLG2:/etc/nut$ sudo upscmd -u admin -p indUStr*a -w apcupskelder shutdown.reboot
SUCCESS
erik@MinipcLG2:/etc/nut$ sudo upscmd -u admin -p indUStr*a -w apcupskelder shutdown.return
Unexpected response from upsd: ERR CMD-NOT-SUPPORTED
erik@MinipcLG2:/etc/nut$ sudo upscmd -u admin -p indUStr*a -w apcupskelder load.off.delay
SUCCESS
erik@MinipcLG2:/etc/nut$ sudo upscmd -u admin -p indUStr*a -w apcupskelder load.off
SUCCESS

But no effect on the lamp...

It may also be that the device model/firmware does not actually support that command, or we poke a wrong USB endpoint for that (e.g. worked for other related devices but not this one).

What would that mean for my setup? End of the line? Or are there more avenues to be walked? :)

[ErikDB87]

Apparently, without a packaged NUT to determine "in-place" replacement paths from, configure reverted to default paths, e.g.:

* Tool program path:    /usr/local/ups/bin

On one hand, this avoids conflicts with system-delivered files as much as possible (e.g. resources for systemd or augeas still land into common locations); on another - these locations are not in your default PATH...

Does this mean I uninstalled the packaged NUT? Should I reinstall it? But maybe first make uninstall, and go through that entire process after the package install?

[jimklimov]

Seems so, wouldn't hurt to redo it cleanly.

[ErikDB87]

Hooray!

erik@MinipcLG2:~$ upsc apcupskelder
battery.charge: 100
battery.charge.low: 98
battery.mfr.date: 2001/01/01
battery.runtime: 2860
battery.runtime.low: 120
battery.type: PbAc
battery.voltage: 13.6
battery.voltage.nominal: 12.0
device.mfr: American Power Conversion
device.model: Back-UPS BX750MI
device.serial: 9B2416A22014
device.type: ups
driver.debug: 0
driver.flag.allow_killpower: 0
driver.name: usbhid-ups
driver.parameter.interrupt_pipe_no_events_tolerance: -1
driver.parameter.pollfreq: 30
driver.parameter.pollinterval: 1
driver.parameter.port: auto
driver.parameter.productid: 0002
driver.parameter.serial: 9B2416A22014
driver.parameter.synchronous: auto
driver.parameter.vendorid: 051d
driver.state: quiet
driver.version: 2.7.4.11052.56-11108-g788888094
driver.version.data: APC HID 0.100
driver.version.internal: 0.60
driver.version.usb: libusb-1.0.27 (API: 0x100010a)
input.sensitivity: medium
input.transfer.high: 295
input.transfer.low: 145
input.voltage: 232.0
input.voltage.nominal: 230
ups.beeper.status: enabled
ups.delay.shutdown: 20
ups.firmware: 295202G -302202G
ups.load: 11
ups.mfr: American Power Conversion
ups.mfr.date: 2024/04/23
ups.model: Back-UPS BX750MI
ups.productid: 0002
ups.realpower.nominal: 410
ups.serial: 9B2416A22014
ups.status: OL
ups.test.result: Done and passed
ups.timer.reboot: 0
ups.timer.shutdown: -1
ups.vendorid: 051d

But changing battery.charge.low doesn't succeed...

erik@MinipcLG2:~$ upscmd -u admin -p indUStr*a apcupskelder test.battery.start.deep
OK
erik@MinipcLG2:~$ upsrw -s battery.charge.low=10  -u admin -p indUStr*a apcupskelder
Unexpected response from upsd: ERR ACCESS-DENIED

And I believe the variable should be changeable?

erik@MinipcLG2:~$ upsrw -l apcupskelder
[battery.charge.low]
Remaining battery level when UPS switches to LB (percent)
Type: STRING
Maximum length: 10
Value: 98

[battery.mfr.date]
Battery manufacturing date
Type: STRING
Maximum length: 10
Value: 2001/01/01

[battery.runtime.low]
Remaining battery runtime when UPS switches to LB (seconds)
Type: STRING
Maximum length: 10
Value: 120

[driver.debug]
Current debug verbosity level of the driver program
Type: NUMBER
Value: 0

[driver.flag.allow_killpower]
Safety flip-switch to allow the driver daemon to send UPS shutdown command (accessible via driver.killpower)
Type: NUMBER
Value: 0

[input.sensitivity]
Input power sensitivity
Type: STRING
Maximum length: 10
Value: medium

[input.transfer.high]
High voltage transfer point (V)
Type: STRING
Maximum length: 10
Value: 295

[input.transfer.low]
Low voltage transfer point (V)
Type: STRING
Maximum length: 10
Value: 145

[ups.delay.shutdown]
Interval to wait after shutdown with delay command (seconds)
Type: STRING
Maximum length: 10
Value: 20

[jimklimov]

In your latest upsd.users I think you did not allow actions = SET?

[ErikDB87]

In your latest upsd.users I think you did not allow actions = SET?

That was it. I should have read that... Apologies.

Alas, no success:

erik@MinipcLG2:~$ upsrw -s battery.charge.low=10  -u admin -p indUStr*a apcupskelder
OK
erik@MinipcLG2:~$ upsc apcupskelder | grep battery
battery.charge: 14
battery.charge.low: 98
battery.mfr.date: 2001/01/01
battery.runtime: 400
battery.runtime.low: 120
battery.type: PbAc
battery.voltage: 12.5
battery.voltage.nominal: 12.0

Also, the battery allegedly is at 14 % again?

[jimklimov]

It seems so, despite the somewhat reasonable 12.5V (might go up to 13.8 or so when fully charged though).

Did you check with upsc immediately? Maybe it takes some time for the firmware to recognize a new setting...

[jimklimov]

As for the battery, perhaps check it by leaving the UPS unplugged with a non-critical load (like an incandescent lamp or fan) that could best emulate the power draw of your computer, and see if it holds up for minutes or seconds.

If the UPS can be safely opened to check the battery visually (most are replaceable) that can also be helpful - see if it is too swollen (plastic walls are usually not perfectly flat, but swelling is distinctive), etc.

There was recently a discussion ported to Wiki about how different community members revise the replacement batteries they order (nominal vs factual weight, etc.) - maybe yours is indeed defective? See https://github.com/networkupstools/nut/wiki/Choosing-replacement-batteries-for-an-UPS

[ErikDB87]

It seems so, despite the somewhat reasonable 12.5V (might go up to 13.8 or so when fully charged though).

But the UPS has been plugged in the entire time, and the value read 100 earlier today (see above)...?

Did you check with upsc immediately? Maybe it takes some time for the firmware to recognize a new setting...

I'll check later today. Maybe the command threw off the battery.charge?

[jimklimov]

Should not have... Although it's anyone's guess what the black box on the other side of the protocol does.

One more guess I had is that some drivers map a number of hardware values (different USB or SNMP readings are mapped to same NUT names in different HW/FW of related models).

But in case of apc-hid.c this excuse does not pass, it only has one mapping for battery.charge.

[ErikDB87]

A few hours ago, this was still the reading:

erik@MinipcLG2:~$ upsc apcupskelder | grep battery
battery.charge: 61
battery.charge.low: 98
battery.mfr.date: 2001/01/01
battery.runtime: 1770
battery.runtime.low: 120
battery.type: PbAc
battery.voltage: 13.7
battery.voltage.nominal: 12.0

But now it's this:

erik@MinipcLG2:~$ upsc apcupskelder | grep battery
battery.charge: 100
battery.charge.low: 10
battery.mfr.date: 2001/01/01
battery.runtime: 2860
battery.runtime.low: 120
battery.type: PbAc
battery.voltage: 14.4
battery.voltage.nominal: 12.0

The UPS works in mysterious ways...

Now of course the next step is to actually make sure a power race can be avoided.

[jimklimov]

Also a gentle reminder - if you got the code base from that PR #2750 built, would be great to check if the driver program would finally start for its shutdown mode (drivername -DDDDDD -a ups -k) or still not find an entity somehow.

[ErikDB87]

Also a gentle reminder - if you got the code base from that PR #2750 built, would be great to check if the driver program would finally start for its shutdown mode (drivername -DDDDDD -a ups -k) or still not find an entity somehow.

I first tried usbhid-ups -DDDDDD -a apcupskelder -k, but that didn't work. I then tried upsdrvctl -DDDDDD -a apcupskelder -k, and my system said I needed to install nut-server (I assume I uninstalled everything some time ago).

I uninstalled the git installation, installed the package, and then reinstalled the git installation. This time the installation took forever!

Now this is the output:

erik@MinipcLG2:~/nut-issue-2666$ upsc apcupskelder | grep battery
Init SSL without certificate database
battery.charge: 100
battery.charge.low: 10
battery.mfr.date: 2001/01/01
battery.runtime: 2436
battery.runtime.low: 120
battery.type: PbAc
battery.voltage: 13.6
battery.voltage.nominal: 12.0
erik@MinipcLG2:~/nut-issue-2666$ usbhid-ups -DDDDDD -a apcupskelder -k
   0.000010     [D5] send_to_all: SETINFO driver.state "init.starting"
Network UPS Tools 2.7.4.11052.56-11108-g788888094 (development iteration after 2.7.4) - Generic HID driver 0.60
USB communication driver (libusb 1.0) 0.50
   0.000150     [D1] upsdrv_makevartable...
   0.000243     [D5] send_to_all: SETINFO driver.version.usb "libusb-1.0.27 (API: 0x100010a)"
   0.000264     [D1] Using USB implementation: libusb-1.0.27 (API: 0x100010a)
   0.000361     Can't open /etc/nut/ups.conf: Can't open /etc/nut/ups.conf: Permission denied
   0.000382     [D5] send_to_all: SETINFO driver.state "cleanup.exit"
   0.000398     upsnotify: notify about state NOTIFY_STATE_STOPPING with libsystemd: was requested, but not running as a service unit now, will not spam more about it
   0.000438     [D1] On systems without service units, consider `export NUT_QUIET_INIT_UPSNOTIFY=true`
   0.000460     upsnotify: failed to notify about state NOTIFY_STATE_STOPPING: no notification tech defined, will not spam more about it
erik@MinipcLG2:~/nut-issue-2666$ sudo usbhid-ups -DDDDDD -a apcupskelder -k
   0.000003     [D5] send_to_all: SETINFO driver.state "init.starting"
Network UPS Tools 2.7.4.11052.56-11108-g788888094 (development iteration after 2.7.4) - Generic HID driver 0.60
USB communication driver (libusb 1.0) 0.50
   0.000060     [D1] upsdrv_makevartable...
   0.000090     [D5] send_to_all: SETINFO driver.version.usb "libusb-1.0.27 (API: 0x100010a)"
   0.000096     [D1] Using USB implementation: libusb-1.0.27 (API: 0x100010a)
   0.000131     [D5] do_upsconf_args: confupsname=(null), var=pollinterval, val=1
   0.000137     [D5] do_upsconf_args: call do_global_args()
   0.000143     [D3] do_global_args: var='pollinterval' val='1'
   0.000156     [D6] testval_reloadable: var=pollinterval, oldval=2, newval=1, reloadable=1, reload_flag=0
   0.000164     [D1] testval_reloadable: setting 'pollinterval' exists and differs: new value '1' vs. '2'
   0.000171     [D6] testval_reloadable: verdict for (re)loading var=pollinterval value: 1
   0.000180     [D5] do_upsconf_args: confupsname=(null), var=maxretry, val=3
   0.000186     [D5] do_upsconf_args: call do_global_args()
   0.000196     [D3] do_global_args: var='maxretry' val='3'
   0.000206     [D5] do_upsconf_args: confupsname=apcupskelder, var=driver, val=usbhid-ups
   0.000212     [D5] do_upsconf_args: call main_arg()
   0.000218     [D3] main_arg: var='driver' val='usbhid-ups'
   0.000228     [D5] do_upsconf_args: not a main_arg()
   0.000234     [D5] do_upsconf_args: this is a 'driver' setting, may we proceed?
   0.000241     [D6] testval_reloadable: var=driver, oldval=usbhid-ups, newval=usbhid-ups, reloadable=0, reload_flag=0
   0.000248     [D6] testval_reloadable: verdict for (re)loading var=driver value: -1
   0.000254     [D5] do_upsconf_args: 'driver' setting already applied with this value
   0.000262     [D5] do_upsconf_args: confupsname=apcupskelder, var=port, val=auto
   0.000267     [D5] do_upsconf_args: call main_arg()
   0.000272     [D3] main_arg: var='port' val='auto'
   0.000278     [D6] testinfo_reloadable: var=port, infoname=driver.parameter.port, newval=auto, reloadable=0, reload_flag=0
   0.000283     [D6] testinfo_reloadable: verdict for (re)loading var=port value: 1
   0.000291     [D5] send_to_all: SETINFO driver.parameter.port "auto"
   0.000329     [D5] do_upsconf_args: confupsname=apcupskelder, var=desc, val=Back-UPS BX750MI  FW:295202G -302202G
   0.000345     [D5] do_upsconf_args: call main_arg()
   0.000352     [D3] main_arg: var='desc' val='Back-UPS BX750MI  FW:295202G -302202G'
   0.000361     [D5] do_upsconf_args: confupsname=apcupskelder, var=vendorid, val=051d
   0.000369     [D5] do_upsconf_args: call main_arg()
   0.000375     [D3] main_arg: var='vendorid' val='051d'
   0.000381     [D5] do_upsconf_args: not a main_arg()
   0.000387     [D5] do_upsconf_args: process as value
   0.000393     [D6] testvar_reloadable: searching for var=vendorid, vartype=2, reload_flag=0
   0.000401     [D6] testvar_reloadable: found var=vendorid, val='(null)' => '051d', vartype=2 => 2, found=0, reloadable=0, reload_flag=0
   0.000411     [D6] testvar_reloadable: verdict for (re)loading var=vendorid value: 1
   0.000421     [D5] send_to_all: SETINFO driver.parameter.vendorid "051d"
   0.000430     [D5] do_upsconf_args: confupsname=apcupskelder, var=productid, val=0002
   0.000436     [D5] do_upsconf_args: call main_arg()
   0.000442     [D3] main_arg: var='productid' val='0002'
   0.000448     [D5] do_upsconf_args: not a main_arg()
   0.000454     [D5] do_upsconf_args: process as value
   0.000460     [D6] testvar_reloadable: searching for var=productid, vartype=2, reload_flag=0
   0.000468     [D6] testvar_reloadable: found var=productid, val='(null)' => '0002', vartype=2 => 2, found=0, reloadable=0, reload_flag=0
   0.000479     [D6] testvar_reloadable: verdict for (re)loading var=productid value: 1
   0.000488     [D5] send_to_all: SETINFO driver.parameter.productid "0002"
   0.000497     [D5] do_upsconf_args: confupsname=apcupskelder, var=serial, val=9B2416A22014
   0.000504     [D5] do_upsconf_args: call main_arg()
   0.000510     [D3] main_arg: var='serial' val='9B2416A22014'
   0.000516     [D5] do_upsconf_args: not a main_arg()
   0.000522     [D5] do_upsconf_args: process as value
   0.000528     [D6] testvar_reloadable: searching for var=serial, vartype=2, reload_flag=0
   0.000535     [D6] testvar_reloadable: found var=serial, val='(null)' => '9B2416A22014', vartype=2 => 2, found=0, reloadable=0, reload_flag=0
   0.000544     [D6] testvar_reloadable: verdict for (re)loading var=serial value: 1
   0.000553     [D5] send_to_all: SETINFO driver.parameter.serial "9B2416A22014"
   0.000571     [D1] Network UPS Tools version 2.7.4.11052.56-11108-g788888094 (development iteration after 2.7.4) built with gcc (Ubuntu 13.3.0-6ubuntu2~24.04) 13.3.0 and configured with flags: --prefix=/usr --sbindir=/usr/sbin --sysconfdir=/etc/nut --with-group=nut --with-user=nut --with-libsystemd
   0.000589     [D1] debug level is '6'
   0.000597     [D5] send_to_all: SETINFO driver.debug "6"
   0.000605     [D5] send_to_all: SETFLAGS driver.debug RW NUMBER
   0.001653     [D1] Succeeded to become_user(nut): now UID=121 GID=130
   0.001695     [D5] upsdrvquery_write: write to driver socket: NOBROADCAST

   0.001706     [D5] upsdrvquery_write: write to driver socket: PING

   0.001716     [D5] upsdrvquery_prepare: waiting for a while to flush server messages
   0.001722     [D5] upsdrvquery_read_timeout: tv={sec=3, usec=000000}
   0.001795     [D5] upsdrvquery_read_timeout: received 5 bytes from driver socket: PONG

   0.001804     [D5] upsdrvquery_prepare: got expected PONG
   0.001831     [D5] upsdrvquery_prepare: ready for tracked commands
   0.001841     [D5] upsdrvquery_write: write to driver socket: SET driver.flag.allow_killpower 1 TRACKING 2DDC5036-F665-4D29-BE4C-0374D091D263

   0.001862     [D5] upsdrvquery_request: will wait up to 15.000000 sec for response to SET driver.flag.allow_killpower 1

   0.001869     [D5] upsdrvquery_read_timeout: tv={sec=15, usec=000000}
   0.001976     [D5] upsdrvquery_read_timeout: received 48 bytes from driver socket: TRACKING 2DDC5036-F665-4D29-BE4C-0374D091D263 0

   0.001997     [D5] upsdrvquery_request: parsed out command status: 0
   0.002004     [D5] upsdrvquery_close: closing driver socket, try to say goodbye
   0.002009     [D5] upsdrvquery_write: write to driver socket: LOGOUT

   0.002057     [D5] upsdrvquery_close: okay
   1.002514     [D5] upsdrvquery_write: write to driver socket: NOBROADCAST

   1.002576     [D5] upsdrvquery_write: write to driver socket: PING

   1.002599     [D5] upsdrvquery_prepare: waiting for a while to flush server messages
   1.002633     [D5] upsdrvquery_read_timeout: tv={sec=3, usec=000000}
   1.096866     [D5] upsdrvquery_read_timeout: received 5 bytes from driver socket: PONG

   1.096895     [D5] upsdrvquery_prepare: got expected PONG
   1.096912     [D5] upsdrvquery_prepare: ready for tracked commands
   1.096939     [D5] upsdrvquery_write: write to driver socket: INSTCMD driver.killpower TRACKING 98C489FD-821C-4132-9D93-4F6590B55E63

   1.097010     [D1] upsdrvquery_request: will wait indefinitely for response to INSTCMD driver.killpower

   1.097031     [D5] upsdrvquery_read_timeout: tv={sec=-1, usec=-00001} (unlimited timeout)
   1.097675     [D5] upsdrvquery_read_timeout: received 48 bytes from driver socket: TRACKING 98C489FD-821C-4132-9D93-4F6590B55E63 0

   1.097719     [D5] upsdrvquery_request: parsed out command status: 0
   1.097734     [D5] upsdrvquery_close: closing driver socket, try to say goodbye
   1.097746     [D5] upsdrvquery_write: write to driver socket: LOGOUT

   1.097772     [D5] upsdrvquery_close: okay
   2.098008     Request to killpower via running driver returned code 0
   2.098061     [D5] send_to_all: SETINFO driver.state "cleanup.exit"
   2.098095     upsnotify: notify about state NOTIFY_STATE_STOPPING with libsystemd: was requested, but not running as a service unit now, will not spam more about it
   2.098132     [D1] On systems without service units, consider `export NUT_QUIET_INIT_UPSNOTIFY=true`
   2.098158     upsnotify: failed to notify about state NOTIFY_STATE_STOPPING: no notification tech defined, will not spam more about it

No success, the UPS never powered down.

I did the same with the UPS unplugged from the power outlet. It looks to me like the same output:

erik@MinipcLG2:~/nut-issue-2666$ sudo usbhid-ups -DDDDDD -a apcupskelder -k
   0.000002     [D5] send_to_all: SETINFO driver.state "init.starting"
Network UPS Tools 2.7.4.11052.56-11108-g788888094 (development iteration after 2.7.4) - Generic HID driver 0.60
USB communication driver (libusb 1.0) 0.50
   0.000045     [D1] upsdrv_makevartable...
   0.000069     [D5] send_to_all: SETINFO driver.version.usb "libusb-1.0.27 (API: 0x100010a)"
   0.000075     [D1] Using USB implementation: libusb-1.0.27 (API: 0x100010a)
   0.000111     [D5] do_upsconf_args: confupsname=(null), var=pollinterval, val=1
   0.000119     [D5] do_upsconf_args: call do_global_args()
   0.000129     [D3] do_global_args: var='pollinterval' val='1'
   0.000140     [D6] testval_reloadable: var=pollinterval, oldval=2, newval=1, reloadable=1, reload_flag=0
   0.000143     [D1] testval_reloadable: setting 'pollinterval' exists and differs: new value '1' vs. '2'
   0.000146     [D6] testval_reloadable: verdict for (re)loading var=pollinterval value: 1
   0.000150     [D5] do_upsconf_args: confupsname=(null), var=maxretry, val=3
   0.000155     [D5] do_upsconf_args: call do_global_args()
   0.000160     [D3] do_global_args: var='maxretry' val='3'
   0.000174     [D5] do_upsconf_args: confupsname=apcupskelder, var=driver, val=usbhid-ups
   0.000179     [D5] do_upsconf_args: call main_arg()
   0.000184     [D3] main_arg: var='driver' val='usbhid-ups'
   0.000188     [D5] do_upsconf_args: not a main_arg()
   0.000191     [D5] do_upsconf_args: this is a 'driver' setting, may we proceed?
   0.000195     [D6] testval_reloadable: var=driver, oldval=usbhid-ups, newval=usbhid-ups, reloadable=0, reload_flag=0
   0.000199     [D6] testval_reloadable: verdict for (re)loading var=driver value: -1
   0.000203     [D5] do_upsconf_args: 'driver' setting already applied with this value
   0.000208     [D5] do_upsconf_args: confupsname=apcupskelder, var=port, val=auto
   0.000211     [D5] do_upsconf_args: call main_arg()
   0.000215     [D3] main_arg: var='port' val='auto'
   0.000219     [D6] testinfo_reloadable: var=port, infoname=driver.parameter.port, newval=auto, reloadable=0, reload_flag=0
   0.000223     [D6] testinfo_reloadable: verdict for (re)loading var=port value: 1
   0.000228     [D5] send_to_all: SETINFO driver.parameter.port "auto"
   0.000241     [D5] do_upsconf_args: confupsname=apcupskelder, var=desc, val=Back-UPS BX750MI  FW:295202G -302202G
   0.000246     [D5] do_upsconf_args: call main_arg()
   0.000252     [D3] main_arg: var='desc' val='Back-UPS BX750MI  FW:295202G -302202G'
   0.000260     [D5] do_upsconf_args: confupsname=apcupskelder, var=vendorid, val=051d
   0.000266     [D5] do_upsconf_args: call main_arg()
   0.000273     [D3] main_arg: var='vendorid' val='051d'
   0.000279     [D5] do_upsconf_args: not a main_arg()
   0.000285     [D5] do_upsconf_args: process as value
   0.000292     [D6] testvar_reloadable: searching for var=vendorid, vartype=2, reload_flag=0
   0.000301     [D6] testvar_reloadable: found var=vendorid, val='(null)' => '051d', vartype=2 => 2, found=0, reloadable=0, reload_flag=0
   0.000312     [D6] testvar_reloadable: verdict for (re)loading var=vendorid value: 1
   0.000325     [D5] send_to_all: SETINFO driver.parameter.vendorid "051d"
   0.000333     [D5] do_upsconf_args: confupsname=apcupskelder, var=productid, val=0002
   0.000339     [D5] do_upsconf_args: call main_arg()
   0.000345     [D3] main_arg: var='productid' val='0002'
   0.000351     [D5] do_upsconf_args: not a main_arg()
   0.000356     [D5] do_upsconf_args: process as value
   0.000362     [D6] testvar_reloadable: searching for var=productid, vartype=2, reload_flag=0
   0.000373     [D6] testvar_reloadable: found var=productid, val='(null)' => '0002', vartype=2 => 2, found=0, reloadable=0, reload_flag=0
   0.000383     [D6] testvar_reloadable: verdict for (re)loading var=productid value: 1
   0.000392     [D5] send_to_all: SETINFO driver.parameter.productid "0002"
   0.000401     [D5] do_upsconf_args: confupsname=apcupskelder, var=serial, val=9B2416A22014
   0.000407     [D5] do_upsconf_args: call main_arg()
   0.000413     [D3] main_arg: var='serial' val='9B2416A22014'
   0.000420     [D5] do_upsconf_args: not a main_arg()
   0.000428     [D5] do_upsconf_args: process as value
   0.000433     [D6] testvar_reloadable: searching for var=serial, vartype=2, reload_flag=0
   0.000440     [D6] testvar_reloadable: found var=serial, val='(null)' => '9B2416A22014', vartype=2 => 2, found=0, reloadable=0, reload_flag=0
   0.000451     [D6] testvar_reloadable: verdict for (re)loading var=serial value: 1
   0.000459     [D5] send_to_all: SETINFO driver.parameter.serial "9B2416A22014"
   0.000477     [D1] Network UPS Tools version 2.7.4.11052.56-11108-g788888094 (development iteration after 2.7.4) built with gcc (Ubuntu 13.3.0-6ubuntu2~24.04) 13.3.0 and configured with flags: --prefix=/usr --sbindir=/usr/sbin --sysconfdir=/etc/nut --with-group=nut --with-user=nut --with-libsystemd
   0.000495     [D1] debug level is '6'
   0.000503     [D5] send_to_all: SETINFO driver.debug "6"
   0.000511     [D5] send_to_all: SETFLAGS driver.debug RW NUMBER
   0.001356     [D1] Succeeded to become_user(nut): now UID=121 GID=130
   0.001391     [D5] upsdrvquery_write: write to driver socket: NOBROADCAST

   0.001401     [D5] upsdrvquery_write: write to driver socket: PING

   0.001409     [D5] upsdrvquery_prepare: waiting for a while to flush server messages
   0.001415     [D5] upsdrvquery_read_timeout: tv={sec=3, usec=000000}
   0.001474     [D5] upsdrvquery_read_timeout: received 5 bytes from driver socket: PONG

   0.001483     [D5] upsdrvquery_prepare: got expected PONG
   0.001489     [D5] upsdrvquery_prepare: ready for tracked commands
   0.001499     [D5] upsdrvquery_write: write to driver socket: SET driver.flag.allow_killpower 1 TRACKING 2DDC5036-F665-4D29-BE4C-0374D091D263

   0.001514     [D5] upsdrvquery_request: will wait up to 15.000000 sec for response to SET driver.flag.allow_killpower 1

   0.001526     [D5] upsdrvquery_read_timeout: tv={sec=15, usec=000000}
   0.001582     [D5] upsdrvquery_read_timeout: received 48 bytes from driver socket: TRACKING 2DDC5036-F665-4D29-BE4C-0374D091D263 0

   0.001604     [D5] upsdrvquery_request: parsed out command status: 0
   0.001609     [D5] upsdrvquery_close: closing driver socket, try to say goodbye
   0.001614     [D5] upsdrvquery_write: write to driver socket: LOGOUT

   0.001649     [D5] upsdrvquery_close: okay
   1.002153     [D5] upsdrvquery_write: write to driver socket: NOBROADCAST

   1.002217     [D5] upsdrvquery_write: write to driver socket: PING

   1.002256     [D5] upsdrvquery_prepare: waiting for a while to flush server messages
   1.002288     [D5] upsdrvquery_read_timeout: tv={sec=3, usec=000000}
   1.008158     [D5] upsdrvquery_read_timeout: received 5 bytes from driver socket: PONG

   1.008204     [D5] upsdrvquery_prepare: got expected PONG
   1.008222     [D5] upsdrvquery_prepare: ready for tracked commands
   1.008255     [D5] upsdrvquery_write: write to driver socket: INSTCMD driver.killpower TRACKING 98C489FD-821C-4132-9D93-4F6590B55E63

   1.008313     [D1] upsdrvquery_request: will wait indefinitely for response to INSTCMD driver.killpower

   1.008336     [D5] upsdrvquery_read_timeout: tv={sec=-1, usec=-00001} (unlimited timeout)
   1.009374     [D5] upsdrvquery_read_timeout: received 48 bytes from driver socket: TRACKING 98C489FD-821C-4132-9D93-4F6590B55E63 0

   1.009427     [D5] upsdrvquery_request: parsed out command status: 0
   1.009476     [D5] upsdrvquery_close: closing driver socket, try to say goodbye
   1.009491     [D5] upsdrvquery_write: write to driver socket: LOGOUT

   1.009523     [D5] upsdrvquery_close: okay
   2.009954     Request to killpower via running driver returned code 0
   2.010000     [D5] send_to_all: SETINFO driver.state "cleanup.exit"
   2.010015     upsnotify: notify about state NOTIFY_STATE_STOPPING with libsystemd: was requested, but not running as a service unit now, will not spam more about it
   2.010036     [D1] On systems without service units, consider `export NUT_QUIET_INIT_UPSNOTIFY=true`
   2.010055     upsnotify: failed to notify about state NOTIFY_STATE_STOPPING: no notification tech defined, will not spam more about it

However! When I plugged the UPS back in, it restarted! So the power race was avoided. Or was that the power race, I forgot the exact terminology.

[ErikDB87]

My Linux box did shut down seconds after unplugging the UPS, and I don't really understand why...

Some relevant file configs here

erik@MinipcLG2:/etc/nut$ sudo cat upssched.conf
CMDSCRIPT /etc/nut/upssched-cmd.sh
PIPEFN /etc/nut/upssched.pipe
LOCKFN /etc/nut/upssched.lock

# Starts a timer when the UPS switches to battery power
AT ONBATT * START-TIMER shutdown_timer 1200

# Cancels the shutdown timer when power is restored
AT ONLINE * CANCEL-TIMER shutdown_timer

# Executes immediate shutdown when battery is low
AT LOWBATT * EXECUTE immediate_shutdown

# Starts a timer on communication failure
AT COMMBAD * START-TIMER commbad_timer 1200

# Cancels the communication failure timer when communication is restored
AT COMMOK * CANCEL-TIMER commbad_timer

# Executes shutdown on persistent communication failure
AT NOCOMM * EXECUTE commbad_shutdown

# Executes powerdown on system shutdown
AT SHUTDOWN * EXECUTE powerdown

&

erik@MinipcLG2:/etc/nut$ sudo cat /etc/nut/upssched-cmd.sh
#!/bin/sh

case $1 in
    shutdown_timer)
        # Log the event and initiate a controlled shutdown
        logger -t upssched-cmd "UPS running on battery for too long, initiating shutdown"
        /usr/sbin/upsmon -c fsd
        ;;

    immediate_shutdown)
        # Log the critical battery status and initiate immediate shutdown
        logger -t upssched-cmd "UPS on battery critical, forced shutdown"
        /usr/sbin/upsmon -c fsd
        ;;

    commbad_timer)
        # Log persistent communication failures and initiate shutdown
        logger -t upssched-cmd "UPS communication failure persists, initiating shutdown"
        /usr/sbin/upsmon -c fsd
        ;;

    commbad_shutdown)
        # Log communication failure and initiate shutdown
        logger -t upssched-cmd "UPS communication failed, initiating shutdown"
        /usr/sbin/upsmon -c fsd
        ;;

    powerdown)
        # Log the execution of the shutdown
        logger -t upssched-cmd "Executing powerdown command"
        ;;

    *)
        # Log unknown commands
        logger -t upssched-cmd "Unrecognized command: $1"
        ;;
esac

I checked the logs, and I don't see any of these log entries...:

erik@MinipcLG2:/etc/nut$ sudo cat /var/log/syslog | grep upssched-cmd
2025-01-06T16:22:22.819313+01:00 MinipcLG2 nut-monitor[5011]: sh: 1: /etc/nut/upssched-cmd.sh: Permission denied
2025-01-06T16:22:22.819986+01:00 MinipcLG2 nut-monitor[5009]: exec_cmd(/etc/nut/upssched-cmd.sh powerdown) returned 126
2025-01-06T16:22:22.820228+01:00 MinipcLG2 upssched[5009]: exec_cmd(/etc/nut/upssched-cmd.sh powerdown) returned 126

Maybe this was a problem:

erik@MinipcLG2:/etc/nut$ ls -pal | grep upssched-cmd
-rwxr-xr--   1 root root  1120 nov  2 18:03 upssched-cmd.sh

So I did this:

erik@MinipcLG2:/etc/nut$ sudo chmod +x upssched-cmd.sh
erik@MinipcLG2:/etc/nut$ ls -pal | grep upssched-cmd
-rwxr-xr-x   1 root root  1120 nov  2 18:03 upssched-cmd.sh

[jimklimov]

So... quite a few things pop out, many about permissions: /etc/nut and files in it should generally be owned by root:nut, readable by both (and executable in case of scripts and dir), writeable by owner (root), inaccessible to others.

In the first test, as erik - that account did not have access, so program failed correctly.

In the latest (with upssched-cmd.sh not executable by nut user - who in case of root:root ownership was "other") you probably fixed the cause.

The quick shutdown remains questionable, maybe FSD conditions struck. On the upside, battery.charge.low=10 remained in place BTW.

Tests with sudo usbhid-ups had the access, and had a dialog with the other driver instance, confirming that one was running after all.

I wonder if due to the mix of packaging and manual installation, there was an older (packaged) driver program running as driver service, started before you make install the custom build. Did you stop services beforehand, as detailed in wiki?

[ErikDB87]

So... quite a few things pop out, many about permissions: /etc/nut and files in it should generally be owned by root:nut, readable by both (and executable in case of scripts and dir), writeable by owner (root), inaccessible to others.

Should I run chown -R root:nut /etc/nut?

The quick shutdown remains questionable, maybe FSD conditions struck. On the upside, battery.charge.low=10 remained in place BTW.

Is it possible to checks some logs to find out which FSD (which I assume stands for "forced shutdown"?) condition possibly struck?

Tests with sudo usbhid-ups had the access, and had a dialog with the other driver instance, confirming that one was running after all.

I wonder if due to the mix of packaging and manual installation, there was an older (packaged) driver program running as driver service, started before you make install the custom build. Did you stop services beforehand, as detailed in wiki?

My initial response was "no", since I only used the command you gave above. But I checked the wiki, and took a closer look at that command. So I now think I did indeed stop the services:

make -j 4 all && make -j 4 check && \
   { sudo systemctl stop nut-monitor nut-server || true ; } && \
   { sudo systemctl stop nut-driver.service || true ; } && \
   { sudo systemctl stop nut-driver.target || true ; } && \
   { sudo systemctl stop nut.target || true ; } && \
   sudo make install && \
   sudo systemctl daemon-reload && \
   sudo systemd-tmpfiles --create && \
   sudo systemctl disable nut.target nut-driver.target nut-monitor nut-server nut-driver-enumerator.path nut-driver-enumerator.service && \
   sudo systemctl enable  nut.target nut-driver.target nut-monitor nut-server nut-driver-enumerator.path nut-driver-enumerator.service && \
   { sudo systemctl restart udev || true ; } && \
   sudo ./scripts/upsdrvsvcctl/nut-driver-enumerator.sh --reconfigure && \
   sudo systemctl restart nut-driver-enumerator.service nut-monitor nut-server

[jimklimov]

That chown should help about programs' access to their configs, yes.

I'm getting a bit lost about which driver programs you do actually have running or not when testing the new build for its shutdown ability. Can you please review the basics like ps -ef | grep -E 'nut|ups' (may catch a few bogies like cups, never mind those)?

[ErikDB87]

erik@MinipcLG2:~$ sudo chown -R root:nut /etc/nut
erik@MinipcLG2:~$ ls -pal /etc/nut
totaal 192
drwxr-xr-x   2 root nut   4096 jan  7 09:08 ./
drwxr-xr-x 191 root root 12288 jan  7 03:30 ../
-rw-r--r--   1 root nut     48 nov  2 18:01 hosts.conf
-rw-r-----   1 root nut     15 nov  2 16:42 nut.conf
-rw-r--r--   1 root nut   8596 jan  6 15:52 nut.conf.sample
-rw-r-----   1 root nut   4156 nov  2 16:41 nut.example.conf
-rw-r-----   1 root nut    385 jan  3 15:07 ups.conf
-rw-r--r--   1 root nut  11847 jan  6 15:52 ups.conf.sample
-rw-r-----   1 root nut     20 nov  2 18:02 upsd.conf
-rw-r--r--   1 root nut   9566 jan  6 15:52 upsd.conf.sample
-rw-r-----   1 root nut   8247 nov  2 16:41 upsd.example.conf
-rw-r-----   1 root nut    132 jan  5 13:48 upsd.users
-rw-r--r--   1 root nut   2476 jan  6 15:52 upsd.users.sample
-rw-r-----   1 root nut   9845 nov  2 16:41 ups.example.conf
-rw-r-----   1 root nut   1257 jan  3 14:11 upsmon.conf
-rw-r--r--   1 root nut  28994 jan  6 15:52 upsmon.conf.sample
-rw-r-----   1 root nut  24344 nov  2 16:41 upsmon.example.conf
-rwxr-xr-x   1 root nut   1120 nov  2 18:03 upssched-cmd.sh
-rw-r-----   1 root nut    747 jan  3 16:14 upssched.conf
-rw-r--r--   1 root nut   4344 jan  6 15:52 upssched.conf.sample
-rw-r-----   1 root nut   4201 nov  2 16:41 upssched.example.conf
erik@MinipcLG2:~$ ps -ef | grep -E 'nut|ups'
nut          937       1  0 jan06 ?        00:01:07 /usr/bin/usbhid-ups -FF -a apcupskelder
nut         1364       1  0 jan06 ?        00:00:20 /usr/sbin/upsd -FF
root        1418       1  0 jan06 ?        00:00:00 /usr/sbin/upsmon -F
nut         1428    1418  0 jan06 ?        00:00:34 /usr/sbin/upsmon -F
root        4967       1  0 jan06 ?        00:00:00 sshd: /usr/sbin/sshd -D [listener] 0 of 10-100 startups
root       27930       1  0 00:00 ?        00:00:00 /usr/sbin/cupsd -l
cups-br+   27940       1  0 00:00 ?        00:00:00 /usr/sbin/cups-browsed
erik       73725   73116  0 13:56 pts/0    00:00:00 grep --color=auto -E nut|ups

[jimklimov]

Thanks, so at the moment at least /usr/bin/usbhid-ups -FF -a apcupskelder is running. At least, this is not a path typical for Debian packaging (they have lib/nut/drivername for some reason), so probably your custom build.

By -FF I presume it is under systemd (with NDE-made wrapping unit), likely [email protected]. If that was also running while you tested the direct driver-requested shutdown, this is who the driver talked to in recent experiments and maybe conflicted with earlier (about exclusive access to USB port).

With -FF it should have left a PID file though, so a manually started driver would be able to kill it, as they always did (or tried to) earlier, before the driver-to-driver dialogues were made. Maybe earlier packaged versions of NUT only used -F (or even -D) to stay "foregrounded inside the service unit" and did not leave a PID file (so the new driver instance could not kill it off and just was conflicted).

[jimklimov]

With this driver running under systemd, we do not see in console log of the drivername -k execution whether/how it actually tried to talk the UPS into shutting down, since the other copy of the program attempts that in practice.

However, especially if the log verbosity is high enough (e.g. temporary debug_min = 6 in ups.conf) such messages can be seen in journalctl -lu [email protected] as it catches the output of the driver program wrapped as a unit.

[ErikDB87]

However, especially if the log verbosity is high enough (e.g. temporary debug_min = 6 in ups.conf) such messages can be seen in journalctl -lu [email protected] as it catches the output of the driver program wrapped as a unit.

I'm afraid you lost me on most of what you said, but I added the debug part:

erik@MinipcLG2:~$ sudo cat /etc/nut/ups.conf
pollinterval = 1
maxretry = 3
debug_min = 6

[apcupskelder]
        driver = usbhid-ups
        port = auto
        desc = "Back-UPS BX750MI  FW:295202G -302202G"
        vendorid = 051d
        productid = 0002
        serial = 9B2416A22014
#        vendor = "American Power Conversion"
#        bus = 001
#        device = 005
#        busport = 003
        ###NOTMATCHED-YET###bcdDevice = "0106"

[ErikDB87]

Maybe earlier packaged versions of NUT only used -F (or even -D) to stay "foregrounded inside the service unit" and did not leave a PID file (so the new driver instance could not kill it off and just was conflicted).

But I just reinstalled the packaged NUT, no? Or was/is there maybe still some packaged version lingering on my system?

[jimklimov]

Well, that's what I suspected (and IIRC it was the case when this discussion started - you had a NUT v2.8.1 package)...

[ErikDB87]

Well, that's what I suspected (and IIRC it was the case when this discussion started - you had a NUT v2.8.1 package)...

I'm afraid I lost track myself... Should I try to uninstall everything? If so, could you recommend the exact commands? That way we avoid the risk of me doing it halfheartedly.

[ErikDB87]

Hi Jim,

I understand you want to close this issue, but could you help me with this last step of uninstalling every and all package NUT installs? :)

[jimklimov]

Oh, the close was automatic due to PR merge, sorry about that. I'll try to take a look at the questions tomorrow, dayjob work load is coming back after team's vacations...

[ErikDB87]

Oh, the close was automatic due to PR merge, sorry about that. I'll try to take a look at the questions tomorrow, dayjob work load is coming back after team's vacations...

Aha, I already found it an unexpected turn of events 😅

There's no rush, of course!

[jimklimov]

So, I guess a prudent way forward to ensure there's only one NUT to consider in the system and there are no conflicts would be to back up /etc/nut configurations just in case, and write down the user/group IDs of the nut account (probably created by packaging, and might get removed with it), and remove the packages.

Verify whether the nut user/group still exist with the same IDs as before, or re-create them (see groupadd/useradd).

In the build workspace you had, also sudo make uninstall to remove whatever it delivered.

With no installation to inherit "in-place" settings from, you may have to pass them explicitly when rebuilding NUT.
Your "screenshots" above have recorded the settings for in-place build:

:; ./autogen.sh && \
   ./configure --prefix=/usr --sbindir=/usr/sbin --sysconfdir=/etc/nut --with-group=nut --with-user=nut --with-libsystemd

NOTE: The sbindir seems superfluous above, would default to same. You might want --with-drvpath=/lib/nut to match more closely what the package delivered; otherwise the drivers are installed into /usr/bin, with the benefit of being in default PATH.

NOTE: If you want to fully match what the packaging delivers, check the huge list of options at https://github.com/networkupstools/nut/wiki/Building-NUT-on-Debian,-Raspbian-and-Ubuntu or the current definition at https://salsa.debian.org/debian/nut/-/blob/debian/debian/rules

Picking up the installation and service activation from Wiki:

:; make -j 4 all && make -j 4 check && \
   { sudo systemctl stop nut-monitor nut-server || true ; } && \
   { sudo systemctl stop nut-driver.service || true ; } && \
   { sudo systemctl stop nut-driver.target || true ; } && \
   { sudo systemctl stop nut.target || true ; } && \
   sudo make install && \
   sudo systemctl daemon-reload && \
   sudo systemd-tmpfiles --create && \
   sudo systemctl disable nut.target nut-driver.target nut-monitor nut-server nut-driver-enumerator.path nut-driver-enumerator.service && \
   sudo systemctl enable  nut.target nut-driver.target nut-monitor nut-server nut-driver-enumerator.path nut-driver-enumerator.service && \
   { sudo systemctl restart udev || true ; } && \
   sudo ./scripts/upsdrvsvcctl/nut-driver-enumerator.sh --reconfigure && \
   sudo systemctl restart nut-driver-enumerator.service nut-monitor nut-server

Note that the sudo systemd-tmpfiles --create part should ensure that locations nut user needs to read/write would exist and be accessible to it.

With current NUT master code base, you can also sudo systemctl preset-all for the services, but beware -- this instills an opinionated selection of enabled and disabled units, so can override whatever you have customized locally (if anything).

[ErikDB87]

Thanks Jim!

I checked for the details of user ´nut´:

erik@MinipcLG2:~/nut-issue-2666$ cat /etc/passwd | grep nut
nut:x:121:130::/var/lib/nut:/usr/sbin/nologin

I uninstalled the packages. The user and group nut were still in the system:

erik@MinipcLG2:~/nut-issue-2666$ cat /etc/passwd | grep nut
nut:x:121:130::/var/lib/nut:/usr/sbin/nologin

I then ran sudo make uninstall and git clean -fffdddxxx.

I thought to go for the full monty, so I then ran the following command:

./autogen.sh && \
./configure --prefix=/usr \
--sbindir=/usr/sbin \
--with-libsystemd \
--includedir=/usr/include --mandir=/usr/share/man \
--infodir=/usr/share/info --sysconfdir=/etc/nut --localstatedir=/var \
--libexecdir=/usr/lib/nut --srcdir=. --enable-maintainer-mode \
--disable-silent-rules --libdir=/usr/lib/`gcc -print-multiarch` \
--with-ssl --with-nss --with-cgi --with-dev --enable-static \
--with-statepath=/var/run/nut --with-altpidpath=/var/run/nut \
--with-drvpath=/lib/nut --with-cgipath=/usr/lib/cgi-bin/nut \
--with-htmlpath=/usr/share/nut/www --with-pidpath=/var/run/nut \
--datadir=/usr/share/nut --with-pkgconfig-dir=/usr/lib/`gcc -print-multiarch`/pkgconfig \
--with-user=nut --with-group=nut --with-udev-dir=/lib/udev \
--with-systemdsystemunitdir=/lib/systemd/system

I then ran your suggested installation command:

:; make -j 4 all && make -j 4 check && \
   { sudo systemctl stop nut-monitor nut-server || true ; } && \
   { sudo systemctl stop nut-driver.service || true ; } && \
   { sudo systemctl stop nut-driver.target || true ; } && \
   { sudo systemctl stop nut.target || true ; } && \
   sudo make install && \
   sudo systemctl daemon-reload && \
   sudo systemd-tmpfiles --create && \
   sudo systemctl disable nut.target nut-driver.target nut-monitor nut-server nut-driver-enumerator.path nut-driver-enumerator.service && \
   sudo systemctl enable  nut.target nut-driver.target nut-monitor nut-server nut-driver-enumerator.path nut-driver-enumerator.service && \
   { sudo systemctl restart udev || true ; } && \
   sudo ./scripts/upsdrvsvcctl/nut-driver-enumerator.sh --reconfigure && \
   sudo systemctl restart nut-driver-enumerator.service nut-monitor nut-server

I'll try to test how this works asap.

(The output was too big, it's in this .txt file: nut-installation-output.txt.)