[Nut-upsuser] CyberPower usbhid-ups continuously disconnects/reconnects

[nut]

Hello,

I've had this same model CyberPower connected to a linux server and a
freebsd server.

[root at sensor003 menon]# lsusb
Bus 005 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 004 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 003 Device 004: ID 0764:0501 Cyber Power System, Inc. CP1500 AVR UPS
Bus 003 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 002 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

When the nut daemons start attempting to monitor the UPS, the device
begins a cycle of disconnecting and reconnecting every 20sec.

Running 'usbhid-ups -a nexups' manually, yields permissions issues:

[root at sensor003 menon]# usbhid-ups -a nexups
Network UPS Tools - Generic HID driver 0.34 (2.4.3)
USB communication driver 0.31
Using subdriver: CyberPower HID 0.3
libusb_get_report: could not claim interface 0: Device or resource busy
Got disconnected by another driver: Device or resource busy
Can't initialize data from HID UPS

[root at sensor003 network-ups-tools]# ls -l /dev/bus/usb/003/
total 0
crw-rw-r-- 1 root root 189, 256 Jun 7 10:55 001
crw-rw---- 1 root nut 189, 270 Jun 7 11:58 015

There is a udev rule to set permissions on this device:

[root at sensor003 menon]# cat /etc/udev/rules.d/91-local.rules
# set permissions for CyberPower UPS -jea 2010-06-02
SUBSYSTEM=="usb", ATTRS{idVendor}=="0764", GROUP="nut", MODE="0660"

The group and permissions show that this has been applied.

I'm not a linux-usb developer, and I don't quite get the depth of this,
but it seems the system hid driver is attaching to this device as it
enumerates, preventing the nut driver from attaching.

This device was finally attached before (nut 2.4) after applying the
patch mentioned here:

http://www.mail-archive.com/nut-upsuser at lists.alioth.debian.org/msg05550.html

This corrected for this low speed device not providing packets greater
than 8 bytes in length.

This patch didn't apply directly to the nut 2.6 source.

Can anyone confirm if this 8byte low speed device buffer size limit is
applied in 2.6?

Thank You Very Much!

johnea

[Arnaud Quette]

Hi

2011/6/7 <nut at johnea.net>

Post by nut
Hello,
I've had this same model CyberPower connected to a linux server and a
freebsd server.
[root at sensor003 menon]# lsusb
Bus 005 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 004 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 003 Device 004: ID 0764:0501 Cyber Power System, Inc. CP1500 AVR UPS
Bus 003 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 002 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
When the nut daemons start attempting to monitor the UPS, the device
begins a cycle of disconnecting and reconnecting every 20sec.
[root at sensor003 menon]# usbhid-ups -a nexups
Network UPS Tools - Generic HID driver 0.34 (2.4.3)
USB communication driver 0.31
Using subdriver: CyberPower HID 0.3
libusb_get_report: could not claim interface 0: Device or resource busy
Got disconnected by another driver: Device or resource busy

this msg is typical of multiple driver instances running, and fighting to
get the hand on the device.
you can confirm this with an 'ls', and fix it by stopping / killing
everything, then starting the driver using upsdrvctl.

Post by nut
Can't initialize data from HID UPS
[root at sensor003 network-ups-tools]# ls -l /dev/bus/usb/003/
total 0
crw-rw-r-- 1 root root 189, 256 Jun 7 10:55 001
crw-rw---- 1 root nut 189, 270 Jun 7 11:58 015
[root at sensor003 menon]# cat /etc/udev/rules.d/91-local.rules
# set permissions for CyberPower UPS -jea 2010-06-02
SUBSYSTEM=="usb", ATTRS{idVendor}=="0764", GROUP="nut", MODE="0660"

there should already be a set of rules generated by NUT and named
52-nut-usbups.rules and located in /lib/udev/rules.d

Post by nut
The group and permissions show that this has been applied.
I'm not a linux-usb developer, and I don't quite get the depth of this,
but it seems the system hid driver is attaching to this device as it
enumerates, preventing the nut driver from attaching.
This device was finally attached before (nut 2.4) after applying the
http://www.mail-archive.com/nut-upsuser at lists.alioth.debian.org/msg05550.html
This corrected for this low speed device not providing packets greater
than 8 bytes in length.
This patch didn't apply directly to the nut 2.6 source.
Can anyone confirm if this 8byte low speed device buffer size limit is
applied in 2.6?

2.6.1 has a smarter fix for this, since having a hard-coded 8 bytes length
caused regressions on some other devices.

cheers
Arnaud

[nut]

Hi

Thanks for your reply Arnaud!

I've installed a bunch of updates, including an update to nut 2.6.1, and
the symptoms have changed slightly, but I believe the root issue is
still unchanged.

I attempt to start the daemon during init, but it fails.

