[PATCH] usb: host: xhci-rcar: Avoid long wait in xhci_reset()

[PATCH] usb: host: xhci-rcar: Avoid long wait in xhci_reset()

[Yoshihiro Shimoda]

If kernel configuration is CONFIG_USB_XHCI_PLATFORM=y and
CONFIG_USB_XHCI_RCAR is not set, R-Car Gen2/3 will cause long wait
in xhci_reset() because such SoCs need specific initialization.
So, this patch modifies the xhci_rcar_init_quirk() in xhci-rcar.h
to exit the probe function immediately.

Fixes: 4ac8918f3a7 (usb: host: xhci-plat: add support for the R-Car H2 and M2 xHCI controllers)
Cc: <stable@vger.kernel.org> # v3.17+
Signed-off-by: Yoshihiro Shimoda <yoshihiro.shimoda.uh@renesas.com>
---
 drivers/usb/host/xhci-rcar.h | 6 +++++-
 1 file changed, 5 insertions(+), 1 deletion(-)

diff --git a/drivers/usb/host/xhci-rcar.h b/drivers/usb/host/xhci-rcar.h
index 2941a25..2afed68 100644
--- a/drivers/usb/host/xhci-rcar.h
+++ b/drivers/usb/host/xhci-rcar.h
@@ -24,7 +24,11 @@ static inline void xhci_rcar_start(struct usb_hcd *hcd)
 
 static inline int xhci_rcar_init_quirk(struct usb_hcd *hcd)
 {
-	return 0;
+	/*
+	 * To avoid wait and timeout in xhci_reset() if CONFIG_XHCI_RCAR is
+	 * disabled, this function fails.
+	 */
+	return -ENODEV;
 }
 #endif
 #endif /* _XHCI_RCAR_H */
-- 
1.9.1

Re: [PATCH] usb: host: xhci-rcar: Avoid long wait in xhci_reset()

[Felipe Balbi]

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

Yoshihiro Shimoda <yoshihiro.shimoda.uh@renesas.com> writes:

> If kernel configuration is CONFIG_USB_XHCI_PLATFORM=y and
> CONFIG_USB_XHCI_RCAR is not set, R-Car Gen2/3 will cause long wait
> in xhci_reset() because such SoCs need specific initialization.

where is the delay coming from exactly ?

> So, this patch modifies the xhci_rcar_init_quirk() in xhci-rcar.h
> to exit the probe function immediately.
>
> Fixes: 4ac8918f3a7 (usb: host: xhci-plat: add support for the R-Car H2 and M2 xHCI controllers)
> Cc: <stable@vger.kernel.org> # v3.17+
> Signed-off-by: Yoshihiro Shimoda <yoshihiro.shimoda.uh@renesas.com>
> ---
>  drivers/usb/host/xhci-rcar.h | 6 +++++-
>  1 file changed, 5 insertions(+), 1 deletion(-)
>
> diff --git a/drivers/usb/host/xhci-rcar.h b/drivers/usb/host/xhci-rcar.h
> index 2941a25..2afed68 100644
> --- a/drivers/usb/host/xhci-rcar.h
> +++ b/drivers/usb/host/xhci-rcar.h
> @@ -24,7 +24,11 @@ static inline void xhci_rcar_start(struct usb_hcd *hcd)
>  
>  static inline int xhci_rcar_init_quirk(struct usb_hcd *hcd)
>  {
> -	return 0;
> +	/*
> +	 * To avoid wait and timeout in xhci_reset() if CONFIG_XHCI_RCAR is
> +	 * disabled, this function fails.
> +	 */
> +	return -ENODEV;
>  }
>  #endif
>  #endif /* _XHCI_RCAR_H */
> -- 
> 1.9.1
>
> --
> To unsubscribe from this list: send the line "unsubscribe linux-usb" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

-- 
balbi

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

RE: [PATCH] usb: host: xhci-rcar: Avoid long wait in xhci_reset()

[Yoshihiro Shimoda]

Hi Felipe,

