Need help diagnosing failed hibernation

@_Undercover

Did you correct this?
It’s not clear to me that you did.

… just one idea of a couple

1 Like

Thanks for the reminder, I’ve changed to swappiness value using sysctl, but I forgot I had a configuration at /etc/sysctl.d/99-sysctl.conf, which means that the value was set back to 0 when I rebooted my machine…

I made this change permanent and will now test my system for another week or so, my bad.

I forgot to add that today, after hibernating, instead of having the screen darken with the TTY saying something related to image allocation being pages short, I have this:

This was earlier today and before the changes to swappiness, which means that it was still set to be zero.

Okay it seems that setting swappiness to 10 fixed it, at least so far, however my system seems to be swapping too much and, because I have a bunch of windows open, it can be quite slow when switching desktops, which isn’t nice.

For example right now I have 3.5 GiB of RAM filled up, with 8 GiB total, and 2.5 GiB of swap space filled up.

In my mind this shouldn’t be as slow as it is, which is very, because I have an NVMe SSD.

But still, I would like to only use swap for hibernation. Would setting it to 1 still possibly fix the hibernation issue, but have more stuff in RAM? Would making a custom hibernation script that would only toggle swap right before hibernation be a good workaround?

False alarm, the issue persists.

On a clean boot, didn’t even open up Spotify, only Firefox, Atom, Thunderbird and Kitty open (obviously other background services running which I’m not 100% aware), one of them refuses to hibernate.
I tried to hibernate and it failed. When I tried it again the following message was shown, in a TTY like screen:

[3434.607049] Freezing of tasks failed after 20.005 seconds (1 tasks refusing to freeze, wq_busy=0):

According to a forum post I should look in ps ax for a D on the third column.
After rebooting I looked for such an entry and found this:

     99 ?        D      0:00 [kworker/u8:1+events_unbound]

However I managed to successfully hibernate my machine, so I’ll wait for the next time I can’t hibernate and repeat this process.

If there’s anywhere I should look for errors and figure out who’s the culprit, please do let me know.

Hibernation failed, here’s the output of ps ax:

