Re: USB DWC2 stops responding when insert/remove cable multiple times

[Minas Harutyunyan <Minas.Harutyunyan-HKixBCOQz3hWk0Htik3J/w@public.gmane.org>]

Hi Otavio,

On 2/28/2020 9:35 PM, Otavio Salvador wrote:
> Hello Minas,
> 
> On Fri, Feb 28, 2020 at 6:01 AM Minas Harutyunyan
> <Minas.Harutyunyan@synopsys.com> wrote:
>> On 2/21/2020 6:07 PM, Otavio Salvador wrote:
>>> On Fri, Feb 21, 2020 at 11:06 AM Otavio Salvador
>>> <otavio@ossystems.com.br> wrote:
>>>> On Fri, Feb 21, 2020 at 3:52 AM Minas Harutyunyan
>>>> <Minas.Harutyunyan@synopsys.com> wrote:
>>>>> On 2/20/2020 5:16 PM, Otavio Salvador wrote:
>>>>>> Hello Minas,
>>>>>>
>>>>>> Thanks for all your help on this, ...
>>>>>>
>>>>>> On Thu, Feb 20, 2020 at 3:59 AM Minas Harutyunyan
>>>>>> <Minas.Harutyunyan@synopsys.com> wrote:
>>>>>>>
>>>>>>> On 2/19/2020 7:10 PM, Otavio Salvador wrote:
>>>>>> ...
>>>>>>>> What sequence do you want us to do?
>>>>>>>
>>>>> Please provide dwc2 debug log when stop working with g_serial exception
>>>>> dump inside.
>>>>> Also provide dwc2 log when it's work without issue.
>>>>
>>>> Attached.
>>>
> 
> [  207.715898] dwc2 30180000.usb: dwc2_hsotg_pullup: is_on: 0 op_state: 3
> [  207.715942] dwc2 30180000.usb: complete: ep b45e8dac ep0, req
> 9e5949b0, -108 => 863fc1b9
> [  207.715966] dwc2 30180000.usb: dwc2_hsotg_complete_setup: failed -108
> [  207.715996] dwc2 30180000.usb: complete: ep edfa46d3 ep2out, req
> c659a301, -108 => f0de5013
> [  207.716050] dwc2 30180000.usb: complete: ep edfa46d3 ep2out, req
> f46b68c4, -108 => f0de5013
> [  207.716078] dwc2 30180000.usb: complete: ep edfa46d3 ep2out, req
> 24890a46, -108 => f0de5013
> [  207.716100] dwc2 30180000.usb: complete: ep edfa46d3 ep2out, req
> fc4810fd, -108 => f0de5013
> [  207.716119] dwc2 30180000.usb: complete: ep edfa46d3 ep2out, req
> f641bdad, -108 => f0de5013
> [  207.716139] dwc2 30180000.usb: complete: ep edfa46d3 ep2out, req
> 92871573, -108 => f0de5013
> [  207.716158] dwc2 30180000.usb: complete: ep edfa46d3 ep2out, req
> fe77b603, -108 => f0de5013
> [  207.716177] dwc2 30180000.usb: complete: ep edfa46d3 ep2out, req
> 3e9064d5, -108 => f0de5013
> [  207.716196] dwc2 30180000.usb: complete: ep edfa46d3 ep2out, req
> 5aae2e11, -108 => f0de5013
> [  207.716216] dwc2 30180000.usb: complete: ep edfa46d3 ep2out, req
> 7c5834db, -108 => f0de5013
> [  207.716236] dwc2 30180000.usb: complete: ep edfa46d3 ep2out, req
> 968af244, -108 => f0de5013
> [  207.716257] dwc2 30180000.usb: complete: ep edfa46d3 ep2out, req
> fa68c2eb, -108 => f0de5013
> [  207.716276] dwc2 30180000.usb: complete: ep edfa46d3 ep2out, req
> 6cfbcee5, -108 => f0de5013
> [  207.716296] dwc2 30180000.usb: complete: ep edfa46d3 ep2out, req
> eea82a2b, -108 => f0de5013
> [  207.716315] dwc2 30180000.usb: complete: ep edfa46d3 ep2out, req
> 56ccd82d, -108 => f0de5013
> [  207.716335] dwc2 30180000.usb: complete: ep edfa46d3 ep2out, req
> a00b7148, -108 => f0de5013
> [  207.716389] dwc2 30180000.usb: dwc2_hsotg_ep_disable(ep edfa46d3)
> [  207.716410] dwc2 30180000.usb: dwc2_hsotg_ep_stop_xfr: stopping
> transfer on ep2out
> [  207.716438] dwc2 30180000.usb: dwc2_hsotg_ep_disable: DxEPCTL=0x08080200
> [  207.716457] dwc2 30180000.usb: dwc2_hsotg_ep_disable(ep 03f40054)
> [  207.716469] dwc2 30180000.usb: dwc2_hsotg_ep_disable: DxEPCTL=0x088a0200
> [  207.716567] dwc2 30180000.usb: dwc2_hsotg_ep_disable(ep 108f89fa)
> [  207.716581] dwc2 30180000.usb: dwc2_hsotg_ep_disable: DxEPCTL=0x098c000a
> [  207.722600] gs_close: before spin_unlock_irq 1: tty->driver_data is baf4a00d
> [  207.722625] gs_close: ttyGS0 (11bbbfea,dc9a1db1) ...
> [  207.722646] gs_close: ttyGS0 (11bbbfea,dc9a1db1) done!
> [  208.040122] dwc2 30180000.usb: dwc2_hsotg_ep_disable(ep 03f40054)
> [  208.040153] dwc2 30180000.usb: dwc2_hsotg_ep_disable: DxEPCTL=0x088a0200
> [  208.040177] dwc2 30180000.usb: dwc2_hsotg_ep_disable(ep edfa46d3)
> [  208.040194] dwc2 30180000.usb: dwc2_hsotg_ep_disable: DxEPCTL=0x080a0200
> [  208.040214] dwc2 30180000.usb: dwc2_hsotg_ep_disable(ep 108f89fa)
> [  208.040227] dwc2 30180000.usb: dwc2_hsotg_ep_disable: DxEPCTL=0x098e000a
> [  208.040243] dwc2 30180000.usb: dwc2_hsotg_ep_disable(ep 12d21028)
> [  208.040255] dwc2 30180000.usb: dwc2_hsotg_ep_disable: DxEPCTL=0x08020400
> [  208.040271] dwc2 30180000.usb: dwc2_hsotg_ep_disable(ep fb6b3e60)
> [  208.040282] dwc2 30180000.usb: dwc2_hsotg_ep_disable: DxEPCTL=0x08020400
> [  208.040298] dwc2 30180000.usb: dwc2_hsotg_ep_disable(ep abea3d06)
> [  208.040310] dwc2 30180000.usb: dwc2_hsotg_ep_disable: DxEPCTL=0x08020400
> [  208.040326] dwc2 30180000.usb: dwc2_hsotg_ep_disable(ep 8074ac21)
> [  208.040338] dwc2 30180000.usb: dwc2_hsotg_ep_disable: DxEPCTL=0x08020400
> [  208.040355] dwc2 30180000.usb: dwc2_hsotg_ep_disable(ep 9449e3ee)
> [  208.040367] dwc2 30180000.usb: dwc2_hsotg_ep_disable: DxEPCTL=0x08020400
> [  208.040383] dwc2 30180000.usb: dwc2_hsotg_ep_disable(ep 3b6cd68c)
> [  208.040395] dwc2 30180000.usb: dwc2_hsotg_ep_disable: DxEPCTL=0x08020400
> [  208.040412] dwc2 30180000.usb: dwc2_hsotg_ep_disable(ep 38c4d9db)
> [  208.040426] dwc2 30180000.usb: dwc2_hsotg_ep_disable: DxEPCTL=0x08020400
> [  208.040443] dwc2 30180000.usb: dwc2_hsotg_ep_disable(ep 67b37434)
> [  208.040457] dwc2 30180000.usb: dwc2_hsotg_ep_disable: DxEPCTL=0x08020400
> [  208.061914] gs_close: before spin_unlock_irq 1: tty->driver_data is baf4a00d
> [  208.061980] 8<--- cut here ---
> [  208.062283] Unable to handle kernel paging request at virtual
> address 00766500
> [  208.062934] pgd = b41c9e7b
> [  208.063189] [00766500] *pgd=00000000
> [  208.063528] Internal error: Oops: 5 [#1] SMP ARM
> [  208.063945] Modules linked in: usb_f_acm u_serial libcomposite
> configfs zram zsmalloc emlog(O) rtc_rk808 clk_rk808 spi_rockchip
> wdtoken(O) [last unloaded: g_serial]
> [  208.065303] CPU: 0 PID: 1203 Comm: sh Tainted: G           O      5.4.21 #1
> [  208.065923] Hardware name: Rockchip (Device Tree)
> [  208.066364] PC is at __cancel_work_timer+0x64/0x200
> [  208.066819] LR is at try_to_grab_pending+0x44/0x1a0
> [  208.067257] pc : [<c0153c70>]    lr : [<c0152a34>]    psr: 20010093
> [  208.067818] sp : c5d91e98  ip : 00000000  fp : c094e8c8
> [  208.068289] r10: 00000000  r9 : c648fb7c  r8 : c5c88f00
> [  208.068760] r7 : 00000000  r6 : 00000000  r5 : c648d204  r4 : c5d90000
> [  208.069343] r3 : 00766500  r2 : 00766565  r1 : c648d204  r0 : 00000000
> [  208.069933] Flags: nzCv  IRQs off  FIQs on  Mode SVC_32  ISA ARM
> Segment none
> [  208.070581] Control: 10c5387d  Table: 6591006a  DAC: 00000051
> [  208.071102] Process sh (pid: 1203, stack limit = 0x7c1578a9)
> [  208.071614] Stack: (0xc5d91e98 to 0xc5d92000)
> [  208.072012] 1e80:
>      60010013 c04a2f50
> [  208.072745] 1ea0: c648fa00 00000000 00000000 c5c8c580 c5c88f00
> c0c05c88 00000000 c648fa00
> [  208.073478] 1ec0: c648fa00 00000000 c5c8c580 c049af84 c0c6f3b4
> c049b080 c648fa00 00000000
> [  208.074211] 1ee0: c648fba8 c049be10 00000000 00000000 00000178
> c648fb04 c648fb04 c09883c0
> [  208.074944] 1f00: 8010000a c5c88f00 000e0003 c5907398 c720a850
> c6e68cc0 00000008 c5c88f08
> [  208.075677] 1f20: 00000000 c02b476c 00000000 00000000 c5d95800
> c5d95c54 c0cb15b4 c5d95c3c
> [  208.076411] 1f40: c634aa80 00000000 000000f8 c0157f78 c5d95800
> c640b400 c5d90000 c640b440
> [  208.077146] 1f60: ffffe000 c013bf64 0000080f c01165cc b6f09abc
> c0c05c88 00000000 000000f8
> [  208.077879] 1f80: 00000000 c013d4b8 00000000 00000004 0050201c
> 000000f8 c0101204 c013d554
> [  208.078611] 1fa0: 00000000 c0101000 00000000 00000004 00000000
> 00000000 00503150 00000000
> [  208.079344] 1fc0: 00000000 00000004 0050201c 000000f8 00000000
> 00000000 00501a78 00000000
> [  208.080077] 1fe0: 00501b28 bec798e4 0048e360 b6e695e4 20010010
> 00000000 00000000 00000000
> [  208.080831] [<c0153c70>] (__cancel_work_timer) from [<c049af84>]
> (release_tty+0x88/0x104)
> [  208.081585] [<c049af84>] (release_tty) from [<c049b080>]
> (tty_release_struct+0x34/0x40)
> [  208.082315] [<c049b080>] (tty_release_struct) from [<c049be10>]
> (tty_release+0x43c/0x640)
> [  208.083056] [<c049be10>] (tty_release) from [<c02b476c>] (__fput+0x88/0x218)
> [  208.083702] [<c02b476c>] (__fput) from [<c0157f78>] (task_work_run+0xa4/0xc4)
> [  208.084357] [<c0157f78>] (task_work_run) from [<c013bf64>]
> (do_exit+0x430/0xaec)
> [  208.085029] [<c013bf64>] (do_exit) from [<c013d4b8>]
> (do_group_exit+0x3c/0xc8)
> [  208.085684] [<c013d4b8>] (do_group_exit) from [<c013d554>]
> (__wake_up_parent+0x0/0x18)
> [  208.086397] Code: e5953000 e3130004 13c330ff 01a042a3 (15933000)
> [  208.086948] ---[ end trace 9aa9566e42b92f1c ]---
> [  208.087367] Fixing recursive fault but reboot is needed!
> 

Sorry, but I can't find any relation between this rmmod g_serial issue 
and dwc2. Don't think that is dwc2 issue.

Thanks,
Minas


> The diff I applied was:
> 
> @@ -662,6 +662,9 @@ static void gs_close(struct tty_struct *tty,
> struct file *file)
>      struct gs_port *port = tty->driver_data;
>      struct gserial  *gser;
> 
> +    pr_debug("gs_close: before spin_unlock_irq 1: tty->driver_data is %p\n",
> +             tty->driver_data);
> +
>      spin_lock_irq(&port->port_lock);
> 
>      if (port->port.count != 1) {
> @@ -687,6 +690,10 @@ static void gs_close(struct tty_struct *tty,
> struct file *file)
>          wait_event_interruptible_timeout(port->drain_wait,
>                      gs_close_flush_done(port),
>                      GS_CLOSE_TIMEOUT * HZ);
> +
> +        pr_debug("gs_close: before spin_unlock_irq 2:
> tty->driver_data is %p\n",
> +                 tty->driver_data);
> +
>          spin_lock_irq(&port->port_lock);
> 
>          if (port->port.count != 1)
> 
>