[QUERY] Cold plugged USB device to Inateck PCIE USB card is not detected

[QUERY] Cold plugged USB device to Inateck PCIE USB card is not detected

[Kishon Vijay Abraham I]

Hi All,

I was trying to test PCIe USB card (Inateck) connected to AM64 EVM and
J7200 EVM. Inateck uses Renesas uPD720201 USB3 host controller.

So if I connect USB pendrive and then boot the board (cold plug), I
don't see the pendrive getting detected. But if I remove and plug it
again, it gets detected.

For the cold plug case, I see this message
	"usb usb1-port3: couldn't allocate usb_device"

It actually fails in
xhci_alloc_dev()->xhci_queue_slot_control()->queue_command()->XHCI_STATE_HALTED

I'm not familiar with xhci but it looks like port event is invoked
before the controller is fully initialized (?).

I tried the following hack which kind of changes the sequence where
xhci_start() and xhci_run_finished() is invoked before port_event() and
with that I could see the pendrive enumerate successfully in cold plug case.

diff --git a/drivers/usb/core/hub.c b/drivers/usb/core/hub.c
index 228e3d4e1a9f..d19f27c46c6f 100644
--- a/drivers/usb/core/hub.c
+++ b/drivers/usb/core/hub.c
@@ -1077,7 +1077,7 @@ static void hub_activate(struct usb_hub *hub, enum
hub_activation_type type)
                        INIT_DELAYED_WORK(&hub->init_work, hub_init_func2);
                        queue_delayed_work(system_power_efficient_wq,
                                        &hub->init_work,
-                                       msecs_to_jiffies(delay));
+                                       msecs_to_jiffies(150));

                        /* Suppress autosuspend until init is done */
                        usb_autopm_get_interface_no_resume(

Irrespective of the delay the port status looks correct and the modified
delay only helps to change the flow.

Adding other prints and delays also change the sequence and seems to
detect the connected pendrive.

Can someone provide hints on how to fix this properly?

Thanks in advance!

Regards
Kishon

Re: [QUERY] Cold plugged USB device to Inateck PCIE USB card is not detected

[Mathias Nyman]

On 19.8.2021 10.54, Kishon Vijay Abraham I wrote:
> Hi All,
> 
> I was trying to test PCIe USB card (Inateck) connected to AM64 EVM and
> J7200 EVM. Inateck uses Renesas uPD720201 USB3 host controller.
> 
> So if I connect USB pendrive and then boot the board (cold plug), I
> don't see the pendrive getting detected. But if I remove and plug it
> again, it gets detected.
> 
> For the cold plug case, I see this message
> 	"usb usb1-port3: couldn't allocate usb_device"
> 
> It actually fails in
> xhci_alloc_dev()->xhci_queue_slot_control()->queue_command()->XHCI_STATE_HALTED
> 
> I'm not familiar with xhci but it looks like port event is invoked
> before the controller is fully initialized (?).

Maybe this controller is capable of generating interrupts before it's running?
 
> 
> I tried the following hack which kind of changes the sequence where
> xhci_start() and xhci_run_finished() is invoked before port_event() and
> with that I could see the pendrive enumerate successfully in cold plug case.
> 
> diff --git a/drivers/usb/core/hub.c b/drivers/usb/core/hub.c
> index 228e3d4e1a9f..d19f27c46c6f 100644
> --- a/drivers/usb/core/hub.c
> +++ b/drivers/usb/core/hub.c
> @@ -1077,7 +1077,7 @@ static void hub_activate(struct usb_hub *hub, enum
> hub_activation_type type)
>                         INIT_DELAYED_WORK(&hub->init_work, hub_init_func2);
>                         queue_delayed_work(system_power_efficient_wq,
>                                         &hub->init_work,
> -                                       msecs_to_jiffies(delay));
> +                                       msecs_to_jiffies(150));
> 
>                         /* Suppress autosuspend until init is done */
>                         usb_autopm_get_interface_no_resume(
> 
> Irrespective of the delay the port status looks correct and the modified
> delay only helps to change the flow.
> 
> Adding other prints and delays also change the sequence and seems to
> detect the connected pendrive.
> 
> Can someone provide hints on how to fix this properly?

Either keep xHC interrupts disabled until second (usb3) hcd is added, and
host is running. (haven't thought about side effects yet)
Or make sure we don't start polling the usb2 roothub until host is running.

Below code should return before port event handler starts roothub polling if 
any xhci->xhc_state flag is set. 
Untested, does it work for you?

diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c
index e676749f543b..9f4cc5c87b27 100644
--- a/drivers/usb/host/xhci-ring.c
+++ b/drivers/usb/host/xhci-ring.c
@@ -2024,6 +2024,8 @@ static void handle_port_status(struct xhci_hcd *xhci,
        if (bogus_port_status)
                return;
 
+       if (xhci->xhc_state != 0)
+               return;
        /*
         * xHCI port-status-change events occur when the "or" of all the
         * status-change bits in the portsc register changes from 0 to 1.
diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c
index f3dabd02382c..b171558956dd 100644
--- a/drivers/usb/host/xhci.c
+++ b/drivers/usb/host/xhci.c
@@ -646,9 +646,15 @@ int xhci_run(struct usb_hcd *hcd)
         */
 
        hcd->uses_new_polling = 1;
-       if (!usb_hcd_is_primary_hcd(hcd))
-               return xhci_run_finished(xhci);
-
+       if (!usb_hcd_is_primary_hcd(hcd)) {
+               ret = xhci_run_finished(xhci);
+               if (ret)
+                       return ret;
+               /* start polling usb2 roothub */
+               set_bit(HCD_FLAG_POLL_RH, &xhci->main_hcd->flags);
+               usb_hcd_poll_rh_status(xhci->main_hcd);
+               return ret;
+       }
        xhci_dbg_trace(xhci, trace_xhci_dbg_init, "xhci_run");
 
        ret = xhci_try_enable_msi(hcd);

Thanks
-Mathias

Re: [QUERY] Cold plugged USB device to Inateck PCIE USB card is not detected

[Alan Stern]

On Thu, Aug 19, 2021 at 04:18:12PM +0300, Mathias Nyman wrote:
> On 19.8.2021 10.54, Kishon Vijay Abraham I wrote:
> > Hi All,
> > 
> > I was trying to test PCIe USB card (Inateck) connected to AM64 EVM and
> > J7200 EVM. Inateck uses Renesas uPD720201 USB3 host controller.
> > 
> > So if I connect USB pendrive and then boot the board (cold plug), I
> > don't see the pendrive getting detected. But if I remove and plug it
> > again, it gets detected.
> > 
> > For the cold plug case, I see this message
> > 	"usb usb1-port3: couldn't allocate usb_device"
> > 
> > It actually fails in
> > xhci_alloc_dev()->xhci_queue_slot_control()->queue_command()->XHCI_STATE_HALTED
> > 
> > I'm not familiar with xhci but it looks like port event is invoked
> > before the controller is fully initialized (?).
> 
> Maybe this controller is capable of generating interrupts before it's running?

Mathias and Kishon:

Note that this issue has also been reported in Bugzilla:

	https://bugzilla.kernel.org/show_bug.cgi?id=214021

Alan Stern

Re: [QUERY] Cold plugged USB device to Inateck PCIE USB card is not detected

[Mathias Nyman]

On 19.8.2021 18.09, Alan Stern wrote:
> On Thu, Aug 19, 2021 at 04:18:12PM +0300, Mathias Nyman wrote:
>> On 19.8.2021 10.54, Kishon Vijay Abraham I wrote:
>>> Hi All,
>>>
>>> I was trying to test PCIe USB card (Inateck) connected to AM64 EVM and
>>> J7200 EVM. Inateck uses Renesas uPD720201 USB3 host controller.
>>>
>>> So if I connect USB pendrive and then boot the board (cold plug), I
>>> don't see the pendrive getting detected. But if I remove and plug it
>>> again, it gets detected.
>>>
>>> For the cold plug case, I see this message
>>> 	"usb usb1-port3: couldn't allocate usb_device"
>>>
>>> It actually fails in
>>> xhci_alloc_dev()->xhci_queue_slot_control()->queue_command()->XHCI_STATE_HALTED
>>>
>>> I'm not familiar with xhci but it looks like port event is invoked
>>> before the controller is fully initialized (?).
>>
>> Maybe this controller is capable of generating interrupts before it's running?
> 
> Mathias and Kishon:
> 
> Note that this issue has also been reported in Bugzilla:
> 
> 	https://bugzilla.kernel.org/show_bug.cgi?id=214021
> 

Thanks, 

I'll follow up on that one.

-Mathias

Re: [QUERY] Cold plugged USB device to Inateck PCIE USB card is not detected

[Kishon Vijay Abraham I]

Hi Mathias,

On 19/08/21 6:48 pm, Mathias Nyman wrote:
> On 19.8.2021 10.54, Kishon Vijay Abraham I wrote:
>> Hi All,
>>
>> I was trying to test PCIe USB card (Inateck) connected to AM64 EVM and
>> J7200 EVM. Inateck uses Renesas uPD720201 USB3 host controller.
>>
>> So if I connect USB pendrive and then boot the board (cold plug), I
>> don't see the pendrive getting detected. But if I remove and plug it
>> again, it gets detected.
>>
>> For the cold plug case, I see this message
>> 	"usb usb1-port3: couldn't allocate usb_device"
>>
>> It actually fails in
>> xhci_alloc_dev()->xhci_queue_slot_control()->queue_command()->XHCI_STATE_HALTED
>>
>> I'm not familiar with xhci but it looks like port event is invoked
>> before the controller is fully initialized (?).
> 
> Maybe this controller is capable of generating interrupts before it's running?

I don't see any MSI interrupts being raised actually..

512:          0          0   ITS-MSI 524288 Edge      xhci_hcd
513:          0          0   ITS-MSI 524289 Edge      xhci_hcd
514:          0          0   ITS-MSI 524290 Edge      xhci_hcd
>  
>>
>> I tried the following hack which kind of changes the sequence where
>> xhci_start() and xhci_run_finished() is invoked before port_event() and
>> with that I could see the pendrive enumerate successfully in cold plug case.
>>
>> diff --git a/drivers/usb/core/hub.c b/drivers/usb/core/hub.c
>> index 228e3d4e1a9f..d19f27c46c6f 100644
>> --- a/drivers/usb/core/hub.c
>> +++ b/drivers/usb/core/hub.c
>> @@ -1077,7 +1077,7 @@ static void hub_activate(struct usb_hub *hub, enum
>> hub_activation_type type)
>>                         INIT_DELAYED_WORK(&hub->init_work, hub_init_func2);
>>                         queue_delayed_work(system_power_efficient_wq,
>>                                         &hub->init_work,
>> -                                       msecs_to_jiffies(delay));
>> +                                       msecs_to_jiffies(150));
>>
>>                         /* Suppress autosuspend until init is done */
>>                         usb_autopm_get_interface_no_resume(
>>
>> Irrespective of the delay the port status looks correct and the modified
>> delay only helps to change the flow.
>>
>> Adding other prints and delays also change the sequence and seems to
>> detect the connected pendrive.
>>
>> Can someone provide hints on how to fix this properly?
> 
> Either keep xHC interrupts disabled until second (usb3) hcd is added, and
> host is running. (haven't thought about side effects yet)
> Or make sure we don't start polling the usb2 roothub until host is running.
> 
> Below code should return before port event handler starts roothub polling if 
> any xhci->xhc_state flag is set. 
> Untested, does it work for you?

I still see the issue. When root hub is polled again in your code
snippet, PORT_CSC is not set and xhci_hub_status_data() returns 0.

I've printed port status in xhci_hub_status_data() below

[    7.422124] xhci_hcd 0000:01:00.0: xHCI Host Controller
[    7.482282] xhci_hcd 0000:01:00.0: new USB bus registered, assigned
bus number 1
[    7.596587] xhci_hcd 0000:01:00.0: hcc params 0x014051cf hci version
0x100 quirks 0x0000001100000410
[    7.679626] usb usb1: New USB device found, idVendor=1d6b,
idProduct=0002, bcdDevice= 5.14
[    7.747969] usb usb1: New USB device strings: Mfr=3, Product=2,
SerialNumber=1
[    7.885643] usb usb1: Product: xHCI Host Controller
[    7.974816] usb usb1: Manufacturer: Linux
5.14.0-rc4-80127-gf061ccba1dcc-dirty xhci-hcd
[    8.004951] usb usb1: SerialNumber: 0000:01:00.0
[    8.016014] hub 1-0:1.0: USB hub found
[    8.020047] hub 1-0:1.0: 4 ports detected
[    8.068702] xhci_hcd 0000:01:00.0: xHCI Host Controller
[    8.142741] xhci_hcd 0000:01:00.0: new USB bus registered, assigned
bus number 2
[    8.196053] usb usb1-port3: couldn't allocate usb_device
[    8.201665] xhci_hub_status_data port=0 status=a0002a0
[    8.206832] xhci_hub_status_data port=1 status=a0002a0
[    8.211977] xhci_hub_status_data port=2 status=c0002e1
[    8.217117] xhci_hub_status_data port=3 status=a0002a0
[    8.259972] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed
[    8.344124] xhci_hub_status_data port=0 status=a0002a0
[    8.349296] xhci_hub_status_data port=1 status=a0002a0
[    8.354439] xhci_hub_status_data port=2 status=c0002e1
[    8.359582] xhci_hub_status_data port=3 status=a0002a0
[    8.458489] usb usb2: We don't know the algorithms for LPM for this
host, disabling LPM.
[    8.531363] usb usb2: New USB device found, idVendor=1d6b,
idProduct=0003, bcdDevice= 5.14
[    8.559934] usb usb2: New USB device strings: Mfr=3, Product=2,
SerialNumber=1
[    8.613931] usb usb2: Product: xHCI Host Controller
[    8.695966] usb usb2: Manufacturer: Linux
5.14.0-rc4-80127-gf061ccba1dcc-dirty xhci-hcd
[    8.805694] usb usb2: SerialNumber: 0000:01:00.0
[    8.848261] hub 2-0:1.0: USB hub found
[    8.905741] hub 2-0:1.0: 4 ports detected
[    8.986168] xhci_hub_status_data port=0 status=a0002a0
[    8.991334] xhci_hub_status_data port=1 status=a0002a0
[    8.996477] xhci_hub_status_data port=2 status=a0002a0
[    9.001616] xhci_hub_status_data port=3 status=a0002a0


I'm unable to get the initial port status in the same run, but on a
different run, the initial port status value looks okay

[    9.603444] xhci_hcd 0000:01:00.0: Get port status 1-1 read: 0x2a0,
return 0x100
[    9.611144] xhci_hcd 0000:01:00.0: Get port status 1-2 read: 0x2a0,
return 0x100
[    9.618832] xhci_hcd 0000:01:00.0: Get port status 1-3 read: 0x202e1,
return 0x10101
[    9.626851] xhci_hcd 0000:01:00.0: Get port status 1-4 read: 0x2a0,
return 0x100

Sometime later the port status changes to c0002e1 (not sure what leads
to it).

As an experiment I added PORT_CONNECT to "mask" in
xhci_hub_status_data() and the device seem to get detected after
multiple "usb usb1-port3: couldn't allocate usb_device". But haven't
tested this extensively and also not sure if there are any side effects.

Thanks
Kishon
> 
> diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c
> index e676749f543b..9f4cc5c87b27 100644
> --- a/drivers/usb/host/xhci-ring.c
> +++ b/drivers/usb/host/xhci-ring.c
> @@ -2024,6 +2024,8 @@ static void handle_port_status(struct xhci_hcd *xhci,
>         if (bogus_port_status)
>                 return;
>  
> +       if (xhci->xhc_state != 0)
> +               return;
>         /*
>          * xHCI port-status-change events occur when the "or" of all the
>          * status-change bits in the portsc register changes from 0 to 1.
> diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c
> index f3dabd02382c..b171558956dd 100644
> --- a/drivers/usb/host/xhci.c
> +++ b/drivers/usb/host/xhci.c
> @@ -646,9 +646,15 @@ int xhci_run(struct usb_hcd *hcd)
>          */
>  
>         hcd->uses_new_polling = 1;
> -       if (!usb_hcd_is_primary_hcd(hcd))
> -               return xhci_run_finished(xhci);
> -
> +       if (!usb_hcd_is_primary_hcd(hcd)) {
> +               ret = xhci_run_finished(xhci);
> +               if (ret)
> +                       return ret;
> +               /* start polling usb2 roothub */
> +               set_bit(HCD_FLAG_POLL_RH, &xhci->main_hcd->flags);
> +               usb_hcd_poll_rh_status(xhci->main_hcd);
> +               return ret;
> +       }
>         xhci_dbg_trace(xhci, trace_xhci_dbg_init, "xhci_run");
>  
>         ret = xhci_try_enable_msi(hcd);
> 
> Thanks
> -Mathias
> 
>