On Mon, Feb 4, 2019 at 8:12 AM Eric Blau <eblau@xxxxxxxxx> wrote: > > On Mon, Feb 4, 2019 at 4:31 AM Mathias Nyman > <mathias.nyman@xxxxxxxxxxxxxxx> wrote: > > > > On 03.02.2019 04:08, Eric Blau wrote: > > > > > > I finally was able to complete the bisect on this issue. It seems that > > > this commit introduced the regression on my MacBook Pro: > > > > > > cc8b329fef53c74a4abf98b0755b3832d572d6ce is the first bad commit > > > commit cc8b329fef53c74a4abf98b0755b3832d572d6ce > > > Author: Mathias Nyman <mathias.nyman@xxxxxxxxxxxxxxx> > > > Date: Thu Nov 15 11:38:41 2018 +0200 > > > > > > usb: xhci: Prevent bus suspend if a port connect change or polling > > > state is detected > > > > > > commit 2f31a67f01a8beb22cae754c53522cb61a005750 upstream. > > > > > > > > > > There's an additional fix for that patch, in 4.19 stable: > > > > commit e13bfb357f5bc04f9e7ccff7d07770388062a8cc > > Author: Mathias Nyman <mathias.nyman@xxxxxxxxxxxxxxx> > > Date: Fri Dec 14 10:54:43 2018 +0200 > > > > xhci: Don't prevent USB2 bus suspend in state check intended for USB3 only > > > > commit 45f750c16cae3625014c14c77bd9005eda975d35 upstream. > > > > If you already have that fix then one of the USB ports may be in a odd state when suspending > > > > Does adding dynamic debug for xhci_hub_control show any messages when suspending? > > > > mount -t debugfs none /sys/kernel/debug > > echo -n 'func xhci_bus_suspend =p' > /sys/kernel/debug/dynamic_debug/control > > Hi Mathias, > > I see this behavior even in 4.20.6. With the above commit reverted, my > laptop suspends and resumes properly again and I don't see the high > CPU usage of the mentioned kernel threads. > > When I suspend with the dynamic debugging enabled on 4.20.6, I see a > flood of xhci_hcd messages like the following: > > Feb 04 08:06:44 eric-macbookpro kernel: xhci_hcd 0000:00:14.0: Bus > suspend bailout, port in polling > Feb 04 08:06:44 eric-macbookpro kernel: xhci_hcd 0000:00:14.0: Bus > suspend bailout, port in polling > Feb 04 08:06:44 eric-macbookpro kernel: xhci_hcd 0000:00:14.0: Bus > suspend bailout, port in polling > Feb 04 08:06:44 eric-macbookpro kernel: xhci_hcd 0000:00:14.0: Bus > suspend bailout, port in polling > > There are so many of them that systemd-journald reports messages are > lost too. From a bit earlier: > > Feb 04 08:06:31 eric-macbookpro systemd-journald[1132]: Missed 7 kernel messages > Feb 04 08:06:31 eric-macbookpro kernel: xhci_hcd 0000:00:14.0: Bus > suspend bailout, port in polling > Feb 04 08:06:31 eric-macbookpro systemd-journald[1132]: Missed 32 > kernel messages > Feb 04 08:06:31 eric-macbookpro kernel: xhci_hcd 0000:00:14.0: Bus > suspend bailout, port in polling > Feb 04 08:06:31 eric-macbookpro systemd-journald[1132]: Missed 27 > kernel messages > Feb 04 08:06:31 eric-macbookpro kernel: xhci_hcd 0000:00:14.0: Bus > suspend bailout, port in polling > Feb 04 08:06:31 eric-macbookpro systemd-journald[1132]: Missed 37 > kernel messages > > then the suspend continues and fails: > > Feb 04 08:06:46 eric-macbookpro kernel: done. > Feb 04 08:06:46 eric-macbookpro kernel: Freezing user space processes > ... (elapsed 0.002 seconds) done. > Feb 04 08:06:46 eric-macbookpro kernel: OOM killer disabled. > Feb 04 08:06:46 eric-macbookpro kernel: Freezing remaining freezable > tasks ... (elapsed 0.001 seconds) done. > Feb 04 08:06:46 eric-macbookpro kernel: printk: Suspending console(s) > (use no_console_suspend to debug) > Feb 04 08:06:46 eric-macbookpro kernel: xhci_hcd 0000:00:14.0: Bus > suspend bailout, port in polling > Feb 04 08:06:46 eric-macbookpro kernel: dpm_run_callback(): > usb_dev_suspend+0x0/0x10 returns -16 > Feb 04 08:06:46 eric-macbookpro kernel: PM: Device usb2 failed to > suspend async: error -16 > Feb 04 08:06:46 eric-macbookpro kernel: sd 0:0:0:0: [sda] > Synchronizing SCSI cache > Feb 04 08:06:46 eric-macbookpro kernel: sd 0:0:0:0: [sda] Stopping disk > Feb 04 08:06:46 eric-macbookpro kernel: PM: Some devices failed to > suspend, or early wake event detected > Feb 04 08:06:46 eric-macbookpro kernel: pci 0000:02:00.0: Refused to > change power state, currently in D3 BTW, when I see the CPU spinning at 100% for one kworker and ksoftirqd thread after a bad suspend attempt, those same messages are being emitted rapidly: PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 1132 root 20 0 698936 281144 279544 R 94.4 3.5 0:53.27 systemd-journal 42 root 20 0 0 0 0 R 74.1 0.0 0:37.59 kworker/2:1+pm 28 root 20 0 0 0 0 R 25.9 0.0 0:13.50 ksoftirqd/2 Feb 04 08:17:01 eric-macbookpro kernel: xhci_hcd 0000:00:14.0: Bus suspend bailout, port in polling Feb 04 08:17:01 eric-macbookpro systemd-journald[22105]: Missed 2 kernel messages Feb 04 08:17:01 eric-macbookpro kernel: xhci_hcd 0000:00:14.0: Bus suspend bailout, port in polling Feb 04 08:17:01 eric-macbookpro systemd-journald[22105]: Missed 2 kernel messages Feb 04 08:17:01 eric-macbookpro kernel: xhci_hcd 0000:00:14.0: Bus suspend bailout, port in polling Feb 04 08:17:01 eric-macbookpro systemd-journald[22105]: Missed 3 kernel messages -Eric
