2013-03-23 14:25:44

by Rafael J. Wysocki

[permalink] [raw]
Subject: [PATCH] PCI / ACPI: Always resume devices on ACPI wakeup notifications

From: Rafael J. Wysocki <[email protected]>

It turns out that _Lxx control methods provided by some BIOSes clear
the PME Status bit of PCI devices they handle, which means that
pci_acpi_wake_dev() cannot really use that bit to check whether or
not the device has signalled wakeup.

For this reason, make pci_acpi_wake_dev() always attempt to resume
the device it is called for regardless of the device's PME Status bit
value (that bit still has to be cleared if set at this point,
though).

Reported-by: Sarah Sharp <[email protected]>
Signed-off-by: Rafael J. Wysocki <[email protected]>
---
drivers/pci/pci-acpi.c | 15 ++++++++-------
1 file changed, 8 insertions(+), 7 deletions(-)

Index: linux-pm/drivers/pci/pci-acpi.c
===================================================================
--- linux-pm.orig/drivers/pci/pci-acpi.c
+++ linux-pm/drivers/pci/pci-acpi.c
@@ -53,14 +53,15 @@ static void pci_acpi_wake_dev(acpi_handl
return;
}

- if (!pci_dev->pm_cap || !pci_dev->pme_support
- || pci_check_pme_status(pci_dev)) {
- if (pci_dev->pme_poll)
- pci_dev->pme_poll = false;
+ /* Clear PME Status if set. */
+ if (pci_dev->pme_support)
+ pci_check_pme_status(pci_dev);

- pci_wakeup_event(pci_dev);
- pm_runtime_resume(&pci_dev->dev);
- }
+ if (pci_dev->pme_poll)
+ pci_dev->pme_poll = false;
+
+ pci_wakeup_event(pci_dev);
+ pm_runtime_resume(&pci_dev->dev);

if (pci_dev->subordinate)
pci_pme_wakeup_bus(pci_dev->subordinate);


2013-03-25 16:46:21

by Sarah Sharp

[permalink] [raw]
Subject: Re: [PATCH] PCI / ACPI: Always resume devices on ACPI wakeup notifications

On Sat, Mar 23, 2013 at 03:33:03PM +0100, Rafael J. Wysocki wrote:
> From: Rafael J. Wysocki <[email protected]>
>
> It turns out that _Lxx control methods provided by some BIOSes clear
> the PME Status bit of PCI devices they handle, which means that
> pci_acpi_wake_dev() cannot really use that bit to check whether or
> not the device has signalled wakeup.
>
> For this reason, make pci_acpi_wake_dev() always attempt to resume
> the device it is called for regardless of the device's PME Status bit
> value (that bit still has to be cleared if set at this point,
> though).
>
> Reported-by: Sarah Sharp <[email protected]>
> Signed-off-by: Rafael J. Wysocki <[email protected]>

Should this be marked for stable? I had this issue on 3.7 and 3.8 as
well.

Sarah

> ---
> drivers/pci/pci-acpi.c | 15 ++++++++-------
> 1 file changed, 8 insertions(+), 7 deletions(-)
>
> Index: linux-pm/drivers/pci/pci-acpi.c
> ===================================================================
> --- linux-pm.orig/drivers/pci/pci-acpi.c
> +++ linux-pm/drivers/pci/pci-acpi.c
> @@ -53,14 +53,15 @@ static void pci_acpi_wake_dev(acpi_handl
> return;
> }
>
> - if (!pci_dev->pm_cap || !pci_dev->pme_support
> - || pci_check_pme_status(pci_dev)) {
> - if (pci_dev->pme_poll)
> - pci_dev->pme_poll = false;
> + /* Clear PME Status if set. */
> + if (pci_dev->pme_support)
> + pci_check_pme_status(pci_dev);
>
> - pci_wakeup_event(pci_dev);
> - pm_runtime_resume(&pci_dev->dev);
> - }
> + if (pci_dev->pme_poll)
> + pci_dev->pme_poll = false;
> +
> + pci_wakeup_event(pci_dev);
> + pm_runtime_resume(&pci_dev->dev);
>
> if (pci_dev->subordinate)
> pci_pme_wakeup_bus(pci_dev->subordinate);
>

2013-03-25 22:27:35

by Rafael J. Wysocki

[permalink] [raw]
Subject: Re: [PATCH] PCI / ACPI: Always resume devices on ACPI wakeup notifications

On Monday, March 25, 2013 09:45:51 AM Sarah Sharp wrote:
> On Sat, Mar 23, 2013 at 03:33:03PM +0100, Rafael J. Wysocki wrote:
> > From: Rafael J. Wysocki <[email protected]>
> >
> > It turns out that _Lxx control methods provided by some BIOSes clear
> > the PME Status bit of PCI devices they handle, which means that
> > pci_acpi_wake_dev() cannot really use that bit to check whether or
> > not the device has signalled wakeup.
> >
> > For this reason, make pci_acpi_wake_dev() always attempt to resume
> > the device it is called for regardless of the device's PME Status bit
> > value (that bit still has to be cleared if set at this point,
> > though).
> >
> > Reported-by: Sarah Sharp <[email protected]>
> > Signed-off-by: Rafael J. Wysocki <[email protected]>
>
> Should this be marked for stable? I had this issue on 3.7 and 3.8 as
> well.

Yes, it probably should, but that's the maintainer's call.

Thanks,
Rafael


> > ---
> > drivers/pci/pci-acpi.c | 15 ++++++++-------
> > 1 file changed, 8 insertions(+), 7 deletions(-)
> >
> > Index: linux-pm/drivers/pci/pci-acpi.c
> > ===================================================================
> > --- linux-pm.orig/drivers/pci/pci-acpi.c
> > +++ linux-pm/drivers/pci/pci-acpi.c
> > @@ -53,14 +53,15 @@ static void pci_acpi_wake_dev(acpi_handl
> > return;
> > }
> >
> > - if (!pci_dev->pm_cap || !pci_dev->pme_support
> > - || pci_check_pme_status(pci_dev)) {
> > - if (pci_dev->pme_poll)
> > - pci_dev->pme_poll = false;
> > + /* Clear PME Status if set. */
> > + if (pci_dev->pme_support)
> > + pci_check_pme_status(pci_dev);
> >
> > - pci_wakeup_event(pci_dev);
> > - pm_runtime_resume(&pci_dev->dev);
> > - }
> > + if (pci_dev->pme_poll)
> > + pci_dev->pme_poll = false;
> > +
> > + pci_wakeup_event(pci_dev);
> > + pm_runtime_resume(&pci_dev->dev);
> >
> > if (pci_dev->subordinate)
> > pci_pme_wakeup_bus(pci_dev->subordinate);
> >
--
I speak only for myself.
Rafael J. Wysocki, Intel Open Source Technology Center.

2013-03-28 17:03:11

by Rafael J. Wysocki

[permalink] [raw]
Subject: [Resend][PATCH] PCI / ACPI: Always resume devices on ACPI wakeup notifications

From: Rafael J. Wysocki <[email protected]>

It turns out that the _Lxx control methods provided by some BIOSes
clear the PME Status bit of PCI devices they handle, which means that
pci_acpi_wake_dev() cannot really use that bit to check whether or
not the device has signalled wakeup.

The symptom of the problem is, for example, that when a PCI USB
controller is affected, then plugging in a new USB device into one of
the controller's ports will not wake up the controller, which should
happen.

For this reason, make pci_acpi_wake_dev() always attempt to resume
the device it is called for regardless of the device's PME Status bit
value (that bit still has to be cleared if set at this point,
though).

Reported-and-tested-by: Sarah Sharp <[email protected]>
Signed-off-by: Rafael J. Wysocki <[email protected]>
Acked-by: Matthew Garrett <[email protected]>
Cc: 3.7+ <[email protected]>
---
drivers/pci/pci-acpi.c | 15 ++++++++-------
1 file changed, 8 insertions(+), 7 deletions(-)

Index: linux-pm/drivers/pci/pci-acpi.c
===================================================================
--- linux-pm.orig/drivers/pci/pci-acpi.c
+++ linux-pm/drivers/pci/pci-acpi.c
@@ -53,14 +53,15 @@ static void pci_acpi_wake_dev(acpi_handl
return;
}

- if (!pci_dev->pm_cap || !pci_dev->pme_support
- || pci_check_pme_status(pci_dev)) {
- if (pci_dev->pme_poll)
- pci_dev->pme_poll = false;
+ /* Clear PME Status if set. */
+ if (pci_dev->pme_support)
+ pci_check_pme_status(pci_dev);

- pci_wakeup_event(pci_dev);
- pm_runtime_resume(&pci_dev->dev);
- }
+ if (pci_dev->pme_poll)
+ pci_dev->pme_poll = false;
+
+ pci_wakeup_event(pci_dev);
+ pm_runtime_resume(&pci_dev->dev);

if (pci_dev->subordinate)
pci_pme_wakeup_bus(pci_dev->subordinate);

2013-03-28 21:00:05

by Rafael J. Wysocki

[permalink] [raw]
Subject: [Update][PATCH] PCI / ACPI: Always resume devices on ACPI wakeup notifications

From: Rafael J. Wysocki <[email protected]>
Subject: PCI / ACPI: Always resume devices on ACPI wakeup notifications

It turns out that the _Lxx control methods provided by some BIOSes
clear the PME Status bit of PCI devices they handle, which means that
pci_acpi_wake_dev() cannot really use that bit to check whether or
not the device has signalled wakeup.

One symptom of the problem is, for example, that when an affected PCI
USB controller is runtime-suspended, then plugging in a new USB device
into one of the controller's ports will not wake up the controller,
which should happen.

For this reason, make pci_acpi_wake_dev() always attempt to resume
the device it is called for regardless of the device's PME Status bit
value (that bit still has to be cleared if set at this point,
though).

Reported-by: Sarah Sharp <[email protected]>
Signed-off-by: Rafael J. Wysocki <[email protected]>
Acked-by: Matthew Garrett <[email protected]>
Cc: 3.7+ <[email protected]>
---

The changelog in this version is slightly better than in the previous one, IMHO.

Thanks,
Rafael

---
drivers/pci/pci-acpi.c | 15 ++++++++-------
1 file changed, 8 insertions(+), 7 deletions(-)

Index: linux-pm/drivers/pci/pci-acpi.c
===================================================================
--- linux-pm.orig/drivers/pci/pci-acpi.c
+++ linux-pm/drivers/pci/pci-acpi.c
@@ -53,14 +53,15 @@ static void pci_acpi_wake_dev(acpi_handl
return;
}

