Re: [Bug 197863] Thinkpad X240 resume dramatically slower on kernels 4.13+
On Fri, Feb 9, 2018 at 2:43 PM, Markus Demleitner wrote: > On Thu, Feb 08, 2018 at 08:12:06PM +0100, Rafael J. Wysocki wrote: >> On Wednesday, February 7, 2018 11:44:15 PM CET Rafael J. Wysocki wrote: >> > On Mon, Feb 5, 2018 at 6:06 PM, Rafael J. Wysocki >> > wrote: >> > > On 2/5/2018 3:14 PM, Bjørn Mork wrote: >> > >> >> > >> "Rafael J. Wysocki" writes: >> > >>> >> > >>> On 2/4/2018 9:28 PM, Bjørn Mork wrote: >> > >>> >> > But I do wonder if the attached (completely untested!!) patch makes >> > things any better? >> > >>> >> > >>> I don't think so, the macro is needed too. >> > >> >> > >> Doh! Obviously. Don't know how I managed to miss that. >> > >> >> > >>> I'll queue up a full revert of 662591461c4b9a1e3b. >> > >> >> > >> Still with the additional exception for "ec == first_ec"? >> > >> >> > > >> > > No, just a full revert for now. >> > >> > That doesn't work, because we made some changes on top of this commit. >> > >> > I'll send a patch to try tomorrow. >> >> Below is a patch for the mainline (should be applicable to 4.15.y) to test. >> Please let me know if it improves things for you. > > It pretty certainly does (patch applied on top of 4.15.0 from > tarball). Five out of five wakeup cycles were fast, and the cell > modem is still properly initialised -- the message went out via the > resumed modem. OK, let's do it, then. Thanks for testing! -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [Bug 197863] Thinkpad X240 resume dramatically slower on kernels 4.13+
On Thu, Feb 08, 2018 at 08:12:06PM +0100, Rafael J. Wysocki wrote: > On Wednesday, February 7, 2018 11:44:15 PM CET Rafael J. Wysocki wrote: > > On Mon, Feb 5, 2018 at 6:06 PM, Rafael J. Wysocki > > wrote: > > > On 2/5/2018 3:14 PM, Bjørn Mork wrote: > > >> > > >> "Rafael J. Wysocki" writes: > > >>> > > >>> On 2/4/2018 9:28 PM, Bjørn Mork wrote: > > >>> > > But I do wonder if the attached (completely untested!!) patch makes > > things any better? > > >>> > > >>> I don't think so, the macro is needed too. > > >> > > >> Doh! Obviously. Don't know how I managed to miss that. > > >> > > >>> I'll queue up a full revert of 662591461c4b9a1e3b. > > >> > > >> Still with the additional exception for "ec == first_ec"? > > >> > > > > > > No, just a full revert for now. > > > > That doesn't work, because we made some changes on top of this commit. > > > > I'll send a patch to try tomorrow. > > Below is a patch for the mainline (should be applicable to 4.15.y) to test. > Please let me know if it improves things for you. It pretty certainly does (patch applied on top of 4.15.0 from tarball). Five out of five wakeup cycles were fast, and the cell modem is still properly initialised -- the message went out via the resumed modem. Thanks! -- Markus [patch retained for reference:] > > The corresponding fix for -stable would still be a full revert of > 662591461c4b9a1e3b, but it needs to be fixed in the mainline first. > > --- > drivers/acpi/ec.c |6 ++ > 1 file changed, 6 insertions(+) > > Index: linux-pm/drivers/acpi/ec.c > === > --- linux-pm.orig/drivers/acpi/ec.c > +++ linux-pm/drivers/acpi/ec.c > @@ -1927,6 +1927,9 @@ static int acpi_ec_suspend_noirq(struct > ec->reference_count >= 1) > acpi_set_gpe(NULL, ec->gpe, ACPI_GPE_DISABLE); > > + if (acpi_sleep_no_ec_events()) > + acpi_ec_enter_noirq(ec); > + > return 0; > } > > @@ -1934,6 +1937,9 @@ static int acpi_ec_resume_noirq(struct d > { > struct acpi_ec *ec = acpi_driver_data(to_acpi_device(dev)); > > + if (acpi_sleep_no_ec_events()) > + acpi_ec_leave_noirq(ec); > + > if (ec_no_wakeup && test_bit(EC_FLAGS_STARTED, &ec->flags) && > ec->reference_count >= 1) > acpi_set_gpe(NULL, ec->gpe, ACPI_GPE_ENABLE); > -- A: Because it messes up the order in which people normally read text. Q: Why is top-posting such a bad thing? A: Top-posting. Q: What is the most annoying thing in e-mail? -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [Bug 197863] Thinkpad X240 resume dramatically slower on kernels 4.13+
On Mon, Feb 5, 2018 at 6:06 PM, Rafael J. Wysocki wrote: > On 2/5/2018 3:14 PM, Bjørn Mork wrote: >> >> "Rafael J. Wysocki" writes: >>> >>> On 2/4/2018 9:28 PM, Bjørn Mork wrote: >>> But I do wonder if the attached (completely untested!!) patch makes things any better? >>> >>> I don't think so, the macro is needed too. >> >> Doh! Obviously. Don't know how I managed to miss that. >> >>> I'll queue up a full revert of 662591461c4b9a1e3b. >> >> Still with the additional exception for "ec == first_ec"? >> > > No, just a full revert for now. That doesn't work, because we made some changes on top of this commit. I'll send a patch to try tomorrow. Thanks, Rafael -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [Bug 197863] Thinkpad X240 resume dramatically slower on kernels 4.13+
On 2/5/2018 3:14 PM, Bjørn Mork wrote: "Rafael J. Wysocki" writes: On 2/4/2018 9:28 PM, Bjørn Mork wrote: But I do wonder if the attached (completely untested!!) patch makes things any better? I don't think so, the macro is needed too. Doh! Obviously. Don't know how I managed to miss that. I'll queue up a full revert of 662591461c4b9a1e3b. Still with the additional exception for "ec == first_ec"? No, just a full revert for now. The above can be fixed on top of that. Thanks, Rafael -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [Bug 197863] Thinkpad X240 resume dramatically slower on kernels 4.13+
"Rafael J. Wysocki" writes: > On 2/4/2018 9:28 PM, Bjørn Mork wrote: > >> But I do wonder if the attached (completely untested!!) patch makes >> things any better? > > I don't think so, the macro is needed too. Doh! Obviously. Don't know how I managed to miss that. > I'll queue up a full revert of 662591461c4b9a1e3b. Still with the additional exception for "ec == first_ec"? Bjørn -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [Bug 197863] Thinkpad X240 resume dramatically slower on kernels 4.13+
On 2/4/2018 9:28 PM, Bjørn Mork wrote: Greg KH writes: On Sat, Feb 03, 2018 at 07:25:54PM +0100, Markus Demleitner wrote: It's 662591461c4b9a1e3b9b159dbf37648a585ebaae. To my eyes, it even looks plausible that it's causing the problematic behaviour, but since I can't say I understand what I'd be doing if I dabbled with the change, I've refrained from guessing how to fix it. I'm happy to try patches, though. Ok, thanks. I've added the authors of this patch to the email here, perhaps they have an idea of what is going on? This thing made me curious enough to dive into code I don't understand, as I have experienced the annoying crazy fan behaviour in resume a few times on my X1 Carbon 4th gen. Maybe I missed something, but it looks like commit c3a696b6e8f8 ("ACPI / EC: Use busy polling mode when GPE is not enabled") introduced suspend/resume busy polling for the "boot EC" unintentionally? The patch moved acpi_ec_leave_noirq() and acpi_ec_leave_noirq() functions outside the #ifdef CONFIG_PM_SLEEP, so they could be reused while installing handlers. But when doing that the if (ec == first_ec) conditions on suspend/resume were silently dropped. I assume the intention might have been to move those intto acpi_ec_suspend_noirq() and acpi_ec_resume_noirq() instead? But that didn't happen AFAICS. Or did I misunderstand this completely? Not unlikely given that I have zero clue about what this code is doing... But I do wonder if the attached (completely untested!!) patch makes things any better? I don't think so, the macro is needed too. I'll queue up a full revert of 662591461c4b9a1e3b. Thanks, Rafael -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [Bug 197863] Thinkpad X240 resume dramatically slower on kernels 4.13+
Greg KH writes: > On Sat, Feb 03, 2018 at 07:25:54PM +0100, Markus Demleitner wrote: > >> It's 662591461c4b9a1e3b9b159dbf37648a585ebaae. To my eyes, it even >> looks plausible that it's causing the problematic behaviour, but >> since I can't say I understand what I'd be doing if I dabbled with >> the change, I've refrained from guessing how to fix it. >> >> I'm happy to try patches, though. > > Ok, thanks. I've added the authors of this patch to the email here, > perhaps they have an idea of what is going on? This thing made me curious enough to dive into code I don't understand, as I have experienced the annoying crazy fan behaviour in resume a few times on my X1 Carbon 4th gen. Maybe I missed something, but it looks like commit c3a696b6e8f8 ("ACPI / EC: Use busy polling mode when GPE is not enabled") introduced suspend/resume busy polling for the "boot EC" unintentionally? The patch moved acpi_ec_leave_noirq() and acpi_ec_leave_noirq() functions outside the #ifdef CONFIG_PM_SLEEP, so they could be reused while installing handlers. But when doing that the if (ec == first_ec) conditions on suspend/resume were silently dropped. I assume the intention might have been to move those intto acpi_ec_suspend_noirq() and acpi_ec_resume_noirq() instead? But that didn't happen AFAICS. Or did I misunderstand this completely? Not unlikely given that I have zero clue about what this code is doing... But I do wonder if the attached (completely untested!!) patch makes things any better? Bjørn >From 82b8f437a243854a3f1d3c82f85520fd2b71 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B8rn=20Mork?= Date: Sun, 4 Feb 2018 21:15:36 +0100 Subject: [PATCH] Revert "ACPI / EC: Drop EC noirq hooks to fix a regression" MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit This reverts commit 662591461c4b9a1e3b9b159dbf37648a585ebaae and re-introduce the conditions dropped by commit c3a696b6e8f8 ("ACPI / EC: Use busy polling mode when GPE is not enabled") Fixes: c3a696b6e8f8 ("ACPI / EC: Use busy polling mode when GPE is not enabled") Signed-off-by: Bjørn Mork --- drivers/acpi/ec.c | 20 1 file changed, 20 insertions(+) diff --git a/drivers/acpi/ec.c b/drivers/acpi/ec.c index d9f38c645e4a..24a772f66847 100644 --- a/drivers/acpi/ec.c +++ b/drivers/acpi/ec.c @@ -1905,6 +1905,26 @@ int __init acpi_ec_ecdt_probe(void) } #ifdef CONFIG_PM_SLEEP +static int acpi_ec_suspend_noirq(struct device *dev) +{ + struct acpi_ec *ec = + acpi_driver_data(to_acpi_device(dev)); + + if (ec == first_ec) + acpi_ec_enter_noirq(ec); + return 0; +} + +static int acpi_ec_resume_noirq(struct device *dev) +{ + struct acpi_ec *ec = + acpi_driver_data(to_acpi_device(dev)); + + if (ec == first_ec) + acpi_ec_leave_noirq(ec); + return 0; +} + static int acpi_ec_suspend(struct device *dev) { struct acpi_ec *ec = -- 2.11.0
Re: [Bug 197863] Thinkpad X240 resume dramatically slower on kernels 4.13+
On Sat, Feb 03, 2018 at 07:25:54PM +0100, Markus Demleitner wrote: > On Tue, Jan 30, 2018 at 07:32:04AM +0100, Greg KH wrote: > > On Mon, Jan 29, 2018 at 07:21:09PM +0100, Markus Demleitner wrote: > > > A while ago I opened bug #197863 in the kernel bugzilla: > > > > > > https://bugzilla.kernel.org/show_bug.cgi?id=197863 > > > > > > Essentially, xhci_hcd on a resume from RAM takes several seconds on a > > > Thinkpad X240 that is equipped with a Sierra LTE modem after an > > > upgrade to 4.13: > [...] > > > Now, interestingly, there are quick resumes in 4.15.0, too, now and > > > then. In that case, things look pretty much like on 4.12.2. Here's > > > a 4.15.0 fast resume example: > > > > > > [ 873.127570] usb 1-4: device firmware changed > > > [ 873.277351] usb 1-8: reset high-speed USB device number 4 using > > > xhci_hcd > > > [ 873.515141] restoring control ----0101/0/2 > > > [ 873.583238] OOM killer enabled. > > > [ 873.583240] Restarting tasks ... > > > [ 873.583339] usb 1-4: USB disconnect, device number 10 > > > [ 873.586356] done. > > > [ 873.604420] PM: suspend exit > > > [ 873.737283] usb 1-4: new high-speed USB device number 11 using xhci_hcd > > > [ 880.867398] usb 1-4: device descriptor read/64, error -110 > > > [ 881.175558] usb 1-4: New USB device found, idVendor=1199, > > > idProduct=a001 > > > [ 881.175563] usb 1-4: New USB device strings: Mfr=1, Product=2, > > > SerialNumber=3 > > > [ 881.175566] usb 1-4: Product: Sierra Wireless EM7345 4G LTE > > > [ 881.175568] usb 1-4: Manufacturer: Sierra Wireless Inc. > > > [ 881.175570] usb 1-4: SerialNumber: 013937002544516 > > > > > > Any guess what might be behind this? > > > > Any chance you can run 'git bisect' to find the offending commit for > > this issue? > > It's 662591461c4b9a1e3b9b159dbf37648a585ebaae. To my eyes, it even > looks plausible that it's causing the problematic behaviour, but > since I can't say I understand what I'd be doing if I dabbled with > the change, I've refrained from guessing how to fix it. > > I'm happy to try patches, though. Ok, thanks. I've added the authors of this patch to the email here, perhaps they have an idea of what is going on? greg k-h -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [Bug 197863] Thinkpad X240 resume dramatically slower on kernels 4.13+
On Tue, Jan 30, 2018 at 07:32:04AM +0100, Greg KH wrote: > On Mon, Jan 29, 2018 at 07:21:09PM +0100, Markus Demleitner wrote: > > A while ago I opened bug #197863 in the kernel bugzilla: > > > > https://bugzilla.kernel.org/show_bug.cgi?id=197863 > > > > Essentially, xhci_hcd on a resume from RAM takes several seconds on a > > Thinkpad X240 that is equipped with a Sierra LTE modem after an > > upgrade to 4.13: [...] > > Now, interestingly, there are quick resumes in 4.15.0, too, now and > > then. In that case, things look pretty much like on 4.12.2. Here's > > a 4.15.0 fast resume example: > > > > [ 873.127570] usb 1-4: device firmware changed > > [ 873.277351] usb 1-8: reset high-speed USB device number 4 using xhci_hcd > > [ 873.515141] restoring control ----0101/0/2 > > [ 873.583238] OOM killer enabled. > > [ 873.583240] Restarting tasks ... > > [ 873.583339] usb 1-4: USB disconnect, device number 10 > > [ 873.586356] done. > > [ 873.604420] PM: suspend exit > > [ 873.737283] usb 1-4: new high-speed USB device number 11 using xhci_hcd > > [ 880.867398] usb 1-4: device descriptor read/64, error -110 > > [ 881.175558] usb 1-4: New USB device found, idVendor=1199, idProduct=a001 > > [ 881.175563] usb 1-4: New USB device strings: Mfr=1, Product=2, > > SerialNumber=3 > > [ 881.175566] usb 1-4: Product: Sierra Wireless EM7345 4G LTE > > [ 881.175568] usb 1-4: Manufacturer: Sierra Wireless Inc. > > [ 881.175570] usb 1-4: SerialNumber: 013937002544516 > > > > Any guess what might be behind this? > > Any chance you can run 'git bisect' to find the offending commit for > this issue? It's 662591461c4b9a1e3b9b159dbf37648a585ebaae. To my eyes, it even looks plausible that it's causing the problematic behaviour, but since I can't say I understand what I'd be doing if I dabbled with the change, I've refrained from guessing how to fix it. I'm happy to try patches, though. Thanks, Markus -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [Bug 197863] Thinkpad X240 resume dramatically slower on kernels 4.13+
Hi Oliver, On Tue, Jan 30, 2018 at 08:45:17AM +0100, Oliver Neukum wrote: > Am Montag, den 29.01.2018, 19:21 +0100 schrieb Markus Demleitner: > > > > Any guess what might be behind this? > > > have you checked the persist attribute between the versions working > well and working badly? Persist is 1 in both cases. But persist was a good point anyway -- there's *probably* little point having an LTE card persist (I don't think it could keep registered with the mobile network on 5..25 mW), and so I tried echo 0 > /sys/bus/usb/devices/1-4/power/persist before suspending. Doing this three times before a suspend, the box came back three out of three with 4.15.0. Suspending without the intervening write immediately brought back the 10 s timeout. Then again two fast resumes with an echo before it. And another one. So -- I think I have a good workaround for me[1]. I'll try to get myself to git-bisecting the problem, because I see it'd be better if we could figure out why persist hasn't been a problem before 4.13.0 and has been causing the long resume delay from then on. I'm not making actual promises, though (I'm a bit scared of checkout sizes, build times, and lots of reboots; log(n) still rises fairly steeply for low n...) Thanks for providing the useful hint, Markus [1] For anyone who ended up here looking for a solution: I dumped #!/bin/sh case "$1" in suspend|hibernate) echo 0 > /sys/bus/usb/devices/1-4/power/persist ;; esac exit 0 into a file /etc/pm/sleep.d/05sierra (works with pm-utils, probably not with systemd) -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [Bug 197863] Thinkpad X240 resume dramatically slower on kernels 4.13+
Am Montag, den 29.01.2018, 19:21 +0100 schrieb Markus Demleitner: > > Any guess what might be behind this? > Hi, have you checked the persist attribute between the versions working well and working badly? Regards Oliver -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [Bug 197863] Thinkpad X240 resume dramatically slower on kernels 4.13+
On Mon, Jan 29, 2018 at 07:21:09PM +0100, Markus Demleitner wrote: > Hi, > > A while ago I opened bug #197863 in the kernel bugzilla: > > https://bugzilla.kernel.org/show_bug.cgi?id=197863 > > Essentially, xhci_hcd on a resume from RAM takes several seconds on a > Thinkpad X240 that is equipped with a Sierra LTE modem after an > upgrade to 4.13: > > On Mon, Nov 20, 2017 at 11:24:09AM +, bugzilla-dae...@bugzilla.kernel.org > wrote: > > https://bugzilla.kernel.org/show_bug.cgi?id=197863 > > > > --- Comment #2 from Greg Kroah-Hartman (g...@kroah.com) --- > > On Mon, Nov 20, 2017 at 09:02:46AM +, > > bugzilla-dae...@bugzilla.kernel.org > > wrote: > > > I think your speculation is right, the xhci has taken too much time for a > > > reset: > > > [ 39.292052] usb 1-4: reset high-speed USB device number 2 using > > > xhci_hcd > > > [ 45.812046] usb 1-4: device descriptor read/64, error -110 > > > [ 46.262082] usb 1-7: reset full-speed USB device number 3 using > > > xhci_hcd > > > I don't know if it should be reset in this case, let me switch to usb > > > component for suggestion. > > > > All USB bugs should be sent to the linux-usb@vger.kernel.org mailing > > list, and not entered into bugzilla. Please bring this issue up there, > > if it is still a problem in the latest kernel release. > > The trouble persists in 4.15.0, and wakeup keeps being fast in 4.12.X. > > I have just looked at things a bit more closely, and it would seem > the changes are due to the USB subsystem blocking until the (slow) > LTE modem sends an all clear. > > Here's a dmesg excerpt from 4.15.0 slow resume: > > > [ 417.234716] ACPI: Low-level resume complete > ...about 30 lines of non-USB jabber elided here... > [ 419.184328] usb usb1: root hub lost power or was reset > [ 419.184332] usb usb2: root hub lost power or was reset > [ 419.463469] usb 3-1: reset high-speed USB device number 2 using ehci-pci > [ 419.583449] usb 1-8: reset high-speed USB device number 4 using xhci_hcd > [ 419.588769] psmouse serio1: synaptics: queried min coordinates: x > [1232..], y [1216..] > [ 419.821258] restoring control ----0101/0/2 > [ 419.913513] usb 1-4: reset high-speed USB device number 9 using xhci_hcd > ...this is when the system hangs; the screen is on, but now wakeup > actions are executed until... > [ 427.343486] usb 1-4: device descriptor read/64, error -110 > [ 427.662438] OOM killer enabled. > [ 427.662440] Restarting tasks ... done. > [ 427.683062] PM: suspend exit > > If you look at the corresponding sequence in 4.12.2: > > [ 31.678001] usb 1-4: reset high-speed USB device number 2 using xhci_hcd > [ 31.848202] usb 1-4: device firmware changed > [ 31.988048] usb 1-7: reset full-speed USB device number 3 using xhci_hcd > [ 32.159069] PM: resume of devices complete after 1170.527 msecs > [ 32.159546] OOM killer enabled. > [ 32.159548] Restarting tasks ... > [ 32.159650] usb 1-4: USB disconnect, device number 2 > [ 32.162274] done. > [ 32.297920] usb 1-4: new high-speed USB device number 5 using xhci_hcd > [ 32.469119] usb 1-4: New USB device found, idVendor=8087, idProduct=0716 > [ 32.469124] usb 1-4: New USB device strings: Mfr=0, Product=0, > SerialNumber=0 > [ 35.639922] usb 1-4: USB disconnect, device number 5 > [ 38.438173] usb 1-4: new high-speed USB device number 6 using xhci_hcd > [ 38.616527] usb 1-4: New USB device found, idVendor=1199, idProduct=a001 > [ 38.616535] usb 1-4: New USB device strings: Mfr=1, Product=2, > SerialNumber=3 > [ 38.616539] usb 1-4: Product: Sierra Wireless EM7345 4G LTE > [ 38.616543] usb 1-4: Manufacturer: Sierra Wireless Inc. > [ 38.616545] usb 1-4: SerialNumber: 013937002544516 > > ...it seems that the resume of the Sierra card happens > "aynchronously", if you will. In the "slow" cases, I just notice, no > messages about the Sierra Wireless card appear in dmesg, but the > modem still works. > > Now, interestingly, there are quick resumes in 4.15.0, too, now and > then. In that case, things look pretty much like on 4.12.2. Here's > a 4.15.0 fast resume example: > > [ 873.127570] usb 1-4: device firmware changed > [ 873.277351] usb 1-8: reset high-speed USB device number 4 using xhci_hcd > [ 873.515141] restoring control ----0101/0/2 > [ 873.583238] OOM killer enabled. > [ 873.583240] Restarting tasks ... > [ 873.583339] usb 1-4: USB disconnect, device number 10 > [ 873.586356] done. > [ 873.604420] PM: suspend exit > [ 873.737283] usb 1-4: new high-speed USB device number 11 using xhci_hcd > [ 880.867398] usb 1-4: device descriptor read/64, error -110 > [ 881.175558] usb 1-4: New USB device found, idVendor=1199, idProduct=a001 > [ 881.175563] usb 1-4: New USB device strings: Mfr=1, Product=2, > SerialNumber=3 > [ 881.175566] usb 1-4: Product: Sierra Wireless EM7345 4G LTE > [ 881.175568] usb 1-4: Manufacturer: Sierra Wireless Inc. > [ 881.175570] us
Re: [Bug 197863] Thinkpad X240 resume dramatically slower on kernels 4.13+
Hi, A while ago I opened bug #197863 in the kernel bugzilla: https://bugzilla.kernel.org/show_bug.cgi?id=197863 Essentially, xhci_hcd on a resume from RAM takes several seconds on a Thinkpad X240 that is equipped with a Sierra LTE modem after an upgrade to 4.13: On Mon, Nov 20, 2017 at 11:24:09AM +, bugzilla-dae...@bugzilla.kernel.org wrote: > https://bugzilla.kernel.org/show_bug.cgi?id=197863 > > --- Comment #2 from Greg Kroah-Hartman (g...@kroah.com) --- > On Mon, Nov 20, 2017 at 09:02:46AM +, bugzilla-dae...@bugzilla.kernel.org > wrote: > > I think your speculation is right, the xhci has taken too much time for a > > reset: > > [ 39.292052] usb 1-4: reset high-speed USB device number 2 using xhci_hcd > > [ 45.812046] usb 1-4: device descriptor read/64, error -110 > > [ 46.262082] usb 1-7: reset full-speed USB device number 3 using xhci_hcd > > I don't know if it should be reset in this case, let me switch to usb > > component for suggestion. > > All USB bugs should be sent to the linux-usb@vger.kernel.org mailing > list, and not entered into bugzilla. Please bring this issue up there, > if it is still a problem in the latest kernel release. The trouble persists in 4.15.0, and wakeup keeps being fast in 4.12.X. I have just looked at things a bit more closely, and it would seem the changes are due to the USB subsystem blocking until the (slow) LTE modem sends an all clear. Here's a dmesg excerpt from 4.15.0 slow resume: [ 417.234716] ACPI: Low-level resume complete ...about 30 lines of non-USB jabber elided here... [ 419.184328] usb usb1: root hub lost power or was reset [ 419.184332] usb usb2: root hub lost power or was reset [ 419.463469] usb 3-1: reset high-speed USB device number 2 using ehci-pci [ 419.583449] usb 1-8: reset high-speed USB device number 4 using xhci_hcd [ 419.588769] psmouse serio1: synaptics: queried min coordinates: x [1232..], y [1216..] [ 419.821258] restoring control ----0101/0/2 [ 419.913513] usb 1-4: reset high-speed USB device number 9 using xhci_hcd ...this is when the system hangs; the screen is on, but now wakeup actions are executed until... [ 427.343486] usb 1-4: device descriptor read/64, error -110 [ 427.662438] OOM killer enabled. [ 427.662440] Restarting tasks ... done. [ 427.683062] PM: suspend exit If you look at the corresponding sequence in 4.12.2: [ 31.678001] usb 1-4: reset high-speed USB device number 2 using xhci_hcd [ 31.848202] usb 1-4: device firmware changed [ 31.988048] usb 1-7: reset full-speed USB device number 3 using xhci_hcd [ 32.159069] PM: resume of devices complete after 1170.527 msecs [ 32.159546] OOM killer enabled. [ 32.159548] Restarting tasks ... [ 32.159650] usb 1-4: USB disconnect, device number 2 [ 32.162274] done. [ 32.297920] usb 1-4: new high-speed USB device number 5 using xhci_hcd [ 32.469119] usb 1-4: New USB device found, idVendor=8087, idProduct=0716 [ 32.469124] usb 1-4: New USB device strings: Mfr=0, Product=0, SerialNumber=0 [ 35.639922] usb 1-4: USB disconnect, device number 5 [ 38.438173] usb 1-4: new high-speed USB device number 6 using xhci_hcd [ 38.616527] usb 1-4: New USB device found, idVendor=1199, idProduct=a001 [ 38.616535] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3 [ 38.616539] usb 1-4: Product: Sierra Wireless EM7345 4G LTE [ 38.616543] usb 1-4: Manufacturer: Sierra Wireless Inc. [ 38.616545] usb 1-4: SerialNumber: 013937002544516 ...it seems that the resume of the Sierra card happens "aynchronously", if you will. In the "slow" cases, I just notice, no messages about the Sierra Wireless card appear in dmesg, but the modem still works. Now, interestingly, there are quick resumes in 4.15.0, too, now and then. In that case, things look pretty much like on 4.12.2. Here's a 4.15.0 fast resume example: [ 873.127570] usb 1-4: device firmware changed [ 873.277351] usb 1-8: reset high-speed USB device number 4 using xhci_hcd [ 873.515141] restoring control ----0101/0/2 [ 873.583238] OOM killer enabled. [ 873.583240] Restarting tasks ... [ 873.583339] usb 1-4: USB disconnect, device number 10 [ 873.586356] done. [ 873.604420] PM: suspend exit [ 873.737283] usb 1-4: new high-speed USB device number 11 using xhci_hcd [ 880.867398] usb 1-4: device descriptor read/64, error -110 [ 881.175558] usb 1-4: New USB device found, idVendor=1199, idProduct=a001 [ 881.175563] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3 [ 881.175566] usb 1-4: Product: Sierra Wireless EM7345 4G LTE [ 881.175568] usb 1-4: Manufacturer: Sierra Wireless Inc. [ 881.175570] usb 1-4: SerialNumber: 013937002544516 Any guess what might be behind this? Thanks, Markus -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.