> From: Felipe Balbi
> Sent: Thursday, April 21, 2016 7:05 PM
> 
> Yoshihiro Shimoda <yoshihiro.shimoda.uh@renesas.com> writes:
> 
> > If kernel configuration is CONFIG_USB_XHCI_PLATFORM=y and
> > CONFIG_USB_XHCI_RCAR is not set, R-Car Gen2/3 will cause long wait
> > in xhci_reset() because such SoCs need specific initialization.
> 
> where is the delay coming from exactly ?

The delay is coming from the following code:

	ret = xhci_handshake(&xhci->op_regs->command,
			CMD_RESET, 0, 10 * 1000 * 1000);
	if (ret)
		return ret;

And, kernel log is the following:

[    1.565605] xhci-hcd ee000000.usb: xHCI Host Controller
[    1.570636] xhci-hcd ee000000.usb: new USB bus registered, assigned bus number 5
[   22.270160] xhci-hcd ee000000.usb: can't setup: -110
[   22.274931] xhci-hcd ee000000.usb: USB bus 5 deregistered
[   22.280158] xhci-hcd: probe of ee000000.usb failed with error -110

The timestamp is strange to me. But, logs of R-Car H3 (ES1.0) and R-Car H2 were the same.

Should I revise the commit log in detail?

Best regards,
Yoshihiro Shimoda

RE: [PATCH] usb: host: xhci-rcar: Avoid long wait in xhci_reset()

[Felipe Balbi]

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

Yoshihiro Shimoda <yoshihiro.shimoda.uh@renesas.com> writes:

> Hi Felipe,
>
>> From: Felipe Balbi
>> Sent: Thursday, April 21, 2016 7:05 PM
>> 
>> Yoshihiro Shimoda <yoshihiro.shimoda.uh@renesas.com> writes:
>> 
>> > If kernel configuration is CONFIG_USB_XHCI_PLATFORM=y and
>> > CONFIG_USB_XHCI_RCAR is not set, R-Car Gen2/3 will cause long wait
>> > in xhci_reset() because such SoCs need specific initialization.
>> 
>> where is the delay coming from exactly ?
>
> The delay is coming from the following code:
>
> 	ret = xhci_handshake(&xhci->op_regs->command,
> 			CMD_RESET, 0, 10 * 1000 * 1000);
> 	if (ret)
> 		return ret;

okay, and why does reset fail ?

> And, kernel log is the following:
>
> [    1.565605] xhci-hcd ee000000.usb: xHCI Host Controller
> [    1.570636] xhci-hcd ee000000.usb: new USB bus registered, assigned bus number 5
> [   22.270160] xhci-hcd ee000000.usb: can't setup: -110
> [   22.274931] xhci-hcd ee000000.usb: USB bus 5 deregistered
> [   22.280158] xhci-hcd: probe of ee000000.usb failed with error -110
>
> The timestamp is strange to me. But, logs of R-Car H3 (ES1.0) and
> R-Car H2 were the same.

yeah, seems like your system timer is counting twice for each tick.

> Should I revise the commit log in detail?

Sure, but let's first why this is the case. It's unclear, to me at
least, why reset fails.

-- 
balbi

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

RE: [PATCH] usb: host: xhci-rcar: Avoid long wait in xhci_reset()

[Yoshihiro Shimoda]

Hi Felipe,

> From: Felipe Balbi
> Sent: Thursday, April 21, 2016 7:19 PM
> 
> Yoshihiro Shimoda <yoshihiro.shimoda.uh@renesas.com> writes:
> 
> > Hi Felipe,
> >
> >> From: Felipe Balbi
> >> Sent: Thursday, April 21, 2016 7:05 PM
> >>
> >> Yoshihiro Shimoda <yoshihiro.shimoda.uh@renesas.com> writes:
> >>
> >> > If kernel configuration is CONFIG_USB_XHCI_PLATFORM=y and
> >> > CONFIG_USB_XHCI_RCAR is not set, R-Car Gen2/3 will cause long wait
> >> > in xhci_reset() because such SoCs need specific initialization.
> >>
> >> where is the delay coming from exactly ?
> >
> > The delay is coming from the following code:
> >
> > 	ret = xhci_handshake(&xhci->op_regs->command,
> > 			CMD_RESET, 0, 10 * 1000 * 1000);
> > 	if (ret)
> > 		return ret;
> 
> okay, and why does reset fail ?

