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

Poll UPS failed - Data stale #1022

Open
HyP3r- opened this issue Apr 21, 2021 · 6 comments
Open

Poll UPS failed - Data stale #1022

HyP3r- opened this issue Apr 21, 2021 · 6 comments
Labels
Connection stability issues Issues about driver<->device and/or networked connections (upsd<->upsmon...) going AWOL over time impacts-release-2.7.4 Issues reported against NUT release 2.7.4 (maybe vanilla or with minor packaging tweaks) Phoenixtec (USB 0x06DA/0xFFFF) This USB chip VID/PID is used in many devices, some with different protocols - detection may be hard PowerWalker PowerWalker and BlueWalker branded devices USB

Comments

@HyP3r-
Copy link

HyP3r- commented Apr 21, 2021

Hello I have a Bluewalker UPS Powerwalker VI 2200 LCD UPS. Unfortunately, always after some time comes the following error messages:

usbhid-ups[2387]: libusb_get_interrupt: could not claim interface 0: Device or resource busy
usbhid-ups[2387]: libusb_get_report: error sending control message: No such device
usbhid-ups[2387]: libusb_get_interrupt: could not claim interface 0: Device or resource busy
usbhid-ups[2387]: libusb_get_report: error sending control message: No such device
usbhid-ups[2387]: libusb_get_interrupt: error submitting URB: No such device
usbhid-ups[2387]: libusb_get_interrupt: could not claim interface 0: Device or resource busy
usbhid-ups[2387]: libusb_get_interrupt: error submitting URB: No such device
usbhid-ups[2387]: libusb_get_interrupt: could not claim interface 0: Device or resource busy
usbhid-ups[2387]: libusb_get_report: error sending control message: No such device
usbhid-ups[2387]: libusb_get_interrupt: error submitting URB: No such device
systemd[1]: /lib/systemd/system/nut-monitor.service:6: PIDFile= references path below legacy directory /var/run/, updating /var/run/nut/upsmon.pid → /run/nut/upsmon.pid; pleas
systemd[1]: nut-monitor.service: Supervising process 2399 which is not our child. We'll most likely not notice when it exits.
systemd[1]: /lib/systemd/system/nut-monitor.service:6: PIDFile= references path below legacy directory /var/run/, updating /var/run/nut/upsmon.pid → /run/nut/upsmon.pid; pleas
systemd[1]: nut-monitor.service: Supervising process 2399 which is not our child. We'll most likely not notice when it exits.
usbhid-ups[2387]: libusb_get_interrupt: error sending control message: Value too large for defined data type
usbhid-ups[2387]: libusb_get_report: error sending control message: No such device
usbhid-ups[2387]: libusb_get_interrupt: error submitting URB: No such device
usbhid-ups[2387]: libusb_get_interrupt: error submitting URB: No such device
usbhid-ups[2387]: libusb_get_interrupt: error submitting URB: No such device
upsd[2391]: Data for UPS [myups] is stale - check driver
upsmon[2399]: Poll UPS [myups@localhost] failed - Data stale
upsmon[2399]: Communications with UPS myups@localhost lost
upsmon[2399]: Poll UPS [myups@localhost] failed - Data stale

In this case the server has been running for 55 days. So after 55 days of operation now these error messages come. What could be the reason for this?

lsusb:

Bus 001 Device 050: ID 06da:ffff Phoenixtec Power Co., Ltd.

cat ups.conf:

[myups]
    driver = usbhid-ups
    port = auto
    vendorid = 06da
    desc = "myups"
    pollinterval = 15

upsd -v:

Network UPS Tools upsd 2.7.4
@jimklimov
Copy link
Member

jimklimov commented Apr 21, 2021 via email

@HyP3r-
Copy link
Author

HyP3r- commented Apr 21, 2021

For the most part the messages indicate that the OS lost the USB device,
not much that NUT can do to fix that part. Might be some power-saving
disabling the chip, or something else frozen on the hub and a USB reset
restarting every connection (either intentionally, or because some vendors
cut corners and implement a port reset same as hub reset).

