Kernel bug message and missing data on libusb_interrupt_transfer

From: Oncaphillis
Date: Mon Apr 04 2011 - 08:20:46 EST


Hi,

We are experiencing sporadic kernel bug messages and total
kernel freezes on usb communication via libusb-1.0.6.

We are currently under kernel 2.6.30.10 but have seen
it also under older and newer kernel (I think the newest was
a 2.6.36.x).

The communication should work as follows:

- Send a 2 byte sequence to endpoint #4
selecting the register to which the command should be send

- The device should answer with the same two byte sequence
on Endpoint #8

- Send a 2 byte command sequence to endpoint #4

- The device should acknowledge the command by returning
the same two bytes on endpoint #8

- The device may also initiate inbound data transfer on endpoint #8
to inform about status changes.

We send the register selection and command data via

libusb_bulk_transfer() with a time out of 10000 ms

and read the reply via libusb_interrupt_transfer
with a time out of 100 ms as specified for our device
We also periodically read on endpoint #8 to get the
status changes.

Sometimes we run into the following situation.

- We send the 2 byte register selection sequence via libusb_bulk_transfer
- We try to read the response via libusb_interrupt_transfer but run into
a time out.
- If we look at the USB communication via USB analyzer we actually see the inbound
transfer of two bytes and the acknowledge by the kernel, but this data never
ends up as a valid result of libusb_interrupt_transfer.
- Since we got a time out we retry the read up to 30 times. Within this polling
we see the following kernel bug message in dmesg. Sometimes the kernel freezes completely

<snip>
------------[ cut here ]------------
kernel BUG at mm/slub.c:2808!
invalid opcode: 0000 [#1] SMP
last sysfs file: /sys/devices/pci0000:00/0000:00:1d.7/usb2/2-3/bConfigurationValue
CPU 3
Modules linked in:
Pid: 4314, comm: rrdupdate Not tainted 2.6.30.10 #2 To Be Filled By O.E.M.
RIP: 0010:[<ffffffff8028d2f8>] [<ffffffff8028d2f8>] kfree+0x7c/0xdb
RSP: 0000:ffff880077de1d38 EFLAGS: 00010246
RAX: 4000000000000000 RBX: ffff88007a07a772 RCX: ffff88007acea7e0
RDX: ffffe20000000000 RSI: ffffe20001ab1ab0 RDI: ffff88007a07a772
RBP: ffff880077de1d58 R08: 0000000000000000 R09: 0000000000000008
R10: 00000000f7f5e000 R11: 00000000f7f5d5b8 R12: ffff88007c081c80
R13: ffffffff802c9cd8 R14: 00000000f7f5e000 R15: ffff880077de1f58
FS: 0000000000000000(0000) GS:ffff88000105b000(0000) knlGS:0000000000000000
CS: 0010 DS: 002b ES: 002b CR0: 000000008005003b
CR2: 00000000f7f5d5b8 CR3: 0000000079940000 CR4: 00000000000406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process rrdupdate (pid: 4314, threadinfo ffff880077de0000, task ffff8800790d8b40)
Stack:
00000000f7f5e000 0000000000000000 ffff88007c081c80 ffff880077d77800
ffff880077de1e48 ffffffff802c9cd8 0000000000000080 ffff880077d77800
0000000000000001 00000000f7f3d000 ffff880077df2000 ffff880077df2000
Call Trace:
[<ffffffff802c9cd8>] load_elf_binary+0xfda/0x1862
[<ffffffff802c0b6f>] ? compat_copy_strings+0x1b8/0x1ca
[<ffffffff802958fe>] search_binary_handler+0xb0/0x23f
[<ffffffff802c0dc7>] compat_do_execve+0x246/0x36f
[<ffffffff8022593b>] sys32_execve+0x3e/0x5c
[<ffffffff80225765>] ia32_ptregs_common+0x25/0x4c
Code: ba 00 00 00 00 00 e2 ff ff 48 c1 e8 0c 48 6b f0 38 48 01 d6 66 83 3e 00 79 04 48 8b 76 10 48 8b 06 84 c0 78 14 66 a9 00 c0 75 04 <0f> 0b eb fe 48 89 f7 e8 35 13 fe ff eb 48 48 8b 4d 08 48 8b 7e
RIP [<ffffffff8028d2f8>] kfree+0x7c/0xdb
RSP <ffff880077de1d38>
---[ end trace ba800619f794f281 ]---

</snip>


I've placed a pdf on

http://www.oncaphillis.net/usb.pdf

which represents the annotated USB log


Thank you

O.

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/