-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
Hi,
The other day, talking about hibernation, I said that sometimes
hibernation would simply fail for me. Well, this night my computer failed
to hibernate - this is the log:
<22>1 2017-12-18T04:28:37.783421+01:00 Telcontar clamd 3884 - - SelfCheck: Database status OK.
<30>1 2017-12-18T04:29:23.150889+01:00 Telcontar systemd 1 - - Reached target Sleep.
<30>1 2017-12-18T04:29:23.150889+01:00 Telcontar systemd 1 - - Reached target Sleep.
<30>1 2017-12-18T04:29:23.172199+01:00 Telcontar systemd 1 - - Starting Hibernate...
<7>1 2017-12-18T04:29:23.179861+01:00 Telcontar kernel - - - [569194.797529] PM: Hibernation mode set to 'platform'
<30>1 2017-12-18T04:29:23.191726+01:00 Telcontar systemd-sleep 16509 - - INFO: running /usr/lib/systemd/system-sleep/grub2.sleep for hibernate
<30>1 2017-12-18T04:29:23.191973+01:00 Telcontar systemd-sleep 16509 - - INFO: Running prepare-grub ..
<30>1 2017-12-18T04:29:23.192395+01:00 Telcontar systemd-sleep 16509 - - 2017-12-18 04:29:23+01:00 - Hibernating the system now...
<30>1 2017-12-18T04:29:23.198353+01:00 Telcontar systemd 1 - - Stopping Deferred execution scheduler...
<28>1 2017-12-18T04:29:23.202597+01:00 Telcontar systemd-sh - - - Hibernating the system now...
<30>1 2017-12-18T04:29:23.219928+01:00 Telcontar systemd-sleep 16509 - - service: no such service upsd.service
<30>1 2017-12-18T04:29:23.220710+01:00 Telcontar systemd 1 - - Stopped Deferred execution scheduler.
<30>1 2017-12-18T04:29:23.512897+01:00 Telcontar systemd-sleep 16509 - - running kernel is grub menu entry openSUSE Leap 42.2 (vmlinuz-4.4.92-18.36-default)
<30>1 2017-12-18T04:29:23.513124+01:00 Telcontar systemd-sleep 16509 - - preparing boot-loader: selecting entry openSUSE Leap 42.2, kernel /boot/4.4.92-18.36-default
<30>1 2017-12-18T04:29:29.227808+01:00 Telcontar systemd-sleep 16509 - - running /usr/sbin/grub2-once "openSUSE Leap 42.2"
<30>1 2017-12-18T04:29:29.371469+01:00 Telcontar systemd-sleep 16509 - - time needed for sync: 5.7 seconds, time needed for grub: 0.1 seconds.
<30>1 2017-12-18T04:29:29.371708+01:00 Telcontar systemd-sleep 16509 - - INFO: Done.
<30>1 2017-12-18T04:29:29.371854+01:00 Telcontar systemd-sleep 16509 - - Suspending system...
<6>1 2017-12-18T04:29:41.548570+01:00 Telcontar kernel - - - [569202.198976] PM: Syncing filesystems ... done.
<6>1 2017-12-18T04:29:41.747276+01:00 Telcontar kernel - - - [569202.767822] Freezing user space processes ... (elapsed 0.016 seconds) done.
<7>1 2017-12-18T04:29:41.747281+01:00 Telcontar kernel - - - [569202.784257] PM: Marking nosave pages: [mem 0x00000000-0x00000fff]
<7>1 2017-12-18T04:29:41.747282+01:00 Telcontar kernel - - - [569202.784259] PM: Marking nosave pages: [mem 0x0009f000-0x000fffff]
<7>1 2017-12-18T04:29:41.747283+01:00 Telcontar kernel - - - [569202.784262] PM: Marking nosave pages: [mem 0xbff90000-0xffffffff]
<7>1 2017-12-18T04:29:41.747284+01:00 Telcontar kernel - - - [569202.784866] PM: Basic memory bitmaps created
<6>1 2017-12-18T04:29:41.747286+01:00 Telcontar kernel - - - [569202.784888] PM: Preallocating image memory...
<7>1 2017-12-18T04:29:41.747287+01:00 Telcontar kernel - - - [569212.924919] PM: Basic memory bitmaps freed
<6>1 2017-12-18T04:29:41.747288+01:00 Telcontar kernel - - - [569212.924928] Restarting tasks ... done.
<28>1 2017-12-18T04:29:41.820886+01:00 Telcontar rtkit-daemon 4543 - - The canary thread is apparently starving. Taking action.
<29>1 2017-12-18T04:29:41.940237+01:00 Telcontar systemd 1 - - systemd-hibernate.service: Main process exited, code=exited, status=1/FAILURE
<30>1 2017-12-18T04:29:41.941655+01:00 Telcontar rtkit-daemon 4543 - - Demoting known real-time threads.
<27>1 2017-12-18T04:29:41.941831+01:00 Telcontar systemd 1 - - Failed to start Hibernate.
<29>1 2017-12-18T04:29:41.950777+01:00 Telcontar rtkit-daemon 4543 - - Successfully demoted thread 4549 of process 4542 (/usr/bin/pulseaudio).
<28>1 2017-12-18T04:29:41.950978+01:00 Telcontar systemd 1 - - Dependency failed for Hibernate.
<29>1 2017-12-18T04:29:41.951114+01:00 Telcontar rtkit-daemon 4543 - - Successfully demoted thread 4548 of process 4542 (/usr/bin/pulseaudio).
<29>1 2017-12-18T04:29:41.964488+01:00 Telcontar rtkit-daemon 4543 - - Successfully demoted thread 4542 of process 4542 (/usr/bin/pulseaudio).
<29>1 2017-12-18T04:29:41.964740+01:00 Telcontar rtkit-daemon 4543 - - Demoted 3 threads.
<28>1 2017-12-18T04:29:41.964870+01:00 Telcontar console-kit-daemon 4445 - - WARNING: Error waiting for native console 12 activation: Resource temporarily unavailable
<28>1 2017-12-18T04:29:41.970606+01:00 Telcontar console-kit-daemon 4445 - - WARNING: Error waiting for native console 5 activation: Resource temporarily unavailable
<30>1 2017-12-18T04:29:42.037062+01:00 Telcontar console-kit-daemon 4445 - - console-kit-daemon[4445]: WARNING: Error waiting for native console 12 activation: Resource temporarily unavailable
<30>1 2017-12-18T04:29:42.037261+01:00 Telcontar console-kit-daemon 4445 - - console-kit-daemon[4445]: WARNING: Error waiting for native console 5 activation: Resource temporarily unavailable
<29>1 2017-12-18T04:29:43.069508+01:00 Telcontar systemd 1 - - hibernate.target: Job hibernate.target/start failed with result 'dependency'.
<30>1 2017-12-18T04:29:43.069771+01:00 Telcontar systemd 1 - - sleep.target: Unit not needed anymore. Stopping.
<38>1 2017-12-18T04:29:43.078001+01:00 Telcontar systemd-logind 1706 - - Operation 'sleep' finished.
<29>1 2017-12-18T04:29:43.081947+01:00 Telcontar systemd 1 - - systemd-hibernate.service: Unit entered failed state.
<28>1 2017-12-18T04:29:43.082123+01:00 Telcontar systemd 1 - - systemd-hibernate.service: Failed with result 'exit-code'.
<30>1 2017-12-18T04:29:43.091305+01:00 Telcontar systemd 1 - - Stopped target Sleep.
<86>1 2017-12-18T04:30:01.946295+01:00 Telcontar cron 16841 - - pam_unix(crond:session): session opened for user cer by (uid=0)
<86>1 2017-12-18T04:30:01.947130+01:00 Telcontar cron 16840 - - pam_unix(crond:session): session opened for user wwwrun by (uid=0)
<86>1 2017-12-18T04:30:01.947316+01:00 Telcontar cron 16839 - - pam_unix(crond:session): session opened for user root by (uid=0)
The reason is not clear:
systemd 1 - - Dependency failed for Hibernate.
systemd-hibernate.service: Failed with result 'exit-code'.
systemd-hibernate.service: Main process exited, code=exited, status=1/FAILURE
Well, I know that it failed, but why?
Telcontar:~ # systemctl status systemd-hibernate
● systemd-hibernate.service - Hibernate
Loaded: loaded (/usr/lib/systemd/system/systemd-hibernate.service; static; vendor preset: disabled)
Active: failed (Result: exit-code) since Mon 2017-12-18 04:29:41 CET; 7h ago
Docs: man:systemd-suspend.service(8)
Process: 16509 ExecStart=/usr/lib/systemd/systemd-sleep hibernate (code=exited, status=1/FAILURE)
Main PID: 16509 (code=exited, status=1/FAILURE)
Dec 18 04:29:23 Telcontar systemd-sleep[16509]: running kernel is grub menu entry openSUSE Leap 42.2 (vmlinuz-4.4.92-18.36-default)
Dec 18 04:29:23 Telcontar systemd-sleep[16509]: preparing boot-loader: selecting entry openSUSE Leap 42.2, kernel /boot/4.4.92-18.36-default
Dec 18 04:29:29 Telcontar systemd-sleep[16509]: running /usr/sbin/grub2-once "openSUSE Leap 42.2"
Dec 18 04:29:29 Telcontar systemd-sleep[16509]: time needed for sync: 5.7 seconds, time needed for grub: 0.1 seconds.
Dec 18 04:29:29 Telcontar systemd-sleep[16509]: INFO: Done.
Dec 18 04:29:29 Telcontar systemd-sleep[16509]: Suspending system...
Dec 18 04:29:41 Telcontar systemd[1]: systemd-hibernate.service: Main process exited, code=exited, status=1/FAILURE
Dec 18 04:29:41 Telcontar systemd[1]: Failed to start Hibernate.
Dec 18 04:29:43 Telcontar systemd[1]: systemd-hibernate.service: Unit entered failed state.
Dec 18 04:29:43 Telcontar systemd[1]: systemd-hibernate.service: Failed with result 'exit-code'.
Telcontar:~ #
I know that if I try again it will very probably succeed, but I would like
to know why it failed this time.
And of course, on the terminal that I called the command to hibernate, I
got no error printed, it just returns as usual.
This is the command I use:
Telcontar:~ # cat /usr/local/bin/hibernate
#!/bin/bash
date --rfc-3339=seconds
systemctl hibernate
sleep 3
xscreensaver-command -lock
Telcontar:~ #
And this was the result:
Telcontar:~ # hibernate
2017-12-18 04:29:23+01:00
xscreensaver-command: activating and locking.
Telcontar:~ #
- --
Cheers
Carlos E. R.
(from 42.2 x86_64 "Malachite" at Telcontar)
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2
iEYEARECAAYFAlo3obwACgkQtTMYHG2NR9UAnQCdHt/LyoJF6h+kOSDK45BYXM3D
Q58AoI76syr5PxRMbeIiVF1AIK5qFlhS
=UmHM
-----END PGP SIGNATURE-----