Bug 767674 - USB device losing connection, showing IRQ handler type mismatch
Summary: USB device losing connection, showing IRQ handler type mismatch
Keywords:
Status: CLOSED NOTABUG
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: 17
Hardware: x86_64
OS: Linux
unspecified
medium
Target Milestone: ---
Assignee: Kernel Maintainer List
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2011-12-14 16:23 UTC by Brian Rademacher
Modified: 2018-11-27 19:25 UTC (History)
5 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2012-08-16 17:58:35 UTC
Type: ---


Attachments (Terms of Use)
dmesg output (122.27 KB, text/plain)
2011-12-14 16:23 UTC, Brian Rademacher
no flags Details
lspci -vv (55.49 KB, application/octet-stream)
2012-05-07 19:23 UTC, Brian Rademacher
no flags Details
lspci -vvn (53.03 KB, application/octet-stream)
2012-05-07 19:23 UTC, Brian Rademacher
no flags Details
lsusb -vv (20.00 KB, application/octet-stream)
2012-05-07 19:23 UTC, Brian Rademacher
no flags Details

Description Brian Rademacher 2011-12-14 16:23:07 UTC
Created attachment 546786 [details]
dmesg output

I have a Cyberpower UPS plugged into a USB port on my Dell Poweredge 2900, which is randomly causing this:

[113644.044051] usb 3-2: reset low speed USB device number 2 using uhci_hcd
[113658.018813] IRQ handler type mismatch for IRQ 12
[113658.019004] current handler: i8042
[113658.019004] Pid: 2123, comm: java Not tainted 3.1.5-1.fc16.x86_64 #1
[113658.019004] Call Trace:
[113658.019004]  [<ffffffff810dc054>] __setup_irq+0x214/0x500
[113658.019004]  [<ffffffff8115e52c>] ? kmem_cache_alloc_trace+0x10c/0x140
[113658.019004]  [<ffffffff810dc3d6>] ? request_threaded_irq+0x96/0x170
[113658.019004]  [<ffffffff8136b360>] ? serial8250_handle_port+0x390/0x390
[113658.019004]  [<ffffffff810dc41d>] request_threaded_irq+0xdd/0x170
[113658.019004]  [<ffffffff8136c051>] serial8250_startup+0x871/0x8c0
[113658.019004]  [<ffffffff8136532c>] uart_startup+0x6c/0x1f0
[113658.019004]  [<ffffffff813656f4>] uart_open+0x124/0x1e0
[113658.019004]  [<ffffffff8134a045>] tty_open+0x235/0x5b0
[113658.019004]  [<ffffffff812b8b41>] ? list_del+0x11/0x40
[113658.019004]  [<ffffffff81176c12>] chrdev_open+0xd2/0x220
[113658.019004]  [<ffffffff81170694>] __dentry_open+0x1e4/0x380
[113658.019004]  [<ffffffff81176b40>] ? cdev_put+0x30/0x30
[113658.019004]  [<ffffffff8117dfa8>] ? inode_permission+0x48/0x100
[113658.019004]  [<ffffffff81171b71>] nameidata_to_filp+0x71/0x80
[113658.019004]  [<ffffffff81181844>] do_last+0x4a4/0x960
[113658.019004]  [<ffffffff81181e12>] path_openat+0xd2/0x3c0
[113658.019004]  [<ffffffff8102f9e8>] ? native_smp_send_reschedule+0x48/0x60
[113658.019004]  [<ffffffff81182222>] do_filp_open+0x42/0xa0
[113658.019004]  [<ffffffff8118de5f>] ? alloc_fd+0x4f/0x150
[113658.019004]  [<ffffffff81171c77>] do_sys_open+0xf7/0x1d0
[113658.019004]  [<ffffffff8101bfa8>] ? sys_clone+0x28/0x30
[113658.019004]  [<ffffffff81171d70>] sys_open+0x20/0x30
[113658.019004]  [<ffffffff815d7802>] system_call_fastpath+0x16/0x1b

The UPS is running a java based monitoring service.  No other USB devices are plugged in.  Kernel is 3.1.5-1.fc16.x86_64.

dmesg output is attached.  Please let me know if I can provide any additional information.

Comment 1 Brian Rademacher 2011-12-14 16:24:34 UTC
Additional info - I have distributed IRQs enabled in the BIOS (ie - "IRQ swizzling" as Dell calls it).

Comment 2 Josh Boyer 2011-12-15 20:07:01 UTC
Did this work with previous kernels at all?

Can you provide the output of lsmod once this error condition starts happening?  I'm somewhat confused which driver/device is being opened by the java application.

Comment 3 Brian Rademacher 2011-12-15 23:00:11 UTC
Unfortunately both the server and UPS are new to me with a clean install of Fedora 16, so I don't have a lot of past experience with any kernels.  Some googling of the problem revealed this post, also with a Poweredge server:

http://www.centos.org/modules/newbb/viewtopic.php?topic_id=19188
(his conclusion was that it was eventually fixed in the kernel, so not terribly helpful...)


Here is lsmod:

