Re: [PATCH 0/6] usb: dwc3: gadget: Rework pullup

[Thinh Nguyen <Thinh.Nguyen@synopsys.com>]

Wesley Cheng wrote:
> Hi Thinh,
> 
> On 5/23/2022 6:34 PM, Wesley Cheng wrote:
>> Hi Thinh,
>>
>> Welcome back! :)
>>
>> On 5/23/2022 5:30 PM, Thinh Nguyen wrote:
>>> Wesley Cheng wrote:
>>>> Hi Thinh,
>>>>
>>>> On 4/26/2022 2:05 PM, Wesley Cheng wrote:
>>>>> Hi Thinh,
>>>>>
>>>>> On 4/21/2022 7:22 PM, Thinh Nguyen wrote:
>>>>>> This series cleanup and enhance dwc3 pullup() handling to cover
>>>>>> different
>>>>>> corner cases.
>>>>>>
>>>>>> Would be great to have some Tested-by before picking this series up.
>>>>>> Thanks!
>>>>>>
>>>>>>
>>>>>> Thinh Nguyen (6):
>>>>>>     usb: dwc3: gadget: Prevent repeat pullup()
>>>>>>     usb: dwc3: gadget: Refactor pullup()
>>>>>>     usb: dwc3: gadget: Don't modify GEVNTCOUNT in pullup()
>>>>>>     usb: dwc3: ep0: Don't prepare beyond Setup stage
>>>>>>     usb: dwc3: gadget: Only End Transfer for ep0 data phase
>>>>>>     usb: dwc3: gadget: Delay issuing End Transfer
>>>>>>
>>>>>>    drivers/usb/dwc3/ep0.c    |   2 +-
>>>>>>    drivers/usb/dwc3/gadget.c | 126
>>>>>> ++++++++++++++++++++------------------
>>>>>>    2 files changed, 69 insertions(+), 59 deletions(-)
>>>>>>
>>>>>>
>>>>>> base-commit: 5c29e864999763baec9eedb9ea5bd557aa4cbd77
>>>>>
>>>>> Thanks for this series.  Running the tests w/ the changes now and will
>>>>> debug if I run into any issues.  I will need to run the previous test
>>>>> cases I had as well, since the change removes the GEVNTCOUNT clearing
>>>>> during pullup disable (this was added for some controller halt
>>>>> failures).
>>>>>
>>>>
>>>> Going to summarize some of the things I've found so far:
>>>> 1.  DWC3_EP_DELAY_STOP flag set for EPs:
>>>> The test case being run will have usb ep dequeue running closely in
>>>> parallel to soft disconnect.  There is a chance that we run into
>>>> controller halt due to active EPs, since we are not
>>>> waiting/synchronizing for DWC3_EP_DELAY_STOP to be cleared or complete.
>>>
>>> I sent an update. Can you test it out?
>>>
>>>>
>>>> Attached thinh_newest_delayed_status_causing_ep_stop_delay_flag.txt
>>>> - Force device crash if run/stop routine fails w/ -ETIMEDOUT.
>>>
>>> Can you clarify here? Did you force the crash or did the crash occur due
>>> to the change?
>>>
>> Just injecting a kernel panic if there is an -ETIMEDOUT condition
>> during run/stop clear.  The end of the traces will be at the point of
>> which the error occurred.
>>
>>>> - There is a situation where a function will return delayed_status, and
>>>> we can see "timed out waiting for SETUP phase" print during pullup
>>>> disable.
>>>
>>> It should be fine that the warning gets printed. The programming guide
>>> suggested that the driver should wait for all the control transfers to
>>> complete. This deviates from the programming guide. If it happens often
>>> enough, we may need to increase the timeout.
>>>
>> Yes, agreed.
>>
>>>>
>>>> 2.  Controller halt failure due to non-zero GEVNTCOUNT
>>>> So with this patch series, and removing the GEVNTCOUNT clearing, I'm
>>>> running into controller halt failures again.  When I printed the
>>>> GEVNTCOUNT register at the time of failure, it showed that there were
>>>> several pending events.
>>>
>>> Do you have the log for this? What's the IO delay for each register read
>>> on your platform? I suspect that the polling for halt status is too
>>> quick, we may need to add some delay between polls.
>>>
>> Will try to collect a log for you after adding the new changes (if I
>> run into this).  I tried to increase the number of loops as well, but
>> that didn't help.
>>
> I think the reason for the non-zero GEVNTCOUNT is probably due to the
> fact that we're still getting EP0 events:
> 
> [ 3548.040859][T20051] dwc3 a600000.dwc3: unexpected direction for Data
> Phase
> [ 3548.061282][T20051] dwc3 a600000.dwc3: unexpected direction for Data
> Phase
> [ 3548.071429][T20051] dwc3 a600000.dwc3: unexpected direction for Data
> Phase
> [ 3548.083499][T20051] dwc3 a600000.dwc3: unexpected direction for Data
> Phase
> [ 3548.095546][T20051] dwc3 a600000.dwc3: unexpected direction for Data
> Phase
> [ 3548.105820][T20051] dwc3 a600000.dwc3: unexpected direction for Data
> Phase
> [ 3548.122027][ T2189] dwc3_gadget_run_stop: pullups_connected = 0
> [ 3548.156770][ T2189] GEVENT COUNT = 8
> 
> In the changes proposed, you're blocking the inspect setup API if
> !dwc->connected, but due to ret = -EINVAL, the exit routine will go and
> issue a stall and restart on EP0.  I think your main intention was just
> to ignore it, correct?
> 