- if (!pci_dev->pm_cap || !pci_dev->pme_support
- || pci_check_pme_status(pci_dev)) {
- if (pci_dev->pme_poll)
- pci_dev->pme_poll = false;
+ /* Clear PME Status if set. */
+ if (pci_dev->pme_support)
+ pci_check_pme_status(pci_dev);

- pci_wakeup_event(pci_dev);
- pm_runtime_resume(&pci_dev->dev);
- }
+ if (pci_dev->pme_poll)
+ pci_dev->pme_poll = false;
+
+ pci_wakeup_event(pci_dev);
+ pm_runtime_resume(&pci_dev->dev);

if (pci_dev->subordinate)
pci_pme_wakeup_bus(pci_dev->subordinate);

2013-03-29 15:08:17

by Martin Mokrejs

[permalink] [raw]
Subject: Re: [Update][PATCH] PCI / ACPI: Always resume devices on ACPI wakeup notifications

Hi,
I applied this patches over 3.8.3 hoping it will fix my issue under
thread: "Re: 3.8.2: xhci port is dead until pcieport PME# goes to disabled"
but unfortunately, it is even worse! Now, although lsusb -v nor lsusb -vv do
wakeup the XHCI port but it falls asleep immediately, more quickly than I am
able to plug a device into the socket. To get a device working in the USB3 socket
I need to plug it in, run lsusb -vv and then it is recognized.

Without the patch, the 'lsusb -vv' woke up the port (PME# disabled happened
on both 1c.4 and 0b:00.0) and I had unlimited time to find some USB device
around and to plug it into the slot.


I noticed this message some while after a bootup (no external USB devices were
connected to the laptop, neither into USB2 socket nor into USB3.0 sockets) before
I started to do the tests:

[ 36.594171] xhci_hcd 0000:0b:00.0: xhci_suspend: stopping port polling.
[ 36.594202] xhci_hcd 0000:0b:00.0: // Setting command ring address to 0xd6007001
[ 36.594247] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_suspend: 0
[ 36.594349] xhci_hcd 0000:0b:00.0: PME# enabled
[ 36.703695] r8169 0000:05:00.0 eth0: link down
[ 37.098299] microcode: CPU0 updated to revision 0x28, date = 2012-04-24
[ 37.098941] microcode: CPU1 updated to revision 0x28, date = 2012-04-24
[ 37.098944] perf_event_intel: PEBS enabled due to microcode update
[ 38.343029] r8169 0000:05:00.0 eth0: link up
[ 39.094944] r8169 0000:05:00.0 eth0: link down
[ 41.492768] r8169 0000:05:00.0 eth0: link up
[ 62.782910] xhci_hcd 0000:0b:00.0: Poll event ring: 4294943584
[ 62.782938] xhci_hcd 0000:0b:00.0: op reg status = 0xffffffff
[ 62.782939] xhci_hcd 0000:0b:00.0: HW died, polling stopped.
[ 88.754183] pcieport 0000:00:1c.0: PME# enabled
[ 88.764182] xhci_hcd 0000:0b:00.0: PME# disabled
[ 88.764192] xhci_hcd 0000:0b:00.0: enabling bus mastering
[ 88.764206] xhci_hcd 0000:0b:00.0: // Setting command ring address to 0xd6007001
[ 88.764242] xhci_hcd 0000:0b:00.0: Port Status Change Event for port 2
[ 88.764246] xhci_hcd 0000:0b:00.0: resume root hub
[ 88.764259] xhci_hcd 0000:0b:00.0: handle_port_status: starting port polling.
[ 88.764276] xhci_hcd 0000:0b:00.0: xhci_resume: starting port polling.
[ 88.764281] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_resume: 0


What "HW died? Why 1c.0 is here? What is this device actually doing?

00:1c.0 PCI bridge: Intel Corporation 6 Series/C200 Series Chipset Family PCI Express Root Port 1 (rev b5) (prog-if 00 [Normal decode])
Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
Latency: 0, Cache Line Size: 64 bytes
Bus: primary=00, secondary=03, subordinate=04, sec-latency=0
I/O behind bridge: 0000f000-00000fff
Memory behind bridge: fff00000-000fffff
Prefetchable memory behind bridge: 00000000fff00000-00000000000fffff
Secondary status: 66MHz- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort+ <SERR- <PERR-
BridgeCtl: Parity- SERR- NoISA- VGA- MAbort- >Reset- FastB2B-
PriDiscTmr- SecDiscTmr- DiscTmrStat- DiscTmrSERREn-
Capabilities: [40] Express (v2) Root Port (Slot+), MSI 00
DevCap: MaxPayload 128 bytes, PhantFunc 0, Latency L0s <64ns, L1 <1us
ExtTag- RBE+ FLReset-
DevCtl: Report errors: Correctable- Non-Fatal- Fatal- Unsupported-
RlxdOrd- ExtTag- PhantFunc- AuxPwr- NoSnoop-
MaxPayload 128 bytes, MaxReadReq 128 bytes
DevSta: CorrErr- UncorrErr- FatalErr- UnsuppReq- AuxPwr+ TransPend-
LnkCap: Port #1, Speed 5GT/s, Width x1, ASPM L0s L1, Latency L0 <1us, L1 <16us
ClockPM- Surprise- LLActRep+ BwNot-
LnkCtl: ASPM L1 Enabled; RCB 64 bytes Disabled- Retrain- CommClk-
ExtSynch- ClockPM- AutWidDis- BWInt- AutBWInt-
LnkSta: Speed 2.5GT/s, Width x0, TrErr- Train- SlotClk+ DLActive- BWMgmt- ABWMgmt-
SltCap: AttnBtn- PwrCtrl- MRL- AttnInd- PwrInd- HotPlug- Surprise-
Slot #0, PowerLimit 10.000W; Interlock- NoCompl+
SltCtl: Enable: AttnBtn- PwrFlt- MRL- PresDet- CmdCplt- HPIrq- LinkChg-
Control: AttnInd Unknown, PwrInd Unknown, Power- Interlock-
SltSta: Status: AttnBtn- PowerFlt- MRL- CmdCplt- PresDet- Interlock-
Changed: MRL- PresDet- LinkState-
RootCtl: ErrCorrectable- ErrNon-Fatal- ErrFatal- PMEIntEna- CRSVisible-
RootCap: CRSVisible-
RootSta: PME ReqID 0000, PMEStatus- PMEPending-
DevCap2: Completion Timeout: Range BC, TimeoutDis+, LTR-, OBFF Not Supported ARIFwd-
DevCtl2: Completion Timeout: 50us to 50ms, TimeoutDis-, LTR-, OBFF Disabled ARIFwd-
LnkCtl2: Target Link Speed: 2.5GT/s, EnterCompliance- SpeedDis-
Transmit Margin: Normal Operating Range, EnterModifiedCompliance- ComplianceSOS-
Compliance De-emphasis: -6dB
LnkSta2: Current De-emphasis Level: -3.5dB, EqualizationComplete-, EqualizationPhase1-
EqualizationPhase2-, EqualizationPhase3-, LinkEqualizationRequest-
Capabilities: [80] MSI: Enable- Count=1/1 Maskable- 64bit-
Address: 00000000 Data: 0000
Capabilities: [90] Subsystem: Dell Device 04b3
Capabilities: [a0] Power Management version 2
Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0+,D1-,D2-,D3hot+,D3cold+)
Status: D3 NoSoftRst- PME-Enable+ DSel=0 DScale=0 PME-
Kernel driver in use: pcieport





Nevertheless, I went to check if if the USB3 socket dies after first unplug of device
or not anymore thanks to the patch being tested:

I plugged into the USB3.0 socket a mouse, it worked. Around its unplug I got:

[ 94.954779] hub 3-0:1.0: debounce: port 2: total 100ms stable 100ms status 0x100
[ 94.954795] hub 3-0:1.0: hub_suspend
[ 94.954802] usb usb3: bus auto-suspend, wakeup 1
[ 94.954817] xhci_hcd 0000:0b:00.0: xhci_hub_status_data: stopping port polling.
[ 94.954835] xhci_hcd 0000:0b:00.0: xhci_suspend: stopping port polling.
[ 94.954857] xhci_hcd 0000:0b:00.0: // Setting command ring address to 0xd6007001
[ 94.954898] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_suspend: 0
[ 94.954983] xhci_hcd 0000:0b:00.0: PME# enabled
[ 169.622513] hub 2-1:1.0: state 7 ports 8 chg 0000 evt 0004
[ 169.623057] hub 2-1:1.0: port 2, status 0101, change 0001, 12 Mb/s
[ 169.777012] hub 2-1:1.0: debounce: port 2: total 100ms stable 100ms status 0x101
[ 169.856992] usb 2-1.2: new low-speed USB device number 4 using ehci-pci

and the port was dead, no matter what "lsusb -v or -vv" options I tried. At about
[ 169.622513] I plugged the mouse into a USB2.0 socket (do not know if that is 1a.0 or 1d.0).

# lspci -tv
-[0000:00]-+-00.0 Intel Corporation 2nd Generation Core Processor Family DRAM Controller
+-02.0 Intel Corporation 2nd Generation Core Processor Family Integrated Graphics Controller
+-16.0 Intel Corporation 6 Series/C200 Series Chipset Family MEI Controller #1
+-1a.0 Intel Corporation 6 Series/C200 Series Chipset Family USB Enhanced Host Controller #2
+-1b.0 Intel Corporation 6 Series/C200 Series Chipset Family High Definition Audio Controller
+-1c.0-[03-04]--
+-1c.1-[05-06]----00.0 Realtek Semiconductor Co., Ltd. RTL8111/8168 PCI Express Gigabit Ethernet controller
+-1c.3-[09-0a]----00.0 Intel Corporation Centrino Wireless-N 1030 [Rainbow Peak]
+-1c.4-[0b-0c]----00.0 Texas Instruments TUSB73x0 SuperSpeed USB 3.0 xHCI Host Controller
+-1c.7-[11-16]----00.0 Silicon Image, Inc. SiI 3132 Serial ATA Raid II Controller
+-1d.0 Intel Corporation 6 Series/C200 Series Chipset Family USB Enhanced Host Controller #1
+-1f.0 Intel Corporation HM67 Express Chipset Family LPC Controller
+-1f.2 Intel Corporation 6 Series/C200 Series Chipset Family 6 port SATA AHCI Controller
\-1f.3 Intel Corporation 6 Series/C200 Series Chipset Family SMBus Controller
#


