Linux-USB Archive on lore.kernel.org
 help / color / Atom feed
From: Felipe Balbi <balbi@kernel.org>
To: Ferry Toth <fntoth@gmail.com>,
	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, 07 Nov 2020 10:01:00 +0200
Message-ID: <87d00py4sj.fsf@kernel.org> (raw)
In-Reply-To: <e21a5a77-9017-4cbe-a228-85357d660da5@gmail.com>


[-- Attachment #1: Type: text/plain, Size: 26625 bytes --]


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?

I don't suppose you have a USB sniffer, do you?

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

-- 
balbi

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 857 bytes --]

  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 [this message]
2020-11-07 13:37                                           ` Ferry Toth
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=87d00py4sj.fsf@kernel.org \
    --to=balbi@kernel.org \
    --cc=Thinh.Nguyen@synopsys.com \
    --cc=andy.shevchenko@gmail.com \
    --cc=fntoth@gmail.com \
    --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