$ ps ax
    PID TTY      STAT   TIME COMMAND
      1 ?        Ss     0:00 /sbin/init
      2 ?        S      0:00 [kthreadd]
      3 ?        I<     0:00 [rcu_gp]
      4 ?        I<     0:00 [rcu_par_gp]
      8 ?        I<     0:00 [mm_percpu_wq]
      9 ?        S      0:00 [ksoftirqd/0]
     10 ?        I      0:02 [rcu_preempt]
     11 ?        S      0:00 [rcub/0]
     12 ?        S      0:00 [rcuc/0]
     13 ?        S      0:00 [migration/0]
     14 ?        S      0:00 [idle_inject/0]
     16 ?        S      0:00 [cpuhp/0]
     17 ?        S      0:00 [cpuhp/1]
     18 ?        S      0:00 [idle_inject/1]
     19 ?        S      0:00 [migration/1]
     20 ?        S      0:00 [rcuc/1]
     21 ?        S      0:00 [ksoftirqd/1]
     23 ?        I<     0:00 [kworker/1:0H-kblockd]
     24 ?        S      0:00 [cpuhp/2]
     25 ?        S      0:00 [idle_inject/2]
     26 ?        S      0:00 [migration/2]
     27 ?        S      0:00 [rcuc/2]
     28 ?        S      0:00 [ksoftirqd/2]
     30 ?        I<     0:00 [kworker/2:0H-kblockd]
     31 ?        S      0:00 [cpuhp/3]
     32 ?        S      0:00 [idle_inject/3]
     33 ?        S      0:00 [migration/3]
     34 ?        S      0:00 [rcuc/3]
     35 ?        S      0:00 [ksoftirqd/3]
     37 ?        I<     0:00 [kworker/3:0H-kblockd]
     38 ?        S      0:00 [kdevtmpfs]
     39 ?        I<     0:00 [netns]
     40 ?        S      0:00 [rcu_tasks_kthre]
     41 ?        S      0:00 [kauditd]
     43 ?        S      0:00 [khungtaskd]
     44 ?        S      0:00 [oom_reaper]
     45 ?        I<     0:00 [writeback]
     46 ?        S      0:00 [kcompactd0]
     47 ?        SN     0:00 [ksmd]
     48 ?        SN     0:00 [khugepaged]
     93 ?        I<     0:00 [kintegrityd]
     94 ?        I<     0:00 [kblockd]
     95 ?        I<     0:00 [blkcg_punt_bio]
     96 ?        I<     0:00 [edac-poller]
     97 ?        I<     0:00 [devfreq_wq]
     98 ?        S      0:00 [watchdogd]
    100 ?        S      0:02 [kswapd0]
    102 ?        I<     0:00 [kthrotld]
    103 ?        S      0:00 [irq/123-aerdrv]
    104 ?        S      0:00 [irq/126-aerdrv]
    106 ?        I<     0:00 [acpi_thermal_pm]
    107 ?        I<     0:00 [nvme-wq]
    108 ?        I<     0:00 [nvme-reset-wq]
    109 ?        I<     0:00 [nvme-delete-wq]
    112 ?        I<     0:00 [ipv6_addrconf]
    122 ?        I<     0:00 [kstrp]
    127 ?        I<     0:00 [kworker/u9:0-rb_allocator]
    136 ?        I<     0:00 [charger_manager]
    160 ?        I<     0:00 [ata_sff]
    163 ?        I<     0:00 [sdhci]
    164 ?        S      0:00 [scsi_eh_0]
    165 ?        I<     0:00 [scsi_tmf_0]
    166 ?        S      0:00 [scsi_eh_1]
    167 ?        I<     0:00 [scsi_tmf_1]
    169 ?        S      0:00 [scsi_eh_2]
    170 ?        I<     0:00 [scsi_tmf_2]
    177 ?        I<     0:00 [kworker/1:1H-events_highpri]
    184 ?        S      0:00 [jbd2/nvme0n1p6-]
    185 ?        I<     0:00 [ext4-rsv-conver]
    186 ?        I<     0:00 [kworker/2:1H-events_highpri]
    219 ?        Ss     0:00 /usr/lib/systemd/systemd-journald
    236 ?        Ss     0:00 /usr/lib/systemd/systemd-udevd
    240 ?        I<     0:00 [kworker/3:1H-kblockd]
    241 ?        I<     0:00 [kworker/0:1H-events_highpri]
    315 ?        I<     0:00 [tpm_dev_wq]
    344 ?        Ss     0:54 /usr/bin/mount.ntfs-3g /dev/nvme0n1p8 /home/undercover/ze -o rw,umask=007,uid=1000,gid=1000
    374 ?        I<     0:00 [cfg80211]
    408 ?        I<     0:00 [cryptd]
    412 ?        S      0:09 [irq/137-iwlwifi]
    418 ?        Ssl    0:00 /usr/lib/systemd/systemd-timesyncd
    466 ?        Ss     0:00 /usr/bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation --syslog-only
    475 ?        Ssl    0:01 /usr/bin/NetworkManager --no-daemon
    484 ?        Ss     0:00 /usr/lib/systemd/systemd-logind
    497 ?        Ss     0:00 /usr/bin/cupsd -l
    499 ?        Ssl    2:29 /usr/bin/mono /opt/duplicati-latest/Duplicati.Server.exe --webservice-port=8200
    515 ?        I<     0:00 [kworker/u9:1-rb_allocator]
    522 ?        Ssl    0:00 /usr/lib/colord
    748 ?        Ss     0:00 /usr/bin/wpa_supplicant -u -s -O /run/wpa_supplicant
    852 ?        Ss     0:00 /usr/bin/python3 -u -m optimus_manager.daemon
    855 ?        SLsl   0:00 /usr/bin/lightdm
    882 tty7     Ssl+   7:35 /usr/lib/Xorg :0 -seat seat0 -auth /run/lightdm/root/:0 -nolisten tcp vt7 -novtswitch
    890 ?        Ssl    0:00 /usr/lib/accounts-daemon
    924 ?        Ssl    0:00 /usr/lib/polkit-1/polkitd --no-debug
   1099 ?        Ssl    0:00 /usr/lib/upowerd
   1134 ?        Sl     0:00 lightdm --session-child 12 19
   1160 ?        Ss     0:00 /usr/lib/systemd/systemd --user
   1161 ?        S      0:00 (sd-pam)
   1169 ?        Ss     0:02 i3
   1182 ?        Ss     0:04 /usr/bin/dbus-daemon --session --address=systemd: --nofork --nopidfile --systemd-activation --syslog-only
   1189 ?        Sl     0:00 /usr/lib/polkit-gnome/polkit-gnome-authentication-agent-1
   1193 ?        Sl     0:03 /usr/bin/xfce4-power-manager
   1195 ?        Sl     0:00 /usr/bin/python /usr/bin/udiskie -a -n -t
   1197 ?        S      0:28 unclutter --timeout 5 --ignore-scrolling --jitter 15
   1199 ?        Ssl    0:01 ksuperkey
   1203 ?        S      0:00 python3 /usr/bin/alternating_layouts.py
   1214 ?        Ssl    2:43 picom -b --config /home/undercover/.config/picom/picom.conf
   1217 ?        Sl     0:08 /usr/bin/python /usr/bin/flashfocus
   1218 ?        Sl     2:02 polybar -c /home/undercover/.config/polybar/config.ini main
   1222 ?        Ssl    0:00 /usr/lib/gvfsd
   1228 ?        Sl     0:00 /usr/lib/gvfsd-fuse /run/user/1000/gvfs -f
   1243 ?        Ssl    0:00 /usr/lib/udisks2/udisksd
   1248 ?        Ssl    0:00 /usr/lib/at-spi-bus-launcher
   1255 ?        S      0:00 /usr/bin/dbus-daemon --config-file=/usr/share/defaults/at-spi2/accessibility.conf --nofork --print-address 3
   1262 ?        Sl     0:00 /usr/lib/xfce4/xfconf/xfconfd
   1264 ?        Sl     0:01 /usr/lib/at-spi2-registryd --use-gnome-session
   1268 ?        Ssl    0:01 /usr/bin/dunst
   1272 ?        Ssl    0:18 /usr/bin/pulseaudio --daemonize=no --log-target=journal
   1277 ?        SNsl   0:00 /usr/lib/rtkit-daemon
   1296 ?        Sl     0:00 /usr/lib/pulse/gsettings-helper
   1320 ?        Ssl    0:00 /usr/bin/espanso daemon
   1325 ?        Sl     0:02 /usr/bin/espanso worker
   1382 ?        S      0:00 /bin/bash /usr/bin/atom
   1384 ?        Sl     0:49 /usr/lib/electron9/electron --executed-from=/home/undercover --pid=1380 /usr/lib/atom/atom
   1388 ?        S      0:00 /usr/lib/electron9/electron --type=zygote --no-zygote-sandbox
   1389 ?        S      0:00 /usr/lib/electron9/electron --type=zygote
   1391 ?        S      0:00 /usr/lib/electron9/electron --type=zygote
   1417 ?        Sl     0:01 /usr/lib/electron9/electron --type=gpu-process --field-trial-handle=12563034494411719120,17347136584692199961,131072 --enable-features=WebComponentsV0Enabled --disable-features=Spare
   1422 ?        Sl     0:00 /usr/lib/electron9/electron --type=utility --field-trial-handle=12563034494411719120,17347136584692199961,131072 --enable-features=WebComponentsV0Enabled --disable-features=SpareRend
   1446 ?        Sl     0:28 /usr/lib/electron9/electron --type=renderer --enable-experimental-web-platform-features --field-trial-handle=12563034494411719120,17347136584692199961,131072 --enable-features=WebCom
   1495 ?        Sl     0:05 kitty
   1509 pts/0    Ss+    0:02 /usr/bin/zsh -l
   1512 pts/0    S      0:00 /usr/bin/zsh -l
   1553 pts/0    Sl     0:00 /home/undercover/.cache/gitstatus/gitstatusd-linux-x86_64 -G v1.0.0 -s 1 -u 1 -d 1 -c 1 -m -1 -v FATAL -t 8
   1630 ?        S      0:00 [nv_queue]
   1631 ?        S      0:00 [nv_queue]
   1896 ?        SLl    0:39 /usr/lib/thunderbird/thunderbird
   2009 ?        Sl     0:02 /usr/lib/thunderbird/thunderbird -contentproc -childID 1 -isForBrowser -prefsLen 1 -prefMapSize 266956 -jsInit 285980 -parentBuildID 20210917145327 -appdir /usr/lib/thunderbird 1896 
   2032 ?        Sl     0:00 /usr/lib/thunderbird/thunderbird -contentproc -childID 2 -isForBrowser -prefsLen 1 -prefMapSize 266956 -jsInit 285980 -parentBuildID 20210917145327 -appdir /usr/lib/thunderbird 1896 
   2528 ?        SLl    0:22 /usr/lib/electron13/electron --disable-dev-mode /usr/lib/element/app.asar
   2531 ?        S      0:00 /usr/lib/electron13/electron --type=zygote --no-zygote-sandbox
   2532 ?        S      0:00 /usr/lib/electron13/electron --type=zygote
   2534 ?        S      0:00 /usr/lib/electron13/electron --type=zygote
   2559 ?        Sl     0:04 /usr/lib/electron13/electron --type=gpu-process --field-trial-handle=6295278442994009915,4718314158585865186,131072 --enable-features=WebRTCPipeWireCapturer --disable-features=Cookie
   2566 ?        Sl     0:11 /usr/lib/electron13/electron --type=utility --utility-sub-type=network.mojom.NetworkService --field-trial-handle=6295278442994009915,4718314158585865186,131072 --enable-features=WebR
   2572 ?        Sl     1:08 /usr/lib/electron13/electron --type=renderer --field-trial-handle=6295278442994009915,4718314158585865186,131072 --enable-features=WebRTCPipeWireCapturer --disable-features=CookiesWi
   5708 ?        I      0:01 [kworker/0:1-events]
  10849 ?        Sl     7:37 /usr/lib/firefox/firefox
  10944 ?        Sl     2:16 /usr/lib/firefox/firefox -contentproc -childID 1 -isForBrowser -prefsLen 1 -prefMapSize 257216 -jsInit 285716 -parentBuildID 20210924002311 -appdir /usr/lib/firefox/browser 10849 tru
  10975 ?        Sl     1:11 /usr/lib/firefox/firefox -contentproc -childID 2 -isForBrowser -prefsLen 217 -prefMapSize 257216 -jsInit 285716 -parentBuildID 20210924002311 -appdir /usr/lib/firefox/browser 10849 t
  11058 ?        Sl     0:11 /usr/lib/firefox/firefox -contentproc -childID 3 -isForBrowser -prefsLen 5785 -prefMapSize 257216 -jsInit 285716 -parentBuildID 20210924002311 -appdir /usr/lib/firefox/browser 10849 
  11081 ?        Sl     0:00 /usr/lib/firefox/firefox -contentproc -parentBuildID 20210924002311 -prefsLen 6715 -prefMapSize 257216 -appdir /usr/lib/firefox/browser 10849 true socket
  11437 ?        Sl     0:00 /usr/lib/firefox/firefox -contentproc -parentBuildID 20210924002311 -prefsLen 7110 -prefMapSize 257216 -appdir /usr/lib/firefox/browser 10849 true rdd
  11727 ?        Sl     1:10 /usr/lib/firefox/firefox -contentproc -childID 4 -isForBrowser -prefsLen 7207 -prefMapSize 257216 -jsInit 285716 -parentBuildID 20210924002311 -appdir /usr/lib/firefox/browser 10849 
  11776 ?        Sl     0:02 kitty
  11782 pts/1    Ss+    0:05 /usr/bin/zsh -l
  11785 pts/1    S      0:00 /usr/bin/zsh -l
  11816 pts/1    Sl     0:00 /home/undercover/.cache/gitstatus/gitstatusd-linux-x86_64 -G v1.0.0 -s 1 -u 1 -d 1 -c 1 -m -1 -v FATAL -t 8
  12015 ?        Sl     0:08 /usr/lib/firefox/firefox -contentproc -childID 5 -isForBrowser -prefsLen 7208 -prefMapSize 257216 -jsInit 285716 -parentBuildID 20210924002311 -appdir /usr/lib/firefox/browser 10849 
  17832 ?        I      0:00 [kworker/1:1-cgroup_destroy]
  21882 ?        Sl     0:06 /usr/lib/firefox/firefox -contentproc -childID 10 -isForBrowser -prefsLen 7417 -prefMapSize 257216 -jsInit 285716 -parentBuildID 20210924002311 -appdir /usr/lib/firefox/browser 10849
  21965 ?        I      0:00 [kworker/1:3-events]
  22232 ?        I      0:00 [kworker/3:0-events]
  22429 ?        S      0:00 [irq/127-mei_me]
  22430 ?        S      0:00 [irq/134-mmc0]
  22464 ?        I      0:02 [kworker/u8:54-events_unbound]
  22679 ?        I<     0:00 [kworker/0:2H]
  22829 ?        I      0:00 [kworker/3:3-events]
  23355 ?        Sl     0:06 /usr/lib/firefox/firefox -contentproc -childID 14 -isForBrowser -prefsLen 7470 -prefMapSize 257216 -jsInit 285716 -parentBuildID 20210924002311 -appdir /usr/lib/firefox/browser 10849
  23415 ?        SLs    0:00 /usr/bin/gpg-agent --supervised
  23711 ?        Sl     0:16 /usr/lib/firefox/firefox -contentproc -childID 15 -isForBrowser -prefsLen 7470 -prefMapSize 257216 -jsInit 285716 -parentBuildID 20210924002311 -appdir /usr/lib/firefox/browser 10849
  24718 ?        I      0:01 [kworker/u8:0-events_unbound]
  24852 ?        I      0:00 [kworker/2:0-events]
  24965 ?        Sl     0:19 /usr/lib/firefox/firefox -contentproc -childID 16 -isForBrowser -prefsLen 10610 -prefMapSize 257216 -jsInit 285716 -parentBuildID 20210924002311 -appdir /usr/lib/firefox/browser 1084
  25909 ?        I      0:00 [kworker/2:1-events]
  25910 ?        I      0:00 [kworker/0:2-events]
  26181 ?        I      0:00 [kworker/u8:3-flush-259:0]
  26726 ?        I      0:00 [kworker/u8:1-flush-259:0]
  26928 ?        I      0:00 [kworker/2:2-events]
  26929 ?        I      0:00 [kworker/2:3]
  27110 ?        D      0:00 [kworker/u8:2+events_unbound]
  27115 ?        I      0:00 [kworker/1:0-events]
  27271 ?        I      0:00 [kworker/0:0-events]
  27273 ?        I      0:00 [kworker/3:1-mm_percpu_wq]
  27276 ?        I      0:00 [kworker/3:2]
  27448 ?        Sl     0:00 kitty
  27454 pts/2    Ss     0:00 /usr/bin/zsh -l
  27457 pts/2    S      0:00 /usr/bin/zsh -l
  27485 pts/2    S      0:00 xclip
  27489 pts/2    Sl     0:00 /home/undercover/.cache/gitstatus/gitstatusd-linux-x86_64 -G v1.0.0 -s 1 -u 1 -d 1 -c 1 -m -1 -v FATAL -t 8
  27503 pts/2    R+     0:00 ps ax

