Bug#895239: [systemd] suspend works 1st time

Ted To wintrymix at theo.to
Sun Apr 8 18:56:32 BST 2018


Package: systemd
Version: 232-25+deb9u3
Severity: important

--- Please enter the report below this line. ---

Suspend only works first time.  It worked fine on an ancient Acer Aspire
One.  Now on an Acer S7 392, suspend works on its first try but
afterwards fails.  Currently running the backports kernel but didn't
work with stable either.

$ sudo journalctl -u suspend.target
[sudo] password for tct:
-- Logs begin at Sun 2018-04-08 12:17:50 EDT, end at Sun 2018-04-08
13:49:23 EDT. --
Apr 08 12:48:07 okeeffe systemd[1]: Reached target Suspend.
Apr 08 12:48:07 okeeffe systemd[1]: suspend.target: Unit is bound to
inactive unit systemd-suspend.service
Apr 08 12:48:07 okeeffe systemd[1]: Stopped target Suspend.
Apr 08 12:48:09 okeeffe systemd[1]: Reached target Suspend.
Apr 08 12:48:09 okeeffe systemd[1]: suspend.target: Unit is bound to
inactive unit systemd-suspend.service
Apr 08 12:48:09 okeeffe systemd[1]: Stopped target Suspend.
Apr 08 13:02:36 okeeffe systemd[1]: Reached target Suspend.
Apr 08 13:02:36 okeeffe systemd[1]: suspend.target: Unit is bound to
inactive unit systemd-suspend.service
Apr 08 13:02:36 okeeffe systemd[1]: Stopped target Suspend.
Apr 08 13:28:28 okeeffe systemd[1]: Reached target Suspend.
Apr 08 13:28:28 okeeffe systemd[1]: suspend.target: Unit is bound to
inactive unit systemd-suspend.service
Apr 08 13:28:28 okeeffe systemd[1]: Stopped target Suspend.
Apr 08 13:29:24 okeeffe systemd[1]: Reached target Suspend.
Apr 08 13:29:24 okeeffe systemd[1]: suspend.target: Unit is bound to
inactive unit systemd-suspend.service
Apr 08 13:29:24 okeeffe systemd[1]: Stopped target Suspend.

and relevant portions of syslog:

Apr  8 13:50:09 debian NetworkManager[533]: <info>  [1523209809.4718]
manager: sleep requested (sleeping: no  enabled: yes)
Apr  8 13:50:09 debian NetworkManager[533]: <info>  [1523209809.4719]
manager: sleeping...
Apr  8 13:50:09 debian NetworkManager[533]: <info>  [1523209809.4720]
manager: NetworkManager state is now ASLEEP
Apr  8 13:50:09 debian NetworkManager[533]: <info>  [1523209809.4724]
device (wlp1s0): state change: activated -> deactivating (reason
'sleeping') [100 110 37]
Apr  8 13:50:09 debian dbus[521]: [system] Activating via systemd:
service name='org.freedesktop.nm_dispatcher'
unit='dbus-org.freedesktop.nm-dispatcher.service'
Apr  8 13:50:09 debian NetworkManager[533]: <info>  [1523209809.4770]
device (wlp1s0): state change: deactivating -> disconnected (reason
'sleeping') [110 30 37]
Apr  8 13:50:09 debian systemd[1]: Starting Network Manager Script
Dispatcher Service...
Apr  8 13:50:09 debian avahi-daemon[519]: Withdrawing address record for
fd21:9228:e650::b2e on wlp1s0.
Apr  8 13:50:09 debian avahi-daemon[519]: Withdrawing address record for
2601:14d:4101:380b::b2e on wlp1s0.
Apr  8 13:50:09 debian avahi-daemon[519]: Withdrawing address record for
fd21:9228:e650:0:889d:b57e:e0cc:c4b2 on wlp1s0.
Apr  8 13:50:09 debian avahi-daemon[519]: Withdrawing address record for
fd21:9228:e650:0:5e51:4fff:fef2:d5b9 on wlp1s0.
Apr  8 13:50:09 debian avahi-daemon[519]: Leaving mDNS multicast group
on interface wlp1s0.IPv6 with address fd21:9228:e650:0:5e51:4fff:fef2:d5b9.
Apr  8 13:50:09 debian avahi-daemon[519]: Joining mDNS multicast group
on interface wlp1s0.IPv6 with address
2601:14d:4101:380b:889d:b57e:e0cc:c4b2.
Apr  8 13:50:09 debian avahi-daemon[519]: Withdrawing address record for
2601:14d:4101:380b:889d:b57e:e0cc:c4b2 on wlp1s0.
Apr  8 13:50:09 debian avahi-daemon[519]: Leaving mDNS multicast group
on interface wlp1s0.IPv6 with address
2601:14d:4101:380b:889d:b57e:e0cc:c4b2.
Apr  8 13:50:09 debian avahi-daemon[519]: Joining mDNS multicast group
on interface wlp1s0.IPv6 with address
2601:14d:4101:380b:5e51:4fff:fef2:d5b9.
Apr  8 13:50:09 debian avahi-daemon[519]: Withdrawing address record for
2601:14d:4101:380b:5e51:4fff:fef2:d5b9 on wlp1s0.
Apr  8 13:50:09 debian avahi-daemon[519]: Leaving mDNS multicast group
on interface wlp1s0.IPv6 with address
2601:14d:4101:380b:5e51:4fff:fef2:d5b9.
Apr  8 13:50:09 debian avahi-daemon[519]: Joining mDNS multicast group
on interface wlp1s0.IPv6 with address fe80::5e51:4fff:fef2:d5b9.
Apr  8 13:50:09 debian avahi-daemon[519]: Registering new address record
for fe80::5e51:4fff:fef2:d5b9 on wlp1s0.*.
Apr  8 13:50:09 debian avahi-daemon[519]: Withdrawing address record for
fe80::5e51:4fff:fef2:d5b9 on wlp1s0.
Apr  8 13:50:09 debian avahi-daemon[519]: Leaving mDNS multicast group
on interface wlp1s0.IPv6 with address fe80::5e51:4fff:fef2:d5b9.
Apr  8 13:50:09 debian avahi-daemon[519]: Interface wlp1s0.IPv6 no
longer relevant for mDNS.
Apr  8 13:50:09 debian dbus[521]: [system] Successfully activated
service 'org.freedesktop.nm_dispatcher'
Apr  8 13:50:09 debian systemd[1]: Started Network Manager Script
Dispatcher Service.
Apr  8 13:50:09 debian nm-dispatcher: req:1 'connectivity-change': new
request (2 scripts)
Apr  8 13:50:09 debian nm-dispatcher: req:1 'connectivity-change': start
running ordered scripts...
Apr  8 13:50:09 debian NetworkManager[533]: <info>  [1523209809.5006]
dhcp4 (wlp1s0): canceled DHCP transaction, DHCP client pid 12108
Apr  8 13:50:09 debian NetworkManager[533]: <info>  [1523209809.5006]
dhcp4 (wlp1s0): state changed bound -> done
Apr  8 13:50:09 debian NetworkManager[533]: <info>  [1523209809.5017]
dhcp6 (wlp1s0): canceled DHCP transaction, DHCP client pid 12191
Apr  8 13:50:09 debian NetworkManager[533]: <info>  [1523209809.5017]
dhcp6 (wlp1s0): state changed bound -> done
Apr  8 13:50:09 debian kernel: [ 4516.205710] wlp1s0: deauthenticating
from c0:4a:00:40:90:f9 by local choice (Reason: 3=DEAUTH_LEAVING)
Apr  8 13:50:09 debian avahi-daemon[519]: Withdrawing address record for
192.168.2.55 on wlp1s0.
Apr  8 13:50:09 debian avahi-daemon[519]: Leaving mDNS multicast group
on interface wlp1s0.IPv4 with address 192.168.2.55.
Apr  8 13:50:09 debian wpa_supplicant[712]: wlp1s0:
CTRL-EVENT-DISCONNECTED bssid=c0:4a:00:40:90:f9 reason=3 locally_generated=1
Apr  8 13:50:09 debian kernel: [ 4516.212385] wlp1s0: failed to remove
key (1, ff:ff:ff:ff:ff:ff) from hardware (-22)
Apr  8 13:50:09 debian kernel: [ 4516.212419] wlp1s0: failed to remove
key (2, ff:ff:ff:ff:ff:ff) from hardware (-22)
Apr  8 13:50:09 debian avahi-daemon[519]: Interface wlp1s0.IPv4 no
longer relevant for mDNS.
Apr  8 13:50:09 debian NetworkManager[533]: <info>  [1523209809.5136]
device (wlp1s0): set-hw-addr: set MAC address to 52:15:36:1B:3F:83
(scanning)
Apr  8 13:50:09 debian kernel: [ 4516.215964] IPv6: ADDRCONF(NETDEV_UP):
wlp1s0: link is not ready
Apr  8 13:50:09 debian nm-dispatcher: req:2 'down' [wlp1s0]: new request
(2 scripts)
Apr  8 13:50:09 debian NetworkManager[533]: <warn>  [1523209809.5166]
sup-iface[0x55fee2d9b460,wlp1s0]: connection disconnected (reason -3)
Apr  8 13:50:09 debian nm-dispatcher: req:2 'down' [wlp1s0]: start
running ordered scripts...
Apr  8 13:50:09 debian NetworkManager[533]: <info>  [1523209809.5167]
device (wlp1s0): supplicant interface state: completed -> disconnected
Apr  8 13:50:09 debian NetworkManager[533]: <info>  [1523209809.5172]
device (wlp1s0): state change: disconnected -> unmanaged (reason
'sleeping') [30 10 37]
Apr  8 13:50:09 debian wpa_supplicant[712]: p2p-dev-wlp1s0:
CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
Apr  8 13:50:09 debian NetworkManager[533]: <info>  [1523209809.5204]
device (wlp1s0): set-hw-addr: reset MAC address to 5C:51:4F:F2:D5:B9
(unmanage)
Apr  8 13:50:09 debian wpa_supplicant[712]: nl80211: deinit
ifname=p2p-dev-wlp1s0 disabled_11b_rates=0
Apr  8 13:50:09 debian systemd[1]: Reached target Sleep.
Apr  8 13:50:09 debian systemd[1]: Starting Suspend...
Apr  8 13:50:09 debian systemd-sleep[16727]: Suspending system...
Apr  8 13:50:09 debian kernel: [ 4516.231030] PM: suspend entry (deep)
Apr  8 13:50:09 debian kernel: [ 4516.231032] PM: Syncing filesystems
... done.
Apr  8 13:50:09 debian kernel: [ 4516.235439] (NULL device *): firmware:
direct-loading firmware iwlwifi-7260-17.ucode
Apr  8 13:50:09 debian kernel: [ 4516.235448] Freezing user space
processes ... (elapsed 0.015 seconds) done.
Apr  8 13:50:09 debian kernel: [ 4516.250494] OOM killer disabled.
Apr  8 13:50:09 debian kernel: [ 4516.250495] Freezing remaining
freezable tasks ... (elapsed 0.001 seconds) done.
Apr  8 13:50:09 debian kernel: [ 4516.251840] Suspending console(s) (use
no_console_suspend to debug)
Apr  8 13:50:09 debian kernel: [ 4516.252327] sd 0:0:0:0: [sda]
Synchronizing SCSI cache
Apr  8 13:50:09 debian kernel: [ 4516.253272] sd 0:0:0:0: [sda] Stopping
disk
Apr  8 13:50:09 debian kernel: [ 4516.326382] tpm tpm0: Error (28)
sending savestate before suspend
Apr  8 13:50:09 debian kernel: [ 4516.326394] __pnp_bus_suspend():
tpm_pm_suspend+0x0/0x170 returns 28
Apr  8 13:50:09 debian kernel: [ 4516.326398] dpm_run_callback():
pnp_bus_suspend+0x0/0x20 returns 28
Apr  8 13:50:09 debian kernel: [ 4516.326401] PM: Device 00:04 failed to
suspend: error 28
Apr  8 13:50:09 debian kernel: [ 4516.330724] PM: Some devices failed to
suspend, or early wake event detected
Apr  8 13:50:09 debian kernel: [ 4516.332039] sd 0:0:0:0: [sda] Starting
disk
Apr  8 13:50:09 debian kernel: [ 4516.577458] OOM killer enabled.
Apr  8 13:50:09 debian kernel: [ 4516.577459] Restarting tasks ... done.
Apr  8 13:50:09 debian kernel: [ 4516.580018] PM: suspend exit
Apr  8 13:50:09 debian systemd-sleep[16727]: System resumed.
Apr  8 13:50:09 debian systemd[1]: Started Suspend.
Apr  8 13:50:09 debian systemd[1]: sleep.target: Unit not needed
anymore. Stopping.
Apr  8 13:50:09 debian systemd[1]: Stopped target Sleep.
Apr  8 13:50:09 debian systemd[1]: Reached target Suspend.
Apr  8 13:50:09 debian systemd[1]: suspend.target: Unit is bound to
inactive unit systemd-suspend.service. Stopping, too.
Apr  8 13:50:09 debian systemd[1]: Stopped target Suspend.


