Bug 488368 - usbhid-ups: "failed to detach kernel driver from USB device"
Summary: usbhid-ups: "failed to detach kernel driver from USB device"
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: nut
Version: 10
Hardware: x86_64
OS: Linux
low
medium
Target Milestone: ---
Assignee: Michal Hlavinka
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2009-03-03 22:14 UTC by Russell Odom
Modified: 2013-01-13 12:45 UTC (History)
2 users (show)

Fixed In Version: 2.2.2-5.fc10
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2009-06-24 19:35:41 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)
Config files as requested (8.95 KB, application/x-tar)
2009-03-17 22:08 UTC, Russell Odom
no flags Details
usbhid-ups -DD -a mge (17.69 KB, text/plain)
2009-03-18 21:43 UTC, Russell Odom
no flags Details
Output of "rpm -ql VirtualBox" (19.90 KB, text/plain)
2009-05-25 19:47 UTC, Russell Odom
no flags Details

Description Russell Odom 2009-03-03 22:14:16 UTC
Description of problem:
I have an MGE Ellipse Pulsar 500 UPS (USB ID 0463:ffff), connected via USB, and since upgrading to F10 from F8, usbhid-ups will not start.

Version-Release number of selected component (if applicable):
[root@detritus ~]# rpm -qa | grep ^nut
nut-client-2.2.2-4.fc10.x86_64
nut-2.2.2-4.fc10.x86_64
[root@detritus ~]# uname -r
2.6.27.15-170.2.24.fc10.x86_64


How reproducible: Every time


Steps to Reproduce:
1. Configure a UPS with driver = usbhid-ups
2. Attempt to start ups service
  
Actual results:
[root@detritus ~]# service ups start
Starting UPS driver controller:                            [FAILED]
Starting upsd:                                             [  OK  ]
Starting UPS monitor (master):                             [  OK  ]

Expected results:
Service should start successfully

Additional info:
[root@detritus ~]# lsusb -d 0463:ffff
Bus 003 Device 002: ID 0463:ffff MGE UPS Systems UPS
[root@detritus ~]# usbhid-ups -DDDDD -a mge -x vendorid=0463 -x productid=ffff
Network UPS Tools: 0.29 USB communication driver - core 0.33 (2.2.2)

debug level is '5'
upsdrv_initups...
[snipped checking other USB devices here]
Checking device (0463/FFFF) (003/002)
- VendorID: 0463
- ProductID: ffff
- Manufacturer: unknown
- Product: unknown
- Serial Number: unknown
- Bus: 003
Trying to match device
Device matches
failed to claim USB device, trying 2 more time(s)...
detaching kernel driver from USB device...
failed to detach kernel driver from USB device...
trying again to claim USB device...
failed to claim USB device, trying 1 more time(s)...
detaching kernel driver from USB device...
failed to detach kernel driver from USB device...
trying again to claim USB device...
failed to claim USB device, trying 0 more time(s)...
detaching kernel driver from USB device...
failed to detach kernel driver from USB device...
trying again to claim USB device...
Unable to get HID descriptor (error sending control message: Operation not permitted)
i=0, extra[i]=09, extra[i+1]=21
HID descriptor, method 2: (9 bytes) => 09 21 00 01 21 01 22 14 02
HID descriptor length 532
Unable to get Report descriptor: Operation not permitted
[snipped checking other USB devices here]
No appropriate HID device found
No matching HID UPS found

This looks very similar to bug 461374, but that was apparently fixed. The documentation tells me that this is definitely the correct driver to use (I think I could use mge-shut if I used a serial cable instead, but my serial port is in use for something else).

Comment 1 Michal Hlavinka 2009-03-10 16:09:33 UTC
could you try check if 

usbhid-ups -u root -DD -a <name>

works? <name> is name of your ups in ups.conf  - in square brackets

also, do you have any selinux denial messages?

do you see any messages in /var/log/messages related to this?

Comment 2 Russell Odom 2009-03-14 19:01:17 UTC
"usbhid-ups -u root -DD -a mge" is successful.

When I start usbhid-ups on its own, without "-u root", /var/log/messages doesn't contain anything (and just a "Connection refused" message when I try to start NUT via the initscript), and I don't see any selinux messages.