After boot, I see repeated disconnect/reconnect of the UPS:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Jun 8 18:07:03 sensor003 kernel: [ 387.250020] usb 3-2: USB
disconnect, address 18
Jun 8 18:07:06 sensor003 kernel: [ 390.366650] usb 3-2: new low speed
USB device using uhci_hcd and address 19
Jun 8 18:07:07 sensor003 kernel: [ 390.688533] generic-usb
0003:0764:0501.0012: hiddev0,hidraw0: USB HID v1.10 Device [CPS CP425HG]
on usb-0000:00:10.1-2/input0

Jun 8 18:07:28 sensor003 kernel: [ 411.500020] usb 3-2: USB
disconnect, address 19
Jun 8 18:07:29 sensor003 kernel: [ 412.476677] usb 3-2: new low speed
USB device using uhci_hcd and address 20
Jun 8 18:07:29 sensor003 kernel: [ 412.794806] generic-usb
0003:0764:0501.0013: hiddev0,hidraw0: USB HID v1.10 Device [CPS CP425HG]
on usb-0000:00:10.1-2/input0
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

However, if I manually run the rc.d script, or 'usbhid-ups -a nexups' or
'upsdrvctl start' the connection to the UPS will sometimes succeed.

On successful start, this line appears with the upsd and upsmon messages:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Jun 8 17:55:34 sensor003 usbhid-ups[1066]: Startup successful
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

On failed startup, the above line is missing from messages.log. but
(after boot) I do see:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Jun 8 18:00:48 sensor003 kernel: [ 7.816712] usb 3-2: new low speed
USB device using uhci_hcd and address 2
Jun 8 18:00:48 sensor003 kernel: [ 8.319356] generic-usb
0003:0764:0501.0001: hiddev0,hidraw0: USB HID v1.10 Device [CPS CP425HG]
on usb-0000:00:10.1-2/input0
Jun 8 18:00:48 sensor003 kernel: [ 8.319395] usbcore: registered new
interface driver usbhid
Jun 8 18:00:48 sensor003 kernel: [ 8.319400] usbhid: USB HID core driver
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

Once nut is successfully started, the cycle of disconnect/reconnect
stops. If I stop nut, the cycle starts again.

Does this seems to indicate the conflict of drivers you mentioned?

What can I do to prevent the core usbhid driver from attaching to this
device?

Thank You for All of Your Hard Work!

johnea

[nut]

Post by nut

Hi

Thanks for your reply Arnaud!

I've updated to kernel 2.6.39 and nut 2.6.1

This continuous disconnect/reconnect issue is still occurring.

After manually trying to start nut 3 or 4 times it will start.

Post by nut
Once nut is successfully started, the cycle of disconnect/reconnect
stops. If I stop nut, the cycle starts again.

-> Does this seems to indicate the conflict of drivers you mentioned?
-> What can I do to prevent the core usbhid driver from attaching to this
-> device?

I've been reading everything I can find, I can't find any way to determine why
the kernel is disconnecting this device.

Thank you very much for any clues that will help me debug this!

johnea

[nut]

Post by nut
-> Does this seems to indicate the conflict of drivers you mentioned?

usbtree data that may indicate driver conflict is the issue:

The output of usbtree when the device is disconnecting:
/: Bus 04.Port 1: Dev 1, Class=root_hub, Drv=uhci_hcd/2p, 12M
|_ Port 1: Dev 26, If 0, Prod=CP425HG, Class=HID, Drv=usbhid, 1.5M

The output of usbtree once usbhid-ups has succesfully connected:
/: Bus 04.Port 1: Dev 1, Class=root_hub, Drv=uhci_hcd/2p, 12M
|_ Port 1: Dev 27, If 0, Prod=CP425HG, Class=HID, Drv=usbfs, 1.5M

Is there a udev rule that can block the usbhid driver from connecting to the device?

Thank You!

johnea

[Charles Lepple]

Post by nut

Post by nut
-> Does this seems to indicate the conflict of drivers you mentioned?

I think Arnaud was referring to the case where two instances of NUT
have been installed, and both user-space drivers are trying to re-open
the device. The "usbhid" driver mentioned below is a kernel driver,
and unless there is a regression in the kernel driver detach code,
that shouldn't be an issue.

Post by nut
/: Bus 04.Port 1: Dev 1, Class=root_hub, Drv=uhci_hcd/2p, 12M
|_ Port 1: Dev 26, If 0, Prod=CP425HG, Class=HID, Drv=usbhid, 1.5M
/: Bus 04.Port 1: Dev 1, Class=root_hub, Drv=uhci_hcd/2p, 12M
|_ Port 1: Dev 27, If 0, Prod=CP425HG, Class=HID, Drv=usbfs, 1.5M
Is there a udev rule that can block the usbhid driver from
connecting to the device?

