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

Message ID	cover.1650593829.git.Thinh.Nguyen@synopsys.com
Headers	show Return-Path: <linux-usb-owner@kernel.org> Date: Thu, 21 Apr 2022 19:22:24 -0700 Message-Id: <cover.1650593829.git.Thinh.Nguyen@synopsys.com> From: Thinh Nguyen <Thinh.Nguyen@synopsys.com> Subject: [PATCH 0/6] usb: dwc3: gadget: Rework pullup To: Felipe Balbi <balbi@kernel.org>, Greg Kroah-Hartman <gregkh@linuxfoundation.org>, linux-usb@vger.kernel.org Cc: John Youn <John.Youn@synopsys.com>, Thinh Nguyen <Thinh.Nguyen@synopsys.com>, Wesley Cheng <quic_wcheng@quicinc.com> Precedence: bulk
Series	usb: dwc3: gadget: Rework pullup \| expand [0/6] usb: dwc3: gadget: Rework pullup [2/6] usb: dwc3: gadget: Refactor pullup() [4/6] usb: dwc3: ep0: Don't prepare beyond Setup stage [6/6] usb: dwc3: gadget: Delay issuing End Transfer

Thinh Nguyen April 22, 2022, 2:22 a.m. UTC

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

Thinh Nguyen May 24, 2022, 12:30 a.m. UTC | #1

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?

> - 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.

> 
> 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.

If you have the log, can you also enable register read/write to see the
delta time?

> 
> Have a few changes I am evaluating to push up, but if you have any
> inputs, please feel free to let me know, and I can add it into my testing.
> 

Thanks for all the tests!

Thinh

Wesley Cheng May 24, 2022, 1:34 a.m. UTC | #2

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.

> If you have the log, can you also enable register read/write to see the
> delta time?
> 
I'll need to collect a set of logs for this.  Will add the register 
read/write log also.

Thanks
Wesley Cheng

Wesley Cheng May 25, 2022, 5:50 p.m. UTC | #3

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?

static void dwc3_ep0_inspect_setup(struct dwc3 *dwc,
		const struct dwc3_event_depevt *event)
{
	struct usb_ctrlrequest *ctrl = (void *) dwc->ep0_trb;
	int ret = -EINVAL;
	u32 len;

	if (!dwc->gadget_driver || !dwc->connected)
		goto out;
...
out:
	if (ret < 0)
		dwc3_ep0_stall_and_restart(dwc);
}