Adding "user = root" to ups.conf seems to allow it to start OK but (having amended my config to use IPv4, as upsd doesn't seem to want to listen on IPv6) upsd still can't connect until I fix a socket permission problem:
[root@detritus ~]# ls -l /var/run/nut/usbhid-ups-mge
srw-rw---- 1 root root 0 2009-03-14 18:44 /var/run/nut/usbhid-ups-mge
[root@detritus ~]# chmod o+rw /var/run/nut/usbhid-ups-mge

After doing this (after NUT startup) everything works, but obviously this is a dirty hack - but I imagine the problem will go away once we get to the bottom of why usbhid-ups needs to run as root in order to work.

Comment 3 Michal Hlavinka 2009-03-17 12:49:59 UTC
First, I've got the same errors when starting ups service. Then I've fully configured it and it works for me now without any errors.

could you upload all your nut config files in this bz?
/etc/sysconfig/ups
/etc/ups/ups.conf
/etc/ups/upsd.conf
/etc/ups/upsd.users
/etc/ups/upsmon.conf
/etc/ups/upssched.conf

Comment 4 Russell Odom 2009-03-17 22:08:11 UTC
Created attachment 335613 [details]
Config files as requested

Here's my config files. Nothing unusual here I don't think.

Comment 5 Michal Hlavinka 2009-03-18 14:08:38 UTC
Your config files looks ok. I've tried to use your config files and it works for me (I've just replaced vendor and product ids)

I found another interesting thing.

First time service ups start is successful, but next time(s) it fails...

please try (as root):
0)remove user=root from ups.conf
1)stop nut : service ups stop
2)check nothing nut related is running : ps aux | grep nut | grep -v grep
3)kill running nut related processes if there are any
4)try to start nut : service ups start

if there is any problem:
repeat steps 1),2),3) and attach output of
usbhid-ups -DD -a mge 
you will need to kill it probably, first 10-20 secs is enough
if there is anything in /var/log/messages attach it too

thanks

Comment 6 Russell Odom 2009-03-18 21:42:03 UTC
Output from /var/log/messages (and console) when starting then stopping NUT:

Broadcast message from nut (Wed Mar 18 21:33:14 2009):

Communications with UPS mge.0.1 lost
Mar 18 21:33:14 detritus upsd[18695]: listening on 0.0.0.0 port 3493
Mar 18 21:33:14 detritus upsd[18695]: Can't connect to UPS [mge] (usbhid-ups-mge): No such file or directory
Mar 18 21:33:14 detritus upsd[18696]: Startup successful
Mar 18 21:33:14 detritus upsmon[18699]: Startup successful
Mar 18 21:33:14 detritus upsd[18696]: Client monmaster.0.1 logged into UPS [mge]
Mar 18 21:33:14 detritus upsmon[18700]: Poll UPS [mge.0.1] failed - Driver not connected
Mar 18 21:33:14 detritus upsmon[18700]: Communications with UPS mge.0.1 lost
Mar 18 21:33:14 detritus wall[18702]: wall: user nut broadcasted 1 lines (44 chars)

Broadcast message from nut (Wed Mar 18 21:33:19 2009):

UPS mge.0.1 is unavailable
Mar 18 21:33:19 detritus upsmon[18700]: Poll UPS [mge.0.1] failed - Driver not connected
Mar 18 21:33:19 detritus upsmon[18700]: UPS mge.0.1 is unavailable
Mar 18 21:33:19 detritus wall[18705]: wall: user nut broadcasted 1 lines (34 chars)
Mar 18 21:33:22 detritus upsmon[18700]: Signal 15: exiting
Mar 18 21:33:22 detritus upsd[18696]: Signal 15: exiting


The output from usbhid-ups -DD -a mge looks the same as my initial report (comment 0) above. Will attach what it looks like with "user = root" re-enabled in a minute...

Comment 7 Russell Odom 2009-03-18 21:43:45 UTC
Created attachment 335770 [details]
usbhid-ups -DD -a mge

This is with "user = root" in ups.conf - all appears to work successfully in this case.

Comment 8 Michal Hlavinka 2009-04-01 14:27:40 UTC
sorry for slow response, but I'm little overloaded last few days

all these without user=root in config file

1)please add output of
id nut
id uucp
lsusb
find /dev/bus/usb/ -ls

2)in /etc/udev/rules.d/52_nut-usbups.rules try changing MODE
ATTR{idVendor}=="0463", ATTR{idProduct}=="ffff", MODE="664", GROUP="uucp"
to
ATTR{idVendor}=="0463", ATTR{idProduct}=="ffff", MODE="666", GROUP="uucp"

if it changes anything (make sure there is nothing nut related running before testing: ps aux | grep nut | grep -v grep ) 

Change it back to 664.

3)try to change selinux mode to permissive (if you have it in enforcing mode: sestatus)
setenforce 0
try if it changes anything (make sure nut is stopped completely) and change it back to enforcing
setenforce 1