Why isn't the PME# enabled/disabled reported for the USB2.0 port of the
same laptop? There I can plugin a device many times in and out and not a single PME# line is
spitted by dmesg.
# grep . /sys/bus/pci/devices/*/power/control
/sys/bus/pci/devices/0000:00:00.0/power/control:auto
/sys/bus/pci/devices/0000:00:02.0/power/control:auto
/sys/bus/pci/devices/0000:00:16.0/power/control:auto
/sys/bus/pci/devices/0000:00:1a.0/power/control:auto
/sys/bus/pci/devices/0000:00:1b.0/power/control:auto
/sys/bus/pci/devices/0000:00:1c.0/power/control:auto
/sys/bus/pci/devices/0000:00:1c.1/power/control:auto
/sys/bus/pci/devices/0000:00:1c.3/power/control:auto
/sys/bus/pci/devices/0000:00:1c.4/power/control:auto
/sys/bus/pci/devices/0000:00:1c.7/power/control:auto
/sys/bus/pci/devices/0000:00:1d.0/power/control:auto
/sys/bus/pci/devices/0000:00:1f.0/power/control:auto
/sys/bus/pci/devices/0000:00:1f.2/power/control:auto
/sys/bus/pci/devices/0000:00:1f.3/power/control:auto
/sys/bus/pci/devices/0000:05:00.0/power/control:auto
/sys/bus/pci/devices/0000:09:00.0/power/control:auto
/sys/bus/pci/devices/0000:0b:00.0/power/control:auto
/sys/bus/pci/devices/0000:11:00.0/power/control:auto
# grep . /sys/bus/pci/devices/*/power/runtime_status
/sys/bus/pci/devices/0000:00:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:02.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:16.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1a.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1b.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1c.1/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.3/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.4/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1c.7/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1d.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.3/power/runtime_status:suspended
/sys/bus/pci/devices/0000:05:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:09:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:0b:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:11:00.0/power/runtime_status:active
#

If I run lsusb -vv it does (with the problematic patch):

[ 1760.414086] pcieport 0000:00:1c.4: PME# disabled
[ 1760.434314] xhci_hcd 0000:0b:00.0: PME# disabled
[ 1760.434327] xhci_hcd 0000:0b:00.0: enabling bus mastering
[ 1760.434338] xhci_hcd 0000:0b:00.0: // Setting command ring address to 0xd6007001
[ 1760.434360] xhci_hcd 0000:0b:00.0: Port Status Change Event for port 2
[ 1760.434363] xhci_hcd 0000:0b:00.0: resume root hub
[ 1760.434367] xhci_hcd 0000:0b:00.0: handle_port_status: starting port polling.
[ 1760.434378] xhci_hcd 0000:0b:00.0: xhci_resume: starting port polling.
[ 1760.434383] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_resume: 0
[ 1760.434388] usb usb3: usb auto-resume
[ 1760.434407] hub 3-0:1.0: hub_resume
[ 1760.434439] xhci_hcd 0000:0b:00.0: get port status, actual port 0 status = 0x2a0
[ 1760.434440] xhci_hcd 0000:0b:00.0: Get port status returned 0x100
[ 1760.434464] xhci_hcd 0000:0b:00.0: get port status, actual port 1 status = 0x202a0
[ 1760.434465] xhci_hcd 0000:0b:00.0: Get port status returned 0x10100
[ 1760.434492] xhci_hcd 0000:0b:00.0: clear port connect change, actual port 1 status = 0x2a0
[ 1760.434642] usb usb4: usb wakeup-resume
[ 1760.434646] usb usb4: usb auto-resume
[ 1760.434661] hub 4-0:1.0: hub_resume
[ 1760.434683] xhci_hcd 0000:0b:00.0: get port status, actual port 0 status = 0x2a0
[ 1760.434684] xhci_hcd 0000:0b:00.0: Get port status returned 0x2a0
[ 1760.434710] xhci_hcd 0000:0b:00.0: get port status, actual port 1 status = 0x2a0
[ 1760.434711] xhci_hcd 0000:0b:00.0: Get port status returned 0x2a0
[ 1760.434727] hub 4-0:1.0: state 7 ports 2 chg 0000 evt 0000
[ 1760.434757] xhci_hcd 0000:0b:00.0: set port remote wake mask, actual port 0 status = 0xe0002a0
[ 1760.434784] xhci_hcd 0000:0b:00.0: set port remote wake mask, actual port 1 status = 0xe0002a0
[ 1760.434791] hub 4-0:1.0: hub_suspend
[ 1760.434796] usb usb4: bus auto-suspend, wakeup 1
[ 1760.434807] xhci_hcd 0000:0b:00.0: xhci_hub_status_data: stopping port polling.
[ 1760.553734] xhci_hcd 0000:0b:00.0: xhci_hub_status_data: stopping port polling.
[ 1760.553751] hub 3-0:1.0: state 7 ports 2 chg 0000 evt 0000
[ 1760.574793] xhci_hcd 0000:0b:00.0: get port status, actual port 0 status = 0x2a0
[ 1760.574794] xhci_hcd 0000:0b:00.0: Get port status returned 0x100
[ 1760.575300] xhci_hcd 0000:0b:00.0: get port status, actual port 1 status = 0x2a0
[ 1760.575301] xhci_hcd 0000:0b:00.0: Get port status returned 0x100
[ 1760.576768] hub 3-0:1.0: hub_suspend
[ 1760.576774] usb usb3: bus auto-suspend, wakeup 1
[ 1760.576789] xhci_hcd 0000:0b:00.0: xhci_hub_status_data: stopping port polling.
[ 1760.576802] xhci_hcd 0000:0b:00.0: xhci_suspend: stopping port polling.
[ 1760.576817] xhci_hcd 0000:0b:00.0: // Setting command ring address to 0xd6007001
[ 1760.576851] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_suspend: 0
[ 1760.576938] xhci_hcd 0000:0b:00.0: PME# enabled
[ 1760.613874] xhci_hcd 0000:0b:00.0: PME# disabled
[ 1760.613884] xhci_hcd 0000:0b:00.0: enabling bus mastering
[ 1760.613895] xhci_hcd 0000:0b:00.0: // Setting command ring address to 0xd6007001
[ 1760.613914] xhci_hcd 0000:0b:00.0: xhci_resume: starting port polling.
[ 1760.613922] xhci_hcd 0000:0b:00.0: xhci_hub_status_data: stopping port polling.
[ 1760.613924] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_resume: 0
[ 1760.613929] usb usb4: usb auto-resume
[ 1760.613945] hub 4-0:1.0: hub_resume
[ 1760.613981] xhci_hcd 0000:0b:00.0: get port status, actual port 0 status = 0x2a0
[ 1760.613982] xhci_hcd 0000:0b:00.0: Get port status returned 0x2a0
[ 1760.614010] xhci_hcd 0000:0b:00.0: get port status, actual port 1 status = 0x2a0
[ 1760.614012] xhci_hcd 0000:0b:00.0: Get port status returned 0x2a0
[ 1760.614038] usb usb3: usb wakeup-resume
[ 1760.614040] usb usb3: usb auto-resume
[ 1760.614059] hub 3-0:1.0: hub_resume
[ 1760.614080] xhci_hcd 0000:0b:00.0: get port status, actual port 0 status = 0x2a0
[ 1760.614081] xhci_hcd 0000:0b:00.0: Get port status returned 0x100
[ 1760.614104] xhci_hcd 0000:0b:00.0: get port status, actual port 1 status = 0x2a0
[ 1760.614105] xhci_hcd 0000:0b:00.0: Get port status returned 0x100
[ 1760.614122] hub 4-0:1.0: state 7 ports 2 chg 0000 evt 0000
[ 1760.614126] hub 3-0:1.0: state 7 ports 2 chg 0000 evt 0000
[ 1760.614134] hub 3-0:1.0: hub_suspend
[ 1760.614139] usb usb3: bus auto-suspend, wakeup 1
[ 1760.614152] xhci_hcd 0000:0b:00.0: xhci_hub_status_data: stopping port polling.
[ 1760.623621] xhci_hcd 0000:0b:00.0: xhci_hub_status_data: stopping port polling.
[ 1760.646744] xhci_hcd 0000:0b:00.0: get port status, actual port 0 status = 0x2a0
[ 1760.646746] xhci_hcd 0000:0b:00.0: Get port status returned 0x2a0
[ 1760.647281] xhci_hcd 0000:0b:00.0: get port status, actual port 1 status = 0x2a0
[ 1760.647283] xhci_hcd 0000:0b:00.0: Get port status returned 0x2a0
[ 1760.657965] xhci_hcd 0000:0b:00.0: set port remote wake mask, actual port 0 status = 0xe0002a0
[ 1760.657992] xhci_hcd 0000:0b:00.0: set port remote wake mask, actual port 1 status = 0xe0002a0
[ 1760.658000] hub 4-0:1.0: hub_suspend
[ 1760.658004] usb usb4: bus auto-suspend, wakeup 1
[ 1760.658015] xhci_hcd 0000:0b:00.0: xhci_hub_status_data: stopping port polling.
[ 1760.658027] xhci_hcd 0000:0b:00.0: xhci_suspend: stopping port polling.
[ 1760.658042] xhci_hcd 0000:0b:00.0: // Setting command ring address to 0xd6007001
[ 1760.658074] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_suspend: 0
[ 1760.658159] xhci_hcd 0000:0b:00.0: PME# enabled
[ 1760.683743] pcieport 0000:00:1c.4: PME# enabled



Hope this helps,
Martin




Rafael J. Wysocki wrote:
> From: Rafael J. Wysocki <[email protected]>
> Subject: PCI / ACPI: Always resume devices on ACPI wakeup notifications
>
> It turns out that the _Lxx control methods provided by some BIOSes
> clear the PME Status bit of PCI devices they handle, which means that
> pci_acpi_wake_dev() cannot really use that bit to check whether or
> not the device has signalled wakeup.
>
> One symptom of the problem is, for example, that when an affected PCI
> USB controller is runtime-suspended, then plugging in a new USB device
> into one of the controller's ports will not wake up the controller,
> which should happen.
>
> For this reason, make pci_acpi_wake_dev() always attempt to resume
> the device it is called for regardless of the device's PME Status bit
> value (that bit still has to be cleared if set at this point,
> though).
>
> Reported-by: Sarah Sharp <[email protected]>
> Signed-off-by: Rafael J. Wysocki <[email protected]>
> Acked-by: Matthew Garrett <[email protected]>
> Cc: 3.7+ <[email protected]>
> ---
>
> The changelog in this version is slightly better than in the previous one, IMHO.
>
> Thanks,
> Rafael
>
> ---
> drivers/pci/pci-acpi.c | 15 ++++++++-------
> 1 file changed, 8 insertions(+), 7 deletions(-)
>
> Index: linux-pm/drivers/pci/pci-acpi.c
> ===================================================================
> --- linux-pm.orig/drivers/pci/pci-acpi.c
> +++ linux-pm/drivers/pci/pci-acpi.c
> @@ -53,14 +53,15 @@ static void pci_acpi_wake_dev(acpi_handl
> return;
> }
>
> - if (!pci_dev->pm_cap || !pci_dev->pme_support
> - || pci_check_pme_status(pci_dev)) {
> - if (pci_dev->pme_poll)
> - pci_dev->pme_poll = false;
> + /* Clear PME Status if set. */
> + if (pci_dev->pme_support)
> + pci_check_pme_status(pci_dev);
>
> - pci_wakeup_event(pci_dev);
> - pm_runtime_resume(&pci_dev->dev);
> - }
> + if (pci_dev->pme_poll)
> + pci_dev->pme_poll = false;
> +
> + pci_wakeup_event(pci_dev);
> + pm_runtime_resume(&pci_dev->dev);
>
> if (pci_dev->subordinate)
> pci_pme_wakeup_bus(pci_dev->subordinate);
>
> --
> To unsubscribe from this list: send the line "unsubscribe linux-acpi" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
>
>

