(Arjen - I apologize if you get two copies, I sent the first one to the old
de-korte.org address)
Arjen, all,
I've run into a usbhid-ups problem with nut on Arch Linux with the new 2.6.35
kernels. (latest is 2.6.35.4-1) For some reason when you get to the udev events
on boot and it tries to load the usbhid-ups driver, it hangs until the 120 sec
timeout occurs and then boot continues but with no usbhid-ups configured. Here
is the log info:
Aug 30 20:31:03 archangel upsd[2295]: listening on 192.168.6.14 port 3493
Aug 30 20:31:03 archangel upsd[2295]: listening on 127.0.0.1 port 3493
Aug 30 20:31:03 archangel upsd[2295]: Can't connect to UPS [archangel_ups]
(usbhid-ups-archangel_ups): No such file or directory
Aug 30 20:31:03 archangel upsd[2296]: Startup successful
Aug 30 20:31:03 archangel upsmon[2298]: Startup successful
Aug 30 20:31:03 archangel upsmon[2300]: Login on UPS [archangel_...@localhost]
failed - got [ERR ACCESS-DENIED]
Aug 30 20:31:03 archangel upsmon[2300]: Login on UPS
[[email protected]] failed - got [ERR ACCESS-DENIED]
Aug 30 20:31:06 archangel kernel: INFO: task modprobe:1579 blocked for more than
120 seconds.
Aug 30 20:31:06 archangel kernel: "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Aug 30 20:31:06 archangel kernel: modprobe D 0000000000000000 0 1579
1576 0x00000000
Aug 30 20:31:06 archangel kernel: ffff88022616da28 0000000000000082
ffffffff8167eb00 ffff880200000000
Aug 30 20:31:06 archangel kernel: 0000000000014f40 0000000000014f40
ffff88022616dfd8 ffff88022616dfd8
Aug 30 20:31:06 archangel kernel: ffff88022616dfd8 ffff8802269c1bc0
ffff88022616dfd8 0000000000014f40
Aug 30 20:31:06 archangel kernel: Call Trace:
Aug 30 20:31:06 archangel kernel: [<ffffffffa0202ba5>] usb_kill_urb+0x85/0xc0
[usbcore]
Aug 30 20:31:06 archangel kernel: [<ffffffff810718d0>] ?
autoremove_wake_function+0x0/0x40
Aug 30 20:31:06 archangel kernel: [<ffffffffa02e0831>]
usbhid_init_reports+0xb1/0x120 [usbhid]
Aug 30 20:31:06 archangel kernel: [<ffffffffa02e0d53>] usbhid_start+0x4b3/0x5a0
[usbhid]
Aug 30 20:31:06 archangel kernel: [<ffffffffa02ca6d8>]
hid_device_probe+0x98/0xe0 [hid]
Aug 30 20:31:06 archangel kernel: [<ffffffff812877ea>] ?
driver_sysfs_add+0x5a/0x90
Aug 30 20:31:06 archangel kernel: [<ffffffff81287ac6>]
driver_probe_device+0x96/0x1c0
Aug 30 20:31:06 archangel kernel: [<ffffffff81287c90>] ?
__device_attach+0x0/0x60
Aug 30 20:31:06 archangel kernel: [<ffffffff81287cdb>] __device_attach+0x4b/0x60
Aug 30 20:31:06 archangel kernel: [<ffffffff812866a4>]
bus_for_each_drv+0x64/0x90
Aug 30 20:31:06 archangel kernel: [<ffffffff8128795f>] device_attach+0x8f/0xb0
Aug 30 20:31:06 archangel kernel: [<ffffffff81287115>]
bus_probe_device+0x25/0x40
Aug 30 20:31:06 archangel kernel: [<ffffffff81284e5f>] device_add+0x4ff/0x5e0
Aug 30 20:31:06 archangel kernel: [<ffffffffa02ca0a7>] hid_add_device+0x87/0x1b0
[hid]
Aug 30 20:31:06 archangel kernel: [<ffffffffa02de4b9>] usbhid_probe+0x329/0x500
[usbhid]
Aug 30 20:31:06 archangel kernel: [<ffffffffa0207a2b>]
usb_probe_interface+0xfb/0x1f0 [usbcore]
Aug 30 20:31:06 archangel kernel: [<ffffffff81287ac6>]
driver_probe_device+0x96/0x1c0
Aug 30 20:31:06 archangel kernel: [<ffffffff81287c8b>] __driver_attach+0x9b/0xa0
Aug 30 20:31:06 archangel kernel: [<ffffffff81287bf0>] ?
__driver_attach+0x0/0xa0
Aug 30 20:31:06 archangel kernel: [<ffffffff812869fe>]
bus_for_each_dev+0x5e/0x90
Aug 30 20:31:06 archangel kernel: [<ffffffff81287789>] driver_attach+0x19/0x20
Aug 30 20:31:06 archangel kernel: [<ffffffff81287297>] bus_add_driver+0xc7/0x2e0
Aug 30 20:31:06 archangel kernel: [<ffffffff81287f01>]
driver_register+0x71/0x140
Aug 30 20:31:06 archangel kernel: [<ffffffffa02066f8>]
usb_register_driver+0xb8/0x170 [usbcore]
Aug 30 20:31:06 archangel kernel: [<ffffffffa0299000>] ? hid_init+0x0/0xd1
[usbhid]
Aug 30 20:31:06 archangel kernel: [<ffffffffa0299093>] hid_init+0x93/0xd1
[usbhid]
Aug 30 20:31:06 archangel kernel: [<ffffffff81002149>]
do_one_initcall+0x39/0x1a0
Aug 30 20:31:06 archangel kernel: [<ffffffff8108cefb>]
sys_init_module+0xbb/0x200
Aug 30 20:31:06 archangel kernel: [<ffffffff81009e82>]
system_call_fastpath+0x16/0x1b
Aug 30 20:31:08 archangel upsmon[2300]: Poll UPS [archangel_...@localhost]
failed - Driver not connected
Aug 30 20:31:08 archangel upsmon[2300]: Communications with UPS
archangel_...@localhost lost
Aug 30 20:31:08 archangel wall[2302]: wall: user nut broadcasted 1 lines (54
chars)
Aug 30 20:31:13 archangel upsmon[2300]: Poll UPS [archangel_...@localhost]
failed - Driver not connected
Aug 30 20:31:13 archangel upsmon[2300]: UPS archangel_...@localhost is
unavailable
Aug 30 20:31:13 archangel wall[2305]: wall: user nut broadcasted 1 lines (44
chars)
Aug 30 20:31:18 archangel upsmon[2300]: Poll UPS [archangel_...@localhost]
failed - Driver not connected
Aug 30 20:31:23 archangel upsmon[2300]: Poll UPS [archangel_...@localhost]
failed - Driver not connected
<snip ~15 more Driver not connected>
Aug 30 20:33:06 archangel kernel: INFO: task modprobe:1579 blocked for more than
120 seconds.
Aug 30 20:33:06 archangel kernel: "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Aug 30 20:33:06 archangel kernel: modprobe D 0000000000000000 0 1579
1576 0x00000000
Aug 30 20:33:06 archangel kernel: ffff88022616da28 0000000000000082
ffffffff8167eb00 ffff880200000000
Aug 30 20:33:06 archangel kernel: 0000000000014f40 0000000000014f40
ffff88022616dfd8 ffff88022616dfd8
Aug 30 20:33:06 archangel kernel: ffff88022616dfd8 ffff8802269c1bc0
ffff88022616dfd8 0000000000014f40
Aug 30 20:33:06 archangel kernel: Call Trace:
Aug 30 20:33:06 archangel kernel: [<ffffffffa0202ba5>] usb_kill_urb+0x85/0xc0
[usbcore]
Aug 30 20:33:06 archangel kernel: [<ffffffff810718d0>] ?
autoremove_wake_function+0x0/0x40
Aug 30 20:33:06 archangel kernel: [<ffffffffa02e0831>]
usbhid_init_reports+0xb1/0x120 [usbhid]
Aug 30 20:33:06 archangel kernel: [<ffffffffa02e0d53>] usbhid_start+0x4b3/0x5a0
[usbhid]
Aug 30 20:33:06 archangel kernel: [<ffffffffa02ca6d8>]
hid_device_probe+0x98/0xe0 [hid]
Aug 30 20:33:06 archangel kernel: [<ffffffff812877ea>] ?
driver_sysfs_add+0x5a/0x90
Aug 30 20:33:06 archangel kernel: [<ffffffff81287ac6>]
driver_probe_device+0x96/0x1c0
Aug 30 20:33:06 archangel kernel: [<ffffffff81287c90>] ?
__device_attach+0x0/0x60
Aug 30 20:33:06 archangel kernel: [<ffffffff81287cdb>] __device_attach+0x4b/0x60
Aug 30 20:33:06 archangel kernel: [<ffffffff812866a4>]
bus_for_each_drv+0x64/0x90
Aug 30 20:33:06 archangel kernel: [<ffffffff8128795f>] device_attach+0x8f/0xb0
Aug 30 20:33:06 archangel kernel: [<ffffffff81287115>]
bus_probe_device+0x25/0x40
Aug 30 20:33:06 archangel kernel: [<ffffffff81284e5f>] device_add+0x4ff/0x5e0
Aug 30 20:33:06 archangel kernel: [<ffffffffa02ca0a7>] hid_add_device+0x87/0x1b0
[hid]
Aug 30 20:33:06 archangel kernel: [<ffffffffa02de4b9>] usbhid_probe+0x329/0x500
[usbhid]
Aug 30 20:33:06 archangel kernel: [<ffffffffa0207a2b>]
usb_probe_interface+0xfb/0x1f0 [usbcore]
Aug 30 20:33:06 archangel kernel: [<ffffffff81287ac6>]
driver_probe_device+0x96/0x1c0
Aug 30 20:33:06 archangel kernel: [<ffffffff81287c8b>] __driver_attach+0x9b/0xa0
Aug 30 20:33:06 archangel kernel: [<ffffffff81287bf0>] ?
__driver_attach+0x0/0xa0
Aug 30 20:33:06 archangel kernel: [<ffffffff812869fe>]
bus_for_each_dev+0x5e/0x90
Aug 30 20:33:06 archangel kernel: [<ffffffff81287789>] driver_attach+0x19/0x20
Aug 30 20:33:06 archangel kernel: [<ffffffff81287297>] bus_add_driver+0xc7/0x2e0
Aug 30 20:33:06 archangel kernel: [<ffffffff81287f01>]
driver_register+0x71/0x140
Aug 30 20:33:06 archangel kernel: [<ffffffffa02066f8>]
usb_register_driver+0xb8/0x170 [usbcore]
Aug 30 20:33:06 archangel kernel: [<ffffffffa0299000>] ? hid_init+0x0/0xd1
[usbhid]
Aug 30 20:33:06 archangel kernel: [<ffffffffa0299093>] hid_init+0x93/0xd1
[usbhid]
Aug 30 20:33:06 archangel kernel: [<ffffffff81002149>]
do_one_initcall+0x39/0x1a0
Aug 30 20:33:06 archangel kernel: [<ffffffff8108cefb>]
sys_init_module+0xbb/0x200
Aug 30 20:33:06 archangel kernel: [<ffffffff81009e82>]
system_call_fastpath+0x16/0x1b
Aug 30 20:33:06 archangel kernel: INFO: task usbhid-ups:2006 blocked for more
than 120 seconds.
Aug 30 20:33:06 archangel kernel: "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Aug 30 20:33:06 archangel kernel: usbhid-ups D 0000000000000000 0 2006
1 0x00000000
Aug 30 20:33:06 archangel kernel: ffff880227789b98 0000000000000082
ffff880227789ae8 ffffffff00000000
Aug 30 20:33:06 archangel kernel: 0000000000014f40 0000000000014f40
ffff880227789fd8 ffff880227789fd8
Aug 30 20:33:06 archangel kernel: ffff880227789fd8 ffff880226c9b780
ffff880227789fd8 0000000000014f40
Aug 30 20:33:06 archangel kernel: Call Trace:
Aug 30 20:33:06 archangel kernel: [<ffffffff81371879>]
__mutex_lock_slowpath+0x139/0x310
Aug 30 20:33:06 archangel kernel: [<ffffffff81371a61>] mutex_lock+0x11/0x30
Aug 30 20:33:06 archangel kernel: [<ffffffffa020c195>] usbdev_open+0x145/0x330
[usbcore]
Aug 30 20:33:06 archangel kernel: [<ffffffff81127807>] chrdev_open+0x127/0x270
Aug 30 20:33:06 archangel kernel: [<ffffffff811276e0>] ? chrdev_open+0x0/0x270
Aug 30 20:33:06 archangel kernel: [<ffffffff81121d2b>] __dentry_open+0x11b/0x3c0
Aug 30 20:33:06 archangel kernel: [<ffffffff811a263a>] ?
security_inode_permission+0x1a/0x20
Aug 30 20:33:06 archangel kernel: [<ffffffff81122f64>]
nameidata_to_filp+0x54/0x70
Aug 30 20:33:06 archangel kernel: [<ffffffff811311f0>] do_last+0x480/0x740
Aug 30 20:33:06 archangel kernel: [<ffffffff8113169d>] do_filp_open+0x1ed/0x680
Aug 30 20:33:06 archangel kernel: [<ffffffff8113cc74>] ? alloc_fd+0xf4/0x150
Aug 30 20:33:06 archangel kernel: [<ffffffff81122fe4>] do_sys_open+0x64/0x130
Aug 30 20:33:06 archangel kernel: [<ffffffff811230cb>] sys_open+0x1b/0x20
Aug 30 20:33:06 archangel kernel: [<ffffffff81009e82>]
system_call_fastpath+0x16/0x1b
Aug 30 20:33:08 archangel upsmon[2300]: Poll UPS [archangel_...@localhost]
failed - Driver not connected
Aug 30 20:33:13 archangel upsmon[2300]: Poll UPS [archangel_...@localhost]
failed - Driver not connected
Looks like some type of udev issue or kernel issue, but I thought I would
check here to see if you guys have any more info on the problem. Anybody seen
this behavior before?
Seems to effect my MSI nvidia 8200 chipset box more than others. This box
has never had a problem with this before the 2.6.35 kernels so something has
changed that impacts the driver, but I'm not sure what it is. Can you think of
any other tests I could run to help narrow it down?
Any help would be appreciated - thanks.
--
David C. Rankin, J.D.,P.E.
Rankin Law Firm, PLLC
510 Ochiltree Street
Nacogdoches, Texas 75961
Telephone: (936) 715-9333
Facsimile: (936) 715-9339
www.rankinlawfirm.com
_______________________________________________
Nut-upsdev mailing list
[email protected]
http://lists.alioth.debian.org/mailman/listinfo/nut-upsdev
