'systemd-sleep suspend' hung after an abortive suspend/resume

[TJ]

On an Asus T300CHI with 16.04 and kernel 4.13.0-25-lowlatency a suspend operation almost immediately resumed but "systemd-sleep suspend" was still running and as a result network-manager thought it was in state "asleep" and would not re-enable networking.

Some system logs looked like they weren't getting the normal flow of messages and 'systemctl status' for the suspend.target and systemd-suspend.service showed they thought the system was suspending/suspended.

This was around 07:36. I left the system most of the day until I could investigate.

I noticed the dmesg showed "Suspended for 23820.656 seconds" when it resumed/failed to suspend immediately.

After a lot of digging and saving command output of interest at 18:33 I did:

sudo kill $(pidof systemd-sleep)

the system immediately suspended. After nearly a minute I pressed the power button and the PC instantly resumed.

dmesg reported "Suspended for 43 seconds" which is correct and network-manager correctly returned to connected state.

---

tj@T300CHI:~$ nmcli gen
STATE CONNECTIVITY WIFI-HW WIFI WWAN-HW WWAN
asleep none enabled enabled enabled enabled

tj@T300CHI:~$ systemctl status suspend.target
Failed to suspend system via logind: There's already a shutdown or sleep operation in progress

tj@T300CHI:~$ systemctl status systemd-suspend.service
systemd-suspend.service - Suspend
   Loaded: loaded (/lib/systemd/system/systemd-suspend.service; static; vendor preset: enabled)
   Active: activating (start) since Fri 2018-01-19 00:56:05 GMT; 17h ago
     Docs: man:systemd-suspend.service(8)
 Main PID: 23868 (systemd-sleep)
    Tasks: 1
   Memory: 536.0K
      CPU: 6ms
   CGroup: /system.slice/systemd-suspend.service
           23868 /lib/systemd/systemd-sleep suspend

Jan 19 00:56:05 T300CHI systemd[1]: Starting Suspend...
Jan 19 00:56:15 T300CHI systemd-sleep[23868]: Selected interface 'p2p-dev-wlp2s0'
Jan 19 00:56:15 T300CHI systemd-sleep[23868]: 'SUSPEND' command timed out.
Jan 19 00:56:15 T300CHI systemd-sleep[23868]: Suspending system...

tj@T300CHI:~$ cat suspend-logind.log
-- Logs begin at Thu 2018-01-18 01:39:09 GMT, end at Fri 2018-01-19 18:00:09 GMT. --
Jan 18 01:39:12 T300CHI systemd[1]: Starting Login Service...
Jan 18 01:39:12 T300CHI systemd[1]: Started Login Service.
Jan 18 01:39:12 T300CHI systemd-logind[1469]: New seat seat0.
Jan 18 01:39:12 T300CHI systemd-logind[1469]: Watching system buttons on /dev/input/event2 (Power Button)
Jan 18 01:39:12 T300CHI systemd-logind[1469]: Watching system buttons on /dev/input/event4 (Asus Wireless Radio Control)
Jan 18 01:39:12 T300CHI systemd-logind[1469]: Watching system buttons on /dev/input/event6 (Video Bus)
Jan 18 01:39:12 T300CHI systemd-logind[1469]: Watching system buttons on /dev/input/event0 (Lid Switch)
Jan 18 01:39:12 T300CHI systemd-logind[1469]: Watching system buttons on /dev/input/event1 (Sleep Button)
Jan 18 01:39:12 T300CHI systemd-logind[1469]: Watching system buttons on /dev/input/event5 (Asus WMI hotkeys)
Jan 18 01:39:14 T300CHI systemd-logind[1469]: New session c1 of user lightdm.
Jan 18 01:39:27 T300CHI systemd-logind[1469]: New session c2 of user tj.
Jan 18 01:39:47 T300CHI systemd-logind[1469]: Removed session c1.
Jan 18 14:13:39 T300CHI systemd-logind[1469]: Operation 'sleep' finished.
Jan 18 14:13:41 T300CHI systemd-logind[1469]: New session c3 of user lightdm.
Jan 19 00:56:16 T300CHI systemd-logind[1469]: New session c4 of user lightdm.
Jan 19 00:56:26 T300CHI systemd-logind[1469]: Removed session c4.
Jan 19 00:56:46 T300CHI systemd-logind[1469]: Removed session c3.
---
ApportVersion: 2.20.1-0ubuntu2.15
Architecture: amd64
CurrentDesktop: XFCE
DistroRelease: Ubuntu 16.04
EcryptfsInUse: Yes
MachineType: ASUSTeK COMPUTER INC. T300CHI
NonfreeKernelModules: wl
Package: systemd 229-4ubuntu21
PackageArchitecture: amd64
ProcKernelCmdLine: BOOT_IMAGE=/vmlinuz-4.13.0-25-lowlatency root=/dev/mapper/VG02-rootfs ro no_console_suspend acpi_osi=! "acpi_osi=Windows 2013" splash crashkernel=384M-2G:128M,2G-:256M vt.handoff=7
ProcVersionSignature: Ubuntu 4.13.0-25.29~16.04.2-lowlatency 4.13.13
Tags: third-party-packages xenial
Uname: Linux 4.13.0-25-lowlatency x86_64
UpgradeStatus: No upgrade log present (probably fresh install)
UserGroups: adm cdrom dialout dip libvirtd lpadmin lxd plugdev sambashare sbuild sudo
_MarkForUpload: True
dmi.bios.date: 08/06/2015
dmi.bios.vendor: American Megatrends Inc.
dmi.bios.version: T300CHI.207
dmi.board.asset.tag: ATN12345678901234567
dmi.board.name: T300CHI
dmi.board.vendor: ASUSTeK COMPUTER INC.
dmi.board.version: 1.0
dmi.chassis.asset.tag: ATN12345678901234567
dmi.chassis.type: 10
dmi.chassis.vendor: ASUSTeK COMPUTER INC.
dmi.chassis.version: 1.0
dmi.modalias: dmi:bvnAmericanMegatrendsInc.:bvrT300CHI.207:bd08/06/2015:svnASUSTeKCOMPUTERINC.:pnT300CHI:pvr1.0:rvnASUSTeKCOMPUTERINC.:rnT300CHI:rvr1.0:cvnASUSTeKCOMPUTERINC.:ct10:cvr1.0:
dmi.product.family: T
dmi.product.name: T300CHI
dmi.product.version: 1.0
dmi.sys.vendor: ASUSTeK COMPUTER INC.