Oops, I don't know why. So, I will investigate it.

> > And, kernel log is the following:
> >
> > [    1.565605] xhci-hcd ee000000.usb: xHCI Host Controller
> > [    1.570636] xhci-hcd ee000000.usb: new USB bus registered, assigned bus number 5
> > [   22.270160] xhci-hcd ee000000.usb: can't setup: -110
> > [   22.274931] xhci-hcd ee000000.usb: USB bus 5 deregistered
> > [   22.280158] xhci-hcd: probe of ee000000.usb failed with error -110
> >
> > The timestamp is strange to me. But, logs of R-Car H3 (ES1.0) and
> > R-Car H2 were the same.
> 
> yeah, seems like your system timer is counting twice for each tick.

Yes, I will investigate this later.

> > Should I revise the commit log in detail?
> 
> Sure, but let's first why this is the case. It's unclear, to me at
> least, why reset fails.

I understood it. I will investigate why reset fails first.

Best regards,
Yoshihiro Shimoda

> --
> balbi

Re: [PATCH] usb: host: xhci-rcar: Avoid long wait in xhci_reset()

[Geert Uytterhoeven]

On Thu, Apr 21, 2016 at 12:27 PM, Yoshihiro Shimoda
<yoshihiro.shimoda.uh@renesas.com> wrote:
>> > [    1.565605] xhci-hcd ee000000.usb: xHCI Host Controller
>> > [    1.570636] xhci-hcd ee000000.usb: new USB bus registered, assigned bus number 5
>> > [   22.270160] xhci-hcd ee000000.usb: can't setup: -110
>> > [   22.274931] xhci-hcd ee000000.usb: USB bus 5 deregistered
>> > [   22.280158] xhci-hcd: probe of ee000000.usb failed with error -110
>> >
>> > The timestamp is strange to me. But, logs of R-Car H3 (ES1.0) and
>> > R-Car H2 were the same.
>>
>> yeah, seems like your system timer is counting twice for each tick.
>
> Yes, I will investigate this later.

The main clock crystal on Salvator-X is half of the expected value. But
despite the correct value being in the DTS, there's some timer code that
doesn't take this into account.

Gr{oetje,eeting}s,

                        Geert

--
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- geert@linux-m68k.org

In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
                                -- Linus Torvalds

Re: [PATCH] usb: host: xhci-rcar: Avoid long wait in xhci_reset()

[Felipe Balbi]

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


Hi,

Geert Uytterhoeven <geert@linux-m68k.org> writes:
> On Thu, Apr 21, 2016 at 12:27 PM, Yoshihiro Shimoda
> <yoshihiro.shimoda.uh@renesas.com> wrote:
>>> > [    1.565605] xhci-hcd ee000000.usb: xHCI Host Controller
>>> > [    1.570636] xhci-hcd ee000000.usb: new USB bus registered, assigned bus number 5
>>> > [   22.270160] xhci-hcd ee000000.usb: can't setup: -110
>>> > [   22.274931] xhci-hcd ee000000.usb: USB bus 5 deregistered
>>> > [   22.280158] xhci-hcd: probe of ee000000.usb failed with error -110
>>> >
>>> > The timestamp is strange to me. But, logs of R-Car H3 (ES1.0) and
>>> > R-Car H2 were the same.
>>>
>>> yeah, seems like your system timer is counting twice for each tick.
>>
>> Yes, I will investigate this later.
>
> The main clock crystal on Salvator-X is half of the expected value. But
> despite the correct value being in the DTS, there's some timer code that
> doesn't take this into account.

cool, thanks for the note. One problem down.

-- 
balbi

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

RE: [PATCH] usb: host: xhci-rcar: Avoid long wait in xhci_reset()

[Yoshihiro Shimoda]

Hi,