Comment 9 Russell Odom 2009-04-03 18:08:04 UTC
1) Here's your info...
[root@detritus ~]# id nut
uid=57(nut) gid=57(nut) groups=57(nut),14(uucp)
[root@detritus ~]# id uucp
uid=10(uucp) gid=14(uucp) groups=14(uucp)
[root@detritus ~]# lsusb
Bus 002 Device 002: ID 2040:8400 Hauppauge 
Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 005 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 001 Device 015: ID 05a4:9862 Ortek Technology, Inc. 
Bus 001 Device 014: ID 0510:0032 Sejin Electron, Inc. 
Bus 001 Device 013: ID 05a4:9837 Ortek Technology, Inc. 
Bus 001 Device 012: ID 03f0:c602 Hewlett-Packard Photosmart D7100 series
Bus 001 Device 011: ID 0c45:6242 Microdia PC Camera (SN9C201 + MI1310)
Bus 001 Device 009: ID 04cc:1521 Philips Semiconductors USB 2.0 Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 004 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 003 Device 002: ID 0463:ffff MGE UPS Systems UPS
Bus 003 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
[root@detritus ~]# find /dev/bus/usb/ -ls
  2477    0 drwxr-xr-x   7 root     root          140 Mar 31 20:37 /dev/bus/usb/
  3722    0 drwxr-xr-x   2 root     root           80 Mar 31 20:37 /dev/bus/usb/002
  3795    0 crw-rw-r--   1 root     vboxusers          Apr  3 12:35 /dev/bus/usb/002/002
  3725    0 crw-rw-r--   1 root     vboxusers          Apr  3 12:35 /dev/bus/usb/002/001
  3691    0 drwxr-xr-x   2 root     root           60 Mar 31 20:37 /dev/bus/usb/005
  3694    0 crw-rw-r--   1 root     vboxusers          Apr  3 12:35 /dev/bus/usb/005/001
  2645    0 drwxr-xr-x   2 root     root          180 Apr  2 21:49 /dev/bus/usb/001
  9560    0 crw-rw-r--   1 root     vboxusers          Apr  3 12:35 /dev/bus/usb/001/015
  9434    0 crw-rw-r--   1 root     vboxusers          Apr  3 12:35 /dev/bus/usb/001/014
  9366    0 crw-rw-r--   1 root     vboxusers          Apr  3 12:35 /dev/bus/usb/001/013
  9102    0 crw-rw-r--   1 root     vboxusers          Apr  3 12:35 /dev/bus/usb/001/012
  8911    0 crw-rw-r--   1 root     vboxusers          Apr  3 12:35 /dev/bus/usb/001/011
  8740    0 crw-rw-r--   1 root     vboxusers          Mar 31 19:37 /dev/bus/usb/001/009
  2648    0 crw-rw-r--   1 root     vboxusers          Apr  3 12:35 /dev/bus/usb/001/001
  2578    0 drwxr-xr-x   2 root     root           60 Mar 31 20:37 /dev/bus/usb/004
  2581    0 crw-rw-r--   1 root     vboxusers          Apr  3 12:35 /dev/bus/usb/004/001
  2478    0 drwxr-xr-x   2 root     root           80 Mar 31 20:37 /dev/bus/usb/003
  2515    0 crw-rw-r--   1 root     vboxusers          Apr  3 17:29 /dev/bus/usb/003/002
  2481    0 crw-rw-r--   1 root     vboxusers          Apr  3 12:35 /dev/bus/usb/003/001

(not quite sure why all the devices have a GID of vboxusers, which is a group created by VirtualBox - perhaps this is the root cause of my problems?)
[root@detritus ~]# getent group vboxusers
vboxusers:x:506:russ
[root@detritus ~]# rpm -q VirtualBox
VirtualBox-2.1.2_41885_fedora9-1.x86_64

2) Changing MODE appears to make no difference (I unplugged and replugged USB cable).

3) Changing selinux to permissive mode didn't help either :-(

Comment 10 Michal Hlavinka 2009-05-19 11:33:18 UTC
yes, it seems, it's vboxusers group related, because it should be uucp group

could you test what happens if you manually change the group to uucp?

in output of 
lsusb
you'll see something like
...
Bus 003 Device 002: ID 0463:ffff MGE UPS Systems UPS

so we need /dev/bus/usb/003/002 to have uucp group:

chmod 0660 /dev/bus/usb/003/002
chown root:uucp /dev/bus/usb/003/002

and try to start nut (without user=root)

If you replug ups to other port, it'll probably be something else than ../003/002, so change the commands accordingly

please add output of
rpm -ql VirtualBox 

