Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
ErikDB87 opened this issue Oct 30, 2024 · 96 comments
Labels
APC DDL impacts-release-2.8.1 Issues reported against NUT release 2.8.1 (maybe vanilla or with minor packaging tweaks) USB

Comments

@ErikDB87
Copy link

ErikDB87 commented Oct 30, 2024

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 ErikDB87 changed the title NUT 2.8.1-3 " Can't claim USB device [051d:0002]@0/0: Entity not found" using usbhid-ups NUT 2.8.1-3 "Can't claim USB device [051d:0002]@0/0: Entity not found" using usbhid-ups Nov 1, 2024
@ErikDB87
Copy link
Author

ErikDB87 commented Nov 2, 2024

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
Copy link
Member

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
Copy link
Author

ErikDB87 commented Nov 2, 2024

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
Copy link
Member

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
Copy link
Author

ErikDB87 commented Nov 2, 2024

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
Copy link
Member

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
Copy link
Author

ErikDB87 commented Nov 6, 2024

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 jimklimov added DDL APC USB impacts-release-2.8.1 Issues reported against NUT release 2.8.1 (maybe vanilla or with minor packaging tweaks) labels Nov 6, 2024
@jimklimov
Copy link
Member

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
Copy link
Member

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

@ErikDB87
Copy link
Author

ErikDB87 commented Nov 6, 2024

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
Copy link
Member

jimklimov commented Nov 6, 2024

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
Copy link
Author

ErikDB87 commented Nov 6, 2024

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
Copy link
Member

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
Copy link
Author

ErikDB87 commented Nov 6, 2024

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
Copy link
Member

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
Copy link
Member

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
Copy link
Member

jimklimov commented Nov 6, 2024

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

@ErikDB87
Copy link
Author

ErikDB87 commented Nov 6, 2024

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
Copy link
Member

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
Copy link
Author

ErikDB87 commented Nov 6, 2024

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
Copy link
Member

"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
Copy link
Member

And that's plain old C code ;)

@ErikDB87
Copy link
Author

ErikDB87 commented Nov 6, 2024

"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? :)

