From: Ferry Toth <fntoth@gmail.com>
To: Felipe Balbi <balbi@kernel.org>,
Andy Shevchenko <andy.shevchenko@gmail.com>
Cc: "linux-usb@vger.kernel.org" <linux-usb@vger.kernel.org>,
Thinh Nguyen <Thinh.Nguyen@synopsys.com>,
Heikki Krogerus <heikki.krogerus@linux.intel.com>,
Jack Pham <jackp@codeaurora.org>,
Mathias Nyman <mathias.nyman@linux.intel.com>
Subject: Re: BUG with linux 5.9.0 with dwc3 in gadget mode
Date: Sat, 7 Nov 2020 14:37:49 +0100
Message-ID: <cdb37a4c-2815-0068-1707-2e9163d1a93c@gmail.com> (raw)
In-Reply-To: <87d00py4sj.fsf@kernel.org>
Hi
Op 07-11-2020 om 09:01 schreef Felipe Balbi:
> Hi,
>
> Ferry Toth <fntoth@gmail.com> writes:
>
>> Hi
>>
>> Op 06-11-2020 om 15:15 schreef Felipe Balbi:
>>> Hi,
>>>
>>> Ferry Toth <fntoth@gmail.com> writes:
>>>>>>> Ferry Toth <fntoth@gmail.com> writes:
>>>>>>>> Op 27-10-2020 om 22:16 schreef Andy Shevchenko:
>>>>>>>>> On Tue, Oct 27, 2020 at 10:13 PM Ferry Toth <fntoth@gmail.com> wrote:
>>>>>>>>>> Op 22-10-2020 om 15:43 schreef Andy Shevchenko:
>>>>>>>>>>> On Thu, Oct 22, 2020 at 4:21 PM Thinh Nguyen <Thinh.Nguyen@synopsys.com> wrote:
>>>>>>>>>>>> Ferry Toth wrote:
>>>>>>>>> ...
>>>>>>>>>
>>>>>>>>>>>> There are some fixes to dwc3 in kernel mainline. Is it possible to test
>>>>>>>>>>>> this against linux-next?
>>>>>>>>>>> I think the best is to wait for v5.10-rc1 and retest.
>>>>>>>>> Can you give a try of v5.10-rc1?
>>>>>>>> Yes, I just tried:
>>>>>>>>
>>>>>>>> I booted in host mode, then flip the switch. Gadget come up, go down
>>>>>>>> once, then come up again and stay up.
>>>>>>> please collect trace events. It's important to figure out why it's going
>>>>>>> down, even if only once. Make sure to collect trace *and* dmesg so we
>>>>>>> can correlate trace with the reenumeration that should show up in dmesg.
>>>>>>>
>>>>>>> thanks
>>>>>> Sorry, I had to replace mobo. Now back on this.
>>>>>>
>>>>>> As is, on Edison I can record with something like "perf record -e
>>>>>> 'dwc3:dwc3_gadget*' -e 'gadget:*' -g -a".
>>>>>> Then get the trace buffer with "perf script > gadget.txt". Then at each
>>>>>> trace point we get a stack trace like:
>>>>>>
>>>>>> file-storage 831 [001] 4445.240038: dwc3:dwc3_gadget_ep_cmd: [FAILED
>>>>>> TO PARSE] name=ep4in cmd=524295 param0=0 param1=0 param2=0 cmd_status=0
>>>>>> ffffffff9a35b7e7 __traceiter_dwc3_gadget_ep_cmd+0x37
>>>>>> ([kernel.kallsyms])
>>>>>> ffffffff9a35b7e7 __traceiter_dwc3_gadget_ep_cmd+0x37
>>>>>> ([kernel.kallsyms])
>>>>>> ffffffff9a35fa40 dwc3_send_gadget_ep_cmd+0x320 ([kernel.kallsyms])
>>>>>> ffffffff9a3606d0 __dwc3_gadget_kick_transfer+0x200 ([kernel.kallsyms])
>>>>>> ffffffff9a361114 dwc3_gadget_ep_queue+0xe4 ([kernel.kallsyms])
>>>>>> ffffffff9a3afc3a usb_ep_queue+0x2a ([kernel.kallsyms])
>>>>>> ffffffffc047c301 start_transfer.isra.0+0x21 ([kernel.kallsyms])
>>>>>> ffffffffc047c88a start_in_transfer.isra.0+0x3a ([kernel.kallsyms])
>>>>>> ffffffffc047c93d send_status+0x8d ([kernel.kallsyms])
>>>>>> ffffffffc047dd05 fsg_main_thread+0x3c5 ([kernel.kallsyms])
>>>>>> ffffffff99c853b9 kthread+0xf9 ([kernel.kallsyms])
>>>>>> ffffffff99c01a32 ret_from_fork+0x22 ([kernel.kallsyms])
>>>>>>
>>>>>> "perf list" shows the tracepoint events, the same as under
>>>>>> /sys/kernel/debug/tracing/events/
>>>>>>
>>>>>> Question is which points to trace (above command fills buffer to 35MB in
>>>>>> 10sec). Do you have suggestions?
>>>>> don't enable any gadget event. Only dwc3 events. Also, enable *all* dwc3
>>>>> events. Usually, I avoid perf when doing this and just go straight to
>>>>> /sys/kernel/trace/.
>>>> Ok, I can do that. But I'm not sure how I turn on tracing and capture
>>>> the results.
>>> Got you covered ;-)
>>>
>>> https://www.kernel.org/doc/html/latest/driver-api/usb/dwc3.html#reporting-bugs
>>>
>> That's exactly the fix I needed :-)
>>
>> Ok, here's what I did:
>>
>> - put the edison switch in gadget mode, with the cable unplugged
>>
>> - booted edison into 5.10.0-rc2-edison-acpi-standard
>>
>> - opened terminal via wifi
>>
>> - prepared tracing per the link above link
>>
>> - in another terminal via wifi journalctl -b 0 -f
>>
>> - plugged the cable and recorded usb connecting. Followed by
>> disconnecting/connecting 2x in the following minute
>>
>> - copied the trace (20MB) and journal tail, 7z attached.
> Oddily, there's nothing indicating a fault. Here are all three
> resets. First one:
>
>> irq/15-dwc3-494 [001] d... 430.442333: dwc3_event: event (00000101): Reset [U0]
>> irq/15-dwc3-494 [001] d... 430.496919: dwc3_event: event (00000201): Connection Done [U0]
>> irq/15-dwc3-494 [001] d... 430.496941: dwc3_gadget_ep_cmd: ep0out: cmd 'Set Endpoint Configuration' [401] params 80000200 00000500 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 430.496946: dwc3_gadget_ep_enable: ep0out: mps 64/512 streams 0 burst 1 ring 0/0 flags E:swBp:>
>> irq/15-dwc3-494 [001] d... 430.496955: dwc3_gadget_ep_cmd: ep0in: cmd 'Set Endpoint Configuration' [401] params 80000200 02000500 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 430.496959: dwc3_gadget_ep_enable: ep0in: mps 64/512 streams 0 burst 1 ring 0/0 flags E:swbp:<
>> irq/15-dwc3-494 [001] d... 430.570050: dwc3_event: event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
>> irq/15-dwc3-494 [001] d... 430.570054: dwc3_ctrl_req: Get Device Descriptor(Index = 0, Length = 64)
>> irq/15-dwc3-494 [001] d... 430.570093: dwc3_prepare_trb: ep0in: trb 00000000fd713550 (E0:D0) buf 0000000007c1a000 size 18 ctrl 00000c53 (HLcs:SC:data)
>> irq/15-dwc3-494 [001] d... 430.570107: dwc3_gadget_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 0726e000 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 430.570115: dwc3_event: event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
>> irq/15-dwc3-494 [001] d... 430.570133: dwc3_event: event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
>> irq/15-dwc3-494 [001] d... 430.570135: dwc3_complete_trb: ep0out: trb 00000000fd713550 (E0:D0) buf 0000000007c1a000 size 0 ctrl 00000c52 (hLcs:SC:data)
>> irq/15-dwc3-494 [001] d... 430.570142: dwc3_gadget_giveback: ep0out: req 00000000cd8dc122 length 18/18 ZsI ==> 0
>> irq/15-dwc3-494 [001] d... 430.570145: dwc3_event: event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
>> irq/15-dwc3-494 [001] d... 430.570146: dwc3_prepare_trb: ep0out: trb 00000000fd713550 (E0:D0) buf 000000000726e000 size 0 ctrl 00000c43 (HLcs:SC:status3)
>> irq/15-dwc3-494 [001] d... 430.570156: dwc3_gadget_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 0726e000 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 430.570266: dwc3_event: event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
>> irq/15-dwc3-494 [001] d... 430.570270: dwc3_complete_trb: ep0out: trb 00000000fd713550 (E0:D0) buf 000000000726e000 size 0 ctrl 00000c42 (hLcs:SC:status3)
>> irq/15-dwc3-494 [001] d... 430.570273: dwc3_prepare_trb: ep0out: trb 00000000fd713550 (E0:D0) buf 000000000726e000 size 8 ctrl 00000c23 (HLcs:SC:setup)
>> irq/15-dwc3-494 [001] d... 430.570283: dwc3_gadget_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 0726e000 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 430.574090: dwc3_event: event (00000101): Reset [U0]
> Second one:
>
>> irq/15-dwc3-494 [001] d... 462.594296: dwc3_event: event (00000101): Reset [U0]
>> irq/15-dwc3-494 [001] d... 462.594307: dwc3_gadget_ep_disable: ep1out: mps 512/2389 streams 16 burst 0 ring 0/0 flags E:swBp:>
>> irq/15-dwc3-494 [001] d... 462.594320: dwc3_gadget_ep_cmd: ep1out: cmd 'End Transfer' [20c08] params 00000000 00000000 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 462.594327: dwc3_gadget_ep_disable: ep2in: mps 512/1034 streams 16 burst 0 ring 0/0 flags E:swBp:<
>> irq/15-dwc3-494 [001] d... 462.594336: dwc3_gadget_ep_cmd: ep2in: cmd 'End Transfer' [40c08] params 00000000 00000000 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 462.594367: dwc3_gadget_ep_disable: ep3in: mps 512/1034 streams 16 burst 0 ring 17/17 flags E:swBp:<
>> irq/15-dwc3-494 [001] d... 462.594376: dwc3_gadget_ep_cmd: ep3in: cmd 'End Transfer' [60c08] params 00000000 00000000 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 462.594387: dwc3_free_request: ep3in: req 00000000899d2838 length 76/76 ZsI ==> 0
>> irq/15-dwc3-494 [001] d... 462.594392: dwc3_free_request: ep3in: req 000000007c941936 length 96/96 ZsI ==> 0
>> irq/15-dwc3-494 [001] d... 462.594393: dwc3_free_request: ep3in: req 00000000d7578dd1 length 0/0 zsI ==> 0
>> irq/15-dwc3-494 [001] d... 462.594395: dwc3_free_request: ep3in: req 00000000d02b987b length 0/0 zsI ==> 0
>> irq/15-dwc3-494 [001] d... 462.594397: dwc3_free_request: ep3in: req 000000008a4586b3 length 0/0 zsI ==> 0
>> irq/15-dwc3-494 [001] d... 462.594399: dwc3_free_request: ep3in: req 000000001b05a881 length 0/0 zsI ==> 0
>> irq/15-dwc3-494 [001] d... 462.594400: dwc3_free_request: ep3in: req 00000000ede49e1b length 0/0 zsI ==> 0
>> irq/15-dwc3-494 [001] d... 462.594402: dwc3_free_request: ep3in: req 000000007710fa93 length 0/0 zsI ==> 0
>> irq/15-dwc3-494 [001] d... 462.594404: dwc3_free_request: ep3in: req 000000006d472cbc length 0/0 zsI ==> 0
>> irq/15-dwc3-494 [001] d... 462.594405: dwc3_free_request: ep3in: req 000000001a5e4f3e length 0/0 zsI ==> 0
>> irq/15-dwc3-494 [001] d... 462.594407: dwc3_gadget_ep_disable: ep2out: mps 512/2389 streams 16 burst 0 ring 53/43 flags E:swBp:>
>> irq/15-dwc3-494 [001] d... 462.594416: dwc3_gadget_ep_cmd: ep2out: cmd 'End Transfer' [30c08] params 00000000 00000000 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 462.594431: dwc3_gadget_giveback: ep2out: req 00000000b4c75191 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 462.594446: dwc3_gadget_giveback: ep2out: req 0000000004911b96 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 462.594452: dwc3_gadget_giveback: ep2out: req 00000000312948aa length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 462.594457: dwc3_gadget_giveback: ep2out: req 00000000c3f1bc7f length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 462.594461: dwc3_gadget_giveback: ep2out: req 00000000e9d45c98 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 462.594466: dwc3_gadget_giveback: ep2out: req 0000000087c88a29 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 462.594471: dwc3_gadget_giveback: ep2out: req 0000000076eac09c length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 462.594477: dwc3_gadget_giveback: ep2out: req 00000000893b5b83 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 462.594481: dwc3_gadget_giveback: ep2out: req 0000000032598a43 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 462.594487: dwc3_gadget_giveback: ep2out: req 000000006f54ed94 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 462.594492: dwc3_free_request: ep2out: req 000000006f54ed94 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 462.594494: dwc3_free_request: ep2out: req 0000000032598a43 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 462.594496: dwc3_free_request: ep2out: req 00000000893b5b83 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 462.594497: dwc3_free_request: ep2out: req 0000000076eac09c length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 462.594499: dwc3_free_request: ep2out: req 0000000087c88a29 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 462.594500: dwc3_free_request: ep2out: req 00000000e9d45c98 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 462.594502: dwc3_free_request: ep2out: req 00000000c3f1bc7f length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 462.594503: dwc3_free_request: ep2out: req 00000000312948aa length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 462.594505: dwc3_free_request: ep2out: req 0000000004911b96 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 462.594506: dwc3_free_request: ep2out: req 00000000b4c75191 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 462.594541: dwc3_gadget_ep_cmd: ep3out: cmd 'End Transfer' [50c08] params 00000000 00000000 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 462.594551: dwc3_gadget_giveback: ep3out: req 0000000021d51c6b length 0/512 zsI ==> -108
>> file-storage-493 [000] .... 462.594608: dwc3_free_request: ep4in: req 00000000807d5502 length 16/16 ZsI ==> 0
>> file-storage-493 [000] .... 462.594614: dwc3_free_request: ep3out: req 0000000021d51c6b length 0/512 zsI ==> -108
>> file-storage-493 [000] .... 462.594616: dwc3_free_request: ep4in: req 00000000e0ba52a1 length 0/13 zsI ==> -104
>> file-storage-493 [000] .... 462.594618: dwc3_free_request: ep3out: req 00000000c631ee54 length 31/512 zsI ==> 0
>> file-storage-493 [000] d... 462.594620: dwc3_gadget_ep_disable: ep4in: mps 512/346 streams 16 burst 0 ring 10/10 flags E:swbP:<
>> file-storage-493 [000] d... 462.594625: dwc3_gadget_ep_disable: ep3out: mps 512/2389 streams 16 burst 0 ring 7/6 flags E:swbp:>
>> irq/15-dwc3-494 [001] d... 462.645482: dwc3_event: event (00000201): Connection Done [U0]
>> irq/15-dwc3-494 [001] d... 462.645503: dwc3_gadget_ep_cmd: ep0out: cmd 'Set Endpoint Configuration' [401] params 80000200 00000500 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 462.645509: dwc3_gadget_ep_enable: ep0out: mps 64/512 streams 0 burst 1 ring 0/0 flags E:swBp:>
>> irq/15-dwc3-494 [001] d... 462.645520: dwc3_gadget_ep_cmd: ep0in: cmd 'Set Endpoint Configuration' [401] params 80000200 02000500 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 462.645525: dwc3_gadget_ep_enable: ep0in: mps 64/512 streams 0 burst 1 ring 0/0 flags E:swbp:<
>> irq/15-dwc3-494 [001] d... 462.722774: dwc3_event: event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
>> irq/15-dwc3-494 [001] d... 462.722778: dwc3_ctrl_req: Get Device Descriptor(Index = 0, Length = 64)
>> irq/15-dwc3-494 [001] d... 462.722816: dwc3_prepare_trb: ep0in: trb 00000000fd713550 (E0:D0) buf 0000000007c1a000 size 18 ctrl 00000c53 (HLcs:SC:data)
>> irq/15-dwc3-494 [001] d... 462.722830: dwc3_gadget_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 0726e000 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 462.722837: dwc3_event: event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
>> irq/15-dwc3-494 [001] d... 462.722881: dwc3_event: event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
>> irq/15-dwc3-494 [001] d... 462.722884: dwc3_complete_trb: ep0out: trb 00000000fd713550 (E0:D0) buf 0000000007c1a000 size 0 ctrl 00000c52 (hLcs:SC:data)
>> irq/15-dwc3-494 [001] d... 462.722891: dwc3_gadget_giveback: ep0out: req 00000000cd8dc122 length 18/18 ZsI ==> 0
>> irq/15-dwc3-494 [001] d... 462.722894: dwc3_event: event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
>> irq/15-dwc3-494 [001] d... 462.722895: dwc3_prepare_trb: ep0out: trb 00000000fd713550 (E0:D0) buf 000000000726e000 size 0 ctrl 00000c43 (HLcs:SC:status3)
>> irq/15-dwc3-494 [001] d... 462.722905: dwc3_gadget_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 0726e000 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 462.722949: dwc3_event: event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
>> irq/15-dwc3-494 [001] d... 462.722951: dwc3_complete_trb: ep0out: trb 00000000fd713550 (E0:D0) buf 000000000726e000 size 0 ctrl 00000c42 (hLcs:SC:status3)
>> irq/15-dwc3-494 [001] d... 462.722953: dwc3_prepare_trb: ep0out: trb 00000000fd713550 (E0:D0) buf 000000000726e000 size 8 ctrl 00000c23 (HLcs:SC:setup)
>> irq/15-dwc3-494 [001] d... 462.722963: dwc3_gadget_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 0726e000 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 462.726933: dwc3_event: event (00000101): Reset [U0]
> And Third:
>
>> irq/15-dwc3-494 [001] d... 468.061065: dwc3_event: event (00000101): Reset [U0]
>> irq/15-dwc3-494 [001] d... 468.061078: dwc3_gadget_ep_disable: ep1out: mps 512/2389 streams 16 burst 0 ring 0/0 flags E:swBp:>
>> irq/15-dwc3-494 [001] d... 468.061091: dwc3_gadget_ep_cmd: ep1out: cmd 'End Transfer' [20c08] params 00000000 00000000 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 468.061098: dwc3_gadget_ep_disable: ep2in: mps 512/1034 streams 16 burst 0 ring 0/0 flags E:swBp:<
>> irq/15-dwc3-494 [001] d... 468.061107: dwc3_gadget_ep_cmd: ep2in: cmd 'End Transfer' [40c08] params 00000000 00000000 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 468.061137: dwc3_gadget_ep_disable: ep3in: mps 512/1034 streams 16 burst 0 ring 2/0 flags E:swBp:<
>> irq/15-dwc3-494 [001] d... 468.061149: dwc3_gadget_ep_cmd: ep3in: cmd 'End Transfer' [60c08] params 00000000 00000000 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 468.061160: dwc3_gadget_giveback: ep3in: req 000000008a4586b3 length 0/116 ZsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061173: dwc3_gadget_giveback: ep3in: req 000000001b05a881 length 0/116 ZsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061179: dwc3_free_request: ep3in: req 000000001b05a881 length 0/116 ZsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061183: dwc3_free_request: ep3in: req 000000008a4586b3 length 0/116 ZsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061185: dwc3_free_request: ep3in: req 00000000ede49e1b length 0/0 zsI ==> 0
>> irq/15-dwc3-494 [001] d... 468.061187: dwc3_free_request: ep3in: req 000000007710fa93 length 0/0 zsI ==> 0
>> irq/15-dwc3-494 [001] d... 468.061189: dwc3_free_request: ep3in: req 000000006d472cbc length 0/0 zsI ==> 0
>> irq/15-dwc3-494 [001] d... 468.061191: dwc3_free_request: ep3in: req 000000001a5e4f3e length 0/0 zsI ==> 0
>> irq/15-dwc3-494 [001] d... 468.061193: dwc3_free_request: ep3in: req 0000000076eac09c length 0/0 zsI ==> 0
>> irq/15-dwc3-494 [001] d... 468.061195: dwc3_free_request: ep3in: req 00000000763f5c3c length 0/0 zsI ==> 0
>> irq/15-dwc3-494 [001] d... 468.061197: dwc3_free_request: ep3in: req 00000000b0300b83 length 0/0 zsI ==> 0
>> irq/15-dwc3-494 [001] d... 468.061199: dwc3_free_request: ep3in: req 000000007c621acb length 0/0 zsI ==> 0
>> irq/15-dwc3-494 [001] d... 468.061200: dwc3_gadget_ep_disable: ep2out: mps 512/2389 streams 16 burst 0 ring 10/0 flags E:swBp:>
>> irq/15-dwc3-494 [001] d... 468.061210: dwc3_gadget_ep_cmd: ep2out: cmd 'End Transfer' [30c08] params 00000000 00000000 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 468.061221: dwc3_gadget_giveback: ep2out: req 00000000e9d45c98 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061229: dwc3_gadget_giveback: ep2out: req 00000000c3f1bc7f length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061234: dwc3_gadget_giveback: ep2out: req 00000000312948aa length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061238: dwc3_gadget_giveback: ep2out: req 0000000004911b96 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061244: dwc3_gadget_giveback: ep2out: req 00000000b4c75191 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061249: dwc3_gadget_giveback: ep2out: req 00000000570c1ba8 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061254: dwc3_gadget_giveback: ep2out: req 00000000899d2838 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061258: dwc3_gadget_giveback: ep2out: req 000000007c941936 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061263: dwc3_gadget_giveback: ep2out: req 00000000d7578dd1 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061269: dwc3_gadget_giveback: ep2out: req 00000000d02b987b length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061274: dwc3_free_request: ep2out: req 00000000d02b987b length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061276: dwc3_free_request: ep2out: req 00000000d7578dd1 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061277: dwc3_free_request: ep2out: req 000000007c941936 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061279: dwc3_free_request: ep2out: req 00000000899d2838 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061280: dwc3_free_request: ep2out: req 00000000570c1ba8 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061282: dwc3_free_request: ep2out: req 00000000b4c75191 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061284: dwc3_free_request: ep2out: req 0000000004911b96 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061285: dwc3_free_request: ep2out: req 00000000312948aa length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061286: dwc3_free_request: ep2out: req 00000000c3f1bc7f length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061288: dwc3_free_request: ep2out: req 00000000e9d45c98 length 0/1536 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061323: dwc3_gadget_ep_cmd: ep3out: cmd 'End Transfer' [50c08] params 00000000 00000000 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 468.061333: dwc3_gadget_giveback: ep3out: req 00000000e0ba52a1 length 0/512 zsI ==> -108
>> irq/15-dwc3-494 [001] d... 468.061347: dwc3_gadget_ep_cmd: ep4in: cmd 'End Transfer' [80c08] params 00000000 00000000 00000000 --> status: Successful
>> file-storage-493 [000] .... 468.061451: dwc3_free_request: ep4in: req 00000000c631ee54 length 0/0 zsI ==> 0
>> file-storage-493 [000] .... 468.061456: dwc3_free_request: ep3out: req 00000000e0ba52a1 length 0/512 zsI ==> -108
>> file-storage-493 [000] .... 468.061458: dwc3_free_request: ep4in: req 0000000021d51c6b length 0/0 zsI ==> 0
>> file-storage-493 [000] .... 468.061460: dwc3_free_request: ep3out: req 00000000807d5502 length 0/0 zsI ==> 0
>> file-storage-493 [000] d... 468.061463: dwc3_gadget_ep_disable: ep4in: mps 512/346 streams 16 burst 0 ring 0/0 flags E:swbp:<
>> file-storage-493 [000] d... 468.061501: dwc3_gadget_ep_disable: ep3out: mps 512/2389 streams 16 burst 0 ring 1/0 flags E:swbp:>
>> irq/15-dwc3-494 [001] d... 468.115718: dwc3_event: event (00000201): Connection Done [U0]
>> irq/15-dwc3-494 [001] d... 468.115742: dwc3_gadget_ep_cmd: ep0out: cmd 'Set Endpoint Configuration' [401] params 80000200 00000500 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 468.115748: dwc3_gadget_ep_enable: ep0out: mps 64/512 streams 0 burst 1 ring 0/0 flags E:swbp:>
>> irq/15-dwc3-494 [001] d... 468.115758: dwc3_gadget_ep_cmd: ep0in: cmd 'Set Endpoint Configuration' [401] params 80000200 02000500 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 468.115761: dwc3_gadget_ep_enable: ep0in: mps 64/512 streams 0 burst 1 ring 0/0 flags E:swBp:<
>> irq/15-dwc3-494 [001] d... 468.185582: dwc3_event: event (0000c042): ep0in: Transfer Complete (sIL) [Status Phase]
>> irq/15-dwc3-494 [001] d... 468.185586: dwc3_complete_trb: ep0out: trb 00000000fd713550 (E0:D0) buf 000000000726e000 size 0 ctrl 00000c32 (hLcs:SC:status2)
>> irq/15-dwc3-494 [001] d... 468.185590: dwc3_gadget_giveback: ep0out: req 00000000cd8dc122 length 0/0 zsI ==> 0
>> irq/15-dwc3-494 [001] d... 468.185596: dwc3_prepare_trb: ep0out: trb 00000000fd713550 (E0:D0) buf 000000000726e000 size 8 ctrl 00000c23 (HLcs:SC:setup)
>> irq/15-dwc3-494 [001] d... 468.185608: dwc3_gadget_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 0726e000 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 468.185626: dwc3_event: event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
>> irq/15-dwc3-494 [001] d... 468.185628: dwc3_ctrl_req: Get Device Descriptor(Index = 0, Length = 64)
>> irq/15-dwc3-494 [001] d... 468.185663: dwc3_prepare_trb: ep0in: trb 00000000fd713550 (E0:D0) buf 0000000007c1a000 size 18 ctrl 00000c53 (HLcs:SC:data)
>> irq/15-dwc3-494 [001] d... 468.185674: dwc3_gadget_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 0726e000 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 468.185680: dwc3_event: event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
>> irq/15-dwc3-494 [001] d... 468.185699: dwc3_event: event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
>> irq/15-dwc3-494 [001] d... 468.185701: dwc3_complete_trb: ep0out: trb 00000000fd713550 (E0:D0) buf 0000000007c1a000 size 0 ctrl 00000c52 (hLcs:SC:data)
>> irq/15-dwc3-494 [001] d... 468.185707: dwc3_gadget_giveback: ep0out: req 00000000cd8dc122 length 18/18 ZsI ==> 0
>> irq/15-dwc3-494 [001] d... 468.185721: dwc3_event: event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
>> irq/15-dwc3-494 [001] d... 468.185722: dwc3_prepare_trb: ep0out: trb 00000000fd713550 (E0:D0) buf 000000000726e000 size 0 ctrl 00000c43 (HLcs:SC:status3)
>> irq/15-dwc3-494 [001] d... 468.185732: dwc3_gadget_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 0726e000 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 468.185832: dwc3_event: event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
>> irq/15-dwc3-494 [001] d... 468.185835: dwc3_complete_trb: ep0out: trb 00000000fd713550 (E0:D0) buf 000000000726e000 size 0 ctrl 00000c42 (hLcs:SC:status3)
>> irq/15-dwc3-494 [001] d... 468.185837: dwc3_prepare_trb: ep0out: trb 00000000fd713550 (E0:D0) buf 000000000726e000 size 8 ctrl 00000c23 (HLcs:SC:setup)
>> irq/15-dwc3-494 [001] d... 468.185847: dwc3_gadget_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 0726e000 00000000 --> status: Successful
>> irq/15-dwc3-494 [001] d... 468.189715: dwc3_event: event (00000101): Reset [U0]
> You can see that in all cases, every transfer is successful. The -108
> givebacks is because we're shutting down the endpoint and those
> transfers were cancelled. But everything is perfectly fine. Can you
> reproduce this behavior in any computer you connect Edison to?
Coincidentally I just replaced my mobo (so new processor/mem/mobo/bios).
There was no difference in behavior.
> I don't suppose you have a USB sniffer, do you?
No, I don't have one of those.
> Andy, could you see if you can reproduce the same behavior with a
> sniffer? It really seems like this either caused by the host side or
> something outside dwc3. Perhaps the PHY is going bonkers?
>
> cheers
But got other inspiration: like you say dwc3 is behaving normally, so
problem might be elsewhere right?
Now, to make gadget working I needed to apply the experiment from Jack Pham:
https://github.com/edison-fw/linux/commit/da90cb63fc8f0ce18805f262d4d6b5b4d8c11d5c
But now Jack has already sent in "[PATCH v3] usb: gadget: audio: Free
requests only after callback"
So, removing the experiment and adding PATCH 3, this issue appears to go
away.
And indeed this fixes a problem in u_audio.c, not in dwc3.
Thanks all, I'm looking forward to the patch to land in 5.10-rc3/4.
next prev parent reply index
Thread overview: 38+ messages / expand[flat|nested] mbox.gz Atom feed top
2020-10-16 20:21 Ferry Toth
2020-10-19 5:45 ` Felipe Balbi
2020-10-19 7:14 ` Ferry Toth
2020-10-19 18:49 ` Ferry Toth
2020-10-20 12:35 ` Felipe Balbi
2020-10-20 21:01 ` Ferry Toth
2020-10-19 7:18 ` Ferry Toth
2020-10-20 12:32 ` Felipe Balbi
2020-10-20 19:46 ` Ferry Toth
2020-10-20 20:37 ` Ferry Toth
2020-10-20 22:10 ` Thinh Nguyen
2020-10-20 22:58 ` Thinh Nguyen
2020-10-21 1:47 ` Jack Pham
2020-10-21 1:56 ` Thinh Nguyen
2020-10-21 20:01 ` Ferry Toth
2020-10-22 9:23 ` Andy Shevchenko
2020-10-21 19:45 ` Ferry Toth
2020-10-21 19:50 ` Thinh Nguyen
2020-10-21 20:42 ` Ferry Toth
2020-10-21 23:32 ` Thinh Nguyen
2020-10-22 13:43 ` Andy Shevchenko
2020-10-27 20:13 ` Ferry Toth
2020-10-27 21:06 ` Jack Pham
2020-10-27 22:07 ` Ferry Toth
2020-10-27 21:16 ` Andy Shevchenko
2020-10-27 21:54 ` Ferry Toth
2020-10-28 9:18 ` Felipe Balbi
2020-11-05 21:29 ` Ferry Toth
2020-11-06 6:38 ` Felipe Balbi
2020-11-06 8:14 ` Ferry Toth
[not found] ` <326aa23e-fabd-f3d6-4778-d036858413a2@gmail.com>
2020-11-06 14:15 ` Felipe Balbi
[not found] ` <e21a5a77-9017-4cbe-a228-85357d660da5@gmail.com>
2020-11-07 8:01 ` Felipe Balbi
2020-11-07 13:37 ` Ferry Toth [this message]
2020-11-09 7:00 ` Felipe Balbi
2020-10-27 21:19 ` Andy Shevchenko
2020-10-19 19:46 ` Andy Shevchenko
2020-10-19 20:46 ` Ferry Toth
2020-10-20 13:27 ` Andy Shevchenko
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=cdb37a4c-2815-0068-1707-2e9163d1a93c@gmail.com \
--to=fntoth@gmail.com \
--cc=Thinh.Nguyen@synopsys.com \
--cc=andy.shevchenko@gmail.com \
--cc=balbi@kernel.org \
--cc=heikki.krogerus@linux.intel.com \
--cc=jackp@codeaurora.org \
--cc=linux-usb@vger.kernel.org \
--cc=mathias.nyman@linux.intel.com \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Linux-USB Archive on lore.kernel.org
Archives are clonable:
git clone --mirror https://lore.kernel.org/linux-usb/0 linux-usb/git/0.git
# If you have public-inbox 1.1+ installed, you may
# initialize and index your mirror using the following commands:
public-inbox-init -V2 linux-usb linux-usb/ https://lore.kernel.org/linux-usb \
linux-usb@vger.kernel.org
public-inbox-index linux-usb
Example config snippet for mirrors
Newsgroup available over NNTP:
nntp://nntp.lore.kernel.org/org.kernel.vger.linux-usb
AGPL code for this site: git clone https://public-inbox.org/public-inbox.git