Re: xhci_hcd 0000:00:14.0: WARN Event TRB for slot 1 ep 2 with no TDs queued?

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hello, Mathias! Did you get a chance to look into this bug?

2017-07-20 19:15 GMT+03:00 Yaroslav Isakov <yaroslav.isakov@xxxxxxxxx>:
> Yes, I can definitely test the patch
>
> 2017-07-20 19:16 GMT+03:00 Mathias Nyman <mathias.nyman@xxxxxxxxxxxxxxx>:
>> On 20.07.2017 18:07, Yaroslav Isakov wrote:
>>>
>>> Here it is
>>>
>>> 2017-07-20 18:06 GMT+03:00 Mathias Nyman <mathias.nyman@xxxxxxxxxxxxxxx>:
>>>>
>>>> On 20.07.2017 17:43, Yaroslav Isakov wrote:
>>>>>
>>>>>
>>>>> Hello everyone! I saw this thread some months ago, but do not know how
>>>>> to properly reply to it. I have the same problem, and it's just not
>>>>> few messages - it was about 40k messages in 10 minutes. No functional
>>>>> of my USB device (which is CCID USB token) is broken, just enormous
>>>>> amount of spam in the logs. I'm on 4.12 kernel, but I've seen this
>>>>> error on 4.11 and 4.9. Could this problem be caused by a bug in e.g.
>>>>> libusb, not a device itself?
>>>>> --
>>>>
>>>>
>>>>
>>>> I'd start by looking at xhci, can you take xhci traces of this?
>>>>
>>>> mount -t debugfs none /sys/kernel/debug
>>>> echo 81920 > /sys/kernel/debug/tracing/buffer_size_kb
>>>> echo 1 > /sys/kernel/debug/tracing/events/xhci-hcd/enable
>>>>
>>>> and then send me the content of
>>>> /sys/kernel/debug/tracing/trace
>>>>
>>>> I'll be away for a couple of weeks, so next response might take some time
>>>>
>>>> -Mathias
>>>>
>>>>
>>
>> Think I found something.   (details mostly for myself in to remember this)
>> A short transfer response on a bulk in transfer which is not the last TRB of
>> a TD
>>
>> According to specs xhci will issue short transfer events both on the short
>> TRB, _and_
>> on the last TRB of the TD in case any previous TRB in the TD was short
>> (see xhci 4.11.3.1)
>>
>> After the first short transfer event the driver fast forward past this TD.
>> (and the last TRB)
>> when we get the second short transfer event there are no TRBs queued and you
>> see the
>> warning.
>>
>> Warning should be harmless in this case, but annoying.
>> If I write a patch can you try it out?
>>
>> As a reference, a snippet when log when a 65556 byte transfer is queued,
>> split into 5 pieces (TRBS),
>> and we get short transfer events for first and last TRB
>>
>> * A URB asking for 65556 bytes is queues:
>> 2369.450362: xhci_urb_enqueue: ep1in-bulk: urb ffff8801398f6540 pipe
>> 3221258880 slot 1 length 0/65556 sgs 5/5 stream 0 flags 00040200
>> * split into 5 pieces ( TRBs at 0x00000002169cb520, ..530, ..540, ..550 and
>> ..560)
>> 2369.450363: xhci_queue_trb: BULK: Buffer 000000010a7dc000 length 16384 TD
>> size 31 intr 0 type 'Normal' flags b:i:i:C:s:I:e:C
>> 2369.450363: xhci_inc_enq: BULK ffff88021726c780: enq
>> 0x00000002169cb530(0x00000002169cb000) deq
>> 0x00000002169cb520(0x00000002169cb000) segs 2 stream 0 free_trbs 508 bounce
>> 6\
>> 2369.450363: xhci_queue_trb: BULK: Buffer 000000011e970000 length 16384 TD
>> size 31 intr 0 type 'Normal' flags b:i:i:C:s:I:e:c
>> 2369.450363: xhci_inc_enq: BULK ffff88021726c780: enq
>> 0x00000002169cb540(0x00000002169cb000) deq
>> 0x00000002169cb520(0x00000002169cb000) segs 2 stream 0 free_trbs 507 bounce
>> 6\
>> 2369.450363: xhci_queue_trb: BULK: Buffer 00000001b63ac000 length 16384 TD
>> size 31 intr 0 type 'Normal' flags b:i:i:C:s:I:e:c
>> 2369.450363: xhci_inc_enq: BULK ffff88021726c780: enq
>> 0x00000002169cb550(0x00000002169cb000) deq
>> 0x00000002169cb520(0x00000002169cb000) segs 2 stream 0 free_trbs 506 bounce
>> 6\
>> 2369.450364: xhci_queue_trb: BULK: Buffer 000000010a7ac000 length 16384 TD
>> size 1 intr 0 type 'Normal' flags b:i:i:C:s:I:e:c
>> 2369.450364: xhci_inc_enq: BULK ffff88021726c780: enq
>> 0x00000002169cb560(0x00000002169cb000) deq
>> 0x00000002169cb520(0x00000002169cb000) segs 2 stream 0 free_trbs 505 bounce
>> 6\
>> 2369.450364: xhci_queue_trb: BULK: Buffer 00000001a26adf40 length 20 TD size
>> 0 intr 0 type 'Normal' flags b:i:I:c:s:I:e:c
>> 2369.450364: xhci_inc_enq: BULK ffff88021726c780: enq
>> 0x00000002169cb570(0x00000002169cb000) deq
>> 0x00000002169cb520(0x00000002169cb000) segs 2 stream 0 free_trbs 504 bounce
>> 6\
>> * short packet event for first TRB at ..520
>> 2369.450505: xhci_handle_event: EVENT: TRB 00000002169cb520 status 'Short
>> Packet' len 16334 slot 1 ep 3 type 'Transfer Event' flags e:c
>> 2369.450506: xhci_handle_transfer: BULK: Buffer 000000010a7dc000 length
>> 16384 TD size 31 intr 0 type 'Normal' flags b:i:i:C:s:I:e:c
>> * fast forward past this TD, move dequeue to ..570)
>> 2369.450506: xhci_inc_deq: BULK ffff88021726c780: enq
>> 0x00000002169cb570(0x00000002169cb000) deq
>> 0x00000002169cb530(0x00000002169cb000) segs 2 stream 0 free_trbs 505 bounce
>> 6\
>> 2369.450506: xhci_inc_deq: BULK ffff88021726c780: enq
>> 0x00000002169cb570(0x00000002169cb000) deq
>> 0x00000002169cb540(0x00000002169cb000) segs 2 stream 0 free_trbs 506 bounce
>> 6\
>> 2369.450506: xhci_inc_deq: BULK ffff88021726c780: enq
>> 0x00000002169cb570(0x00000002169cb000) deq
>> 0x00000002169cb550(0x00000002169cb000) segs 2 stream 0 free_trbs 507 bounce
>> 6\
>> 2369.450506: xhci_inc_deq: BULK ffff88021726c780: enq
>> 0x00000002169cb570(0x00000002169cb000) deq
>> 0x00000002169cb560(0x00000002169cb000) segs 2 stream 0 free_trbs 508 bounce
>> 6\
>> 2369.450506: xhci_inc_deq: BULK ffff88021726c780: enq
>> 0x00000002169cb570(0x00000002169cb000) deq
>> 0x00000002169cb570(0x00000002169cb000) segs 2 stream 0 free_trbs 509 bounce
>> 6\
>> 2369.450506: xhci_urb_giveback: ep1in-bulk: urb ffff8801398f6540 pipe
>> 3221258880 slot 1 length 50/65556 sgs 5/5 stream 0 flags 00040200
>> * short transfer event for last TRB in TD at ..560
>> 2369.450507: xhci_handle_event: EVENT: TRB 00000002169cb560 status 'Short
>> Packet' len 20 slot 1 ep 3 type 'Transfer Event' flags e:c
>> we are already past 560, we are at 570 with a empty ring, not expecting
>> events for this ring
>>
>> -Mathias
>>
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html



[Index of Archives]     [Linux Media]     [Linux Input]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]     [Old Linux USB Devel Archive]

  Powered by Linux