On 11.02.2019 18:38, Eric Blau wrote:
On Mon, Feb 11, 2019 at 10:25 AM Mathias Nyman
<mathias.nyman@xxxxxxxxxxxxxxx> wrote:
Can I ask you to take yet another set of logs, same as before, xhci traces, and
usbcore and xhci dynamic debug, but preferably everything from boot up to and including
a failed system suspend event.
In the course of trying to capture the logs you asked for, the first
time I was actually not able to reproduce the problem even after
suspending 5-6 times. I never saw a port stuck in polling and suspends
never failed. After I cold booted my laptop and tried again, the
problem occurred again.
This logs shows a USB3 Apple card reader successfully suspending to U3 state
once, but fails to resume back to U0. It is logically disconnected as a result of
failing to resume, and is left stuck in a polling link state.
This is the only USB3 device connected. The polling link state does not yet show the device
as connected or enabled, so hub attempts to autosuspend.
There is however a final check before autosuspending the hub which prevents suspend
due to the port in polling state. This autosuspend attempt continues in a loop.
Details from log:
Feb 11 11:23:58 eric-macbookpro kernel: usb 2-3: Product: Card Reader
Feb 11 11:23:58 eric-macbookpro kernel: usb 2-3: Manufacturer: Apple
...
1st resume:
Feb 11 11:25:43 eric-macbookpro kernel: usb usb1: usb resume
Feb 11 11:25:43 eric-macbookpro kernel: hub 1-0:1.0: hub_resume
Feb 11 11:25:43 eric-macbookpro kernel: usb usb1-port3: status 0107 change 0000
Feb 11 11:25:43 eric-macbookpro kernel: usb usb1-port5: status 0107 change 0000
For USB2 devices 0x107 means connected, enabled and powered
Feb 11 11:25:43 eric-macbookpro kernel: usb usb2: usb resume
Feb 11 11:25:43 eric-macbookpro kernel: hub 2-0:1.0: hub_resume
Feb 11 11:25:43 eric-macbookpro kernel: usb usb2-port3: status 0263 change 0000
For USB3 devices 0x0263 means Powered, U3, Enabled, connected (U3 is suspended)
bus_resume() should have tried to resume the port by now, either it failed, or never tried.
Feb 11 11:25:43 eric-macbookpro kernel: ACPI: button: The lid device is not compliant to SW_LID.
Feb 11 11:25:43 eric-macbookpro kernel: sd 0:0:0:0: [sda] Starting disk
Feb 11 11:25:43 eric-macbookpro kernel: usb 2-3: usb resume
Feb 11 11:25:43 eric-macbookpro kernel: usb 1-3: usb resume
Feb 11 11:25:43 eric-macbookpro kernel: usb 1-5: usb resume
Feb 11 11:25:43 eric-macbookpro kernel: usb 2-3: Waited 0ms for CONNECT
usb_port_resume() should try to resume the port here, but apparently it fails as well.
check_port_resume_type() called later still finds the port in U3 suspended state (0x0263),
and returns -ENODEV (-19)
Feb 11 11:25:43 eric-macbookpro kernel: usb usb2-port3: status 0000.0263 after resume, -19
Feb 11 11:25:43 eric-macbookpro kernel: usb 2-3: can't resume, status -19
This -19 status forces usb_port_resume() to logically disconnect the port,
and port ends up in polling state (via RxDetect), and into a autosuspend attempt loop:
Feb 11 11:25:43 eric-macbookpro kernel: usb usb2-port3: debounce total 100ms stable 100ms status 0x2e0
Feb 11 11:25:43 eric-macbookpro kernel: hub 2-0:1.0: hub_suspend
Feb 11 11:25:43 eric-macbookpro kernel: usb usb2: bus auto-suspend, wakeup 1
Feb 11 11:25:43 eric-macbookpro kernel: usb usb2: bus suspend fail, err -16
Feb 11 11:25:43 eric-macbookpro kernel: hub 2-0:1.0: hub_resume
Feb 11 11:25:43 eric-macbookpro kernel: hub 2-0:1.0: state 7 ports 4 chg 0000 evt 0000
Feb 11 11:25:43 eric-macbookpro kernel: hub 2-0:1.0: hub_suspend
Feb 11 11:25:43 eric-macbookpro kernel: usb usb2: bus auto-suspend, wakeup 1
Feb 11 11:25:43 eric-macbookpro kernel: usb usb2: bus suspend fail, err -16
Feb 11 11:25:43 eric-macbookpro kernel: hub 2-0:1.0: hub_resume
Feb 11 11:25:43 eric-macbookpro kernel: hub 2-0:1.0: state 7 ports 4 chg 0000 evt 0000
Feb 11 11:25:43 eric-macbookpro kernel: hub 2-0:1.0: hub_suspend
Feb 11 11:25:43 eric-macbookpro kernel: usb usb2: bus auto-suspend, wakeup 1
Feb 11 11:25:43 eric-macbookpro kernel: usb usb2: bus suspend fail, err -16
-Mathias