[TJ (tj)]

apport information

[TJ (tj)]

apport information

[TJ (tj)]

apport information

[TJ (tj)]

apport information

[TJ (tj)]

apport information

[TJ (tj)]

apport information

[TJ (tj)]

apport information

[TJ (tj)]

apport information

[TJ (tj)]

apport information

[TJ (tj)]

apport information

[TJ (tj)]

apport information

[TJ (tj)]

apport information

[TJ (tj)]

apport information

[TJ (tj)]

Just re-discovered my own report here whilst trying to solve another occurrence of the same issue 18 months later.

Now with 18.04 and 4.15.0-56-lowlatency (amd64).

With assistance of grawity in IRC #systemd I found some more information which might help narrow this down.
$ uname -a

Linux T300CHI 4.15.0-56-lowlatency #62-Ubuntu SMP PREEMPT Wed Jul 24 21:03:13 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux

$ systemctl list-jobs

   JOB UNIT TYPE STATE
740792 systemd-suspend.service start running
740791 suspend.target start waiting

2 jobs listed.

$ systemctl status systemd-suspend.service

● systemd-suspend.service - Suspend
   Loaded: loaded (/lib/systemd/system/systemd-suspend.service; static; vendor preset: enabled)
   Active: activating (start) since Fri 2019-08-02 08:26:54 BST; 53min ago
     Docs: man:systemd-suspend.service(8)
 Main PID: 16968 (systemd-sleep)
    Tasks: 1 (limit: 4915)
   CGroup: /system.slice/systemd-suspend.service
           â””─16968 /lib/systemd/systemd-sleep suspend

Aug 02 08:26:54 T300CHI systemd[1]: Starting Suspend...
Aug 02 08:26:55 T300CHI systemd-sleep[16968]: Suspending system...

$ sudo cat /proc/$(pidof systemd-sleep)/stack

[<0>] __vt_event_wait.isra.2.part.3+0x40/0x90
[<0>] vt_waitactive+0x7b/0xd0
[<0>] vt_move_to_console+0x46/0xc0
[<0>] pm_prepare_console+0x23/0x40
[<0>] pm_suspend+0x19c/0x3b0
[<0>] state_store+0x85/0xf0
[<0>] kobj_attr_store+0x12/0x20
[<0>] sysfs_kf_write+0x3c/0x50
[<0>] kernfs_fop_write+0x125/0x1a0
[<0>] __vfs_write+0x1b/0x40
[<0>] vfs_write+0xb1/0x1a0
[<0>] SyS_write+0x55/0xc0
[<0>] do_syscall_64+0x73/0x130
[<0>] entry_SYSCALL_64_after_hwframe+0x3d/0xa2
[<0>] 0xffffffffffffffff

[TJ (tj)]

Strongly related bug for 18.04 with an explanation of what is hanging but referencing plymouth's "splash" which this system doesn't use:

$ cat /proc/cmdline
BOOT_IMAGE=/vmlinuz-4.15.0-56-lowlatency root=/dev/mapper/VG02-rootfs ro intremap=no_x2apic_optout no_console_suspend acpi_osi=! "acpi_osi=Windows 2013"

[Dan Streetman (ddstreet)]

please reopen if this is still an issue