This is a Debian 10 which runs on a HP ProLiant DL360. I mention this because I can't imagine that such a server has energy saving mechanisms for the USB system. How can I find out if something like this happened at this moment?

Guessing by your device name, containing "vm", I might add potentially some
delays or flaws in virtualization/passthrough layer as a possible problem
source.

It is not a virtual machine but the hypervisor. As platform I use Debian 10 with Proxmox VE.

On a busy machine (hypervisor with many guests, or other
compute/IO/context-switch heavy systems) or on an under-powered machine
(preempted VM just not on CPU) there might also be some exceeded hardcoded
timeouts in any layer of the OS, drivers and software down to libusb used
by NUT driver, perceiving a loss of device because last data exchange was a
bit too long ago.

As already described, the system actually runs a hypervisor. And the system is also relatively busy. But somehow I can't imagine that this is enough to hang up so much.

In that log I see the lost device reported all over April, but the driver
only aborted once? I believe that means retries succeeded to find (maybe
reinitialize) the USB device except once.

It seems so yes: the last few months the connection is repeatedly interrupted, only unfortunately today it did not work to restore the connection.

For context: which OS and version of NUT (packaged or custom built) is that
happening with? If you do/can run a custom build, are you in position to
check if native libusb-1.0 support from some of the competing branches in
issue #300 would behave better?

I just tried a few times to compile the branches "libusb-1.0+0.1", "libusb-1.0" and "libusb-compat-1.0" but with no full success: The branches "libusb-1.0+0.1" and "libusb-1.0" I could compile but were unable to use them. I always get the following error message:

upsdrvctl[44892]: Failed to read pid from /var/state/ups/usbhid-ups1-myups.pid
upsdrvctl[44892]: Network UPS Tools - Generic HID driver 0.42 (2.7.4-420-g2999c95f)
upsdrvctl[44892]: USB communication driver (libusb 1.0) 0.02
upsdrvctl[44892]: No matching HID UPS found
upsdrvctl[44892]: Driver failed to start (exit status=1)
upsmon[18049]: Poll UPS [myups@localhost] failed - Driver not connected

@jimklimov
Copy link
Member

jimklimov commented Apr 21, 2021 via email

@HyP3r-
Copy link
Author

HyP3r- commented Apr 23, 2021

After I called configure Debian conform the library could be compiled and used. I will now observe the whole thing for a quarter. If it doesn't hang anymore, the ticket can be closed.

I will inform you in this issue.

@jimklimov
Copy link
Member

jimklimov commented Apr 23, 2021 via email

@jimklimov jimklimov added PowerWalker PowerWalker and BlueWalker branded devices USB Phoenixtec (USB 0x06DA/0xFFFF) This USB chip VID/PID is used in many devices, some with different protocols - detection may be hard labels Dec 1, 2021
@graemev
Copy link

graemev commented Feb 29, 2024

OK, I hit this issue, a reboot "fixed" it but I gathered some info before the reboot , might help somebody, esp if the real fix is to raise a kernel defect. (BTW this happened about 10 days after a real power cut...that would have been annoying if it had failed):

The messages:

Feb 25 14:06:57 ybox usbhid-ups[727]: libusb_get_interrupt: could not claim interface 0: Device or resource busy                                                                                                              
Feb 25 14:07:07 ybox usbhid-ups[727]: libusb_get_interrupt: error sending control message: Protocol error                                                                                                                     
Feb 25 14:07:17 ybox usbhid-ups[727]: libusb_get_interrupt: error sending control message: Protocol error                                                                                                                     
... 33K of similar messages  

Stop and restart nut-server (debian bullseye)


