Discussion:
xhci_hcd can't detect new devices after enabling runtime PM and disabling S3 wake (bug #85701)
Dmitry Nezhevenko
2014-10-06 18:06:08 UTC
Permalink
[ resending from bugzilla as requested ]+

On Lenovo t440p machine I've xhci_hcd port that doesn't work after enabling runtime PM:

1. Just after boot, rmmod xhci_hcd and modprobe it again:

[ 120.595176] xhci_hcd 0000:00:14.0: enabling bus mastering
[ 120.595188] xhci_hcd 0000:00:14.0: xHCI Host Controller
[ 120.595194] xhci_hcd 0000:00:14.0: new USB bus registered, assigned bus number 1
[ 120.595344] xhci_hcd 0000:00:14.0: cache line size of 64 is not supported
[ 120.595368] xhci_hcd 0000:00:14.0: irq 29 for MSI/MSI-X
[ 120.595420] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[ 120.595421] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 120.595422] usb usb1: Product: xHCI Host Controller
[ 120.595422] usb usb1: Manufacturer: Linux 3.17.0+ xhci_hcd
[ 120.595423] usb usb1: SerialNumber: 0000:00:14.0
[ 120.595512] hub 1-0:1.0: USB hub found
[ 120.595533] hub 1-0:1.0: 15 ports detected
[ 120.597745] xhci_hcd 0000:00:14.0: xHCI Host Controller
[ 120.597748] xhci_hcd 0000:00:14.0: new USB bus registered, assigned bus number 2
[ 120.597782] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003
[ 120.597783] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 120.597784] usb usb2: Product: xHCI Host Controller
[ 120.597785] usb usb2: Manufacturer: Linux 3.17.0+ xhci_hcd
[ 120.597785] usb usb2: SerialNumber: 0000:00:14.0
[ 120.597865] hub 2-0:1.0: USB hub found
[ 120.597882] hub 2-0:1.0: 6 ports detected
[ 120.598504] usb: failed to peer usb2-port4 and usb1-port3 by location (usb2-port4:none) (usb1-port3:usb2-port3)
[ 120.598506] usb usb2-port4: failed to peer to usb1-port3 (-16)
[ 120.598809] usb: failed to peer usb2-port6 and usb1-port3 by location (usb2-port6:none) (usb1-port3:usb2-port3)
[ 120.598810] usb usb2-port6: failed to peer to usb1-port3 (-16)
[ 120.909228] usb 1-5: new full-speed USB device number 2 using xhci_hcd
[ 121.038496] usb 1-5: No LPM exit latency info found, disabling LPM.
[ 121.046968] usb 1-5: New USB device found, idVendor=058f, idProduct=9540
[ 121.046971] usb 1-5: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[ 121.046972] usb 1-5: Product: EMV Smartcard Reader
[ 121.046974] usb 1-5: Manufacturer: Generic
[ 121.213054] usb 1-7: new full-speed USB device number 3 using xhci_hcd
[ 121.343171] usb 1-7: New USB device found, idVendor=138a, idProduct=0017
[ 121.343174] usb 1-7: New USB device strings: Mfr=0, Product=0, SerialNumber=1
[ 121.343175] usb 1-7: SerialNumber: bd077adaec22
[ 121.456997] usb 1-12: new high-speed USB device number 4 using xhci_hcd
[ 121.709358] usb 1-12: New USB device found, idVendor=04f2, idProduct=b39a
[ 121.709362] usb 1-12: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[ 121.709363] usb 1-12: Product: Integrated Camera
[ 121.709364] usb 1-12: Manufacturer: SunplusIT INC.
[ 121.779568] uvcvideo: Found UVC 1.00 device Integrated Camera (04f2:b39a)
[ 121.788387] input: Integrated Camera as /devices/pci0000:00/0000:00:14.0/usb1/1-12/1-12:1.0/input/input20

2. apply power_settings:

