On 18.02.2016 18:34, Mike Murdoch wrote:
On 2016-02-18 16:12, Mathias Nyman wrote:
On 16.02.2016 23:58, main.haarp@xxxxxxxxxxxxxx wrote:
On 2016-02-08 15:31, Mathias Nyman wrote:
Hi
On 06.02.2016 19:08, Mike Murdoch wrote:
Bug ID: 111251
Hello,
I have a NEC uPD720200 USB3.0 controller in a Thinkpad W520 laptop on
kernel 4.4.1-gentoo.
0e:00.0 USB controller: NEC Corporation uPD720200 USB 3.0 Host
Controller (rev 04) (prog-if 30 [XHCI])
Subsystem: Lenovo uPD720200 USB 3.0 Host Controller
When runtime power control for this controller is disabled
(/sys/bus/pci/devices/0000:0e:00.0/power/control = on), the controller
works fine and reaches over 120MB/s transfer rates.
When runtime power control for this controller is enabled
(/sys/bus/pci/devices/0000:0e:00.0/power/control = auto), two effects
can be observed:
- Transfer rates are much lower at around 30MB/s
- During transfers, the controller dies after a couple of seconds:
At this point, a reboot is required to reactivate the controller,
unloading and reloading the xhci_* modules does not work.
...
I did some more digging, there are a few things that need to be addressed:
1. We should resume USB3 bus before USB2 bus to let devices enumerate as USB3 better,
this gives them more time to finish the link training.
2. After resuming xhci we don't see any port changes immediately, hub thinks nothing
happended and stops polling the ports, hub will suspend again -> xhci will try to
suspend.
3. Roothubs will autosuspend immediately after autoresume, (autosuspend timeout = 0)
This could be a reason why we see the "xhci_suspend" entry in the log. We either
need to increase the autosuspend timeout, or prevent suspend if we can see the pending
event in a xhci status register.
inserting usb3 storage device
Feb 16 20:03:33 xhci_hcd 0000:0e:00.0: // Setting command ring address to 0xffffe001
Feb 16 20:03:33 xhci_hcd 0000:0e:00.0: xhci_resume: starting port polling.
Feb 16 20:03:33 xhci_hcd 0000:0e:00.0: xhci_hub_status_data: stopping port polling.
Feb 16 20:03:33 xhci_hcd 0000:0e:00.0: xhci_suspend: stopping port polling.
I got a few patches, attached. They both partially try to fix the issue, and add more logging.
Same changes can be found in a topic branch from in:
git://git.kernel.org/pub/scm/linux/kernel/git/mnyman/xhci.git bug_usb3_enum_rtresume
Any chance to try them out?
-Mathias
>From 4427456ee6228155e72f38c740e0bf78c8ad7792 Mon Sep 17 00:00:00 2001
From: Mathias Nyman <mathias.nyman@xxxxxxxxxxxxxxx>
Date: Mon, 29 Feb 2016 11:33:25 +0200
Subject: [PATCH 1/3] xhci: resume USB 3 roothub first
Give USB 3 devices a better chance to enumerate at USB 3 speeds if
they are connected to a suspended host.
Signed-off-by: Mathias Nyman <mathias.nyman@xxxxxxxxxxxxxxx>
---
drivers/usb/host/xhci.c | 6 +++---
1 file changed, 3 insertions(+), 3 deletions(-)
diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c
index d51ee0c..b609288 100644
--- a/drivers/usb/host/xhci.c
+++ b/drivers/usb/host/xhci.c
@@ -1108,8 +1108,8 @@ int xhci_resume(struct xhci_hcd *xhci, bool hibernated)
/* Resume root hubs only when have pending events. */
status = readl(&xhci->op_regs->status);
if (status & STS_EINT) {
- usb_hcd_resume_root_hub(hcd);
usb_hcd_resume_root_hub(xhci->shared_hcd);
+ usb_hcd_resume_root_hub(hcd);
}
}
@@ -1124,10 +1124,10 @@ int xhci_resume(struct xhci_hcd *xhci, bool hibernated)
/* Re-enable port polling. */
xhci_dbg(xhci, "%s: starting port polling.\n", __func__);
- set_bit(HCD_FLAG_POLL_RH, &hcd->flags);
- usb_hcd_poll_rh_status(hcd);
set_bit(HCD_FLAG_POLL_RH, &xhci->shared_hcd->flags);
usb_hcd_poll_rh_status(xhci->shared_hcd);
+ set_bit(HCD_FLAG_POLL_RH, &hcd->flags);
+ usb_hcd_poll_rh_status(hcd);
return retval;
}
--
1.9.1
>From a37d2160f8e801fe8ba3c1a4938f0fa17d56de7b Mon Sep 17 00:00:00 2001
From: Mathias Nyman <mathias.nyman@xxxxxxxxxxxxxxx>
Date: Mon, 29 Feb 2016 16:07:03 +0200
Subject: [PATCH 2/3] xhci: Add bus number to debug output
Debugging enumeration races between usb USB2 and USB3 buses
are hard to debug when there is no indication of what message
belongs to which bus.
Signed-off-by: Mathias Nyman <mathias.nyman@xxxxxxxxxxxxxxx>
---
drivers/usb/host/xhci-hub.c | 26 ++++++++++++++------------
drivers/usb/host/xhci-ring.c | 8 +++++---
drivers/usb/host/xhci.c | 2 +-
3 files changed, 20 insertions(+), 16 deletions(-)
diff --git a/drivers/usb/host/xhci-hub.c b/drivers/usb/host/xhci-hub.c
index d61fcc4..8e61925 100644
--- a/drivers/usb/host/xhci-hub.c
+++ b/drivers/usb/host/xhci-hub.c
@@ -458,8 +458,8 @@ static void xhci_disable_port(struct usb_hcd *hcd, struct xhci_hcd *xhci,
/* Write 1 to disable the port */
writel(port_status | PORT_PE, addr);
port_status = readl(addr);
- xhci_dbg(xhci, "disable port, actual port %d status = 0x%x\n",
- wIndex, port_status);
+ xhci_dbg(xhci, "disable port, bus%d port %d portsc = 0x%x\n",
+ hcd->self.busnum, wIndex, port_status);
}
static void xhci_clear_port_change_bit(struct xhci_hcd *xhci, u16 wValue,
@@ -508,8 +508,8 @@ static void xhci_clear_port_change_bit(struct xhci_hcd *xhci, u16 wValue,
/* Change bits are all write 1 to clear */
writel(port_status | status, addr);
port_status = readl(addr);
- xhci_dbg(xhci, "clear port %s change, actual port %d status = 0x%x\n",
- port_change_bit, wIndex, port_status);
+ xhci_dbg(xhci, "clear port %s change, port %d portsc = 0x%x\n",
+ port_change_bit, wIndex, port_status);
}
static int xhci_get_ports(struct usb_hcd *hcd, __le32 __iomem ***port_array)
@@ -932,8 +932,8 @@ int xhci_hub_control(struct usb_hcd *hcd, u16 typeReq, u16 wValue,
if (status == 0xffffffff)
goto error;
- xhci_dbg(xhci, "get port status, actual port %d status = 0x%x\n",
- wIndex, temp);
+ xhci_dbg(xhci, "get port status, bus%d port %d portsc = 0x%x\n",
+ hcd->self.busnum, wIndex, temp);
xhci_dbg(xhci, "Get port status returned 0x%x\n", status);
put_unaligned(cpu_to_le32(status), (__le32 *) buf);
@@ -1084,7 +1084,8 @@ int xhci_hub_control(struct usb_hcd *hcd, u16 typeReq, u16 wValue,
writel(temp | PORT_POWER, port_array[wIndex]);
temp = readl(port_array[wIndex]);
- xhci_dbg(xhci, "set port power, actual port %d status = 0x%x\n", wIndex, temp);
+ xhci_dbg(xhci, "set port power, bus%d port %d portsc = 0x%x\n",
+ hcd->self.busnum, wIndex, temp);
spin_unlock_irqrestore(&xhci->lock, flags);
temp = usb_acpi_power_manageable(hcd->self.root_hub,
@@ -1099,15 +1100,15 @@ int xhci_hub_control(struct usb_hcd *hcd, u16 typeReq, u16 wValue,
writel(temp, port_array[wIndex]);
temp = readl(port_array[wIndex]);
- xhci_dbg(xhci, "set port reset, actual port %d status = 0x%x\n", wIndex, temp);
+ xhci_dbg(xhci, "set port reset, bus%d port %d portsc = 0x%x\n",
+ hcd->self.busnum, wIndex, temp);
break;
case USB_PORT_FEAT_REMOTE_WAKE_MASK:
xhci_set_remote_wake_mask(xhci, port_array,
wIndex, wake_mask);
temp = readl(port_array[wIndex]);
- xhci_dbg(xhci, "set port remote wake mask, "
- "actual port %d status = 0x%x\n",
- wIndex, temp);
+ xhci_dbg(xhci, "set port remote wake mask, bus%d port %d portsc = 0x%x\n",
+ hcd->self.busnum, wIndex, temp);
break;
case USB_PORT_FEAT_BH_PORT_RESET:
temp |= PORT_WR;
@@ -1273,7 +1274,8 @@ int xhci_hub_status_data(struct usb_hcd *hcd, char *buf)
reset_change = true;
}
if (!status && !reset_change) {
- xhci_dbg(xhci, "%s: stopping port polling.\n", __func__);
+ xhci_dbg(xhci, "%s: stopping port polling on bus%d\n",
+ __func__, hcd->self.busnum);
clear_bit(HCD_FLAG_POLL_RH, &hcd->flags);
}
spin_unlock_irqrestore(&xhci->lock, flags);
diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c
index 7cf6621..eb46fee 100644
--- a/drivers/usb/host/xhci-ring.c
+++ b/drivers/usb/host/xhci-ring.c
@@ -1552,7 +1552,7 @@ static void handle_port_status(struct xhci_hcd *xhci,
temp = readl(port_array[faked_port_index]);
if (hcd->state == HC_STATE_SUSPENDED) {
- xhci_dbg(xhci, "resume root hub\n");
+ xhci_dbg(xhci, "resume bus%d root hub\n", hcd->self.busnum);
usb_hcd_resume_root_hub(hcd);
}
@@ -1560,7 +1560,8 @@ static void handle_port_status(struct xhci_hcd *xhci,
bus_state->port_remote_wakeup &= ~(1 << faked_port_index);
if ((temp & PORT_PLC) && (temp & PORT_PLS_MASK) == XDEV_RESUME) {
- xhci_dbg(xhci, "port resume event for port %d\n", port_id);
+ xhci_dbg(xhci, "port resume event for bus%d port %d\n",
+ hcd->self.busnum, port_id);
temp1 = readl(&xhci->op_regs->command);
if (!(temp1 & CMD_RUN)) {
@@ -1657,7 +1658,8 @@ cleanup:
* bits are still set. When an event occurs, switch over to
* polling to avoid losing status changes.
*/
- xhci_dbg(xhci, "%s: starting port polling.\n", __func__);
+ xhci_dbg(xhci, "%s: starting port polling on bus%d.\n",
+ __func__, hcd->self.busnum);
set_bit(HCD_FLAG_POLL_RH, &hcd->flags);
spin_unlock(&xhci->lock);
/* Pass this up to the core */
diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c
index b609288..0a468cb 100644
--- a/drivers/usb/host/xhci.c
+++ b/drivers/usb/host/xhci.c
@@ -1123,7 +1123,7 @@ int xhci_resume(struct xhci_hcd *xhci, bool hibernated)
compliance_mode_recovery_timer_init(xhci);
/* Re-enable port polling. */
- xhci_dbg(xhci, "%s: starting port polling.\n", __func__);
+ xhci_dbg(xhci, "%s: starting port polling, both buses\n", __func__);
set_bit(HCD_FLAG_POLL_RH, &xhci->shared_hcd->flags);
usb_hcd_poll_rh_status(xhci->shared_hcd);
set_bit(HCD_FLAG_POLL_RH, &hcd->flags);
--
1.9.1
>From 7d4b3b6ff96ff769fd47e8038486bcf3c1148653 Mon Sep 17 00:00:00 2001
From: Mathias Nyman <mathias.nyman@xxxxxxxxxxxxxxx>
Date: Tue, 1 Mar 2016 16:21:20 +0200
Subject: [PATCH 3/3] xhci: Don't suspend the xhci bus it there is a pending
event.
We don't want to suspend the bus if there is an event pending.
Also add debugging of the xhci status register in various pm
callbacks to help pm and event debugging.
Signed-off-by: Mathias Nyman <mathias.nyman@xxxxxxxxxxxxxxx>
---
drivers/usb/host/xhci-hub.c | 8 ++++++++
drivers/usb/host/xhci.c | 1 +
2 files changed, 9 insertions(+)
diff --git a/drivers/usb/host/xhci-hub.c b/drivers/usb/host/xhci-hub.c
index 8e61925..c9f753c 100644
--- a/drivers/usb/host/xhci-hub.c
+++ b/drivers/usb/host/xhci-hub.c
@@ -1291,12 +1291,20 @@ int xhci_bus_suspend(struct usb_hcd *hcd)
__le32 __iomem **port_array;
struct xhci_bus_state *bus_state;
unsigned long flags;
+ u32 status;
max_ports = xhci_get_ports(hcd, &port_array);
bus_state = &xhci->bus_state[hcd_index(hcd)];
spin_lock_irqsave(&xhci->lock, flags);
+ /* Don't suspend root hub if there's an event pending. */
+ /* FIXME, should we check for port event ? STS_PORT??*/
+ status = readl(&xhci->op_regs->status);
+ xhci_dbg(xhci, "xhci status reg in xhci_bus_suspend = 0x%x\n", status);
+ if (status & STS_EINT)
+ return -EBUSY;
+
if (hcd->self.root_hub->do_remote_wakeup) {
if (bus_state->resuming_ports || /* USB2 */
bus_state->port_remote_wakeup) { /* USB3 */
diff --git a/drivers/usb/host/xhci.c b/drivers/usb/host/xhci.c
index 0a468cb..3da0636 100644
--- a/drivers/usb/host/xhci.c
+++ b/drivers/usb/host/xhci.c
@@ -1107,6 +1107,7 @@ int xhci_resume(struct xhci_hcd *xhci, bool hibernated)
if (retval == 0) {
/* Resume root hubs only when have pending events. */
status = readl(&xhci->op_regs->status);
+ xhci_dbg(xhci, "xhci_resume status reg = 0x%x\n", status);
if (status & STS_EINT) {
usb_hcd_resume_root_hub(xhci->shared_hcd);
usb_hcd_resume_root_hub(hcd);
--
1.9.1
