[Nut-upsuser] Usbhip-ups going wild

Tue Aug 11 08:37:36 UTC 2009

Hello again,

I managed to get it work correctly. I ran all night without disconnexion.
So it appears that some UPS devices are too long to answer the usb polling.
MGE Ellipse did take too long but MGE Evolution is fast.

So to get it work just play with the global parameter of ups.conf :
pollinterval.
Default is 2 seconds, when set to 10 it works great.

On the machine connected to a MGE Evolutipn 1250, I got this message during
the night :
Aug 10 23:44:17 localhost kernel: hub 3-0:1.0: port 2 disabled by hub
(EMI?), re-enabling...
Aug 10 23:44:17 localhost kernel: usb 3-2: USB disconnect, address 14
Aug 10 23:44:26 localhost kernel: usb 3-2: new low speed USB device using
address 16

It doesn't really bother me because it is reconnected in 10 seconds but
isn't there some issue here?
It is the kernel that disconnects the device but I wonder why... 

Regards,
Antoine

-----Message d'origine-----
De : Antoine Gatineau [mailto:antoine.gatineau at alcatel-lucent.com] 
Envoyé : vendredi 7 août 2009 16:56
À : 'Christopher X. Candreva'; 'nut-upsuser'
Cc : antoine.gatineau at alcatel-lucent.com
Objet : RE: [Nut-upsuser] Usbhip-ups going wild

Thanks for the info.

I tried to add OWNER but no change.
However, I discovered after that the rights are set by hal. So libhidups and
libhid.usermap are required after all.

I still have kernel: usbhid: probe of 3-2:1.0 failed with error -5 in syslog
and on screen. 

I have a very wierd behavior but I don't think it is related. Here is the
/var/log/message :
Aug  7 16:14:46 k2pbeta-host upsdrvctl: Using subdriver: MGE HID 1.12 Aug  7
16:14:47 k2pbeta-host upsdrvctl: Network UPS Tools - Generic HID driver 0.34
(2.4.1) Aug  7 16:14:47 k2pbeta-host upsdrvctl: USB communication driver
0.31 Aug  7 16:14:48 k2pbeta-host usbhid-ups[23785]: Startup successful Aug
7 16:14:48 k2pbeta-host upsdrvctl: Network UPS Tools - UPS driver controller
2.4.1 Aug  7 16:14:48 k2pbeta-host ups: upsdrvctl startup succeeded Aug  7
16:14:48 k2pbeta-host ups:  succeeded Aug  7 16:14:48 k2pbeta-host
upsd[23789]: listening on 127.0.0.1 port 3493 Aug  7 16:14:48 k2pbeta-host
upsd[23789]: Connected to UPS [ups_on_usb]:
usbhid-ups-ups_on_usb
Aug  7 16:14:48 k2pbeta-host upsd: listening on 127.0.0.1 port 3493 Aug  7
16:14:48 k2pbeta-host upsd: Connected to UPS [ups_on_usb]:
usbhid-ups-ups_on_usb
Aug  7 16:14:48 k2pbeta-host upsd[23790]: Startup successful Aug  7 16:14:48
k2pbeta-host ups: upsd startup succeeded Aug  7 16:14:48 k2pbeta-host ups:
succeeded Aug  7 16:14:48 k2pbeta-host upsmon[23795]: Startup successful Aug
7 16:14:48 k2pbeta-host upsd[23790]: User upsmon at 127.0.0.1 logged into UPS
[ups_on_usb] Aug  7 16:14:48 k2pbeta-host upsmon: UPS: ups_on_usb at localhost
(master) (power value 1) Aug  7 16:14:49 k2pbeta-host upsmon: Using power
down flag file /etc/killpower Aug  7 16:14:49 k2pbeta-host upsmon:
Aug  7 16:14:49 k2pbeta-host ups: upsmon startup succeeded Aug  7 16:14:49
k2pbeta-host ups:  succeeded Aug  7 16:32:26 k2pbeta-host kernel: usb 2-1:
control timeout on ep0in Aug  7 16:32:28 k2pbeta-host last message repeated
2 times Aug  7 16:32:28 k2pbeta-host upsd[23790]: Data for UPS [ups_on_usb]
is stale
- check driver
Aug  7 16:32:29 k2pbeta-host kernel: usb 2-1: control timeout on ep0in Aug
7 16:32:29 k2pbeta-host upsmon[23796]: Poll UPS [ups_on_usb at localhost]
failed - Data stale Aug  7 16:32:29 k2pbeta-host upsmon[23796]:
Communications with UPS ups_on_usb at localhost lost Aug  7 16:32:29
k2pbeta-host wall[23802]: wall: user nut broadcasted 1 lines
(51 chars)
Aug  7 16:32:30 k2pbeta-host kernel: usb 2-1: control timeout on ep0in Aug
7 16:32:34 k2pbeta-host last message repeated 4 times Aug  7 16:32:34
k2pbeta-host upsmon[23796]: Poll UPS [ups_on_usb at localhost] failed - Data
stale Aug  7 16:32:35 k2pbeta-host kernel: usb 2-1: control timeout on ep0in
Aug  7 16:32:39 k2pbeta-host last message repeated 4 times Aug  7 16:32:39
k2pbeta-host upsmon[23796]: Poll UPS [ups_on_usb at localhost] failed - Data
stale Aug  7 16:32:40 k2pbeta-host kernel: usb 2-1: control timeout on ep0in
Aug  7 16:32:44 k2pbeta-host last message repeated 4 times Aug  7 16:32:44
k2pbeta-host upsmon[23796]: Poll UPS [ups_on_usb at localhost] failed - Data
stale Aug  7 16:32:45 k2pbeta-host kernel: usb 2-1: control timeout on ep0in
Aug  7 16:32:49 k2pbeta-host last message repeated 4 times

