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

From: Kishon Vijay Abraham I
Date: Fri Aug 20 2021 - 08:18:44 EST


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