You are not logged in.

#1 2015-05-31 19:11:49

jlindgren
Member
Registered: 2011-02-27
Posts: 256

[SOLVED] Slow suspend with systemd 220

I have my laptop configured to suspend when the power button is pressed ("HandlePowerKey=suspend" in /etc/systemd/logind.conf).  This was working fine up to systemd 219.  After updating to version 220, I am seeing a 5 second delay between the time I press the power button and the time the system suspends.  It's not a complete hang; the whole system (mouse, keyboard, XFCE desktop) is still usable for those 5 seconds.

Oddly, "systemctl suspend" still suspends the system immediately.

The system log (journalctl) from 219:

May 31 14:41:45 pandorica systemd-logind[202]: Power key pressed.
May 31 14:41:45 pandorica systemd-logind[202]: Suspending...
May 31 14:41:45 pandorica NetworkManager[228]: <info>  sleep requested (sleeping: no  enabled: yes)
May 31 14:41:45 pandorica NetworkManager[228]: <info>  sleeping...
May 31 14:41:45 pandorica NetworkManager[228]: <info>  (enp12s0): device state change: unavailable -> unmanaged (reason 'sleeping') [20 10 37]
May 31 14:41:45 pandorica NetworkManager[228]: <info>  (wlp2s0): device state change: activated -> unmanaged (reason 'sleeping') [100 10 37]
May 31 14:41:45 pandorica NetworkManager[228]: <info>  (wlp2s0): deactivating device (reason 'sleeping') [37]
May 31 14:41:45 pandorica kernel: IPv6: ADDRCONF(NETDEV_UP): enp12s0: link is not ready
May 31 14:41:45 pandorica NetworkManager[228]: <info>  (wlp2s0): canceled DHCP transaction, DHCP client pid 402
May 31 14:41:45 pandorica NetworkManager[228]: <info>  (wlp2s0): DHCPv4 state changed bound -> done
May 31 14:41:45 pandorica kernel: wlp2s0: deauthenticating from 74:9d:dc:00:6d:f9 by local choice (Reason: 3=DEAUTH_LEAVING)
May 31 14:41:45 pandorica kernel: cfg80211: Calling CRDA for country: US
May 31 14:41:45 pandorica NetworkManager[228]: <info>  NetworkManager state is now ASLEEP
May 31 14:41:45 pandorica kernel: IPv6: ADDRCONF(NETDEV_UP): wlp2s0: link is not ready
May 31 14:41:45 pandorica systemd[1]: Reached target Sleep.
May 31 14:41:45 pandorica systemd[1]: Starting Sleep.
May 31 14:41:45 pandorica systemd[1]: Starting Suspend...
May 31 14:41:45 pandorica systemd-sleep[494]: Suspending system...

And from 220:

May 31 14:39:45 pandorica systemd-logind[227]: Power key pressed.
May 31 14:39:45 pandorica systemd-logind[227]: Suspending...
May 31 14:39:45 pandorica NetworkManager[203]: <info>  sleep requested (sleeping: no  enabled: yes)
May 31 14:39:45 pandorica NetworkManager[203]: <info>  sleeping...
May 31 14:39:45 pandorica NetworkManager[203]: <info>  (enp12s0): device state change: unavailable -> unmanaged (reason 'sleeping') [20 10 37]
May 31 14:39:45 pandorica NetworkManager[203]: <info>  (wlp2s0): device state change: activated -> unmanaged (reason 'sleeping') [100 10 37]
May 31 14:39:45 pandorica NetworkManager[203]: <info>  (wlp2s0): deactivating device (reason 'sleeping') [37]
May 31 14:39:45 pandorica kernel: IPv6: ADDRCONF(NETDEV_UP): enp12s0: link is not ready
May 31 14:39:45 pandorica NetworkManager[203]: <info>  (wlp2s0): canceled DHCP transaction, DHCP client pid 639
May 31 14:39:45 pandorica NetworkManager[203]: <info>  (wlp2s0): DHCPv4 state changed bound -> done
May 31 14:39:45 pandorica avahi-daemon[692]: Withdrawing address record for 2602:306:335d:c680:6267:20ff:fe7b:acfc on wlp2s0.
May 31 14:39:45 pandorica avahi-daemon[692]: Registering new address record for fe80::6267:20ff:fe7b:acfc on wlp2s0.*.
May 31 14:39:45 pandorica avahi-daemon[692]: Withdrawing address record for fe80::6267:20ff:fe7b:acfc on wlp2s0.
May 31 14:39:45 pandorica avahi-daemon[692]: Withdrawing address record for 192.168.1.66 on wlp2s0.
May 31 14:39:45 pandorica avahi-daemon[692]: Leaving mDNS multicast group on interface wlp2s0.IPv4 with address 192.168.1.66.
May 31 14:39:45 pandorica kernel: wlp2s0: deauthenticating from 74:9d:dc:00:6d:f9 by local choice (Reason: 3=DEAUTH_LEAVING)
May 31 14:39:45 pandorica avahi-daemon[692]: Interface wlp2s0.IPv4 no longer relevant for mDNS.
May 31 14:39:45 pandorica kernel: cfg80211: Calling CRDA to update world regulatory domain
May 31 14:39:45 pandorica NetworkManager[203]: <info>  NetworkManager state is now ASLEEP
May 31 14:39:45 pandorica kernel: IPv6: ADDRCONF(NETDEV_UP): wlp2s0: link is not ready
May 31 14:39:45 pandorica dbus[204]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
May 31 14:39:45 pandorica systemd[1]: org.cups.cupsd.socket: Cannot add dependency job, ignoring: Unit org.cups.cupsd.socket failed to load: No such file or directory.
May 31 14:39:45 pandorica systemd[1]: Starting Network Manager Script Dispatcher Service...
May 31 14:39:45 pandorica dbus[204]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
May 31 14:39:45 pandorica systemd[1]: Started Network Manager Script Dispatcher Service.
May 31 14:39:50 pandorica systemd[1]: Reached target Sleep.
May 31 14:39:50 pandorica systemd[1]: Starting Sleep.
May 31 14:39:50 pandorica systemd[1]: Starting Suspend...
May 31 14:39:50 pandorica systemd-sleep[756]: Suspending system...

So from the previous log message, 5 seconds elapsed before "Reached target Sleep", but there is nothing in the log to indicate what caused the delay.  How would I go about debugging this?

Last edited by jlindgren (2015-06-26 23:30:56)

Offline

#2 2015-06-01 06:05:22

mauritiusdadd
Member
From: Benevento, Italy
Registered: 2013-10-27
Posts: 776

Re: [SOLVED] Slow suspend with systemd 220

Same behaviour here. The culprit seems to be NetworManager, in fact if you stop its service

systemctl stop NetworkManager

then the machine sleeps almost instantly.


About me - github

-- When you have eliminated the impossible, whatever remains, however improbable, must be the truth -- Spock | Sherlock Holmes

Offline

#3 2015-06-24 23:56:34

jlindgren
Member
Registered: 2011-02-27
Posts: 256

Re: [SOLVED] Slow suspend with systemd 220

Offline

Board footer

Powered by FluxBB