root@ybox:/var/log# systemctl start  nut-server                                                                                                                                                                               
root@ybox:/var/log# systemctl status 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 Thu 2024-02-29 10:50:45 GMT; 38s ago                                                                                                                                                      
    Process: 1066411 ExecStart=/sbin/upsd (code=exited, status=0/SUCCESS)                                                                                                                                                     
   Main PID: 1066412 (upsd)                                                                                                                                                                                                   
      Tasks: 1 (limit: 4476)                                                                                                                                                                                                  
     Memory: 772.0K                                                                                                                                                                                                           
        CPU: 33ms                                                                                                                                                                                                             
     CGroup: /system.slice/nut-server.service                                                                                                                                                                                 
             └─1066412 /lib/nut/upsd                                      

Feb 29 10:50:45 ybox upsd[1066411]: listening on 127.0.0.1 port 3493                                                                                                                                                          
Feb 29 10:50:45 ybox upsd[1066411]: listening on 10.117.0.152 port 3493                                                                                                                                                       
Feb 29 10:50:45 ybox upsd[1066411]: listening on 127.0.0.1 port 3493                                                                                                                                                          
Feb 29 10:50:45 ybox upsd[1066411]: Can't connect to UPS [qnapups] (usbhid-ups-qnapups): No such file or directory                                                                                                            
Feb 29 10:50:45 ybox upsd[1066411]: Can't connect to UPS [qnapups] (usbhid-ups-qnapups): No such file or directory                                                                                                            
Feb 29 10:50:45 ybox upsd[1066411]: /etc/nut/upsd.users is world readable                                                                                                                                                     
Feb 29 10:50:45 ybox upsd[1066411]: /etc/nut/upsd.users is world readable                                                                                                                                                     
Feb 29 10:50:45 ybox upsd[1066412]: Startup successful                                                                                                                                                                        
Feb 29 10:50:45 ybox systemd[1]: Started Network UPS Tools - power devices information server.                                                                                                                                
Feb 29 10:50:50 ybox upsd[1066412]: User admin@127.0.0.1 logged into UPS [qnapups]  

The driver failed to start:

root@ybox:/var/log# /lib/nut/usbhid-ups -DDD -a qnapups -u nut   
 ....
0.032911        Checking device (051D/0002) (001/002)                                                                                                                                                                         
   0.034470     - VendorID: 051d                                                                                                                                                                                              
   0.034502     - ProductID: 0002                                                                                                                                                                                             
   0.034516     - Manufacturer: unknown                                                                                                                                                                                       
   0.034529     - Product: unknown                                                                                                                                                                                            
   0.034542     - Serial Number: unknown                                                                                                                                                                                      
   0.034554     - Bus: 001                                                                                                                                                                                                    
   0.034566     - Device release number: 0106                                                                                                                                                                                 
   0.034586     Trying to match device                                                                                                                                                                                        
   0.034605     device->Product is NULL so it is not possible to determine whether to activate max_report_size workaround                                                                                                     
   0.034641     Device matches                                                                                                                                                                                                
   0.034703     nut_usb_set_altinterface: skipped usb_set_altinterface(udev, 0)                                                                                                                                               
   0.035360     Unable to get HID descriptor (error sending control message: Protocol error)                                                                                                                                  
   0.035391     HID descriptor length (method 1) -1                                                                                                                                                                           
   0.035419     HID descriptor, method 2: (9 bytes) => 09 21 10 01 21 01 22 05 04                                                                                                                                             
   0.035440     HID descriptor length (method 2) 1029                                                                                                                                                                         
   0.035502     HID descriptor length 1029                                                                                                                                                                                    
   0.039396     Unable to get Report descriptor: Protocol error                                                                                                                                                               
...

So it thinks Product is NULL ...

root@ybox:/var/log# lsusb -d 051d:                                                                                                                                                                                            
Bus 001 Device 002: ID 051d:0002 American Power Conversion Uninterruptible Power Supply                                                                                                                                       
        
