On 6/10/2021 11:21 AM, Wesley Cheng wrote:
>
>
> On 6/10/2021 4:09 AM, Felipe Balbi wrote:
>> Wesley Cheng <wcheng@xxxxxxxxxxxxxx> writes:
>>
>>> Current sequence utilizes dwc3_gadget_disable_irq() alongside
>>> synchronize_irq() to ensure that no further DWC3 events are generated.
>>> However, the dwc3_gadget_disable_irq() API only disables device
>>> specific events. Endpoint events can still be generated. Briefly
>>> disable the interrupt line, so that the cleanup code can run to
>>> prevent device and endpoint events. (i.e. __dwc3_gadget_stop() and
>>> dwc3_stop_active_transfers() respectively)
>>>
>>> Without doing so, it can lead to both the interrupt handler and the
>>> pullup disable routine both writing to the GEVNTCOUNT register, which
>>> will cause an incorrect count being read from future interrupts.
>>>
>>> Fixes: ae7e86108b12 ("usb: dwc3: Stop active transfers before halting the controller")
>>> Signed-off-by: Wesley Cheng <wcheng@xxxxxxxxxxxxxx>
>>> ---
>>> drivers/usb/dwc3/gadget.c | 11 +++++------
>>> 1 file changed, 5 insertions(+), 6 deletions(-)
>>>
>>> diff --git a/drivers/usb/dwc3/gadget.c b/drivers/usb/dwc3/gadget.c
>>> index 49ca5da..89aa9ac 100644
>>> --- a/drivers/usb/dwc3/gadget.c
>>> +++ b/drivers/usb/dwc3/gadget.c
>>> @@ -2260,13 +2260,10 @@ static int dwc3_gadget_pullup(struct usb_gadget *g, int is_on)
>>> }
>>>
>>> /*
>>> - * Synchronize any pending event handling before executing the controller
>>> - * halt routine.
>>> + * Synchronize and disable any further event handling while controller
>>> + * is being enabled/disabled.
>>> */
>>> - if (!is_on) {
>>> - dwc3_gadget_disable_irq(dwc);
>>> - synchronize_irq(dwc->irq_gadget);
>>> - }
>>> + disable_irq(dwc->irq_gadget);
>>>
>>> spin_lock_irqsave(&dwc->lock, flags);
>>
>> spin_lock_irqsave() is already disabling interrupt, right? Why do we
>> need another call to disable_irq()?
>>
>
> Hi Felipe,
>
> Yes, I remember you brought up that point as well before. So when I
> checked the logs (USB and scheduler ftrace) for this issue, I clearly
> saw that we were handling a soft disconnect on CPU3 and then an DWC3 IRQ
> being scheduled into CPU0. Last time we discussed, I mentioned that
> spin_lock_irqsave() only disables interrupts on that particular CPU the
> thread is running on.
>
Hi Felipe,
Let me share the ftrace snippets as well:
USB FTRACE:
<idle>-0 [002] 304.567900: dwc3_gadget_ep_cmd name=ep0out
cmd=1030 param0=0 param1=4026523648 param2=0 cmd_status=0
<idle>-0 [004] 304.583225: dwc3_gadget_ep_cmd name=ep1out
cmd=134152 param0=0 param1=0 param2=0 cmd_status=0
//We don't have any logging in pullup disable, but this is when that
occurs, as we start to see -ESHUTDOWN statuses due to stop active
transfer.
<idle>-0 [004] 304.583237: dwc3_gadget_giveback name=ep1out
req=1243650560 actual=0 length=16384 status=4294967188 zero=0
short_not_ok=0 no_interrupt=0
<idle>-0 [004] 304.583275: dwc3_gadget_giveback name=ep1out
req=1243645440 actual=0 length=16384 status=4294967188 zero=0
short_not_ok=0 no_interrupt=0
<idle>-0 [004] 304.583282: dwc3_gadget_giveback name=ep1out
req=1243648256 actual=0 length=16384 status=4294967188 zero=0
short_not_ok=0 no_interrupt=0
<idle>-0 [004] 304.583312: dwc3_gadget_giveback name=ep1out
req=4075146240 actual=0 length=16384 status=4294967188 zero=0
short_not_ok=0 no_interrupt=0
...
//USB gadget disconnect is printed AFTER the pullup(0) routine is complete.
<idle>-0 [004] 304.584240: usb_gadget_disconnect speed=3
max_speed=6 state=7 mA=500 sg_supported=1 is_otg=0
is_a_peripheral=0 b_hnp_enable=0 a_hnp_support=0
hnp_polling_support=0 host_request_flag=0 quirk_ep_out_aligned_size=0
quirk_altset_not_supp=0 quirk_stall_not_supp=0 quirk_zlp_not_supp=0
is_selfpowered=0 deactivated=0 connected=1 ret=4294967186
---------------------------------------------------------
CPU2 SCHED FTRACE:
kworker/u16:5-192 [002] 304.583354: irq_handler_entry irq=343
name=dwc3-msm
kworker/u16:5-192 [002] 304.583356: irq_handler_exit irq=343
ret=0
kworker/u16:5-192 [002] 304.583358: irq_handler_entry irq=343
name=dwc3
kworker/u16:5-192 [002] 304.583366: irq_handler_exit irq=343
ret=2
kworker/u16:5-192 [002] 304.583377: sched_wakeup
comm=irq/343-dwc3 pid=20174 prio=100 success=1 target_cpu=2
kworker/u16:5-192 [002] 304.583411: sched_switch:
prev_comm=kworker/u16:5 prev_pid=192 prev_prio=120 prev_state=R ==>
next_comm=irq/343-dwc3 next_pid=20174 next_prio=100
irq/343-dwc3-20174 [002] 304.583454: irq_handler_entry irq=343
name=dwc3-msm
irq/343-dwc3-20174 [002] 304.583455: irq_handler_exit irq=343
ret=0
irq/343-dwc3-20174 [002] 304.583458: irq_handler_entry irq=343
name=dwc3
irq/343-dwc3-20174 [002] 304.583465: irq_handler_exit irq=343
ret=2
So if we assume that the point of error happens @ 304.567900 due to the
below points:
- DWC3 pullup disable routine synchronized IRQs (w/ previous logic)
before calling stop active transfers.
- DWC3 request statuses shows ESHUTDOWN, which occurs during stop active
transfer, as we call giveback w/ that error code
Then we can see that on CPU2, we're still getting DWC3 core IRQs, and
DWC3 IRQ handler is returning --> 2, which is IRQ_WAKE_THREAD.
Thanks
Wesley Cheng
--
The Qualcomm Innovation Center, Inc. is a member of the Code Aurora Forum,
a Linux Foundation Collaborative Project