2013-03-29 16:05:59

by Sarah Sharp

[permalink] [raw]
Subject: Re: [Update][PATCH] PCI / ACPI: Always resume devices on ACPI wakeup notifications

On Fri, Mar 29, 2013 at 04:05:54PM +0100, Martin Mokrejs wrote:
> [ 36.594171] xhci_hcd 0000:0b:00.0: xhci_suspend: stopping port polling.
> [ 36.594202] xhci_hcd 0000:0b:00.0: // Setting command ring address to 0xd6007001
> [ 36.594247] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_suspend: 0
> [ 36.594349] xhci_hcd 0000:0b:00.0: PME# enabled
> [ 36.703695] r8169 0000:05:00.0 eth0: link down
> [ 37.098299] microcode: CPU0 updated to revision 0x28, date = 2012-04-24
> [ 37.098941] microcode: CPU1 updated to revision 0x28, date = 2012-04-24
> [ 37.098944] perf_event_intel: PEBS enabled due to microcode update
> [ 38.343029] r8169 0000:05:00.0 eth0: link up
> [ 39.094944] r8169 0000:05:00.0 eth0: link down
> [ 41.492768] r8169 0000:05:00.0 eth0: link up
> [ 62.782910] xhci_hcd 0000:0b:00.0: Poll event ring: 4294943584
> [ 62.782938] xhci_hcd 0000:0b:00.0: op reg status = 0xffffffff
> [ 62.782939] xhci_hcd 0000:0b:00.0: HW died, polling stopped.
> [ 88.754183] pcieport 0000:00:1c.0: PME# enabled
> [ 88.764182] xhci_hcd 0000:0b:00.0: PME# disabled
> [ 88.764192] xhci_hcd 0000:0b:00.0: enabling bus mastering
> [ 88.764206] xhci_hcd 0000:0b:00.0: // Setting command ring address to 0xd6007001
> [ 88.764242] xhci_hcd 0000:0b:00.0: Port Status Change Event for port 2
> [ 88.764246] xhci_hcd 0000:0b:00.0: resume root hub
> [ 88.764259] xhci_hcd 0000:0b:00.0: handle_port_status: starting port polling.
> [ 88.764276] xhci_hcd 0000:0b:00.0: xhci_resume: starting port polling.
> [ 88.764281] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_resume: 0
>
>
> What "HW died? Why 1c.0 is here? What is this device actually doing?

It's harmless. The xHCI polling loop to debug the host registers and
rings simply notices that the registers are reading as all ffs. I
believe that's normal when a PCI device is in D3. I just haven't had
time to make a patch to disable the polling loop when the host is suspended.

So, for now, ignore the "HW died, polling stopped." messages.

> Nevertheless, I went to check if if the USB3 socket dies after first unplug of device
> or not anymore thanks to the patch being tested:
>
> I plugged into the USB3.0 socket a mouse, it worked. Around its unplug I got:
>
> [ 94.954779] hub 3-0:1.0: debounce: port 2: total 100ms stable 100ms status 0x100
> [ 94.954795] hub 3-0:1.0: hub_suspend
> [ 94.954802] usb usb3: bus auto-suspend, wakeup 1
> [ 94.954817] xhci_hcd 0000:0b:00.0: xhci_hub_status_data: stopping port polling.
> [ 94.954835] xhci_hcd 0000:0b:00.0: xhci_suspend: stopping port polling.
> [ 94.954857] xhci_hcd 0000:0b:00.0: // Setting command ring address to 0xd6007001
> [ 94.954898] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_suspend: 0
> [ 94.954983] xhci_hcd 0000:0b:00.0: PME# enabled
> [ 169.622513] hub 2-1:1.0: state 7 ports 8 chg 0000 evt 0004
> [ 169.623057] hub 2-1:1.0: port 2, status 0101, change 0001, 12 Mb/s
> [ 169.777012] hub 2-1:1.0: debounce: port 2: total 100ms stable 100ms status 0x101
> [ 169.856992] usb 2-1.2: new low-speed USB device number 4 using ehci-pci
>
> and the port was dead, no matter what "lsusb -v or -vv" options I tried. At about
> [ 169.622513] I plugged the mouse into a USB2.0 socket (do not know if that is 1a.0 or 1d.0).

All right, I wonder if the USB core/xHCI driver is forgetting to clear a
port status change bit after the device is unplugged. That can cause
the xHCI host to not give us a port status change event later (and thus
no PME). Looking at the logs later, it doesn't seem like we do this
though.

> If I run lsusb -vv it does (with the problematic patch):
>
> [ 1760.414086] pcieport 0000:00:1c.4: PME# disabled
> [ 1760.434314] xhci_hcd 0000:0b:00.0: PME# disabled
> [ 1760.434327] xhci_hcd 0000:0b:00.0: enabling bus mastering
> [ 1760.434338] xhci_hcd 0000:0b:00.0: // Setting command ring address to 0xd6007001
> [ 1760.434360] xhci_hcd 0000:0b:00.0: Port Status Change Event for port 2

Ok, so the xHCI driver *is* getting a port status change event, and thus
must have gotten a PME. So the PCI layer is doing its job.

> [ 1760.434363] xhci_hcd 0000:0b:00.0: resume root hub
> [ 1760.434367] xhci_hcd 0000:0b:00.0: handle_port_status: starting port polling.
> [ 1760.434378] xhci_hcd 0000:0b:00.0: xhci_resume: starting port polling.
> [ 1760.434383] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_resume: 0
> [ 1760.434388] usb usb3: usb auto-resume
> [ 1760.434407] hub 3-0:1.0: hub_resume
> [ 1760.434439] xhci_hcd 0000:0b:00.0: get port status, actual port 0 status = 0x2a0
> [ 1760.434440] xhci_hcd 0000:0b:00.0: Get port status returned 0x100
> [ 1760.434464] xhci_hcd 0000:0b:00.0: get port status, actual port 1 status = 0x202a0
> [ 1760.434465] xhci_hcd 0000:0b:00.0: Get port status returned 0x10100
> [ 1760.434492] xhci_hcd 0000:0b:00.0: clear port connect change, actual port 1 status = 0x2a0

Odd. The port status shows there's no device connected, but there was a
connect change:

sarah@xanatos:~$ ./decode-port-status 0x202a0
port status = 0x0202a0
bit 0 (CCS) 0x0, device not connected
bit 1 (PED) 0x0, port disabled
bit 3 (OCA) 0x0, no over-current condition
bit 4 (PR) 0x0, port not in reset
bits 8:5 (PLS) 0x5, link is in the RxDetect state
bit 9 (PP) 0x1, port power on
bits 13:10 (speed) 0x0, Undefined
bits 15:14 (indicators) 0x0, port indicators are off
bit 17 (CSC) 0x1, connect change
bit 18 (PEC) 0x0, no port enable/disable change
bit 19 (WRC) 0x0, no warm port reset change
bit 20 (OCC) 0x0, no over-current change
bit 21 (PRC) 0x0, no port reset change
bit 22 (PLC) 0x0, no port link change
bit 23 (CEC) 0x0, no port config error change
bit 25 (WCE) 0x0, wake on connect disabled
bit 26 (WDE) 0x0, wake on disconnect disabled
bit 27 (WOE) 0x0, wake on over-current enable disabled
bit 30 (DR) 0x0, device is permanently attached

RxDetect is the "I'm looking for a USB device" port state.

> [ 1760.434642] usb usb4: usb wakeup-resume
> [ 1760.434646] usb usb4: usb auto-resume
> [ 1760.434661] hub 4-0:1.0: hub_resume
> [ 1760.434683] xhci_hcd 0000:0b:00.0: get port status, actual port 0 status = 0x2a0
> [ 1760.434684] xhci_hcd 0000:0b:00.0: Get port status returned 0x2a0
> [ 1760.434710] xhci_hcd 0000:0b:00.0: get port status, actual port 1 status = 0x2a0
> [ 1760.434711] xhci_hcd 0000:0b:00.0: Get port status returned 0x2a0
> [ 1760.434727] hub 4-0:1.0: state 7 ports 2 chg 0000 evt 0000
> [ 1760.434757] xhci_hcd 0000:0b:00.0: set port remote wake mask, actual port 0 status = 0xe0002a0
> [ 1760.434784] xhci_hcd 0000:0b:00.0: set port remote wake mask, actual port 1 status = 0xe0002a0
> [ 1760.434791] hub 4-0:1.0: hub_suspend
> [ 1760.434796] usb usb4: bus auto-suspend, wakeup 1
> [ 1760.434807] xhci_hcd 0000:0b:00.0: xhci_hub_status_data: stopping port polling.
> [ 1760.553734] xhci_hcd 0000:0b:00.0: xhci_hub_status_data: stopping port polling.
> [ 1760.553751] hub 3-0:1.0: state 7 ports 2 chg 0000 evt 0000
> [ 1760.574793] xhci_hcd 0000:0b:00.0: get port status, actual port 0 status = 0x2a0
> [ 1760.574794] xhci_hcd 0000:0b:00.0: Get port status returned 0x100
> [ 1760.575300] xhci_hcd 0000:0b:00.0: get port status, actual port 1 status = 0x2a0
> [ 1760.575301] xhci_hcd 0000:0b:00.0: Get port status returned 0x100

sarah@xanatos:~$ ./decode-port-status 0x2a0
port status = 0x0002a0
bit 0 (CCS) 0x0, device not connected
bit 1 (PED) 0x0, port disabled
bit 3 (OCA) 0x0, no over-current condition
bit 4 (PR) 0x0, port not in reset
bits 8:5 (PLS) 0x5, link is in the RxDetect state
bit 9 (PP) 0x1, port power on
bits 13:10 (speed) 0x0, Undefined
bits 15:14 (indicators) 0x0, port indicators are off
bit 17 (CSC) 0x0, no connect change
bit 18 (PEC) 0x0, no port enable/disable change
bit 19 (WRC) 0x0, no warm port reset change
bit 20 (OCC) 0x0, no over-current change
bit 21 (PRC) 0x0, no port reset change
bit 22 (PLC) 0x0, no port link change
bit 23 (CEC) 0x0, no port config error change
bit 25 (WCE) 0x0, wake on connect disabled
bit 26 (WDE) 0x0, wake on disconnect disabled
bit 27 (WOE) 0x0, wake on over-current enable disabled
bit 30 (DR) 0x0, device is permanently attached

