Hello,
I'm trying to connect a USB audio device (DJ-Tech CTRL) to my laptop
using a Linux 5.4.5 kernel (with Debian patches, but not for xhci), but
that fails with the above error message. I've tried with a number of
kernels before during the last 9 months with the same result, but didn't
get round to actually collect the debug log and make a bug report yet.
The device worked on two different computers (one Windows 10, the other
an older 4.x Linux kernel) that have USB2 ports.
I've attached dynamic debug output (module xhci_hcd =pflm) from a
connection attempt. Is there any other info I should provide or any
other tests (vanilla kernel, rc kernel or the like) I should perform?
Thanks in advance for help.
Best regards,
René
[ 5055.671781] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16068 bytes untransferred
[ 5055.677147] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16060 bytes untransferred
[ 5055.693065] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 15980 bytes untransferred
[ 5055.693098] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 14784 bytes untransferred
[ 5055.693106] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 14720 bytes untransferred
[ 5057.246468] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16036 bytes untransferred
[ 5057.672570] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16068 bytes untransferred
[ 5059.674065] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16068 bytes untransferred
[ 5060.286530] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16036 bytes untransferred
[ 5061.674672] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16068 bytes untransferred
[ 5062.554485] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16040 bytes untransferred
[ 5062.678505] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16004 bytes untransferred
[ 5063.295120] xhci_hcd:xhci_ring_cmd_db:282: xhci_hcd 0000:05:00.4: // Ding dong!
[ 5063.295152] xhci_hcd:xhci_alloc_virt_device:993: xhci_hcd 0000:05:00.4: Slot 9 output ctx = 0xfff33000 (dma)
[ 5063.295156] xhci_hcd:xhci_alloc_virt_device:1001: xhci_hcd 0000:05:00.4: Slot 9 input ctx = 0xffe9f000 (dma)
[ 5063.295164] xhci_hcd:xhci_alloc_virt_device:1020: xhci_hcd 0000:05:00.4: Set slot id 9 dcbaa entry 0000000065b38789 to 0xfff33000
[ 5063.332378] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16036 bytes untransferred
[ 5063.386123] usb 3-2.3: new full-speed USB device number 11 using xhci_hcd
[ 5063.386133] xhci_hcd:xhci_setup_addressable_virt_dev:1154: xhci_hcd 0000:05:00.4: Set root hub portnum to 2
[ 5063.386136] xhci_hcd:xhci_setup_addressable_virt_dev:1155: xhci_hcd 0000:05:00.4: Set fake root hub portnum to 2
[ 5063.386141] xhci_hcd:xhci_setup_addressable_virt_dev:1194: xhci_hcd 0000:05:00.4: udev->tt = 0000000006df9d27
[ 5063.386143] xhci_hcd:xhci_setup_addressable_virt_dev:1195: xhci_hcd 0000:05:00.4: udev->ttport = 0x3
[ 5063.386149] xhci_hcd:xhci_ring_cmd_db:282: xhci_hcd 0000:05:00.4: // Ding dong!
[ 5063.386195] xhci_hcd:xhci_dbg_trace:31: xhci_hcd 0000:05:00.4: Successful setup context command
[ 5063.386200] xhci_hcd:xhci_dbg_trace:31: xhci_hcd 0000:05:00.4: Op regs DCBAA ptr = 0x000000ffff7000
[ 5063.386203] xhci_hcd:xhci_dbg_trace:31: xhci_hcd 0000:05:00.4: Slot ID 9 dcbaa entry @0000000065b38789 = 0x000000fff33000
[ 5063.386206] xhci_hcd:xhci_dbg_trace:31: xhci_hcd 0000:05:00.4: Output Context DMA address = 0xfff33000
[ 5063.386208] xhci_hcd:xhci_dbg_trace:31: xhci_hcd 0000:05:00.4: Internal device address = 0
[ 5063.386922] xhci_hcd:process_ctrl_td:2094: xhci_hcd 0000:05:00.4: Waiting for status stage event
[ 5063.478509] xhci_hcd:xhci_discover_or_reset_device:3746: xhci_hcd 0000:05:00.4: Resetting device with slot ID 9
[ 5063.478519] xhci_hcd:xhci_ring_cmd_db:282: xhci_hcd 0000:05:00.4: // Ding dong!
[ 5063.478578] xhci_hcd:xhci_handle_cmd_reset_dev:1279: xhci_hcd 0000:05:00.4: Completed reset device command.
[ 5063.478589] xhci_hcd:xhci_discover_or_reset_device:3787: xhci_hcd 0000:05:00.4: Can't reset device (slot ID 9) in default state
[ 5063.478592] xhci_hcd:xhci_discover_or_reset_device:3790: xhci_hcd 0000:05:00.4: Not freeing device rings.
[ 5063.478599] xhci_hcd:xhci_ring_cmd_db:282: xhci_hcd 0000:05:00.4: // Ding dong!
[ 5063.478817] xhci_hcd:xhci_dbg_trace:31: xhci_hcd 0000:05:00.4: Successful setup address command
[ 5063.478823] xhci_hcd:xhci_dbg_trace:31: xhci_hcd 0000:05:00.4: Op regs DCBAA ptr = 0x000000ffff7000
[ 5063.478827] xhci_hcd:xhci_dbg_trace:31: xhci_hcd 0000:05:00.4: Slot ID 9 dcbaa entry @0000000065b38789 = 0x000000fff33000
[ 5063.478829] xhci_hcd:xhci_dbg_trace:31: xhci_hcd 0000:05:00.4: Output Context DMA address = 0xfff33000
[ 5063.478832] xhci_hcd:xhci_dbg_trace:31: xhci_hcd 0000:05:00.4: Internal device address = 9
[ 5063.498074] xhci_hcd:xhci_dbg_trace:31: xhci_hcd 0000:05:00.4: Max Packet Size for ep 0 changed.
[ 5063.498078] xhci_hcd:xhci_dbg_trace:31: xhci_hcd 0000:05:00.4: Max packet size in usb_device = 8
[ 5063.498081] xhci_hcd:xhci_dbg_trace:31: xhci_hcd 0000:05:00.4: Max packet size in xHCI HW = 64
[ 5063.498084] xhci_hcd:xhci_dbg_trace:31: xhci_hcd 0000:05:00.4: Issuing evaluate context command.
[ 5063.498090] xhci_hcd:xhci_ring_cmd_db:282: xhci_hcd 0000:05:00.4: // Ding dong!
[ 5063.498133] xhci_hcd:xhci_dbg_trace:31: xhci_hcd 0000:05:00.4: Successful evaluate context command
[ 5063.508815] xhci_hcd:process_ctrl_td:2094: xhci_hcd 0000:05:00.4: Waiting for status stage event
[ 5063.511945] xhci_hcd:process_ctrl_td:2094: xhci_hcd 0000:05:00.4: Waiting for status stage event
[ 5063.514941] xhci_hcd:process_ctrl_td:2094: xhci_hcd 0000:05:00.4: Waiting for status stage event
[ 5063.517938] xhci_hcd:process_ctrl_td:2094: xhci_hcd 0000:05:00.4: Waiting for status stage event
[ 5063.518821] usb 3-2.3: New USB device found, idVendor=2485, idProduct=504f, bcdDevice= 2.54
[ 5063.518825] usb 3-2.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 5063.518828] usb 3-2.3: Product: CTRL
[ 5063.518830] usb 3-2.3: Manufacturer: CTRL
[ 5063.518832] usb 3-2.3: SerialNumber: CTRL
[ 5063.519100] xhci_hcd:xhci_add_endpoint:1917: xhci_hcd 0000:05:00.4: add ep 0x1, slot id 9, new drop flags = 0x0, new add flags = 0x5
[ 5063.519113] xhci_hcd:xhci_add_endpoint:1917: xhci_hcd 0000:05:00.4: add ep 0x81, slot id 9, new drop flags = 0x0, new add flags = 0xd
[ 5063.519118] xhci_hcd:xhci_check_bandwidth:2878: xhci_hcd 0000:05:00.4: xhci_check_bandwidth called for udev 00000000f9c39172
[ 5063.519123] xhci_hcd:xhci_ring_cmd_db:282: xhci_hcd 0000:05:00.4: // Ding dong!
[ 5063.519167] xhci_hcd 0000:05:00.4: ERROR: unexpected command completion code 0x11.
[ 5063.519174] xhci_hcd:xhci_reset_bandwidth:2968: xhci_hcd 0000:05:00.4: xhci_reset_bandwidth called for udev 00000000f9c39172
[ 5063.519201] usb 3-2.3: can't set config #1, error -22
[ 5063.675540] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16068 bytes untransferred
[ 5065.659401] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16032 bytes untransferred
[ 5065.659438] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 15992 bytes untransferred
[ 5065.670966] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16060 bytes untransferred
[ 5065.676831] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16068 bytes untransferred
[ 5065.686932] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 15980 bytes untransferred
[ 5065.686963] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 13380 bytes untransferred
[ 5066.363714] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16036 bytes untransferred
[ 5066.395840] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16068 bytes untransferred
[ 5067.678212] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16068 bytes untransferred
[ 5069.370006] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16044 bytes untransferred
[ 5069.370059] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16044 bytes untransferred
[ 5069.679534] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16068 bytes untransferred
[ 5071.680166] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16068 bytes untransferred
[ 5072.379855] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 15960 bytes untransferred
[ 5073.681413] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16068 bytes untransferred
[ 5075.295816] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 15940 bytes untransferred
[ 5075.304573] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 15568 bytes untransferred
[ 5075.319036] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 15780 bytes untransferred
[ 5075.338924] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16068 bytes untransferred
[ 5075.418659] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16036 bytes untransferred
[ 5075.675209] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16060 bytes untransferred
[ 5075.682197] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16068 bytes untransferred
[ 5075.690167] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 15980 bytes untransferred
[ 5075.690219] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 13380 bytes untransferred
[ 5076.961369] usb 3-2.3: USB disconnect, device number 11
[ 5076.961380] xhci_hcd:xhci_check_bandwidth:2878: xhci_hcd 0000:05:00.4: xhci_check_bandwidth called for udev 00000000f9c39172
[ 5076.961659] xhci_hcd:xhci_ring_cmd_db:282: xhci_hcd 0000:05:00.4: // Ding dong!
[ 5077.533612] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 15824 bytes untransferred
[ 5077.533644] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 15940 bytes untransferred
[ 5077.683255] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16068 bytes untransferred
[ 5078.418644] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16036 bytes untransferred
[ 5079.315613] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16040 bytes untransferred
[ 5079.437420] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16004 bytes untransferred
[ 5079.684935] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16068 bytes untransferred
[ 5081.456512] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16036 bytes untransferred
[ 5081.685711] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16068 bytes untransferred
[ 5083.686602] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16068 bytes untransferred
[ 5084.112833] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 15932 bytes untransferred
[ 5084.476642] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16036 bytes untransferred
[ 5085.655145] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16060 bytes untransferred
[ 5085.671949] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 15980 bytes untransferred
[ 5085.671973] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 13376 bytes untransferred
[ 5085.687793] xhci_hcd:process_bulk_intr_td:2257: xhci_hcd 0000:05:00.4: ep 0x87 - asked for 16384 bytes, 16068 bytes untransferred
