Bug 861194

Summary: suspend is slow on lenovo x201 when triggered by laptop lid
Product: [Fedora] Fedora Reporter: J. Bruce Fields <bfields>
Component: systemdAssignee: systemd-maint
Status: CLOSED WORKSFORME QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 18CC: johannbg, lnykryn, metherid, msekleta, notting, plautrba, systemd-maint, vpavlin
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-01-15 23:04:33 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
/var/log/messages none

Description J. Bruce Fields 2012-09-27 19:01:59 UTC
Description of problem: It takes an unexpectedly long time for my x201 running Fedora 18 to suspend after I close the lid.

Version-Release number of selected component (if applicable):

I'm using the live image downloaded from 
http://adamwill.fedorapeople.org/graphics_test_week_20120924/20120924-test_days-x86_64.iso.  Kernel 3.6.0-0.rc7.git0.1.fc18.x86_64, systemd --version reports "systemd 188".  (Assignment to systemd component is a wild guess, apologies.)

How reproducible:

Boot the live cd, log in, put the laptop lid down.  Measure the time between when the laptop lid latches and the moon-shaped LED turns on.

Actual results: Time to suspend is anywhere from 10 to 40 seconds.


Expected results: Time to suspend is 1-2 seconds.  (That's what I get with Fedora 17.  It's also what I get on Fedora 18 if I suspend using the system menu or pm-suspend from the commandline.)


Additional info: Also, under Fedora 17 the moon-shaped indicator LED blinks while the laptop is going into suspend, which gives useful feedback telling me the laptop is trying to suspend.  Under Fedora 18 it stays black.

Comment 1 J. Bruce Fields 2012-09-27 19:06:22 UTC
Created attachment 618242 [details]
/var/log/messages

/var/log/messages attached.  An example of a problem suspend starts at 14:54:52; most of the delay is here:

Sep 27 14:54:52 localhost systemd-logind[616]: Lid closed.
Sep 27 14:55:17 localhost dbus-daemon[622]: dbus[622]: [system] Rejected send message, 2 matched rules; type="error", sender=":1.1" (uid=0 pid=616 comm="/usr/lib/systemd/systemd-logind ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.NoReply" requested_reply="0" destination=":1.189" (uid=42 pid=4862 comm="/usr/libexec/gnome-settings-daemon ")
Sep 27 14:55:17 localhost dbus[622]: [system] Rejected send message, 2 matched rules; type="error", sender=":1.1" (uid=0 pid=616 comm="/usr/lib/systemd/systemd-logind ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.NoReply" requested_reply="0" destination=":1.189" (uid=42 pid=4862 comm="/usr/libexec/gnome-settings-daemon ")
Sep 27 14:55:42 localhost dbus-daemon[622]: dbus[622]: [system] Rejected send message, 2 matched rules; type="error", sender=":1.1" (uid=0 pid=616 comm="/usr/lib/systemd/systemd-logind ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.NoReply" requested_reply="0" destination=":1.157" (uid=1001 pid=4372 comm="/usr/libexec/gnome-settings-daemon ")
Sep 27 14:55:42 localhost dbus[622]: [system] Rejected send message, 2 matched rules; type="error", sender=":1.1" (uid=0 pid=616 comm="/usr/lib/systemd/systemd-logind ") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.NoReply" requested_reply="0" destination=":1.157" (uid=1001 pid=4372 comm="/usr/libexec/gnome-settings-daemon ")
Sep 27 14:55:42 localhost dbus-daemon[622]: dbus[622]: [system] Rejected send message, 2 matched rules; type="method_return", sender=":1.1" (uid=0 pid=616 comm="/usr/lib/systemd/systemd-logind ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.100" (uid=1000 pid=3569 comm="/usr/libexec/gnome-settings-daemon ")
Sep 27 14:55:42 localhost dbus[622]: [system] Rejected send message, 2 matched rules; type="method_return", sender=":1.1" (uid=0 pid=616 comm="/usr/lib/systemd/systemd-logind ") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.100" (uid=1000 pid=3569 comm="/usr/libexec/gnome-settings-daemon ")
Sep 27 14:55:42 localhost systemd-sleep[7687]: Suspending system...

Note 50 seconds pass getting to this point.  Then:

Sep 27 14:55:42 localhost kernel: [ 4227.552383] PM: Syncing filesystems ... done.
Sep 27 14:55:42 localhost gdm-autologin][3377]: AccountsService-DEBUG(+): ActUserManager: Found x11 display of session '7': :2
Sep 27 14:55:42 localhost gdm-password][4172]: AccountsService-DEBUG(+): ActUserManager: Found x11 display of session '7': :2
Sep 27 14:55:42 localhost gdm-autologin][3377]: AccountsService-DEBUG(+): ActUserManager: ignoring tty session '3' since it's not graphical: Success
Sep 27 14:55:42 localhost gdm-password][4172]: AccountsService-DEBUG(+): ActUserManager: ignoring tty session '3' since it's not graphical: Success
Sep 27 14:55:50 localhost kernel: [ 4227.787383] Freezing user space processes ... (elapsed 0.01 seconds) done.
Sep 27 14:55:50 localhost kernel: [ 4227.799372] Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.

And everything else happens with a second.

Comment 2 Lennart Poettering 2013-01-14 19:44:53 UTC
Does this problem still exist on current F18?

Comment 3 J. Bruce Fields 2013-01-15 02:38:17 UTC
I tried booting from https://dl.fedoraproject.org/pub/alt/stage/18-RC4/Live/x86_64/Fedora-18-x86_64-Live-Desktop.iso but am having other problems (varrious errors doing graphical login, lots of "SQUASHFS error: Unable to read data cache entry" if I try to log in to text console).  I'll try to find time to investigate further later in the week.  I did check the sha256sum (dd if=/dev/sdd bs=1M count=916|sha256sum) and it was correct, so I don't think it's a bad usb stick.

That said: suspending by closing laptop lid while on login screen takes less than a second.

Not sure if that'll be representative of behavior while logged in to a correctly working system, though.

Comment 4 Lennart Poettering 2013-01-15 23:04:33 UTC
(In reply to comment #3)
> I tried booting from
> https://dl.fedoraproject.org/pub/alt/stage/18-RC4/Live/x86_64/Fedora-18-
> x86_64-Live-Desktop.iso but am having other problems (varrious errors doing
> graphical login, lots of "SQUASHFS error: Unable to read data cache entry"
> if I try to log in to text console).  I'll try to find time to investigate
> further later in the week.  I did check the sha256sum (dd if=/dev/sdd bs=1M
> count=916|sha256sum) and it was correct, so I don't think it's a bad usb
> stick.
> 
> That said: suspending by closing laptop lid while on login screen takes less
> than a second.

Ah, OK, so the issue this bug report is about is fixed? Awesome, closing this then. Feel free to reopen if the issue resurfaces.

Please file separate bugs for the squashfs issue, but then again, F18 is now officially out, might make sense to try the final images before filing a bug.