Nope, your host really isn't reporting there's a device connected
*at all*. That's just broken hardware, and there's really nothing
software can do if the hardware isn't reporting connect events, even
with polling.

It also doesn't sound like the other TI redriver bug. That bug only
effected USB 3.0 ports, and when lsusb was run, we would find the port
in Compliance Mode. This is the host simply not reporting the USB 2.0
port connect at all.

Maybe if we completely disable PCI runtime PM for your host, we can work
around this bug?

Can you send me the output of `sudo lspci -vvv -n` again?

Sarah Sharp

> [ 1760.576768] hub 3-0:1.0: hub_suspend
> [ 1760.576774] usb usb3: bus auto-suspend, wakeup 1
> [ 1760.576789] xhci_hcd 0000:0b:00.0: xhci_hub_status_data: stopping port polling.
> [ 1760.576802] xhci_hcd 0000:0b:00.0: xhci_suspend: stopping port polling.
> [ 1760.576817] xhci_hcd 0000:0b:00.0: // Setting command ring address to 0xd6007001
> [ 1760.576851] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_suspend: 0
> [ 1760.576938] xhci_hcd 0000:0b:00.0: PME# enabled
> [ 1760.613874] xhci_hcd 0000:0b:00.0: PME# disabled
> [ 1760.613884] xhci_hcd 0000:0b:00.0: enabling bus mastering
> [ 1760.613895] xhci_hcd 0000:0b:00.0: // Setting command ring address to 0xd6007001
> [ 1760.613914] xhci_hcd 0000:0b:00.0: xhci_resume: starting port polling.
> [ 1760.613922] xhci_hcd 0000:0b:00.0: xhci_hub_status_data: stopping port polling.
> [ 1760.613924] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_resume: 0
> [ 1760.613929] usb usb4: usb auto-resume
> [ 1760.613945] hub 4-0:1.0: hub_resume
> [ 1760.613981] xhci_hcd 0000:0b:00.0: get port status, actual port 0 status = 0x2a0
> [ 1760.613982] xhci_hcd 0000:0b:00.0: Get port status returned 0x2a0
> [ 1760.614010] xhci_hcd 0000:0b:00.0: get port status, actual port 1 status = 0x2a0
> [ 1760.614012] xhci_hcd 0000:0b:00.0: Get port status returned 0x2a0
> [ 1760.614038] usb usb3: usb wakeup-resume
> [ 1760.614040] usb usb3: usb auto-resume
> [ 1760.614059] hub 3-0:1.0: hub_resume
> [ 1760.614080] xhci_hcd 0000:0b:00.0: get port status, actual port 0 status = 0x2a0
> [ 1760.614081] xhci_hcd 0000:0b:00.0: Get port status returned 0x100
> [ 1760.614104] xhci_hcd 0000:0b:00.0: get port status, actual port 1 status = 0x2a0
> [ 1760.614105] xhci_hcd 0000:0b:00.0: Get port status returned 0x100
> [ 1760.614122] hub 4-0:1.0: state 7 ports 2 chg 0000 evt 0000
> [ 1760.614126] hub 3-0:1.0: state 7 ports 2 chg 0000 evt 0000
> [ 1760.614134] hub 3-0:1.0: hub_suspend
> [ 1760.614139] usb usb3: bus auto-suspend, wakeup 1
> [ 1760.614152] xhci_hcd 0000:0b:00.0: xhci_hub_status_data: stopping port polling.
> [ 1760.623621] xhci_hcd 0000:0b:00.0: xhci_hub_status_data: stopping port polling.
> [ 1760.646744] xhci_hcd 0000:0b:00.0: get port status, actual port 0 status = 0x2a0
> [ 1760.646746] xhci_hcd 0000:0b:00.0: Get port status returned 0x2a0
> [ 1760.647281] xhci_hcd 0000:0b:00.0: get port status, actual port 1 status = 0x2a0
> [ 1760.647283] xhci_hcd 0000:0b:00.0: Get port status returned 0x2a0
> [ 1760.657965] xhci_hcd 0000:0b:00.0: set port remote wake mask, actual port 0 status = 0xe0002a0
> [ 1760.657992] xhci_hcd 0000:0b:00.0: set port remote wake mask, actual port 1 status = 0xe0002a0
> [ 1760.658000] hub 4-0:1.0: hub_suspend
> [ 1760.658004] usb usb4: bus auto-suspend, wakeup 1
> [ 1760.658015] xhci_hcd 0000:0b:00.0: xhci_hub_status_data: stopping port polling.
> [ 1760.658027] xhci_hcd 0000:0b:00.0: xhci_suspend: stopping port polling.
> [ 1760.658042] xhci_hcd 0000:0b:00.0: // Setting command ring address to 0xd6007001
> [ 1760.658074] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_suspend: 0
> [ 1760.658159] xhci_hcd 0000:0b:00.0: PME# enabled
> [ 1760.683743] pcieport 0000:00:1c.4: PME# enabled

2013-03-29 17:43:29

by Martin Mokrejs

[permalink] [raw]
Subject: Re: [Update][PATCH] PCI / ACPI: Always resume devices on ACPI wakeup notifications

Sarah,
please let me know if you feel the test was screwed by laptop-mode-tools
kicking in, although I believed they were not running while I was on AC power.
I was testing under these conditions:

vostro ~ # grep . /sys/bus/pci/devices/*/power/control
/sys/bus/pci/devices/0000:00:00.0/power/control:auto
/sys/bus/pci/devices/0000:00:02.0/power/control:auto
/sys/bus/pci/devices/0000:00:16.0/power/control:auto
/sys/bus/pci/devices/0000:00:1a.0/power/control:auto
/sys/bus/pci/devices/0000:00:1b.0/power/control:auto
/sys/bus/pci/devices/0000:00:1c.0/power/control:auto
/sys/bus/pci/devices/0000:00:1c.1/power/control:auto
/sys/bus/pci/devices/0000:00:1c.3/power/control:auto
/sys/bus/pci/devices/0000:00:1c.4/power/control:auto
/sys/bus/pci/devices/0000:00:1c.7/power/control:auto
/sys/bus/pci/devices/0000:00:1d.0/power/control:auto
/sys/bus/pci/devices/0000:00:1f.0/power/control:auto
/sys/bus/pci/devices/0000:00:1f.2/power/control:auto
/sys/bus/pci/devices/0000:00:1f.3/power/control:auto
/sys/bus/pci/devices/0000:05:00.0/power/control:auto
/sys/bus/pci/devices/0000:09:00.0/power/control:auto
/sys/bus/pci/devices/0000:0b:00.0/power/control:auto
/sys/bus/pci/devices/0000:11:00.0/power/control:auto
vostro ~ # grep . /sys/bus/pci/devices/*/power/runtime_status
/sys/bus/pci/devices/0000:00:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:02.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:16.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1a.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1b.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1c.1/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.3/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.4/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.7/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1d.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.3/power/runtime_status:suspended
/sys/bus/pci/devices/0000:05:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:09:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:0b:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:11:00.0/power/runtime_status:active
vostro ~ #

My apologies if that twisted the test and thanks for you detailed explanations.

I will spot below, however, a few questions.

Sarah Sharp wrote:
> On Fri, Mar 29, 2013 at 04:05:54PM +0100, Martin Mokrejs wrote:

>
>> Nevertheless, I went to check if if the USB3 socket dies after first unplug of device
>> or not anymore thanks to the patch being tested:
>>
>> I plugged into the USB3.0 socket a mouse, it worked. Around its unplug I got:
>>
>> [ 94.954779] hub 3-0:1.0: debounce: port 2: total 100ms stable 100ms status 0x100
>> [ 94.954795] hub 3-0:1.0: hub_suspend
>> [ 94.954802] usb usb3: bus auto-suspend, wakeup 1
>> [ 94.954817] xhci_hcd 0000:0b:00.0: xhci_hub_status_data: stopping port polling.
>> [ 94.954835] xhci_hcd 0000:0b:00.0: xhci_suspend: stopping port polling.
>> [ 94.954857] xhci_hcd 0000:0b:00.0: // Setting command ring address to 0xd6007001
>> [ 94.954898] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_suspend: 0
>> [ 94.954983] xhci_hcd 0000:0b:00.0: PME# enabled
>> [ 169.622513] hub 2-1:1.0: state 7 ports 8 chg 0000 evt 0004
>> [ 169.623057] hub 2-1:1.0: port 2, status 0101, change 0001, 12 Mb/s
>> [ 169.777012] hub 2-1:1.0: debounce: port 2: total 100ms stable 100ms status 0x101
>> [ 169.856992] usb 2-1.2: new low-speed USB device number 4 using ehci-pci
>>
>> and the port was dead, no matter what "lsusb -v or -vv" options I tried. At about
>> [ 169.622513] I plugged the mouse into a USB2.0 socket (do not know if that is 1a.0 or 1d.0).
>
> All right, I wonder if the USB core/xHCI driver is forgetting to clear a
> port status change bit after the device is unplugged. That can cause
> the xHCI host to not give us a port status change event later (and thus
> no PME). Looking at the logs later, it doesn't seem like we do this
> though.
>
>> If I run lsusb -vv it does (with the problematic patch):
>>
>> [ 1760.414086] pcieport 0000:00:1c.4: PME# disabled
>> [ 1760.434314] xhci_hcd 0000:0b:00.0: PME# disabled
>> [ 1760.434327] xhci_hcd 0000:0b:00.0: enabling bus mastering
>> [ 1760.434338] xhci_hcd 0000:0b:00.0: // Setting command ring address to 0xd6007001
>> [ 1760.434360] xhci_hcd 0000:0b:00.0: Port Status Change Event for port 2
>
> Ok, so the xHCI driver *is* getting a port status change event, and thus
> must have gotten a PME. So the PCI layer is doing its job.
>
>> [ 1760.434363] xhci_hcd 0000:0b:00.0: resume root hub
>> [ 1760.434367] xhci_hcd 0000:0b:00.0: handle_port_status: starting port polling.
>> [ 1760.434378] xhci_hcd 0000:0b:00.0: xhci_resume: starting port polling.
>> [ 1760.434383] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_resume: 0
>> [ 1760.434388] usb usb3: usb auto-resume
>> [ 1760.434407] hub 3-0:1.0: hub_resume
>> [ 1760.434439] xhci_hcd 0000:0b:00.0: get port status, actual port 0 status = 0x2a0
>> [ 1760.434440] xhci_hcd 0000:0b:00.0: Get port status returned 0x100
>> [ 1760.434464] xhci_hcd 0000:0b:00.0: get port status, actual port 1 status = 0x202a0
>> [ 1760.434465] xhci_hcd 0000:0b:00.0: Get port status returned 0x10100
>> [ 1760.434492] xhci_hcd 0000:0b:00.0: clear port connect change, actual port 1 status = 0x2a0
>
> Odd. The port status shows there's no device connected, but there was a
> connect change:
>
> sarah@xanatos:~$ ./decode-port-status 0x202a0
> port status = 0x0202a0
> bit 0 (CCS) 0x0, device not connected
> bit 1 (PED) 0x0, port disabled
> bit 3 (OCA) 0x0, no over-current condition
> bit 4 (PR) 0x0, port not in reset
> bits 8:5 (PLS) 0x5, link is in the RxDetect state
> bit 9 (PP) 0x1, port power on
> bits 13:10 (speed) 0x0, Undefined
> bits 15:14 (indicators) 0x0, port indicators are off
> bit 17 (CSC) 0x1, connect change
> bit 18 (PEC) 0x0, no port enable/disable change
> bit 19 (WRC) 0x0, no warm port reset change
> bit 20 (OCC) 0x0, no over-current change
> bit 21 (PRC) 0x0, no port reset change
> bit 22 (PLC) 0x0, no port link change
> bit 23 (CEC) 0x0, no port config error change
> bit 25 (WCE) 0x0, wake on connect disabled
> bit 26 (WDE) 0x0, wake on disconnect disabled
> bit 27 (WOE) 0x0, wake on over-current enable disabled
> bit 30 (DR) 0x0, device is permanently attached
>
> RxDetect is the "I'm looking for a USB device" port state.
>
>> [ 1760.434642] usb usb4: usb wakeup-resume
>> [ 1760.434646] usb usb4: usb auto-resume
>> [ 1760.434661] hub 4-0:1.0: hub_resume
>> [ 1760.434683] xhci_hcd 0000:0b:00.0: get port status, actual port 0 status = 0x2a0
>> [ 1760.434684] xhci_hcd 0000:0b:00.0: Get port status returned 0x2a0
>> [ 1760.434710] xhci_hcd 0000:0b:00.0: get port status, actual port 1 status = 0x2a0
>> [ 1760.434711] xhci_hcd 0000:0b:00.0: Get port status returned 0x2a0
>> [ 1760.434727] hub 4-0:1.0: state 7 ports 2 chg 0000 evt 0000
>> [ 1760.434757] xhci_hcd 0000:0b:00.0: set port remote wake mask, actual port 0 status = 0xe0002a0
>> [ 1760.434784] xhci_hcd 0000:0b:00.0: set port remote wake mask, actual port 1 status = 0xe0002a0
>> [ 1760.434791] hub 4-0:1.0: hub_suspend
>> [ 1760.434796] usb usb4: bus auto-suspend, wakeup 1
>> [ 1760.434807] xhci_hcd 0000:0b:00.0: xhci_hub_status_data: stopping port polling.
>> [ 1760.553734] xhci_hcd 0000:0b:00.0: xhci_hub_status_data: stopping port polling.
>> [ 1760.553751] hub 3-0:1.0: state 7 ports 2 chg 0000 evt 0000
>> [ 1760.574793] xhci_hcd 0000:0b:00.0: get port status, actual port 0 status = 0x2a0
>> [ 1760.574794] xhci_hcd 0000:0b:00.0: Get port status returned 0x100
>> [ 1760.575300] xhci_hcd 0000:0b:00.0: get port status, actual port 1 status = 0x2a0
>> [ 1760.575301] xhci_hcd 0000:0b:00.0: Get port status returned 0x100
>
> sarah@xanatos:~$ ./decode-port-status 0x2a0
> port status = 0x0002a0
> bit 0 (CCS) 0x0, device not connected
> bit 1 (PED) 0x0, port disabled
> bit 3 (OCA) 0x0, no over-current condition
> bit 4 (PR) 0x0, port not in reset
> bits 8:5 (PLS) 0x5, link is in the RxDetect state
> bit 9 (PP) 0x1, port power on
> bits 13:10 (speed) 0x0, Undefined
> bits 15:14 (indicators) 0x0, port indicators are off
> bit 17 (CSC) 0x0, no connect change
> bit 18 (PEC) 0x0, no port enable/disable change
> bit 19 (WRC) 0x0, no warm port reset change
> bit 20 (OCC) 0x0, no over-current change
> bit 21 (PRC) 0x0, no port reset change
> bit 22 (PLC) 0x0, no port link change
> bit 23 (CEC) 0x0, no port config error change
> bit 25 (WCE) 0x0, wake on connect disabled
> bit 26 (WDE) 0x0, wake on disconnect disabled
> bit 27 (WOE) 0x0, wake on over-current enable disabled
> bit 30 (DR) 0x0, device is permanently attached
>
> Nope, your host really isn't reporting there's a device connected
> *at all*. That's just broken hardware, and there's really nothing
> software can do if the hardware isn't reporting connect events, even
> with polling.
>
> It also doesn't sound like the other TI redriver bug. That bug only
> effected USB 3.0 ports, and when lsusb was run, we would find the port
> in Compliance Mode. This is the host simply not reporting the USB 2.0
> port connect at all.
>
> Maybe if we completely disable PCI runtime PM for your host, we can work
> around this bug?

I am not sure I understand what you mean. The proposed patch makes the
situation worse. To be able to use the xHCI port for second and later times,
I have to plugin a device and run 'lsusb -vv' to get the device detected
before the "port" falls asleep. This is NOT necessary for the SandyBridge
USB2.0 port under same conditions (well, regarding the disclaimer I made
on the very top of this message, from the other thread where Ying found that
I had laptop-mode-tools installed I realized that laptop-mode-tools
fiddled with xHCI port while NOT with EHCI port. Please correct me if
I was wrong. So, please re-consider your above conclusions. Most importantly,
I don not understand the "This is the host simply not reporting the USB 2.0
port connect at all.". Did you mean "USB 3.0 instead"?

Other than that, I am ready to file a bug report to Dell's Pro Support site
but from my last experience they were quite clue-less regarding the broken
"express card PresDet detection". ;-) I bet they could replace the TexasInstruments
USB3.0 card which is a separate thing in the laptop. At least I could get
the TI hardware which has hopefully fixed the redriver. ;-)
How could I reproduce the issue in Win7 which are on the laptop? I mean,
the change the PM handling to reproduce what I got on linux under laptop-mode-tools?
;)

>
> Can you send me the output of `sudo lspci -vvv -n` again?

Will send after I reboot into a clean state and re-test the behavior while
laptop-mode-tools are gone. Maybe the issue will remain anyways.
So so far I tested effectively as under:

echo auto > /sys/bus/pci/devices/0000:0b:00.0/power/control

and without laptop-mode-tools trickery I should be now testing under

echo on > /sys/bus/pci/devices/0000:0b:00.0/power/control

, right?

Thank you,
Martin

2013-03-29 18:33:13

by Martin Mokrejs

[permalink] [raw]
Subject: Re: [Update][PATCH] PCI / ACPI: Always resume devices on ACPI wakeup notifications

So, I re-tested again with the patch and 3.8.3 but without laptop-mode-tools.
The xHCI port works fine provided /sys/bus/pci/devices/0000:0b:00.0/power/control
is set to on and /sys/bus/pci/devices/0000:00:1c.4/power/control also to on.
If I set parent 1c.4 to auto, it gets suspended and the port seems dead until
a device is in and I wake it using lsusb -vv. There must be a bug in linux so
that it cannot overcome upstream 1c.4 sleeping while willing to access 0b:00.
Or more likely, that upstream root port should be prevented to fall asleep, right?


# lspci -tv
-[0000:00]-+-00.0 Intel Corporation 2nd Generation Core Processor Family DRAM Controller
+-02.0 Intel Corporation 2nd Generation Core Processor Family Integrated Graphics Controller
+-16.0 Intel Corporation 6 Series/C200 Series Chipset Family MEI Controller #1
+-1a.0 Intel Corporation 6 Series/C200 Series Chipset Family USB Enhanced Host Controller #2
+-1b.0 Intel Corporation 6 Series/C200 Series Chipset Family High Definition Audio Controller
+-1c.0-[03-04]--
+-1c.1-[05-06]----00.0 Realtek Semiconductor Co., Ltd. RTL8111/8168 PCI Express Gigabit Ethernet controller
+-1c.3-[09-0a]----00.0 Intel Corporation Centrino Wireless-N 1030 [Rainbow Peak]
+-1c.4-[0b-0c]----00.0 Texas Instruments TUSB73x0 SuperSpeed USB 3.0 xHCI Host Controller
+-1c.7-[11-16]----00.0 Silicon Image, Inc. SiI 3132 Serial ATA Raid II Controller
+-1d.0 Intel Corporation 6 Series/C200 Series Chipset Family USB Enhanced Host Controller #1
+-1f.0 Intel Corporation HM67 Express Chipset Family LPC Controller
+-1f.2 Intel Corporation 6 Series/C200 Series Chipset Family 6 port SATA AHCI Controller
\-1f.3 Intel Corporation 6 Series/C200 Series Chipset Family SMBus Controller
#



I have attached the lspci -vvv -n.

Interestingly, maybe, the TI xHCI controller ended up after my tests
changed. I booted up with all devices with power/control set to on
due to laptop-mode-tools uninstalled. I fiddled with the echo commands
tweaking 1c.4 and 0b:00 but in the end set both back to "on". However,
below is some diff. Don't know what that means. Maybe because I tried
to write '0', 'off', 'none' to the control file? ;-)

