Disconnection Issue with tripplite_usb

[Jsalas424]

Disconnection Issue with tripplite_usb

[Jsalas424]

Resolved with upgrade to 2.8.0.

There are still occasional disconnects but it's able to come back online now unlike in v2.7.4.

Nov 01 16:33:02 Server upsd[1092085]: Data for UPS [TrippLiteUPS] is stale - check driver
Nov 01 16:33:03 Server nut-monitor[1092077]: Poll UPS [TrippLiteUPS@localhost] failed - Data stale
Nov 01 16:33:03 Server kernel: usb 3-6: new low-speed USB device number 70 using xhci_hcd
Nov 01 16:33:03 Server kernel: usb 3-6: New USB device found, idVendor=09ae, idProduct=0001, bcdDevice= 0.0a
Nov 01 16:33:03 Server kernel: usb 3-6: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Nov 01 16:33:03 Server kernel: usb 3-6: Product: TRIPP LITE SMART500RT1U 
Nov 01 16:33:03 Server kernel: usb 3-6: Manufacturer: Tripp Lite 
Nov 01 16:33:03 Server kernel: hid-generic 0003:09AE:0001.0140: hiddev0,hidraw0: USB HID v1.10 Device [Tripp Lite  TRIPP LITE SMART500RT1U ] on usb-0000:00:14.0-6/input0
Nov 01 16:33:06 Server tripplite_usb[1921583]: libusb_set_report() returned 0 instead of 8
Nov 01 16:33:06 Server tripplite_usb[1921583]: Error reading S value: Device detached? (error 0: Success)
Nov 01 16:33:06 Server tripplite_usb[1921583]: Reconnect attempt #4
Nov 01 16:33:06 Server tripplite_usb[1921583]: Successfully reconnected
Nov 01 16:33:07 Server tripplite_usb[1921583]: Using binary SMART protocol (3005)
Nov 01 16:33:07 Server tripplite_usb[1921583]: Unit ID: 65535
Nov 01 16:33:08 Server nut-monitor[1092077]: Poll UPS [TrippLiteUPS@localhost] failed - Data stale
Nov 01 16:33:12 Server nut-server[1092085]: UPS [TrippLiteUPS] data is no longer stale
Nov 01 16:33:12 Server upsd[1092085]: UPS [TrippLiteUPS] data is no longer stale
Nov 01 16:33:13 Server nut-monitor[1092077]: Communications with UPS TrippLiteUPS@localhost established
Nov 01 16:33:13 Server nut-monitor[1921710]: Network UPS Tools upsmon 2.8.0

The only other interesting point is that I'm getting the following error:
libusb1: Could not open any HID devices: insufficient permissions on everything

But that's a fight for another day.

[jimklimov]

Hello, is this some problem that started recently?

How long do you have/monitor this device?

Were there any other recent hardware changes (can we implicate e.g. USB cabling and/or noise on it - you do mention a new cable) or software ones (something else trying to kidnap the libusb device)?

Are you sure one instance of the driver is running; in case of restart - that the older instance did die (and no service/script/crontab resurrects it in a separate process tree from e.g. systemd unit lifecycle)?

CC: @dzomaya @aquette

[Jsalas424]

I have only recently started monitoring this tripplite device, I had some issues in the past getting it setup with NUT at all.

I will certainly look into all these factors in the near future, in the meantime I'm dropping off some new interesting logs:

Jul 30 20:36:48 Server tripplite_usb[2778403]: Successfully reconnected
Jul 30 20:36:48 Server tripplite_usb[2778403]: Using binary SMART protocol (3005)
Jul 30 20:36:48 Server tripplite_usb[2778403]: libusb_set_report() returned 0 instead of 8
Jul 30 20:36:48 Server tripplite_usb[2778403]: Could not reset watchdog. Please send model information to nut-upsdev mailing list
Jul 30 20:36:49 Server tripplite_usb[2778403]: libusb_get_interrupt() returned 0 instead of 8 while sending 3a 53 ac 0d 00 00 00 00 '.S......'
Jul 30 20:36:50 Server tripplite_usb[2778403]: libusb_get_interrupt() returned 0 instead of 8 while sending 3a 53 ac 0d 00 00 00 00 '.S......'
Jul 30 20:36:51 Server tripplite_usb[2778403]: libusb_get_interrupt() returned 0 instead of 8 while sending 3a 53 ac 0d 00 00 00 00 '.S......'

Data has been flowing okay for the past couple of hours until ~10min ago when it suddenly stopped altogether and now all I'm getting is Jul 30 20:49:11 Server upsmon[2778364]: Poll UPS [TrippLiteUPS@localhost] failed - Driver not connected

[Jsalas424]

Were there any other recent hardware changes (can we implicate e.g. USB cabling and/or noise on it - you do mention a new cable) or software ones (something else trying to kidnap the libusb device)?