There’s only one entry with D on it:

  27110 ?        D      0:00 [kworker/u8:2+events_unbound]

I just now saw that the exit code seems to be different (again, no Spotify running in the background, Atom, Firefox, Kitty, Thunderbird, Element and Nautilus are open and the same background services as usual):

set 28 23:58:07 Legion systemd[1]: Starting Hibernate...
set 28 23:58:07 Legion systemd-sleep[36737]: [13] INFO: # Pre-suspend hook
set 28 23:58:07 Legion systemd-sleep[36737]: [13] INFO: Previous state was: {'type': 'done', 'switch_id': '20210928T174958', 'current_mode': 'integrated'}
set 28 23:58:07 Legion systemd-sleep[36737]: [14] INFO: Switching option: none
set 28 23:58:07 Legion systemd-sleep[36737]: [14] INFO: Turning Nvidia GPU back on
set 28 23:58:07 Legion systemd-sleep[36779]: modinfo: ERROR: Module bbswitch not found.
set 28 23:58:07 Legion systemd-sleep[36783]: modinfo: ERROR: Module acpi_call not found.
set 28 23:58:08 Legion systemd-sleep[36737]: [512] INFO: switching=none, nothing to do
set 28 23:58:08 Legion systemd-sleep[36737]: [512] INFO: Writing state {'type': 'pending_post_resume', 'switch_id': '20210928T174958', 'current_mode': 'integrated'}
set 28 23:58:08 Legion systemd-sleep[36737]: [512] INFO: Pre-suspend hook completed successfully.
set 28 23:58:08 Legion systemd-sleep[36734]: Entering sleep state 'hibernate'...
set 28 23:58:28 Legion systemd-sleep[36734]: Failed to put system to sleep. System resumed again: Device or resource busy
set 28 23:58:28 Legion systemd-sleep[36894]: [11] INFO: # Post-resume hook
set 28 23:58:28 Legion systemd-sleep[36894]: [12] INFO: Previous state was: {'type': 'pending_post_resume', 'switch_id': '20210928T174958', 'current_mode': 'integrated'}
set 28 23:58:28 Legion systemd-sleep[36894]: [13] INFO: Turning Nvidia GPU off again
set 28 23:58:28 Legion systemd-sleep[36945]: modinfo: ERROR: Module bbswitch not found.
set 28 23:58:28 Legion systemd-sleep[36950]: modinfo: ERROR: Module acpi_call not found.
set 28 23:58:29 Legion systemd-sleep[36894]: [467] INFO: switching=none, nothing to do
set 28 23:58:29 Legion systemd-sleep[36894]: [467] INFO: Writing state {'type': 'done', 'switch_id': '20210928T174958', 'current_mode': 'integrated'}
set 28 23:58:29 Legion systemd-sleep[36894]: [468] INFO: Post-resume hook completed successfully.
set 28 23:58:29 Legion systemd[1]: systemd-hibernate.service: Main process exited, code=exited, status=1/FAILURE
set 28 23:58:29 Legion systemd[1]: systemd-hibernate.service: Failed with result 'exit-code'.
set 28 23:58:29 Legion systemd[1]: Failed to start Hibernate.
set 28 23:58:29 Legion systemd[1]: systemd-hibernate.service: Consumed 2.198s CPU time.

EDIT: Right making this post, which means 5 minutes after the failed hibernation attempt, I’ve tried to hibernate again, the same message saying that a task was refusing to freeze showed up in the TTY (see 2 posts above for more on that message), yet it hibernated, with the same pattern of blanking the screen, shutting down lighting on peripherals, lighting up the screen and peripherals again, and hibernating with an audible pop on the headset. Quite inconsistent…