00:1c.4 0604: 8086:1c18 (rev b5) (prog-if 00 [Normal decode])
Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
Latency: 0, Cache Line Size: 64 bytes
Bus: primary=00, secondary=0b, subordinate=0c, sec-latency=0
I/O behind bridge: 0000f000-00000fff
Memory behind bridge: f7d00000-f7dfffff
Prefetchable memory behind bridge: 00000000fff00000-00000000000fffff
Secondary status: 66MHz- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort+ <SERR- <PERR-
BridgeCtl: Parity- SERR- NoISA- VGA- MAbort- >Reset- FastB2B-
PriDiscTmr- SecDiscTmr- DiscTmrStat- DiscTmrSERREn-
Capabilities: [40] Express (v2) Root Port (Slot+), MSI 00
DevCap: MaxPayload 128 bytes, PhantFunc 0, Latency L0s <64ns, L1 <1us
ExtTag- RBE+ FLReset-
DevCtl: Report errors: Correctable- Non-Fatal- Fatal- Unsupported-
RlxdOrd- ExtTag- PhantFunc- AuxPwr- NoSnoop-
MaxPayload 128 bytes, MaxReadReq 128 bytes
DevSta: CorrErr- UncorrErr- FatalErr- UnsuppReq- AuxPwr+ TransPend-
LnkCap: Port #5, Speed 5GT/s, Width x1, ASPM L0s L1, Latency L0 <512ns, L1 <16us
ClockPM- Surprise- LLActRep+ BwNot-
LnkCtl: ASPM L1 Enabled; RCB 64 bytes Disabled- Retrain- CommClk+
ExtSynch- ClockPM- AutWidDis- BWInt- AutBWInt-
LnkSta: Speed 5GT/s, Width x1, TrErr- Train- SlotClk+ DLActive+ BWMgmt+ ABWMgmt+
SltCap: AttnBtn- PwrCtrl- MRL- AttnInd- PwrInd- HotPlug- Surprise-
Slot #4, PowerLimit 10.000W; Interlock- NoCompl+
SltCtl: Enable: AttnBtn- PwrFlt- MRL- PresDet- CmdCplt- HPIrq- LinkChg-
Control: AttnInd Unknown, PwrInd Unknown, Power- Interlock-
SltSta: Status: AttnBtn- PowerFlt- MRL- CmdCplt- PresDet+ Interlock-
Changed: MRL- PresDet- LinkState+
RootCtl: ErrCorrectable- ErrNon-Fatal- ErrFatal- PMEIntEna- CRSVisible-
RootCap: CRSVisible-
- RootSta: PME ReqID 0000, PMEStatus- PMEPending-
+ RootSta: PME ReqID 0b00, PMEStatus- PMEPending-
DevCap2: Completion Timeout: Range BC, TimeoutDis+, LTR-, OBFF Not Supported ARIFwd-
DevCtl2: Completion Timeout: 50us to 50ms, TimeoutDis-, LTR-, OBFF Disabled ARIFwd-
LnkCtl2: Target Link Speed: 5GT/s, EnterCompliance- SpeedDis-
Transmit Margin: Normal Operating Range, EnterModifiedCompliance- ComplianceSOS-
Compliance De-emphasis: -6dB
LnkSta2: Current De-emphasis Level: -6dB, EqualizationComplete-, EqualizationPhase1-
EqualizationPhase2-, EqualizationPhase3-, LinkEqualizationRequest-
Capabilities: [80] MSI: Enable- Count=1/1 Maskable- 64bit-
Address: 00000000 Data: 0000
Capabilities: [90] Subsystem: 1028:04b3
Capabilities: [a0] Power Management version 2
Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0+,D1-,D2-,D3hot+,D3cold+)
Status: D0 NoSoftRst- PME-Enable- DSel=0 DScale=0 PME-
Kernel driver in use: pcieport


0b:00.0 0c03: 104c:8241 (rev 02) (prog-if 30 [XHCI])
Subsystem: 1028:04b3
Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+
Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
Latency: 0, Cache Line Size: 64 bytes
Interrupt: pin A routed to IRQ 16
Region 0: Memory at f7d00000 (64-bit, non-prefetchable) [size=64K]
Region 2: Memory at f7d10000 (64-bit, non-prefetchable) [size=8K]
Capabilities: [40] Power Management version 3
Flags: PMEClk- DSI- D1+ D2+ AuxCurrent=100mA PME(D0+,D1+,D2+,D3hot+,D3cold+)
Status: D0 NoSoftRst+ PME-Enable- DSel=0 DScale=0 PME-
Capabilities: [48] MSI: Enable- Count=1/8 Maskable- 64bit+
Address: 0000000000000000 Data: 0000
Capabilities: [70] Express (v2) Endpoint, MSI 00
DevCap: MaxPayload 1024 bytes, PhantFunc 0, Latency L0s unlimited, L1 unlimited
ExtTag- AttnBtn- AttnInd- PwrInd- RBE+ FLReset-
DevCtl: Report errors: Correctable- Non-Fatal- Fatal- Unsupported-
RlxdOrd- ExtTag- PhantFunc- AuxPwr- NoSnoop-
MaxPayload 128 bytes, MaxReadReq 512 bytes
DevSta: CorrErr+ UncorrErr- FatalErr- UnsuppReq+ AuxPwr+ TransPend-
LnkCap: Port #0, Speed 5GT/s, Width x1, ASPM L0s L1, Latency L0 <512ns, L1 <64us
ClockPM+ Surprise- LLActRep- BwNot-
LnkCtl: ASPM L1 Enabled; RCB 64 bytes Disabled- Retrain- CommClk+
ExtSynch- ClockPM+ AutWidDis- BWInt- AutBWInt-
LnkSta: Speed 5GT/s, Width x1, TrErr- Train- SlotClk+ DLActive- BWMgmt- ABWMgmt-
DevCap2: Completion Timeout: Not Supported, TimeoutDis+, LTR-, OBFF Not Supported
DevCtl2: Completion Timeout: 50us to 50ms, TimeoutDis-, LTR-, OBFF Disabled
LnkCtl2: Target Link Speed: 5GT/s, EnterCompliance- SpeedDis-
Transmit Margin: Normal Operating Range, EnterModifiedCompliance- ComplianceSOS-
Compliance De-emphasis: -6dB
LnkSta2: Current De-emphasis Level: -6dB, EqualizationComplete-, EqualizationPhase1-
EqualizationPhase2-, EqualizationPhase3-, LinkEqualizationRequest-
Capabilities: [c0] MSI-X: Enable+ Count=8 Masked-
Vector table: BAR=2 offset=00000000
PBA: BAR=2 offset=00001000
Capabilities: [100 v2] Advanced Error Reporting
UESta: DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
UEMsk: DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
UESvrt: DLP+ SDES+ TLP- FCP+ CmpltTO- CmpltAbrt- UnxCmplt- RxOF+ MalfTLP+ ECRC- UnsupReq- ACSViol-
- CESta: RxErr- BadTLP- BadDLLP- Rollover- Timeout- NonFatalErr+
+ CESta: RxErr- BadTLP- BadDLLP+ Rollover- Timeout- NonFatalErr+
CEMsk: RxErr- BadTLP- BadDLLP- Rollover- Timeout- NonFatalErr+
AERCap: First Error Pointer: 00, GenCap+ CGenEn- ChkCap+ ChkEn-
Capabilities: [150 v1] Device Serial Number 08-00-28-00-00-20-00-00
Kernel driver in use: xhci_hcd




Attachments:
lspci_vvvn_initial.txt (31.07 kB)

2013-03-29 21:27:24

by Rafael J. Wysocki

[permalink] [raw]
Subject: Re: [Update][PATCH] PCI / ACPI: Always resume devices on ACPI wakeup notifications

On Friday, March 29, 2013 04:05:54 PM Martin Mokrejs wrote:
> Hi,
> I applied this patches over 3.8.3 hoping it will fix my issue under
> thread: "Re: 3.8.2: xhci port is dead until pcieport PME# goes to disabled"
> but unfortunately, it is even worse! Now, although lsusb -v nor lsusb -vv do
> wakeup the XHCI port but it falls asleep immediately, more quickly than I am
> able to plug a device into the socket. To get a device working in the USB3 socket
> I need to plug it in, run lsusb -vv and then it is recognized.
>
> Without the patch, the 'lsusb -vv' woke up the port (PME# disabled happened
> on both 1c.4 and 0b:00.0) and I had unlimited time to find some USB device
> around and to plug it into the slot.

Well, using lsusb to work around problems in the PCI subsystem isn't even
*supposed* to work as far as I can tell.

First off, do you use laptop-mode (or something equivalent) to enable runtime
PM for all PCI devices in your system? If you do, please test things without
it and see if they work then.

Second, do things work after you echo "on" to the xHCI controller's
/sys/devices/.../power/control file?

Rafael


--
I speak only for myself.
Rafael J. Wysocki, Intel Open Source Technology Center.

2013-03-29 21:29:44

by Rafael J. Wysocki

[permalink] [raw]
Subject: Re: [Update][PATCH] PCI / ACPI: Always resume devices on ACPI wakeup notifications