Thanks
Wesley Cheng
[ 3543.665647844       0xff31049d6]   dbg_ep_queue: ep7in: req ffffff8042dca200 length 0/65536 zsI ==> -115
[ 3543.665876855       0xff3105b03]   dbg_prepare: ep7in: trb ffffffc01ce2b520 (E83:D0) buf 00000000ef550000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.666146646       0xff3106f40]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.685383469       0xff3161202]   dbg_ep_queue: ep7in: req ffffff80442ecc00 length 0/65536 zsI ==> -115
[ 3543.685611230       0xff3162318]   dbg_prepare: ep7in: trb ffffffc01ce2b530 (E84:D0) buf 00000000ee970000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.685873313       0xff31636bf]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.686912324       0xff31684ac]   dbg_ep_queue: ep7in: req ffffff87b0b06800 length 0/65536 zsI ==> -115
[ 3543.687196386       0xff31699fa]   dbg_prepare: ep7in: trb ffffffc01ce2b540 (E85:D0) buf 00000000ebb20000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.687459407       0xff316adb4]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.707405501       0xff31c85a9]   dbg_ep_queue: ep7in: req ffffff87b0b07c00 length 0/65536 zsI ==> -115
[ 3543.707667115       0xff31c9949]   dbg_prepare: ep7in: trb ffffffc01ce2b550 (E86:D0) buf 00000000eb5e0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.707942115       0xff31cade8]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.721826751       0xff320bf41]   dbg_ep_queue: ep7in: req ffffff87b0b06e00 length 0/65536 zsI ==> -115
[ 3543.722128001       0xff320d5d9]   dbg_prepare: ep7in: trb ffffffc01ce2b560 (E87:D0) buf 00000000ecc50000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.722405657       0xff320eaac]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.723483834       0xff3213b89]   dbg_ep_queue: ep7in: req ffffff804d372a00 length 0/65536 zsI ==> -115
[ 3543.723716751       0xff3214d02]   dbg_prepare: ep7in: trb ffffffc01ce2b570 (E88:D0) buf 00000000ebff0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.723991542       0xff321619d]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.726934667       0xff3223e59]   dbg_ep_queue: ep7in: req ffffff8041579a00 length 0/65536 zsI ==> -115
[ 3543.727024824       0xff322451c]   dbg_prepare: ep7in: trb ffffffc01ce2b580 (E89:D0) buf 00000000eabf0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.727134980       0xff3224d5f]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.729622324       0xff32307ec]   dbg_ep_queue: ep7in: req ffffff8041579400 length 0/65536 zsI ==> -115
[ 3543.729737063       0xff3231087]   dbg_prepare: ep7in: trb ffffffc01ce2b590 (E90:D0) buf 00000000eb600000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.729862011       0xff32319e6]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.736333678       0xff324ff47]   dbg_ep_queue: ep7in: req ffffff8041fbb000 length 0/65536 zsI ==> -115
[ 3543.736575709       0xff325116e]   dbg_prepare: ep7in: trb ffffffc01ce2b5a0 (E91:D0) buf 00000000ec2b0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.736839511       0xff3252537]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.737918678       0xff3257626]   dbg_ep_queue: ep7in: req ffffff802489b000 length 0/65536 zsI ==> -115
[ 3543.738149928       0xff325877f]   dbg_prepare: ep7in: trb ffffffc01ce2b5b0 (E92:D0) buf 00000000ede00000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.738409511       0xff3259af7]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.739479042       0xff325eb2e]   dbg_ep_queue: ep7in: req ffffff802489ab00 length 0/65536 zsI ==> -115
[ 3543.739772792       0xff3260135]   dbg_prepare: ep7in: trb ffffffc01ce2b5c0 (E93:D0) buf 00000000eac20000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.740043730       0xff3261587]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.741843105       0xff3269c7b]   dbg_ep_queue: ep7in: req ffffff87dd69c200 length 0/65536 zsI ==> -115
[ 3543.742136334       0xff326b27a]   dbg_prepare: ep7in: trb ffffffc01ce2b5d0 (E94:D0) buf 00000000ee190000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.742396647       0xff326c600]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.744603990       0xff3276b8d]   dbg_ep_queue: ep7in: req ffffff87dd69c900 length 0/65536 zsI ==> -115
[ 3543.744840553       0xff3277d4a]   dbg_prepare: ep7in: trb ffffffc01ce2b5e0 (E95:D0) buf 00000000ece40000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.745105136       0xff3279123]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.746174980       0xff327e160]   dbg_ep_queue: ep7in: req ffffff87dd69de00 length 0/65536 zsI ==> -115
[ 3543.746413417       0xff327f341]   dbg_prepare: ep7in: trb ffffffc01ce2b5f0 (E96:D0) buf 00000000efc30000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.746680761       0xff328074f]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.748428105       0xff3288a5c]   dbg_ep_queue: ep7in: req ffffff87dd69d100 length 0/65536 zsI ==> -115
[ 3543.748713053       0xff3289fbb]   dbg_prepare: ep7in: trb ffffffc01ce2b600 (E97:D0) buf 00000000eb3d0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.748978678       0xff328b3a7]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.750055970       0xff3290473]   dbg_ep_queue: ep7in: req ffffff87dd69ce00 length 0/65536 zsI ==> -115
[ 3543.750300292       0xff32916c6]   dbg_prepare: ep7in: trb ffffffc01ce2b610 (E98:D0) buf 00000000efbd0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.750557740       0xff3292a14]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.752304980       0xff329ad20]   dbg_ep_queue: ep7in: req ffffff87dd69d500 length 0/65536 zsI ==> -115
[ 3543.752598209       0xff329c31e]   dbg_prepare: ep7in: trb ffffffc01ce2b620 (E99:D0) buf 00000000ed640000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.752888678       0xff329d8e6]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.753951803       0xff32a28a3]   dbg_ep_queue: ep7in: req ffffff87dd69d600 length 0/65536 zsI ==> -115
[ 3543.754241490       0xff32a3e5d]   dbg_prepare: ep7in: trb ffffffc01ce2b630 (E100:D0) buf 00000000ed050000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.754505553       0xff32a522a]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.756346543       0xff32adc3e]   dbg_ep_queue: ep7in: req ffffff87dd69c100 length 0/65536 zsI ==> -115
[ 3543.756595136       0xff32aeee2]   dbg_prepare: ep7in: trb ffffffc01ce2b640 (E101:D0) buf 00000000ef1a0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.756850449       0xff32b0209]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.757988886       0xff32b576b]   dbg_ep_queue: ep7in: req ffffff87dd69c400 length 0/65536 zsI ==> -115
[ 3543.758278574       0xff32b6d25]   dbg_prepare: ep7in: trb ffffffc01ce2b650 (E102:D0) buf 00000000ee460000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.758534303       0xff32b8053]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.760340553       0xff32c07cb]   dbg_ep_queue: ep7in: req ffffff87dd69cb00 length 0/65536 zsI ==> -115
[ 3543.760629824       0xff32c1d7c]   dbg_prepare: ep7in: trb ffffffc01ce2b660 (E103:D0) buf 00000000ec550000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.760899199       0xff32c31b1]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.762069928       0xff32c897f]   dbg_ep_queue: ep7in: req ffffff87dd69df00 length 0/65536 zsI ==> -115
[ 3543.762304043       0xff32c9b0d]   dbg_prepare: ep7in: trb ffffffc01ce2b670 (E104:D0) buf 00000000ec560000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.762561647       0xff32cae60]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.764321386       0xff32d325b]   dbg_ep_queue: ep7in: req ffffff87dd69da00 length 0/65536 zsI ==> -115
[ 3543.764560240       0xff32d4444]   dbg_prepare: ep7in: trb ffffffc01ce2b680 (E105:D0) buf 00000000ec570000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.764835501       0xff32d58e9]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.765905032       0xff32da920]   dbg_ep_queue: ep7in: req ffffff87dd69c000 length 0/65536 zsI ==> -115
[ 3543.766140449       0xff32dbac9]   dbg_prepare: ep7in: trb ffffffc01ce2b690 (E106:D0) buf 00000000ebb30000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.766402793       0xff32dce75]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.768196907       0xff32e5505]   dbg_ep_queue: ep7in: req ffffff87dd69c600 length 0/65536 zsI ==> -115
[ 3543.768438522       0xff32e6723]   dbg_prepare: ep7in: trb ffffffc01ce2b6a0 (E107:D0) buf 00000000ecc70000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.768698834       0xff32e7aaa]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.769772011       0xff32ecb27]   dbg_ep_queue: ep7in: req ffffff87dd69dd00 length 0/65536 zsI ==> -115
[ 3543.770002480       0xff32edc6f]   dbg_prepare: ep7in: trb ffffffc01ce2b6b0 (E108:D0) buf 00000000eec50000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.770268834       0xff32ef069]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.771371438       0xff32f431b]   dbg_ep_queue: ep7in: req ffffff87dd69d800 length 0/65536 zsI ==> -115
[ 3543.771609772       0xff32f54fc]   dbg_prepare: ep7in: trb ffffffc01ce2b6c0 (E109:D0) buf 00000000eec70000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.771867636       0xff32f6853]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.773507793       0xff32fe355]   dbg_ep_queue: ep7in: req ffffff880668f100 length 0/65536 zsI ==> -115
[ 3543.773734824       0xff32ff45d]   dbg_prepare: ep7in: trb ffffffc01ce2b6d0 (E110:D0) buf 00000000ef020000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.773999980       0xff3300840]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.775035501       0xff33055e9]   dbg_ep_queue: ep7in: req ffffff880668f700 length 0/65536 zsI ==> -115
[ 3543.775256647       0xff3306680]   dbg_prepare: ep7in: trb ffffffc01ce2b6e0 (E111:D0) buf 00000000e9200000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.775513209       0xff33079be]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.777514772       0xff3310fdc]   dbg_ep_queue: ep7in: req ffffff880668e800 length 0/65536 zsI ==> -115
[ 3543.777757272       0xff331220b]   dbg_prepare: ep7in: trb ffffffc01ce2b6f0 (E112:D0) buf 00000000eba80000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.778020136       0xff33135c3]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.779196022       0xff3318df4]   dbg_ep_queue: ep7in: req ffffff803afdef00 length 0/65536 zsI ==> -115
[ 3543.779435761       0xff3319fef]   dbg_prepare: ep7in: trb ffffffc01ce2b700 (E113:D0) buf 00000000ed320000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.779696595       0xff331b37f]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.782044824       0xff332639d]   dbg_ep_queue: ep7in: req ffffff803afde000 length 0/65536 zsI ==> -115
[ 3543.782274772       0xff33274db]   dbg_prepare: ep7in: trb ffffffc01ce2b710 (E114:D0) buf 00000000ec2e0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.782542532       0xff33288f1]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.792565241       0xff33578a5]   dbg_ep_queue: ep7in: req ffffff87faca8c00 length 0/65536 zsI ==> -115
[ 3543.792803105       0xff3358a7b]   dbg_prepare: ep7in: trb ffffffc01ce2b720 (E115:D0) buf 00000000ec2d0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.793301959       0xff335afe6]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.811461074       0xff33b01d5]   dbg_ep_queue: ep7in: req ffffff80255aa500 length 0/65536 zsI ==> -115
[ 3543.811724251       0xff33b1592]   dbg_prepare: ep7in: trb ffffffc01ce2b730 (E116:D0) buf 00000000ebbf0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.811981126       0xff33b28d5]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.830350032       0xff3408a80]   dbg_ep_queue: ep7in: req ffffff8040d34c00 length 0/65536 zsI ==> -115
[ 3543.830591751       0xff3409ca1]   dbg_prepare: ep7in: trb ffffffc01ce2b740 (E117:D0) buf 00000000e74a0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.830858522       0xff340b0a3]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.853519355       0xff3475433]   dbg_ep_queue: ep7in: req ffffff8040d34200 length 0/65536 zsI ==> -115
[ 3543.853759199       0xff3476630]   dbg_prepare: ep7in: trb ffffffc01ce2b750 (E118:D0) buf 00000000ef1e0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.854022584       0xff34779f1]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.855212324       0xff347d32c]   dbg_ep_queue: ep7in: req ffffff8040d34500 length 0/65536 zsI ==> -115
[ 3543.855428001       0xff347e359]   dbg_prepare: ep7in: trb ffffffc01ce2b760 (E119:D0) buf 00000000ecaf0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.855694355       0xff347f753]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.887188939       0xff351316b]   dbg_ep_queue: ep7in: req ffffff8040d35200 length 0/65536 zsI ==> -115
[ 3543.887303001       0xff35139f9]   dbg_prepare: ep7in: trb ffffffc01ce2b770 (E120:D0) buf 00000000ea7f0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.887420241       0xff35142c4]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.888246282       0xff35180b9]   dbg_ep_queue: ep7in: req ffffff87d2bdd300 length 0/65536 zsI ==> -115
[ 3543.888351022       0xff3518893]   dbg_prepare: ep7in: trb ffffffc01ce2b780 (E121:D0) buf 00000000e91e0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.888474512       0xff35191d7]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.888969407       0xff351b6f4]   dbg_ep_queue: ep7in: req ffffff87d2bddd00 length 0/65536 zsI ==> -115
[ 3543.889069251       0xff351be71]   dbg_prepare: ep7in: trb ffffffc01ce2b790 (E122:D0) buf 00000000eb6b0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.889192845       0xff351c7b6]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.893088366       0xff352ebe0]   dbg_ep_queue: ep7in: req ffffff87d2bdc300 length 0/65536 zsI ==> -115
[ 3543.893193262       0xff352f3be]   dbg_prepare: ep7in: trb ffffffc01ce2b7a0 (E123:D0) buf 00000000ed730000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.893312845       0xff352fcb6]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.893816439       0xff353227b]   dbg_ep_queue: ep7in: req ffffff87d2bdcf00 length 0/65536 zsI ==> -115
[ 3543.893948001       0xff3532c59]   dbg_prepare: ep7in: trb ffffffc01ce2b7b0 (E124:D0) buf 00000000edbe0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.894056960       0xff3533485]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.894488366       0xff35354e0]   dbg_ep_queue: ep7in: req ffffff87d2bdc600 length 0/65536 zsI ==> -115
[ 3543.894570658       0xff3535b0c]   dbg_prepare: ep7in: trb ffffffc01ce2b7c0 (E125:D0) buf 00000000e7020000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.894669564       0xff3536277]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.895074668       0xff35380d9]   dbg_ep_queue: ep7in: req ffffff87d2bdcd00 length 0/65536 zsI ==> -115
[ 3543.895153522       0xff35386c3]   dbg_prepare: ep7in: trb ffffffc01ce2b7d0 (E126:D0) buf 00000000e7030000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.895255345       0xff3538e66]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.896041855       0xff353c963]   dbg_ep_queue: ep7in: req ffffff87d2bdde00 length 0/65536 zsI ==> -115
[ 3543.896128678       0xff353cfe6]   dbg_prepare: ep7in: trb ffffffc01ce2b7e0 (E127:D0) buf 00000000e7040000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.896246074       0xff353d8b4]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.896739824       0xff353fdbc]   dbg_ep_queue: ep7in: req ffffff804167cb00 length 0/65536 zsI ==> -115
[ 3543.896849408       0xff35405f4]   dbg_prepare: ep7in: trb ffffffc01ce2b7f0 (E128:D0) buf 00000000e7050000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.896969095       0xff3540eef]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.897454043       0xff354334d]   dbg_ep_queue: ep7in: req ffffff804167dc00 length 0/65536 zsI ==> -115
[ 3543.897556908       0xff3543b04]   dbg_prepare: ep7in: trb ffffffc01ce2b800 (E129:D0) buf 00000000e7060000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.897676699       0xff3544400]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.898107272       0xff354644b]   dbg_ep_queue: ep7in: req ffffff804167d500 length 0/65536 zsI ==> -115
[ 3543.898208262       0xff3546bde]   dbg_prepare: ep7in: trb ffffffc01ce2b810 (E130:D0) buf 00000000e7070000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.898325449       0xff35474a8]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.898817064       0xff3549987]   dbg_ep_queue: ep7in: req ffffff804167c800 length 0/65536 zsI ==> -115
[ 3543.898914095       0xff354a0ce]   dbg_prepare: ep7in: trb ffffffc01ce2b820 (E131:D0) buf 00000000e7080000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.899035345       0xff354a9e6]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.976658366       0xff36b67a0]   dbg_ep_queue: ep7in: req ffffff87c5713f00 length 0/65536 zsI ==> -115
[ 3543.976905502       0xff36b7a29]   dbg_prepare: ep7in: trb ffffffc01ce2b830 (E132:D0) buf 00000000ef5f0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.977163106       0xff36b8d7b]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.983350606       0xff36d5d8b]   dbg_ep_queue: ep7in: req ffffff87c5712300 length 0/65536 zsI ==> -115
[ 3543.983560658       0xff36d6d4c]   dbg_prepare: ep7in: trb ffffffc01ce2b840 (E133:D0) buf 00000000ec0f0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.983807793       0xff36d7fd5]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.985431699       0xff36df9a0]   dbg_ep_queue: ep7in: req ffffff87c5712200 length 0/65536 zsI ==> -115
[ 3543.985652585       0xff36e0a31]   dbg_prepare: ep7in: trb ffffffc01ce2b850 (E134:D0) buf 00000000ebbd0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.985914252       0xff36e1dd1]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3543.986873418       0xff36e65c1]   dbg_ep_queue: ep7in: req ffffff87c5713a00 length 0/65536 zsI ==> -115
[ 3543.987045866       0xff36e72b0]   dbg_prepare: ep7in: trb ffffffc01ce2b860 (E135:D0) buf 00000000eef30000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3543.987262481       0xff36e82ef]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.028316127       0xff37a89f5]   dbg_ep_queue: ep7in: req ffffff87c5712500 length 0/65536 zsI ==> -115
[ 3544.028408106       0xff37a90db]   dbg_prepare: ep7in: trb ffffffc01ce2b870 (E136:D0) buf 00000000ee270000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.028508002       0xff37a9859]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.028911387       0xff37ab69a]   dbg_ep_queue: ep7in: req ffffff87a64d2f00 length 0/65536 zsI ==> -115
[ 3544.028990554       0xff37abc8a]   dbg_prepare: ep7in: trb ffffffc01ce2b880 (E137:D0) buf 00000000ec420000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.029089877       0xff37ac3fd]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.029447012       0xff37adec6]   dbg_ep_queue: ep7in: req ffffff87a64d2700 length 0/65536 zsI ==> -115
[ 3544.029522481       0xff37ae46f]   dbg_prepare: ep7in: trb ffffffc01ce2b890 (E138:D0) buf 00000000ee990000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.029609877       0xff37aeafd]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.029958262       0xff37b051e]   dbg_ep_queue: ep7in: req ffffff87a64d3c00 length 0/65536 zsI ==> -115
[ 3544.030053575       0xff37b0c44]   dbg_prepare: ep7in: trb ffffffc01ce2b8a0 (E139:D0) buf 00000000ee6e0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.030162950       0xff37b1478]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.030595554       0xff37b34ea]   dbg_ep_queue: ep7in: req ffffff804143fd00 length 0/65536 zsI ==> -115
[ 3544.030681856       0xff37b3b63]   dbg_prepare: ep7in: trb ffffffc01ce2b8b0 (E140:D0) buf 00000000ef730000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.030789148       0xff37b436f]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.031176491       0xff37b607d]   dbg_ep_queue: ep7in: req ffffff804162f400 length 0/65536 zsI ==> -115
[ 3544.031252481       0xff37b662f]   dbg_prepare: ep7in: trb ffffffc01ce2b8c0 (E141:D0) buf 00000000ef720000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.031339408       0xff37b6cb4]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.032146543       0xff37ba93d]   dbg_ep_queue: ep7in: req ffffff87d5d17200 length 0/65536 zsI ==> -115
[ 3544.032249304       0xff37bb0f2]   dbg_prepare: ep7in: trb ffffffc01ce2b8d0 (E142:D0) buf 00000000ef710000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.032372637       0xff37bba32]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.032828470       0xff37bdc62]   dbg_ep_queue: ep7in: req ffffff87d5d17800 length 0/65536 zsI ==> -115
[ 3544.032916439       0xff37be2fb]   dbg_prepare: ep7in: trb ffffffc01ce2b8e0 (E143:D0) buf 00000000eeb60000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.033015762       0xff37bea6e]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.033425710       0xff37c092d]   dbg_ep_queue: ep7in: req ffffff87d5d16d00 length 0/65536 zsI ==> -115
[ 3544.033514408       0xff37c0fd4]   dbg_prepare: ep7in: trb ffffffc01ce2b8f0 (E144:D0) buf 00000000ed890000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.033621127       0xff37c17d5]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.034038418       0xff37c3721]   dbg_ep_queue: ep7in: req ffffff87d5d17000 length 0/65536 zsI ==> -115
[ 3544.034114668       0xff37c3cd9]   dbg_prepare: ep7in: trb ffffffc01ce2b900 (E145:D0) buf 00000000eba20000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.034213314       0xff37c443f]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.034618366       0xff37c62a0]   dbg_ep_queue: ep7in: req ffffff87d5d16200 length 0/65536 zsI ==> -115
[ 3544.034699564       0xff37c68b7]   dbg_prepare: ep7in: trb ffffffc01ce2b910 (E146:D0) buf 00000000ed860000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.034797585       0xff37c7011]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.035160085       0xff37c8b41]   dbg_ep_queue: ep7in: req ffffff87d5d17300 length 0/65536 zsI ==> -115
[ 3544.035233210       0xff37c90bd]   dbg_prepare: ep7in: trb ffffffc01ce2b920 (E147:D0) buf 00000000ee160000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.035323887       0xff37c978a]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.094064981       0xff38dcd1f]   dbg_ep_queue: ep7in: req ffffff87d5d17100 length 0/65536 zsI ==> -115
[ 3544.094303106       0xff38ddefb]   dbg_prepare: ep7in: trb ffffffc01ce2b930 (E148:D0) buf 00000000ee150000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.094558366       0xff38df220]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.096294044       0xff38e744e]   dbg_ep_queue: ep7in: req ffffff87d0b9c600 length 0/65536 zsI ==> -115
[ 3544.096546960       0xff38e8745]   dbg_prepare: ep7in: trb ffffffc01ce2b940 (E149:D0) buf 00000000edc80000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.096790710       0xff38e998d]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.097747689       0xff38ee153]   dbg_ep_queue: ep7in: req ffffff803af47700 length 0/65536 zsI ==> -115
[ 3544.097933939       0xff38eef4b]   dbg_prepare: ep7in: trb ffffffc01ce2b950 (E150:D0) buf 00000000ee9a0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.098192585       0xff38f02b1]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.099084096       0xff38f458e]   dbg_ep_queue: ep7in: req ffffff882974d100 length 0/65536 zsI ==> -115
[ 3544.099250346       0xff38f5206]   dbg_prepare: ep7in: trb ffffffc01ce2b960 (E151:D0) buf 00000000ef100000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.099467064       0xff38f6247]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.100863002       0xff38fcaf9]   dbg_ep_queue: ep7in: req ffffff882974c200 length 0/65536 zsI ==> -115
[ 3544.101026856       0xff38fd743]   dbg_prepare: ep7in: trb ffffffc01ce2b970 (E152:D0) buf 00000000ec5f0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.101219148       0xff38fe5b0]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.102063679       0xff3902506]   dbg_ep_queue: ep7in: req ffffff87b728cb00 length 0/65536 zsI ==> -115
[ 3544.102281908       0xff3903564]   dbg_prepare: ep7in: trb ffffffc01ce2b980 (E153:D0) buf 00000000ec830000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.102520502       0xff3904749]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.160870710       0xff3a15f8d]   dbg_ep_queue: ep7in: req ffffff87b728d000 length 0/65536 zsI ==> -115
[ 3544.161140554       0xff3a173ca]   dbg_prepare: ep7in: trb ffffffc01ce2b990 (E154:D0) buf 00000000eb6f0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.161388002       0xff3a18659]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.162994721       0xff3a1feda]   dbg_ep_queue: ep7in: req ffffff87b728da00 length 0/65536 zsI ==> -115
[ 3544.163190450       0xff3a20d88]   dbg_prepare: ep7in: trb ffffffc01ce2b9a0 (E155:D0) buf 00000000ee4e0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.163443523       0xff3a22083]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.164768679       0xff3a283e7]   dbg_ep_queue: ep7in: req ffffff8041e77c00 length 0/65536 zsI ==> -115
[ 3544.164901075       0xff3a28dd4]   dbg_prepare: ep7in: trb ffffffc01ce2b9b0 (E156:D0) buf 00000000ee4f0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.165050450       0xff3a29908]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.165900138       0xff3a2d8c3]   dbg_ep_queue: ep7in: req ffffff8041e76e00 length 0/65536 zsI ==> -115
[ 3544.166114460       0xff3a2e8d5]   dbg_prepare: ep7in: trb ffffffc01ce2b9c0 (E157:D0) buf 00000000ee500000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.166359460       0xff3a2fb35]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.167367742       0xff3a346d4]   dbg_ep_queue: ep7in: req ffffff8044306100 length 0/65536 zsI ==> -115
[ 3544.167581544       0xff3a356dd]   dbg_prepare: ep7in: trb ffffffc01ce2b9d0 (E158:D0) buf 00000000ed140000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.167842742       0xff3a36a74]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.210368263       0xff3afdfde]   dbg_ep_queue: ep7in: req ffffff8044307000 length 0/65536 zsI ==> -115
[ 3544.210586075       0xff3aff034]   dbg_prepare: ep7in: trb ffffffc01ce2b9e0 (E159:D0) buf 00000000ef320000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.210813106       0xff3b0013b]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.229437690       0xff3b57613]   dbg_ep_queue: ep7in: req ffffff8044307e00 length 0/65536 zsI ==> -115
[ 3544.229611752       0xff3b58321]   dbg_prepare: ep7in: trb ffffffc01ce2b9f0 (E160:D0) buf 00000000ebc10000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.229781596       0xff3b58fde]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.230341856       0xff3b5b9e3]   dbg_ep_queue: ep7in: req ffffff8783b84200 length 0/65536 zsI ==> -115
[ 3544.230438992       0xff3b5c12d]   dbg_prepare: ep7in: trb ffffffc01ce2ba00 (E161:D0) buf 00000000ef560000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.230567065       0xff3b5cac7]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.272648054       0xff3c21eda]   dbg_ep_queue: ep7in: req ffffff8040cc6200 length 0/65536 zsI ==> -115
[ 3544.272869721       0xff3c22f7a]   dbg_prepare: ep7in: trb ffffffc01ce2ba10 (E162:D0) buf 00000000e7330000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.273109252       0xff3c24171]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.274633315       0xff3c2b3bf]   dbg_ep_queue: ep7in: req ffffff8040cc6600 length 0/65536 zsI ==> -115
[ 3544.274851023       0xff3c2c413]   dbg_prepare: ep7in: trb ffffffc01ce2ba20 (E163:D0) buf 00000000eea20000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.275092742       0xff3c2d635]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.276650971       0xff3c34b12]   dbg_ep_queue: ep7in: req ffffff802c6e9300 length 0/65536 zsI ==> -115
[ 3544.276799148       0xff3c3562f]   dbg_prepare: ep7in: trb ffffffc01ce2ba30 (E164:D0) buf 00000000eb690000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.276974200       0xff3c36350]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.277608002       0xff3c392d9]   dbg_ep_queue: ep7in: req ffffff881e595a00 length 0/65536 zsI ==> -115
[ 3544.277769096       0xff3c39eef]   dbg_prepare: ep7in: trb ffffffc01ce2ba40 (E165:D0) buf 00000000eb5c0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.277956180       0xff3c3acf6]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.278778575       0xff3c3eaa4]   dbg_ep_queue: ep7in: req ffffff881e595800 length 0/65536 zsI ==> -115
[ 3544.278985346       0xff3c3fa26]   dbg_prepare: ep7in: trb ffffffc01ce2ba50 (E166:D0) buf 00000000ec490000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.279225919       0xff3c40c31]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.353890190       0xff3d9ec03]   dbg_ep_queue: ep7in: req ffffff881e594d00 length 0/65536 zsI ==> -115
[ 3544.354134201       0xff3d9fe50]   dbg_prepare: ep7in: trb ffffffc01ce2ba60 (E167:D0) buf 00000000eca50000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.354389669       0xff3da1179]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.355410086       0xff3da5e01]   dbg_ep_queue: ep7in: req ffffff804043f900 length 0/65536 zsI ==> -115
[ 3544.355628680       0xff3da6e66]   dbg_prepare: ep7in: trb ffffffc01ce2ba70 (E168:D0) buf 00000000eca40000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.355877430       0xff3da810e]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.358116336       0xff3db28f9]   dbg_ep_queue: ep7in: req ffffff804043f300 length 0/65536 zsI ==> -115
[ 3544.358323680       0xff3db3886]   dbg_prepare: ep7in: trb ffffffc01ce2ba80 (E169:D0) buf 00000000e9290000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.358562221       0xff3db4a6a]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.404537430       0xff3e8c28e]   dbg_ep_queue: ep7in: req ffffff804043f200 length 0/65536 zsI ==> -115
[ 3544.404674513       0xff3e8ccd6]   dbg_prepare: ep7in: trb ffffffc01ce2ba90 (E170:D0) buf 00000000ed780000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.404830919       0xff3e8d891]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.406466909       0xff3e95344]   dbg_ep_queue: ep7in: req ffffff804043f400 length 0/65536 zsI ==> -115
[ 3544.406658315       0xff3e9619f]   dbg_prepare: ep7in: trb ffffffc01ce2baa0 (E171:D0) buf 00000000ed8f0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.406881336       0xff3e97259]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.408466024       0xff3e9e933]   dbg_ep_queue: ep7in: req ffffff885e9ac300 length 0/65536 zsI ==> -115
[ 3544.408656597       0xff3e9f77e]   dbg_prepare: ep7in: trb ffffffc01ce2bab0 (E172:D0) buf 00000000ef9d0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.408902117       0xff3ea09e9]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.409728992       0xff3ea47ec]   dbg_ep_queue: ep7in: req ffffff885e9ace00 length 0/65536 zsI ==> -115
[ 3544.409938211       0xff3ea579e]   dbg_prepare: ep7in: trb ffffffc01ce2bac0 (E173:D0) buf 00000000eb9f0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.410185607       0xff3ea6a2b]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.418411961       0xff3ecd325]   dbg_ep_queue: ep7in: req ffffff885e9ad800 length 0/65536 zsI ==> -115
[ 3544.418621961       0xff3ece2e5]   dbg_prepare: ep7in: trb ffffffc01ce2bad0 (E174:D0) buf 00000000e6ff0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.418871336       0xff3ecf599]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.422158888       0xff3edec2a]   dbg_ep_queue: ep7in: req ffffff885e9ac900 length 0/65536 zsI ==> -115
[ 3544.422376545       0xff3edfc7d]   dbg_prepare: ep7in: trb ffffffc01ce2bae0 (E175:D0) buf 00000000e6fe0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.422622378       0xff3ee0eed]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.424252274       0xff3ee892b]   dbg_ep_queue: ep7in: req ffffff885e9ac400 length 0/65536 zsI ==> -115
[ 3544.424411128       0xff3ee9515]   dbg_prepare: ep7in: trb ffffffc01ce2baf0 (E176:D0) buf 00000000e6fd0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.424598940       0xff3eea32b]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.425406388       0xff3eedfba]   dbg_ep_queue: ep7in: req ffffff885e9acd00 length 0/65536 zsI ==> -115
[ 3544.425586284       0xff3eeed38]   dbg_prepare: ep7in: trb ffffffc01ce2bb00 (E177:D0) buf 00000000e6fc0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.425808211       0xff3eefddd]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.426772013       0xff3ef4626]   dbg_ep_queue: ep7in: req ffffff8042d7ba00 length 0/65536 zsI ==> -115
[ 3544.426949722       0xff3ef537a]   dbg_prepare: ep7in: trb ffffffc01ce2bb10 (E178:D0) buf 00000000eb7c0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.427163836       0xff3ef6389]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.542913003       0xff4114cb9]   dbg_ep_queue: ep7in: req ffffff88605f4300 length 0/65536 zsI ==> -115
[ 3544.543039826       0xff411563c]   dbg_prepare: ep7in: trb ffffffc01ce2bb20 (E179:D0) buf 00000000ef860000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.543161962       0xff4115f65]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.543947066       0xff4119a47]   dbg_ep_queue: ep7in: req ffffff88605f5100 length 0/65536 zsI ==> -115
[ 3544.544039878       0xff411a13d]   dbg_prepare: ep7in: trb ffffffc01ce2bb30 (E180:D0) buf 00000000efc60000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.544157795       0xff411aa15]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.544643628       0xff411ce85]   dbg_ep_queue: ep7in: req ffffff88605f4600 length 0/65536 zsI ==> -115
[ 3544.544746441       0xff411d63c]   dbg_prepare: ep7in: trb ffffffc01ce2bb40 (E181:D0) buf 00000000eeec0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.544869305       0xff411df72]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.545353368       0xff41203c0]   dbg_ep_queue: ep7in: req ffffff88605f5a00 length 0/65536 zsI ==> -115
[ 3544.545449618       0xff4120af8]   dbg_prepare: ep7in: trb ffffffc01ce2bb50 (E182:D0) buf 00000000eeeb0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.545566337       0xff41213b9]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.546050972       0xff4123812]   dbg_ep_queue: ep7in: req ffffff88605f5700 length 0/65536 zsI ==> -115
[ 3544.546154878       0xff4123fdd]   dbg_prepare: ep7in: trb ffffffc01ce2bb60 (E183:D0) buf 00000000eeea0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.546271701       0xff41248a0]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.546736284       0xff4126b79]   dbg_ep_queue: ep7in: req ffffff88605f4000 length 0/65536 zsI ==> -115
[ 3544.546837847       0xff4127316]   dbg_prepare: ep7in: trb ffffffc01ce2bb70 (E184:D0) buf 00000000ee5e0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.546951649       0xff4127b9f]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.548436597       0xff412eafe]   dbg_ep_queue: ep7in: req ffffff88605f5f00 length 0/65536 zsI ==> -115
[ 3544.548537170       0xff412f289]   dbg_prepare: ep7in: trb ffffffc01ce2bb80 (E185:D0) buf 00000000ef610000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.548654566       0xff412fb57]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.549122951       0xff4131e78]   dbg_ep_queue: ep7in: req ffffff88605f4d00 length 0/65536 zsI ==> -115
[ 3544.549219305       0xff41325b2]   dbg_prepare: ep7in: trb ffffffc01ce2bb90 (E186:D0) buf 00000000ef620000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.549340087       0xff4132ec1]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.549817274       0xff413528b]   dbg_ep_queue: ep7in: req ffffff804d199100 length 0/65536 zsI ==> -115
[ 3544.549913472       0xff41359c2]   dbg_prepare: ep7in: trb ffffffc01ce2bba0 (E187:D0) buf 00000000ec290000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.550034462       0xff41362d5]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.550549878       0xff413897d]   dbg_ep_queue: ep7in: req ffffff804d198b00 length 0/65536 zsI ==> -115
[ 3544.550651701       0xff4139120]   dbg_prepare: ep7in: trb ffffffc01ce2bbb0 (E188:D0) buf 00000000ec140000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.550763420       0xff4139981]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.551288889       0xff413c0ea]   dbg_ep_queue: ep7in: req ffffff87cc07c400 length 0/65536 zsI ==> -115
[ 3544.551388160       0xff413c85c]   dbg_prepare: ep7in: trb ffffffc01ce2bbc0 (E189:D0) buf 00000000ec130000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.551508628       0xff413d165]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.574830087       0xff41aa681]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.576657014       0xff41b2f86]   event (0000c042): ep0in: Transfer Complete (sIL) [Status Phase]
[ 3544.576860139       0xff41b3ec2]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 0/0 zsI ==> 0
[ 3544.577219930       0xff41b59bf]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.577771128       0xff41b8316]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.577965191       0xff41b91a4]   dbg_trace_log_ctrl: Clear Device Feature(Self Powered)
[ 3544.578400087       0xff41bb242]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.578680920       0xff41bc752]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.579192066       0xff41beda8]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.579534149       0xff41c074f]   dbg_gadget_giveback: ep0out: req ffffff87df01d000 length 16/16 zsI ==> 0
[ 3544.579752066       0xff41c17a8]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.579970555       0xff41c280b]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.580830920       0xff41c6892]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.581120816       0xff41c7e4f]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.581657483       0xff41ca690]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.581851233       0xff41cb518]   dbg_trace_log_ctrl: Clear Device Feature(Self Powered)
[ 3544.582258108       0xff41cd39c]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.582533628       0xff41ce846]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.583035555       0xff41d0deb]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.583359983       0xff41d2640]   dbg_gadget_giveback: ep0out: req ffffff87df01d000 length 64/64 zsI ==> 0
[ 3544.583598212       0xff41d381d]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.583889670       0xff41d4df9]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.584571649       0xff41d811f]   dbg_ep_queue: ep7in: req ffffff87cc07db00 length 0/65536 zsI ==> -115
[ 3544.584661076       0xff41d87d4]   dbg_prepare: ep7in: trb ffffffc01ce2bbd0 (E190:D0) buf 00000000e71b0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.584749149       0xff41d8e6f]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.585178160       0xff41dae9c]   dbg_ep_queue: ep7in: req ffffff87cc07c700 length 0/65536 zsI ==> -115
[ 3544.585278108       0xff41db61b]   dbg_prepare: ep7in: trb ffffffc01ce2bbe0 (E191:D0) buf 00000000e71c0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.585389722       0xff41dbe7a]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.585482170       0xff41dc569]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.585731910       0xff41dd825]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.585926233       0xff41de6b7]   dbg_ep_queue: ep7in: req ffffff804163bd00 length 0/65536 zsI ==> -115
[ 3544.586014670       0xff41ded59]   dbg_prepare: ep7in: trb ffffffc01ce2bbf0 (E192:D0) buf 00000000e71d0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.586121389       0xff41df55a]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.586221128       0xff41dfcd5]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.586387118       0xff41e0949]   dbg_trace_log_ctrl: Get String Descriptor(Index = 2, Length = 4)
[ 3544.586557118       0xff41e1608]   dbg_ep_queue: ep7in: req ffffff8041e75f00 length 0/65536 zsI ==> -115
[ 3544.586627639       0xff41e1b52]   dbg_prepare: ep7in: trb ffffffc01ce2bc00 (E193:D0) buf 00000000e71e0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.586702430       0xff41e20ee]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.586894983       0xff41e2f60]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.587066701       0xff41e3c40]   dbg_ep_queue: ep7in: req ffffff8041e75a00 length 0/65536 zsI ==> -115
[ 3544.587135399       0xff41e4167]   dbg_prepare: ep7in: trb ffffffc01ce2bc10 (E194:D0) buf 00000000e71f0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.587224201       0xff41e4810]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.587315555       0xff41e4eeb]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.588028785       0xff41e8468]   dbg_ep_queue: ep7in: req ffffff8041e75c00 length 0/65536 zsI ==> -115
[ 3544.588118472       0xff41e8b22]   dbg_prepare: ep7in: trb ffffffc01ce2bc20 (E195:D0) buf 00000000e7200000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.588216753       0xff41e9281]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.588307847       0xff41e9957]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.588597222       0xff41eaf0a]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 4/4 zsI ==> 0
[ 3544.588738420       0xff41eb9a1]   dbg_ep_queue: ep7in: req ffffff80255db800 length 0/65536 zsI ==> -115
[ 3544.588814930       0xff41ebf5e]   dbg_prepare: ep7in: trb ffffffc01ce2bc30 (E196:D0) buf 00000000e7210000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.588903785       0xff41ec608]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.588988941       0xff41ecc6c]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.589240920       0xff41edf52]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.589425764       0xff41eed2e]   dbg_ep_queue: ep7in: req ffffff80255dae00 length 0/65536 zsI ==> -115
[ 3544.589507274       0xff41ef34b]   dbg_prepare: ep7in: trb ffffffc01ce2bc40 (E197:D0) buf 00000000ee6a0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.589604201       0xff41efa91]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.589692587       0xff41f0131]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.589958108       0xff41f151c]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.590144097       0xff41f230e]   dbg_ep_queue: ep7in: req ffffff80255db100 length 0/65536 zsI ==> -115
[ 3544.590224618       0xff41f2918]   dbg_prepare: ep7in: trb ffffffc01ce2bc50 (E198:D0) buf 00000000ee6b0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.590330295       0xff41f3105]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.590425868       0xff41f3831]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.590585868       0xff41f4431]   dbg_trace_log_ctrl: Get String Descriptor(Index = 0, Length = 255)
[ 3544.590756753       0xff41f5101]   dbg_ep_queue: ep7in: req ffffff80255da800 length 0/65536 zsI ==> -115
[ 3544.590833576       0xff41f56c4]   dbg_prepare: ep7in: trb ffffffc01ce2bc60 (E199:D0) buf 00000000efb80000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.590909930       0xff41f5c7e]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.591107326       0xff41f6b4d]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.591330087       0xff41f7c01]   dbg_ep_queue: ep7in: req ffffff87a6479200 length 0/65536 zsI ==> -115
[ 3544.591419774       0xff41f82bb]   dbg_prepare: ep7in: trb ffffffc01ce2bc70 (E200:D0) buf 00000000ec030000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.591540503       0xff41f8bc9]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.591651753       0xff41f9421]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.592697378       0xff41fe28e]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.592981233       0xff41ff7d7]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 4/4 ZsI ==> 0
[ 3544.593172899       0xff4200638]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.593430608       0xff420198c]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.593853264       0xff420393f]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.594134045       0xff4204e4e]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.594607639       0xff42071d3]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.594779774       0xff4207ebc]   dbg_trace_log_ctrl: Get String Descriptor(Index = 2, Length = 48)
[ 3544.595154410       0xff4209ad4]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.595396233       0xff420acf8]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.596787430       0xff421154f]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.597082170       0xff4212b6a]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 48/48 zsI ==> 0
[ 3544.597279566       0xff4213a38]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.597528524       0xff4214ce3]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.597997587       0xff4217012]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.598281858       0xff4218564]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.598822118       0xff421ade9]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.599013003       0xff421bc3a]   dbg_trace_log_ctrl: Get String Descriptor(Index = 1, Length = 255)
[ 3544.599421649       0xff421dadf]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.599698420       0xff421efa2]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.600817639       0xff4224393]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.601151858       0xff4225ca3]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 18/18 ZsI ==> 0
[ 3544.601330243       0xff4226a05]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.601542639       0xff42279f3]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.601952170       0xff42298a9]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.602253160       0xff422af3d]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.602750660       0xff422d48d]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.602940451       0xff422e2c9]   dbg_trace_log_ctrl: Get String Descriptor(Index = 2, Length = 255)
[ 3544.603375035       0xff4230361]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.603657951       0xff4231899]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.604778941       0xff4236cac]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.605117847       0xff4238617]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 48/48 ZsI ==> 0
[ 3544.605345087       0xff4239721]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.605648576       0xff423ade5]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.606191128       0xff423d696]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.606507431       0xff423ee4e]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.607060503       0xff42417ca]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.607242378       0xff424256d]   dbg_trace_log_ctrl: Get String Descriptor(Index = 2, Length = 4)
[ 3544.607657378       0xff424448e]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.607933576       0xff4245945]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.609193993       0xff424b7cd]   event (000090c2): ep0in: Transfer Not Ready [0] (Active) [Data Phase]
[ 3544.609572535       0xff424d431]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.610207118       0xff42503c9]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 4/4 zsI ==> 0
[ 3544.610669358       0xff4252674]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.611225868       0xff4255031]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.614273889       0xff42634ca]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.614900347       0xff42663c7]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.617084722       0xff427079b]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.617425972       0xff4272133]   dbg_trace_log_ctrl: Get String Descriptor(Index = 2, Length = 48)
[ 3544.618232847       0xff4275db6]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.618783941       0xff427870b]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.621860608       0xff4286dcc]   event (000090c2): ep0in: Transfer Not Ready [0] (Active) [Data Phase]
[ 3544.622232326       0xff42889ac]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.622874462       0xff428b9d5]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 48/48 zsI ==> 0
[ 3544.623314670       0xff428dada]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.623920347       0xff4290847]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.626124774       0xff429ad9c]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.626707483       0xff429d950]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.630479410       0xff42af435]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.630835243       0xff42b0ee5]   dbg_trace_log_ctrl: Get String Descriptor(Index = 6, Length = 4)
[ 3544.631621337       0xff42b49da]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.632141597       0xff42b70de]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.633225347       0xff42bc226]   dbg_ep_queue: ep7in: req ffffff87a6479600 length 0/65536 zsI ==> -115
[ 3544.633465191       0xff42bd423]   dbg_prepare: ep7in: trb ffffffc01ce2bc80 (E201:D0) buf 00000000eb940000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.633717587       0xff42be711]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.634628576       0xff42c2b66]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.635168004       0xff42c53da]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 4/4 zsI ==> 0
[ 3544.635505712       0xff42c6d2d]   dbg_ep_queue: ep7in: req ffffff8023a40a00 length 0/65536 zsI ==> -115
[ 3544.635711597       0xff42c7c9e]   dbg_prepare: ep7in: trb ffffffc01ce2bc90 (E202:D0) buf 00000000ed490000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.635949254       0xff42c8e71]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.636171754       0xff42c9f22]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.636701076       0xff42cc6d5]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.637545556       0xff42d062a]   dbg_ep_queue: ep7in: req ffffff8040fbc600 length 0/65536 zsI ==> -115
[ 3544.637756597       0xff42d15fe]   dbg_prepare: ep7in: trb ffffffc01ce2bca0 (E203:D0) buf 00000000ee520000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.638009201       0xff42d28f0]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.638916858       0xff42d6d05]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.639430868       0xff42d9391]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.639883576       0xff42db584]   dbg_ep_queue: ep7in: req ffffff87e9690200 length 0/65536 zsI ==> -115
[ 3544.640092014       0xff42dc526]   dbg_prepare: ep7in: trb ffffffc01ce2bcb0 (E204:D0) buf 00000000eeb10000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.640354097       0xff42dd8ce]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.641655243       0xff42e3a66]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.642017066       0xff42e5589]   dbg_trace_log_ctrl: Get String Descriptor(Index = 6, Length = 12)
[ 3544.642792326       0xff42e8fac]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.643319514       0xff42eb737]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.645519201       0xff42f5c32]   event (000090c2): ep0in: Transfer Not Ready [0] (Active) [Data Phase]
[ 3544.645906233       0xff42f7937]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.646501754       0xff42fa5e2]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 12/12 zsI ==> 0
[ 3544.646924306       0xff42fc592]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.647448368       0xff42fece0]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.649645139       0xff43091a3]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.650240451       0xff430be48]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.657185608       0xff432c72c]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.657542379       0xff432e1ee]   dbg_trace_log_ctrl: Get String Descriptor(Index = 7, Length = 4)
[ 3544.658332118       0xff4331d29]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.658868733       0xff4334567]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.662133577       0xff4343a46]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.662765399       0xff43469a7]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 4/4 zsI ==> 0
[ 3544.663203524       0xff4348a83]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.663768941       0xff434b4ec]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.665941024       0xff43557d4]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.666539097       0xff43584ae]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.668989202       0xff4363c72]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.669348524       0xff4365764]   dbg_trace_log_ctrl: Get String Descriptor(Index = 7, Length = 18)
[ 3544.669729410       0xff43673f4]   dbg_ep_queue: ep7in: req ffffff885f067300 length 0/65536 zsI ==> -115
[ 3544.669939410       0xff43683b5]   dbg_prepare: ep7in: trb ffffffc01ce2bcc0 (E205:D0) buf 00000000ecba0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.670177379       0xff436958d]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.670671806       0xff436baa3]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.671218160       0xff436e39d]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.673520660       0xff437904e]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.674156233       0xff437bff8]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 18/18 zsI ==> 0
[ 3544.674591337       0xff437e09a]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.675151493       0xff4380a9c]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.677994931       0xff438dfde]   dbg_ep_queue: ep7in: req ffffff885f066a00 length 0/65536 zsI ==> -115
[ 3544.678187327       0xff438ee4c]   dbg_prepare: ep7in: trb ffffffc01ce2bcd0 (E206:D0) buf 00000000edce0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.678427639       0xff4390052]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.678660243       0xff43911c6]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.679250087       0xff4393e02]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.679706441       0xff439603b]   dbg_ep_queue: ep7in: req ffffff885f066d00 length 0/65536 zsI ==> -115
[ 3544.679914774       0xff4396fdb]   dbg_prepare: ep7in: trb ffffffc01ce2bce0 (E207:D0) buf 00000000ebd10000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.680177847       0xff4398397]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.681770243       0xff439fb06]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.682079827       0xff43a123d]   dbg_trace_log_ctrl: Get String Descriptor(Index = 8, Length = 4)
[ 3544.682436597       0xff43a2cfe]   dbg_ep_queue: ep7in: req ffffff885f067e00 length 0/65536 zsI ==> -115
[ 3544.682628420       0xff43a3b61]   dbg_prepare: ep7in: trb ffffffc01ce2bcf0 (E208:D0) buf 00000000ea7c0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.682863472       0xff43a4d02]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.683399097       0xff43a752f]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.683947795       0xff43a9e56]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.686103941       0xff43b400c]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.686723941       0xff43b6e8c]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 4/4 zsI ==> 0
[ 3544.687164410       0xff43b8f95]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.687710504       0xff43bb88a]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.689859462       0xff43c59b7]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.690451389       0xff43c861b]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.692519254       0xff43d2133]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.692681337       0xff43d2d59]   dbg_trace_log_ctrl: Get String Descriptor(Index = 8, Length = 20)
[ 3544.693095660       0xff43d4c6c]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.693569514       0xff43d6ff7]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.694471858       0xff43db3a4]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.695092118       0xff43de228]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 20/20 zsI ==> 0
[ 3544.695533264       0xff43e033e]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.696060764       0xff43e2ace]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.698216285       0xff43ecc7a]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.698831389       0xff43efa9b]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.701164045       0xff43fa98e]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.701480764       0xff43fc14e]   dbg_trace_log_ctrl: Get String Descriptor(Index = 9, Length = 4)
[ 3544.702260920       0xff43ffbd2]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.702786389       0xff440233a]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.705214045       0xff440d94f]   event (000090c2): ep0in: Transfer Not Ready [0] (Active) [Data Phase]
[ 3544.705580556       0xff440f4cb]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.706178629       0xff44121a6]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 4/4 zsI ==> 0
[ 3544.706617691       0xff4414294]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.707174097       0xff4416c4e]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.710117587       0xff4424913]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.710712587       0xff44275b1]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.712872066       0xff44317a9]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.713234045       0xff44332cd]   dbg_trace_log_ctrl: Get String Descriptor(Index = 9, Length = 28)
[ 3544.714001285       0xff4436c59]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.714525556       0xff44393ab]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.716653368       0xff4443342]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.717273577       0xff44461c5]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 28/28 zsI ==> 0
[ 3544.717700400       0xff44481c7]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.718247795       0xff444aad6]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.719270973       0xff444f793]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.719863733       0xff4452408]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.722041233       0xff445c759]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.722410087       0xff445e302]   dbg_trace_log_ctrl: Get String Descriptor(Index = 2, Length = 4)
[ 3544.723173368       0xff4461c41]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.723693004       0xff446433a]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.724742223       0xff44691ea]   dbg_ep_queue: ep7in: req ffffff885f067b00 length 0/65536 zsI ==> -115
[ 3544.724884514       0xff4469c96]   dbg_prepare: ep7in: trb ffffffc01ce2bd00 (E209:D0) buf 00000000eba40000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.725039983       0xff446a83f]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.725805035       0xff446e1a0]   dbg_ep_queue: ep7in: req ffffff8023ad8d00 length 0/65536 zsI ==> -115
[ 3544.726001441       0xff446f05b]   dbg_prepare: ep7in: trb ffffffc01ce2bd10 (E210:D0) buf 00000000ef580000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.726266545       0xff447043d]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.726491025       0xff4471515]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.727126441       0xff44744bb]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 4/4 zsI ==> 0
[ 3544.727467587       0xff4475e51]   dbg_ep_queue: ep7in: req ffffff87e7cab100 length 0/65536 zsI ==> -115
[ 3544.727681493       0xff4476e5c]   dbg_prepare: ep7in: trb ffffffc01ce2bd20 (E211:D0) buf 00000000ee060000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.727908473       0xff4477f62]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.728106962       0xff4478e46]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.728635816       0xff447b5f0]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.729413212       0xff447f03d]   dbg_ep_queue: ep7in: req ffffff8040cc5800 length 0/65536 zsI ==> -115
[ 3544.729686545       0xff44804bd]   dbg_prepare: ep7in: trb ffffffc01ce2bd30 (E212:D0) buf 00000000ec640000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.729939879       0xff44817bd]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.730811285       0xff4485918]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.731336598       0xff448807f]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.731788681       0xff448a266]   dbg_ep_queue: ep7in: req ffffff8040cc5000 length 0/65536 zsI ==> -115
[ 3544.731970035       0xff448b000]   dbg_prepare: ep7in: trb ffffffc01ce2bd40 (E213:D0) buf 00000000eb450000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.732231650       0xff448c3a0]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.733468473       0xff4492063]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.733782014       0xff44937e7]   dbg_trace_log_ctrl: Get String Descriptor(Index = 2, Length = 4)
[ 3544.734489306       0xff4496cf2]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.735030087       0xff4499582]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.737304358       0xff44a4015]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.737930816       0xff44a6f10]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 4/4 zsI ==> 0
[ 3544.738379358       0xff44a90b4]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.738869723       0xff44ab57a]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.742001077       0xff44ba056]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.742594046       0xff44bccce]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.744740452       0xff44c6dc9]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.745098889       0xff44c88ab]   dbg_trace_log_ctrl: Get String Descriptor(Index = 2, Length = 48)
[ 3544.745854827       0xff44cc15c]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.746367639       0xff44ce7d3]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.747347483       0xff44d3150]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.747966389       0xff44d5fbb]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 48/48 zsI ==> 0
[ 3544.748403473       0xff44d8082]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.748932431       0xff44da82e]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.751164410       0xff44e4f94]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.751788473       0xff44e7e62]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.753984723       0xff44f231c]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.754344723       0xff44f3e1b]   dbg_trace_log_ctrl: Get String Descriptor(Index = 2, Length = 48)
[ 3544.755126754       0xff44f78c3]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.755657952       0xff44fa098]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.758301441       0xff45066dc]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.758933056       0xff450963b]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 48/48 zsI ==> 0
[ 3544.759368264       0xff450b6df]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.759910868       0xff450df90]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.762141389       0xff45186da]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.762741129       0xff451b3d5]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.765040921       0xff4526053]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.765409358       0xff4527bf3]   dbg_trace_log_ctrl: Get String Descriptor(Index = 3, Length = 4)
[ 3544.766214983       0xff452b85f]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.766729827       0xff452defd]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.768855556       0xff4537e6c]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.769482066       0xff453ad67]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 4/4 zsI ==> 0
[ 3544.769909462       0xff453cd75]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.770444619       0xff453f598]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.771430973       0xff4543f93]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.772018421       0xff4546ba1]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.774859150       0xff45540b0]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.775210400       0xff4555b07]   dbg_trace_log_ctrl: Get String Descriptor(Index = 3, Length = 4)
[ 3544.776003473       0xff4559683]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.776504358       0xff455bc14]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.777142379       0xff455ebed]   dbg_ep_queue: ep7in: req ffffff8040e96f00 length 0/65536 zsI ==> -115
[ 3544.777392535       0xff455feb1]   dbg_prepare: ep7in: trb ffffffc01ce2bd50 (E214:D0) buf 00000000eef50000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.777654619       0xff4561258]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.778637796       0xff4565c15]   dbg_ep_queue: ep7in: req ffffff80407d1e00 length 0/65536 zsI ==> -115
[ 3544.778826598       0xff4566a3e]   dbg_prepare: ep7in: trb ffffffc01ce2bd60 (E215:D0) buf 00000000eb360000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.779060764       0xff4567bce]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.779287014       0xff4568cc6]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.779906806       0xff456bb42]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 4/4 zsI ==> 0
[ 3544.780348629       0xff456dc66]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.780871702       0xff45703a0]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.781314671       0xff45724d9]   dbg_ep_queue: ep7in: req ffffff87b6cd2c00 length 0/65536 zsI ==> -115
[ 3544.781517691       0xff4573413]   dbg_prepare: ep7in: trb ffffffc01ce2bd70 (E216:D0) buf 00000000ee550000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.781777379       0xff457478d]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.782774827       0xff457925c]   dbg_ep_queue: ep7in: req ffffff8862351b00 length 0/65536 zsI ==> -115
[ 3544.782982483       0xff457a1ef]   dbg_prepare: ep7in: trb ffffffc01ce2bd80 (E217:D0) buf 00000000ee530000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.783210452       0xff457b309]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.783449827       0xff457c4fe]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.784009462       0xff457eef6]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.786891129       0xff458c717]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.787256181       0xff458e276]   dbg_trace_log_ctrl: Get String Descriptor(Index = 3, Length = 18)
[ 3544.787823473       0xff4590d03]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.788038056       0xff4591d1b]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.789184983       0xff459731f]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.789506806       0xff4598b43]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 18/18 zsI ==> 0
[ 3544.789725244       0xff4599ba4]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.790001077       0xff459b055]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.790516441       0xff459d6fb]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.790844150       0xff459ef8f]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.791406129       0xff45a19b5]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.791597014       0xff45a2807]   dbg_trace_log_ctrl: Get String Descriptor(Index = 3, Length = 18)
[ 3544.792006858       0xff45a46c4]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.792301546       0xff45a5cdd]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.794334306       0xff45af553]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.794655087       0xff45b0d62]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 18/18 zsI ==> 0
[ 3544.794890504       0xff45b1f09]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.795194046       0xff45b35ce]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.796339619       0xff45b8bb8]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.796656546       0xff45ba37d]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.797206077       0xff45bccb5]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.797359931       0xff45bd83e]   dbg_trace_log_ctrl: Clear Endpoint Feature(Halt ep1in)
[ 3544.797577431       0xff45be88f]   dbg_send_ep_cmd: ep1in: cmd 'End Transfer' [30d08] params 00000000 00000000 00000000 --> status: Successful
[ 3544.797723004       0xff45bf379]   event (000020c2): ep0in: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.798172223       0xff45c152a]   event (080301c6): ep1in: Endpoint Command Complete
[ 3544.798465869       0xff45c2b31]   dbg_send_ep_cmd: ep1in: cmd 'Clear Stall' [405] params 00000000 00000000 00000000 --> status: Successful
[ 3544.798793160       0xff45c43bd]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.799338004       0xff45c6c99]   event (0000c042): ep0in: Transfer Complete (sIL) [Status Phase]
[ 3544.799652587       0xff45c8432]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.800837952       0xff45cdd19]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.801040192       0xff45cec44]   dbg_trace_log_ctrl: Clear Endpoint Feature(Halt ep2in)
[ 3544.801333889       0xff45d024b]   dbg_send_ep_cmd: ep2in: cmd 'End Transfer' [50d08] params 00000000 00000000 00000000 --> status: Successful
[ 3544.801545764       0xff45d122f]   event (000020c2): ep0in: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.802065139       0xff45d3923]   event (080501ca): ep2in: Endpoint Command Complete
[ 3544.802329619       0xff45d4cf9]   dbg_send_ep_cmd: ep2in: cmd 'Clear Stall' [405] params 00000000 00000000 00000000 --> status: Successful
[ 3544.802595452       0xff45d60e9]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.802824619       0xff45d7218]   dbg_ep_queue: ep7in: req ffffff87cb6f7c00 length 0/65536 zsI ==> -115
[ 3544.802929358       0xff45d79f3]   dbg_prepare: ep7in: trb ffffffc01ce2bd90 (E218:D0) buf 00000000ec430000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.803056910       0xff45d8384]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.803174150       0xff45d8c4f]   event (0000c042): ep0in: Transfer Complete (sIL) [Status Phase]
[ 3544.803501494       0xff45da4dd]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.803844306       0xff45dbe92]   dbg_ep_queue: ep7in: req ffffff87cb6f7600 length 0/65536 zsI ==> -115
[ 3544.803906858       0xff45dc343]   dbg_prepare: ep7in: trb ffffffc01ce2bda0 (E219:D0) buf 00000000eef70000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.803983837       0xff45dc909]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.804315712       0xff45de1ed]   dbg_ep_queue: ep7in: req ffffff87cb6f7f00 length 0/65536 zsI ==> -115
[ 3544.804390608       0xff45de78b]   dbg_prepare: ep7in: trb ffffffc01ce2bdb0 (E220:D0) buf 00000000ef390000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.804491806       0xff45def22]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.804883160       0xff45e0c7d]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.805061806       0xff45e19e3]   dbg_trace_log_ctrl: Clear Endpoint Feature(Halt ep1out)
[ 3544.805308577       0xff45e2c65]   dbg_send_ep_cmd: ep1out: cmd 'End Transfer' [20d08] params 00000000 00000000 00000000 --> status: Successful
[ 3544.805463056       0xff45e37fb]   event (000020c2): ep0in: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.805627744       0xff45e4454]   dbg_ep_queue: ep7in: req ffffff87a578b200 length 0/65536 zsI ==> -115
[ 3544.805707327       0xff45e4a4c]   dbg_prepare: ep7in: trb ffffffc01ce2bdc0 (E221:D0) buf 00000000edeb0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.805805712       0xff45e51ad]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.805900400       0xff45e58c8]   event (080201c4): ep1out: Endpoint Command Complete
[ 3544.806151546       0xff45e6b9d]   dbg_send_ep_cmd: ep1out: cmd 'Clear Stall' [405] params 00000000 00000000 00000000 --> status: Successful
[ 3544.806371025       0xff45e7c14]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.806609358       0xff45e8df4]   dbg_send_ep_cmd: ep1out: cmd 'Start Transfer' [406] params 00000000 efff8000 00000000 --> status: Successful
[ 3544.806793108       0xff45e9bbb]   dbg_ep_queue: ep7in: req ffffff8042c2b800 length 0/65536 zsI ==> -115
[ 3544.806873681       0xff45ea1c6]   dbg_prepare: ep7in: trb ffffffc01ce2bdd0 (E222:D0) buf 00000000e6f80000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.806980035       0xff45ea9c1]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.807078421       0xff45eb122]   event (0000c042): ep0in: Transfer Complete (sIL) [Status Phase]
[ 3544.807364514       0xff45ec697]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.807646806       0xff45edbc2]   dbg_ep_queue: ep7in: req ffffff8042c2a200 length 0/65536 zsI ==> -115
[ 3544.807710608       0xff45ee08b]   dbg_prepare: ep7in: trb ffffffc01ce2bde0 (E223:D0) buf 00000000e6f90000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.807806233       0xff45ee7b7]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.808190817       0xff45f048f]   dbg_ep_queue: ep7in: req ffffff8034aeb100 length 0/65536 zsI ==> -115
[ 3544.808268889       0xff45f0a6a]   dbg_prepare: ep7in: trb ffffffc01ce2bdf0 (E224:D0) buf 00000000eab80000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.808368525       0xff45f11e3]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.808479098       0xff45f1a2f]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.808647848       0xff45f26d6]   dbg_trace_log_ctrl: Clear Endpoint Feature(Halt ep2out)
[ 3544.808860921       0xff45f36d2]   dbg_send_ep_cmd: ep2out: cmd 'End Transfer' [40d08] params 00000000 00000000 00000000 --> status: Successful
[ 3544.809006858       0xff45f41c4]   event (000020c2): ep0in: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.809173056       0xff45f4e3a]   dbg_ep_queue: ep7in: req ffffff8034aea400 length 0/65536 zsI ==> -115
[ 3544.809254098       0xff45f544e]   dbg_prepare: ep7in: trb ffffffc01ce2be00 (E225:D0) buf 00000000eebe0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.809354410       0xff45f5bd4]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.809448473       0xff45f62e2]   event (080401c8): ep2out: Endpoint Command Complete
[ 3544.809697379       0xff45f758e]   dbg_send_ep_cmd: ep2out: cmd 'Clear Stall' [405] params 00000000 00000000 00000000 --> status: Successful
[ 3544.809908473       0xff45f8563]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.810135504       0xff45f9669]   dbg_send_ep_cmd: ep2out: cmd 'Start Transfer' [406] params 00000000 efff6000 00000000 --> status: Successful
[ 3544.810318421       0xff45fa421]   dbg_ep_queue: ep7in: req ffffff8042dcee00 length 0/65536 zsI ==> -115
[ 3544.810398160       0xff45faa1c]   dbg_prepare: ep7in: trb ffffffc01ce2be10 (E226:D0) buf 00000000ee760000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.810494254       0xff45fb151]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.810590035       0xff45fb881]   event (0000c042): ep0in: Transfer Complete (sIL) [Status Phase]
[ 3544.810862587       0xff45fccf1]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.811049410       0xff45fdaf4]   dbg_ep_queue: ep7in: req ffffff87cc07b300 length 0/65536 zsI ==> -115
[ 3544.811129306       0xff45fe0f3]   dbg_prepare: ep7in: trb ffffffc01ce2be20 (E227:D0) buf 00000000e8ef0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.811229983       0xff45fe87f]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.817737900       0xff461d098]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.817938421       0xff461dfa1]   dbg_trace_log_ctrl: Get String Descriptor(Index = 6, Length = 4)
[ 3544.818369983       0xff461ffff]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.818643421       0xff4621482]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.844969723       0xff469cafa]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.845546025       0xff469f634]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 4/4 zsI ==> 0
[ 3544.845908942       0xff46a116c]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.846383317       0xff46a34ff]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.847305869       0xff46a7a31]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.847729515       0xff46a99f7]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.857547952       0xff46d7a5a]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.857905973       0xff46d9533]   dbg_trace_log_ctrl: Get String Descriptor(Index = 6, Length = 12)
[ 3544.858714150       0xff46dd1cf]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.859273473       0xff46dfbc3]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.861268629       0xff46e9167]   event (000090c2): ep0in: Transfer Not Ready [0] (Active) [Data Phase]
[ 3544.861455817       0xff46e9f70]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.861992900       0xff46ec7b9]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 12/12 zsI ==> 0
[ 3544.862435088       0xff46ee8e2]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.862974150       0xff46f1150]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.865121650       0xff46fb260]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.865718785       0xff46fdf28]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.866757275       0xff4702d0b]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.867115921       0xff47047f2]   dbg_trace_log_ctrl: Get String Descriptor(Index = 3, Length = 4)
[ 3544.867883525       0xff4708183]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.868316025       0xff470a1f4]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.877934254       0xff4737351]   dbg_ep_queue: ep7in: req ffffff80414fbd00 length 0/65536 zsI ==> -115
[ 3544.878190400       0xff4738687]   dbg_prepare: ep7in: trb ffffffc01ce2be30 (E228:D0) buf 00000000ec9e0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.878456129       0xff4739a75]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.879225504       0xff473d42c]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.879861077       0xff47403d4]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 4/4 zsI ==> 0
[ 3544.880244775       0xff474209b]   dbg_ep_queue: ep7in: req ffffff8042c27d00 length 0/65536 zsI ==> -115
[ 3544.880414827       0xff4742d5c]   dbg_prepare: ep7in: trb ffffffc01ce2be40 (E229:D0) buf 00000000ed8c0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.880638213       0xff4743e1d]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.880868629       0xff4744f66]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.881452744       0xff4747b35]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.881908838       0xff4749d69]   dbg_ep_queue: ep7in: req ffffff8041e7ec00 length 0/65536 zsI ==> -115
[ 3544.882119827       0xff474ad3c]   dbg_prepare: ep7in: trb ffffffc01ce2be50 (E230:D0) buf 00000000ebd20000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.882387692       0xff474c153]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.883380973       0xff4750bd2]   dbg_ep_queue: ep7in: req ffffff8033cfcd00 length 0/65536 zsI ==> -115
[ 3544.883589411       0xff4751b74]   dbg_prepare: ep7in: trb ffffffc01ce2be60 (E231:D0) buf 00000000ec1d0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.883826233       0xff4752d37]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.886349150       0xff475ea71]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.886946858       0xff4761743]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.889455869       0xff476d372]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.889818629       0xff476eea6]   dbg_trace_log_ctrl: Get String Descriptor(Index = 3, Length = 18)
[ 3544.890607223       0xff47729ca]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.891106598       0xff4774f3f]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.893395400       0xff477fae7]   event (0000c042): ep0in: Transfer Complete (sIL) [Data Phase]
[ 3544.894033890       0xff4782acb]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 18/18 zsI ==> 0
[ 3544.894461286       0xff4784ad8]   event (000020c0): ep0out: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.894996858       0xff4787304]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.905757952       0xff47b9a1a]   event (0000c040): ep0out: Transfer Complete (sIL) [Status Phase]
[ 3544.906348004       0xff47bc659]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.907409515       0xff47c15f7]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.907758161       0xff47c301c]   dbg_trace_log_ctrl: Clear Endpoint Feature(Halt ep5in)
[ 3544.908288056       0xff47c57db]   dbg_send_ep_cmd: ep5in: cmd 'End Transfer' [b0d08] params 00000000 00000000 00000000 --> status: Successful
[ 3544.908652900       0xff47c7338]   event (000020c2): ep0in: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.911086650       0xff47d29c1]   event (080b01d6): ep5in: Endpoint Command Complete
[ 3544.911618213       0xff47d519e]   dbg_send_ep_cmd: ep5in: cmd 'Clear Stall' [405] params 00000000 00000000 00000000 --> status: Successful
[ 3544.912208577       0xff47d7de5]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.914608577       0xff47e31e6]   event (0000c042): ep0in: Transfer Complete (sIL) [Status Phase]
[ 3544.915203004       0xff47e5e7a]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.918004150       0xff47f3091]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.918361390       0xff47f4b5a]   dbg_trace_log_ctrl: Clear Endpoint Feature(Halt ep4in)
[ 3544.918893004       0xff47f733a]   dbg_send_ep_cmd: ep4in: cmd 'Clear Stall' [405] params 00000000 00000000 00000000 --> status: Successful
[ 3544.919244775       0xff47f8d9b]   event (000020c2): ep0in: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.919739254       0xff47fb2b1]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.922508265       0xff4808260]   event (0000c042): ep0in: Transfer Complete (sIL) [Status Phase]
[ 3544.923138577       0xff480b1a4]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.925691702       0xff4817120]   dbg_ep_queue: ep7in: req ffffff8033cfd700 length 0/65536 zsI ==> -115
[ 3544.925928629       0xff48182e5]   dbg_prepare: ep7in: trb ffffffc01ce2be70 (E232:D0) buf 00000000ec1e0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.926174150       0xff481954f]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.926405452       0xff481a6aa]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.926769827       0xff481c1fd]   dbg_trace_log_ctrl: Clear Endpoint Feature(Halt ep3out)
[ 3544.927268109       0xff481e75c]   dbg_send_ep_cmd: ep3out: cmd 'Clear Stall' [405] params 00000000 00000000 00000000 --> status: Successful
[ 3544.927610973       0xff4820113]   event (000020c2): ep0in: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.928049463       0xff48221f6]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.928456494       0xff482407c]   dbg_ep_queue: ep7in: req ffffff8033cfd600 length 0/65536 zsI ==> -115
[ 3544.928673421       0xff48250c1]   dbg_prepare: ep7in: trb ffffffc01ce2be80 (E233:D0) buf 00000000eaf30000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.928939723       0xff48264ba]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.930742796       0xff482ebf5]   dbg_ep_queue: ep7in: req ffffff8033cfd100 length 0/65536 zsI ==> -115
[ 3544.930936650       0xff482fa7f]   dbg_prepare: ep7in: trb ffffffc01ce2be90 (E234:D0) buf 00000000ef340000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.931180140       0xff4830cc2]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.931415192       0xff4831e65]   event (0000c042): ep0in: Transfer Complete (sIL) [Status Phase]
[ 3544.932007327       0xff4834ace]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.934601546       0xff4840d5d]   dbg_ep_queue: ep7in: req ffffff87b91f1f00 length 0/65536 zsI ==> -115
[ 3544.934813682       0xff4841d46]   dbg_prepare: ep7in: trb ffffffc01ce2bea0 (E235:D0) buf 00000000eeb30000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.935086546       0xff48431bd]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.935329046       0xff48443ef]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.935711702       0xff48460a1]   dbg_trace_log_ctrl: Clear Endpoint Feature(Halt ep4in)
[ 3544.936220400       0xff48486c7]   dbg_send_ep_cmd: ep4in: cmd 'Clear Stall' [405] params 00000000 00000000 00000000 --> status: Successful
[ 3544.936563317       0xff484a07f]   event (000020c2): ep0in: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.937098629       0xff484c8a6]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.941146859       0xff485f845]   event (0000c042): ep0in: Transfer Complete (sIL) [Status Phase]
[ 3544.941739723       0xff48624bb]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.942759775       0xff486713b]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.943103994       0xff4868b0d]   dbg_trace_log_ctrl: Clear Endpoint Feature(Halt ep3out)
[ 3544.943645921       0xff486b3b1]   dbg_send_ep_cmd: ep3out: cmd 'Clear Stall' [405] params 00000000 00000000 00000000 --> status: Successful
[ 3544.944018577       0xff486cfa5]   event (000020c2): ep0in: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.944518473       0xff486f523]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.947332171       0xff487c82a]   event (0000c042): ep0in: Transfer Complete (sIL) [Status Phase]
[ 3544.947929098       0xff487f4ee]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.951164411       0xff488e796]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.951541442       0xff48903dc]   dbg_trace_log_ctrl: 21 22 00 00 02 00 00 00
[ 3544.953510973       0xff4899792]   event (000020c2): ep0in: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.954075296       0xff489c1e6]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.958168109       0xff48af4dc]   event (0000c042): ep0in: Transfer Complete (sIL) [Status Phase]
[ 3544.958529723       0xff48b0ffa]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 0/0 zsI ==> 0
[ 3544.959184046       0xff48b410e]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.962348317       0xff48c2e60]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.962710921       0xff48c4992]   dbg_trace_log_ctrl: 21 22 01 00 02 00 00 00
[ 3544.963727744       0xff48c95d5]   event (000020c2): ep0in: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.964204619       0xff48cb999]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.967255713       0xff48d9e6d]   event (0000c042): ep0in: Transfer Complete (sIL) [Status Phase]
[ 3544.967604255       0xff48db892]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 0/0 zsI ==> 0
[ 3544.968241598       0xff48de85e]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.971033786       0xff48eb9c9]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3544.971394463       0xff48ed4d6]   dbg_trace_log_ctrl: Get Interface Status(Intf = 2, Length = 16)
[ 3544.972373682       0xff48f1e47]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.972872900       0xff48f43b8]   event (000010c0): ep0out: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.978611911       0xff490f226]   event (000010c0): ep0out: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3544.978986286       0xff4910e39]   event (00002040): ep0out: Transfer Complete (Sil) [Data Phase]
[ 3544.979544567       0xff4913819]   dbg_gadget_giveback: ep0out: req ffffff87df01c200 length 16/16 zsI ==> 0
[ 3544.980264359       0xff4916e14]   event (000020c2): ep0in: Transfer Not Ready [0] (Not Active) [Status Phase]
[ 3544.980548577       0xff4918364]   dbg_send_ep_cmd: ep0in: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.982512327       0xff49216ae]   event (0000c042): ep0in: Transfer Complete (sIL) [Status Phase]
[ 3544.983100713       0xff49242ce]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3544.983620661       0xff49269cc]   dbg_ep_queue: ep7in: req ffffff87b91f1000 length 0/65536 zsI ==> -115
[ 3544.983876286       0xff4927cf8]   dbg_prepare: ep7in: trb ffffffc01ce2beb0 (E236:D0) buf 00000000ecae0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.984136338       0xff4929079]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.985734046       0xff493084d]   dbg_ep_queue: ep7in: req ffffff87b91f0700 length 0/65536 zsI ==> -115
[ 3544.985956598       0xff49318fe]   dbg_prepare: ep7in: trb ffffffc01ce2bec0 (E237:D0) buf 00000000ec2f0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.986224828       0xff4932d1c]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.987259932       0xff4937abe]   dbg_ep_queue: ep7in: req ffffff87b91f0f00 length 0/65536 zsI ==> -115
[ 3544.987476025       0xff4938af3]   dbg_prepare: ep7in: trb ffffffc01ce2bed0 (E238:D0) buf 00000000eb4f0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.987742744       0xff4939ef4]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.989672067       0xff4942fa7]   dbg_ep_queue: ep7in: req ffffff87b91f0200 length 0/65536 zsI ==> -115
[ 3544.989877796       0xff4943f15]   dbg_prepare: ep7in: trb ffffffc01ce2bee0 (E239:D0) buf 00000000ed240000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.990127953       0xff49451d8]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.991012900       0xff4949437]   dbg_ep_queue: ep7in: req ffffff87b91f0400 length 0/65536 zsI ==> -115
[ 3544.991231234       0xff494a498]   dbg_prepare: ep7in: trb ffffffc01ce2bef0 (E240:D0) buf 00000000ef230000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.991473682       0xff494b6c6]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.993042275       0xff4952c6b]   dbg_ep_queue: ep7in: req ffffff87b91f1300 length 0/65536 zsI ==> -115
[ 3544.993243109       0xff4953b7b]   dbg_prepare: ep7in: trb ffffffc01ce2bf00 (E241:D0) buf 00000000ec000000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.993512067       0xff4954fa7]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3544.999035765       0xff496edee]   dbg_ep_queue: ep7in: req ffffff87b91f1800 length 0/65536 zsI ==> -115
[ 3544.999255296       0xff496fe65]   dbg_prepare: ep7in: trb ffffffc01ce2bf10 (E242:D0) buf 00000000ec220000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3544.999523161       0xff497127c]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3545.000823838       0xff4977409]   dbg_ep_queue: ep7in: req ffffff8041e89300 length 0/65536 zsI ==> -115
[ 3545.001017588       0xff4978291]   dbg_prepare: ep7in: trb ffffffc01ce2bf20 (E243:D0) buf 00000000ef3b0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3545.001283630       0xff4979685]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3545.002296755       0xff497e281]   dbg_ep_queue: ep7in: req ffffff8041e88800 length 0/65536 zsI ==> -115
[ 3545.002522067       0xff497f367]   dbg_prepare: ep7in: trb ffffffc01ce2bf30 (E244:D0) buf 00000000ee6d0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3545.002787432       0xff498074e]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3545.004364411       0xff4987d94]   dbg_ep_queue: ep7in: req ffffff8041e89d00 length 0/65536 zsI ==> -115
[ 3545.004549775       0xff4988b7b]   dbg_prepare: ep7in: trb ffffffc01ce2bf40 (E245:D0) buf 00000000ee6c0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3545.004809619       0xff4989ef8]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3545.005820244       0xff498eac4]   dbg_ep_queue: ep7in: req ffffff87de297600 length 0/65536 zsI ==> -115
[ 3545.006030296       0xff498fa85]   dbg_prepare: ep7in: trb ffffffc01ce2bf50 (E246:D0) buf 00000000e9090000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3545.006295192       0xff4990e63]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3545.007306494       0xff4995a3c]   dbg_ep_queue: ep7in: req ffffff8044310e00 length 0/65536 zsI ==> -115
[ 3545.007514411       0xff49969d4]   dbg_prepare: ep7in: trb ffffffc01ce2bf60 (E247:D0) buf 00000000e9080000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3545.007779515       0xff4997db6]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3545.009537953       0xff49a0198]   dbg_ep_queue: ep7in: req ffffff8020658300 length 0/65536 zsI ==> -115
[ 3545.009740609       0xff49a10cc]   dbg_prepare: ep7in: trb ffffffc01ce2bf70 (E248:D0) buf 00000000e9070000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3545.010012275       0xff49a252b]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3545.011008994       0xff49a6fec]   dbg_ep_queue: ep7in: req ffffff8783d97c00 length 0/65536 zsI ==> -115
[ 3545.011221078       0xff49a7fd4]   dbg_prepare: ep7in: trb ffffffc01ce2bf80 (E249:D0) buf 00000000e9350000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3545.011476025       0xff49a92f3]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3545.012842484       0xff49af96f]   dbg_ep_queue: ep7in: req ffffff8042d79800 length 0/65536 zsI ==> -115
[ 3545.012993682       0xff49b04c6]   dbg_prepare: ep7in: trb ffffffc01ce2bf90 (E250:D0) buf 00000000ec650000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3545.013202223       0xff49b146a]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3545.014157744       0xff49b5c14]   dbg_ep_queue: ep7in: req ffffff8042d79700 length 0/65536 zsI ==> -115
[ 3545.014373890       0xff49b6c4a]   dbg_prepare: ep7in: trb ffffffc01ce2bfa0 (E251:D0) buf 00000000eaf20000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3545.014633473       0xff49b7fc2]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3545.016293005       0xff49bfc39]   dbg_ep_queue: ep7in: req ffffff8042d78b00 length 0/65536 zsI ==> -115
[ 3545.016488473       0xff49c0ae2]   dbg_prepare: ep7in: trb ffffffc01ce2bfb0 (E252:D0) buf 00000000ec5e0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3545.016715088       0xff49c1be1]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3545.017709411       0xff49c6674]   dbg_ep_queue: ep7in: req ffffff8041574f00 length 0/65536 zsI ==> -115
[ 3545.017907692       0xff49c7553]   dbg_prepare: ep7in: trb ffffffc01ce2bfc0 (E253:D0) buf 00000000ec5d0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3545.018169307       0xff49c88f2]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3545.019192588       0xff49cd5b1]   dbg_ep_queue: ep7in: req ffffff8041575b00 length 0/65536 zsI ==> -115
[ 3545.019379671       0xff49ce3b9]   dbg_prepare: ep7in: trb ffffffc01ce2bfd0 (E254:D0) buf 00000000ec5c0000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3545.019643473       0xff49cf782]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3545.021278057       0xff49d721a]   dbg_ep_queue: ep7in: req ffffff8041575600 length 0/65536 zsI ==> -115
[ 3545.021486078       0xff49d81b4]   dbg_prepare: ep7in: trb ffffffc01ce2bfe0 (E0:D0) buf 00000000ed630000 size 65536 ctrl 00000811 (Hlcs:sC:normal)
[ 3545.021756546       0xff49d95fd]   dbg_send_ep_cmd: ep7in: cmd 'Update Transfer' [f0007] params 00000000 00000000 00000000 --> status: Successful
[ 3546.570987801       0xff6637655]   dbg_send_ep_cmd: ep1out: cmd 'End Transfer' [20c08] params 00000000 00000000 00000000 --> status: Successful
[ 3546.571290249       0xff6638d04]   dbg_gadget_giveback: ep1out: req ffffff87de5da100 length 0/16384 zsI ==> -108
[ 3546.576021707       0xff664efe0]   dbg_gadget_giveback: ep1out: req ffffff87de5dbb00 length 0/16384 zsI ==> -108
[ 3546.576768270       0xff66527df]   dbg_gadget_giveback: ep1out: req ffffff87de5dbe00 length 0/16384 zsI ==> -108
[ 3546.577526707       0xff66560c0]   dbg_gadget_giveback: ep1out: req ffffff804143ef00 length 0/16384 zsI ==> -108
[ 3546.578279624       0xff6659938]   dbg_gadget_giveback: ep1out: req ffffff804162f500 length 0/16384 zsI ==> -108
[ 3546.579061343       0xff665d3d9]   dbg_gadget_giveback: ep1out: req ffffff80407d0700 length 0/16384 zsI ==> -108
[ 3546.600517801       0xff66c1d15]   dbg_gadget_giveback: ep1out: req ffffff80407d0200 length 0/16384 zsI ==> -108
[ 3546.601288947       0xff66c56eb]   dbg_gadget_giveback: ep1out: req ffffff878085a900 length 0/16384 zsI ==> -108
[ 3546.602830301       0xff66cca85]   dbg_gadget_giveback: ep1out: req ffffff8835235000 length 0/16384 zsI ==> -108
[ 3546.610145666       0xff66eef2c]   dbg_gadget_giveback: ep1out: req ffffff87b6cd2100 length 0/16384 zsI ==> -108
[ 3546.610807280       0xff66f20cb]   dbg_gadget_giveback: ep1out: req ffffff87b6cd3800 length 0/16384 zsI ==> -108
[ 3546.611689728       0xff66f62fa]   dbg_gadget_giveback: ep1out: req ffffff804d2c9100 length 0/16384 zsI ==> -108
[ 3546.612144728       0xff66f851a]   dbg_gadget_giveback: ep1out: req ffffff804d2c8800 length 0/16384 zsI ==> -108
[ 3546.612825301       0xff66fb825]   dbg_gadget_giveback: ep1out: req ffffff804143b100 length 0/16384 zsI ==> -108
[ 3546.613457801       0xff66fe795]   dbg_gadget_giveback: ep1out: req ffffff804143ac00 length 0/16384 zsI ==> -108
[ 3546.614589468       0xff6703c75]   dbg_gadget_giveback: ep1out: req ffffff80407b0f00 length 0/16384 zsI ==> -108
[ 3546.615163999       0xff670678c]   dbg_gadget_giveback: ep1out: req ffffff80407b1700 length 0/16384 zsI ==> -108
[ 3546.642499155       0xff67869af]   dbg_gadget_giveback: ep1out: req ffffff803ae3cc00 length 0/16384 zsI ==> -108
[ 3546.644764572       0xff6791397]   dbg_gadget_giveback: ep1out: req ffffff887eb33400 length 0/16384 zsI ==> -108
[ 3546.646234312       0xff67981d2]   dbg_gadget_giveback: ep1out: req ffffff87d72def00 length 0/16384 zsI ==> -108
[ 3546.648443583       0xff67a2784]   dbg_gadget_giveback: ep1out: req ffffff87d72df200 length 0/16384 zsI ==> -108
[ 3546.666252958       0xff67f5f38]   dbg_gadget_giveback: ep1out: req ffffff87d72df000 length 0/16384 zsI ==> -108
[ 3546.668549781       0xff6800b7b]   dbg_gadget_giveback: ep1out: req ffffff87d72de500 length 0/16384 zsI ==> -108
[ 3546.670117645       0xff6808112]   dbg_gadget_giveback: ep1out: req ffffff886052ed00 length 0/16384 zsI ==> -108
[ 3546.672526760       0xff68135c1]   dbg_gadget_giveback: ep1out: req ffffff87c0a1a900 length 0/16384 zsI ==> -108
[ 3546.689826656       0xff686473f]   dbg_gadget_giveback: ep1out: req ffffff87c1f60100 length 0/16384 zsI ==> -108
[ 3546.692273635       0xff686fec6]   dbg_gadget_giveback: ep1out: req ffffff87c1f61c00 length 0/16384 zsI ==> -108
[ 3546.693741447       0xff6876cdb]   dbg_gadget_giveback: ep1out: req ffffff87d739e300 length 0/16384 zsI ==> -108
[ 3546.695320093       0xff687e341]   dbg_gadget_giveback: ep1out: req ffffff87d739ed00 length 0/16384 zsI ==> -108
[ 3546.706078218       0xff68b0a1e]   dbg_gadget_giveback: ep1out: req ffffff87d739fd00 length 0/16384 zsI ==> -108
[ 3546.708486812       0xff68bbec2]   dbg_gadget_giveback: ep1out: req ffffff87d739f100 length 0/16384 zsI ==> -108
[ 3546.710014624       0xff68c3158]   dbg_gadget_giveback: ep1out: req ffffff87d739fe00 length 0/16384 zsI ==> -108
[ 3546.712261239       0xff68cd9d7]   dbg_send_ep_cmd: ep2out: cmd 'End Transfer' [40c08] params 00000000 00000000 00000000 --> status: Successful
[ 3546.712775979       0xff68d0072]   dbg_gadget_giveback: ep2out: req ffffff87cfb99c00 length 0/2048 zsI ==> -108
[ 3546.721128427       0xff68f72e1]   dbg_gadget_giveback: ep2out: req ffffff87cfb98200 length 0/2048 zsI ==> -108
[ 3546.722142124       0xff68fbee8]   dbg_gadget_giveback: ep2out: req ffffff87cfb98000 length 0/2048 zsI ==> -108
[ 3546.723088479       0xff69005e3]   dbg_gadget_giveback: ep2out: req ffffff87cfb99200 length 0/2048 zsI ==> -108
[ 3546.724774416       0xff6908454]   dbg_gadget_giveback: ep2out: req ffffff87cfb99e00 length 0/2048 zsI ==> -108
[ 3546.725747281       0xff690cd4b]   dbg_gadget_giveback: ep2out: req ffffff87cfb98500 length 0/2048 zsI ==> -108
[ 3546.726799520       0xff6911c36]   dbg_gadget_giveback: ep2out: req ffffff87cfb98e00 length 0/2048 zsI ==> -108
[ 3546.745217281       0xff696818b]   dbg_gadget_giveback: ep2out: req ffffff87cfb99d00 length 0/2048 zsI ==> -108
[ 3546.746147750       0xff696c754]   dbg_send_ep_cmd: ep3in: cmd 'End Transfer' [70c08] params 00000000 00000000 00000000 --> status: Successful
[ 3546.746620041       0xff696eac1]   dbg_send_ep_cmd: ep4out: cmd 'End Transfer' [80c08] params 00000000 00000000 00000000 --> status: Successful
[ 3546.747192906       0xff69715b7]   dbg_gadget_giveback: ep4out: req ffffff87cfb99300 length 0/16384 zsI ==> -108
[ 3546.749558375       0xff697c720]   dbg_gadget_giveback: ep4out: req ffffff87cfb99f00 length 0/16384 zsI ==> -108
[ 3546.751148479       0xff6983e62]   dbg_gadget_giveback: ep4out: req ffffff87cfb98c00 length 0/16384 zsI ==> -108
[ 3546.761907593       0xff69b6551]   dbg_gadget_giveback: ep4out: req ffffff87cfb98a00 length 0/16384 zsI ==> -108
[ 3546.773237698       0xff69eb713]   dbg_gadget_giveback: ep4out: req ffffff8040fc6200 length 0/16384 zsI ==> -108
[ 3546.774910875       0xff69f3490]   dbg_gadget_giveback: ep4out: req ffffff885f8c1000 length 0/16384 zsI ==> -108
[ 3546.797683791       0xff6a5e088]   dbg_gadget_giveback: ep4out: req ffffff87cb631700 length 0/16384 zsI ==> -108
[ 3546.808186552       0xff6a8f43d]   dbg_gadget_giveback: ep4out: req ffffff87cb631e00 length 0/16384 zsI ==> -108
[ 3546.808893791       0xff6a92948]   dbg_send_ep_cmd: ep7in: cmd 'End Transfer' [f0c08] params 00000000 00000000 00000000 --> status: Successful
[ 3546.809169000       0xff6a93dec]   dbg_gadget_giveback: ep7in: req ffffff87d1c9aa00 length 0/64000 zsI ==> -108
[ 3546.810318114       0xff6a9941c]   dbg_gadget_giveback: ep7in: req ffffff87d1c9b400 length 0/65536 zsI ==> -108
[ 3546.811101604       0xff6a9cede]   dbg_gadget_giveback: ep7in: req ffffff87d1c9af00 length 0/65536 zsI ==> -108
[ 3546.816830927       0xff6ab7c91]   dbg_gadget_giveback: ep7in: req ffffff87d1c9a300 length 0/65536 zsI ==> -108
[ 3546.817616864       0xff6abb783]   dbg_gadget_giveback: ep7in: req ffffff87d1c9a900 length 0/65536 zsI ==> -108
[ 3546.818396604       0xff6abf1fe]   dbg_gadget_giveback: ep7in: req ffffff87d1c9bb00 length 0/65536 zsI ==> -108
[ 3546.819172125       0xff6ac2c28]   dbg_gadget_giveback: ep7in: req ffffff87d1c9bf00 length 0/65536 zsI ==> -108
[ 3546.820307021       0xff6ac8146]   dbg_gadget_giveback: ep7in: req ffffff87d1c9bd00 length 0/65536 zsI ==> -108
[ 3546.821069000       0xff6acba6c]   dbg_gadget_giveback: ep7in: req ffffff87d1c9a100 length 0/65536 zsI ==> -108
[ 3546.821847437       0xff6acf4ce]   dbg_gadget_giveback: ep7in: req ffffff87d1c9a700 length 0/65536 zsI ==> -108
[ 3546.822722229       0xff6ad366a]   dbg_gadget_giveback: ep7in: req ffffff87d1c9b700 length 0/65536 zsI ==> -108
[ 3546.844334417       0xff6b38b55]   dbg_gadget_giveback: ep7in: req ffffff87d1c9a400 length 0/65536 zsI ==> -108
[ 3546.845472906       0xff6b3e0b7]   dbg_gadget_giveback: ep7in: req ffffff87d1c9b300 length 0/65536 zsI ==> -108
[ 3546.846332594       0xff6b42131]   dbg_gadget_giveback: ep7in: req ffffff87d1c9b100 length 0/65536 zsI ==> -108
[ 3546.847033739       0xff6b455c7]   dbg_gadget_giveback: ep7in: req ffffff87d1c9be00 length 0/65536 zsI ==> -108
[ 3546.860407281       0xff6b840cb]   dbg_gadget_giveback: ep7in: req ffffff87d1c9ad00 length 0/65536 zsI ==> -108
[ 3546.861356760       0xff6b88802]   dbg_gadget_giveback: ep7in: req ffffff87d1c9ac00 length 0/65536 zsI ==> -108
[ 3546.862109521       0xff6b8c076]   dbg_gadget_giveback: ep7in: req ffffff87d1c9bc00 length 0/65536 zsI ==> -108
[ 3546.862830510       0xff6b8f689]   dbg_gadget_giveback: ep7in: req ffffff87d1c9a500 length 0/65536 zsI ==> -108
[ 3546.865225875       0xff6b9aa30]   dbg_gadget_giveback: ep7in: req ffffff87d1c9ae00 length 0/65536 zsI ==> -108
[ 3546.866001656       0xff6b9e45f]   dbg_gadget_giveback: ep7in: req ffffff87d1c9ab00 length 0/65536 zsI ==> -108
[ 3546.866778635       0xff6ba1ea5]   dbg_gadget_giveback: ep7in: req ffffff87d1c9a200 length 0/65536 zsI ==> -108
[ 3546.868045719       0xff6ba7dad]   dbg_gadget_giveback: ep7in: req ffffff87d1c9b000 length 0/65536 zsI ==> -108
[ 3546.868744312       0xff6bab212]   dbg_gadget_giveback: ep7in: req ffffff88321c7000 length 0/65536 zsI ==> -108
[ 3546.869525510       0xff6baeca9]   dbg_gadget_giveback: ep7in: req ffffff8040ee4a00 length 0/65536 zsI ==> -108
[ 3546.870300146       0xff6bb26c2]   dbg_gadget_giveback: ep7in: req ffffff8036baf300 length 0/65536 zsI ==> -108
[ 3546.871167594       0xff6bb67d1]   dbg_gadget_giveback: ep7in: req ffffff8036bae500 length 0/65536 zsI ==> -108
[ 3546.881933479       0xff6be8f42]   dbg_gadget_giveback: ep7in: req ffffff804d0d1400 length 0/65536 zsI ==> -108
[ 3546.882782594       0xff6becef1]   dbg_gadget_giveback: ep7in: req ffffff804d0d0400 length 0/65536 zsI ==> -108
[ 3546.884671760       0xff6bf5ca1]   dbg_gadget_giveback: ep7in: req ffffff804d0d1b00 length 0/65536 zsI ==> -108
[ 3546.885435042       0xff6bf95e1]   dbg_gadget_giveback: ep7in: req ffffff804d37c900 length 0/65536 zsI ==> -108
[ 3546.886215875       0xff6bfd070]   dbg_gadget_giveback: ep7in: req ffffff804d37c300 length 0/65536 zsI ==> -108
[ 3546.901101760       0xff6c42ce1]   dbg_gadget_giveback: ep7in: req ffffff8041ede000 length 0/65536 zsI ==> -108
[ 3546.901817177       0xff6c46289]   dbg_gadget_giveback: ep7in: req ffffff8041edf800 length 0/65536 zsI ==> -108
[ 3546.910264833       0xff6c6dc1c]   dbg_gadget_giveback: ep7in: req ffffff8023a31000 length 0/65536 zsI ==> -108
[ 3546.911045823       0xff6c716af]   dbg_gadget_giveback: ep7in: req ffffff8023a30e00 length 0/65536 zsI ==> -108
[ 3546.912214573       0xff6c76e57]   dbg_gadget_giveback: ep7in: req ffffff8023a30b00 length 0/65536 zsI ==> -108
[ 3546.917393167       0xff6c8f2bc]   dbg_gadget_giveback: ep7in: req ffffff8032384d00 length 0/65536 zsI ==> -108
[ 3546.918179990       0xff6c92dbf]   dbg_gadget_giveback: ep7in: req ffffff8042dd0c00 length 0/65536 zsI ==> -108
[ 3546.918975094       0xff6c96961]   dbg_gadget_giveback: ep7in: req ffffff88620afa00 length 0/65536 zsI ==> -108
[ 3546.920188323       0xff6c9c45f]   dbg_gadget_giveback: ep7in: req ffffff88620ae700 length 0/65536 zsI ==> -108
[ 3546.936851761       0xff6cea621]   dbg_gadget_giveback: ep7in: req ffffff87895f8000 length 0/65536 zsI ==> -108
[ 3546.937623844       0xff6cee00a]   dbg_gadget_giveback: ep7in: req ffffff87895f9b00 length 0/65536 zsI ==> -108
[ 3546.938406917       0xff6cf1ac4]   dbg_gadget_giveback: ep7in: req ffffff8023baad00 length 0/65536 zsI ==> -108
[ 3546.939205667       0xff6cf56ac]   dbg_gadget_giveback: ep7in: req ffffff8023bab100 length 0/65536 zsI ==> -108
[ 3546.970570406       0xff6d88707]   dbg_gadget_giveback: ep7in: req ffffff87b44f8800 length 0/65536 zsI ==> -108
[ 3546.971821969       0xff6d8e4e5]   dbg_gadget_giveback: ep7in: req ffffff87b44f9400 length 0/65536 zsI ==> -108
[ 3546.972633844       0xff6d921c9]   dbg_gadget_giveback: ep7in: req ffffff804d0dc000 length 0/65536 zsI ==> -108
[ 3546.973397854       0xff6d95b17]   dbg_gadget_giveback: ep7in: req ffffff8040cd8d00 length 0/65536 zsI ==> -108
[ 3546.974192802       0xff6d996b5]   dbg_gadget_giveback: ep7in: req ffffff8040cd8a00 length 0/65536 zsI ==> -108
[ 3546.975155198       0xff6d9dee3]   dbg_gadget_giveback: ep7in: req ffffff8040cd9d00 length 0/65536 zsI ==> -108
[ 3546.978181709       0xff6dac1e0]   dbg_gadget_giveback: ep7in: req ffffff8041723100 length 0/65536 zsI ==> -108
[ 3546.978944365       0xff6dafb13]   dbg_gadget_giveback: ep7in: req ffffff8040d3c700 length 0/65536 zsI ==> -108
[ 3546.979974938       0xff6db485e]   dbg_gadget_giveback: ep7in: req ffffff802499ad00 length 0/65536 zsI ==> -108
[ 3546.980641344       0xff6db7a59]   dbg_gadget_giveback: ep7in: req ffffff87e4615e00 length 0/65536 zsI ==> -108
[ 3546.981403584       0xff6dbb384]   dbg_gadget_giveback: ep7in: req ffffff8849202100 length 0/65536 zsI ==> -108
[ 3546.982172542       0xff6dbed30]   dbg_gadget_giveback: ep7in: req ffffff87de5da900 length 0/65536 zsI ==> -108
[ 3546.982942438       0xff6dc26ee]   dbg_gadget_giveback: ep7in: req ffffff87de5dae00 length 0/65536 zsI ==> -108
[ 3547.008291761       0xff6e39421]   dbg_gadget_giveback: ep7in: req ffffff87de5daa00 length 0/65536 zsI ==> -108
[ 3547.009399834       0xff6e3e73c]   dbg_gadget_giveback: ep7in: req ffffff87de5dbf00 length 0/65536 zsI ==> -108
[ 3547.010163896       0xff6e4208a]   dbg_gadget_giveback: ep7in: req ffffff87de5da000 length 0/65536 zsI ==> -108
[ 3547.010932386       0xff6e45a2d]   dbg_gadget_giveback: ep7in: req ffffff87de5dac00 length 0/65536 zsI ==> -108
[ 3547.011926917       0xff6e4a4c4]   dbg_gadget_giveback: ep7in: req ffffff87de5da200 length 0/65536 zsI ==> -108
[ 3547.012638063       0xff6e4da1a]   dbg_gadget_giveback: ep7in: req ffffff87de5dbd00 length 0/65536 zsI ==> -108
[ 3547.013404625       0xff6e51398]   dbg_gadget_giveback: ep7in: req ffffff87de5dba00 length 0/65536 zsI ==> -108
[ 3547.014173636       0xff6e54d45]   dbg_gadget_giveback: ep7in: req ffffff87de5dbc00 length 0/65536 zsI ==> -108
[ 3547.014942646       0xff6e586f3]   dbg_gadget_giveback: ep7in: req ffffff87de5daf00 length 0/65536 zsI ==> -108
[ 3547.033604365       0xff6eafe93]   dbg_gadget_giveback: ep7in: req ffffff87de5da800 length 0/65536 zsI ==> -108
[ 3547.034769261       0xff6eb55f1]   dbg_gadget_giveback: ep7in: req ffffff87de5db200 length 0/65536 zsI ==> -108
[ 3547.035854730       0xff6eba75a]   dbg_gadget_giveback: ep7in: req ffffff87de5dad00 length 0/65536 zsI ==> -108
[ 3547.036624000       0xff6ebe10c]   dbg_gadget_giveback: ep7in: req ffffff87de5db000 length 0/65536 zsI ==> -108
[ 3547.037382490       0xff6ec19f0]   dbg_gadget_giveback: ep7in: req ffffff87de5db100 length 0/65536 zsI ==> -108
[ 3547.038150823       0xff6ec538f]   dbg_gadget_giveback: ep7in: req ffffff87de5da500 length 0/65536 zsI ==> -108
[ 3547.038859990       0xff6ec88bf]   dbg_gadget_giveback: ep7in: req ffffff87de5da300 length 0/65536 zsI ==> -108
[ 3547.039919417       0xff6ecd835]   dbg_gadget_giveback: ep7in: req ffffff8040c99700 length 0/65536 zsI ==> -108
[ 3547.056859730       0xff6f1ceba]   dbg_gadget_giveback: ep7in: req ffffff8040c99b00 length 0/65536 zsI ==> -108
[ 3547.057651813       0xff6f20a23]   dbg_gadget_giveback: ep7in: req ffffff8032246300 length 0/65536 zsI ==> -108
[ 3547.059332438       0xff6f2882e]   dbg_gadget_giveback: ep7in: req ffffff87d68d3c00 length 0/65536 zsI ==> -108
[ 3547.061640980       0xff6f33552]   dbg_gadget_giveback: ep7in: req ffffff87d68d3f00 length 0/65536 zsI ==> -108
[ 3547.063105407       0xff6f3a327]   dbg_gadget_giveback: ep7in: req ffffff87d68d2b00 length 0/65536 zsI ==> -108
[ 3547.084589573       0xff6f9ee78]   dbg_gadget_giveback: ep7in: req ffffff80249dfe00 length 0/65536 zsI ==> -108
[ 3547.085392907       0xff6fa2ab7]   dbg_gadget_giveback: ep7in: req ffffff80249ded00 length 0/65536 zsI ==> -108
[ 3547.086182438       0xff6fa65ee]   dbg_gadget_giveback: ep7in: req ffffff8042dca200 length 0/65536 zsI ==> -108
[ 3547.087045719       0xff6faa6ad]   dbg_gadget_giveback: ep7in: req ffffff80442ecc00 length 0/65536 zsI ==> -108
[ 3547.088267646       0xff6fb0252]   dbg_gadget_giveback: ep7in: req ffffff87b0b06800 length 0/65536 zsI ==> -108
[ 3547.089061553       0xff6fb3ddd]   dbg_gadget_giveback: ep7in: req ffffff87b0b07c00 length 0/65536 zsI ==> -108
[ 3547.089855824       0xff6fb7970]   dbg_gadget_giveback: ep7in: req ffffff87b0b06e00 length 0/65536 zsI ==> -108
[ 3547.090638271       0xff6fbb41e]   dbg_gadget_giveback: ep7in: req ffffff804d372a00 length 0/65536 zsI ==> -108
[ 3547.091681605       0xff6fc025e]   dbg_gadget_giveback: ep7in: req ffffff8041579a00 length 0/65536 zsI ==> -108
[ 3547.115009626       0xff702d7f8]   dbg_gadget_giveback: ep7in: req ffffff8041579400 length 0/65536 zsI ==> -108
[ 3547.116185303       0xff7033025]   dbg_gadget_giveback: ep7in: req ffffff8041fbb000 length 0/65536 zsI ==> -108
[ 3547.116970303       0xff7036b05]   dbg_gadget_giveback: ep7in: req ffffff802489b000 length 0/65536 zsI ==> -108
[ 3547.117783949       0xff703a80b]   dbg_gadget_giveback: ep7in: req ffffff802489ab00 length 0/65536 zsI ==> -108
[ 3547.118563480       0xff703e282]   dbg_gadget_giveback: ep7in: req ffffff87dd69c200 length 0/65536 zsI ==> -108
[ 3547.119763949       0xff7043c8b]   dbg_gadget_giveback: ep7in: req ffffff87dd69c900 length 0/65536 zsI ==> -108
[ 3547.120534574       0xff7047657]   dbg_gadget_giveback: ep7in: req ffffff87dd69de00 length 0/65536 zsI ==> -108
[ 3547.121331605       0xff704b21e]   dbg_gadget_giveback: ep7in: req ffffff87dd69d100 length 0/65536 zsI ==> -108
[ 3547.121958376       0xff704e120]   dbg_gadget_giveback: ep7in: req ffffff87dd69ce00 length 0/65536 zsI ==> -108
[ 3547.122534990       0xff7050c5f]   dbg_gadget_giveback: ep7in: req ffffff87dd69d500 length 0/65536 zsI ==> -108
[ 3547.123312751       0xff70546b4]   dbg_gadget_giveback: ep7in: req ffffff87dd69d600 length 0/65536 zsI ==> -108
[ 3547.158687438       0xff70fa3ce]   dbg_gadget_giveback: ep7in: req ffffff87dd69c100 length 0/65536 zsI ==> -108
[ 3547.161101188       0xff71058d7]   dbg_gadget_giveback: ep7in: req ffffff87dd69c400 length 0/65536 zsI ==> -108
[ 3547.162877178       0xff710de09]   dbg_gadget_giveback: ep7in: req ffffff87dd69cb00 length 0/65536 zsI ==> -108
[ 3547.176528168       0xff714dddc]   dbg_gadget_giveback: ep7in: req ffffff87dd69df00 length 0/65536 zsI ==> -108
[ 3547.177409470       0xff7151ff5]   dbg_gadget_giveback: ep7in: req ffffff87dd69da00 length 0/65536 zsI ==> -108
[ 3547.178189365       0xff7155a73]   dbg_gadget_giveback: ep7in: req ffffff87dd69c000 length 0/65536 zsI ==> -108
[ 3547.179003897       0xff715978a]   dbg_gadget_giveback: ep7in: req ffffff87dd69c600 length 0/65536 zsI ==> -108
[ 3547.193686032       0xff719e4b3]   dbg_gadget_giveback: ep7in: req ffffff87dd69dd00 length 0/65536 zsI ==> -108
[ 3547.213244470       0xff71f9f96]   dbg_gadget_giveback: ep7in: req ffffff87dd69d800 length 0/65536 zsI ==> -108
[ 3547.214852178       0xff7201829]   dbg_gadget_giveback: ep7in: req ffffff880668f100 length 0/65536 zsI ==> -108
[ 3547.217412386       0xff720d82d]   dbg_gadget_giveback: ep7in: req ffffff880668f700 length 0/65536 zsI ==> -108
[ 3547.219051032       0xff7215313]   dbg_gadget_giveback: ep7in: req ffffff880668e800 length 0/65536 zsI ==> -108
[ 3547.229822855       0xff7247af6]   dbg_gadget_giveback: ep7in: req ffffff803afdef00 length 0/65536 zsI ==> -108
[ 3547.232341866       0xff72537e3]   dbg_gadget_giveback: ep7in: req ffffff803afde000 length 0/65536 zsI ==> -108
[ 3547.233918011       0xff725ae1a]   dbg_gadget_giveback: ep7in: req ffffff87faca8c00 length 0/65536 zsI ==> -108
[ 3547.235279834       0xff726143c]   dbg_gadget_giveback: ep7in: req ffffff80255aa500 length 0/65536 zsI ==> -108
[ 3547.249605824       0xff72a46af]   dbg_gadget_giveback: ep7in: req ffffff8040d34c00 length 0/65536 zsI ==> -108
[ 3547.250976553       0xff72aad7d]   dbg_gadget_giveback: ep7in: req ffffff8040d34200 length 0/65536 zsI ==> -108
[ 3547.269110355       0xff72ffd86]   dbg_gadget_giveback: ep7in: req ffffff8040d34500 length 0/65536 zsI ==> -108
[ 3547.270894262       0xff7308351]   dbg_gadget_giveback: ep7in: req ffffff8040d35200 length 0/65536 zsI ==> -108
[ 3547.273144626       0xff7312c18]   dbg_gadget_giveback: ep7in: req ffffff87d2bdd300 length 0/65536 zsI ==> -108
[ 3547.274712439       0xff731a1ae]   dbg_gadget_giveback: ep7in: req ffffff87d2bddd00 length 0/65536 zsI ==> -108
[ 3547.293424887       0xff7371d1e]   dbg_gadget_giveback: ep7in: req ffffff87d2bdc300 length 0/65536 zsI ==> -108
[ 3547.295049782       0xff73796fb]   dbg_gadget_giveback: ep7in: req ffffff87d2bdcf00 length 0/65536 zsI ==> -108
[ 3547.297308220       0xff738405d]   dbg_gadget_giveback: ep7in: req ffffff87d2bdc600 length 0/65536 zsI ==> -108
[ 3547.298899939       0xff738b7be]   dbg_gadget_giveback: ep7in: req ffffff87d2bdcd00 length 0/65536 zsI ==> -108
[ 3547.317192387       0xff73e13ad]   dbg_gadget_giveback: ep7in: req ffffff87d2bdde00 length 0/65536 zsI ==> -108
[ 3547.320626918       0xff73f1544]   dbg_gadget_giveback: ep7in: req ffffff804167cb00 length 0/65536 zsI ==> -108
[ 3547.337847543       0xff74420d0]   dbg_gadget_giveback: ep7in: req ffffff804167dc00 length 0/65536 zsI ==> -108
[ 3547.366441554       0xff74c815d]   dbg_gadget_giveback: ep7in: req ffffff804167d500 length 0/65536 zsI ==> -108
[ 3547.368828585       0xff74d3465]   dbg_gadget_giveback: ep7in: req ffffff804167c800 length 0/65536 zsI ==> -108
[ 3547.370431293       0xff74dac98]   dbg_gadget_giveback: ep7in: req ffffff87c5713f00 length 0/65536 zsI ==> -108
[ 3547.389275772       0xff75331ee]   dbg_gadget_giveback: ep7in: req ffffff87c5712300 length 0/65536 zsI ==> -108
[ 3547.392396189       0xff7541bf7]   dbg_gadget_giveback: ep7in: req ffffff87c5712200 length 0/65536 zsI ==> -108
[ 3547.393965877       0xff75491b0]   dbg_gadget_giveback: ep7in: req ffffff87c5713a00 length 0/65536 zsI ==> -108
[ 3547.396504835       0xff755501c]   dbg_gadget_giveback: ep7in: req ffffff87c5712500 length 0/65536 zsI ==> -108
[ 3547.418647700       0xff75bccd3]   dbg_gadget_giveback: ep7in: req ffffff87a64d2f00 length 0/65536 zsI ==> -108
[ 3547.421113845       0xff75c85c9]   dbg_gadget_giveback: ep7in: req ffffff87a64d2700 length 0/65536 zsI ==> -108
[ 3547.422741866       0xff75cffe3]   dbg_gadget_giveback: ep7in: req ffffff87a64d3c00 length 0/65536 zsI ==> -108
[ 3547.446278064       0xff763e51a]   dbg_gadget_giveback: ep7in: req ffffff804143fd00 length 0/65536 zsI ==> -108
[ 3547.448724939       0xff7649c9e]   dbg_gadget_giveback: ep7in: req ffffff804162f400 length 0/65536 zsI ==> -108
[ 3547.450535720       0xff765246d]   dbg_gadget_giveback: ep7in: req ffffff87d5d17200 length 0/65536 zsI ==> -108
[ 3547.468997387       0xff76a8d0d]   dbg_gadget_giveback: ep7in: req ffffff87d5d17800 length 0/65536 zsI ==> -108
[ 3547.470651710       0xff76b0920]   dbg_gadget_giveback: ep7in: req ffffff87d5d16d00 length 0/65536 zsI ==> -108
[ 3547.486019418       0xff76f89b4]   dbg_gadget_giveback: ep7in: req ffffff87d5d17000 length 0/65536 zsI ==> -108
[ 3547.491145564       0xff7710a2a]   dbg_gadget_giveback: ep7in: req ffffff87d5d16200 length 0/65536 zsI ==> -108
[ 3547.493527231       0xff771bcca]   dbg_gadget_giveback: ep7in: req ffffff87d5d17300 length 0/65536 zsI ==> -108
[ 3547.495059783       0xff7722fbb]   dbg_gadget_giveback: ep7in: req ffffff87d5d17100 length 0/65536 zsI ==> -108
[ 3547.514971033       0xff7780514]   dbg_gadget_giveback: ep7in: req ffffff87d0b9c600 length 0/65536 zsI ==> -108
[ 3547.517345929       0xff778b732]   dbg_gadget_giveback: ep7in: req ffffff803af47700 length 0/65536 zsI ==> -108
[ 3547.520089471       0xff77984f6]   dbg_gadget_giveback: ep7in: req ffffff882974d100 length 0/65536 zsI ==> -108
[ 3547.521710512       0xff779fe8a]   dbg_gadget_giveback: ep7in: req ffffff882974c200 length 0/65536 zsI ==> -108
[ 3547.524341554       0xff77ac3de]   dbg_gadget_giveback: ep7in: req ffffff87b728cb00 length 0/65536 zsI ==> -108
[ 3547.525982908       0xff77b3ef7]   dbg_gadget_giveback: ep7in: req ffffff87b728d000 length 0/65536 zsI ==> -108
[ 3547.528625877       0xff77c0531]   dbg_gadget_giveback: ep7in: req ffffff87b728da00 length 0/65536 zsI ==> -108
[ 3547.530335512       0xff77c856a]   dbg_gadget_giveback: ep7in: req ffffff8041e77c00 length 0/65536 zsI ==> -108
[ 3547.542120721       0xff77ff94e]   dbg_gadget_giveback: ep7in: req ffffff8041e76e00 length 0/65536 zsI ==> -108
[ 3547.544416919       0xff780a585]   dbg_gadget_giveback: ep7in: req ffffff8044306100 length 0/65536 zsI ==> -108
[ 3547.545927179       0xff78116c9]   dbg_gadget_giveback: ep7in: req ffffff8044307000 length 0/65536 zsI ==> -108
[ 3547.548311762       0xff781c9a2]   dbg_gadget_giveback: ep7in: req ffffff8044307e00 length 0/65536 zsI ==> -108
[ 3547.558400460       0xff784be48]   dbg_gadget_giveback: ep7in: req ffffff8783b84200 length 0/65536 zsI ==> -108
[ 3547.560926554       0xff7857bbe]   dbg_gadget_giveback: ep7in: req ffffff8040cc6200 length 0/65536 zsI ==> -108
[ 3547.563162908       0xff7862378]   dbg_gadget_giveback: ep7in: req ffffff8040cc6600 length 0/65536 zsI ==> -108
[ 3547.565831137       0xff786eb96]   dbg_gadget_giveback: ep7in: req ffffff802c6e9300 length 0/65536 zsI ==> -108
[ 3547.568820252       0xff787cbc5]   dbg_gadget_giveback: ep7in: req ffffff881e595a00 length 0/65536 zsI ==> -108
[ 3547.573917804       0xff7894a16]   dbg_gadget_giveback: ep7in: req ffffff881e595800 length 0/65536 zsI ==> -108
[ 3547.593806085       0xff78f1db5]   dbg_gadget_giveback: ep7in: req ffffff881e594d00 length 0/65536 zsI ==> -108
[ 3547.598598065       0xff790851c]   dbg_gadget_giveback: ep7in: req ffffff804043f900 length 0/65536 zsI ==> -108
[ 3547.620778169       0xff797049c]   dbg_gadget_giveback: ep7in: req ffffff804043f300 length 0/65536 zsI ==> -108
[ 3547.622610513       0xff7978e09]   dbg_gadget_giveback: ep7in: req ffffff804043f200 length 0/65536 zsI ==> -108
[ 3547.635258950       0xff79b42ab]   dbg_gadget_giveback: ep7in: req ffffff804043f400 length 0/65536 zsI ==> -108
[ 3547.637727648       0xff79bfbd2]   dbg_gadget_giveback: ep7in: req ffffff885e9ac300 length 0/65536 zsI ==> -108
[ 3547.639346763       0xff79c7541]   dbg_gadget_giveback: ep7in: req ffffff885e9ace00 length 0/65536 zsI ==> -108
[ 3547.641704784       0xff79d261b]   dbg_gadget_giveback: ep7in: req ffffff885e9ad800 length 0/65536 zsI ==> -108
[ 3547.643324211       0xff79d9f90]   dbg_gadget_giveback: ep7in: req ffffff885e9ac900 length 0/65536 zsI ==> -108
[ 3547.653940044       0xff7a0bbc0]   dbg_gadget_giveback: ep7in: req ffffff885e9ac400 length 0/65536 zsI ==> -108
[ 3547.656689940       0xff7a189fe]   dbg_gadget_giveback: ep7in: req ffffff885e9acd00 length 0/65536 zsI ==> -108
[ 3547.658324054       0xff7a2048d]   dbg_gadget_giveback: ep7in: req ffffff8042d7ba00 length 0/65536 zsI ==> -108
[ 3547.669459627       0xff7a547b8]   dbg_gadget_giveback: ep7in: req ffffff88605f4300 length 0/65536 zsI ==> -108
[ 3547.671027179       0xff7a5bd49]   dbg_gadget_giveback: ep7in: req ffffff88605f5100 length 0/65536 zsI ==> -108
[ 3547.673341711       0xff7a66ae0]   dbg_gadget_giveback: ep7in: req ffffff88605f4600 length 0/65536 zsI ==> -108
[ 3547.674821554       0xff7a6d9dd]   dbg_gadget_giveback: ep7in: req ffffff88605f5a00 length 0/65536 zsI ==> -108
[ 3547.685686763       0xff7aa08c1]   dbg_gadget_giveback: ep7in: req ffffff88605f5700 length 0/65536 zsI ==> -108
[ 3547.688658117       0xff7aae79b]   dbg_gadget_giveback: ep7in: req ffffff88605f4000 length 0/65536 zsI ==> -108
[ 3547.690248065       0xff7ab5eda]   dbg_gadget_giveback: ep7in: req ffffff88605f5f00 length 0/65536 zsI ==> -108
[ 3547.701005200       0xff7ae85a3]   dbg_gadget_giveback: ep7in: req ffffff88605f4d00 length 0/65536 zsI ==> -108
[ 3547.702637805       0xff7af0015]   dbg_gadget_giveback: ep7in: req ffffff804d199100 length 0/65536 zsI ==> -108
[ 3547.704923690       0xff7afab86]   dbg_gadget_giveback: ep7in: req ffffff804d198b00 length 0/65536 zsI ==> -108
[ 3547.706694784       0xff7b0305b]   dbg_gadget_giveback: ep7in: req ffffff87cc07c400 length 0/65536 zsI ==> -108
[ 3547.717655565       0xff7b3666a]   dbg_gadget_giveback: ep7in: req ffffff87cc07db00 length 0/65536 zsI ==> -108
[ 3547.719285773       0xff7b3e0ae]   dbg_gadget_giveback: ep7in: req ffffff87cc07c700 length 0/65536 zsI ==> -108
[ 3547.721625982       0xff7b49032]   dbg_gadget_giveback: ep7in: req ffffff804163bd00 length 0/65536 zsI ==> -108
[ 3547.723244055       0xff7b5098e]   dbg_gadget_giveback: ep7in: req ffffff8041e75f00 length 0/65536 zsI ==> -108
[ 3547.741823378       0xff7ba7b00]   dbg_gadget_giveback: ep7in: req ffffff8041e75a00 length 0/65536 zsI ==> -108
[ 3547.742606607       0xff7bab5be]   dbg_gadget_giveback: ep7in: req ffffff8041e75c00 length 0/65536 zsI ==> -108
[ 3547.744292961       0xff7bb3438]   dbg_gadget_giveback: ep7in: req ffffff80255db800 length 0/65536 zsI ==> -108
[ 3547.753918169       0xff7be061d]   dbg_gadget_giveback: ep7in: req ffffff80255dae00 length 0/65536 zsI ==> -108
[ 3547.754675253       0xff7be3ee4]   dbg_gadget_giveback: ep7in: req ffffff80255db100 length 0/65536 zsI ==> -108
[ 3547.756314471       0xff7beb9d5]   dbg_gadget_giveback: ep7in: req ffffff80255da800 length 0/65536 zsI ==> -108
[ 3547.758286815       0xff7bf4dc3]   dbg_gadget_giveback: ep7in: req ffffff87a6479200 length 0/65536 zsI ==> -108
[ 3547.759180409       0xff7bf90c7]   dbg_gadget_giveback: ep7in: req ffffff87a6479600 length 0/65536 zsI ==> -108
[ 3547.760461034       0xff7bff0d4]   dbg_gadget_giveback: ep7in: req ffffff8023a40a00 length 0/65536 zsI ==> -108
[ 3547.761229211       0xff7c02a70]   dbg_gadget_giveback: ep7in: req ffffff8040fbc600 length 0/65536 zsI ==> -108
[ 3547.761993534       0xff7c063c3]   dbg_gadget_giveback: ep7in: req ffffff87e9690200 length 0/65536 zsI ==> -108
[ 3547.762758638       0xff7c09d25]   dbg_gadget_giveback: ep7in: req ffffff885f067300 length 0/65536 zsI ==> -108
[ 3547.777595201       0xff7c4f5e3]   dbg_gadget_giveback: ep7in: req ffffff885f066a00 length 0/65536 zsI ==> -108
[ 3547.778378951       0xff7c530ab]   dbg_gadget_giveback: ep7in: req ffffff885f066d00 length 0/65536 zsI ==> -108
[ 3547.779185096       0xff7c56d21]   dbg_gadget_giveback: ep7in: req ffffff885f067e00 length 0/65536 zsI ==> -108
[ 3547.785993274       0xff7c76bbe]   dbg_gadget_giveback: ep7in: req ffffff885f067b00 length 0/65536 zsI ==> -108
[ 3547.786798586       0xff7c7a824]   dbg_gadget_giveback: ep7in: req ffffff8023ad8d00 length 0/65536 zsI ==> -108
[ 3547.794789211       0xff7c9ff70]   dbg_gadget_giveback: ep7in: req ffffff87e7cab100 length 0/65536 zsI ==> -108
[ 3547.797819940       0xff7cae2be]   dbg_gadget_giveback: ep7in: req ffffff8040cc5800 length 0/65536 zsI ==> -108
[ 3547.798592440       0xff7cb1cae]   dbg_gadget_giveback: ep7in: req ffffff8040cc5000 length 0/65536 zsI ==> -108
[ 3547.800129419       0xff7cb8ff4]   dbg_gadget_giveback: ep7in: req ffffff8040e96f00 length 0/65536 zsI ==> -108
[ 3547.805922024       0xff7cd4266]   dbg_gadget_giveback: ep7in: req ffffff80407d1e00 length 0/65536 zsI ==> -108
[ 3547.806672909       0xff7cd7ab7]   dbg_gadget_giveback: ep7in: req ffffff87b6cd2c00 length 0/65536 zsI ==> -108
[ 3547.808150722       0xff7cde98d]   dbg_gadget_giveback: ep7in: req ffffff8862351b00 length 0/65536 zsI ==> -108
[ 3547.821870930       0xff7d1ee91]   dbg_gadget_giveback: ep7in: req ffffff87cb6f7c00 length 0/65536 zsI ==> -108
[ 3547.822674992       0xff7d22adf]   dbg_gadget_giveback: ep7in: req ffffff87cb6f7600 length 0/65536 zsI ==> -108
[ 3547.823323117       0xff7d25b7b]   dbg_gadget_giveback: ep7in: req ffffff87cb6f7f00 length 0/65536 zsI ==> -108
[ 3547.830154992       0xff7d45bdf]   dbg_gadget_giveback: ep7in: req ffffff87a578b200 length 0/65536 zsI ==> -108
[ 3547.830996607       0xff7d49aff]   dbg_gadget_giveback: ep7in: req ffffff8042c2b800 length 0/65536 zsI ==> -108
[ 3547.832107284       0xff7d4ee4b]   dbg_gadget_giveback: ep7in: req ffffff8042c2a200 length 0/65536 zsI ==> -108
[ 3547.832926347       0xff7d52bb9]   dbg_gadget_giveback: ep7in: req ffffff8034aeb100 length 0/65536 zsI ==> -108
[ 3547.833693690       0xff7d56546]   dbg_gadget_giveback: ep7in: req ffffff8034aea400 length 0/65536 zsI ==> -108
[ 3547.834456034       0xff7d59e73]   dbg_gadget_giveback: ep7in: req ffffff8042dcee00 length 0/65536 zsI ==> -108
[ 3547.835271138       0xff7d5db95]   dbg_gadget_giveback: ep7in: req ffffff87cc07b300 length 0/65536 zsI ==> -108
[ 3547.850399472       0xff7da4a35]   dbg_gadget_giveback: ep7in: req ffffff80414fbd00 length 0/65536 zsI ==> -108
[ 3547.851164472       0xff7da8395]   dbg_gadget_giveback: ep7in: req ffffff8042c27d00 length 0/65536 zsI ==> -108
[ 3547.860316034       0xff7dd31f3]   dbg_gadget_giveback: ep7in: req ffffff8041e7ec00 length 0/65536 zsI ==> -108
[ 3547.860939263       0xff7dd60b1]   dbg_gadget_giveback: ep7in: req ffffff8033cfcd00 length 0/65536 zsI ==> -108
[ 3547.861590201       0xff7dd9183]   dbg_gadget_giveback: ep7in: req ffffff8033cfd700 length 0/65536 zsI ==> -108
[ 3547.862373222       0xff7ddcc3d]   dbg_gadget_giveback: ep7in: req ffffff8033cfd600 length 0/65536 zsI ==> -108
[ 3547.863239680       0xff7de0d39]   dbg_gadget_giveback: ep7in: req ffffff8033cfd100 length 0/65536 zsI ==> -108
[ 3547.868545670       0xff7df9b2c]   dbg_gadget_giveback: ep7in: req ffffff87b91f1f00 length 0/65536 zsI ==> -108
[ 3547.869334940       0xff7dfd65e]   dbg_gadget_giveback: ep7in: req ffffff87b91f1000 length 0/65536 zsI ==> -108
[ 3547.870114003       0xff7e010cc]   dbg_gadget_giveback: ep7in: req ffffff87b91f0700 length 0/65536 zsI ==> -108
[ 3547.870925253       0xff7e04da4]   dbg_gadget_giveback: ep7in: req ffffff87b91f0f00 length 0/65536 zsI ==> -108
[ 3547.885231399       0xff7e47e9a]   dbg_gadget_giveback: ep7in: req ffffff87b91f0200 length 0/65536 zsI ==> -108
[ 3547.887091972       0xff7e50a25]   dbg_gadget_giveback: ep7in: req ffffff87b91f0400 length 0/65536 zsI ==> -108
[ 3547.894081920       0xff7e71664]   dbg_gadget_giveback: ep7in: req ffffff87b91f1300 length 0/65536 zsI ==> -108
[ 3547.896615513       0xff7e7d469]   dbg_gadget_giveback: ep7in: req ffffff87b91f1800 length 0/65536 zsI ==> -108
[ 3547.898270566       0xff7e8508b]   dbg_gadget_giveback: ep7in: req ffffff8041e89300 length 0/65536 zsI ==> -108
[ 3547.916835878       0xff7edc0f0]   dbg_gadget_giveback: ep7in: req ffffff8041e88800 length 0/65536 zsI ==> -108
[ 3547.918536139       0xff7ee4075]   dbg_gadget_giveback: ep7in: req ffffff8041e89d00 length 0/65536 zsI ==> -108
[ 3547.920910618       0xff7eef28b]   dbg_gadget_giveback: ep7in: req ffffff87de297600 length 0/65536 zsI ==> -108
[ 3547.922542336       0xff7ef6cec]   dbg_gadget_giveback: ep7in: req ffffff8044310e00 length 0/65536 zsI ==> -108
[ 3547.939264264       0xff7f45311]   dbg_gadget_giveback: ep7in: req ffffff8020658300 length 0/65536 zsI ==> -108
[ 3547.953857493       0xff7f8998f]   dbg_gadget_giveback: ep7in: req ffffff8783d97c00 length 0/65536 zsI ==> -108
[ 3547.956519159       0xff7f9612f]   dbg_gadget_giveback: ep7in: req ffffff8042d79800 length 0/65536 zsI ==> -108
[ 3547.957915097       0xff7f9c9e1]   dbg_gadget_giveback: ep7in: req ffffff8042d79700 length 0/65536 zsI ==> -108
[ 3547.960268118       0xff7fa7a5b]   dbg_gadget_giveback: ep7in: req ffffff8042d78b00 length 0/65536 zsI ==> -108
[ 3547.973576191       0xff7fe6077]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3547.974296868       0xff7fe9684]   dbg_send_ep_cmd: ep0out: cmd 'Set Stall' [404] params 00000000 00000000 00000000 --> status: Successful
[ 3547.975006607       0xff7fecbbf]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3547.975438326       0xff7feec20]   event (000010c0): ep0out: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3547.976404680       0xff7ff3499]   dbg_gadget_giveback: ep7in: req ffffff8041574f00 length 0/65536 zsI ==> -108
[ 3547.977924837       0xff7ffa69d]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3547.978679941       0xff7ffdf3f]   dbg_send_ep_cmd: ep0out: cmd 'Set Stall' [404] params 00000000 00000000 00000000 --> status: Successful
[ 3547.979498587       0xff8001ca4]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3547.979938482       0xff8003da3]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3547.988020045       0xff8029bc1]   dbg_send_ep_cmd: ep0out: cmd 'End Transfer' [508] params 00000000 00000000 00000000 --> status: Successful
[ 3547.988533066       0xff802c23a]   dbg_send_ep_cmd: ep0out: cmd 'Set Stall' [404] params 00000000 00000000 00000000 --> status: Successful
[ 3547.989320930       0xff802fd52]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3547.994597076       0xff8048907]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3547.995339212       0xff804c0b2]   dbg_send_ep_cmd: ep0out: cmd 'Set Stall' [404] params 00000000 00000000 00000000 --> status: Successful
[ 3547.996399108       0xff8051030]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3547.996835670       0xff80530ec]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3548.004830253       0xff8078885]   dbg_send_ep_cmd: ep0out: cmd 'End Transfer' [508] params 00000000 00000000 00000000 --> status: Successful
[ 3548.005331764       0xff807ae21]   dbg_send_ep_cmd: ep0out: cmd 'Set Stall' [404] params 00000000 00000000 00000000 --> status: Successful
[ 3548.006170410       0xff807ed08]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3548.006653014       0xff808113a]   event (080001c0): ep0out: Endpoint Command Complete
[ 3548.007085045       0xff80831a1]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3548.015352910       0xff80a9db9]   dbg_send_ep_cmd: ep0out: cmd 'End Transfer' [508] params 00000000 00000000 00000000 --> status: Successful
[ 3548.016071608       0xff80ad39f]   dbg_send_ep_cmd: ep0out: cmd 'Set Stall' [404] params 00000000 00000000 00000000 --> status: Successful
[ 3548.016781868       0xff80b08e3]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3548.017235306       0xff80b2ae5]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3548.017997753       0xff80b6415]   dbg_send_ep_cmd: ep0out: cmd 'Set Stall' [404] params 00000000 00000000 00000000 --> status: Successful
[ 3548.019023951       0xff80bb10c]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3548.019262337       0xff80bc2ec]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3548.026914941       0xff80e00df]   dbg_send_ep_cmd: ep0out: cmd 'End Transfer' [508] params 00000000 00000000 00000000 --> status: Successful
[ 3548.027250201       0xff80e1a04]   dbg_send_ep_cmd: ep0out: cmd 'Set Stall' [404] params 00000000 00000000 00000000 --> status: Successful
[ 3548.027656608       0xff80e387e]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3548.028066295       0xff80e5738]   dbg_gadget_giveback: ep7in: req ffffff8041575b00 length 0/65536 zsI ==> -108
[ 3548.030426712       0xff80f0841]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3548.030821347       0xff80f25da]   dbg_send_ep_cmd: ep0out: cmd 'Set Stall' [404] params 00000000 00000000 00000000 --> status: Successful
[ 3548.031474993       0xff80f56e0]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: No Resource
[ 3548.031717128       0xff80f6909]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3548.039318587       0xff811a325]   dbg_send_ep_cmd: ep0out: cmd 'End Transfer' [508] params 00000000 00000000 00000000 --> status: Successful
[ 3548.039650670       0xff811bc0d]   dbg_send_ep_cmd: ep0out: cmd 'Set Stall' [404] params 00000000 00000000 00000000 --> status: Successful
[ 3548.040223795       0xff811e708]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3548.040454941       0xff811f85f]   event (080001c0): ep0out: Endpoint Command Complete
[ 3548.040665774       0xff812082f]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3548.058869524       0xff8175d77]   dbg_send_ep_cmd: ep0out: cmd 'End Transfer' [508] params 00000000 00000000 00000000 --> status: Successful
[ 3548.059194941       0xff81775df]   dbg_send_ep_cmd: ep0out: cmd 'Set Stall' [404] params 00000000 00000000 00000000 --> status: Successful
[ 3548.059788535       0xff817a263]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3548.059987285       0xff817b14c]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3548.060320879       0xff817ca50]   dbg_send_ep_cmd: ep0out: cmd 'Set Stall' [404] params 00000000 00000000 00000000 --> status: Successful
[ 3548.060880306       0xff817f446]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: No Resource
[ 3548.061096816       0xff8180482]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3548.068926504       0xff81a4fbe]   dbg_send_ep_cmd: ep0out: cmd 'End Transfer' [508] params 00000000 00000000 00000000 --> status: Successful
[ 3548.069517129       0xff81a7c09]   dbg_send_ep_cmd: ep0out: cmd 'Set Stall' [404] params 00000000 00000000 00000000 --> status: Successful
[ 3548.070349264       0xff81aba73]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3548.070716764       0xff81ad601]   event (080001c0): ep0out: Endpoint Command Complete
[ 3548.071090149       0xff81af203]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3548.079188639       0xff81d5166]   dbg_send_ep_cmd: ep0out: cmd 'End Transfer' [508] params 00000000 00000000 00000000 --> status: Successful
[ 3548.079884472       0xff81d8596]   dbg_send_ep_cmd: ep0out: cmd 'Set Stall' [404] params 00000000 00000000 00000000 --> status: Successful
[ 3548.080772858       0xff81dc836]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3548.081172806       0xff81de636]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3548.081777441       0xff81e138f]   dbg_send_ep_cmd: ep0out: cmd 'Set Stall' [404] params 00000000 00000000 00000000 --> status: Successful
[ 3548.082772077       0xff81e5e28]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: No Resource
[ 3548.083161035       0xff81e7b53]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3548.091268691       0xff820db68]   dbg_send_ep_cmd: ep0out: cmd 'End Transfer' [508] params 00000000 00000000 00000000 --> status: Successful
[ 3548.091950879       0xff8210e91]   dbg_send_ep_cmd: ep0out: cmd 'Set Stall' [404] params 00000000 00000000 00000000 --> status: Successful
[ 3548.092840514       0xff821514a]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3548.093229420       0xff8216e74]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3548.093844681       0xff8219c99]   dbg_send_ep_cmd: ep0out: cmd 'Set Stall' [404] params 00000000 00000000 00000000 --> status: Successful
[ 3548.094784577       0xff821e318]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: No Resource
[ 3548.095177077       0xff8220088]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3548.103311400       0xff824629a]   dbg_send_ep_cmd: ep0out: cmd 'End Transfer' [508] params 00000000 00000000 00000000 --> status: Successful
[ 3548.103973170       0xff824943d]   dbg_send_ep_cmd: ep0out: cmd 'Set Stall' [404] params 00000000 00000000 00000000 --> status: Successful
[ 3548.104742441       0xff824cdee]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 3548.105139681       0xff824ebba]   event (080001c0): ep0out: Endpoint Command Complete
[ 3548.105498952       0xff82506ac]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]
[ 3548.113527285       0xff82760cd]   dbg_send_ep_cmd: ep0out: cmd 'End Transfer' [508] params 00000000 00000000 00000000 --> status: Successful
[ 3548.114139525       0xff8278eb7]   dbg_send_ep_cmd: ep0out: cmd 'Set Stall' [404] params 00000000 00000000 00000000 --> status: Successful
[ 3548.114927493       0xff827c9d0]   dbg_send_ep_cmd: ep0out: cmd 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: Successful
[ 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
[ 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
[ 3548.158130254       0xff8347206]   event (0000c040): ep0out: Transfer Complete (sIL) [Setup Phase]
[ 3548.158495306       0xff8348d66]   event (000010c2): ep0in: Transfer Not Ready [0] (Not Active) [Data Phase]

Thinh Nguyen May 26, 2022, 12:25 a.m. UTC | #4

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

Wesley Cheng June 1, 2022, 9:18 p.m. UTC | #5

Hi Thinh,

On 5/25/2022 5:25 PM, Thinh Nguyen wrote:
> 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.
> 

With the test I'm running, I have to make some changes to hook into the 
DWC3 tracepoints we have and save it into a different logging mechanism 
we have.  The default ftrace is being routed to a different path while 
this test is running.

I'll see if I can add some reg reads/writes logs.

With the current changes (I've also seen this w/o the latest msleep() 
change), I'm getting into a situation where there is a controller halt. 
  In this case though, GEVNTCNT is 0, but I think what is happening is 
that we are interweaving pullup enable and pullup disable calls, and 
some pullup enable sequences are failing, which lead to the next pullup 
disable to fail halting of the controller.

if (dwc->pullups_connected == is_on)
         return 0;

If the pullup disable routine is running the run/stop path, and USB 
gadget attempts to call pullup enable, this IF condition will allow the 
pullup enable to continue.  This is because pullups_connected is set to 
FALSE before the controller halt polling, so 0->1 transition is valid.

I'm not sure how most USB composite devices behave, but I don't think 
most will retry if the pullup enable returns an error. (?)  I say this 
because we can modify the IF condition to block the subsequent pullup 
enable call, if we have not yet finished the controller halt.

In the snippet below, we can see that, we disabled the run/stop bit and 
halted the controller shortly after receiving the RESET event.  This 
means that the dwc3 gadget stop was called, and EP0 was disabled as well 
(flags were also cleared).  This is leading to the CONNDONE event to 
then re-do the start config, as EP0 is not "enabled."  I think that is 
not the expected sequence.

[ 3899.673491795       0x118aae3bf1]   dbg_send_ep_cmd: ep0out: cmd 'Set 
Endpoint Configuration' [401] params 00001000 00000500 00000000 --> 
status: Successful
[ 3899.673534504       0x118aae3f25]   dbg_send_ep_cmd: ep0in: cmd 'Set 
Endpoint Configuration' [401] params 00001000 02000500 00000000 --> 
status: Successful
[ 3899.673584920       0x118aae42ed]   dbg_send_ep_cmd: ep0out: cmd 
'Start Transfer' [406] params 00000000 efffa000 00000000 --> status: 
Successful
[ 3899.700573][T24732] dwc3_gadget_run_stop: pullups_connected = 1

[ 3899.744634556       0x118ac313a7]   event (00030601): Suspend [U3]
[ 3899.838616483       0x118ade9c4d]   event (00000101): Reset [U0]

[ 3899.922413][ T2186] dwc3_gadget_run_stop: pullups_connected = 0

[ 3900.147395911       0x118b3912c0]   event (00000201): Connection Done 
[U0]
[ 3900.147486276       0x118b391988]   dbg_send_ep_cmd: ep0out: cmd 
'Start New Configuration' [409] params 00000000 00000000 00000000 --> 
status: Successful
[ 3900.147535234       0x118b391d34]   dbg_send_ep_cmd: ep0out: cmd 'Set 
Endpoint Transfer Resource' [402] params 00000001 00000000 00000000 --> 
status: Successful

Thanks
Wesley Cheng

Thinh Nguyen June 1, 2022, 10:07 p.m. UTC | #6

Hi Wesley,

Wesley Cheng wrote:
> Hi Thinh,
> 
> On 5/25/2022 5:25 PM, Thinh Nguyen wrote:
>> 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.
>>
> 
> With the test I'm running, I have to make some changes to hook into the
> DWC3 tracepoints we have and save it into a different logging mechanism
> we have.  The default ftrace is being routed to a different path while
> this test is running.
> 
> I'll see if I can add some reg reads/writes logs.
> 
> With the current changes (I've also seen this w/o the latest msleep()
> change), I'm getting into a situation where there is a controller halt.
>  In this case though, GEVNTCNT is 0, but I think what is happening is
> that we are interweaving pullup enable and pullup disable calls, and
> some pullup enable sequences are failing, which lead to the next pullup
> disable to fail halting of the controller.

How can the pullup() enable fail? There should be a soft reset if
there's pullup() enable, which should reset the controller. Do you have
the driver log for that failure?

> 
> if (dwc->pullups_connected == is_on)
>         return 0;
> 
> If the pullup disable routine is running the run/stop path, and USB
> gadget attempts to call pullup enable, this IF condition will allow the
> pullup enable to continue.  This is because pullups_connected is set to
> FALSE before the controller halt polling, so 0->1 transition is valid.

Why is it not protected? The caller of pullup() should prevent the
interweaving of the pullup calls. A pullup() should be completed before
the next call. From what I see, the caller of this pullup()
(usb_gadget_connect/disconnect in udc/core.c) handles it properly with a
mutex in gadget binding and sysfs connect.

> 
> I'm not sure how most USB composite devices behave, but I don't think
> most will retry if the pullup enable returns an error. (?)  I say this
> because we can modify the IF condition to block the subsequent pullup
> enable call, if we have not yet finished the controller halt.

The composite device uses the udc core api, so it should be protected.

> 
> In the snippet below, we can see that, we disabled the run/stop bit and
> halted the controller shortly after receiving the RESET event.  This
> means that the dwc3 gadget stop was called, and EP0 was disabled as well
> (flags were also cleared).  This is leading to the CONNDONE event to
> then re-do the start config, as EP0 is not "enabled."  I think that is
> not the expected sequence.

If the pullup() disable completed successfully, then the device is
halted and remains disconnected. The conndone event doesn't connect the
device back unless there's pullup enable. The next pullup() enable will
re-initialize the device again after a soft reset.

> 
> [ 3899.673491795       0x118aae3bf1]   dbg_send_ep_cmd: ep0out: cmd 'Set
> Endpoint Configuration' [401] params 00001000 00000500 00000000 -->
> status: Successful
> [ 3899.673534504       0x118aae3f25]   dbg_send_ep_cmd: ep0in: cmd 'Set
> Endpoint Configuration' [401] params 00001000 02000500 00000000 -->
> status: Successful
> [ 3899.673584920       0x118aae42ed]   dbg_send_ep_cmd: ep0out: cmd
> 'Start Transfer' [406] params 00000000 efffa000 00000000 --> status:
> Successful
> [ 3899.700573][T24732] dwc3_gadget_run_stop: pullups_connected = 1
> 
> [ 3899.744634556       0x118ac313a7]   event (00030601): Suspend [U3]
> [ 3899.838616483       0x118ade9c4d]   event (00000101): Reset [U0]
> 
> [ 3899.922413][ T2186] dwc3_gadget_run_stop: pullups_connected = 0
> 
> [ 3900.147395911       0x118b3912c0]   event (00000201): Connection Done
> [U0]
> [ 3900.147486276       0x118b391988]   dbg_send_ep_cmd: ep0out: cmd
> 'Start New Configuration' [409] params 00000000 00000000 00000000 -->
> status: Successful
> [ 3900.147535234       0x118b391d34]   dbg_send_ep_cmd: ep0out: cmd 'Set
> Endpoint Transfer Resource' [402] params 00000001 00000000 00000000 -->
> status: Successful
> 

I'm not clear what's the failure here. You noted that pullup() enable
fails now, but I don't see it. Can you help clarify further.

Thanks,
Thinh

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

Message

Comments