Bug 1645870

Summary: systemctl hibernate on EFI-boot returns "Failed to hibernate system via logind: Resume not configured, can't hibernate" on Fedora 29
Product: [Fedora] Fedora Reporter: Ranjan Maitra <itsme_410>
Component: systemdAssignee: systemd-maint
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: urgent Docs Contact:
Priority: unspecified    
Version: 29CC: arjunak234, benw04, bugzilla.redhat.com, butirsky, bwat47, chris, earl.aaron, fgarciad, fnord, garrett.mitchener, jgetsoian, johannes.t, Krause.Markus, krinkodot22, liblit, lnykryn, luigic, matthias.andree, msekleta, ppywlkiqletw, samuel-rhbugs, skr, sorosj, ssahani, s, systemd-maint, taocrismon, us-, w.weiland, xelld, zbyszek, zhelezov
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: systemd-239-7.git3bf819c.fc29 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2018-12-21 19:39:33 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
Output of journalctl -n -p err none

Description Ranjan Maitra 2018-11-04 14:55:50 UTC
Description of problem:

After upgrade to Fedora 29, EFI-boot system no longer hibernates. Instead we get
"Failed to hibernate system via logind: Resume not configured, can't hibernate" message. 
systemctl hibernate worked flawlessly on Fedora 28. 


Version-Release number of selected component (if applicable):

systemd-239-6.git9f3aed1.fc29.x86_64

How reproducible:

Always

Steps to Reproduce:
1. On Fedora 29 system with resume set up in the boot parameter on grub, type systemctl hibernate


Actual results:

Failed to hibernate system via logind: Resume not configured, can't hibernate

And nothing happens.

Expected results:

system goes to hibernate, and wakes up correctly when woken up with the power button.


Additional info:

Here is my /etc/default/grub:

GRUB_TIMEOUT=5
GRUB_DISTRIBUTOR="$(sed 's, release .*$,,g' /etc/system-release)"
GRUB_DEFAULT=saved
GRUB_DISABLE_SUBMENU=true
GRUB_TERMINAL_OUTPUT="console"
GRUB_CMDLINE_LINUX="resume=UUID=a83ac239-cc10-43a6-be54-de4ce7050605 rhgb quiet"
GRUB_DISABLE_RECOVERY="true"

Here is the relevant portion of my blkid:

/dev/nvme0n1p4: UUID="a83ac239-cc10-43a6-be54-de4ce7050605" TYPE="swap" PARTUUID="1b80fbac-938f-41f1-82bc-3e0dee5ffef1"

Here is my /proc/cmdline:

BOOT_IMAGE=/boot/vmlinuz-4.18.16-300.fc29.x86_64 root=UUID=bfae51c6-7f8c-4b0b-8b3b-af6af9ae5446 ro resume=UUID=a83ac239-cc10-43a6-be54-de4ce7050605 rhgb quiet LANG=en_US.UTF-8

Here are the results from my "sudo journalctl -fa".


Nov 04 07:19:29 machine.name polkitd[800]: Registered Authentication Agent for unix-process:2334:95259 (system bus name :1.175 [/usr/bin/pkttyagent --notify-fd 5 --fallback], object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8)
Nov 04 07:19:29 machine.name audit[827]: AVC avc:  denied  { read } for  pid=827 comm="systemd-logind" name="nvme0n1p1" dev="devtmpfs" ino=17625 scontext=system_u:system_r:systemd_logind_t:s0 tcontext=system_u:object_r:nvme_device_t:s0 tclass=blk_file permissive=0
Nov 04 07:19:29 machine.name audit[827]: SYSCALL arch=c000003e syscall=257 success=no exit=-13 a0=ffffff9c a1=7ffe3533e050 a2=80000 a3=0 items=0 ppid=1 pid=827 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="systemd-logind" exe="/usr/lib/systemd/systemd-logind" subj=system_u:system_r:systemd_logind_t:s0 key=(null)
Nov 04 07:19:29 machine.name audit: PROCTITLE proctitle="/usr/lib/systemd/systemd-logind"
Nov 04 07:19:29 machine.name systemd-logind[827]: Failed to open file system "/boot/efi": Permission denied
Nov 04 07:19:29 machine.name polkitd[800]: Unregistered Authentication Agent for unix-process:2334:95259 (system bus name :1.175, object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8) (disconnected from bus)
Nov 04 07:19:29 machine.name kernel: audit: type=1400 audit(1541337569.994:258): avc:  denied  { read } for  pid=827 comm="systemd-logind" name="nvme0n1p1" dev="devtmpfs" ino=17625 scontext=system_u:system_r:systemd_logind_t:s0 tcontext=system_u:object_r:nvme_device_t:s0 tclass=blk_file permissive=0
Nov 04 07:19:29 machine.name kernel: audit: type=1300 audit(1541337569.994:258): arch=c000003e syscall=257 success=no exit=-13 a0=ffffff9c a1=7ffe3533e050 a2=80000 a3=0 items=0 ppid=1 pid=827 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="systemd-logind" exe="/usr/lib/systemd/systemd-logind" subj=system_u:system_r:systemd_logind_t:s0 key=(null)
Nov 04 07:19:29 machine.name kernel: audit: type=1327 audit(1541337569.994:258): proctitle="/usr/lib/systemd/systemd-logind"