Module                  Size  Used by
nf_conntrack_ftp       11244  0
xt_state                1370  33
ipt_MASQUERADE          2344  1
iptable_nat             5087  1
nf_nat                 20538  2 ipt_MASQUERADE,iptable_nat
nf_conntrack_ipv4       9030  36 iptable_nat,nf_nat
nf_conntrack           76503  6 nf_conntrack_ftp,xt_state,ipt_MASQUERADE,iptable_nat,nf_nat,nf_conntrack_ipv4
nf_defrag_ipv4          1561  1 nf_conntrack_ipv4
ip6_tables             19304  0
bridge                 83678  0
stp                     2007  1 bridge
llc                     5106  2 bridge,stp
tun                    16048  0
bonding               117745  0
i5000_edac              8566  0
raid0                   8221  1
edac_core              45283  3 i5000_edac
igb                   143837  0
bnx2                   75492  0
dcdbas                  8084  0
ses                     6397  0
ioatdma                51170  15
iTCO_wdt               12452  0
i5k_amb                 4838  0
shpchp                 28194  0
iTCO_vendor_support     2699  1 iTCO_wdt
dca                     6378  2 igb,ioatdma
enclosure               7616  1 ses
serio_raw               4558  0
joydev                 10372  0
megaraid_sas           75251  3
radeon                995772  1
ttm                    61533  1 radeon
drm_kms_helper         30277  1 radeon
drm                   213647  3 radeon,ttm,drm_kms_helper
i2c_algo_bit            5572  1 radeon
i2c_core               28203  4 radeon,drm_kms_helper,drm,i2c_algo_bit

Comment 4 Brian Rademacher 2012-03-21 01:05:40 UTC
This is still happening under the latest F16 kernel, just to refresh this bug:


[80331.446062] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[80345.165789] IRQ handler type mismatch for IRQ 12
[80345.166006] current handler: i8042
[80345.166006] Pid: 2094, comm: java Not tainted 3.2.10-3.fc16.x86_64 #1
[80345.166006] Call Trace:
[80345.166006]  [<ffffffff810e0717>] __setup_irq+0x457/0x540
[80345.166006]  [<ffffffff8116666b>] ? kmem_cache_alloc_trace+0x10b/0x140
[80345.166006]  [<ffffffff8137a270>] ? serial8250_release_port+0x40/0x40
[80345.166006]  [<ffffffff810e08f4>] request_threaded_irq+0xf4/0x1c0
[80345.166006]  [<ffffffff8137cfe9>] serial8250_startup+0x829/0x890
[80345.166006]  [<ffffffff813766fc>] uart_startup+0x6c/0x1f0
[80345.166006]  [<ffffffff81376ab5>] uart_open+0x115/0x1c0
[80345.166006]  [<ffffffff8135b2f5>] tty_open+0x235/0x5b0
[80345.166006]  [<ffffffff811761b5>] ? mem_cgroup_bad_page_check+0x25/0x30
[80345.166006]  [<ffffffff8117f722>] chrdev_open+0xd2/0x220
[80345.166006]  [<ffffffff81178fb0>] __dentry_open+0x290/0x360
[80345.166006]  [<ffffffff8117f650>] ? cdev_put+0x30/0x30
[80345.166006]  [<ffffffff811881ab>] ? do_lookup+0x4b/0x3a0
[80345.166006]  [<ffffffff8117a3c1>] nameidata_to_filp+0x71/0x80
[80345.166006]  [<ffffffff8118a09c>] do_last+0x26c/0x8f0
[80345.166006]  [<ffffffff8118a832>] path_openat+0xd2/0x3c0
[80345.166006]  [<ffffffff810318a8>] ? native_smp_send_reschedule+0x48/0x60
[80345.166006]  [<ffffffff8118ac42>] do_filp_open+0x42/0xa0
[80345.166006]  [<ffffffff8119698f>] ? alloc_fd+0x4f/0x150
[80345.166006]  [<ffffffff8117a4c7>] do_sys_open+0xf7/0x1d0
[80345.166006]  [<ffffffff8101d408>] ? sys_clone+0x28/0x30
[80345.166006]  [<ffffffff8117a5c0>] sys_open+0x20/0x30
[80345.166006]  [<ffffffff815ecac2>] system_call_fastpath+0x16/0x1b

Comment 5 Dave Jones 2012-03-22 16:49:14 UTC
[mass update]
kernel-3.3.0-4.fc16 has been pushed to the Fedora 16 stable repository.
Please retest with this update.

Comment 6 Dave Jones 2012-03-22 16:53:38 UTC
[mass update]
kernel-3.3.0-4.fc16 has been pushed to the Fedora 16 stable repository.
Please retest with this update.

Comment 7 Dave Jones 2012-03-22 17:04:18 UTC
[mass update]
kernel-3.3.0-4.fc16 has been pushed to the Fedora 16 stable repository.
Please retest with this update.

Comment 8 Brian Rademacher 2012-03-22 17:40:40 UTC
No luck with 3.3.0-4...