On Friday, March 29, 2013 09:05:35 AM Sarah Sharp wrote:
> On Fri, Mar 29, 2013 at 04:05:54PM +0100, Martin Mokrejs wrote:
> > [ 36.594171] xhci_hcd 0000:0b:00.0: xhci_suspend: stopping port polling.
> > [ 36.594202] xhci_hcd 0000:0b:00.0: // Setting command ring address to 0xd6007001
> > [ 36.594247] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_suspend: 0
> > [ 36.594349] xhci_hcd 0000:0b:00.0: PME# enabled
> > [ 36.703695] r8169 0000:05:00.0 eth0: link down
> > [ 37.098299] microcode: CPU0 updated to revision 0x28, date = 2012-04-24
> > [ 37.098941] microcode: CPU1 updated to revision 0x28, date = 2012-04-24
> > [ 37.098944] perf_event_intel: PEBS enabled due to microcode update
> > [ 38.343029] r8169 0000:05:00.0 eth0: link up
> > [ 39.094944] r8169 0000:05:00.0 eth0: link down
> > [ 41.492768] r8169 0000:05:00.0 eth0: link up
> > [ 62.782910] xhci_hcd 0000:0b:00.0: Poll event ring: 4294943584
> > [ 62.782938] xhci_hcd 0000:0b:00.0: op reg status = 0xffffffff
> > [ 62.782939] xhci_hcd 0000:0b:00.0: HW died, polling stopped.
> > [ 88.754183] pcieport 0000:00:1c.0: PME# enabled
> > [ 88.764182] xhci_hcd 0000:0b:00.0: PME# disabled
> > [ 88.764192] xhci_hcd 0000:0b:00.0: enabling bus mastering
> > [ 88.764206] xhci_hcd 0000:0b:00.0: // Setting command ring address to 0xd6007001
> > [ 88.764242] xhci_hcd 0000:0b:00.0: Port Status Change Event for port 2
> > [ 88.764246] xhci_hcd 0000:0b:00.0: resume root hub
> > [ 88.764259] xhci_hcd 0000:0b:00.0: handle_port_status: starting port polling.
> > [ 88.764276] xhci_hcd 0000:0b:00.0: xhci_resume: starting port polling.
> > [ 88.764281] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_resume: 0
> >
> >
> > What "HW died? Why 1c.0 is here? What is this device actually doing?
>
> It's harmless. The xHCI polling loop to debug the host registers and
> rings simply notices that the registers are reading as all ffs. I
> believe that's normal when a PCI device is in D3. I just haven't had
> time to make a patch to disable the polling loop when the host is suspended.
>
> So, for now, ignore the "HW died, polling stopped." messages.
>
> > Nevertheless, I went to check if if the USB3 socket dies after first unplug of device
> > or not anymore thanks to the patch being tested:
> >
> > I plugged into the USB3.0 socket a mouse, it worked. Around its unplug I got:
> >
> > [ 94.954779] hub 3-0:1.0: debounce: port 2: total 100ms stable 100ms status 0x100
> > [ 94.954795] hub 3-0:1.0: hub_suspend
> > [ 94.954802] usb usb3: bus auto-suspend, wakeup 1
> > [ 94.954817] xhci_hcd 0000:0b:00.0: xhci_hub_status_data: stopping port polling.
> > [ 94.954835] xhci_hcd 0000:0b:00.0: xhci_suspend: stopping port polling.
> > [ 94.954857] xhci_hcd 0000:0b:00.0: // Setting command ring address to 0xd6007001
> > [ 94.954898] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_suspend: 0
> > [ 94.954983] xhci_hcd 0000:0b:00.0: PME# enabled
> > [ 169.622513] hub 2-1:1.0: state 7 ports 8 chg 0000 evt 0004
> > [ 169.623057] hub 2-1:1.0: port 2, status 0101, change 0001, 12 Mb/s
> > [ 169.777012] hub 2-1:1.0: debounce: port 2: total 100ms stable 100ms status 0x101
> > [ 169.856992] usb 2-1.2: new low-speed USB device number 4 using ehci-pci
> >
> > and the port was dead, no matter what "lsusb -v or -vv" options I tried. At about
> > [ 169.622513] I plugged the mouse into a USB2.0 socket (do not know if that is 1a.0 or 1d.0).
>
> All right, I wonder if the USB core/xHCI driver is forgetting to clear a
> port status change bit after the device is unplugged. That can cause
> the xHCI host to not give us a port status change event later (and thus
> no PME). Looking at the logs later, it doesn't seem like we do this
> though.
>
> > If I run lsusb -vv it does (with the problematic patch):
> >
> > [ 1760.414086] pcieport 0000:00:1c.4: PME# disabled
> > [ 1760.434314] xhci_hcd 0000:0b:00.0: PME# disabled
> > [ 1760.434327] xhci_hcd 0000:0b:00.0: enabling bus mastering
> > [ 1760.434338] xhci_hcd 0000:0b:00.0: // Setting command ring address to 0xd6007001
> > [ 1760.434360] xhci_hcd 0000:0b:00.0: Port Status Change Event for port 2
>
> Ok, so the xHCI driver *is* getting a port status change event, and thus
> must have gotten a PME. So the PCI layer is doing its job.
>
> > [ 1760.434363] xhci_hcd 0000:0b:00.0: resume root hub
> > [ 1760.434367] xhci_hcd 0000:0b:00.0: handle_port_status: starting port polling.
> > [ 1760.434378] xhci_hcd 0000:0b:00.0: xhci_resume: starting port polling.
> > [ 1760.434383] xhci_hcd 0000:0b:00.0: hcd_pci_runtime_resume: 0
> > [ 1760.434388] usb usb3: usb auto-resume
> > [ 1760.434407] hub 3-0:1.0: hub_resume
> > [ 1760.434439] xhci_hcd 0000:0b:00.0: get port status, actual port 0 status = 0x2a0
> > [ 1760.434440] xhci_hcd 0000:0b:00.0: Get port status returned 0x100
> > [ 1760.434464] xhci_hcd 0000:0b:00.0: get port status, actual port 1 status = 0x202a0
> > [ 1760.434465] xhci_hcd 0000:0b:00.0: Get port status returned 0x10100
> > [ 1760.434492] xhci_hcd 0000:0b:00.0: clear port connect change, actual port 1 status = 0x2a0
>
> Odd. The port status shows there's no device connected, but there was a
> connect change:
>
> sarah@xanatos:~$ ./decode-port-status 0x202a0
> port status = 0x0202a0
> bit 0 (CCS) 0x0, device not connected
> bit 1 (PED) 0x0, port disabled
> bit 3 (OCA) 0x0, no over-current condition
> bit 4 (PR) 0x0, port not in reset
> bits 8:5 (PLS) 0x5, link is in the RxDetect state
> bit 9 (PP) 0x1, port power on
> bits 13:10 (speed) 0x0, Undefined
> bits 15:14 (indicators) 0x0, port indicators are off
> bit 17 (CSC) 0x1, connect change
> bit 18 (PEC) 0x0, no port enable/disable change
> bit 19 (WRC) 0x0, no warm port reset change
> bit 20 (OCC) 0x0, no over-current change
> bit 21 (PRC) 0x0, no port reset change
> bit 22 (PLC) 0x0, no port link change
> bit 23 (CEC) 0x0, no port config error change
> bit 25 (WCE) 0x0, wake on connect disabled
> bit 26 (WDE) 0x0, wake on disconnect disabled
> bit 27 (WOE) 0x0, wake on over-current enable disabled
> bit 30 (DR) 0x0, device is permanently attached
>
> RxDetect is the "I'm looking for a USB device" port state.
>
> > [ 1760.434642] usb usb4: usb wakeup-resume
> > [ 1760.434646] usb usb4: usb auto-resume
> > [ 1760.434661] hub 4-0:1.0: hub_resume
> > [ 1760.434683] xhci_hcd 0000:0b:00.0: get port status, actual port 0 status = 0x2a0
> > [ 1760.434684] xhci_hcd 0000:0b:00.0: Get port status returned 0x2a0
> > [ 1760.434710] xhci_hcd 0000:0b:00.0: get port status, actual port 1 status = 0x2a0
> > [ 1760.434711] xhci_hcd 0000:0b:00.0: Get port status returned 0x2a0
> > [ 1760.434727] hub 4-0:1.0: state 7 ports 2 chg 0000 evt 0000
> > [ 1760.434757] xhci_hcd 0000:0b:00.0: set port remote wake mask, actual port 0 status = 0xe0002a0
> > [ 1760.434784] xhci_hcd 0000:0b:00.0: set port remote wake mask, actual port 1 status = 0xe0002a0
> > [ 1760.434791] hub 4-0:1.0: hub_suspend
> > [ 1760.434796] usb usb4: bus auto-suspend, wakeup 1
> > [ 1760.434807] xhci_hcd 0000:0b:00.0: xhci_hub_status_data: stopping port polling.
> > [ 1760.553734] xhci_hcd 0000:0b:00.0: xhci_hub_status_data: stopping port polling.
> > [ 1760.553751] hub 3-0:1.0: state 7 ports 2 chg 0000 evt 0000
> > [ 1760.574793] xhci_hcd 0000:0b:00.0: get port status, actual port 0 status = 0x2a0
> > [ 1760.574794] xhci_hcd 0000:0b:00.0: Get port status returned 0x100
> > [ 1760.575300] xhci_hcd 0000:0b:00.0: get port status, actual port 1 status = 0x2a0
> > [ 1760.575301] xhci_hcd 0000:0b:00.0: Get port status returned 0x100
>
> sarah@xanatos:~$ ./decode-port-status 0x2a0
> port status = 0x0002a0
> bit 0 (CCS) 0x0, device not connected
> bit 1 (PED) 0x0, port disabled
> bit 3 (OCA) 0x0, no over-current condition
> bit 4 (PR) 0x0, port not in reset
> bits 8:5 (PLS) 0x5, link is in the RxDetect state
> bit 9 (PP) 0x1, port power on
> bits 13:10 (speed) 0x0, Undefined
> bits 15:14 (indicators) 0x0, port indicators are off
> bit 17 (CSC) 0x0, no connect change
> bit 18 (PEC) 0x0, no port enable/disable change
> bit 19 (WRC) 0x0, no warm port reset change
> bit 20 (OCC) 0x0, no over-current change
> bit 21 (PRC) 0x0, no port reset change
> bit 22 (PLC) 0x0, no port link change
> bit 23 (CEC) 0x0, no port config error change
> bit 25 (WCE) 0x0, wake on connect disabled
> bit 26 (WDE) 0x0, wake on disconnect disabled
> bit 27 (WOE) 0x0, wake on over-current enable disabled
> bit 30 (DR) 0x0, device is permanently attached
>
> Nope, your host really isn't reporting there's a device connected
> *at all*. That's just broken hardware, and there's really nothing
> software can do if the hardware isn't reporting connect events, even
> with polling.
>
> It also doesn't sound like the other TI redriver bug. That bug only
> effected USB 3.0 ports, and when lsusb was run, we would find the port
> in Compliance Mode. This is the host simply not reporting the USB 2.0
> port connect at all.
>
> Maybe if we completely disable PCI runtime PM for your host, we can work
> around this bug?

Well, that's what I've just asked Martin to try.

Thanks,
Rafael


--
I speak only for myself.
Rafael J. Wysocki, Intel Open Source Technology Center.

2013-04-03 22:38:27

by Bjorn Helgaas

[permalink] [raw]
Subject: Re: [Update][PATCH] PCI / ACPI: Always resume devices on ACPI wakeup notifications

On Thu, Mar 28, 2013 at 3:07 PM, Rafael J. Wysocki <[email protected]> wrote:
> From: Rafael J. Wysocki <[email protected]>
> Subject: PCI / ACPI: Always resume devices on ACPI wakeup notifications
>
> It turns out that the _Lxx control methods provided by some BIOSes
> clear the PME Status bit of PCI devices they handle, which means that
> pci_acpi_wake_dev() cannot really use that bit to check whether or
> not the device has signalled wakeup.
>
> One symptom of the problem is, for example, that when an affected PCI
> USB controller is runtime-suspended, then plugging in a new USB device
> into one of the controller's ports will not wake up the controller,
> which should happen.
>
> For this reason, make pci_acpi_wake_dev() always attempt to resume
> the device it is called for regardless of the device's PME Status bit
> value (that bit still has to be cleared if set at this point,
> though).
>
> Reported-by: Sarah Sharp <[email protected]>
> Signed-off-by: Rafael J. Wysocki <[email protected]>
> Acked-by: Matthew Garrett <[email protected]>
> Cc: 3.7+ <[email protected]>
> ---
>
> The changelog in this version is slightly better than in the previous one, IMHO.

I applied this to for-linus for v3.9. Thanks!

> ---
> drivers/pci/pci-acpi.c | 15 ++++++++-------
> 1 file changed, 8 insertions(+), 7 deletions(-)
>
> Index: linux-pm/drivers/pci/pci-acpi.c
> ===================================================================
> --- linux-pm.orig/drivers/pci/pci-acpi.c
> +++ linux-pm/drivers/pci/pci-acpi.c
> @@ -53,14 +53,15 @@ static void pci_acpi_wake_dev(acpi_handl
> return;
> }
>
> - if (!pci_dev->pm_cap || !pci_dev->pme_support
> - || pci_check_pme_status(pci_dev)) {
> - if (pci_dev->pme_poll)
> - pci_dev->pme_poll = false;
> + /* Clear PME Status if set. */
> + if (pci_dev->pme_support)
> + pci_check_pme_status(pci_dev);
>
> - pci_wakeup_event(pci_dev);
> - pm_runtime_resume(&pci_dev->dev);
> - }
> + if (pci_dev->pme_poll)
> + pci_dev->pme_poll = false;
> +
> + pci_wakeup_event(pci_dev);
> + pm_runtime_resume(&pci_dev->dev);
>
> if (pci_dev->subordinate)
> pci_pme_wakeup_bus(pci_dev->subordinate);
>