-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
Hi,
This past night I could not hibernate my desktop machine, it refused.
Looking at the log, I found a clue:
<4.5> 2020-03-20 03:07:40 Telcontar sudo - - - root : TTY=pts/76 ; PWD=/root ; USER=root ; COMMAND=/usr/bin/chvt 10
<10.6> 2020-03-20 03:07:40 Telcontar sudo - - - pam_unix(sudo:session): session opened for user root by (uid=0)
<10.6> 2020-03-20 03:07:41 Telcontar sudo - - - pam_unix(sudo:session): session closed for user root
<4.5> 2020-03-20 03:07:46 Telcontar sudo - - - root : TTY=pts/76 ; PWD=/root ; USER=root ; COMMAND=/usr/bin/systemctl hibernate
<10.6> 2020-03-20 03:07:46 Telcontar sudo - - - pam_unix(sudo:session): session opened for user root by (uid=0)
<10.6> 2020-03-20 03:07:46 Telcontar sudo - - - pam_unix(sudo:session): session closed for user root
<3.6> 2020-03-20 03:07:46 Telcontar systemd 1 - - Reached target Sleep.
<3.6> 2020-03-20 03:07:46 Telcontar systemd 1 - - Starting Hibernate...
<0.7> 2020-03-20 03:07:46 Telcontar kernel - - - [317397.413158] PM: Hibernation mode set to 'shutdown'
<3.6> 2020-03-20 03:07:46 Telcontar systemd-sleep 14514 - - INFO: running /usr/lib/systemd/system-sleep/grub2.sleep for hibernate
<3.6> 2020-03-20 03:07:46 Telcontar systemd-sleep 14514 - - INFO: Running prepare-grub ..
<3.6> 2020-03-20 03:07:46 Telcontar systemd-sleep 14514 - - 2020-03-20 03:07:46+01:00 - Hibernating the system now...
<3.4> 2020-03-20 03:07:46 Telcontar systemd-sh - - - Hibernating the system now...
<3.6> 2020-03-20 03:07:46 Telcontar systemd-sleep 14514 - - service: no such service upsd.service
<3.6> 2020-03-20 03:07:46 Telcontar systemd-sleep 14514 - - running kernel is grub menu entry Main_openSUSE (vmlinuz-4.12.14-lp151.28.40-default)
<3.6> 2020-03-20 03:07:46 Telcontar systemd-sleep 14514 - - preparing boot-loader: selecting entry Main_openSUSE, kernel /boot/4.12.14-lp151.28.40-default
<3.6> 2020-03-20 03:07:47 Telcontar systemd-sleep 14514 - - running /usr/sbin/grub2-once "Main_openSUSE"
<3.6> 2020-03-20 03:07:47 Telcontar systemd-sleep 14514 - - time needed for sync: 0.5 seconds, time needed for grub: 0.2 seconds.
<3.6> 2020-03-20 03:07:47 Telcontar systemd-sleep 14514 - - INFO: Done.
<3.6> 2020-03-20 03:07:51 Telcontar systemd-sleep 14514 - - Suspending system...
<0.4> 2020-03-20 03:07:51 Telcontar kernel - - - [317402.526273] PM: Tried to create trampoline again
<0.6> 2020-03-20 03:07:51 Telcontar kernel - - - [317402.559008] PM: Syncing filesystems ...
<3.4> 2020-03-20 03:08:12 Telcontar rtkit-daemon 5395 - - The canary thread is apparently starving. Taking action.
<3.6> 2020-03-20 03:08:12 Telcontar rtkit-daemon 5395 - - Demoting known real-time threads.
<3.5> 2020-03-20 03:08:12 Telcontar rtkit-daemon 5395 - - Successfully demoted thread 5399 of process 5394 (/usr/bin/pulseaudio).
<3.5> 2020-03-20 03:08:12 Telcontar rtkit-daemon 5395 - - Successfully demoted thread 5398 of process 5394 (/usr/bin/pulseaudio).
<3.5> 2020-03-20 03:08:12 Telcontar rtkit-daemon 5395 - - Successfully demoted thread 5394 of process 5394 (/usr/bin/pulseaudio).
<3.5> 2020-03-20 03:08:12 Telcontar rtkit-daemon 5395 - - Demoted 3 threads.
<0.6> 2020-03-20 03:08:12 Telcontar kernel - - - [317403.182461] PM: done.
<0.6> 2020-03-20 03:08:12 Telcontar kernel - - - [317403.182463] Freezing user space processes ...
<0.3> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185120] Freezing of tasks failed after 20.001 seconds (2 tasks refusing to freeze, wq_busy=0):
<0.6> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185147] pool D 0 14428 5381 0x00000004
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185150] Call Trace:
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185159] ? __schedule+0x27f/0x830
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185161] schedule+0x28/0x80
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185168] request_wait_answer+0x79/0x1e0 [fuse]
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185172] ? wait_woken+0x80/0x80
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185176] __fuse_request_send+0x78/0x80 [fuse]
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185180] fuse_simple_request+0xbd/0x190 [fuse]
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185184] fuse_do_getattr+0xf3/0x2b0 [fuse]
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185190] fuse_update_attributes+0x7a/0x90 [fuse]
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185198] vfs_statx+0x79/0xb0
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185200] SYSC_newlstat+0x26/0x40
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185203] do_syscall_64+0x7b/0x160
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185204] entry_SYSCALL_64_after_hwframe+0x3d/0xa2
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185206] RIP: 0033:0x7fc61ad0f535
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185207] RSP: 002b:00007fc60d1e8738 EFLAGS: 00000246 ORIG_RAX: 0000000000000006
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185209] RAX: ffffffffffffffda RBX: 00007fc60413d5c0 RCX: 00007fc61ad0f535
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185209] RDX: 00007fc60d1e87a0 RSI: 00007fc60d1e87a0 RDI: 00007fc604172fd0
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185210] RBP: 0000559c247e1590 R08: 00007fc6040aa860 R09: 00007fc61ad60470
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185211] R10: 0000000000100007 R11: 0000000000000246 R12: 00007fc604172fd0
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185212] R13: 00007fc60d1e8920 R14: 00007fc604172fd0 R15: 00007fc604017110
<0.6> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185253] mc D 0 3425 1 0x00000004 <=======================
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185255] Call Trace:
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185257] ? __schedule+0x27f/0x830
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185259] schedule+0x28/0x80
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185261] request_wait_answer+0x110/0x1e0 [fuse]
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185263] ? wait_woken+0x80/0x80
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185265] __fuse_request_send+0x78/0x80 [fuse]
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185268] fuse_simple_request+0xbd/0x190 [fuse]
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185271] fuse_do_getattr+0xf3/0x2b0 [fuse]
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185275] fuse_update_attributes+0x7a/0x90 [fuse]
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185276] vfs_statx+0x79/0xb0
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185278] SYSC_newlstat+0x26/0x40
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185279] do_syscall_64+0x7b/0x160
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185281] entry_SYSCALL_64_after_hwframe+0x3d/0xa2
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185282] RIP: 0033:0x7f9d3c1b1535
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185282] RSP: 002b:00007fff021b3808 EFLAGS: 00000246 ORIG_RAX: 0000000000000006
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185284] RAX: ffffffffffffffda RBX: 00007fff021b4940 RCX: 00007f9d3c1b1535
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185285] RDX: 00007fff021b3840 RSI: 00007fff021b3840 RDI: 00007fff021b3940
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185286] RBP: 00007fff021b3910 R08: 0000000000000000 R09: 00007f9d3c202290
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185286] R10: 00007f9d3c1ffe30 R11: 0000000000000246 R12: 00007fff021b3940
<0.4> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185287] R13: 000056285945211a R14: 0000562859452124 R15: 00007fff021b3954
<0.6> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185291] OOM killer enabled.
<0.6> 2020-03-20 03:08:12 Telcontar kernel - - - [317423.185292] Restarting tasks ... done.
<3.5> 2020-03-20 03:08:12 Telcontar systemd 1 - - systemd-hibernate.service: Main process exited, code=exited, status=1/FAILURE
<3.3> 2020-03-20 03:08:12 Telcontar systemd 1 - - Failed to start Hibernate.
<3.4> 2020-03-20 03:08:12 Telcontar systemd 1 - - Dependency failed for Hibernate.
<4.6> 2020-03-20 03:08:12 Telcontar systemd-logind 1557 - - Operation 'sleep' finished.
<3.5> 2020-03-20 03:08:12 Telcontar systemd 1 - - hibernate.target: Job hibernate.target/start failed with result 'dependency'.
<3.6> 2020-03-20 03:08:12 Telcontar systemd 1 - - sleep.target: Unit not needed anymore. Stopping.
<3.5> 2020-03-20 03:08:12 Telcontar systemd 1 - - systemd-hibernate.service: Unit entered failed state.
<3.4> 2020-03-20 03:08:12 Telcontar systemd 1 - - systemd-hibernate.service: Failed with result 'exit-code'.
<3.6> 2020-03-20 03:08:12 Telcontar systemd 1 - - Stopped target Sleep.
The user run application 'mc' (Midnight Commander) was blocking hibernation
(and now I see there was another application named 'pool').
I tried to kill 'mc' with killall -9. It still refused. I killed the
terminal that had it, no way. In the end, I had to poweroff the machine
instead.
I think that mc was blocked because it had open a remote directory
externally:
sshfs cer@192.168.1.134:/ ~/fusermount/
and that other machine had been hibernated a minute before.
How can it be that a plebeian app stops the almighty kernel in its tracks?
- --
Cheers
Carlos E. R.
(from 15.1 x86_64 at Telcontar)
-----BEGIN PGP SIGNATURE-----
iHoEARECADoWIQQZEb51mJKK1KpcU/W1MxgcbY1H1QUCXnSa+Bwccm9iaW4ubGlz
dGFzQHRlbGVmb25pY2EubmV0AAoJELUzGBxtjUfVY7kAmwQyudMUHLBapNUWQTAU
RrOXoQ4dAJ9kHsU9bLDY79jb7fozH2sASLOOlw==
=Vbxz
-----END PGP SIGNATURE-----
--
To unsubscribe, e-mail: opensuse+unsubscribe(a)opensuse.org
To contact the owner, e-mail: opensuse+owner(a)opensuse.org