--- System information. ---
Architecture: Kernel:       Linux 4.14.0-0.bpo.3-amd64

Debian Release: 9.4
  500 stable-updates  deb.debian.org   500 stable
repository.spotify.com   500 stable          deb.debian.org   100
stretch-backports deb.debian.org
--- Package information. ---
Depends                              (Version) | Installed
==============================================-+-============================
libacl1                          (>= 2.2.51-8) | 2.2.52-3+b1
libapparmor1                 (>= 2.9.0-3+exp2) | 2.11.0-3+deb9u2
libaudit1                         (>= 1:2.2.1) | 1:2.6.7-2
libblkid1                          (>= 2.19.1) | 2.29.2-1+deb9u1
libc6                                (>= 2.17) | libcap2
           (>= 1:2.10) | libcryptsetup4                    (>= 2:1.4.3)
| libgcrypt20                         (>= 1.7.0) | libgpg-error0
               (>= 1.14) | libidn11                             (>=
1.13) | libip4tc0          (>= 1.6.0+snapshot20161117) | libkmod2
                       (>= 5~) | liblz4-1                         (>=
0.0~r127) | liblzma5              (>= 5.1.1alpha+20120614) | libmount1
                       (>= 2.26.2) | libpam0g
(>= 0.99.7.1) | libseccomp2                         (>= 2.3.1) |
libselinux1                         (>= 2.1.9) | libsystemd0
     (= 232-25+deb9u3) | util-linux                         (>= 2.27.1)
| mount                                (>= 2.26) | adduser
                         | procps                                         |

Package Status       (Version) | Installed
==============================-+-===========
udev                           | 232-25+deb9u3
dracut                         | initramfs-tools                | 0.130


Recommends          (Version) | Installed
=============================-+-===========
libpam-systemd                | 232-25+deb9u3
dbus                          | 1.10.26-0+deb9u1


Suggests               (Version) | Installed
================================-+-===========
systemd-ui                       | systemd-container                |
policykit-1                      | 0.105-18



--- Output from package bug script ---



More information about the Pkg-systemd-maintainers mailing list