Bus 001 Device 002: ID 051d:0002 American Power Conversion Uninterruptible Power Supply                                                                                                                                       
Device Descriptor:                                                                                                                                                                                                            
  bLength                18                                                                                                                                                                                                   
  bDescriptorType         1                                                                                                                                                                                                   
  bcdUSB               1.10                                                                                                                                                                                                   
  bDeviceClass            0                                                                                                                                                                                                   
  bDeviceSubClass         0                                                                                                                                                                                                   
  bDeviceProtocol         0                                                                                                                                                                                                   
  bMaxPacketSize0         8                                                                                                                                                                                                   
  idVendor           0x051d American Power Conversion                                                                                                                                                                         
  idProduct          0x0002 Uninterruptible Power Supply                                                                                                                                                                      
  bcdDevice            1.06                                                                                                                                                                                                   
  iManufacturer           3 American Power Conversion                                                                                                                                                                         
  iProduct                1 Back-UPS XS 700U   FW:924.Z5 .I USB FW:Z5                                                                                                                                                         
  iSerial                 2 3B2041X34361                                                                                                                                                                                      
  bNumConfigurations      1                                                                                                                                                                                                   
  Configuration Descriptor:                                                                                                                                                                                                   
    bLength                 9                                                                                                                                                                                                 
    bDescriptorType         2                                                                                                                                                                                                 
    wTotalLength       0x0022                                                                                                                                                                                                 
    bNumInterfaces          1                                                                                                                                                                                                 
    bConfigurationValue     1                                                                                                                                                                                                 
    iConfiguration          0                                                                                                                                                                                                 
    bmAttributes         0xe0                                                                                                                                                                                                 
      Self Powered                                                                                                                                                                                                            
      Remote Wakeup                                                                                                                                                                                                           
    MaxPower               24mA                                                                                                                                                                                               
    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           33 US                                                                                                                                                                                        
          bNumDescriptors         1                                                                                                                                                                                           
          bDescriptorType        34 Report                                                                                                                                                                                    
          wDescriptorLength    1029                                                                                                                                                                                           
          Report Descriptor: (length is -1)                                                                                                                                                                                   
      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                                                                                                                                                                                             
can't get debug descriptor: Resource temporarily unavailable                                                                                                                                                                  
cannot read device status, Resource temporarily unavailable (11)   

(BTW that last line may be key)

Looking at:

root@ybox:/var/log# cat /sys/bus/usb/devices/1-1/product                                                                                                                                                                      
Back-UPS XS 700U   FW:924.Z5 .I USB FW:Z5                                                                                                                                                                                     
                                    

It appears to be there.

(also did this as user NUT also OK)

Will reboot ..

Following reboot ...all seemed to come up OK (UPS WAS NOT power cycled)

I noted the following diffs in the output of lsusb:

Before Reboot:                                                                                                                                                                                                                
          Report Descriptor: (length is -1)                                                                                                                                                                                   
          ...                                                                                                                                                                                                                 
          can't get debug descriptor: Resource temporarily unavailable                                                                                                                                                        
          cannot read device status, Resource temporarily unavailable (11)                                                                                                                                            
                                                                                                                                                                                                                              
After Reboot:                                                                                                                                                                                                                 
         Report Descriptors:                                                                                                                                                                                                  
           UNAVAILABLE                                                                                                                                                                                                  
                                                                                                                                                                                                                              
           can't get debug descriptor: Resource temporarily unavailable      
                                                                                                                                          
           **Device Status:     0x0000  **                                                                                                                                                                                       
             (Bus Powered)                                                                                                                                                                                  
   


@jimklimov jimklimov added impacts-release-2.7.4 Issues reported against NUT release 2.7.4 (maybe vanilla or with minor packaging tweaks) Connection stability issues Issues about driver<->device and/or networked connections (upsd<->upsmon...) going AWOL over time labels Mar 1, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Connection stability issues Issues about driver<->device and/or networked connections (upsd<->upsmon...) going AWOL over time impacts-release-2.7.4 Issues reported against NUT release 2.7.4 (maybe vanilla or with minor packaging tweaks) Phoenixtec (USB 0x06DA/0xFFFF) This USB chip VID/PID is used in many devices, some with different protocols - detection may be hard PowerWalker PowerWalker and BlueWalker branded devices USB
Projects
None yet
Development

No branches or pull requests

3 participants