[v3] usb: warm-reset ports on hub resume, if requested

[Mathias Nyman <mathias.nyman@linux.intel.com>]

On 30.01.2019 14:38, Jan-Marek Glogowski wrote:
> On plug-in of my USB-C device, its USB_SS_PORT_LS_SS_INACTIVE
> link state bit is set. Greping all the kernel for this bit shows
> that the port status requests a warm-reset this way.
> 
> This just happens, if its the only device on that hub and the
> hub resumes, so we don't call port_event, which would otherwise
> warm-reset ports. The device works ok without this patch, if
> there is already any other device connected to the hub.
> 
> Signed-off-by: Jan-Marek Glogowski <glogow@fbihome.de>
> ---
> 
> The original thread is "USB-C storage device not detected on USB 3.1 Gen 2
> host when plugged in after boot". A different patch, suggested by Mathias
> Nyman, didn't work for me. This patch was just rebased on usb-next, but not
> re-tested. Original tests are based on 5.0-rc.
> 

I started to look into this in more detail, disregard the code I sent earlier, it's
not relevant.

I think your patch could be a solution, but it worries me that your logs show hub_event
evt (hub->event_bits) are zero even if port status 0x4002c0 should set a bit there.

 From you earlier log:

[  116.032422] xhci_hcd:handle_port_status: xhci_hcd 0000:00:14.0: Port Status Change Event for port 19
[  116.032432] xhci_hcd:handle_port_status: xhci_hcd 0000:00:14.0: resume root hub
[  116.032447] xhci_hcd:handle_port_status: xhci_hcd 0000:00:14.0: handle_port_status: starting port polling.
[  116.032510] usbcore:usb_remote_wakeup: usb usb3: usb wakeup-resume
[  116.032518] usbcore:hcd_bus_resume: usb usb3: usb auto-resume
[  116.032538] usbcore:hub_resume: hub 3-0:1.0: hub_resume
[  116.032567] xhci_hcd:xhci_hub_control: xhci_hcd 0000:00:14.0: get port status, actual port 0 status  = 0x2a0
[  116.032571] xhci_hcd:xhci_hub_control: xhci_hcd 0000:00:14.0: Get port status returned 0x2a0
[  116.032602] xhci_hcd:xhci_hub_control: xhci_hcd 0000:00:14.0: get port status, actual port 1 status  = 0x2a0
[  116.032606] xhci_hcd:xhci_hub_control: xhci_hcd 0000:00:14.0: Get port status returned 0x2a0
[  116.032624] xhci_hcd:xhci_hub_control: xhci_hcd 0000:00:14.0: get port status, actual port 2 status  = 0x4002c0
[  116.032633] xhci_hcd:xhci_hub_control: xhci_hcd 0000:00:14.0: Get port status returned 0x4002c0
[  116.032654] xhci_hcd:xhci_hub_control: xhci_hcd 0000:00:14.0: get port status, actual port 3 status  = 0x2a0
[  116.032658] xhci_hcd:xhci_hub_control: xhci_hcd 0000:00:14.0: Get port status returned 0x2a0
[  116.032675] xhci_hcd:xhci_hub_control: xhci_hcd 0000:00:14.0: get port status, actual port 4 status  = 0x2a0
[  116.032679] xhci_hcd:xhci_hub_control: xhci_hcd 0000:00:14.0: Get port status returned 0x2a0
[  116.032697] xhci_hcd:xhci_hub_control: xhci_hcd 0000:00:14.0: get port status, actual port 5 status  = 0x2a0
[  116.032701] xhci_hcd:xhci_hub_control: xhci_hcd 0000:00:14.0: Get port status returned 0x2a0
[  116.032766] usbcore:hub_event: hub 3-0:1.0: state 7 ports 6 chg 0000 evt 0000
[  116.032784] xhci_hcd:xhci_hub_control: xhci_hcd 0000:00:14.0: set port remote wake mask, actual port 0 status  = 0xe0002a0
[  116.032807] xhci_hcd:xhci_hub_control: xhci_hcd 0000:00:14.0: set port remote wake mask, actual port 1 status  = 0xe0002a0
[  116.032829] xhci_hcd:xhci_hub_control: xhci_hcd 0000:00:14.0: set port remote wake mask, actual port 2 status  = 0xe4002c0
[  116.032846] xhci_hcd:xhci_hub_control: xhci_hcd 0000:00:14.0: set port remote wake mask, actual port 3 status  = 0xe0002a0
[  116.032870] xhci_hcd:xhci_hub_control: xhci_hcd 0000:00:14.0: set port remote wake mask, actual port 4 status  = 0xe0002a0
[  116.032892] xhci_hcd:xhci_hub_control: xhci_hcd 0000:00:14.0: set port remote wake mask, actual port 5 status  = 0xe0002a0
[  116.032906] usbcore:hub_suspend: hub 3-0:1.0: hub_suspend
[  116.032925] usbcore:hcd_bus_suspend: usb usb3: bus auto-suspend, wakeup 1
[  116.032946] usbcore:hcd_bus_suspend: usb usb3: suspend raced with wakeup event
[  116.032950] usbcore:hcd_bus_resume: usb usb3: usb auto-resume


The hub->event bits are set when roothub polling timer function gets data from
hub_status_data(), writes the data to a status urb, and returns the urb.

Normal operation:
usb_hcd_poll_rh_status()        // roothub polling timer function
   hcd->driver->hub_status_data(hcd, buffer)   -> xhci_hub_status_data()
     xhci_hub_status_data()      //returns buffer with bits set if a port needs attention
   if (buffer && urb)
     memcpy(urb->transfer_buffer, buffer)       // copy buffer bits to urb
     usb_hcd_giveback_urb(urb)  -> hub_irq      // calls urb complete callback function
       hub_irq()
         hub->event_bits = urb->transfer_buffer //
   mod_timer(usb_hcd_poll_rh_status, future)    // reschedule roothub polling timer

I'm guessing usb_hcd_poll_rh_status() never properly completes a URB in your case.

This could be possible if roothub is polled before properly resumed, then the URB wouldn't
be available yet, and no hub->event_bits are set.
Because no bits are set the hub starts suspending again after resume, probably before roothub
timer polls roothub again.
suspend fails when it manually checks hcd->driver->hub_status_data() for activity, and
it start resuming again, and continues this in a loop.

Either roothub polling is stopped at the suspend attempt, or maybe continuously rescheduled
into the future because as a part of suspend attempt/resume loop.

Could you add one more line of debugging and capture new logs:


Thanks
-Mathias

diff --git a/drivers/usb/core/hcd.c b/drivers/usb/core/hcd.c
index 015b126..6d400f9 100644
--- a/drivers/usb/core/hcd.c
+++ b/drivers/usb/core/hcd.c
@@ -759,6 +759,10 @@ void usb_hcd_poll_rh_status(struct usb_hcd *hcd)
                 return;
  
         length = hcd->driver->hub_status_data(hcd, buffer);
+
+       dev_err(&hcd->self.root_hub->dev, "%s, length %d, hcd->flags 0x%lx, status_urb %s\n",
+               __func__, length, hcd->flags, hcd->status_urb ? "Exists" : "NULL" );
+
         if (length > 0) {
  
                 /* try to complete the status urb */