<...
     And it continues forever so I shut it down ...>

Aug  7 16:33:34 k2pbeta-host upsmon[23796]: Poll UPS [ups_on_usb at localhost]
failed - Data stale Aug  7 16:33:35 k2pbeta-host kernel: usb 2-1: control
timeout on ep0in Aug  7 16:33:39 k2pbeta-host last message repeated 4 times
Aug  7 16:33:39 k2pbeta-host upsmon[23796]: Poll UPS [ups_on_usb at localhost]
failed - Data stale Aug  7 16:33:40 k2pbeta-host kernel: usb 2-1: control
timeout on ep0in Aug  7 16:33:42 k2pbeta-host last message repeated 2 times
Aug  7 16:33:42 k2pbeta-host upsmon[23796]: Signal 15: exiting Aug  7
16:33:42 k2pbeta-host upsd[23790]: User upsmon at 127.0.0.1 logged out from UPS
[ups_on_usb] Aug  7 16:33:42 k2pbeta-host ups: upsmon shutdown succeeded Aug
7 16:33:42 k2pbeta-host upsd[23790]: mainloop: Interrupted system call Aug
7 16:33:42 k2pbeta-host upsd[23790]: Signal 15: exiting Aug  7 16:33:42
k2pbeta-host ups: upsd shutdown succeeded Aug  7 16:33:42 k2pbeta-host ups:
succeeded Aug  7 16:33:42 k2pbeta-host ups:  succeeded Aug  7 16:33:43
k2pbeta-host kernel: usb 2-1: control timeout on ep0in Aug  7 16:33:43
k2pbeta-host usbhid-ups[23785]: Signal 15: exiting ....

Connexion seems to be broken.

Dmesg give me the following :
...
usb 2-1: control timeout on ep0in
usb 2-1: usbfs: USBDEVFS_CONTROL failed cmd usbhid-ups rqt 128 rq 6 len 256
ret -110 usb 2-1: control timeout on ep0in usb 2-1: usbfs: USBDEVFS_CONTROL
failed cmd usbhid-ups rqt 128 rq 6 len 256 ret -110 usb 2-1: control timeout
on ep0in usb 2-1: usbfs: USBDEVFS_CONTROL failed cmd usbhid-ups rqt 128 rq 6
len 256 ret -110 usb 2-1: control timeout on ep0in usb 2-1: usbfs:
USBDEVFS_CONTROL failed cmd usbhid-ups rqt 128 rq 6 len 256 ret -110 usb
2-1: control timeout on ep0in ...
tones of them

I have attached the output of "lsusb -v -s 002:002" which is my MGE UPS. Too
long to be displayed in the body. Here are the relevant elements :
  idVendor           0x0463 MGE UPS Systems
  idProduct          0xffff UPS
  bcdDevice           42.41
  iManufacturer           1 MGE UPS SYSTEMS
  iProduct                2 ELLIPSE
  iSerial                 4 1HDG0202Y
	    bDescriptorType        34 Report
          wDescriptorLength     769

Any idea on that?
I'm quite lost now, it is internal nut mechanisms.

On this examples, it takes only 18 minutes for the problems to begin. On
another machine it took nearly 3hours.

Thanks
Antoine

-----Message d'origine-----
De :
nut-upsuser-bounces+antoine.gatineau=alcatel-lucent.com at lists.alioth.debian.
org
[mailto:nut-upsuser-bounces+antoine.gatineau=alcatel-lucent.com at lists.alioth
.debian.org] De la part de Christopher X. Candreva Envoyé : jeudi 6 août
2009 18:02 À : nut-upsuser Objet : Re: [Nut-upsuser] Usbhip-ups going wild

On Thu, 6 Aug 2009, Arnaud Quette wrote:

> I have to chown root:dialout and chmod 0660 the 
> /proc/bus/usb/003/006...
>  
> However this should have been done by udev rules. Here is the line for 
> my device :
> #  various models  - usbhid-ups
> ATTR{idVendor}=="0463", ATTR{idProduct}=="ffff", MODE="664", 
> GROUP="dialout"

I happen to be working on some udev rules for myself, unrelated to nut. 
However, I found that the GROUP and MODE settings didn't have an effect
unless I also included a OWNER command.

In my case I was trying to set GROUP="uucp" and had to add OWNER="uucp"

==========================================================
Chris Candreva  -- chris at westnet.com -- (914) 948-3162 WestNet Internet
Services of Westchester http://www.westnet.com/

_______________________________________________
Nut-upsuser mailing list
Nut-upsuser at lists.alioth.debian.org
http://lists.alioth.debian.org/mailman/listinfo/nut-upsuser