[Nut-upsuser] Problem making usbhid-ups working on Centos 5.7

Fri Apr 25 09:08:53 UTC 2014

Le Thu, 24 Apr 2014 09:25:36 -0400
Charles Lepple <clepple at gmail.com> écrivait:

> Thanks for a thorough problem report.
> 
> What version of udev and Linux kernel does your system use? (Alternatively,
> is there a URL that lists package versions for CentOS, similar to
> http://packages.debian.org/nut?)

# yum list | grep -i ^udev
udev.i386                          095-14.27.el5_7.1          installed 

# uname -r
2.6.32.43-0.4.1.xs1.6.10.734.170748xen

I've cleaned the /etc/udev/rules.d/52-nut-usbups.rules file :

ACTION!="add|change", GOTO="nut-usbups_rules_end"
SUBSYSTEM=="usb_device", GOTO="nut-usbups_rules_real"
SUBSYSTEM=="usb", GOTO="nut-usbups_rules_real"
SUBSYSTEM!="usb", GOTO="nut-usbups_rules_end"

LABEL="nut-usbups_rules_real"

# Dell
#  various models  - usbhid-ups
ATTR{idVendor}=="047c", ATTR{idProduct}=="ffff", MODE="664", GROUP="ups"

LABEL="nut-usbups_rules_end"

> Could you please run udevd in debug mode while plugging in the UPS? This
> message shows what happens when udev properly detects the UPS and changes
> permissions on the /dev nodes:

# udevcontrol log_priority=debug

I plugged the UPS. 

# lsusb -d 047c:ffff
Bus 001 Device 010: ID 047c:ffff Dell Computer Corp. 

Here is the result in /var/log/messages (a little bit long, sorry) :

Apr 25 10:43:43 gs08-2 udevd[1691]: udev_event_run: seq 3192 forked, pid [28985], 'add' 'usb', 0 seconds old
Apr 25 10:43:43 gs08-2 udevd-event[28985]: wait_for_sysfs: file '/sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.4/bus' appeared after 0 loops
Apr 25 10:43:43 gs08-2 udevd-event[28985]: udev_rules_get_name: no node name set, will use kernel name '1-1.4'
Apr 25 10:43:43 gs08-2 udevd-event[28985]: udev_db_get_device: no db file to read /dev/.udev/db/devices at pci0000:00 at 0000:00:1a.0 at usb1@1-1 at 1-1.4: No such file or directory
Apr 25 10:43:43 gs08-2 udevd-event[28985]: udev_node_add: creating device node '/dev/1-1.4', major = '189', minor = '9', mode = '0600', uid = '0', gid = '0'
Apr 25 10:43:43 gs08-2 udevd-event[28985]: pass_env_to_socket: passed -1 bytes to socket '/org/kernel/udev/monitor', 
Apr 25 10:43:43 gs08-2 udevd-event[28985]: run_program: '/lib/udev/udev_run_hotplugd'
Apr 25 10:43:43 gs08-2 udevd-event[28985]: run_program: '/lib/udev/udev_run_hotplugd' returned with status 0
Apr 25 10:43:43 gs08-2 udevd-event[28985]: run_program: '/lib/udev/udev_run_devd'
Apr 25 10:43:43 gs08-2 udevd-event[28985]: run_program: '/lib/udev/udev_run_devd' returned with status 0
Apr 25 10:43:43 gs08-2 udevd-event[28985]: pass_env_to_socket: passed -1 bytes to socket '/org/freedesktop/hal/udev_event', 
Apr 25 10:43:43 gs08-2 udevd-event[28985]: run_program: '/bin/sh -c '[ -x /opt/dell/srvadmin/sbin/dataeng.hotplug ] && /opt/dell/srvadmin/sbin/dataeng.hotplug usb''
Apr 25 10:43:43 gs08-2 udevd-event[28985]: run_program: '/bin/sh' returned with status 0
Apr 25 10:43:43 gs08-2 udevd-event[28985]: run_program: '/sbin/pam_console_apply /dev/1-1.4 '
Apr 25 10:43:43 gs08-2 udevd-event[28985]: run_program: '/sbin/pam_console_apply' returned with status 0
Apr 25 10:43:43 gs08-2 udevd-event[28985]: udev_event_run: seq 3192 finished
Apr 25 10:43:43 gs08-2 udevd[1691]: udev_done: seq 3192, pid [28985] exit with 0, 0 seconds old
Apr 25 10:43:43 gs08-2 udevd[1691]: udev_event_run: seq 3193 forked, pid [28996], 'add' 'usb', 0 seconds old
Apr 25 10:43:43 gs08-2 udevd-event[28996]: wait_for_sysfs: file '/sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.4/1-1.4:1.0/bus' appeared after 0 loops
Apr 25 10:43:43 gs08-2 udevd-event[28996]: run_program: 'modprobe  usb:v047CpFFFFd0100dc00dsc00dp00ic03isc00ip00'
Apr 25 10:43:43 gs08-2 udevd-event[28996]: run_program: '/lib/udev/modprobe' returned with status 0
Apr 25 10:43:43 gs08-2 udevd-event[28996]: pass_env_to_socket: passed -1 bytes to socket '/org/kernel/udev/monitor', 
Apr 25 10:43:43 gs08-2 udevd-event[28996]: run_program: '/lib/udev/udev_run_hotplugd'
Apr 25 10:43:43 gs08-2 udevd-event[28996]: run_program: '/lib/udev/udev_run_hotplugd' returned with status 0
Apr 25 10:43:43 gs08-2 udevd-event[28996]: run_program: '/lib/udev/udev_run_devd'
Apr 25 10:43:43 gs08-2 udevd-event[28996]: run_program: '/lib/udev/udev_run_devd' returned with status 0
Apr 25 10:43:43 gs08-2 udevd-event[28996]: pass_env_to_socket: passed -1 bytes to socket '/org/freedesktop/hal/udev_event', 
Apr 25 10:43:43 gs08-2 udevd-event[28996]: run_program: '/bin/sh -c '[ -x /opt/dell/srvadmin/sbin/dataeng.hotplug ] && /opt/dell/srvadmin/sbin/dataeng.hotplug usb''
Apr 25 10:43:44 gs08-2 udevd-event[28996]: run_program: '/bin/sh' returned with status 0
Apr 25 10:43:44 gs08-2 udevd-event[28996]: run_program: '/sbin/pam_console_apply  '
Apr 25 10:43:44 gs08-2 udevd-event[28996]: run_program: '/sbin/pam_console_apply' returned with status 0
Apr 25 10:43:44 gs08-2 udevd-event[28996]: udev_event_run: seq 3193 finished
Apr 25 10:43:44 gs08-2 udevd[1691]: udev_done: seq 3193, pid [28996] exit with 0, 1 seconds old
Apr 25 10:43:44 gs08-2 udevd[1691]: udev_event_run: seq 3194 forked, pid [29009], 'add' 'hid', 1 seconds old
Apr 25 10:43:44 gs08-2 udevd-event[29009]: wait_for_sysfs: file '/sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.4/1-1.4:1.0/0003:047C:FFFF.0009/bus' appeared after 0 loops
Apr 25 10:43:44 gs08-2 udevd-event[29009]: run_program: 'modprobe  hid:b0003v0000047Cp0000FFFF'
Apr 25 10:43:44 gs08-2 udevd-event[29009]: run_program: '/lib/udev/modprobe' (stderr) 'FATAL: Module hid:b0003v0000047Cp0000FFFF not found.'
Apr 25 10:43:44 gs08-2 udevd-event[29009]: run_program: '/lib/udev/modprobe' returned with status 1
Apr 25 10:43:44 gs08-2 udevd-event[29009]: pass_env_to_socket: passed -1 bytes to socket '/org/kernel/udev/monitor', 
Apr 25 10:43:44 gs08-2 udevd-event[29009]: run_program: '/lib/udev/udev_run_hotplugd'
Apr 25 10:43:44 gs08-2 udevd-event[29009]: run_program: '/lib/udev/udev_run_hotplugd' returned with status 0
Apr 25 10:43:44 gs08-2 udevd-event[29009]: run_program: '/lib/udev/udev_run_devd'
Apr 25 10:43:44 gs08-2 udevd-event[29009]: run_program: '/lib/udev/udev_run_devd' returned with status 0
Apr 25 10:43:44 gs08-2 udevd-event[29009]: pass_env_to_socket: passed -1 bytes to socket '/org/freedesktop/hal/udev_event', 
Apr 25 10:43:44 gs08-2 udevd-event[29009]: run_program: '/sbin/pam_console_apply  '
Apr 25 10:43:44 gs08-2 udevd-event[29009]: run_program: '/sbin/pam_console_apply' returned with status 0
Apr 25 10:43:44 gs08-2 udevd-event[29009]: udev_event_run: seq 3194 finished
Apr 25 10:43:44 gs08-2 udevd[1691]: udev_done: seq 3194, pid [29009] exit with 1, 1 seconds old
Apr 25 10:43:46 gs08-2 udevd[1691]: udev_event_run: seq 3195 forked, pid [29015], 'add' 'usb_device', 0 seconds old
Apr 25 10:43:46 gs08-2 udevd-event[29015]: run_program: '/bin/sh -c 'K=usbdev1.10; K=${K#usbdev}; printf bus/usb/%03i/%03i ${K%%.*} ${K#*.}''
Apr 25 10:43:46 gs08-2 udevd-event[29015]: run_program: '/bin/sh' (stdout) 'bus/usb/001/010'
Apr 25 10:43:46 gs08-2 udevd-event[29015]: run_program: '/bin/sh' returned with status 0
Apr 25 10:43:46 gs08-2 udevd-event[29015]: udev_rules_get_name: rule applied, 'usbdev1.10' becomes 'bus/usb/001/010'
Apr 25 10:43:46 gs08-2 udevd-event[29015]: udev_db_get_device: no db file to read /dev/.udev/db/class at usb_device@usbdev1.10: No such file or directory
Apr 25 10:43:46 gs08-2 udevd-event[29015]: udev_node_add: creating device node '/dev/bus/usb/001/010', major = '189', minor = '9', mode = '0644', uid = '0', gid = '0'
Apr 25 10:43:46 gs08-2 udevd-event[29015]: pass_env_to_socket: passed -1 bytes to socket '/org/kernel/udev/monitor', 
Apr 25 10:43:46 gs08-2 udevd-event[29015]: run_program: '/lib/udev/udev_run_hotplugd'
Apr 25 10:43:46 gs08-2 udevd-event[29015]: run_program: '/lib/udev/udev_run_hotplugd' returned with status 0
Apr 25 10:43:46 gs08-2 udevd-event[29015]: run_program: '/lib/udev/udev_run_devd'
Apr 25 10:43:46 gs08-2 udevd-event[29015]: run_program: '/lib/udev/udev_run_devd' returned with status 0
Apr 25 10:43:46 gs08-2 udevd-event[29015]: pass_env_to_socket: passed -1 bytes to socket '/org/freedesktop/hal/udev_event', 
Apr 25 10:43:46 gs08-2 udevd-event[29015]: run_program: '/sbin/pam_console_apply /dev/bus/usb/001/010 '
Apr 25 10:43:46 gs08-2 udevd-event[29015]: run_program: '/sbin/pam_console_apply' returned with status 0
Apr 25 10:43:46 gs08-2 udevd-event[29015]: udev_event_run: seq 3195 finished
Apr 25 10:43:46 gs08-2 udevd[1691]: udev_done: seq 3195, pid [29015] exit with 0, 0 seconds old

However, I've made a workaround. I put this line in my /etc/init.d/upsd script :

USB_PORT=`lsusb -d 047c:ffff | awk '{ print "/dev/bus/usb/"$2"/"$4 }' | sed -e "s/://"`
chmod 664 $USB_PORT
chgrp ups $USB_PORT

Not very clean method, but it works :-)

Regards

-- 
Frantz de Germain
Département Informatique UFR Sciences / DDN
Université d'Angers