[Bug 1744370] Re: 'systemd-sleep suspend' hung after an abortive suspend/resume

Fri Jan 19 19:05:00 UTC 2018

** Description changed:

  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 at T300CHI:~$ nmcli gen 
+ STATE   CONNECTIVITY  WIFI-HW  WIFI     WWAN-HW  WWAN    
+ asleep  none          enabled  enabled  enabled  enabled 
+ 
+ tj at T300CHI:~$ systemctl status suspend.target 
+ Failed to suspend system via logind: There's already a shutdown or sleep operation in progress
+ 
+ tj at 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 at 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.

** Attachment added: "dmesg captured whilst system thought it was suspending"
   https://bugs.launchpad.net/ubuntu/+source/systemd/+bug/1744370/+attachment/5039690/+files/suspend-dmesg.log

** Tags added: apport-collected third-party-packages xenial

** Description changed:

  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 at T300CHI:~$ nmcli gen 
  STATE   CONNECTIVITY  WIFI-HW  WIFI     WWAN-HW  WWAN    
  asleep  none          enabled  enabled  enabled  enabled 

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

  tj at 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 at 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.

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to systemd in Ubuntu.
https://bugs.launchpad.net/bugs/1744370

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

Status in systemd package in Ubuntu:
  New

Bug description:
  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 at T300CHI:~$ nmcli gen 
  STATE   CONNECTIVITY  WIFI-HW  WIFI     WWAN-HW  WWAN    
  asleep  none          enabled  enabled  enabled  enabled 

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

  tj at 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 at 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.

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/systemd/+bug/1744370/+subscriptions