Score:1

Dell server is no more accessible after entering sleep state: kernel: PM: suspend entry (s2idle)

cn flag
s.k

[Original post title: "Ubuntu regularly shut down on a SSD NVME disk (LVM) on a physical server"

The beginning of the post is kept for historical reasons, but the edits hereunder tends to show this is an issue with a suspend state being triggered, and the system not able to wake up afterwards]

I am using an Ubuntu physical server (Dell Precision 7920 Rack) (I do have a physical access to it) which randomly shuts down for the past few days (no matter what I do, it can also stop when I'm not using it).

This may be due to a distribution upgrade (from 20.04 to 22.04 using do-release-upgrade) but the machine went fine for some hours after that and it has been rebooted several times. I installed some new software, mainly python libs without any troubles.

Power supply and main board where changed. The problem still persists.

I unplugged a secondary HDD for data storage. The problem persists.

memtest86+ has run fine for some hours.

I changed the main SSD with a new one and did a fresh 22.04 install. The problem disappeared.

I kept the old SSD plugged to be able to inspect it but I don't know where to start. Maybe in the log files? Which ones?

That main disk (containing the former Ubuntu 22.04) which is now only plugged in as a secondary disk, is a 1 TB SSD/NVME , partitioned as follows:

$ lsblk
NAME                        MAJ:MIN RM   SIZE RO TYPE MOUNTPOINTS
(....)
nvme1n1                     259:1    0 953.9G  0 disk 
├─nvme1n1p1                 259:2    0   512M  0 part 
├─nvme1n1p2                 259:3    0   488M  0 part 
└─nvme1n1p3                 259:5    0 952.9G  0 part 
  ├─ubuntu--vg-root         253:0    0 675.6G  0 lvm  /mnt/ubuntu-vg/root
  └─ubuntu--vg-swap_1       253:1    0 255.7G  0 lvm 

I didn't really know what are these "vg" flagged partitions, neither that "lvm" type.

I spent some hours searching for their meanings, and it seems that the disk is using a Logical Volume Manager. This page helped a lot: https://www.cyberciti.biz/faq/linux-mount-an-lvm-volume-partition-command/

So here is some more information:

$ sudo vgscan 
  Found volume group "ubuntu-vg" using metadata type lvm2
$ sudo lvs
  LV     VG            Attr       LSize    Pool Origin Data%  Meta%  Move Log Cpy%Sync Convert
  root   ubuntu-vg     -wi-ao----  675.63g                                                    
  swap_1 ubuntu-vg     -wi-a----- <255.69g

That root partition was the one containing Ubuntu.

Showing details using lvdisplay:

$ sudo lvdisplay 
  --- Logical volume ---
  LV Path                /dev/ubuntu-vg/root
  LV Name                root
  VG Name                ubuntu-vg
  LV UUID                <UUID-string>
  LV Write Access        read/write
  LV Creation host, time ubuntu, 2018-01-19 14:11:21 +0100
  LV Status              available
  # open                 1
  LV Size                675.63 GiB
  Current LE             172962
  Segments               1
  Allocation             inherit
  Read ahead sectors     auto
  - currently set to     256
  Block device           253:0
   
  --- Logical volume ---
  LV Path                /dev/ubuntu-vg/swap_1
  LV Name                swap_1
  VG Name                ubuntu-vg
  LV UUID                <UUID-string>
  LV Write Access        read/write
  LV Creation host, time ubuntu, 2018-01-19 14:11:21 +0100
  LV Status              available
  # open                 0
  LV Size                <255.69 GiB
  Current LE             65456
  Segments               1
  Allocation             inherit
  Read ahead sectors     auto
  - currently set to     256
  Block device           253:1

with smartmontools:

$ sudo smartctl -a /dev/nvme1n1
smartctl 7.2 2020-12-30 r5155 [x86_64-linux-5.15.0-48-generic] (local build)
Copyright (C) 2002-20, Bruce Allen, Christian Franke, www.smartmontools.org

=== START OF INFORMATION SECTION ===
Model Number:                       THNSN51T02DU7 NVMe TOSHIBA 1024GB
Serial Number:                      <serial number>
Firmware Version:                   57DC4101
PCI Vendor/Subsystem ID:            0x1179
IEEE OUI Identifier:                0x00080d
Controller ID:                      0
NVMe Version:                       <1.2
Number of Namespaces:               1
Namespace 1 Size/Capacity:          1,024,209,543,168 [1.02 TB]
Namespace 1 Formatted LBA Size:     512
Namespace 1 IEEE EUI-64:            00080d 0200119860
Local Time is:                      Sat Oct  8 16:02:51 2022 CEST
Firmware Updates (0x02):            1 Slot
Optional Admin Commands (0x0016):   Format Frmw_DL Self_Test
Optional NVM Commands (0x001e):     Wr_Unc DS_Mngmt Wr_Zero Sav/Sel_Feat
Warning  Comp. Temp. Threshold:     78 Celsius
Critical Comp. Temp. Threshold:     82 Celsius

Supported Power States
St Op     Max   Active     Idle   RL RT WL WT  Ent_Lat  Ex_Lat
 0 +     6.00W       -        -    0  0  0  0        0       0
 1 +     2.40W       -        -    1  1  1  1        0       0
 2 +     1.90W       -        -    2  2  2  2        0       0
 3 -   0.0120W       -        -    3  3  3  3     5000   10000
 4 -   0.0060W       -        -    4  4  4  4   100000   50000

Supported LBA Sizes (NSID 0x1)
Id Fmt  Data  Metadt  Rel_Perf
 0 +     512       0         2
 1 -    4096       0         1

=== START OF SMART DATA SECTION ===
SMART overall-health self-assessment test result: PASSED

SMART/Health Information (NVMe Log 0x02)
Critical Warning:                   0x00
Temperature:                        40 Celsius
Available Spare:                    100%
Available Spare Threshold:          50%
Percentage Used:                    11%
Data Units Read:                    13,261,121 [6.78 TB]
Data Units Written:                 62,390,020 [31.9 TB]
Host Read Commands:                 323,925,170
Host Write Commands:                2,274,659,640
Controller Busy Time:               6,206
Power Cycles:                       48
Power On Hours:                     41,151
Unsafe Shutdowns:                   34
Media and Data Integrity Errors:    0
Error Information Log Entries:      0
Warning  Comp. Temperature Time:    0
Critical Comp. Temperature Time:    0
Temperature Sensor 1:               40 Celsius

Error Information (NVMe Log 0x01, 16 of 128 entries)
No Errors Logged

and nvme smart-log:

$ sudo nvme smart-log /dev/nvme1n1
Smart Log for NVME device:nvme1n1 namespace-id:ffffffff
critical_warning            : 0
temperature                 : 40 C (313 Kelvin)
available_spare             : 100%
available_spare_threshold   : 50%
percentage_used             : 11%
endurance group critical warning summary: 0
data_units_read             : 13261121
data_units_written          : 62390020
host_read_commands          : 323925170
host_write_commands         : 2274659640
controller_busy_time        : 6206
power_cycles                : 48
power_on_hours              : 41151
unsafe_shutdowns            : 34
media_errors                : 0
num_err_log_entries         : 0
Warning Temperature Time        : 0
Critical Composite Temperature Time : 0
Temperature Sensor 1                : 40 C (313 Kelvin)
Thermal Management T1 Trans Count   : 0
Thermal Management T2 Trans Count   : 0
Thermal Management T1 Total Time    : 0
Thermal Management T2 Total Time    : 0

Knowing this, is it possible to say if the disk is unhealthy?

By checking where are the partitions of that SSD now that the system boots on another drive:

$ ls -lart /dev/ubuntu-vg/
total 0
lrwxrwxrwx  1 root root    7 Oct  8 14:48 root -> ../dm-0
lrwxrwxrwx  1 root root    7 Oct  8 14:48 swap_1 -> ../dm-1

I am also able to mount it so that I can explore the files:

$ sudo mount /dev/dm-0 /mnt/ubuntu-vg/root/

From that point I don't really know where and what to search for.
Any help is greatly appreciated. journalctl is of no help on a secondary drive.

Edit

Okay, after a useful comment by @Hannu (thanks!); I was able to run journalctl on my former /var/log/journal directory (hopefully this is the right directory to run journalctl on?). By restricting the time window to where I first definitively lost the SSH session (without being able to recover a new one and having to physically reboot the server) journalctl shows me these lines:

$ journalctl --directory="/mnt/ubuntu-vg/root/var/log/journal/<journal-id>/" --since "2022-09-25 15:37" --until "2022-09-25 18:00"
Sep 25 15:37:35 ubuntu sudo[23028]:      username : TTY=pts/0 ; PWD=/etc/apt/sources.list.d ; USER=root ; COMMAND=/usr/bin/apt-get update
Sep 25 15:37:35 ubuntu sudo[23028]: pam_unix(sudo:session): session opened for user root(uid=0) by username(uid=1002)
Sep 25 15:37:37 ubuntu sudo[23028]: pam_unix(sudo:session): session closed for user root
Sep 25 15:37:37 ubuntu sudo[23398]:      username : TTY=pts/0 ; PWD=/etc/apt/sources.list.d ; USER=root ; COMMAND=/usr/bin/apt-get upgrade
Sep 25 15:37:37 ubuntu sudo[23398]: pam_unix(sudo:session): session opened for user root(uid=0) by username(uid=1002)
Sep 25 15:37:38 ubuntu sudo[23398]: pam_unix(sudo:session): session closed for user root
Sep 25 15:37:38 ubuntu sudo[23424]:      username : TTY=pts/0 ; PWD=/etc/apt/sources.list.d ; USER=root ; COMMAND=/usr/bin/apt-get dist-upgrade
Sep 25 15:37:38 ubuntu sudo[23424]: pam_unix(sudo:session): session opened for user root(uid=0) by username(uid=1002)
Sep 25 15:37:39 ubuntu sudo[23424]: pam_unix(sudo:session): session closed for user root
Sep 25 15:37:39 ubuntu sudo[23450]:      username : TTY=pts/0 ; PWD=/etc/apt/sources.list.d ; USER=root ; COMMAND=/usr/bin/apt-get autoremove --purge
Sep 25 15:37:39 ubuntu sudo[23450]: pam_unix(sudo:session): session opened for user root(uid=0) by username(uid=1002)
Sep 25 15:37:39 ubuntu sudo[23450]: pam_unix(sudo:session): session closed for user root
Sep 25 15:37:39 ubuntu sudo[23523]:      username : TTY=pts/0 ; PWD=/etc/apt/sources.list.d ; USER=root ; COMMAND=/usr/bin/apt-get autoclean
Sep 25 15:37:39 ubuntu sudo[23523]: pam_unix(sudo:session): session opened for user root(uid=0) by username(uid=1002)
Sep 25 15:37:39 ubuntu sudo[23523]: pam_unix(sudo:session): session closed for user root
Sep 25 15:37:39 ubuntu sudo[23528]:      username : TTY=pts/0 ; PWD=/etc/apt/sources.list.d ; USER=root ; COMMAND=/usr/sbin/ldconfig
Sep 25 15:37:39 ubuntu sudo[23528]: pam_unix(sudo:session): session opened for user root(uid=0) by username(uid=1002)
Sep 25 15:37:40 ubuntu sudo[23528]: pam_unix(sudo:session): session closed for user root
Sep 25 15:40:35 ubuntu ModemManager[3889]: <info>  [sleep-monitor] system is about to suspend
Sep 25 15:40:35 ubuntu NetworkManager[3980]: <info>  [1664113235.8663] manager: sleep: sleep requested (sleeping: no  enabled: yes)
Sep 25 15:40:35 ubuntu NetworkManager[3980]: <info>  [1664113235.8667] device (eno3): state change: unavailable -> unmanaged (reason 'sleeping', sys-iface-state: 'managed')
Sep 25 15:40:35 ubuntu NetworkManager[3980]: <info>  [1664113235.9082] device (eno4): state change: unavailable -> unmanaged (reason 'sleeping', sys-iface-state: 'managed')
Sep 25 15:40:35 ubuntu NetworkManager[3980]: <info>  [1664113235.9477] device (eno1): state change: activated -> deactivating (reason 'sleeping', sys-iface-state: 'managed')
Sep 25 15:40:35 ubuntu dbus-daemon[3769]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.15' (uid=0 pid=3980>
Sep 25 15:40:35 ubuntu systemd[1]: Starting Network Manager Script Dispatcher Service...
Sep 25 15:40:36 ubuntu dbus-daemon[3769]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Sep 25 15:40:36 ubuntu systemd[1]: Started Network Manager Script Dispatcher Service.
Sep 25 15:40:36 ubuntu NetworkManager[3980]: <info>  [1664113236.0052] device (eno1): state change: deactivating -> disconnected (reason 'sleeping', sys-iface-state: 'managed')
Sep 25 15:40:36 ubuntu avahi-daemon[3768]: Withdrawing address record for fe80::xxxx:xxxx:xxxx:xxxx on eno1.
Sep 25 15:40:36 ubuntu avahi-daemon[3768]: Leaving mDNS multicast group on interface eno1.IPv6 with address fe80::xxxx:xxxx:xxxx:xxxx.
Sep 25 15:40:36 ubuntu avahi-daemon[3768]: Interface eno1.IPv6 no longer relevant for mDNS.
Sep 25 15:40:36 ubuntu NetworkManager[3980]: <info>  [1664113236.0435] dhcp4 (eno1): canceled DHCP transaction
Sep 25 15:40:36 ubuntu NetworkManager[3980]: <info>  [1664113236.0436] dhcp4 (eno1): activation: beginning transaction (timeout in 45 seconds)
Sep 25 15:40:36 ubuntu NetworkManager[3980]: <info>  [1664113236.0436] dhcp4 (eno1): state changed no lease
Sep 25 15:40:36 ubuntu avahi-daemon[3768]: Withdrawing address record for 10.192.xxx.x on eno1.
Sep 25 15:40:36 ubuntu avahi-daemon[3768]: Leaving mDNS multicast group on interface eno1.IPv4 with address 10.192.xxx.x.
Sep 25 15:40:36 ubuntu systemd-resolved[4099]: eno1: Bus client reset search domain list.
Sep 25 15:40:36 ubuntu avahi-daemon[3768]: Interface eno1.IPv4 no longer relevant for mDNS.
Sep 25 15:40:36 ubuntu systemd-resolved[4099]: eno1: Bus client set default route setting: no
Sep 25 15:40:36 ubuntu systemd-resolved[4099]: eno1: Bus client reset DNS server list.
Sep 25 15:40:36 ubuntu NetworkManager[3980]: <info>  [1664113236.0687] device (eno1): state change: disconnected -> unmanaged (reason 'sleeping', sys-iface-state: 'managed')
Sep 25 15:40:36 ubuntu systemd[1]: Reached target Sleep.
Sep 25 15:40:36 ubuntu systemd[1]: Starting Record successful boot for GRUB...
Sep 25 15:40:36 ubuntu systemd[1]: Starting System Suspend...
Sep 25 15:40:36 ubuntu systemd[1]: grub-common.service: Deactivated successfully.
Sep 25 15:40:36 ubuntu systemd[1]: Finished Record successful boot for GRUB.
Sep 25 15:40:36 ubuntu systemd[1]: Starting GRUB failed boot detection...
Sep 25 15:40:36 ubuntu systemd-sleep[24557]: Entering sleep state 'suspend'...
Sep 25 15:40:36 ubuntu kernel: PM: suspend entry (s2idle)
Sep 25 15:40:36 ubuntu systemd[1]: grub-initrd-fallback.service: Deactivated successfully.
Sep 25 15:40:36 ubuntu systemd[1]: Finished GRUB failed boot detection.
Sep 25 15:40:36 ubuntu kernel: Filesystems sync: 0.010 seconds

I can obviously see some last update/upgrade/cleaning command that I manually ran using sudo, after what I went to a meeting, and these are the very last lines before the machine being definitively inaccessible. It doesn't even seem to be critical or failure messages... I really don't get it. At this point, I even wonder if it wasn't simply some kind of network issue, i.e. the machine was still running, but I wasn't able to reach it anymore, maybe(?)

This is a little obscure to me, I don't know how to interpret this.

All those lines after the sudo manual commands are always repeated before some other 'crashes' of the machine (I'm heavily doubting it was really crashing, but it was certainly no more accessible after these kind of "events").

E.g. another of such event, occurring at 11:07:25 (please notice that nothing happens for ten seconds before, from 11:07:15):

$ journalctl --directory="/mnt/ubuntu-vg/root/var/log/journal/<journal-id>/" --since "2022-09-28 11:07:15" --until "2022-09-28 11:07:35"

Sep 28 11:07:25 ubuntu ModemManager[4003]: <info>  [sleep-monitor] system is about to suspend
Sep 28 11:07:25 ubuntu NetworkManager[4121]: <info>  [1664356045.8836] manager: sleep: sleep requested (sleeping: no  enabled: yes)
Sep 28 11:07:25 ubuntu NetworkManager[4121]: <info>  [1664356045.8840] device (eno3): state change: unavailable -> unmanaged (reason 'sleeping', sys-iface-state: 'managed')
Sep 28 11:07:25 ubuntu NetworkManager[4121]: <info>  [1664356045.9257] device (eno4): state change: unavailable -> unmanaged (reason 'sleeping', sys-iface-state: 'managed')
Sep 28 11:07:25 ubuntu NetworkManager[4121]: <info>  [1664356045.9649] device (eno1): state change: activated -> deactivating (reason 'sleeping', sys-iface-state: 'managed')
Sep 28 11:07:25 ubuntu dbus-daemon[3905]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.15' (uid=0 pid=4121>
Sep 28 11:07:25 ubuntu systemd[1]: Starting Network Manager Script Dispatcher Service...
Sep 28 11:07:26 ubuntu dbus-daemon[3905]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Sep 28 11:07:26 ubuntu systemd[1]: Started Network Manager Script Dispatcher Service.
Sep 28 11:07:26 ubuntu NetworkManager[4121]: <info>  [1664356046.0080] device (eno1): state change: deactivating -> disconnected (reason 'sleeping', sys-iface-state: 'managed')
Sep 28 11:07:26 ubuntu avahi-daemon[3903]: Withdrawing address record for fe80::xxxx:xxxx:xxxx:xxxx on eno1.
Sep 28 11:07:26 ubuntu avahi-daemon[3903]: Leaving mDNS multicast group on interface eno1.IPv6 with address fe80::xxxx:xxxx:xxxx:xxxx.
Sep 28 11:07:26 ubuntu avahi-daemon[3903]: Interface eno1.IPv6 no longer relevant for mDNS.
Sep 28 11:07:26 ubuntu NetworkManager[4121]: <info>  [1664356046.0476] dhcp4 (eno1): canceled DHCP transaction
Sep 28 11:07:26 ubuntu NetworkManager[4121]: <info>  [1664356046.0476] dhcp4 (eno1): activation: beginning transaction (timeout in 45 seconds)
Sep 28 11:07:26 ubuntu NetworkManager[4121]: <info>  [1664356046.0477] dhcp4 (eno1): state changed no lease
Sep 28 11:07:26 ubuntu systemd-resolved[4232]: eno1: Bus client reset search domain list.
Sep 28 11:07:26 ubuntu avahi-daemon[3903]: Withdrawing address record for 10.192.xxx.x on eno1.
Sep 28 11:07:26 ubuntu avahi-daemon[3903]: Leaving mDNS multicast group on interface eno1.IPv4 with address 10.192.xxx.x.
Sep 28 11:07:26 ubuntu avahi-daemon[3903]: Interface eno1.IPv4 no longer relevant for mDNS.
Sep 28 11:07:26 ubuntu systemd-resolved[4232]: eno1: Bus client set default route setting: no
Sep 28 11:07:26 ubuntu systemd-resolved[4232]: eno1: Bus client reset DNS server list.
Sep 28 11:07:26 ubuntu NetworkManager[4121]: <info>  [1664356046.0741] device (eno1): state change: disconnected -> unmanaged (reason 'sleeping', sys-iface-state: 'managed')
Sep 28 11:07:26 ubuntu systemd[1]: Reached target Sleep.
Sep 28 11:07:26 ubuntu systemd[1]: Starting Record successful boot for GRUB...
Sep 28 11:07:26 ubuntu systemd[1]: Starting System Suspend...
Sep 28 11:07:26 ubuntu systemd-sleep[23486]: Entering sleep state 'suspend'...
Sep 28 11:07:26 ubuntu kernel: PM: suspend entry (s2idle)
Sep 28 11:07:26 ubuntu systemd[1]: grub-common.service: Deactivated successfully.
Sep 28 11:07:26 ubuntu systemd[1]: Finished Record successful boot for GRUB.
Sep 28 11:07:26 ubuntu systemd[1]: Starting GRUB failed boot detection...
Sep 28 11:07:26 ubuntu kernel: Filesystems sync: 0.009 seconds

And if I put more focus, like:

$ journalctl --directory="/mnt/ubuntu-vg/root/var/log/journal/<journal-id>/" | grep -i "system is about to suspend\|sleep requested"

Sep 25 15:40:35 ubuntu ModemManager[3889]: <info>  [sleep-monitor] system is about to suspend
Sep 25 15:40:35 ubuntu NetworkManager[3980]: <info>  [1664113235.8663] manager: sleep: sleep requested (sleeping: no  enabled: yes)

Sep 28 11:07:25 ubuntu ModemManager[4003]: <info>  [sleep-monitor] system is about to suspend
Sep 28 11:07:25 ubuntu NetworkManager[4121]: <info>  [1664356045.8836] manager: sleep: sleep requested (sleeping: no  enabled: yes)

Sep 29 16:31:42 ubuntu NetworkManager[4023]: <info>  [1664461902.3198] manager: sleep: sleep requested (sleeping: no  enabled: yes)
Sep 29 16:31:42 ubuntu ModemManager[3919]: <info>  [sleep-monitor] system is about to suspend

Sep 29 17:33:26 ubuntu ModemManager[4035]: <info>  [sleep-monitor] system is about to suspend
Sep 29 17:33:26 ubuntu NetworkManager[4141]: <info>  [1664465606.6327] manager: sleep: sleep requested (sleeping: no  enabled: yes)

Oct 03 10:53:22 ubuntu NetworkManager[4026]: <info>  [1664787202.5245] manager: sleep: sleep requested (sleeping: no  enabled: yes)
Oct 03 10:53:22 ubuntu ModemManager[3937]: <info>  [sleep-monitor] system is about to suspend

Oct 03 15:40:28 ubuntu ModemManager[3876]: <info>  [sleep-monitor] system is about to suspend
Oct 03 15:40:28 ubuntu NetworkManager[3998]: <info>  [1664804428.9916] manager: sleep: sleep requested (sleeping: no  enabled: yes)

Oct 05 12:05:16 ubuntu ModemManager[4657]: <info>  [sleep-monitor] system is about to suspend
Oct 05 12:05:16 ubuntu NetworkManager[3968]: <info>  [1664964316.1700] manager: sleep: sleep requested (sleeping: no  enabled: yes)

Oct 05 13:14:53 ubuntu ModemManager[4657]: <info>  [sleep-monitor] system is about to suspend
Oct 05 13:14:53 ubuntu NetworkManager[3968]: <info>  [1664968493.9235] manager: sleep: sleep requested (sleeping: no  enabled: yes)

Oct 05 14:16:00 ubuntu NetworkManager[4162]: <info>  [1664972160.4328] manager: sleep: sleep requested (sleeping: no  enabled: yes)
Oct 05 14:16:00 ubuntu ModemManager[4066]: <info>  [sleep-monitor] system is about to suspend

These "events" all correspond to what I thought were crash events. But they seem to be actual "sleep" or "suspend" events. I separated them by a blank line for a better readability here.
What is strange is that the order between the ModemManager and the NetworkManager lines in the log is kind of random. As if they occur so close together in time, that the system cannot log their true chronological occurrences. May it be that the NetworkManager is triggering the sleep? I'm not quite sure...

Also, as suggested in the comment below, here is a log with a little bit of info before the event (-10min):

$ journalctl --directory=. --since "2022-09-29 17:20:00" --until "2022-09-29 17:40:00" 

Sep 29 17:22:55 ubuntu dockerd[5101]: time="2022-09-29T17:22:55.573071250+02:00" level=info msg="NetworkDB stats ubuntu(56f4cff42518) - netID:ej327ec80c49s1azrhnal3opf leaving:false netPeers:1 entries:2>
Sep 29 17:23:04 ubuntu dbus-daemon[3913]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.15' (uid=0 pid=4141>
Sep 29 17:23:04 ubuntu systemd[1]: Starting Network Manager Script Dispatcher Service...
Sep 29 17:23:04 ubuntu dbus-daemon[3913]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Sep 29 17:23:04 ubuntu systemd[1]: Started Network Manager Script Dispatcher Service.
Sep 29 17:23:07 ubuntu ntpd[5775]: 91.189.xxx.xxx local addr 10.192.xxx.x -> <null>
Sep 29 17:23:08 ubuntu ntpd[5775]: 91.189.xxx.x local addr 10.192.xxx.x -> <null>
Sep 29 17:23:16 ubuntu systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
Sep 29 17:25:01 ubuntu CRON[19024]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
Sep 29 17:25:01 ubuntu CRON[19025]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Sep 29 17:25:01 ubuntu CRON[19024]: pam_unix(cron:session): session closed for user root
Sep 29 17:27:40 ubuntu systemd[1]: Starting Cleanup of Temporary Directories...
Sep 29 17:27:40 ubuntu systemd[1]: systemd-tmpfiles-clean.service: Deactivated successfully.
Sep 29 17:27:40 ubuntu systemd[1]: Finished Cleanup of Temporary Directories.
Sep 29 17:27:55 ubuntu dockerd[5101]: time="2022-09-29T17:27:55.573600169+02:00" level=info msg="NetworkDB stats ubuntu(58f4cee4b558) - netID:ej327ec80c49s1azrhnal3opf leaving:false netPeers:1 entries:2>
Sep 29 17:28:06 ubuntu ntpd[5775]: 140.238.xxx.xxx local addr 10.192.xxx.x -> <null>
Sep 29 17:29:26 ubuntu dbus-daemon[9792]: [session uid=113 pid=9792] Activating service name='org.freedesktop.Notifications' requested by ':1.23' (uid=113 pid=9954 comm="/usr/lib/unity-settings-daemon/unity>
Sep 29 17:29:26 ubuntu notify-osd[20628]: cannot open display: 
Sep 29 17:29:26 ubuntu dbus-daemon[9792]: [session uid=113 pid=9792] Activated service 'org.freedesktop.Notifications' failed: Process org.freedesktop.Notifications exited with status 1
Sep 29 17:30:01 ubuntu CRON[20664]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
Sep 29 17:30:01 ubuntu CRON[20665]: (root) CMD ([ -x /etc/init.d/anacron ] && if [ ! -d /run/systemd/system ]; then /usr/sbin/invoke-rc.d anacron start >/dev/null; fi)
Sep 29 17:30:01 ubuntu CRON[20664]: pam_unix(cron:session): session closed for user root
Sep 29 17:30:10 ubuntu systemd[1]: Starting Ubuntu Advantage Timer for running repeated jobs...
Sep 29 17:30:10 ubuntu systemd[1]: ua-timer.service: Deactivated successfully.
Sep 29 17:30:10 ubuntu systemd[1]: Finished Ubuntu Advantage Timer for running repeated jobs.
Sep 29 17:30:15 ubuntu ntpd[5775]: 212.xx.xx.xxx local addr 10.192.xxx.x -> <null>
Sep 29 17:30:41 ubuntu systemd[1]: Started Run anacron jobs.
Sep 29 17:30:41 ubuntu anacron[20976]: Anacron 2.3 started on 2022-09-29
Sep 29 17:30:41 ubuntu anacron[20976]: Normal exit (0 jobs run)
Sep 29 17:30:41 ubuntu systemd[1]: anacron.service: Deactivated successfully.
Sep 29 17:32:55 ubuntu dockerd[5101]: time="2022-09-29T17:32:55.773040019+02:00" level=info msg="NetworkDB stats ubuntu(56f4cff42518) - netID:ej327ec80c49s1azrhnal3opf leaving:false netPeers:1 entries:2>
Sep 29 17:33:26 ubuntu ModemManager[4035]: <info>  [sleep-monitor] system is about to suspend
Sep 29 17:33:26 ubuntu NetworkManager[4141]: <info>  [1664465606.6327] manager: sleep: sleep requested (sleeping: no  enabled: yes)
Sep 29 17:33:26 ubuntu NetworkManager[4141]: <info>  [1664465606.6330] device (eno3): state change: unavailable -> unmanaged (reason 'sleeping', sys-iface-state: 'managed')
Sep 29 17:33:26 ubuntu NetworkManager[4141]: <info>  [1664465606.6752] device (eno4): state change: unavailable -> unmanaged (reason 'sleeping', sys-iface-state: 'managed')
Sep 29 17:33:26 ubuntu NetworkManager[4141]: <info>  [1664465606.7148] device (eno1): state change: activated -> deactivating (reason 'sleeping', sys-iface-state: 'managed')
Sep 29 17:33:26 ubuntu dbus-daemon[3913]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.15' (uid=0 pid=4141>
Sep 29 17:33:26 ubuntu systemd[1]: Starting Network Manager Script Dispatcher Service...
Sep 29 17:33:26 ubuntu dbus-daemon[3913]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Sep 29 17:33:26 ubuntu systemd[1]: Started Network Manager Script Dispatcher Service.
Sep 29 17:33:26 ubuntu NetworkManager[4141]: <info>  [1664465606.7566] device (eno1): state change: deactivating -> disconnected (reason 'sleeping', sys-iface-state: 'managed')
Sep 29 17:33:26 ubuntu avahi-daemon[3912]: Withdrawing address record for fe80::xxxx:xxxx:xxxx:xxxx on eno1.
Sep 29 17:33:26 ubuntu avahi-daemon[3912]: Leaving mDNS multicast group on interface eno1.IPv6 with address fe80::xxxx:xxxx:xxxx:xxxx.
Sep 29 17:33:26 ubuntu avahi-daemon[3912]: Interface eno1.IPv6 no longer relevant for mDNS.
Sep 29 17:33:26 ubuntu NetworkManager[4141]: <info>  [1664465606.7790] dhcp4 (eno1): canceled DHCP transaction
Sep 29 17:33:26 ubuntu NetworkManager[4141]: <info>  [1664465606.7791] dhcp4 (eno1): activation: beginning transaction (timeout in 45 seconds)
Sep 29 17:33:26 ubuntu NetworkManager[4141]: <info>  [1664465606.7791] dhcp4 (eno1): state changed no lease
Sep 29 17:33:26 ubuntu systemd-resolved[4260]: eno1: Bus client reset search domain list.
Sep 29 17:33:26 ubuntu avahi-daemon[3912]: Withdrawing address record for 10.192.xxx.x on eno1.
Sep 29 17:33:26 ubuntu avahi-daemon[3912]: Leaving mDNS multicast group on interface eno1.IPv4 with address 10.192.xxx.x.
Sep 29 17:33:26 ubuntu systemd-resolved[4260]: eno1: Bus client set default route setting: no
Sep 29 17:33:26 ubuntu avahi-daemon[3912]: Interface eno1.IPv4 no longer relevant for mDNS.
Sep 29 17:33:26 ubuntu systemd-resolved[4260]: eno1: Bus client reset DNS server list.
Sep 29 17:33:26 ubuntu NetworkManager[4141]: <info>  [1664465606.8093] device (eno1): state change: disconnected -> unmanaged (reason 'sleeping', sys-iface-state: 'managed')
Sep 29 17:33:26 ubuntu systemd[1]: Reached target Sleep.
Sep 29 17:33:26 ubuntu systemd[1]: Starting Record successful boot for GRUB...
Sep 29 17:33:26 ubuntu systemd[1]: Starting System Suspend...
Sep 29 17:33:26 ubuntu systemd[1]: grub-common.service: Deactivated successfully.
Sep 29 17:33:26 ubuntu systemd[1]: Finished Record successful boot for GRUB.
Sep 29 17:33:26 ubuntu systemd-sleep[21965]: Entering sleep state 'suspend'...
Sep 29 17:33:26 ubuntu kernel: PM: suspend entry (s2idle)

There seems to be some routine tasks occuring before the system goes to sleep when it's left untouched by a human. But nothing special to me.

Version info

Ubuntu version was Linux version 5.15.0-48-generic (buildd@lcy02-amd64-080) (gcc (Ubuntu 11.2.0-19ubuntu1) 11.2.0, GNU ld (GNU Binutils for Ubuntu) 2.38) #54-Ubuntu SMP Fri Aug 26 13:26:29 UTC 2022 (Ubuntu 5.15.0-48.54-generic 5.15.53) on this disk.
And is the same on the new disk.

Hannu avatar
ca flag
`journalctl --help` => using the `--directory=PATH` option may help...
s.k avatar
cn flag
s.k
Thanks a lot for your comment @Hannu; it helped me narrowing down the issue a lot, I guess...
Hannu avatar
ca flag
As I understand your logs, they show the actual shutdown, it might be more interesting to study log entries slightly more (a few minutes?) before these too. I'd expect to see something that would trigger the shutdown.
Score:1
cn flag

You can configure systemd to disallow entering sleep mode by creating file /etc/systemd/sleep.conf and entering in it:

[Sleep]
AllowSuspend=no
AllowHibernation=no
AllowSuspendThenHibernate=no
AllowHybridSleep=no

See man systemd-sleep.conf. I don't know if a daemon-reload is enough to take this into account, or if you need to reboot.

The Debian wiki also says you can mask the appropriate systemd targets:

sudo systemctl mask sleep.target suspend.target hibernate.target hybrid-sleep.target
s.k avatar
cn flag
s.k
Thanks, I will try that. But there is no difference with the currently running Ubuntu 22.04 system on the new drive (which still didn't go to sleep for more than 24h now): `diff /mnt/ubuntu-vg/root/etc/systemd/sleep.conf /etc/systemd/sleep.conf` -> no output; so the files are the same (basically absolutely everything is commented, except the line with `[Sleep]`). Do you know by any chance if those "defaults that are set during compilation" as stated in the man can be found in any other file? <- `The default configuration is set during compilation, so configuration is only needed when it (...)`
meuh avatar
cn flag
Sorry, I don't see how to find what the defaults are, but I would assume they would all be "yes". I added another `mask` command you can try, from the Debian wiki on suspend.
s.k avatar
cn flag
s.k
Yeah I've seen that second solution on some old blogs this evening, I will try it as well asap next week. Thanks again.
mangohost

Post an answer

Most people don’t grasp that asking a lot of questions unlocks learning and improves interpersonal bonding. In Alison’s studies, for example, though people could accurately recall how many questions had been asked in their conversations, they didn’t intuit the link between questions and liking. Across four studies, in which participants were engaged in conversations themselves or read transcripts of others’ conversations, people tended not to realize that question asking would influence—or had influenced—the level of amity between the conversationalists.