jimklimov added a commit to jimklimov/nut that referenced this issue Nov 12, 2024
…usb adding its CFLAGS and LIBS into the loop [networkupstools#2666]

Signed-off-by: Jim Klimov <[email protected]>
jimklimov added a commit to jimklimov/nut that referenced this issue Nov 12, 2024
jimklimov added a commit to jimklimov/nut that referenced this issue Nov 12, 2024
jimklimov added a commit to jimklimov/nut that referenced this issue Nov 12, 2024
…bmodbus was used to build this driver [networkupstools#2666]

Signed-off-by: Jim Klimov <[email protected]>
jimklimov added a commit to jimklimov/nut that referenced this issue Nov 12, 2024
jimklimov added a commit to jimklimov/nut that referenced this issue Nov 12, 2024
…th-modbus+usb=yes and fix a typo checking --with-drivers there [networkupstools#2666]

Signed-off-by: Jim Klimov <[email protected]>
jimklimov added a commit to jimklimov/nut that referenced this issue Nov 12, 2024
@jimklimov
Copy link
Member

So, the prospective fix was published as a PR #2677.

You can try building that branch of NUT which is a source of the PR, with a separate checkout location, e.g.:

:; git clone https://github.com/jimklimov -b issue-2666 nut-issue-2666
:; cd nut-issue-2666
:; ./autogen.sh
:; ./configure --with-drivers=apc_modbus --with-modbus+usb --with-modbus-includes=-I/usr/local/include/modbus --with-modbus-libs="-L/usr/local/lib -lmodbus" --without-docs --enable-inplace-runtime

...assuming the static build of libmodbus is still under /usr/local.

Now it should more actively reject build combinations where we implicitly seem to want, or explicitly request, the use of usb-capable libmodbus (for apc_modbus driver building). The built driver should also expose its capability more visibly. More details in that PR's description.

@ErikDB87
Copy link
Author

You can try building that branch of NUT which is a source of the PR

Am I doing something wrong?

erik@MinipcLG2:~$ git clone https://github.com/jimklimov -b issue-2666 nut-issue-2666
Cloning into 'nut-issue-2666'...
remote: Not Found
fatal: repository 'https://github.com/jimklimov/' not found
erik@MinipcLG2:~$ sudo git clone https://github.com/jimklimov -b issue-2666 nut-issue-2666
Cloning into 'nut-issue-2666'...
remote: Not Found
fatal: repository 'https://github.com/jimklimov/' not found

@ErikDB87
Copy link
Author

Aha, I figured it out: /nut is missing from that URL. I'll try it all ASAP!

@ErikDB87
Copy link
Author

ErikDB87 commented Nov 12, 2024

Initially: Hooray!

erik@MinipcLG2:~/nut-issue-2666$ cat include/config.h | grep NUT_MODBUS_HAS_USB
#define NUT_MODBUS_HAS_USB 1

But the actual driver part still isn't successful... I tried without and later with -u root:

erik@MinipcLG2:~/nut-issue-2666$ cat include/config.h | grep NUT_MODBUS_HAS_USB
#define NUT_MODBUS_HAS_USB 1
erik@MinipcLG2:~/nut-issue-2666$ sudo systemctl stop nut-driver@apcupskelder
erik@MinipcLG2:~/nut-issue-2666$ sudo ./drivers/apc_modbus -s tempups  -d1 -DDDDDD -x port=auto
   0.000000     [D5] send_to_all: SETINFO driver.state "init.starting"
Network UPS Tools 2.7.4.10428.38-10466-geb99e125f (development iteration after 2.7.4) - NUT APC Modbus driver with USB support 0.10
   0.000192     [D5] send_to_all: SETINFO driver.version.usb "libusb-1.0.27 (API: 0x100010a)"
   0.000217     [D1] Using USB implementation: libusb-1.0.27 (API: 0x100010a)
   0.000241     [D1] This build of the driver is USB-capable; also Serial and TCP Modbus RTU are supported
   0.000290     [D3] main_arg: var='port' val='auto'
   0.000318     [D6] testinfo_reloadable: var=port, infoname=driver.parameter.port, newval=auto, reloadable=0, reload_flag=0
   0.000338     [D6] testinfo_reloadable: verdict for (re)loading var=port value: 1
   0.000376     [D5] send_to_all: SETINFO driver.parameter.port "auto"
   0.000395     [D1] Network UPS Tools version 2.7.4.10428.38-10466-geb99e125f (development iteration after 2.7.4) built with gcc (Ubuntu 13.2.0-23ubuntu4) 13.2.0 and configured with flags: --prefix=/usr --sbindir=/usr/sbin --bindir=/usr/bin --sysconfdir=/etc/nut --with-group=nut --with-user=nut --with-drivers=apc_modbus --with-modbus+usb --with-modbus-includes=-I/usr/local/include/modbus --with-modbus-libs='-L/usr/local/lib -lmodbus' --without-docs
   0.000532     [D1] debug level is '6'
   0.000558     [D5] send_to_all: SETINFO driver.debug "6"
   0.000598     [D5] send_to_all: SETFLAGS driver.debug RW NUMBER
   0.003329     [D1] Succeeded to become_user(nut): now UID=121 GID=130
   0.003349     [D1] Signalling UPS [tempups]: driver.exit (quietly, no fuss if no driver is running or responding)
   0.003388     Can't open /var/state/ups/apc_modbus-tempups: No such file or directory
   0.003401     [D1] Request for other driver to exit returned code -1
   0.003414     [D1] Socket dialog with the other driver instance (may be absent) failed: No such file or directory
   0.003428     [D5] send_to_all: SETINFO device.type "ups"
   0.003441     [D5] send_to_all: SETINFO driver.state "init.device"
Number of USB devices: 4
Considering device #1 (0403:6001)
libusb_open for device #1 failed: Access denied (insufficient permissions)
Considering device #2 (051d:0002)
   0.015059     [D1] _apc_modbus_usb_callback: Failed to match!: Resource temporarily unavailable
No matching device found
   0.015226     modbus_connect: unable to connect: No such device
   0.015249     [D5] send_to_all: SETINFO driver.state "cleanup.exit"
erik@MinipcLG2:~/nut-issue-2666$ sudo ./drivers/apc_modbus -u root -s tempups  -d1 -DDDDDD -x port=auto
   0.000000     [D5] send_to_all: SETINFO driver.state "init.starting"
Network UPS Tools 2.7.4.10428.38-10466-geb99e125f (development iteration after 2.7.4) - NUT APC Modbus driver with USB support 0.10
   0.000060     [D5] send_to_all: SETINFO driver.version.usb "libusb-1.0.27 (API: 0x100010a)"
   0.000067     [D1] Using USB implementation: libusb-1.0.27 (API: 0x100010a)
   0.000072     [D1] This build of the driver is USB-capable; also Serial and TCP Modbus RTU are supported
   0.000084     [D1] Built-in default or configured user for drivers 'nut' was ignored due to 'root' specified on command line
   0.000092     [D3] main_arg: var='port' val='auto'
   0.000098     [D6] testinfo_reloadable: var=port, infoname=driver.parameter.port, newval=auto, reloadable=0, reload_flag=0
   0.000105     [D6] testinfo_reloadable: verdict for (re)loading var=port value: 1
   0.000112     [D5] send_to_all: SETINFO driver.parameter.port "auto"
   0.000117     [D1] Network UPS Tools version 2.7.4.10428.38-10466-geb99e125f (development iteration after 2.7.4) built with gcc (Ubuntu 13.2.0-23ubuntu4) 13.2.0 and configured with flags: --prefix=/usr --sbindir=/usr/sbin --bindir=/usr/bin --sysconfdir=/etc/nut --with-group=nut --with-user=nut --with-drivers=apc_modbus --with-modbus+usb --with-modbus-includes=-I/usr/local/include/modbus --with-modbus-libs='-L/usr/local/lib -lmodbus' --without-docs
   0.000140     [D1] debug level is '6'
   0.000148     [D5] send_to_all: SETINFO driver.debug "6"
   0.000155     [D5] send_to_all: SETFLAGS driver.debug RW NUMBER
   0.000656     [D1] Succeeded to become_user(root): now UID=0 GID=0
   0.000668     [D1] Signalling UPS [tempups]: driver.exit (quietly, no fuss if no driver is running or responding)
   0.000680     Can't open /var/state/ups/apc_modbus-tempups: No such file or directory
   0.000685     [D1] Request for other driver to exit returned code -1
   0.000692     [D1] Socket dialog with the other driver instance (may be absent) failed: No such file or directory
   0.000699     [D5] send_to_all: SETINFO device.type "ups"
   0.000710     [D5] send_to_all: SETINFO driver.state "init.device"
Number of USB devices: 4
Considering device #1 (0403:6001)
_modbus_rtu_usb_connect: failed to get HID descriptor: Input/Output Error
   0.009247     [D1] _apc_modbus_usb_callback: Failed to match!: Success
Considering device #2 (051d:0002)
   0.014713     [D1] _apc_modbus_usb_callback: Failed to match!: Resource temporarily unavailable
No matching device found
   0.014914     modbus_connect: unable to connect: No such device
   0.014933     [D5] send_to_all: SETINFO driver.state "cleanup.exit"
erik@MinipcLG2:~/nut-issue-2666$

Two lines look suspect, I would think...
"0.000680 Can't open /var/state/ups/apc_modbus-tempups: No such file or directory"?
"0.014713 [D1] _apc_modbus_usb_callback: Failed to match!: Resource temporarily unavailable"?

Awaiting further orders. ;) (If there's any log document that might be useful, I'll gladly provide it.)

Or does this mean the modbus driver also doesn't work on my UPS? I forgot this avenue was only a possible solution...

@jimklimov
Copy link
Member

Aha, I figured it out: /nut is missing from that URL. I'll try it all ASAP!

Argh, my bad, deleted too much cruft from the copied URL. Glad you found your way around this bit , and sorry again :D

@jimklimov
Copy link
Member

So, finally, these lines confirm the correct code got built:

Network UPS Tools 2.7.4.10428.38-10466-geb99e125f (development iteration after 2.7.4) -
   NUT APC Modbus driver with USB support 0.10
...
   0.000241     [D1] This build of the driver is USB-capable; also Serial and TCP Modbus RTU are supported

(ignore the "2.7.4" as baseline + 10K commits afterwards: it is based on git tags you workspace has downloaded or not).

As for "Resource temporarily unavailable" - are you sure your driver dried earlier is stopped (likely wrapped as a nut-driver@apcupskelder systemd service unit), so it is not that program holding the device?

@ErikDB87
Copy link
Author

As for "Resource temporarily unavailable" - are you sure your driver dried earlier is stopped (likely wrapped as a nut-driver@apcupskelder systemd service unit), so it is not that program holding the device?

I ran sudo systemctl stop nut-driver@apcupskelder ... Shouldn't that stop the driver? Is there anything else that I should've stopped?

@jimklimov
Copy link
Member

Should have... maybe there is one running from upsdrvctl experiments?
Can you check with ps -ef | grep usbhid-ups if anything is running? If yes, the second column of output is the PID of that process which you can kill...

@ErikDB87
Copy link
Author

Should have... maybe there is one running from upsdrvctl experiments? Can you check with ps -ef | grep usbhid-ups if anything is running? If yes, the second column of output is the PID of that process which you can kill...

It took me a while to figure this output out: I couldn't kill the processes, and the PID kept changing... But I realized it was referencing the search command itself. So there was no other process with upsdrvctl in it.

I played around with it a bit, and maybe this is something?

erik@MinipcLG2:~/nut-issue-2666$ ps -ef | grep ups
nut         1334       1  0 nov11 ?        00:00:32 /lib/nut/upsd -F
root        1349       1  0 nov11 ?        00:00:00 /lib/nut/upsmon -F
nut         1357    1349  0 nov11 ?        00:00:22 /lib/nut/upsmon -F
root        6848       1  0 nov11 ?        00:00:00 sshd: /usr/sbin/sshd -D [listener] 0 of 10-100 startups
root      205252       1  0 00:00 ?        00:00:00 /usr/sbin/cupsd -l
cups-br+  205263       1  0 00:00 ?        00:00:00 /usr/sbin/cups-browsed
erik      275141  274152  0 14:56 pts/0    00:00:00 grep --color=auto ups
And for the sake of completeness...
erik@MinipcLG2:~/nut-issue-2666$ ps -ef
UID          PID    PPID  C STIME TTY          TIME CMD
root           1       0  0 nov11 ?        00:00:07 /sbin/init splash
root           2       0  0 nov11 ?        00:00:00 [kthreadd]
root           3       2  0 nov11 ?        00:00:00 [pool_workqueue_release]
root           4       2  0 nov11 ?        00:00:00 [kworker/R-rcu_g]
root           5       2  0 nov11 ?        00:00:00 [kworker/R-rcu_p]
root           6       2  0 nov11 ?        00:00:00 [kworker/R-slub_]
root           7       2  0 nov11 ?        00:00:00 [kworker/R-netns]
root           9       2  0 nov11 ?        00:00:00 [kworker/0:0H-events_highpri]
root          12       2  0 nov11 ?        00:00:00 [kworker/R-mm_pe]
root          13       2  0 nov11 ?        00:00:00 [rcu_tasks_kthread]
root          14       2  0 nov11 ?        00:00:00 [rcu_tasks_rude_kthread]
root          15       2  0 nov11 ?        00:00:00 [rcu_tasks_trace_kthread]
root          16       2  0 nov11 ?        00:00:01 [ksoftirqd/0]
root          17       2  0 nov11 ?        00:01:05 [rcu_preempt]
root          18       2  0 nov11 ?        00:00:00 [migration/0]
root          19       2  0 nov11 ?        00:00:00 [idle_inject/0]
root          20       2  0 nov11 ?        00:00:00 [cpuhp/0]
root          21       2  0 nov11 ?        00:00:00 [cpuhp/1]
root          22       2  0 nov11 ?        00:00:00 [idle_inject/1]
root          23       2  0 nov11 ?        00:00:00 [migration/1]
root          24       2  0 nov11 ?        00:00:02 [ksoftirqd/1]
root          26       2  0 nov11 ?        00:00:00 [kworker/1:0H-events_highpri]
root          27       2  0 nov11 ?        00:00:00 [cpuhp/2]
root          28       2  0 nov11 ?        00:00:00 [idle_inject/2]
root          29       2  0 nov11 ?        00:00:00 [migration/2]
root          30       2  0 nov11 ?        00:00:03 [ksoftirqd/2]
root          32       2  0 nov11 ?        00:00:00 [kworker/2:0H-events_highpri]
root          33       2  0 nov11 ?        00:00:00 [cpuhp/3]
root          34       2  0 nov11 ?        00:00:00 [idle_inject/3]
root          35       2  0 nov11 ?        00:00:01 [migration/3]
root          36       2  0 nov11 ?        00:00:03 [ksoftirqd/3]
root          38       2  0 nov11 ?        00:00:00 [kworker/3:0H-events_highpri]
root          39       2  0 nov11 ?        00:00:00 [kdevtmpfs]
root          40       2  0 nov11 ?        00:00:00 [kworker/R-inet_]
root          42       2  0 nov11 ?        00:00:00 [kauditd]
root          43       2  0 nov11 ?        00:00:00 [khungtaskd]
root          44       2  0 nov11 ?        00:00:00 [oom_reaper]
root          46       2  0 nov11 ?        00:00:00 [kworker/R-write]
root          47       2  0 nov11 ?        00:00:21 [kcompactd0]
root          48       2  0 nov11 ?        00:00:00 [ksmd]
root          49       2  0 nov11 ?        00:00:00 [khugepaged]
root          50       2  0 nov11 ?        00:00:00 [kworker/R-kinte]
root          51       2  0 nov11 ?        00:00:00 [kworker/R-kbloc]
root          52       2  0 nov11 ?        00:00:00 [kworker/R-blkcg]
root          53       2  0 nov11 ?        00:00:00 [irq/9-acpi]
root          56       2  0 nov11 ?        00:00:00 [kworker/R-tpm_d]
root          57       2  0 nov11 ?        00:00:00 [kworker/R-ata_s]
root          58       2  0 nov11 ?        00:00:00 [kworker/R-md]
root          59       2  0 nov11 ?        00:00:00 [kworker/R-md_bi]
root          60       2  0 nov11 ?        00:00:00 [kworker/R-edac-]
root          61       2  0 nov11 ?        00:00:00 [kworker/R-devfr]
root          62       2  0 nov11 ?        00:00:00 [watchdogd]
root          63       2  0 nov11 ?        00:00:03 [kworker/0:1H-kblockd]
root          64       2  0 nov11 ?        00:00:16 [kswapd0]
root          65       2  0 nov11 ?        00:00:00 [ecryptfs-kthread]
root          66       2  0 nov11 ?        00:00:00 [kworker/R-kthro]
root          68       2  0 nov11 ?        00:00:00 [kworker/R-acpi_]
root          69       2  0 nov11 ?        00:00:01 [hwrng]
root          70       2  0 nov11 ?        00:00:00 [kworker/R-mld]
root          71       2  0 nov11 ?        00:00:03 [kworker/2:1H-kblockd]
root          72       2  0 nov11 ?        00:00:00 [kworker/R-ipv6_]
root          79       2  0 nov11 ?        00:00:00 [kworker/R-kstrp]
root          81       2  0 nov11 ?        00:00:00 [kworker/u9:0]
root          86       2  0 nov11 ?        00:00:00 [kworker/R-crypt]
root          96       2  0 nov11 ?        00:00:00 [kworker/R-charg]
root         124       2  0 nov11 ?        00:00:04 [kworker/3:1H-kblockd]
root         151       2  0 nov11 ?        00:00:04 [kworker/1:1H-kblockd]
root         164       2  0 nov11 ?        00:00:00 [scsi_eh_0]
root         165       2  0 nov11 ?        00:00:00 [kworker/R-scsi_]
root         166       2  0 nov11 ?        00:00:00 [scsi_eh_1]
root         167       2  0 nov11 ?        00:00:00 [kworker/R-scsi_]
root         168       2  0 nov11 ?        00:00:00 [scsi_eh_2]
root         169       2  0 nov11 ?        00:00:00 [kworker/R-scsi_]
root         170       2  0 nov11 ?        00:00:00 [scsi_eh_3]
root         171       2  0 nov11 ?        00:00:00 [kworker/R-scsi_]
root         172       2  0 nov11 ?        00:00:00 [scsi_eh_4]
root         173       2  0 nov11 ?        00:00:00 [kworker/R-scsi_]
root         239       2  0 nov11 ?        00:00:13 [jbd2/sda2-8]
root         240       2  0 nov11 ?        00:00:00 [kworker/R-ext4-]
root         302       1  0 nov11 ?        00:00:47 /usr/lib/systemd/systemd-journald
root         364       1  0 nov11 ?        00:00:00 /usr/lib/systemd/systemd-udevd
root         367       2  0 nov11 ?        00:00:00 [psimon]
root         445       2  0 nov11 ?        00:00:00 [irq/123-mei_me]
root         505       2  0 nov11 ?        00:00:00 [kworker/R-ttm]
root         517       2  0 nov11 ?        00:00:00 [card1-crtc0]
root         518       2  0 nov11 ?        00:00:00 [card1-crtc1]
root         519       2  0 nov11 ?        00:00:00 [card1-crtc2]
root         558       2  0 nov11 ?        00:00:00 [spl_system_task]
root         559       2  0 nov11 ?        00:00:00 [spl_delay_taskq]
root         560       2  0 nov11 ?        00:00:00 [spl_dynamic_tas]
root         561       2  0 nov11 ?        00:00:00 [spl_kmem_cache]
root         562       2  0 nov11 ?        00:00:00 [zvol]
root         563       2  0 nov11 ?        00:00:00 [arc_prune]
root         564       2  0 nov11 ?        00:00:04 [arc_evict]
root         565       2  0 nov11 ?        00:00:04 [arc_reap]
root         566       2  0 nov11 ?        00:00:00 [dbu_evict]
root         567       2  0 nov11 ?        00:00:04 [dbuf_evict]
root         568       2  0 nov11 ?        00:00:00 [z_vdev_file]
root         569       2  0 nov11 ?        00:00:04 [l2arc_feed]
_rpc         685       1  0 nov11 ?        00:00:00 /sbin/rpcbind -f -w
systemd+     687       1  0 nov11 ?        00:00:02 /usr/lib/systemd/systemd-resolved
systemd+     692       1  0 nov11 ?        00:00:01 /usr/lib/systemd/systemd-timesyncd
root         749       2  0 nov11 ?        00:00:00 [kworker/R-rpcio]
root         751       2  0 nov11 ?        00:00:00 [kworker/R-xprti]
root         833       1  0 nov11 ?        00:00:06 /usr/libexec/accounts-daemon
avahi        835       1  0 nov11 ?        00:01:29 avahi-daemon: running [MinipcLG2.local]
root         837       1  0 nov11 ?        00:00:00 /usr/sbin/cron -f -P
message+     838       1  0 nov11 ?        00:00:04 @dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation --syslog-only
root         843       1  0 nov11 ?        00:00:15 /usr/sbin/irqbalance
root         851       1  0 nov11 ?        00:00:00 /usr/bin/python3 /usr/bin/networkd-dispatcher --run-startup-triggers
polkitd      858       1  0 nov11 ?        00:00:01 /usr/lib/polkit-1/polkitd --no-debug
root         867       1  0 nov11 ?        00:00:10 /usr/lib/snapd/snapd
root         868       1  0 nov11 ?        00:00:00 /usr/libexec/switcheroo-control
root         875       1  0 nov11 ?        00:00:00 /usr/lib/systemd/systemd-logind
systemd+     876       1  0 nov11 ?        00:00:00 /usr/lib/systemd/systemd-networkd
root         881       1  0 nov11 ?        00:00:17 /usr/sbin/thermald --systemd --dbus-enable --adaptive
root         886       1  0 nov11 ?        00:00:20 /usr/libexec/udisks2/udisksd
root         889       1  0 nov11 ?        00:00:00 zed -F
root         929       1  0 nov11 ?        00:00:18 /usr/sbin/NetworkManager --no-daemon
avahi        930     835  0 nov11 ?        00:00:00 avahi-daemon: chroot helper
root         934       1  0 nov11 ?        00:00:00 /usr/sbin/wpa_supplicant -u -s -O DIR=/run/wpa_supplicant GROUP=netdev
root        1094       2  0 nov11 ?        00:00:00 [kworker/R-cfg80]
syslog      1116       1  0 nov11 ?        00:00:04 /usr/sbin/rsyslogd -n -iNONE
root        1184       1  0 nov11 ?        00:00:00 /usr/sbin/ModemManager
root        1318       2  0 nov11 ?        00:00:00 [psimon]
root        1330       1  0 nov11 ?        00:00:00 /usr/bin/python3 /usr/share/unattended-upgrades/unattended-upgrade-shutdown --wait-for-signal
root        1332       1  0 nov11 ?        00:00:00 /usr/bin/vncserver-x11-serviced -fg
nut         1334       1  0 nov11 ?        00:00:32 /lib/nut/upsd -F
root        1341    1332  0 nov11 ?        00:00:20 /usr/bin/vncserver-x11-core -service
root        1349       1  0 nov11 ?        00:00:00 /lib/nut/upsmon -F
root        1351       1  0 nov11 ?        00:00:00 /usr/sbin/lightdm
nut         1357    1349  0 nov11 ?        00:00:22 /lib/nut/upsmon -F
mosquit+    1358       1  0 nov11 ?        00:01:39 /usr/sbin/mosquitto -c /etc/mosquitto/mosquitto.conf
colord      1360       1  0 nov11 ?        00:00:00 /usr/libexec/colord
unbound     1365       1  0 nov11 ?        00:00:41 /usr/sbin/unbound -d -p
root        1375    1351  0 nov11 tty7     00:05:41 /usr/lib/xorg/Xorg -core :0 -seat seat0 -auth /var/run/lightdm/root/:0 -nolisten tcp vt7 -novtswitch
root        1381       1  0 nov11 tty1     00:00:00 /sbin/agetty -o -p -- \u --noclear - linux
root        1391    1341  0 nov11 ?        00:00:00 /usr/bin/vncagent service 0
root        1420    1351  0 nov11 ?        00:00:00 lightdm --session-child 17 20
lightdm     1426       1  0 nov11 ?        00:00:00 /usr/lib/systemd/systemd --user
lightdm     1427    1426  0 nov11 ?        00:00:00 (sd-pam)
lightdm     1439    1426  0 nov11 ?        00:00:00 /usr/bin/pipewire
lightdm     1440    1426  0 nov11 ?        00:00:00 /usr/bin/pipewire -c filter-chain.conf
lightdm     1441    1426  0 nov11 ?        00:00:00 /usr/bin/wireplumber
lightdm     1442    1426  0 nov11 ?        00:00:00 /usr/bin/pipewire-pulse
lightdm     1444    1426  0 nov11 ?        00:00:00 /usr/bin/gnome-keyring-daemon --foreground --components=pkcs11,secrets --control-directory=/run/user/113
lightdm     1447    1426  0 nov11 ?        00:00:00 /usr/bin/dbus-daemon --session --address=systemd: --nofork --nopidfile --systemd-activation --syslog-onl
rtkit       1455       1  0 nov11 ?        00:00:02 /usr/libexec/rtkit-daemon
lightdm     1460    1420  0 nov11 ?        00:00:00 /bin/sh /usr/lib/lightdm/lightdm-greeter-session /usr/sbin/slick-greeter
lightdm     1461    1460  0 nov11 ?        00:05:36 /usr/sbin/slick-greeter
lightdm     1479    1426  0 nov11 ?        00:00:00 /usr/libexec/dconf-service
lightdm     1497    1426  0 nov11 ?        00:00:00 /usr/libexec/at-spi-bus-launcher
lightdm     1504    1497  0 nov11 ?        00:00:00 /usr/bin/dbus-daemon --config-file=/usr/share/defaults/at-spi2/accessibility.conf --nofork --print-addre
lightdm     1505    1426  0 nov11 ?        00:00:00 /usr/libexec/gvfsd
lightdm     1511    1426  0 nov11 ?        00:00:00 /usr/libexec/gvfsd-fuse /run/user/113/gvfs -f
root        1524       1  0 nov11 ?        00:00:01 /usr/libexec/upowerd
root        1535    1351  0 nov11 ?        00:00:00 lightdm --session-child 13 20
lightdm     1537    1426  0 nov11 ?        00:00:00 /usr/libexec/at-spi2-registryd --use-gnome-session
openhab     1685       1 13 nov11 ?        05:56:09 /usr/bin/java -XX:-UsePerfData -Dopenhab.home=/usr/share/openhab -Dopenhab.conf=/etc/openhab -Dopenhab.r
pihole      1728       1  0 nov11 ?        00:04:24 /usr/bin/pihole-FTL -f
root        1741       2  0 nov11 ?        00:00:00 [kworker/R-nfsio]
kernoops    1761       1  0 nov11 ?        00:00:12 /usr/sbin/kerneloops --test
kernoops    1773       1  0 nov11 ?        00:00:12 /usr/sbin/kerneloops
root        1804       1  0 nov11 ?        00:00:28 /usr/sbin/nmbd --foreground --no-process-group
root        1892    1804  0 nov11 ?        00:00:00 /usr/sbin/nmbd --foreground --no-process-group
root        1905       1  0 nov11 ?        00:00:00 /usr/sbin/smbd --foreground --no-process-group
root        1907       2  0 nov11 ?        00:00:00 [NFSv4 callback]
root        1941    1905  0 nov11 ?        00:04:02 smbd: notifyd .
root        1947    1905  0 nov11 ?        00:00:00 smbd: cleanupd
root        2340       1  0 nov11 ?        00:00:01 /usr/lib/postfix/sbin/master -w
postfix     2342    2340  0 nov11 ?        00:00:00 qmgr -l -t unix -u
root        6848       1  0 nov11 ?        00:00:00 sshd: /usr/sbin/sshd -D [listener] 0 of 10-100 startups
root        7331       2  0 nov11 ?        00:00:00 [kworker/R-tls-s]
root        8874       1  0 nov11 ?        00:00:11 /usr/sbin/apache2 -k start
root        8978       1  0 nov11 ?        00:00:11 /usr/libexec/fwupd/fwupd
postfix    86824    2340  0 nov12 ?        00:00:00 tlsmgr -l -t unix -u -c
root      147942       2  0 nov12 ?        00:00:09 [kworker/1:1-events]
root      205252       1  0 00:00 ?        00:00:00 /usr/sbin/cupsd -l
www-data  205255    8874  0 00:00 ?        00:00:00 /usr/sbin/apache2 -k start
www-data  205257    8874  0 00:00 ?        00:00:01 /usr/sbin/apache2 -k start
www-data  205258    8874  0 00:00 ?        00:00:01 /usr/sbin/apache2 -k start
www-data  205259    8874  0 00:00 ?        00:00:01 /usr/sbin/apache2 -k start
www-data  205260    8874  0 00:00 ?        00:00:01 /usr/sbin/apache2 -k start
www-data  205261    8874  0 00:00 ?        00:00:01 /usr/sbin/apache2 -k start
cups-br+  205263       1  0 00:00 ?        00:00:00 /usr/sbin/cups-browsed
www-data  205281    8874  0 00:00 ?        00:00:01 /usr/sbin/apache2 -k start
root      249019       2  0 09:09 ?        00:00:05 [kworker/2:1-events_freezable]
root      249107       2  0 09:09 ?        00:00:02 [kworker/0:1-events]
root      249113       2  0 09:09 ?        00:00:01 [kworker/3:3-events]
root      267775       2  0 13:25 ?        00:00:02 [kworker/u8:4-rpciod]
root      269234       2  0 13:43 ?        00:00:00 [kworker/2:2-cgroup_destroy]
root      270828       2  0 14:06 ?        00:00:00 [kworker/0:2]
postfix   271420    2340  0 14:13 ?        00:00:00 pickup -l -t unix -u -c
root      272186       2  0 14:25 ?        00:00:01 [kworker/u8:0-flush-8:0]
root      272777       2  0 14:33 ?        00:00:00 [kworker/1:2]
root      272980       2  0 14:36 ?        00:00:00 [kworker/u8:2-events_unbound]
root      273225       2  0 14:39 ?        00:00:00 [kworker/3:1-events]
root      273770    1905  0 14:47 ?        00:00:00 smbd: client [192.168.1.50]
root      273876    6848  0 14:48 ?        00:00:00 sshd: erik [priv]
erik      274003       1  0 14:48 ?        00:00:00 /usr/lib/systemd/systemd --user
erik      274006  274003  0 14:48 ?        00:00:00 (sd-pam)
erik      274045  274003  0 14:48 ?        00:00:00 /usr/bin/pipewire
erik      274052  274003  0 14:48 ?        00:00:00 /usr/bin/pipewire -c filter-chain.conf
erik      274055  274003  0 14:48 ?        00:00:00 /usr/bin/wireplumber
erik      274058  274003  0 14:48 ?        00:00:00 /usr/bin/pipewire-pulse
erik      274070  274003  0 14:48 ?        00:00:00 /usr/bin/dbus-daemon --session --address=systemd: --nofork --nopidfile --systemd-activation --syslog-onl
erik      274141  273876  0 14:48 ?        00:00:00 sshd: erik@pts/0
erik      274152  274141  0 14:48 pts/0    00:00:00 -bash
root      275065       2  0 14:55 ?        00:00:00 [kworker/u8:1-flush-8:0]
erik      275378  274152  0 14:59 pts/0    00:00:00 ps -ef

@jimklimov
Copy link
Member

Just in case, CCing @EchterAgo - maybe there are some ideas about "_apc_modbus_usb_callback: Failed to match!: Resource temporarily unavailable"?

But in short, probably the device does not support the protocol, until proven otherwise...

@ErikDB87
Copy link
Author

ErikDB87 commented Nov 13, 2024

To a large extent, by increasing driver verbosity and/or using an -x explore subdriver option, so usbhid-ups program dumps all "USB HID reports" it sees, interspersed with how it understood (some of) them.

Could this be a way to find out the command? Or would that also not work, because we can't seem to be able to 'reach' the USB port?

In any case, the Windows PowerChute or what was its name did shut down the UPS, so there must be a command somewhere...

I assume it's impossible to 'open up' that Windows program and take a look inside? :)

@jimklimov
Copy link
Member

At least worth a try. I am not sure exploring finds supported commands, or only data reports. @aquette might know more on this, if online...

As for vendor programs, there's always good old sniffing (e.g. with Wireshark equivalent for USB) to check the protocol, but my knowledge is vague on how that is generally done or the next steps how to investigate those dumps and make code. I am sure there are blogs or mailing list entries on that, maybe even docs in NUT sources...

@ErikDB87
Copy link
Author

I am sure there are blogs or mailing list entries on that, maybe even docs in NUT sources...

Is there an effective way to search these mailing list entries? Opening every month's list is not that. :p

As for vendor programs, there's always good old sniffing (e.g. with Wireshark equivalent for USB) to check the protocol

I assume the raw data it generates will be too raw for my understanding, but I'll give this a go!

@ErikDB87
Copy link
Author

ErikDB87 commented Nov 14, 2024

Thanks to this guide (https://www.youtube.com/watch?v=0MC-D_oNzbk) I was able to generate two logs. The scenario was both initially the same: I unplugged the UPS from the electricity grid, and the PowerChute Serial Shutdown software started closing down my (Windows) laptop. Then I tried two scenarios:

  • 2024-11-14-APC-BX750MI-1.pcap: I let everything run its course, and the UPS shut down, a little over a minute after my laptop had shut down completely (so maybe two minutes after initiating the process, as referenced on that forum I linked somewhere above?). I then plugged the UPS back in, and it restarted (of course).
  • 2024-11-14-APC-BX750MI-2.pcap: As soon as Windows notified me of the shutdown that was going to occur, I plugged the UPS back in. I was pleasantly surprised that the same process as in scenario 1 happened, and the UPS power cycled.

The only caveat is of course that I don't know whether the PowerChute Serial Shutdown software shut down USBPcap prior to giving its final command - the holy grail - to the UPS... I don't think this is the case: I saw 2024-11-14-APC-BX750MI-2.pcap "growing" even after I plugged the UPS back in.

(I can't upload the log files, because they're not an allowed file type, so here's a link to a directory on my Google Drive, where they can be found: https://drive.google.com/drive/folders/12xLZH4YWJGXEjNETs2YBJix4boIUVDAE?usp=sharing.)

Maybe I should open a new issue and/or start a new mail chain, focused on retrieving the command from these data? That probably reaches more people, who have categorized the current issue as not for them?

@ErikDB87
Copy link
Author

"0.000680 Can't open /var/state/ups/apc_modbus-tempups: No such file or directory"?

What about this, by the way?

@jimklimov
Copy link
Member

New mail thread

Makes sense :)

Can't open /var/state/ups/apc_modbus-tempups: No such file or directory

That's a path to Unix local socket filem by which driver talks to upsd, and since 2.8.1 or so two copies of the driver (running and newly launched) can talk to each other e.g. to reload or exit older copy and start a new (older alternative to send OS signals is not as flexible/scalable).

The message means no older socket was found - since no older driver was running (earlier attempt could not connect to device and exited).

@aquette
Copy link
Member

aquette commented Nov 17, 2024

Read that in 30 seconds so...
Explore vs rw should show settings and commands (both being just settable Usages...), hard to auto distinguish, but I once thought about some ML using the friendly names on snmp-ups (and mibs lookup) to try to guess... That was a possible next step to my gen-subdriver work...
Cheers there

@ErikDB87
Copy link
Author

Read that in 30 seconds so...
Explore vs rw should show settings and commands (both being just settable Usages...), hard to auto distinguish, but I once thought about some ML using the friendly names on snmp-ups (and mibs lookup) to try to guess... That was a possible next step to my gen-subdriver work...
Cheers there

I'm afraid my knowledge of NUT (of Linux for that matter) is fairly limited... I don't really understand what you mean. Jim mentioned something about explore as well earlier, but I don't see what the full command would be...?

@ErikDB87
Copy link
Author

@jimklimov, @aquette, I tried to do some digging in the elaborate docs, and based on this, this and this info, I tried the following:

erik@MinipcLG2:~$ cd ~/nut-issue-2666
erik@MinipcLG2:~/nut-issue-2666$ git clean -fffdddxxx
erik@MinipcLG2:~/nut-issue-2666$ ./autogen.sh
erik@MinipcLG2:~/nut-issue-2666$ ./configure --with-drivers=apc_modbus --with-drivers=usbhid-ups --with-usb=yes --with-modbus+usb --with-modbus-includes=-I/usr/local/include/modbus --with-modbus-libs="-L/usr/local/lib -lmodbus" --without-docs --enable-inplace-runtime
erik@MinipcLG2:~/nut-issue-2666$ make

But alas, no success:

erik@MinipcLG2:~/nut-issue-2666$ sudo systemctl stop nut-driver@apcupskelder
erik@MinipcLG2:~/nut-issue-2666$ sudo ./drivers/usbhid-ups -DDDDDD -u root -x explore -x vendorid="051D" -x port=auto -s ups
   0.000007     [D5] send_to_all: SETINFO driver.state "init.starting"
Network UPS Tools 2.7.4.10428.38-10466-geb99e125f (development iteration after 2.7.4) - Generic HID driver 0.57
USB communication driver (libusb 1.0) 0.49
   0.000112     [D1] upsdrv_makevartable...
   0.000178     [D5] send_to_all: SETINFO driver.version.usb "libusb-1.0.27 (API: 0x100010a)"
   0.000194     [D1] Using USB implementation: libusb-1.0.27 (API: 0x100010a)
   0.000216     [D1] Built-in default or configured user for drivers 'nut' was ignored due to 'root' specified on command line
   0.000225     [D3] main_arg: var='explore' val='<null>'
   0.000243     [D5] send_to_all: SETINFO driver.flag.explore "enabled"
   0.000256     [D3] main_arg: var='vendorid' val='051D'
   0.000283     [D5] send_to_all: SETINFO driver.parameter.vendorid "051D"
   0.000295     [D3] main_arg: var='port' val='auto'
   0.000305     [D6] testinfo_reloadable: var=port, infoname=driver.parameter.port, newval=auto, reloadable=0, reload_flag=0
   0.000319     [D6] testinfo_reloadable: verdict for (re)loading var=port value: 1
   0.000335     [D5] send_to_all: SETINFO driver.parameter.port "auto"
   0.000346     [D1] Network UPS Tools version 2.7.4.10428.38-10466-geb99e125f (development iteration after 2.7.4) built with gcc (Ubuntu 13.2.0-23ubuntu4) 13.2.0 and configured with flags: --prefix=/usr --sbindir=/usr/sbin --bindir=/usr/bin --sysconfdir=/etc/nut --with-group=nut --with-user=nut --with-drivers=apc_modbus --with-drivers=usbhid-ups --with-usb=yes --with-modbus+usb --with-modbus-includes=-I/usr/local/include/modbus --with-modbus-libs='-L/usr/local/lib -lmodbus' --without-docs
   0.000385     [D1] debug level is '6'
   0.000400     [D5] send_to_all: SETINFO driver.debug "6"
   0.000414     [D5] send_to_all: SETFLAGS driver.debug RW NUMBER
   0.001294     [D1] Succeeded to become_user(root): now UID=0 GID=0
   0.001320     Can't chdir to /var/state/ups: No such file or directory
   0.001339     [D5] send_to_all: SETINFO driver.state "cleanup.exit"
   0.001352     upsnotify: failed to notify about state 4: no notification tech defined, will not spam more about it

I wasn't able to figure out what "explore vs rw" exactly means... Or "ML"...?

All help is appreciated! :)

@aquette
Copy link
Member

aquette commented Nov 19, 2024

Hi @ErikDB87

I'm unsure if your device is USB hid compliant. An lsusb -v as root may help
Or simply rey apx_modbus. Here Jim can drive you...

My ML (machine learning) vs explore (usbhid-ups flag) relates to the explore output of this driver, and snmp-ups somehow. I made some automations to extract data for these, to create new drivers. And I had some follow-up work to ease more, using a sort of ML... For @jimklimov

@ErikDB87
Copy link
Author

Hi, @aquette

erik@MinipcLG2:~$ sudo lsusb -v
(...)
Bus 001 Device 002: ID 051d:0002 American Power Conversion Uninterruptible Power Supply
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               2.00
  bDeviceClass            0 [unknown]
  bDeviceSubClass         0 [unknown]
  bDeviceProtocol         0
  bMaxPacketSize0        64
  idVendor           0x051d American Power Conversion
  idProduct          0x0002 Uninterruptible Power Supply
  bcdDevice            1.06
  iManufacturer           1 American Power Conversion
  iProduct                2 Back-UPS BX750MI  FW:295202G -302202G
  iSerial                 3 9B2416A22014
  bNumConfigurations      1
  Configuration Descriptor:
    bLength                 9
    bDescriptorType         2
    wTotalLength       0x0022
    bNumInterfaces          1
    bConfigurationValue     1
    iConfiguration          0
    bmAttributes         0xa0
      (Bus Powered)
      Remote Wakeup
    MaxPower              100mA
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        0
      bAlternateSetting       0
      bNumEndpoints           1
      bInterfaceClass         3 Human Interface Device
      bInterfaceSubClass      0 [unknown]
      bInterfaceProtocol      0
      iInterface              0
        HID Device Descriptor:
          bLength                 9
          bDescriptorType        33
          bcdHID               1.10
          bCountryCode           33 US
          bNumDescriptors         1
          bDescriptorType        34 Report
          wDescriptorLength     745
          Report Descriptors:
            ** UNAVAILABLE **
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x81  EP 1 IN
        bmAttributes            3
          Transfer Type            Interrupt
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0006  1x 6 bytes
        bInterval              10
Device Status:     0x0002
  (Bus Powered)
  Remote Wakeup Enabled

I see something about HID? But I can't make anything out of it, of course... I'm not sure what you mean with "rey apx_modbus"...?

The machine learning part sounds interesting. :) But I gather you haven't worked with these .pcap outputs then?

(By the way, I made another "sniff" log (2024-11-19-APC-BX750MI.pcap, via above mentioned link), this time with the setting that my Windows system would be shut down after 1 second of battery usage, and I unplugged the USB cable as soon as Windows notified me of the shutdown. That way I hoped to keep the log file shorter, and the shutdown command as close to the end of it as possible. The output was still 712 entries long, though...)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
APC DDL impacts-release-2.8.1 Issues reported against NUT release 2.8.1 (maybe vanilla or with minor packaging tweaks) USB
Projects
Status: Todo
Development

No branches or pull requests

4 participants