> From: linux-renesas-soc-owner@vger.kernel.org [mailto:linux-renesas-soc-owner@vger.kernel.org] On Behalf Of Yoshihiro
> Shimoda
> Sent: Thursday, April 21, 2016 7:28 PM
> 
> Hi Felipe,
> 
> > From: Felipe Balbi
> > Sent: Thursday, April 21, 2016 7:19 PM
> >
> > Yoshihiro Shimoda <yoshihiro.shimoda.uh@renesas.com> writes:
> >
> > > Hi Felipe,
> > >
> > >> From: Felipe Balbi
> > >> Sent: Thursday, April 21, 2016 7:05 PM
> > >>
> > >> Yoshihiro Shimoda <yoshihiro.shimoda.uh@renesas.com> writes:
> > >>
> > >> > If kernel configuration is CONFIG_USB_XHCI_PLATFORM=y and
> > >> > CONFIG_USB_XHCI_RCAR is not set, R-Car Gen2/3 will cause long wait
> > >> > in xhci_reset() because such SoCs need specific initialization.
> > >>
> > >> where is the delay coming from exactly ?
> > >
> > > The delay is coming from the following code:
> > >
> > > 	ret = xhci_handshake(&xhci->op_regs->command,
> > > 			CMD_RESET, 0, 10 * 1000 * 1000);
> > > 	if (ret)
> > > 		return ret;
> >
> > okay, and why does reset fail ?
> 
> Oops, I don't know why. So, I will investigate it.
> 
> > > And, kernel log is the following:
> > >
> > > [    1.565605] xhci-hcd ee000000.usb: xHCI Host Controller
> > > [    1.570636] xhci-hcd ee000000.usb: new USB bus registered, assigned bus number 5
> > > [   22.270160] xhci-hcd ee000000.usb: can't setup: -110
> > > [   22.274931] xhci-hcd ee000000.usb: USB bus 5 deregistered
> > > [   22.280158] xhci-hcd: probe of ee000000.usb failed with error -110
> > >
> > > The timestamp is strange to me. But, logs of R-Car H3 (ES1.0) and
> > > R-Car H2 were the same.
> >
> > yeah, seems like your system timer is counting twice for each tick.
> 
> Yes, I will investigate this later.
> 
> > > Should I revise the commit log in detail?
> >
> > Sure, but let's first why this is the case. It's unclear, to me at
> > least, why reset fails.
> 
> I understood it. I will investigate why reset fails first.