There is a blacklist in the kernel, but I don't think this is the
issue here. The UPS shouldn't be completely disconnecting, even if two
drivers are fighting over it. (If that's the case, you just get a
volley of EBUSY errors between the two drivers.)

Double-check the cabling, because disconnect messages such as the
following are reported to the kernel by the USB host controller chip:

Jun 8 18:07:28 sensor003 kernel: [ 411.500020] usb 3-2: USB
disconnect, address 19

Is it consistently disconnecting every 20 seconds? That almost sounds
like some proprietary extension to the HID protocol - the UPS expects
the computer to send something that only the CyberPower software knows
to send.

[nut]

Double-check the cabling, because disconnect messages such as the following are
Jun 8 18:07:28 sensor003 kernel: [ 411.500020] usb 3-2: USB disconnect,
address 19
Is it consistently disconnecting every 20 seconds? That almost sounds like some
proprietary extension to the HID protocol - the UPS expects the computer to send
something that only the CyberPower software knows to send.

Ah So...

It does disconnect exactly every 20sec.

I did check the cable, and moved it to each of the host receptacles. Also tried
it on several different computers, with the exact same results (including
FreeBSD 8.2)

So this seems like a usb device originating issue.

Once the usbhid-ups driver connects, the disconnect/reconnect cycle stops.

In this light, the problem seems to be that the device may be temporarily
unavailable at the moment the usbhid-ups driver attempts to connect, at boot time.

ASIDE
Maybe this is a relatively fixed, but unknown asyncronous delay at boot time.
When this delay is favorable, so that the device is available when the driver
checks, the connection is established, and nut starts successfully at system
boot.
When the delay is unfavorable, the device is in the middle of
disconnect/reconnect when the driver checks and nut fails to connect and
start.
This would explain why some combinations of kernel, drivers, boot order, etc,
just _seemed_ to work reliably.
/ASIDE

If this is correct, it seems the 'fix' would be to build a small delay, and
retry, into the initial connection code of the usbhid-ups driver. Before giving
up on finding the device.

Is this practical?

Thank you Again Charles and Arnaud!

johnea

[nut]

Post by nut

Is it consistently disconnecting every 20 seconds? That almost sounds like some
proprietary extension to the HID protocol - the UPS expects the computer to send
something that only the CyberPower software knows to send.

In this light, the problem seems to be that the device may be temporarily
unavailable at the moment the usbhid-ups driver attempts to connect, at boot time.

I'm in the lab now, I think I've confirmed this.

If I move the upsd startup to before the system's dhcp, it always connects to
the UPS at boot. If it's after the dhcp delay, then the UPS has dropped offline,
and the nut startup fails.

Post by nut
If this is correct, it seems the 'fix' would be to build a small delay, and
retry, into the initial connection code of the usbhid-ups driver. Before giving
up on finding the device.
Is this practical?

This startup retry would only need to affect the usbhid-ups CyberPower subdriver:

-> Using subdriver: CyberPower HID 0.3

Post by nut
Thank you Again Charles and Arnaud!
johnea

[Arnaud Quette]

2011/6/16 Charles Lepple <clepple at gmail.com>

(...)
Is it consistently disconnecting every 20 seconds? That almost sounds like
some proprietary extension to the HID protocol - the UPS expects the
computer to send something that only the CyberPower software knows to send.

in this case, doing an usbsnoop run is the way to go:
http://lists.alioth.debian.org/pipermail/nut-upsdev/2010-February/004528.html

cheers,
Arnaud

[nut]

Post by Arnaud Quette
2011/6/16 Charles Lepple <clepple at gmail.com>

(...)
Is it consistently disconnecting every 20 seconds? That almost sounds like
some proprietary extension to the HID protocol - the UPS expects the
computer to send something that only the CyberPower software knows to send.

http://lists.alioth.debian.org/pipermail/nut-upsdev/2010-February/004528.html

It seems the usbhid-ups driver already knows how to make the UPS happy. Once the
driver has successfully connected to the UPS, the disconnect/reconnect cycle
stops and the UPS stays connected and communicating from then on.

It only misses connecting if the device is given enough time to disconnect
(presumably because it timed out after 20sec).

Unless the administrator can guarantee to _always_ connect to the device within
20sec of boot, the usbhid-ups needs to delay a second or two and then retry, 2
or 3 times, before giving up on finding the CyberPower subdriver based UPS.

Post by Arnaud Quette
cheers,
Arnaud

Thank You Arnaud!

p.s. I tried to make a patch for this, but it failed, attached for reference
-------------- next part --------------
An embedded and charset-unspecified text was scrubbed...
Name: hid-retry.patch
URL: <http://lists.alioth.debian.org/pipermail/nut-upsuser/attachments/20110617/7f1445f6/attachment.ksh>

[Charles Lepple]

Post by nut