[   21.419859] IRQ handler type mismatch for IRQ 12
[   21.419943] current handler: i8042
[   21.420004] Pid: 2059, comm: java Not tainted 3.3.0-4.fc16.x86_64 #1
[   21.420007] Call Trace:
[   21.420018]  [<ffffffff810e58ce>] __setup_irq+0x45e/0x550
[   21.420025]  [<ffffffff8116d02b>] ? kmem_cache_alloc_trace+0x11b/0x150
[   21.420029]  [<ffffffff810e5a6b>] ? request_threaded_irq+0xab/0x1c0
[   21.420035]  [<ffffffff81385b90>] ? serial8250_release_port+0x40/0x40
[   21.420038]  [<ffffffff810e5ab4>] request_threaded_irq+0xf4/0x1c0
[   21.420042]  [<ffffffff8138894a>] serial8250_startup+0x82a/0x890
[   21.420045]  [<ffffffff81382921>] uart_startup.part.3+0x61/0x200
[   21.420049]  [<ffffffff81382c0d>] uart_open+0x14d/0x1b0
[   21.420053]  [<ffffffff81366b0e>] tty_open+0x2ee/0x5f0
[   21.420057]  [<ffffffff813a466a>] ? kobj_lookup+0x12a/0x1e0
[   21.420062]  [<ffffffff81185420>] ? mount_fs+0x1b0/0x1b0
[   21.420065]  [<ffffffff81185e62>] chrdev_open+0xd2/0x220
[   21.420070]  [<ffffffff8117f580>] __dentry_open+0x290/0x360
[   21.420073]  [<ffffffff81185d90>] ? cdev_put+0x30/0x30
[   21.420077]  [<ffffffff8118df4b>] ? do_lookup+0x4b/0x3a0
[   21.420080]  [<ffffffff81180991>] nameidata_to_filp+0x71/0x80
[   21.420084]  [<ffffffff811908bc>] do_last+0x26c/0x8e0
[   21.420087]  [<ffffffff81191043>] path_openat+0xd3/0x3c0
[   21.420092]  [<ffffffff81031f28>] ? native_smp_send_reschedule+0x48/0x60
[   21.420095]  [<ffffffff81191452>] do_filp_open+0x42/0xa0
[   21.420099]  [<ffffffff8119d4af>] ? alloc_fd+0x4f/0x150
[   21.420102]  [<ffffffff81180a98>] do_sys_open+0xf8/0x1d0
[   21.420106]  [<ffffffff8101d6a8>] ? sys_clone+0x28/0x30
[   21.420109]  [<ffffffff81180b91>] sys_open+0x21/0x30
[   21.420113]  [<ffffffff815fc029>] system_call_fastpath+0x16/0x1b

Comment 9 Brian Rademacher 2012-04-03 18:56:17 UTC
As the poster stated here:  http://www.centos.org/modules/newbb/viewtopic.php?topic_id=19188 , enabling the serial port in the BIOS got rid of the IRQ error (which was apparently fixed/surpressed in later cent kernels for him).  I am, however, still left with the USB disconnects as of 3.3.0-8.fc16.x86_64:


[101378.800034] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[101382.569052] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[102691.765057] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[102695.341051] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[102715.564054] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[106668.067056] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[106671.891046] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[108700.739054] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[108704.315041] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[125595.636053] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[125599.460035] usb 4-2: reset low-speed USB device number 2 using uhci_hcd

Comment 10 Brian Rademacher 2012-05-07 19:22:07 UTC
Still happening with 3.3.4-3.fc16.x86_64 ...


[ 7990.107050] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[ 7993.962060] usb 4-2: reset low-speed USB device number 2 using uhci_hcd

Attached:

lspci -vv
lspci -vvn
lsusb -vv

Let me know if there is anything else I can provide for this bug...

Comment 11 Brian Rademacher 2012-05-07 19:23:11 UTC
Created attachment 582765 [details]
lspci -vv

Comment 12 Brian Rademacher 2012-05-07 19:23:35 UTC
Created attachment 582766 [details]
lspci -vvn

Comment 13 Brian Rademacher 2012-05-07 19:23:55 UTC
Created attachment 582767 [details]
lsusb -vv

Comment 14 Brian Rademacher 2012-07-16 19:31:58 UTC
This continues in F17 - 3.4.4-5.fc17.x86_64

Should I refile this under F17, or can it be transferred?

[464597.932055] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[464601.500056] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[473818.651058] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[473822.475046] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[474768.521057] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[474772.097049] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[475331.205053] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[475334.781046] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[490219.163052] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[490222.739038] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[492213.082039] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[492216.906043] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[494513.004057] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[494516.581044] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[502908.900034] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[502912.724049] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[504266.683055] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[504270.259050] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[516361.441056] usb 4-2: reset low-speed USB device number 2 using uhci_hcd
[516365.010053] usb 4-2: reset low-speed USB device number 2 using uhci_hcd

Comment 15 Brian Rademacher 2012-08-16 17:58:35 UTC
I think this is worth closing - I finally got this back from Cyberpower:

The USB timeout issue is being caused by a bug in the firmware for the
PR1500LCDRTXL2U. We're working on the solution and are hoping to apply
the fix to either the 2.4 release of Business Edition or the 2.4.1
release.

So much for all this effort :)


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