No other hardware changes. This is running directly on my proxmox hypervisor, this is one of the only software's installed on top of the base OS. I checked every VM to make sure I wasn't inadvertently passing through any USB ports, but I don't pass through anything at all.

I only have 1 USB plugged in to this computer:

root@TracheNodeB:~# lsusb
Bus 004 Device 002: ID 8087:8000 Intel Corp. Integrated Rate Matching Hub
Bus 004 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 002 Device 002: ID 8087:8008 Intel Corp. Integrated Rate Matching Hub
Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 003 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 003: ID 09ae:0001 Tripp Lite TRIPP LITE SMART500RT1U 
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

Here's the verbose output for that port:

Bus 001 Device 003: ID 09ae:0001 Tripp Lite TRIPP LITE SMART500RT1U 
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               1.10
  bDeviceClass            0 
  bDeviceSubClass         0 
  bDeviceProtocol         0 
  bMaxPacketSize0         8
  idVendor           0x09ae Tripp Lite
  idProduct          0x0001 
  bcdDevice            0.0a
  iManufacturer           1 Tripp Lite 
  iProduct                2 TRIPP LITE SMART500RT1U 
  iSerial                 0 
  bNumConfigurations      1
  Configuration Descriptor:
    bLength                 9
    bDescriptorType         2
    wTotalLength       0x0022
    bNumInterfaces          1
    bConfigurationValue     1
    iConfiguration          0 
    bmAttributes         0xc0
      Self Powered
    MaxPower                0mA
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        0
      bAlternateSetting       0
      bNumEndpoints           1
      bInterfaceClass         3 Human Interface Device
      bInterfaceSubClass      0 
      bInterfaceProtocol      0 
      iInterface              0 
        HID Device Descriptor:
          bLength                 9
          bDescriptorType        33
          bcdHID               1.10
          bCountryCode            0 Not supported
          bNumDescriptors         1
          bDescriptorType        34 Report
          wDescriptorLength      52
         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     0x0008  1x 8 bytes
        bInterval              10
can't get debug descriptor: Resource temporarily unavailable
Device Status:     0x0001
  Self Powered

Are you sure one instance of the driver is running; in case of restart - that the older instance did die (and no service/script/crontab resurrects it in a separate process tree from e.g. systemd unit lifecycle)?

There are no cron jobs for the user

root@Server:~# crontab -l
no crontab for root

The systemwide cron jobs don't mention anything NUT related:

root@Server:~# cat /etc/crontab /etc/cron.d/*
# /etc/crontab: system-wide crontab
# Unlike any other crontab you don't have to run the `crontab'
# command to install the new version when you edit this file
# and files in /etc/cron.d. These files also have username fields,
# that none of the other crontabs do.

SHELL=/bin/sh
PATH=/usr/local/sbin:/usr/local/bin:/sbin:/bin:/usr/sbin:/usr/bin

# Example of job definition:
# .---------------- minute (0 - 59)
# |  .------------- hour (0 - 23)
# |  |  .---------- day of month (1 - 31)
# |  |  |  .------- month (1 - 12) OR jan,feb,mar,apr ...
# |  |  |  |  .---- day of week (0 - 6) (Sunday=0 or 7) OR sun,mon,tue,wed,thu,fri,sat
# |  |  |  |  |
# *  *  *  *  * user-name command to be executed
17 *    * * *   root    cd / && run-parts --report /etc/cron.hourly
25 6    * * *   root    test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily )
47 6    * * 7   root    test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.weekly )
52 6    1 * *   root    test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.monthly )
#
30 3 * * 0 root test -e /run/systemd/system || SERVICE_MODE=1 /usr/lib/x86_64-linux-gnu/e2fsprogs/e2scrub_all_cron
10 3 * * * root test -e /run/systemd/system || SERVICE_MODE=1 /sbin/e2scrub_all -A -r
# cluster wide vzdump cron schedule
# Automatically generated file - do not edit

PATH="/usr/sbin:/usr/bin:/sbin:/bin"

PATH=/usr/local/sbin:/usr/local/bin:/sbin:/bin:/usr/sbin:/usr/bin

# TRIM the first Sunday of every month.
24 0 1-7 * * root if [ $(date +\%w) -eq 0 ] && [ -x /usr/lib/zfs-linux/trim ]; then /usr/lib/zfs-linux/trim; fi

# Scrub the second Sunday of every month.
24 0 8-14 * * root if [ $(date +\%w) -eq 0 ] && [ -x /usr/lib/zfs-linux/scrub ]; then /usr/lib/zfs-linux/scrub; fi

It's not the systemd timers:

root@Server:~# systemctl list-timers
NEXT                        LEFT          LAST                        PASSED       UNIT                         ACTIVATES
Wed 2023-08-02 18:54:50 EDT 3min 29s left Wed 2023-08-02 18:49:50 EDT 1min 30s ago smart_exporter.timer         smart_exporter.service
Wed 2023-08-02 22:32:57 EDT 3h 41min left Tue 2023-08-01 22:32:57 EDT 20h ago      systemd-tmpfiles-clean.timer systemd-tmpfiles-clean.service
Thu 2023-08-03 00:00:00 EDT 5h 8min left  Wed 2023-08-02 00:00:57 EDT 18h ago      logrotate.timer              logrotate.service
Thu 2023-08-03 00:00:00 EDT 5h 8min left  Wed 2023-08-02 00:00:57 EDT 18h ago      man-db.timer                 man-db.service
Thu 2023-08-03 00:25:39 EDT 5h 34min left Wed 2023-08-02 11:27:46 EDT 7h ago       apt-daily.timer              apt-daily.service
Thu 2023-08-03 05:54:00 EDT 11h left      Wed 2023-08-02 05:38:46 EDT 13h ago      pve-daily-update.timer       pve-dai>
Thu 2023-08-03 06:27:43 EDT 11h left      Wed 2023-08-02 06:45:46 EDT 12h ago      apt-daily-upgrade.timer      apt-dai>
Sun 2023-08-06 03:10:21 EDT 3 days left   Sun 2023-07-30 03:11:09 EDT 3 days ago   e2scrub_all.timer            e2scrub>
Mon 2023-08-07 01:26:07 EDT 4 days left   Mon 2023-07-31 00:33:57 EDT 2 days ago   fstrim.timer                 fstrim.>

9 timers listed.
Pass --all to see loaded but inactive timers, too.

The nut-client config:

root@Server:~# systemctl status nut-client
● nut-monitor.service - Network UPS Tools - power device monitor and shutdown controller
     Loaded: loaded (/lib/systemd/system/nut-monitor.service; enabled; vendor preset: enabled)
     Active: active (running) since Wed 2023-08-02 18:56:42 EDT; 4s ago
    Process: 3142243 ExecStart=/sbin/upsmon (code=exited, status=0/SUCCESS)
   Main PID: 3142245 (upsmon)
      Tasks: 3 (limit: 38361)
     Memory: 924.0K
        CPU: 6ms
     CGroup: /system.slice/nut-monitor.service
             ├─3142244 /lib/nut/upsmon
             └─3142245 /lib/nut/upsmon

Aug 02 18:56:42 TracheNodeB upsmon[3142243]: fopen /run/nut/upsmon.pid: No such file or directory
Aug 02 18:56:42 TracheNodeB upsmon[3142243]: Using power down flag file /etc/killpower
Aug 02 18:56:42 TracheNodeB upsmon[3142243]: UPS: TrippLiteUPS@localhost (master) (power value 1)
Aug 02 18:56:42 TracheNodeB upsmon[3142244]: Startup successful
Aug 02 18:56:42 TracheNodeB systemd[1]: nut-monitor.service: Can't open PID file /run/nut/upsmon.pid (yet?) after start>
Aug 02 18:56:42 TracheNodeB systemd[1]: nut-monitor.service: Supervising process 3142245 which is not our child. We'll >
Aug 02 18:56:42 TracheNodeB systemd[1]: Started Network UPS Tools - power device monitor and shutdown controller.

root@Server:~# cat /lib/systemd/system/nut-monitor.service
[Unit]
Description=Network UPS Tools - power device monitor and shutdown controller
After=local-fs.target network.target nut-server.service

[Service]
ExecStart=/sbin/upsmon
PIDFile=/run/nut/upsmon.pid
Type=forking

[Install]
WantedBy=multi-user.target

Nut-server:

● nut-server.service - Network UPS Tools - power devices information server
     Loaded: loaded (/lib/systemd/system/nut-server.service; enabled; vendor preset: enabled)
     Active: active (running) since Sun 2023-07-30 22:16:22 EDT; 2 days ago
    Process: 2385 ExecStart=/sbin/upsd (code=exited, status=0/SUCCESS)
   Main PID: 2386 (upsd)
      Tasks: 1 (limit: 38361)
     Memory: 1.2M
        CPU: 12.515s
     CGroup: /system.slice/nut-server.service
             └─2386 /lib/nut/upsd

root@Server:~# cat /lib/systemd/system/nut-server.service
[Unit]
Description=Network UPS Tools - power devices information server
After=local-fs.target network.target nut-driver.service
# We don't Require drivers to be successfully started! This would be
# a change of behavior compared to init SysV, and could prevent from
# accessing successfully started, at least to audit a system.
Wants=nut-driver.service
Before=nut-monitor.service

[Service]
ExecStart=/sbin/upsd 
Type=forking

[Install]
WantedBy=multi-user.target