and attach VirtualBox's files from /lib/udev/rules.d/ and /etc/udev/rules.d/

thanks

Comment 11 Russell Odom 2009-05-25 19:46:44 UTC
[root@detritus ~]# lsusb | grep MGE
Bus 004 Device 003: ID 0463:ffff MGE UPS Systems UPS
[root@detritus ~]# ls -l /dev/bus/usb/004/003
crw-rw-r-- 1 root vboxusers 189, 386 2009-05-25 20:34 /dev/bus/usb/004/003
[root@detritus ~]# chown :uucp /dev/bus/usb/004/003
[root@detritus ~]# ls -l /dev/bus/usb/004/003
crw-rw-r-- 1 root uucp 189, 386 2009-05-25 20:34 /dev/bus/usb/004/003

The ups service now starts successfully without "user = root" in ups.conf!

[root@detritus ~]# rpm -ql VirtualBox | grep udev
[root@detritus ~]# ls -l /etc/udev/rules.d/*-vboxdrv.rules 
-rw-r--r-- 1 root root 208 2009-04-03 17:47 /etc/udev/rules.d/10-vboxdrv.rules
-rw-r--r-- 1 root root 208 2009-01-22 20:20 /etc/udev/rules.d/60-vboxdrv.rules
[root@detritus ~]# cat /etc/udev/rules.d/10-vboxdrv.rules 
KERNEL=="vboxdrv", NAME="vboxdrv", OWNER="root", GROUP="root", MODE="0600"
SUBSYSTEM=="usb_device", GROUP="vboxusers", MODE="0664"
SUBSYSTEM=="usb", ENV{DEVTYPE}=="usb_device", GROUP="vboxusers", MODE="0664"
[root@detritus ~]# cat /etc/udev/rules.d/60-vboxdrv.rules 
KERNEL=="vboxdrv", NAME="vboxdrv", OWNER="root", GROUP="root", MODE="0600"
SUBSYSTEM=="usb_device", GROUP="vboxusers", MODE="0664"
SUBSYSTEM=="usb", ENV{DEVTYPE}=="usb_device", GROUP="vboxusers", MODE="0664"

Comment 12 Russell Odom 2009-05-25 19:47:50 UTC
Created attachment 345352 [details]
Output of "rpm -ql VirtualBox"

Comment 13 Michal Hlavinka 2009-05-26 06:36:37 UTC
ok, try this (as root):
1) move nut rule to later position
mv /etc/udev/rules.d/52_nut-usbups.rules /etc/udev/rules.d/62_nut-usbups.rules
2) reload udev
udevcontrol --reload_rules
3) stop nut
4) re-plug your ups
5) start nut
6) check permissions of /dev/bus/usb/XXX/YYY as in comment #11

virtualbox is the broken one here, but because fedora doesn't ship virtualbox, we can't fix it. 

This moves nut's udev rules after the virtualbox. In udev, later rule overwrites the prev one (if special keywords are not used).

If this work, I'll change this in nut package

Comment 14 Russell Odom 2009-05-31 19:44:14 UTC
Just tried that, works a treat!

[root@detritus ~]# ls -l /dev/bus/usb/004/004
crw-rw-r-- 1 root uucp 189, 387 2009-05-31 20:40 /dev/bus/usb/004/004

Comment 15 Fedora Update System 2009-06-03 06:48:53 UTC
nut-2.4.1-6.fc11 has been submitted as an update for Fedora 11.
http://admin.fedoraproject.org/updates/nut-2.4.1-6.fc11

Comment 16 Fedora Update System 2009-06-03 06:49:51 UTC
nut-2.2.2-5.fc10 has been submitted as an update for Fedora 10.
http://admin.fedoraproject.org/updates/nut-2.2.2-5.fc10

Comment 17 Fedora Update System 2009-06-04 21:20:01 UTC
nut-2.2.2-5.fc10 has been pushed to the Fedora 10 testing repository.  If problems still persist, please make note of it in this bug report.
 If you want to test the update, you can install it with 
 su -c 'yum --enablerepo=updates-testing update nut'.  You can provide feedback for this update here: http://admin.fedoraproject.org/updates/F10/FEDORA-2009-5921

Comment 18 Fedora Update System 2009-06-24 19:24:49 UTC
nut-2.4.1-6.fc11 has been pushed to the Fedora 11 stable repository.  If problems still persist, please make note of it in this bug report.

Comment 19 Fedora Update System 2009-06-24 19:35:36 UTC
nut-2.2.2-5.fc10 has been pushed to the Fedora 10 stable repository.  If problems still persist, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.