And here is my free:

              total        used        free      shared  buff/cache   available
Mem:       16124252     1590104    12510124      506248     2024024    13684680
Swap:      20967420           0    20967420


It is important to note that systemctl hibernate still works fine on my legacy boot systems so EFI boot may be the issue here.

It may well be a systemd bug upstream:

https://github.com/systemd/systemd/issues/10613

Please fix asap, because hibernation and wakeup is very important to me. 

Happy to test as much as needed.

Comment 1 Samuel Sieb 2018-11-05 02:41:54 UTC
With the debug logging enabled, it is clear that it's the failure to open /boot/efi that is causing it to not work.  The swap is ok and there is a correct resume= parameter.

Nov 04 19:12:41 machine.name systemd-logind[805]: Failed to open file system "/boot/efi": Permission denied
Nov 04 19:12:41 machine.name systemd-logind[805]: Cannot read boot configuration from ESP, assuming hibernation is not possible.

Comment 2 Villy Kruse 2018-11-07 07:20:17 UTC
Created attachment 1502855 [details]
Output of journalctl -n -p err

After upgrading to selinux-policy-3.14.2-41.fc29 the error is moved slightly.

It seems that systemd-logind gets confused if systemd-boot isn't used, which is quite rarely the case on fedora systems.

Comment 3 Villy Kruse 2018-11-07 07:30:27 UTC
(In reply to Samuel Sieb from comment #1)
> With the debug logging enabled, it is clear that it's the failure to open
> /boot/efi that is causing it to not work.  The swap is ok and there is a
> correct resume= parameter.
> 
> Nov 04 19:12:41 machine.name systemd-logind[805]: Failed to open file system
> "/boot/efi": Permission denied
> Nov 04 19:12:41 machine.name systemd-logind[805]: Cannot read boot
> configuration from ESP, assuming hibernation is not possible.

It is actually a failure to open the disk device which holds the file system for /boot/efi.  The message could have been formulated clearer.

selinux-policy-3.14.2-41.fc29 fixes this permission problem, though.

Comment 4 Samuel Sieb 2018-11-07 07:40:06 UTC
We had come to the conclusion that it wasn't selinux because turning enforcing off didn't fix it.  Do you know why that would be?

Comment 5 Villy Kruse 2018-11-07 08:18:33 UTC
(In reply to Samuel Sieb from comment #4)
> We had come to the conclusion that it wasn't selinux because turning
> enforcing off didn't fix it.  Do you know why that would be?

See attachment 1502855 [details] and comment #2

SELinux was part of the problem, but after that has ben fixed then this applies:
https://github.com/systemd/systemd/issues/10613

Comment 6 Samuel Sieb 2018-11-07 08:22:45 UTC
Ok, I knew about that systemd issue, but it wasn't clear that your comment #2 was related to that.

Comment 7 Aaron Earl 2018-11-07 13:27:05 UTC
Hello.

I encountered the same problem with a clean install of Fedora 29 [Bug #1645814].  However, I noted that the hibernation functioned correctly until I set the root password.  Tell me, is yours also a fresh install of Fedora 29 and did you also set your root password?

Comment 8 Ranjan Maitra 2018-11-07 14:16:56 UTC
(In reply to Aaron Earl from comment #7)
> Hello.
> 
> I encountered the same problem with a clean install of Fedora 29 [Bug
> #1645814].  However, I noted that the hibernation functioned correctly until
> I set the root password.  Tell me, is yours also a fresh install of Fedora
> 29 and did you also set your root password?

I upgraded from Fedora 28 (where it worked flawlessly, from outer appearance at least, and where we had done a clean install). I also do not have a root password set.

Comment 9 Villy Kruse 2018-11-08 21:55:24 UTC
As far as I can see the problem could come from git commit 5fdf2d51c244288ac41443d1bd81365fab7b7b81 src/shared/sleep-config.




        r = find_default_boot_entry(NULL, NULL, &config, &e);
        if (r == -ENOKEY)
                log_debug_errno(r, "Cannot find the ESP partition mount point, falling back to other checks.");
        else if (r < 0) 
                return log_debug_errno(r, "Cannot read boot configuration from ESP, assuming hibernation is not possible.");
        else {
                _cleanup_free_ char *options = NULL;

                options = strv_join(e->options, " ");
                if (!options)
                        return log_oom();

                r = resume_configured_in_options(options);
                if (r < 0)
                        return log_error_errno(r, "Failed to parse kernel options in \"%s\": %m",
                                               strnull(e->path));
                return r;
        }


If the systemd-boot configuration files are not found then you get the log message "Cannot read boot configuration from ESP, assuming hibernation is not possible.". and then hibernation is disabled.

It would make sense to skip the whole thing and jump directly to read the kernel command line from /proc/cmdline; at least for Fedora.  At least do not return with an error if find_default_boot_entry returns the value -ENOENT.

By the way, SELinux would also block reading the systemd-boot configuration file found in /boot/efi/loader.

Comment 10 Krause.Markus 2018-11-09 21:14:23 UTC
As a workaround, you may downgrade systemd.

I can confirm on Fedora29 by running

dnf install systemd-239-3.fc29

you can restore hibernate functionality until an upstream fix is available.

All the other packages are latest-greatest, especially the aforementioned selinux policy update.

Comment 11 Aaron Earl 2018-11-10 00:46:30 UTC
I have followed this suggestion as it relates to my problem [Bug 1645814] and downgraded my systemd package from systemd-239-6.git9f3aed1.fc29 to systemd-239-3.fc29 and can report that my hibernation functionality is restored.

A comparison of the results of running the command

sudo SYSTEMD_LOG_LEVEL=debug /usr/lib/systemd/tests/test-sleep

before and after this downgrade suggests that Villy Kruse is correct that the difference is the skipping of reading the systemd-boot configuration files.

Thanks to you both!

Comment 12 Krause.Markus 2018-11-12 19:52:49 UTC
Just to update: The upstream bug (which was originally created because of an Arch Linux issue) seems to have a pull request now:

https://github.com/systemd/systemd/issues/10613

This should be tracked as soon as it's clear that it fixes the problem.
We currently have all updates halted for all Fedora machines because of this.

Comment 13 Luigi Cantoni 2018-11-13 01:09:02 UTC
As per above I can confirm.
I upgraded from F28->F29.
Hibernate was working fine with F28 and then stopped with F29 with the above error.

Applied suggested patch
dnf install systemd-239-3.fc29
rebooted hibernate working again as before.

Thanks Krause.Markus the temporary fix is much appreciated.

Comment 14 john getsoian 2018-11-13 14:58:50 UTC
Aslo confirming for FC29 that backleveling systemd as per Marcus-Krause re-enables hibernation. ThinkPad 450s.

Comment 15 Chris Tao 2018-11-14 10:46:00 UTC
Can confirm this bug on F29 with systemd-239-6.git9f3aed1.fc29.

May be caused by this change: 

https://src.fedoraproject.org/rpms/systemd/blob/981940521311b1ac864556b1bc9ff561e118d446/f/systemd.spec#_718

Comment 16 Krause.Markus 2018-11-14 18:27:28 UTC
(In reply to Chris Tao from comment #15)
> Can confirm this bug on F29 with systemd-239-6.git9f3aed1.fc29.
> 
> May be caused by this change: 
> 
> https://src.fedoraproject.org/rpms/systemd/blob/
> 981940521311b1ac864556b1bc9ff561e118d446/f/systemd.spec#_718

No this is not the cause, because all people who have this problem have resume= set correctly. Please look at the upstream bug in SystemD I have posted above. the reason and commit which causes this bug is already found.

Comment 18 Villy Kruse 2018-11-21 09:10:53 UTC
See the pull request and discussion at https://github.com/systemd/systemd/pull/10735

Comment 19 Zbigniew Jędrzejewski-Szmek 2018-11-21 13:21:22 UTC
https://github.com/systemd/systemd/pull/10868

Comment 20 Krause.Markus 2018-11-25 21:33:29 UTC
Very good. Any ETA when this will be in systemd fc29?

Comment 21 Sebastian Krämer 2018-11-29 19:46:05 UTC
Just to subscribe and let you know, a downgrade from systemd-239-6.git9f3aed1.fc29.x86_64 to systemd-239-3.fc29.x86_64 fixed the issue for me.

Comment 22 Krause.Markus 2018-12-16 10:10:10 UTC
Hi, this is still in POST phase, when can we expect this to release to Fedora 29?
This is a blocking issue and I would like to re-enable updates on our machines without always having to mask out systemd.

Comment 23 Fedora Update System 2018-12-19 03:36:24 UTC
systemd-239-7.git3bf819c.fc29 has been pushed to the Fedora 29 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2018-a26479d04a

Comment 24 Vladimir Zhelezov 2018-12-19 09:23:14 UTC
With this update I get hibernation working _if_ I disable Secure Boot.

Secure Boot disabled:
--------------------
$ cat /sys/power/{disk,mem_sleep,state}
[platform] shutdown reboot suspend test_resume
s2idle [deep]
freeze mem disk
$ qdbus --system org.freedesktop.UPower /org/freedesktop/UPower org.freedesktop.UPower.GetCriticalAction                                                              
HybridSleep
$ systemctl hibernate
# working as expected

Secure Boot enabled:
-------------------
$ cat /sys/power/{state,mem_sleep,disk}
freeze mem
s2idle [deep]
[disabled]
$ qdbus --system org.freedesktop.UPower /org/freedesktop/UPower org.freedesktop.UPower.GetCriticalAction
PowerOff
$ systemctl hibernate
Failed to hibernate system via logind: Sleep verb "hibernate" not supported

So, at least the resume parameter is properly detected now. And error messages from logind trying to access non-existent entries in /boot/efi are gone.



system: ThinkPad X230
kernel: 4.19.9-300.fc29.x86_64
systemd: systemd-239-7.git3bf819c.fc29

$ cat /proc/cmdline
BOOT_IMAGE=/vmlinuz-4.19.9-300.fc29.x86_64 root=/dev/mapper/fedora-root ro resume=/dev/mapper/fedora-swap rd.lvm.lv=fedora/root rd.luks.uuid=luks-7ac6e844-4869-4b75-a5e7-818720369e81 rd.lvm.lv=fedora/swap rhgb quiet LANG=en_US.UTF-8

Comment 25 Vladimir Zhelezov 2018-12-19 09:29:37 UTC
My bad: bug 1518473

Comment 26 Luigi Cantoni 2018-12-20 00:02:21 UTC
Hi,
I tried to do as directed in
See https://fedoraproject.org/wiki/QA:Updates_Testing
to try and update to the test version of systemd

dnf upgrade systemd --enablerepo=updates-testing

It only finds
systemd               x86_64     239-6.git9f3aed1.fc29       updates     3.4 M
etc
nothing from the updates_testing.

I have tried the other method mentioned in the instructions but still only 239-6 not 239-7.
I have it working by reloading 239-3 so this is not really too big an issue for me but it would be nice to do the odd testing to help if I can.
Please advise.

Comment 27 Zbigniew Jędrzejewski-Szmek 2018-12-20 08:26:43 UTC
Luigi, it looks like you might get a stale mirror. You can just download the rpms directly from koji: https://koji.fedoraproject.org/koji/buildinfo?buildID=1174020.

Comment 28 Luigi Cantoni 2018-12-20 09:08:25 UTC
Yes turns out my cache needed flushing.

I have updated successfully.
I have rebooted.
Hibernate work exactly as before.
Great I can confirm all fixed as far as I am concerned.

Comment 29 Fedora Update System 2018-12-21 19:39:33 UTC
systemd-239-7.git3bf819c.fc29 has been pushed to the Fedora 29 stable repository. If problems still persist, please make note of it in this bug report.

Comment 30 Zbigniew Jędrzejewski-Szmek 2019-01-11 15:22:21 UTC
*** Bug 1645814 has been marked as a duplicate of this bug. ***