Post by Arnaud Quette
2011/6/16 Charles Lepple <clepple at gmail.com>

(...)
Is it consistently disconnecting every 20 seconds? That almost sounds like
some proprietary extension to the HID protocol - the UPS expects the
computer to send something that only the CyberPower software knows to send.

http://lists.alioth.debian.org/pipermail/nut-upsdev/2010-February/004528.html

It seems the usbhid-ups driver already knows how to make the UPS happy. Once the
driver has successfully connected to the UPS, the disconnect/
reconnect cycle
stops and the UPS stays connected and communicating from then on.
It only misses connecting if the device is given enough time to disconnect
(presumably because it timed out after 20sec).

By the way, this is fairly broken behavior on the part of the UPS
firmware. There are standards-compliant ways for a USB device to
suspend after inactivity while still remaining connected to the bus.

I don't know if this UPS has upgradeable firmware, but if it were
mine, I'd let the manufacturer know.

Post by nut
Unless the administrator can guarantee to _always_ connect to the device within
20sec of boot, the usbhid-ups needs to delay a second or two and then retry, 2
or 3 times, before giving up on finding the CyberPower subdriver based UPS.

What if you add the loop in the script that starts the driver (through
upsdrvctl)? That might be easier to prototype.

[nut]

By the way, this is fairly broken behavior on the part of the UPS firmware.
There are standards-compliant ways for a USB device to suspend after inactivity
while still remaining connected to the bus.
I don't know if this UPS has upgradeable firmware, but if it were mine, I'd let
the manufacturer know.

I will pass this info on to CyberPower. I'm not sure if the firmware is
upgradable, I would guess not. Their HID models seem to all be cheaper consumer
oriented products.

To tell the truth, I really questioned if it was worth pursuing this issue. It
seemed pretty clear from the beginning that the whole problem was in some way
caused by the device (since other usb devices seem to work).

Since you correctly diagnosed the situation as being the device itself that
terminates the connection, it seemed to me that the only real benefit to be
gained was to improve the ability, of linux-usb and nut, to deal with such
misbehaving hardware.

So this is why I've continued to pursue this instead of just throwing these
units in the trash and buying something that works (really, it's not just to
badger you guys 8-)

What if you add the loop in the script that starts the driver (through
upsdrvctl)? That might be easier to prototype.

I tried to do this, but failed again. I tried to loop on the execv for the
forked child process, in forkexec() called from start_driver(). There's probably
a better place to locate the loop, but I haven't found it yet. (patch attached
for reference)

Thanks for your support!

johnea
-------------- next part --------------
An embedded and charset-unspecified text was scrubbed...
Name: cyberpower-hid-retry.patch
URL: <http://lists.alioth.debian.org/pipermail/nut-upsuser/attachments/20110619/db65a489/attachment.ksh>

[johnea]

Hello,

I've had this same model CyberPower connected to a linux server and a
freebsd server.

[root at sensor003 menon]# lsusb
Bus 005 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 004 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 003 Device 004: ID 0764:0501 Cyber Power System, Inc. CP1500 AVR UPS
Bus 003 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 002 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

When the nut daemons start attempting to monitor the UPS, the device
begins a cycle of disconnecting and reconnecting every 20sec.

Running 'usbhid-ups -a nexups' manually, yields permissions issues:

[root at sensor003 menon]# usbhid-ups -a nexups
Network UPS Tools - Generic HID driver 0.34 (2.4.3)
USB communication driver 0.31
Using subdriver: CyberPower HID 0.3
libusb_get_report: could not claim interface 0: Device or resource busy
Got disconnected by another driver: Device or resource busy
Can't initialize data from HID UPS

[root at sensor003 network-ups-tools]# ls -l /dev/bus/usb/003/
total 0
crw-rw-r-- 1 root root 189, 256 Jun 7 10:55 001
crw-rw---- 1 root nut 189, 270 Jun 7 11:58 015

There is a udev rule to set permissions on this device:

[root at sensor003 menon]# cat /etc/udev/rules.d/91-local.rules
# set permissions for CyberPower UPS -jea 2010-06-02
SUBSYSTEM=="usb", ATTRS{idVendor}=="0764", GROUP="nut", MODE="0660"

The group and permissions show that this has been applied.

I'm not a linux-usb developer, and I don't quite get the depth of this,
but it seems the system hid driver is attaching to this device as it
enumerates, preventing the nut driver from attaching.

This device was finally attached before (nut 2.4) after applying the
patch mentioned here:

http://www.mail-archive.com/nut-upsuser at lists.alioth.debian.org/msg05550.html

This corrected for this low speed device not providing packets greater
than 8 bytes in length.

This patch didn't apply directly to the nut 2.6 source.

Can anyone confirm if this 8byte low speed device buffer size limit is
applied in 2.6?

Thank You Very Much!

johnea