According to the HW team of R-Car SoCs, the firmware of R-Car USB 3.0 host controller
will control the reset. So, if the xhci-rcar driver doesn't do firmware downloading,
the reset of USB3.0 host controller doesn't work correctly.
The HW team intends to describe this specification on next datasheet revision.
(In other words, the current datasheet doesn't mention exactly about this.)

So, I will revise the commit log and submit such a patch later.

Best regards,
Yoshihiro Shimoda

> Best regards,
> Yoshihiro Shimoda
> 
> > --
> > balbi

RE: [PATCH] usb: host: xhci-rcar: Avoid long wait in xhci_reset()

[Felipe Balbi]

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


Hi,

Yoshihiro Shimoda <yoshihiro.shimoda.uh@renesas.com> writes:
>> > > And, kernel log is the following:
>> > >
>> > > [    1.565605] xhci-hcd ee000000.usb: xHCI Host Controller
>> > > [    1.570636] xhci-hcd ee000000.usb: new USB bus registered, assigned bus number 5
>> > > [   22.270160] xhci-hcd ee000000.usb: can't setup: -110
>> > > [   22.274931] xhci-hcd ee000000.usb: USB bus 5 deregistered
>> > > [   22.280158] xhci-hcd: probe of ee000000.usb failed with error -110
>> > >
>> > > The timestamp is strange to me. But, logs of R-Car H3 (ES1.0) and
>> > > R-Car H2 were the same.
>> >
>> > yeah, seems like your system timer is counting twice for each tick.
>> 
>> Yes, I will investigate this later.
>> 
>> > > Should I revise the commit log in detail?
>> >
>> > Sure, but let's first why this is the case. It's unclear, to me at
>> > least, why reset fails.
>> 
>> I understood it. I will investigate why reset fails first.
>
> According to the HW team of R-Car SoCs, the firmware of R-Car USB 3.0 host controller
> will control the reset. So, if the xhci-rcar driver doesn't do firmware downloading,
> the reset of USB3.0 host controller doesn't work correctly.
> The HW team intends to describe this specification on next datasheet revision.
> (In other words, the current datasheet doesn't mention exactly about this.)

that explains it, thanks :-)

> So, I will revise the commit log and submit such a patch later.

great, thanks

-- 
balbi

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

Re: [PATCH] usb: host: xhci-rcar: Avoid long wait in xhci_reset()

[Geert Uytterhoeven]

Hi Shimoda-san,

On Thu, Apr 21, 2016 at 2:57 PM, Geert Uytterhoeven
<geert@linux-m68k.org> wrote:
> On Thu, Apr 21, 2016 at 12:27 PM, Yoshihiro Shimoda
> <yoshihiro.shimoda.uh@renesas.com> wrote:
>>> > [    1.565605] xhci-hcd ee000000.usb: xHCI Host Controller
>>> > [    1.570636] xhci-hcd ee000000.usb: new USB bus registered, assigned bus number 5
>>> > [   22.270160] xhci-hcd ee000000.usb: can't setup: -110
>>> > [   22.274931] xhci-hcd ee000000.usb: USB bus 5 deregistered
>>> > [   22.280158] xhci-hcd: probe of ee000000.usb failed with error -110
>>> >
>>> > The timestamp is strange to me. But, logs of R-Car H3 (ES1.0) and
>>> > R-Car H2 were the same.
>>>
>>> yeah, seems like your system timer is counting twice for each tick.
>>
>> Yes, I will investigate this later.
>
> The main clock crystal on Salvator-X is half of the expected value. But
> despite the correct value being in the DTS, there's some timer code that
> doesn't take this into account.

It's fixed by upgrading to bootloader v270:

-Architected cp15 timer(s) running at 16.66MHz (virt).
+Architected cp15 timer(s) running at 8.33MHz (virt).

Gr{oetje,eeting}s,

                        Geert

--
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- geert@linux-m68k.org

In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
                                -- Linus Torvalds

RE: [PATCH] usb: host: xhci-rcar: Avoid long wait in xhci_reset()

[Yoshihiro Shimoda]

Hi Geert-san,

> From: Geert Uytterhoeven
> Sent: Monday, April 25, 2016 11:57 PM
> 
> Hi Shimoda-san,
> 
> On Thu, Apr 21, 2016 at 2:57 PM, Geert Uytterhoeven
> <geert@linux-m68k.org> wrote:
> > On Thu, Apr 21, 2016 at 12:27 PM, Yoshihiro Shimoda
> > <yoshihiro.shimoda.uh@renesas.com> wrote:
> >>> > [    1.565605] xhci-hcd ee000000.usb: xHCI Host Controller
> >>> > [    1.570636] xhci-hcd ee000000.usb: new USB bus registered, assigned bus number 5
> >>> > [   22.270160] xhci-hcd ee000000.usb: can't setup: -110
> >>> > [   22.274931] xhci-hcd ee000000.usb: USB bus 5 deregistered
> >>> > [   22.280158] xhci-hcd: probe of ee000000.usb failed with error -110
> >>> >
> >>> > The timestamp is strange to me. But, logs of R-Car H3 (ES1.0) and
> >>> > R-Car H2 were the same.
> >>>
> >>> yeah, seems like your system timer is counting twice for each tick.
> >>
> >> Yes, I will investigate this later.
> >
> > The main clock crystal on Salvator-X is half of the expected value. But
> > despite the correct value being in the DTS, there's some timer code that
> > doesn't take this into account.
> 
> It's fixed by upgrading to bootloader v270:
> 
> -Architected cp15 timer(s) running at 16.66MHz (virt).
> +Architected cp15 timer(s) running at 8.33MHz (virt).

Thank you for the comment!
Yes, the timer works correct on my environment.

echo do > /dev/kmsg; sleep 60; echo done > /dev/kmsg
[  169.784474] do
[  229.791962] done

However, the xhci timeout is still about 20 seconds.
So, I investigated this issue more. Then, it seemed that readl() in xhci_handshake() is
large delay (about 10 seconds) when the xhci driver didn't do firmware downloading.

Best regards,
Yoshihiro Shimoda

> Gr{oetje,eeting}s,
> 
>                         Geert
> 
> --
> Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- geert@linux-m68k.org
> 
> In personal conversations with technical people, I call myself a hacker. But
> when I'm talking to journalists I just say "programmer" or something like that.
>                                 -- Linus Torvalds