% for F in /sys/bus/usb/devices/*; do test -f $F/power/control && echo auto | sudo tee $F/power/control; done

[ 947.442248] xhci_hcd 0000:00:14.0: PME# enabled
[ 947.482119] xhci_hcd 0000:00:14.0: power state changed by ACPI to D3cold

3. disable XHCI in /proc/acpi/wakeup:

% echo XHCI | sudo tee /proc/acpi/wakeup
% cat /proc/acpi/wakeup| grep XHCI
XHCI S3 *disabled pci:0000:00:14.0

4. plug some USB device to port:

[ 1072.724884] xhci_hcd 0000:00:14.0: power state changed by ACPI to D0
[ 1072.828927] xhci_hcd 0000:00:14.0: PME# disabled
[ 1072.828951] xhci_hcd 0000:00:14.0: enabling bus mastering
[ 1072.829114] pci_pm_runtime_suspend(): hcd_pci_runtime_suspend+0x0/0x40 [usbcore] returns -16
[ 1072.933036] xhci_hcd 0000:00:14.0: PME# enabled
[ 1072.972798] xhci_hcd 0000:00:14.0: power state changed by ACPI to D3cold

5. device is not detected and not present in lsusb. I'm using smartphone as
device and it's starts charging (but doesn't display 'connected' message).
Reenabling xhci in /proc/acpi/wakeup doesn't help. Always reproduces.

6. Unplug device, rmmod xhci_hcd and repeat everything again except 3 (don't
disable XHCI in /proc/acpi/wakeup):

...
[ 1240.128339] xhci_hcd 0000:00:14.0: PME# enabled
[ 1240.176209] xhci_hcd 0000:00:14.0: power state changed by ACPI to D3cold

7. Plug device again (XHCI is enabled in /proc/acpi/wakeup):

[ 1295.636130] xhci_hcd 0000:00:14.0: power state changed by ACPI to D0
[ 1295.740136] xhci_hcd 0000:00:14.0: PME# disabled
[ 1295.740150] xhci_hcd 0000:00:14.0: enabling bus mastering
[ 1295.740238] pci_pm_runtime_suspend(): hcd_pci_runtime_suspend+0x0/0x40 [usbcore] returns -16
[ 1295.844209] xhci_hcd 0000:00:14.0: PME# enabled
[ 1295.876043] xhci_hcd 0000:00:14.0: power state changed by ACPI to D3cold
[ 1296.667761] xhci_hcd 0000:00:14.0: power state changed by ACPI to D0
[ 1296.771757] xhci_hcd 0000:00:14.0: PME# disabled
[ 1296.771772] xhci_hcd 0000:00:14.0: enabling bus mastering
[ 1296.771860] pci_pm_runtime_suspend(): hcd_pci_runtime_suspend+0x0/0x40 [usbcore] returns -16
[ 1296.987688] usb 1-6: new high-speed USB device number 5 using xhci_hcd
[ 1297.118812] usb 1-6: New USB device found, idVendor=0fca, idProduct=8012
[ 1297.118815] usb 1-6: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 1297.118817] usb 1-6: Product: RIM Network Device
[ 1297.118818] usb 1-6: Manufacturer: Research In Motion, Ltd.
[ 1297.118819] usb 1-6: SerialNumber: EBD1BA7B6C5E4765D017A580236520AB97994D33
[ 1297.139270] rndis_host 1-6:1.0: rndis media connect
[ 1297.161920] rndis_host 1-6:1.0 usb0: register 'rndis_host' at usb-0000:00:14.0-6, RNDIS device, 96:eb:cd:0d:5f:e9
[ 1297.173486] rndis_host 1-6:1.0 usb6: renamed from usb0
[ 1297.191666] systemd-udevd[19181]: renamed network interface usb0 to usb6

So now it works as expected. I'm disabling everything from /proc/acpi/wakeup to
make sure that laptop will not be resumed by any USB device.

Full dmesg attached to https://bugzilla.kernel.org/show_bug.cgi?id=85701
--
WBR, Dmitry
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo-***@public.gmane.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Alan Stern
2014-10-06 18:49:29 UTC
Permalink
Post by Dmitry Nezhevenko
[ resending from bugzilla as requested ]+
...
Post by Dmitry Nezhevenko
% for F in /sys/bus/usb/devices/*; do test -f $F/power/control && echo auto | sudo tee $F/power/control; done
[ 947.442248] xhci_hcd 0000:00:14.0: PME# enabled
[ 947.482119] xhci_hcd 0000:00:14.0: power state changed by ACPI to D3cold
% echo XHCI | sudo tee /proc/acpi/wakeup
% cat /proc/acpi/wakeup| grep XHCI
XHCI S3 *disabled pci:0000:00:14.0
The right way to disable wakeup is to write "disabled" to the device's
power/wakeup attribute in sysfs. Don't use /proc/acpi/wakeup.
Post by Dmitry Nezhevenko
[ 1072.724884] xhci_hcd 0000:00:14.0: power state changed by ACPI to D0
[ 1072.828927] xhci_hcd 0000:00:14.0: PME# disabled
[ 1072.828951] xhci_hcd 0000:00:14.0: enabling bus mastering
[ 1072.829114] pci_pm_runtime_suspend(): hcd_pci_runtime_suspend+0x0/0x40 [usbcore] returns -16
[ 1072.933036] xhci_hcd 0000:00:14.0: PME# enabled
[ 1072.972798] xhci_hcd 0000:00:14.0: power state changed by ACPI to D3cold
We need to see what's going on here in more detail. An easy way to
start is to acquire a usbmon trace for bus 1 (see
Documentation/usb/usbmon.txt for instructions). Start the trace before
plugging in the device and stop it after the device is attached.

Also, you should enable debugging for usbcore:

echo 'module usbcore =p' >/sys/kernel/debug/dynamic_debug/control

assuming you have dynamic debugging enabled in your kernel.
Post by Dmitry Nezhevenko
5. device is not detected and not present in lsusb. I'm using smartphone as
device and it's starts charging (but doesn't display 'connected' message).
Reenabling xhci in /proc/acpi/wakeup doesn't help. Always reproduces.
6. Unplug device, rmmod xhci_hcd and repeat everything again except 3 (don't
...
[ 1240.128339] xhci_hcd 0000:00:14.0: PME# enabled
[ 1240.176209] xhci_hcd 0000:00:14.0: power state changed by ACPI to D3cold
[ 1295.636130] xhci_hcd 0000:00:14.0: power state changed by ACPI to D0
[ 1295.740136] xhci_hcd 0000:00:14.0: PME# disabled
[ 1295.740150] xhci_hcd 0000:00:14.0: enabling bus mastering
[ 1295.740238] pci_pm_runtime_suspend(): hcd_pci_runtime_suspend+0x0/0x40 [usbcore] returns -16
[ 1295.844209] xhci_hcd 0000:00:14.0: PME# enabled
[ 1295.876043] xhci_hcd 0000:00:14.0: power state changed by ACPI to D3cold
[ 1296.667761] xhci_hcd 0000:00:14.0: power state changed by ACPI to D0
[ 1296.771757] xhci_hcd 0000:00:14.0: PME# disabled
[ 1296.771772] xhci_hcd 0000:00:14.0: enabling bus mastering
[ 1296.771860] pci_pm_runtime_suspend(): hcd_pci_runtime_suspend+0x0/0x40 [usbcore] returns -16
[ 1296.987688] usb 1-6: new high-speed USB device number 5 using xhci_hcd
[ 1297.118812] usb 1-6: New USB device found, idVendor=0fca, idProduct=8012
[ 1297.118815] usb 1-6: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 1297.118817] usb 1-6: Product: RIM Network Device
[ 1297.118818] usb 1-6: Manufacturer: Research In Motion, Ltd.
[ 1297.118819] usb 1-6: SerialNumber: EBD1BA7B6C5E4765D017A580236520AB97994D33
[ 1297.139270] rndis_host 1-6:1.0: rndis media connect
[ 1297.161920] rndis_host 1-6:1.0 usb0: register 'rndis_host' at usb-0000:00:14.0-6, RNDIS device, 96:eb:cd:0d:5f:e9
[ 1297.173486] rndis_host 1-6:1.0 usb6: renamed from usb0
[ 1297.191666] systemd-udevd[19181]: renamed network interface usb0 to usb6
So now it works as expected. I'm disabling everything from /proc/acpi/wakeup to
make sure that laptop will not be resumed by any USB device.
This is odd because the wakeup setting should not make any difference
at all, since you're not using system suspend.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo-***@public.gmane.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Dmitry Nezhevenko
2014-10-06 19:10:56 UTC
Permalink
Post by Alan Stern
Post by Dmitry Nezhevenko
% echo XHCI | sudo tee /proc/acpi/wakeup
% cat /proc/acpi/wakeup| grep XHCI
XHCI S3 *disabled pci:0000:00:14.0
The right way to disable wakeup is to write "disabled" to the device's
power/wakeup attribute in sysfs. Don't use /proc/acpi/wakeup.
Ok. thanks
Post by Alan Stern
Post by Dmitry Nezhevenko
[ 1072.724884] xhci_hcd 0000:00:14.0: power state changed by ACPI to D0
[ 1072.828927] xhci_hcd 0000:00:14.0: PME# disabled
[ 1072.828951] xhci_hcd 0000:00:14.0: enabling bus mastering
[ 1072.829114] pci_pm_runtime_suspend(): hcd_pci_runtime_suspend+0x0/0x40 [usbcore] returns -16
[ 1072.933036] xhci_hcd 0000:00:14.0: PME# enabled
[ 1072.972798] xhci_hcd 0000:00:14.0: power state changed by ACPI to D3cold
We need to see what's going on here in more detail. An easy way to
start is to acquire a usbmon trace for bus 1 (see
Documentation/usb/usbmon.txt for instructions). Start the trace before
plugging in the device and stop it after the device is attached.
echo 'module usbcore =p' >/sys/kernel/debug/dynamic_debug/control
assuming you have dynamic debugging enabled in your kernel.
[ 2003.227172] hub 2-0:1.0: state 7 ports 6 chg 0000 evt 0000
[ 2003.227228] hub 2-0:1.0: hub_suspend
[ 2003.227233] usb usb2: bus auto-suspend, wakeup 1
[ 2005.251283] usb 1-12: usb auto-suspend, wakeup 0
[ 2007.362546] usb 1-5: usb auto-suspend, wakeup 0
[ 2007.550513] usb 1-7: usb auto-suspend, wakeup 0
[ 2007.566576] hub 1-0:1.0: hub_suspend
[ 2007.566585] usb usb1: bus auto-suspend, wakeup 1
[ 2007.566669] xhci_hcd 0000:00:14.0: hcd_pci_runtime_suspend: 0
[ 2007.566704] xhci_hcd 0000:00:14.0: PME# enabled
[ 2007.594484] xhci_hcd 0000:00:14.0: power state changed by ACPI to D3cold

--- device plugged ---

[ 2116.861499] xhci_hcd 0000:00:14.0: power state changed by ACPI to D0
[ 2116.962998] xhci_hcd 0000:00:14.0: PME# disabled
[ 2116.963015] xhci_hcd 0000:00:14.0: enabling bus mastering
[ 2116.963094] xhci_hcd 0000:00:14.0: hcd_pci_runtime_resume: 0
[ 2116.963102] xhci_hcd 0000:00:14.0: hcd_pci_runtime_suspend: -16
[ 2116.963138] pci_pm_runtime_suspend(): hcd_pci_runtime_suspend+0x0/0x40 [usbcore] returns -16
[ 2116.963140] usb usb1: usb wakeup-resume
[ 2116.963152] usb usb1: usb auto-resume
[ 2116.963185] hub 1-0:1.0: hub_resume
[ 2116.963240] usb usb1-port5: status 0107 change 0000
[ 2116.963263] usb usb1-port7: status 0107 change 0000
[ 2116.963316] usb usb1-port12: status 0507 change 0000
[ 2117.066893] hub 1-0:1.0: state 7 ports 15 chg 0000 evt 0000
[ 2117.066906] hub 1-0:1.0: hub_suspend
[ 2117.066927] usb usb1: bus auto-suspend, wakeup 1
[ 2117.066999] xhci_hcd 0000:00:14.0: hcd_pci_runtime_suspend: 0
[ 2117.067035] xhci_hcd 0000:00:14.0: PME# enabled
[ 2117.106879] xhci_hcd 0000:00:14.0: power state changed by ACPI to D3cold

dump of /sys/kernel/debug/usb/usbmon/1u

ffff880429206040 1870921236 S Ci:1:001:0 s a3 00 0000 0001 0004 4 <
ffff880429206040 1870921256 C Ci:1:001:0 0 4 = 00010000
ffff880429206040 1870921260 S Ci:1:001:0 s a3 00 0000 0002 0004 4 <
ffff880429206040 1870921268 C Ci:1:001:0 0 4 = 00010000
ffff880429206040 1870921270 S Ci:1:001:0 s a3 00 0000 0003 0004 4 <
ffff880429206040 1870921273 C Ci:1:001:0 0 4 = 00010000
ffff880429206040 1870921275 S Ci:1:001:0 s a3 00 0000 0004 0004 4 <
ffff880429206040 1870921278 C Ci:1:001:0 0 4 = 00010000
ffff880429206040 1870921279 S Ci:1:001:0 s a3 00 0000 0005 0004 4 <
ffff880429206040 1870921282 C Ci:1:001:0 0 4 = 07010000
ffff880429206040 1870921287 S Ci:1:001:0 s a3 00 0000 0006 0004 4 <
ffff880429206040 1870921295 C Ci:1:001:0 0 4 = 00010100
ffff880429206040 1870921297 S Co:1:001:0 s 23 01 0010 0006 0000 0
ffff880429206040 1870921301 C Co:1:001:0 0 0
ffff880429206040 1870921303 S Ci:1:001:0 s a3 00 0000 0007 0004 4 <
ffff880429206040 1870921306 C Ci:1:001:0 0 4 = 07010000
ffff880429206040 1870921309 S Ci:1:001:0 s a3 00 0000 0008 0004 4 <
ffff880429206040 1870921321 C Ci:1:001:0 0 4 = 00010000
ffff880429206040 1870921323 S Ci:1:001:0 s a3 00 0000 0009 0004 4 <
ffff880429206040 1870921331 C Ci:1:001:0 0 4 = 00010000
ffff880429206040 1870921333 S Ci:1:001:0 s a3 00 0000 000a 0004 4 <
ffff880429206040 1870921339 C Ci:1:001:0 0 4 = 00010000
ffff880429206040 1870921341 S Ci:1:001:0 s a3 00 0000 000b 0004 4 <
ffff880429206040 1870921344 C Ci:1:001:0 0 4 = 00010000
ffff880429206040 1870921348 S Ci:1:001:0 s a3 00 0000 000c 0004 4 <
ffff880429206040 1870921359 C Ci:1:001:0 0 4 = 07050000
ffff880429206040 1870921363 S Ci:1:001:0 s a3 00 0000 000d 0004 4 <
ffff880429206040 1870921374 C Ci:1:001:0 0 4 = 00010000
ffff880429206040 1870921383 S Ci:1:001:0 s a3 00 0000 000e 0004 4 <
ffff880429206040 1870921395 C Ci:1:001:0 0 4 = 00010000
ffff880429206040 1870921398 S Ci:1:001:0 s a3 00 0000 000f 0004 4 <
ffff880429206040 1870921405 C Ci:1:001:0 0 4 = 00010000
ffff8803fdd93100 1871024959 S Ii:1:001:1 -115:2048 4 <
ffff8803fdd93100 1871024996 C Ii:1:001:1 -2:2048 0

Just after this port seems to be completely died. Unplugging and plugging
device don't produce any new messages (checked both dmesg and usbmon)
--
WBR, Dmitry
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo-***@public.gmane.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Alan Stern
2014-10-06 19:28:33 UTC
Permalink
Post by Dmitry Nezhevenko
--- device plugged ---
[ 2116.861499] xhci_hcd 0000:00:14.0: power state changed by ACPI to D0
[ 2116.962998] xhci_hcd 0000:00:14.0: PME# disabled
[ 2116.963015] xhci_hcd 0000:00:14.0: enabling bus mastering
[ 2116.963094] xhci_hcd 0000:00:14.0: hcd_pci_runtime_resume: 0
[ 2116.963102] xhci_hcd 0000:00:14.0: hcd_pci_runtime_suspend: -16
[ 2116.963138] pci_pm_runtime_suspend(): hcd_pci_runtime_suspend+0x0/0x40 [usbcore] returns -16
[ 2116.963140] usb usb1: usb wakeup-resume
[ 2116.963152] usb usb1: usb auto-resume
[ 2116.963185] hub 1-0:1.0: hub_resume
[ 2116.963240] usb usb1-port5: status 0107 change 0000
[ 2116.963263] usb usb1-port7: status 0107 change 0000
[ 2116.963316] usb usb1-port12: status 0507 change 0000
But nothing on port 6? That's strange.
Post by Dmitry Nezhevenko
[ 2117.066893] hub 1-0:1.0: state 7 ports 15 chg 0000 evt 0000
[ 2117.066906] hub 1-0:1.0: hub_suspend
[ 2117.066927] usb usb1: bus auto-suspend, wakeup 1
[ 2117.066999] xhci_hcd 0000:00:14.0: hcd_pci_runtime_suspend: 0
[ 2117.067035] xhci_hcd 0000:00:14.0: PME# enabled
[ 2117.106879] xhci_hcd 0000:00:14.0: power state changed by ACPI to D3cold
What does the debugging log show if you don't disable wakeup?

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo-***@public.gmane.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Dmitry Nezhevenko
2014-10-06 19:31:08 UTC
Permalink
Post by Alan Stern
Post by Dmitry Nezhevenko
--- device plugged ---
[ 2116.861499] xhci_hcd 0000:00:14.0: power state changed by ACPI to D0
[ 2116.962998] xhci_hcd 0000:00:14.0: PME# disabled
[ 2116.963015] xhci_hcd 0000:00:14.0: enabling bus mastering
[ 2116.963094] xhci_hcd 0000:00:14.0: hcd_pci_runtime_resume: 0
[ 2116.963102] xhci_hcd 0000:00:14.0: hcd_pci_runtime_suspend: -16
[ 2116.963138] pci_pm_runtime_suspend(): hcd_pci_runtime_suspend+0x0/0x40 [usbcore] returns -16
[ 2116.963140] usb usb1: usb wakeup-resume
[ 2116.963152] usb usb1: usb auto-resume
[ 2116.963185] hub 1-0:1.0: hub_resume
[ 2116.963240] usb usb1-port5: status 0107 change 0000
[ 2116.963263] usb usb1-port7: status 0107 change 0000
[ 2116.963316] usb usb1-port12: status 0507 change 0000
But nothing on port 6? That's strange.
Post by Dmitry Nezhevenko
[ 2117.066893] hub 1-0:1.0: state 7 ports 15 chg 0000 evt 0000
[ 2117.066906] hub 1-0:1.0: hub_suspend
[ 2117.066927] usb usb1: bus auto-suspend, wakeup 1
[ 2117.066999] xhci_hcd 0000:00:14.0: hcd_pci_runtime_suspend: 0
[ 2117.067035] xhci_hcd 0000:00:14.0: PME# enabled
[ 2117.106879] xhci_hcd 0000:00:14.0: power state changed by ACPI to D3cold
What does the debugging log show if you don't disable wakeup?
$It looks like same, but later it resumes once again.

[ 2836.134277] hub 2-0:1.0: state 7 ports 6 chg 0000 evt 0000
[ 2836.134340] hub 2-0:1.0: hub_suspend
[ 2836.134346] usb usb2: bus auto-suspend, wakeup 1
[ 2838.797692] usb 1-12: usb auto-suspend, wakeup 0
[ 2839.237510] usb 1-5: usb auto-suspend, wakeup 0
[ 2839.405473] usb 1-7: usb auto-suspend, wakeup 0
[ 2839.421487] hub 1-0:1.0: hub_suspend
[ 2839.421497] usb usb1: bus auto-suspend, wakeup 1
[ 2839.421586] xhci_hcd 0000:00:14.0: hcd_pci_runtime_suspend: 0
[ 2839.421622] xhci_hcd 0000:00:14.0: PME# enabled
[ 2839.453479] xhci_hcd 0000:00:14.0: power state changed by ACPI to D3cold
[ 2854.647991] xhci_hcd 0000:00:14.0: power state changed by ACPI to D0
[ 2854.751914] xhci_hcd 0000:00:14.0: PME# disabled
[ 2854.751928] xhci_hcd 0000:00:14.0: enabling bus mastering
[ 2854.751989] xhci_hcd 0000:00:14.0: hcd_pci_runtime_resume: 0
[ 2854.751994] xhci_hcd 0000:00:14.0: hcd_pci_runtime_suspend: -16
[ 2854.752017] pci_pm_runtime_suspend(): hcd_pci_runtime_suspend+0x0/0x40 [usbcore] returns -16
[ 2854.752019] usb usb1: usb wakeup-resume
[ 2854.752026] usb usb1: usb auto-resume
[ 2854.752056] hub 1-0:1.0: hub_resume
[ 2854.752095] usb usb1-port5: status 0107 change 0000
[ 2854.752107] usb usb1-port7: status 0107 change 0000
[ 2854.752125] usb usb1-port12: status 0507 change 0000
[ 2854.855937] hub 1-0:1.0: state 7 ports 15 chg 0000 evt 0000
[ 2854.855951] hub 1-0:1.0: hub_suspend
[ 2854.855966] usb usb1: bus auto-suspend, wakeup 1
[ 2854.856002] usb usb1: suspend raced with wakeup event
[ 2854.856003] usb usb1: usb auto-resume
[ 2854.875324] hub 1-0:1.0: hub_resume
[ 2854.875368] usb usb1-port5: status 0107 change 0000
[ 2854.875386] usb usb1-port6: status 0101 change 0001
[ 2854.875409] usb usb1-port7: status 0107 change 0000
[ 2854.875461] usb usb1-port12: status 0507 change 0000
[ 2854.975854] hub 1-0:1.0: state 7 ports 15 chg 0040 evt 0000
[ 2854.975904] usb usb1-port6: status 0101, change 0000, 12 Mb/s
[ 2855.087783] usb 1-6: new high-speed USB device number 5 using xhci_hcd
[ 2855.220940] usb 1-6: skipped 1 descriptor after configuration
[ 2855.220943] usb 1-6: skipped 3 descriptors after interface
[ 2855.221201] usb 1-6: default language 0x0409
[ 2855.222070] usb 1-6: udev 5, busnum 1, minor = 4
[ 2855.222073] usb 1-6: New USB device found, idVendor=0fca, idProduct=8012
[ 2855.222075] usb 1-6: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 2855.222077] usb 1-6: Product: RIM Network Device
[ 2855.222078] usb 1-6: Manufacturer: Research In Motion, Ltd.
[ 2855.222080] usb 1-6: SerialNumber: EBD1BA7B6C5E4765D017A580236520AB97994D33
[ 2855.222252] usb 1-6: usb_probe_device
[ 2855.222255] usb 1-6: configuration #1 chosen from 1 choice
[ 2855.227119] usb 1-6: adding 1-6:1.0 (config #1, interface 0)
[ 2855.227160] rndis_host 1-6:1.0: usb_probe_interface
[ 2855.227161] rndis_host 1-6:1.0: usb_probe_interface - got id
[ 2855.240339] rndis_host 1-6:1.0: rndis media connect
[ 2855.266399] rndis_host 1-6:1.0 usb0: register 'rndis_host' at usb-0000:00:14.0-6, RNDIS device, 96:eb:cd:0d:5f:e9
[ 2855.266430] usb 1-6: adding 1-6:1.1 (config #1, interface 1)
[ 2855.266479] usb 1-6: adding 1-6:1.2 (config #1, interface 2)
[ 2855.277605] rndis_host 1-6:1.0 usb6: renamed from usb0
[ 2855.295753] systemd-udevd[22685]: renamed network interface usb0 to usb6
--
WBR, Dmitry
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo-***@public.gmane.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Alan Stern
2014-10-07 15:07:53 UTC
Permalink
Post by Dmitry Nezhevenko
Post by Alan Stern
What does the debugging log show if you don't disable wakeup?
$It looks like same, but later it resumes once again.
[ 2836.134277] hub 2-0:1.0: state 7 ports 6 chg 0000 evt 0000
[ 2836.134340] hub 2-0:1.0: hub_suspend
[ 2836.134346] usb usb2: bus auto-suspend, wakeup 1
[ 2838.797692] usb 1-12: usb auto-suspend, wakeup 0
[ 2839.237510] usb 1-5: usb auto-suspend, wakeup 0
[ 2839.405473] usb 1-7: usb auto-suspend, wakeup 0
[ 2839.421487] hub 1-0:1.0: hub_suspend
[ 2839.421497] usb usb1: bus auto-suspend, wakeup 1
[ 2839.421586] xhci_hcd 0000:00:14.0: hcd_pci_runtime_suspend: 0
[ 2839.421622] xhci_hcd 0000:00:14.0: PME# enabled
[ 2839.453479] xhci_hcd 0000:00:14.0: power state changed by ACPI to D3cold
[ 2854.647991] xhci_hcd 0000:00:14.0: power state changed by ACPI to D0
[ 2854.751914] xhci_hcd 0000:00:14.0: PME# disabled
[ 2854.751928] xhci_hcd 0000:00:14.0: enabling bus mastering
[ 2854.751989] xhci_hcd 0000:00:14.0: hcd_pci_runtime_resume: 0
[ 2854.751994] xhci_hcd 0000:00:14.0: hcd_pci_runtime_suspend: -16
[ 2854.752017] pci_pm_runtime_suspend(): hcd_pci_runtime_suspend+0x0/0x40 [usbcore] returns -16
[ 2854.752019] usb usb1: usb wakeup-resume
[ 2854.752026] usb usb1: usb auto-resume
[ 2854.752056] hub 1-0:1.0: hub_resume
[ 2854.752095] usb usb1-port5: status 0107 change 0000
[ 2854.752107] usb usb1-port7: status 0107 change 0000
[ 2854.752125] usb usb1-port12: status 0507 change 0000
[ 2854.855937] hub 1-0:1.0: state 7 ports 15 chg 0000 evt 0000
[ 2854.855951] hub 1-0:1.0: hub_suspend
[ 2854.855966] usb usb1: bus auto-suspend, wakeup 1
[ 2854.856002] usb usb1: suspend raced with wakeup event
That's the difference. It appears to be caused by a bug in xhci-hcd.
Does the patch below fix the problem?

Alan Stern



Index: usb-3.17/drivers/usb/host/xhci-hub.c
===================================================================
--- usb-3.17.orig/drivers/usb/host/xhci-hub.c
+++ usb-3.17/drivers/usb/host/xhci-hub.c
@@ -1136,13 +1136,11 @@ int xhci_bus_suspend(struct usb_hcd *hcd
t2 |= PORT_LINK_STROBE | XDEV_U3;
set_bit(port_index, &bus_state->bus_suspended);
}
- /* USB core sets remote wake mask for USB 3.0 hubs,
- * including the USB 3.0 roothub, but only if CONFIG_PM_RUNTIME
- * is enabled, so also enable remote wake here.
+ /* USB core sets remote wake mask for USB 3.0 hubs but
+ * not for USB 2.0 hubs (and only if CONFIG_PM_RUNTIME
+ * is enabled), so enable remote wake here.
*/
- if (hcd->self.root_hub->do_remote_wakeup
- && device_may_wakeup(hcd->self.controller)) {
Dmitry Nezhevenko
2014-10-08 08:44:21 UTC
Permalink
Post by Alan Stern
That's the difference. It appears to be caused by a bug in xhci-hcd.
Does the patch below fix the problem?
Hi,

Your patch fixes it for me. So now USB port works well.

Thanks!
Post by Alan Stern
Index: usb-3.17/drivers/usb/host/xhci-hub.c
===================================================================
--- usb-3.17.orig/drivers/usb/host/xhci-hub.c
+++ usb-3.17/drivers/usb/host/xhci-hub.c
@@ -1136,13 +1136,11 @@ int xhci_bus_suspend(struct usb_hcd *hcd
t2 |= PORT_LINK_STROBE | XDEV_U3;
set_bit(port_index, &bus_state->bus_suspended);
}
- /* USB core sets remote wake mask for USB 3.0 hubs,
- * including the USB 3.0 roothub, but only if CONFIG_PM_RUNTIME
- * is enabled, so also enable remote wake here.
+ /* USB core sets remote wake mask for USB 3.0 hubs but
+ * not for USB 2.0 hubs (and only if CONFIG_PM_RUNTIME
+ * is enabled), so enable remote wake here.
*/
- if (hcd->self.root_hub->do_remote_wakeup
- && device_may_wakeup(hcd->self.controller)) {
-
+ if (hcd->self.root_hub->do_remote_wakeup) {
if (t1 & PORT_CONNECT) {
t2 |= PORT_WKOC_E | PORT_WKDISC_E;
t2 &= ~PORT_WKCONN_E;
--
WBR, Dmitry
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo-***@public.gmane.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Mathias Nyman
2014-10-08 14:24:12 UTC
Permalink
Post by Alan Stern
Post by Dmitry Nezhevenko
Post by Alan Stern
What does the debugging log show if you don't disable wakeup?
$It looks like same, but later it resumes once again.
[ 2836.134277] hub 2-0:1.0: state 7 ports 6 chg 0000 evt 0000
[ 2836.134340] hub 2-0:1.0: hub_suspend
[ 2836.134346] usb usb2: bus auto-suspend, wakeup 1
[ 2838.797692] usb 1-12: usb auto-suspend, wakeup 0
[ 2839.237510] usb 1-5: usb auto-suspend, wakeup 0
[ 2839.405473] usb 1-7: usb auto-suspend, wakeup 0
[ 2839.421487] hub 1-0:1.0: hub_suspend
[ 2839.421497] usb usb1: bus auto-suspend, wakeup 1
[ 2839.421586] xhci_hcd 0000:00:14.0: hcd_pci_runtime_suspend: 0
[ 2839.421622] xhci_hcd 0000:00:14.0: PME# enabled
[ 2839.453479] xhci_hcd 0000:00:14.0: power state changed by ACPI to D3cold
[ 2854.647991] xhci_hcd 0000:00:14.0: power state changed by ACPI to D0
[ 2854.751914] xhci_hcd 0000:00:14.0: PME# disabled
[ 2854.751928] xhci_hcd 0000:00:14.0: enabling bus mastering
[ 2854.751989] xhci_hcd 0000:00:14.0: hcd_pci_runtime_resume: 0
[ 2854.751994] xhci_hcd 0000:00:14.0: hcd_pci_runtime_suspend: -16
[ 2854.752017] pci_pm_runtime_suspend(): hcd_pci_runtime_suspend+0x0/0x40 [usbcore] returns -16
[ 2854.752019] usb usb1: usb wakeup-resume
[ 2854.752026] usb usb1: usb auto-resume
[ 2854.752056] hub 1-0:1.0: hub_resume
[ 2854.752095] usb usb1-port5: status 0107 change 0000
[ 2854.752107] usb usb1-port7: status 0107 change 0000
[ 2854.752125] usb usb1-port12: status 0507 change 0000
[ 2854.855937] hub 1-0:1.0: state 7 ports 15 chg 0000 evt 0000
[ 2854.855951] hub 1-0:1.0: hub_suspend
[ 2854.855966] usb usb1: bus auto-suspend, wakeup 1
[ 2854.856002] usb usb1: suspend raced with wakeup event
That's the difference. It appears to be caused by a bug in xhci-hcd.
Does the patch below fix the problem?
Alan Stern
Index: usb-3.17/drivers/usb/host/xhci-hub.c
===================================================================
--- usb-3.17.orig/drivers/usb/host/xhci-hub.c
+++ usb-3.17/drivers/usb/host/xhci-hub.c
@@ -1136,13 +1136,11 @@ int xhci_bus_suspend(struct usb_hcd *hcd
t2 |= PORT_LINK_STROBE | XDEV_U3;
set_bit(port_index, &bus_state->bus_suspended);
}
- /* USB core sets remote wake mask for USB 3.0 hubs,
- * including the USB 3.0 roothub, but only if CONFIG_PM_RUNTIME
- * is enabled, so also enable remote wake here.
+ /* USB core sets remote wake mask for USB 3.0 hubs but
+ * not for USB 2.0 hubs (and only if CONFIG_PM_RUNTIME
+ * is enabled), so enable remote wake here.
*/
- if (hcd->self.root_hub->do_remote_wakeup
- && device_may_wakeup(hcd->self.controller)) {
-
+ if (hcd->self.root_hub->do_remote_wakeup) {
if (t1 & PORT_CONNECT) {
t2 |= PORT_WKOC_E | PORT_WKDISC_E;
t2 &= ~PORT_WKCONN_E;
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
More majordomo info at http://vger.kernel.org/majordomo-info.html
Hi

The device_may_wakeup() check was recently added in patch:

commit ff8cbf250b448aac35589f6075082c3fcad8a8fe
xhci: clear root port wake on bits if controller isn't wake-up capable

http://marc.info/?l=linux-usb&m=140261803101225&w=2

Seems it caused some unexpected issues.

Is there some way to fix both cases before ending up reverting that patch?

Any idea why hcd_bus_suspend() doesn't see the suspend race when calling hcd->driver->hub_status_data() in any case?
Are the wake-on [dis]connect bits somehow tied to connect status change bits?

When hcd_bus_suspend() checks for the suspend race condition it checks all xhci status change bits.
Shouldn't those indicate a connect change and prevent the second suspend?

Or maybe we should check for those bits resume as well?

Baolu, do you still have the hardware that caused spurious wakeups? do we know in detail what caused the wakeup?

-Mathias


--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo-***@public.gmane.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Alan Stern
2014-10-08 15:52:56 UTC
Permalink
Post by Mathias Nyman
Post by Alan Stern
Index: usb-3.17/drivers/usb/host/xhci-hub.c
===================================================================
--- usb-3.17.orig/drivers/usb/host/xhci-hub.c
+++ usb-3.17/drivers/usb/host/xhci-hub.c
@@ -1136,13 +1136,11 @@ int xhci_bus_suspend(struct usb_hcd *hcd
t2 |= PORT_LINK_STROBE | XDEV_U3;
set_bit(port_index, &bus_state->bus_suspended);
}
- /* USB core sets remote wake mask for USB 3.0 hubs,
- * including the USB 3.0 roothub, but only if CONFIG_PM_RUNTIME
- * is enabled, so also enable remote wake here.
+ /* USB core sets remote wake mask for USB 3.0 hubs but
+ * not for USB 2.0 hubs (and only if CONFIG_PM_RUNTIME
+ * is enabled), so enable remote wake here.
*/
- if (hcd->self.root_hub->do_remote_wakeup
- && device_may_wakeup(hcd->self.controller)) {
-
+ if (hcd->self.root_hub->do_remote_wakeup) {
if (t1 & PORT_CONNECT) {
t2 |= PORT_WKOC_E | PORT_WKDISC_E;
t2 &= ~PORT_WKCONN_E;
Hi
commit ff8cbf250b448aac35589f6075082c3fcad8a8fe
xhci: clear root port wake on bits if controller isn't wake-up capable
The description of that commit doesn't agree with the title. The
description says that some platforms get spurious wakeups, so the
wake-on bits should be cleared if do_wakeup is false. It says nothing
about the controller not being wakeup-capable.

Also, the commit description says:

When xHCI PCI host is suspended, if do_wakeup is false in xhci_pci_suspend,
xhci_bus_suspend needs to clear all root port wake on bits...

This makes no sense, because xhci_bus_suspend() is not called from
xhci_pci_suspend(). They are two completely separate pathways.
Post by Mathias Nyman
http://marc.info/?l=linux-usb&m=140261803101225&w=2
Seems it caused some unexpected issues.
Evidently the commit was meant to fix a problem with system suspend,
and the author totally failed to realize that the code it touched also
gets used for runtime suspend.
Post by Mathias Nyman
Is there some way to fix both cases before ending up reverting that patch?
The commit altered the wrong routine. If the controller isn't allowed
to wake up then the port wake-on bits should be cleared in
xhci_suspend(), not in xhci_bus_suspend(). In fact, it would be a good
idea to check in xhci_suspend() for a wakeup-in-progress as well.

Unfortunately, the curent code doesn't tell xhci_suspend() whether
wakeup should be enabled. This can easily be fixed;
xhci_pci_suspend() should pass its do_wakeup argument on to
xhci_suspend().
Post by Mathias Nyman
Any idea why hcd_bus_suspend() doesn't see the suspend race when calling hcd->driver->hub_status_data() in any case?
I don't really understand what went wrong on Dmitry's system, or why
enabling the wake-on bits should make a difference. I merely noticed
that xhci_bus_suspend() was doing the wrong thing, and it seemed like
it might be related to the bug.
Post by Mathias Nyman
Are the wake-on [dis]connect bits somehow tied to connect status change bits?
I assume they are. Only the hardware designers know for sure. :-)
Post by Mathias Nyman
When hcd_bus_suspend() checks for the suspend race condition it checks all xhci status change bits.
Shouldn't those indicate a connect change and prevent the second suspend?
Or maybe we should check for those bits resume as well?
Suspect something rather subtle must be going on.

xhci_hub_status_data() tests for resume-in-progress by checking
bus_state->resuming_ports. That variable gets set by
handle_port_status() in response to a Port Status Change Event TRB.
Maybe under some circumstances the controller doesn't generate those
events unless the corresponding wake-on bit is set; I don't know.

What actually happened on Dmitry's system is a little strange. When he
plugged in the device there was a wakeup request, and the
port-connect-status-change bit was set. But the port-connect-status
bit was _not_ set, even after a 100 ms delay, so the system tried to
suspend the root hub again. Without my patch, resuming_ports wasn't
set, and so the suspend succeeded and the connection ended up getting
lost. With my patch, resuming_ports was set, and so the suspend was
aborted and the connection was eventually detected.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo-***@public.gmane.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Alan Stern
2014-10-08 16:38:35 UTC
Permalink
Post by Alan Stern
What actually happened on Dmitry's system is a little strange. When he
plugged in the device there was a wakeup request, and the
port-connect-status-change bit was set. But the port-connect-status
bit was _not_ set, even after a 100 ms delay, so the system tried to
suspend the root hub again. Without my patch, resuming_ports wasn't
set, and so the suspend succeeded and the connection ended up getting
lost. With my patch, resuming_ports was set, and so the suspend was
aborted and the connection was eventually detected.
Dmitry, this gave me another idea. Can you test the patch below,
_without_ the previous patch? And post the corresponding usbmon trace
and dmesg log?

Alan Stern



Index: usb-3.17/drivers/usb/core/hub.c
===================================================================
--- usb-3.17.orig/drivers/usb/core/hub.c
+++ usb-3.17/drivers/usb/core/hub.c
@@ -1171,7 +1171,8 @@ static void hub_activate(struct usb_hub
* check for a new connection
*/
if (udev || (portstatus & USB_PORT_STAT_CONNECTION) ||
- (portstatus & USB_PORT_STAT_OVERCURRENT))
+ (portstatus & USB_PORT_STAT_OVERCURRENT) ||
+ (portchange & USB_PORT_STAT_C_CONNECTION))
set_bit(port1, hub->change_bits);

} else if (portstatus & USB_PORT_STAT_ENABLE) {

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo-***@public.gmane.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Dmitry Nezhevenko
2014-10-10 07:16:16 UTC
Permalink
Post by Alan Stern
Dmitry, this gave me another idea. Can you test the patch below,
_without_ the previous patch? And post the corresponding usbmon trace
and dmesg log?
Hi, it doesn't work. All other attempts to plug device (after first one+)
don't produce any dmesg output.

[ 140.766041] xhci_hcd 0000:00:14.0: PME# enabled
[ 140.801962] xhci_hcd 0000:00:14.0: power state changed by ACPI to D3cold
[ 211.872301] xhci_hcd 0000:00:14.0: power state changed by ACPI to D0
[ 211.976315] xhci_hcd 0000:00:14.0: PME# disabled
[ 211.976332] xhci_hcd 0000:00:14.0: enabling bus mastering
[ 211.976408] xhci_hcd 0000:00:14.0: hcd_pci_runtime_resume: 0
[ 211.976415] xhci_hcd 0000:00:14.0: hcd_pci_runtime_suspend: -16
[ 211.976450] pci_pm_runtime_suspend(): hcd_pci_runtime_suspend+0x0/0x40 [usbcore] returns -16
[ 211.976452] usb usb1: usb wakeup-resume
[ 211.976465] usb usb1: usb auto-resume
[ 211.976498] hub 1-0:1.0: hub_resume
[ 211.976551] usb usb1-port5: status 0107 change 0000
[ 211.976573] usb usb1-port7: status 0107 change 0000
[ 211.976616] usb usb1-port12: status 0507 change 0000
[ 212.080230] hub 1-0:1.0: state 7 ports 15 chg 0040 evt 0000
[ 212.080297] usb usb1-port6: status 0100, change 0000, 12 Mb/s
[ 212.080314] hub 1-0:1.0: hub_suspend
[ 212.080328] usb usb1: bus auto-suspend, wakeup 1
[ 212.080410] xhci_hcd 0000:00:14.0: hcd_pci_runtime_suspend: 0
[ 212.080458] xhci_hcd 0000:00:14.0: PME# enabled
[ 212.120252] xhci_hcd 0000:00:14.0: power state changed by ACPI to D3cold

ffff88042830e7c0 1795043513 S Ci:1:001:0 s a3 00 0000 0001 0004 4 <
ffff88042830e7c0 1795043534 C Ci:1:001:0 0 4 = 00010000
ffff88042830e7c0 1795043538 S Ci:1:001:0 s a3 00 0000 0002 0004 4 <
ffff88042830e7c0 1795043545 C Ci:1:001:0 0 4 = 00010000
ffff88042830e7c0 1795043548 S Ci:1:001:0 s a3 00 0000 0003 0004 4 <
ffff88042830e7c0 1795043550 C Ci:1:001:0 0 4 = 00010000
ffff88042830e7c0 1795043552 S Ci:1:001:0 s a3 00 0000 0004 0004 4 <
ffff88042830e7c0 1795043555 C Ci:1:001:0 0 4 = 00010000
ffff88042830e7c0 1795043557 S Ci:1:001:0 s a3 00 0000 0005 0004 4 <
ffff88042830e7c0 1795043560 C Ci:1:001:0 0 4 = 07010000
ffff88042830e7c0 1795043564 S Ci:1:001:0 s a3 00 0000 0006 0004 4 <
ffff88042830e7c0 1795043572 C Ci:1:001:0 0 4 = 00010100
ffff88042830e7c0 1795043574 S Co:1:001:0 s 23 01 0010 0006 0000 0
ffff88042830e7c0 1795043578 C Co:1:001:0 0 0
ffff88042830e7c0 1795043580 S Ci:1:001:0 s a3 00 0000 0007 0004 4 <
ffff88042830e7c0 1795043582 C Ci:1:001:0 0 4 = 07010000
ffff88042830e7c0 1795043585 S Ci:1:001:0 s a3 00 0000 0008 0004 4 <
ffff88042830e7c0 1795043596 C Ci:1:001:0 0 4 = 00010000
ffff88042830e7c0 1795043598 S Ci:1:001:0 s a3 00 0000 0009 0004 4 <
ffff88042830e7c0 1795043601 C Ci:1:001:0 0 4 = 00010000
ffff88042830e7c0 1795043603 S Ci:1:001:0 s a3 00 0000 000a 0004 4 <
ffff88042830e7c0 1795043606 C Ci:1:001:0 0 4 = 00010000
ffff88042830e7c0 1795043608 S Ci:1:001:0 s a3 00 0000 000b 0004 4 <
ffff88042830e7c0 1795043611 C Ci:1:001:0 0 4 = 00010000
ffff88042830e7c0 1795043615 S Ci:1:001:0 s a3 00 0000 000c 0004 4 <
ffff88042830e7c0 1795043625 C Ci:1:001:0 0 4 = 07050000
ffff88042830e7c0 1795043629 S Ci:1:001:0 s a3 00 0000 000d 0004 4 <
ffff88042830e7c0 1795043640 C Ci:1:001:0 0 4 = 00010000
ffff88042830e7c0 1795043641 S Ci:1:001:0 s a3 00 0000 000e 0004 4 <
ffff88042830e7c0 1795043644 C Ci:1:001:0 0 4 = 00010000
ffff88042830e7c0 1795043646 S Ci:1:001:0 s a3 00 0000 000f 0004 4 <
ffff88042830e7c0 1795043649 C Ci:1:001:0 0 4 = 00010000
ffff8800ad06bac0 1795147238 S Ii:1:001:1 -115:2048 4 <
ffff880427003040 1795147287 S Ci:1:001:0 s a3 00 0000 0006 0004 4 <
ffff880427003040 1795147312 C Ci:1:001:0 0 4 = 00010000
ffff8800ad06bac0 1795147369 C Ii:1:001:1 -2:2048 0
Post by Alan Stern
Index: usb-3.17/drivers/usb/core/hub.c
===================================================================
--- usb-3.17.orig/drivers/usb/core/hub.c
+++ usb-3.17/drivers/usb/core/hub.c
@@ -1171,7 +1171,8 @@ static void hub_activate(struct usb_hub
* check for a new connection
*/
if (udev || (portstatus & USB_PORT_STAT_CONNECTION) ||
- (portstatus & USB_PORT_STAT_OVERCURRENT))
+ (portstatus & USB_PORT_STAT_OVERCURRENT) ||
+ (portchange & USB_PORT_STAT_C_CONNECTION))
set_bit(port1, hub->change_bits);
} else if (portstatus & USB_PORT_STAT_ENABLE) {
--
WBR, Dmitry
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo-***@public.gmane.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Lu, Baolu
2014-10-11 07:51:47 UTC
Permalink
Hi Dmitry,

Can you please try to disable wakeup of root hub instead of host controller?

Regards,
-baolu
Post by Dmitry Nezhevenko
Post by Alan Stern
Dmitry, this gave me another idea. Can you test the patch below,
_without_ the previous patch? And post the corresponding usbmon trace
and dmesg log?
Hi, it doesn't work. All other attempts to plug device (after first one+)
don't produce any dmesg output.
[ 140.766041] xhci_hcd 0000:00:14.0: PME# enabled
[ 140.801962] xhci_hcd 0000:00:14.0: power state changed by ACPI to D3cold
[ 211.872301] xhci_hcd 0000:00:14.0: power state changed by ACPI to D0
[ 211.976315] xhci_hcd 0000:00:14.0: PME# disabled
[ 211.976332] xhci_hcd 0000:00:14.0: enabling bus mastering
[ 211.976408] xhci_hcd 0000:00:14.0: hcd_pci_runtime_resume: 0
[ 211.976415] xhci_hcd 0000:00:14.0: hcd_pci_runtime_suspend: -16
[ 211.976450] pci_pm_runtime_suspend(): hcd_pci_runtime_suspend+0x0/0x40 [usbcore] returns -16
[ 211.976452] usb usb1: usb wakeup-resume
[ 211.976465] usb usb1: usb auto-resume
[ 211.976498] hub 1-0:1.0: hub_resume
[ 211.976551] usb usb1-port5: status 0107 change 0000
[ 211.976573] usb usb1-port7: status 0107 change 0000
[ 211.976616] usb usb1-port12: status 0507 change 0000
[ 212.080230] hub 1-0:1.0: state 7 ports 15 chg 0040 evt 0000
[ 212.080297] usb usb1-port6: status 0100, change 0000, 12 Mb/s
[ 212.080314] hub 1-0:1.0: hub_suspend
[ 212.080328] usb usb1: bus auto-suspend, wakeup 1
[ 212.080410] xhci_hcd 0000:00:14.0: hcd_pci_runtime_suspend: 0
[ 212.080458] xhci_hcd 0000:00:14.0: PME# enabled
[ 212.120252] xhci_hcd 0000:00:14.0: power state changed by ACPI to D3cold
ffff88042830e7c0 1795043513 S Ci:1:001:0 s a3 00 0000 0001 0004 4 <
ffff88042830e7c0 1795043534 C Ci:1:001:0 0 4 = 00010000
ffff88042830e7c0 1795043538 S Ci:1:001:0 s a3 00 0000 0002 0004 4 <
ffff88042830e7c0 1795043545 C Ci:1:001:0 0 4 = 00010000
ffff88042830e7c0 1795043548 S Ci:1:001:0 s a3 00 0000 0003 0004 4 <
ffff88042830e7c0 1795043550 C Ci:1:001:0 0 4 = 00010000
ffff88042830e7c0 1795043552 S Ci:1:001:0 s a3 00 0000 0004 0004 4 <
ffff88042830e7c0 1795043555 C Ci:1:001:0 0 4 = 00010000
ffff88042830e7c0 1795043557 S Ci:1:001:0 s a3 00 0000 0005 0004 4 <
ffff88042830e7c0 1795043560 C Ci:1:001:0 0 4 = 07010000
ffff88042830e7c0 1795043564 S Ci:1:001:0 s a3 00 0000 0006 0004 4 <
ffff88042830e7c0 1795043572 C Ci:1:001:0 0 4 = 00010100
ffff88042830e7c0 1795043574 S Co:1:001:0 s 23 01 0010 0006 0000 0
ffff88042830e7c0 1795043578 C Co:1:001:0 0 0
ffff88042830e7c0 1795043580 S Ci:1:001:0 s a3 00 0000 0007 0004 4 <
ffff88042830e7c0 1795043582 C Ci:1:001:0 0 4 = 07010000
ffff88042830e7c0 1795043585 S Ci:1:001:0 s a3 00 0000 0008 0004 4 <
ffff88042830e7c0 1795043596 C Ci:1:001:0 0 4 = 00010000
ffff88042830e7c0 1795043598 S Ci:1:001:0 s a3 00 0000 0009 0004 4 <
ffff88042830e7c0 1795043601 C Ci:1:001:0 0 4 = 00010000
ffff88042830e7c0 1795043603 S Ci:1:001:0 s a3 00 0000 000a 0004 4 <
ffff88042830e7c0 1795043606 C Ci:1:001:0 0 4 = 00010000
ffff88042830e7c0 1795043608 S Ci:1:001:0 s a3 00 0000 000b 0004 4 <
ffff88042830e7c0 1795043611 C Ci:1:001:0 0 4 = 00010000
ffff88042830e7c0 1795043615 S Ci:1:001:0 s a3 00 0000 000c 0004 4 <
ffff88042830e7c0 1795043625 C Ci:1:001:0 0 4 = 07050000
ffff88042830e7c0 1795043629 S Ci:1:001:0 s a3 00 0000 000d 0004 4 <
ffff88042830e7c0 1795043640 C Ci:1:001:0 0 4 = 00010000
ffff88042830e7c0 1795043641 S Ci:1:001:0 s a3 00 0000 000e 0004 4 <
ffff88042830e7c0 1795043644 C Ci:1:001:0 0 4 = 00010000
ffff88042830e7c0 1795043646 S Ci:1:001:0 s a3 00 0000 000f 0004 4 <
ffff88042830e7c0 1795043649 C Ci:1:001:0 0 4 = 00010000
ffff8800ad06bac0 1795147238 S Ii:1:001:1 -115:2048 4 <
ffff880427003040 1795147287 S Ci:1:001:0 s a3 00 0000 0006 0004 4 <
ffff880427003040 1795147312 C Ci:1:001:0 0 4 = 00010000
ffff8800ad06bac0 1795147369 C Ii:1:001:1 -2:2048 0
Post by Alan Stern
Index: usb-3.17/drivers/usb/core/hub.c
===================================================================
--- usb-3.17.orig/drivers/usb/core/hub.c
+++ usb-3.17/drivers/usb/core/hub.c
@@ -1171,7 +1171,8 @@ static void hub_activate(struct usb_hub
* check for a new connection
*/
if (udev || (portstatus & USB_PORT_STAT_CONNECTION) ||
- (portstatus & USB_PORT_STAT_OVERCURRENT))
+ (portstatus & USB_PORT_STAT_OVERCURRENT) ||
+ (portchange & USB_PORT_STAT_C_CONNECTION))
set_bit(port1, hub->change_bits);
} else if (portstatus & USB_PORT_STAT_ENABLE) {
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo-***@public.gmane.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Dmitry Nezhevenko
2014-10-15 10:07:29 UTC
Permalink
Post by Lu, Baolu
Hi Dmitry,
Can you please try to disable wakeup of root hub instead of host controller?
Hi,

Sorry for delay. Can you please suggest how to do this?

And should I use mainline 3.17 kernel or one with attached patches?

I'll back with results tomorrow.

Thanks!
--
WBR, Dmitry
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo-***@public.gmane.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Lu, Baolu
2014-10-16 00:46:46 UTC
Permalink
Post by Dmitry Nezhevenko
Post by Lu, Baolu
Hi Dmitry,
Can you please try to disable wakeup of root hub instead of host controller?
Hi,
Sorry for delay. Can you please suggest how to do this?
I always do this with below steps. "lsusb -t" on my machine prints

***@allen-ivb:/sys/bus/pci/devices/0000:00:14.0/usb3$ lsusb -t
/: Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/4p, 5000M
/: Bus 03.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/4p, 480M
|__ Port 3: Dev 2, If 0, Class=Hub, Driver=hub/3p, 12M
|__ Port 1: Dev 3, If 0, Class=Human Interface Device,
Driver=usbhid, 12M
|__ Port 1: Dev 3, If 1, Class=Human Interface Device,
Driver=usbhid, 12M
/: Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/3p, 480M
|__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/8p, 480M
|__ Port 5: Dev 3, If 0, Class=Human Interface Device,
Driver=usbhid, 1.5M
|__ Port 6: Dev 4, If 0, Class=Human Interface Device,
Driver=usbhid, 1.5M
|__ Port 6: Dev 4, If 1, Class=Human Interface Device,
Driver=usbhid, 1.5M
/: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/3p, 480M
|__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/6p, 480M

I want to disable remote wake up of xHC USB2 root hub (/: Bus 03.Port
1: Dev 1, Class=root_hub, Driver=xhci_hcd/4p, 480M).

Find the sys device path of the host controller. (You might need to use
lspci to get the bus/dev/fun of your xHC).

On my machine, it's /sys/bus/pci/devices/0000:00:14.0.

***@allen-ivb:/sys/devices/pci0000:00/0000:00:14.0# echo disabled >
usb3/power/wakeup

Thanks,
-baolu
Post by Dmitry Nezhevenko
And should I use mainline 3.17 kernel or one with attached patches?
Please try the latest kernel without extra patches.
Post by Dmitry Nezhevenko
I'll back with results tomorrow.
Thanks!
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo-***@public.gmane.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Alan Stern
2014-10-16 14:11:41 UTC
Permalink
Post by Lu, Baolu
Post by Dmitry Nezhevenko
Post by Lu, Baolu
Hi Dmitry,
Can you please try to disable wakeup of root hub instead of host controller?
Hi,
Sorry for delay. Can you please suggest how to do this?
I always do this with below steps. "lsusb -t" on my machine prints
/: Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/4p, 5000M
/: Bus 03.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/4p, 480M
|__ Port 3: Dev 2, If 0, Class=Hub, Driver=hub/3p, 12M
|__ Port 1: Dev 3, If 0, Class=Human Interface Device,
Driver=usbhid, 12M
|__ Port 1: Dev 3, If 1, Class=Human Interface Device,
Driver=usbhid, 12M
/: Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/3p, 480M
|__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/8p, 480M
|__ Port 5: Dev 3, If 0, Class=Human Interface Device,
Driver=usbhid, 1.5M
|__ Port 6: Dev 4, If 0, Class=Human Interface Device,
Driver=usbhid, 1.5M
|__ Port 6: Dev 4, If 1, Class=Human Interface Device,
Driver=usbhid, 1.5M
/: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/3p, 480M
|__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/6p, 480M
I want to disable remote wake up of xHC USB2 root hub (/: Bus 03.Port
1: Dev 1, Class=root_hub, Driver=xhci_hcd/4p, 480M).
Find the sys device path of the host controller. (You might need to use
lspci to get the bus/dev/fun of your xHC).
On my machine, it's /sys/bus/pci/devices/0000:00:14.0.
usb3/power/wakeup
It doesn't have to be so complicated. You can simply do:

echo disabled >/sys/bus/usb/devices/usb3/power/wakeup

However that file contains "disabled" by default, so doing this may not
accomplish anything.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo-***@public.gmane.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Lu, Baolu
2014-10-11 06:54:33 UTC
Permalink
Post by Alan Stern
Post by Mathias Nyman
Post by Alan Stern
Index: usb-3.17/drivers/usb/host/xhci-hub.c
===================================================================
--- usb-3.17.orig/drivers/usb/host/xhci-hub.c
+++ usb-3.17/drivers/usb/host/xhci-hub.c
@@ -1136,13 +1136,11 @@ int xhci_bus_suspend(struct usb_hcd *hcd
t2 |= PORT_LINK_STROBE | XDEV_U3;
set_bit(port_index, &bus_state->bus_suspended);
}
- /* USB core sets remote wake mask for USB 3.0 hubs,
- * including the USB 3.0 roothub, but only if CONFIG_PM_RUNTIME
- * is enabled, so also enable remote wake here.
+ /* USB core sets remote wake mask for USB 3.0 hubs but
+ * not for USB 2.0 hubs (and only if CONFIG_PM_RUNTIME
+ * is enabled), so enable remote wake here.
*/
- if (hcd->self.root_hub->do_remote_wakeup
- && device_may_wakeup(hcd->self.controller)) {
-
+ if (hcd->self.root_hub->do_remote_wakeup) {
if (t1 & PORT_CONNECT) {
t2 |= PORT_WKOC_E | PORT_WKDISC_E;
t2 &= ~PORT_WKCONN_E;
Hi
commit ff8cbf250b448aac35589f6075082c3fcad8a8fe
xhci: clear root port wake on bits if controller isn't wake-up capable
The description of that commit doesn't agree with the title. The
description says that some platforms get spurious wakeups, so the
wake-on bits should be cleared if do_wakeup is false. It says nothing
about the controller not being wakeup-capable.
When xHCI PCI host is suspended, if do_wakeup is false in xhci_pci_suspend,
xhci_bus_suspend needs to clear all root port wake on bits...
This makes no sense, because xhci_bus_suspend() is not called from
xhci_pci_suspend(). They are two completely separate pathways.
Post by Mathias Nyman
http://marc.info/?l=linux-usb&m=140261803101225&w=2
Seems it caused some unexpected issues.
Evidently the commit was meant to fix a problem with system suspend,
and the author totally failed to realize that the code it touched also
gets used for runtime suspend.
I apologize for the wrong fix. I will follow up with a right fix.
Post by Alan Stern
Post by Mathias Nyman
Is there some way to fix both cases before ending up reverting that patch?
The commit altered the wrong routine. If the controller isn't allowed
to wake up then the port wake-on bits should be cleared in
xhci_suspend(), not in xhci_bus_suspend(). In fact, it would be a good
idea to check in xhci_suspend() for a wakeup-in-progress as well.
Unfortunately, the curent code doesn't tell xhci_suspend() whether
wakeup should be enabled. This can easily be fixed;
xhci_pci_suspend() should pass its do_wakeup argument on to
xhci_suspend().
Post by Mathias Nyman
Any idea why hcd_bus_suspend() doesn't see the suspend race when calling hcd->driver->hub_status_data() in any case?
I don't really understand what went wrong on Dmitry's system, or why
enabling the wake-on bits should make a difference. I merely noticed
that xhci_bus_suspend() was doing the wrong thing, and it seemed like
it might be related to the bug.
Post by Mathias Nyman
Are the wake-on [dis]connect bits somehow tied to connect status change bits?
I assume they are. Only the hardware designers know for sure. :-)
Post by Mathias Nyman
When hcd_bus_suspend() checks for the suspend race condition it checks all xhci status change bits.
Shouldn't those indicate a connect change and prevent the second suspend?
Or maybe we should check for those bits resume as well?
Suspect something rather subtle must be going on.
xhci_hub_status_data() tests for resume-in-progress by checking
bus_state->resuming_ports. That variable gets set by
handle_port_status() in response to a Port Status Change Event TRB.
Maybe under some circumstances the controller doesn't generate those
events unless the corresponding wake-on bit is set; I don't know.
What actually happened on Dmitry's system is a little strange. When he
plugged in the device there was a wakeup request, and the
port-connect-status-change bit was set. But the port-connect-status
bit was _not_ set, even after a 100 ms delay, so the system tried to
suspend the root hub again. Without my patch, resuming_ports wasn't
set, and so the suspend succeeded and the connection ended up getting
lost. With my patch, resuming_ports was set, and so the suspend was
aborted and the connection was eventually detected.
If I understand it correctly, Dmitry's issue should also happen if
"disabled" is written to root hub's power/wakeup attribute in sysfs.

Thanks,
-baolu
Post by Alan Stern
Alan Stern
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo-***@public.gmane.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Loading...