No, not just ignoring it. The intention is that while polling for the
halted state, the driver will continue to service any interrupt 
generated by the controller. If it's a control transfer, then the 
controller will respond with a STALL and rejects any new control 
transfer and setup a new TRB for the next setup stage. The interrupt 
handler will clear the GEVNTCOUNT while polling for halted state. The 
expectation here is to poll for the halted state long enough for the 
interrupt handler to come and clear the GEVNTCOUNT before the timeout.

Looks like somehow the polling for the halted state block the irq 
handler:

[ 3548.117872285       0xff828a6ab]   dbg_gadget_giveback: ep7in: req ffffff8041575600 length 0/65536 zsI ==> -108
[ 3548.120646816       0xff82976c3]   dbg_send_ep_cmd: ep8in: cmd 'End Transfer' [110c08] params 00000000 00000000 00000000 --> status: Successful

There's a 30ms gap here. Probably during the polling? (would be good to 
have more register read/write tracepoints)

[ 3548.151314473       0xff83272d7]   event (080001c0): ep0out: Endpoint Command Complete
[ 3548.151760931       0xff8329451]   event (080001c0): ep0out: Endpoint Command Complete
[ 3548.152104577       0xff832ae18]   event (080001c0): ep0out: Endpoint Command Complete
[ 3548.152452441       0xff832c82e]   event (080001c0): ep0out: Endpoint Command Complete
[ 3548.152842702       0xff832e574]   event (080001c0): ep0out: Endpoint Command Complete
[ 3548.153250150       0xff8330403]   event (080001c0): ep0out: Endpoint Command Complete
[ 3548.153657285       0xff833228b]   event (080001c0): ep0out: Endpoint Command Complete


Can you add msleep(1) in between the polling:

diff --git a/drivers/usb/dwc3/gadget.c b/drivers/usb/dwc3/gadget.c
index ee8e8974302d..9c0d61a2dd82 100644
--- a/drivers/usb/dwc3/gadget.c
+++ b/drivers/usb/dwc3/gadget.c
@@ -2814,6 +2814,8 @@ static int dwc3_gadget_run_stop(struct dwc3 *dwc, int is_on, int suspend)
        dwc3_gadget_dctl_write_safe(dwc, reg);
 
        do {
+               msleep(1);
+
                reg = dwc3_readl(dwc->regs, DWC3_DSTS);
                reg &= DWC3_DSTS_DEVCTRLHLT;
        } while (--timeout && !(!is_on ^ !reg));


(If this works, we can slightly modify this logic to save 1ms)

BTW, is there a problem with enabling other tracepoint events? I have to 
make some guesses when reading the log.

Thanks,
Thinh