[systemd-devel] Antw: [EXT] [systemd‑devel] no log information about why machine is sleeping

[Ulrich Windl]

>>> George Avrunin <avrunin at math.umass.edu> schrieb am 11.08.2021 um 23:11 in
Nachricht <20210811171121.0e197883 at g.localdomain>:
> Hello,
> 
> As a result of a major power outage and consequent issues with some
> switches, my office workstation, a Dell Precision T1700 running
> fully‑updated Fedora 34, was off the network for most of last weekend.  As
> our department IT staff detected and fixed the switch issues, they noticed
> that my workstation was putting itself to sleep when it couldn't connect
> to the switch for my floor.  Right now, everything is back up and working,
> but they will probably have to replace the switch.
> 
> However, I haven't been able to figure out why the machine puts itself to
> sleep when it can't reach the switch.  I asked about this on the Fedora

I don't know, but caring about the earch climate my PC goes to STR (suspend to
RAM) when there is no activity for a longer time.
Maybe your PC uses a similar setting, and being constantly attacked keeps it
busy, so when there is no switch connection your PC becomes actually idle ;-)

> users list (and included the log entries shown below), and Chris Murphy
> noted that systemd doesn't normally insert the sleep request in the log,
> so it's not possible to determine what caused the sleep request.  He
> suggested that I start a thread here to ask if at least a single line of
> information about how the sleep is being initiated could be dumped into
> the log by default.  

Mine logs a lot when suspending or resuming, bu tOI dn't run Fedora (Leap 15.3
instead).

> 
> I will experiment with rebooting with systemd.log_level=debug when I know
> the switch will be shut down for replacement.  But it would be good to get
> more information about what's initiating sleep by default.
> 
> Thanks,
> 
>   George Avrunin
> 
> 
> Here are the relevant log entries from one of the times the machine put
> itself to sleep, apparently because it couldn't connect to the network.
> If there's more information I can supply, please let me know.
> 
> (This starts after power was restored to the building and the machine had
> been manually rebooted just to be sure it would go online.)
> 
> Aug 06 17:47:32 ext.math.umass.edu kernel:
> Lockdown: systemd‑logind: hibernation is restricted; see man
> kernel_lockdown.7 Aug 06 17:47:32 ext.math.umass.edu kernel: Lockdown:
> systemd‑logind: hibernation is restricted; see man kernel_lockdown.7
> Aug 06 17:47:32 ext.math.umass.edu NetworkManager[2111]: <info>
> [1628286452.1872] manager: sleep: sleep requested (sleeping: no  enabled:
> yes) Aug 06 17:47:32 ext.math.umass.edu NetworkManager[2111]: <info>
> [1628286452.1876] manager: NetworkManager state is now ASLEEP
> Aug 06 17:47:32 ext.math.umass.edu ModemManager[1954]: <info>
> [sleep‑monitor] system is about to suspend
> Aug 06 17:47:32 ext.math.umass.edu gnome‑shell[4292]: Screen lock is
> locked down, not locking
> Aug 06 17:47:32 ext.math.umass.edu systemd[1]: Reached target Sleep.
> Aug 06 17:47:32 ext.math.umass.edu systemd[1]: Starting System Suspend...

But here is a sleep request logged!

> Aug 06 17:47:32 ext.math.umass.edu systemd‑sleep[40504]: Suspending
> system...
> Aug 06 17:47:32 ext.math.umass.edu kernel: PM: suspend entry (deep)


This log buffer is logged with the wrong time: Actually it the last part of
suspend, logged at resume time.

> Aug 07 14:09:22 ext.math.umass.edu kernel: Filesystems sync: 0.379 seconds
> Aug 07 14:09:22 ext.math.umass.edu kernel: Freezing user space processes
> ... (elapsed 0.002 seconds) done.
> Aug 07 14:09:22 ext.math.umass.edu kernel: OOM killer disabled.
> Aug 07 14:09:22 ext.math.umass.edu kernel: Freezing remaining freezable
> tasks ... (elapsed 0.001 seconds) done.
> Aug 07 14:09:22 ext.math.umass.edu kernel: printk: Suspending console(s)
> (use no_console_suspend to debug)
> Aug 07 14:09:22 ext.math.umass.edu kernel: serial 00:06: disabled
> Aug 07 14:09:22 ext.math.umass.edu kernel: e1000e: EEE TX LPI TIMER:
> 00000011
> Aug 07 14:09:22 ext.math.umass.edu kernel: sd 0:0:0:0: [sda] Synchronizing
> SCSI cache
> Aug 07 14:09:22 ext.math.umass.edu kernel: sd 1:0:0:0: [sdb] Synchronizing
> SCSI cache
> Aug 07 14:09:22 ext.math.umass.edu kernel: sd 1:0:0:0: [sdb] Stopping disk
> Aug 07 14:09:22 ext.math.umass.edu kernel: sd 0:0:0:0: [sda] Stopping disk
> Aug 07 14:09:22 ext.math.umass.edu kernel: PM: suspend devices took 1.031
> seconds
> Aug 07 14:09:22 ext.math.umass.edu kernel: ACPI: Preparing to enter system
> sleep state S3
> Aug 07 14:09:22 ext.math.umass.edu kernel: PM: Saving platform NVS memory
> Aug 07 14:09:22 ext.math.umass.edu kernel: Disabling non‑boot CPUs ...

This is still the suspend part...

> lines 835‑871
> etc.