Bug 1136679 - HP ZBook, fallback.efi always reports BootOrder not found, NVRAM accumulates Boot entries
Summary: HP ZBook, fallback.efi always reports BootOrder not found, NVRAM accumulates ...
Keywords:
Status: CLOSED EOL
Alias: None
Product: Fedora
Classification: Fedora
Component: shim
Version: 21
Hardware: x86_64
OS: Linux
unspecified
unspecified
Target Milestone: ---
Assignee: Matthew Garrett
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2014-09-03 04:26 UTC by patrick korsnick
Modified: 2015-12-02 16:15 UTC (History)
9 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2015-12-02 03:42:17 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
/tmp/anaconda.log (62.60 KB, text/plain)
2014-09-03 04:26 UTC, patrick korsnick
no flags Details
/tmp/storage.log (770.47 KB, text/plain)
2014-09-03 04:27 UTC, patrick korsnick
no flags Details
/tmp/program.log (36.49 KB, text/plain)
2014-09-03 04:27 UTC, patrick korsnick
no flags Details
anaconda.log from 2nd install (48.78 KB, text/plain)
2014-09-05 19:06 UTC, patrick korsnick
no flags Details
program.log from second install (38.35 KB, text/plain)
2014-09-05 19:08 UTC, patrick korsnick
no flags Details
storage.log from second install (580.75 KB, text/plain)
2014-09-05 19:08 UTC, patrick korsnick
no flags Details
dmesg output from second install (116.46 KB, text/plain)
2014-09-05 19:09 UTC, patrick korsnick
no flags Details
journal.log from second install (1.92 MB, text/plain)
2014-09-05 19:12 UTC, patrick korsnick
no flags Details
screenshot of the BootOrder not found error (2.90 MB, image/png)
2014-09-06 21:58 UTC, patrick korsnick
no flags Details
much smaller file size version of screenshot.png (633.67 KB, application/octet-stream)
2014-09-06 22:04 UTC, patrick korsnick
no flags Details

Description patrick korsnick 2014-09-03 04:26:08 UTC
Created attachment 933944 [details]
/tmp/anaconda.log

Description of problem:
While installing from Fedora-Live-Workstation-x86_64-21-Alpha-TC5.iso on a usb stick to a HP zbook 17 in UEFI mode with CSM disabled and Secure Boot enabled I get the following errors (from anaconda.log):

21:56:22,396 ERR anaconda: BootLoader setup failed: failed to find a suitable stage1 device
22:02:06,828 ERR anaconda: bootloader.write failed: failed to set new efi boot target. This is most likely a kernel bug.

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


How reproducible:
every time

Steps to Reproduce:
1. put machine into pure UEFI mode with secure boot enabled
2. install f21 workstation from usb
2. wait for the error box to pop up
3.

Actual results:
get an error box asking if you want to continue installation

Expected results:

no error

Additional info:

Comment 1 patrick korsnick 2014-09-03 04:27:09 UTC
Created attachment 933945 [details]
/tmp/storage.log

Comment 2 patrick korsnick 2014-09-03 04:27:50 UTC
Created attachment 933946 [details]
/tmp/program.log

Comment 3 Chris Murphy 2014-09-03 06:22:16 UTC
The 21:56:22,396 error seems bogus because it clearly gets setup as an ESP, and has files copied to it. So I'm not sure what that's about.

The 22:02:06,828 error is going to be either an efibootmgr, kernel, or firmware bug. From the program.log, if you can run this command:
efibootmgr -c -w -L Fedora -d /dev/sda -p 1 -l \EFI\fedora\shim.efi
and see what result you get, that will narrow it down.

But the main question is, is the resulting system still bootable?

Comment 4 patrick korsnick 2014-09-04 18:08:55 UTC
Chris,

I hit continue when the error box popped up and the resulting system is indeed bootable. Regarding the efibootmgr command you listed above, do I need to run it from the live session that produces the error or can I run it on the resulting working system?

Comment 5 David Shea 2014-09-04 19:49:33 UTC
The live session would be preferable. Additionally, can you attach the /tmp/anaconda-tb* file generated after the crash to this bug? Thanks.

Comment 6 patrick korsnick 2014-09-05 01:17:47 UTC
Ok I installed again and here is the output of that command:

[root@localhost liveuser]# efibootmgr -c -w -L Fedora -d /dev/sda -p 1 -l \EFI\fedora\shim.efi
** Warning ** : Boot0006 has same label Fedora

Regarding the anaconda-tb file, there was no file in /tmp with that name.

Comment 7 Chris Murphy 2014-09-05 01:53:33 UTC
Right, no crash, no anaconda-tb. When the installer reports bootloader problems on EFI, we'll need program.log, dmesg, and efibootmgr -v. I think the only one of those not in the -tb is efibootmgr -v.

The posted program.log shows no boot entries from the efibootmgr command anaconda ran. Therefore anaconda didn't run efibootmgr -B to delete prior entries, and yet the efibootmgr -c command is bothered by an existing Fedora entry. This is confusing.

Regardless of how you're booted, can you post the results from efibootmgr -v on this same machine?

Comment 8 Chris Murphy 2014-09-05 02:12:01 UTC
And also post the new program.log from the installation referred to in comment 6, it'll be in /var/log/anaconda on the installed system. And also include journal.log.

Comment 9 patrick korsnick 2014-09-05 19:06:53 UTC
Created attachment 934893 [details]
anaconda.log from 2nd install

Comment 10 patrick korsnick 2014-09-05 19:08:31 UTC
Created attachment 934895 [details]
program.log from second install

Comment 11 patrick korsnick 2014-09-05 19:08:57 UTC
Created attachment 934896 [details]
storage.log from second install

Comment 12 patrick korsnick 2014-09-05 19:09:42 UTC
Created attachment 934897 [details]
dmesg output from second install

Comment 13 patrick korsnick 2014-09-05 19:12:54 UTC
Created attachment 934898 [details]
journal.log from second install

Comment 14 Chris Murphy 2014-09-05 21:27:33 UTC
OK this is completely different than the first program.log, there must have been multiple attempts to have so many Fedora entries.
19:14:19,043 INFO program: Boot0000* Fedora
19:14:19,043 INFO program: Boot0001* Fedora
19:14:19,043 INFO program: Boot0002* Fedora
19:14:19,043 INFO program: Boot0003* Fedora
19:14:19,043 INFO program: Boot0004* Fedora
19:14:19,043 INFO program: Boot0005* Fedora
19:14:19,043 INFO program: Boot0006* Fedora

But then also, somehow those entries weren't being removed? In this program log I see it try to remove them all except 0006.

19:14:19,044 INFO program: Running... efibootmgr -b 0000 -B
19:14:19,086 INFO program: Running... efibootmgr -b 0001 -B
19:14:19,130 INFO program: Running... efibootmgr -b 0002 -B
19:14:19,170 INFO program: Running... efibootmgr -b 0003 -B
19:14:19,210 INFO program: Running... efibootmgr -b 0004 -B
19:14:19,248 INFO program: Running... efibootmgr -b 0005 -B
19:14:19,274 DEBUG program: Return code: 1

Yet it doesn't change BootCurrent from 0000 to 0006, which is the only entry it left intact. Anaconda doesn't run efibootmgr -c in this program.log. BootCurrent 0000 with only an 0006 entry seems like a bug, without calling efibootmgr -v how does it know 0006 is the right entry to keep? That entry could be pointing to shim on some completely different device or partition than the current installation. I'm also not sure which command failed, the 0005 removal?

dmesg contains nothing related at all.

Can anaconda devs shed some light on what program and which instance is returning code 1?
19:14:19,274 DEBUG program: Return code: 1

patrick, my suggestion is that you keep testing installs on this computer because we need to figure this out. I think there's more than one bug here. Before you reboot at the end of an install, grab the lines in program.log between the first efibootmgr instance and grub2-set-default, and include those as an attachment. And also the results from efibootmgr -v. And then for any efibootmgr command that's followed (maybe some lines down) by "DEBUG program: Return code: 1" run that exact same command and see what the result is. I'd expect that an efibootmgr fail that also doesn't record something in dmesg, ought to mean some kind of backtrace gets generated by efibootmgr.

The problem is that we're not getting enough debugging granularity out of either the installer log, or the kernel, so it's sorta like pulling teeth what the problem is.

Comment 15 patrick korsnick 2014-09-05 22:50:25 UTC
Chris,

Here's the output from running efibootmgr -v on the resulting system. Is it normal to have all those entries when I did an ATA Secure Erase immediately before installing F21 and have done no installs after?

[ppk@neuromancer ~]$ sudo efibootmgr -v
[sudo] password for ppk: 
BootCurrent: 0000
Timeout: 0 seconds
BootOrder: 000B,000A,0009,0008,0005,0004,0003,0002,0001,0000
Boot0000* Fedora	ACPI(a0341d0,0)PCI(1f,2)SATA(0,0,0)HD(1,800,64000,628c5300-7ece-4bc4-aed0-7f75b6893fca)File(\EFI\fedora\shim.efi)..
Boot0001* Fedora	ACPI(a0341d0,0)PCI(1f,2)SATA(0,0,0)HD(1,800,64000,628c5300-7ece-4bc4-aed0-7f75b6893fca)File(\EFI\fedora\shim.efi)..
Boot0002* Fedora	ACPI(a0341d0,0)PCI(1f,2)SATA(0,0,0)HD(1,800,64000,628c5300-7ece-4bc4-aed0-7f75b6893fca)File(\EFI\fedora\shim.efi)..
Boot0003* Fedora	ACPI(a0341d0,0)PCI(1f,2)SATA(0,0,0)HD(1,800,64000,628c5300-7ece-4bc4-aed0-7f75b6893fca)File(\EFI\fedora\shim.efi)..
Boot0004* Fedora	ACPI(a0341d0,0)PCI(1f,2)SATA(0,0,0)HD(1,800,64000,628c5300-7ece-4bc4-aed0-7f75b6893fca)File(\EFI\fedora\shim.efi)..
Boot0005* Fedora	ACPI(a0341d0,0)PCI(1f,2)SATA(0,0,0)HD(1,800,64000,628c5300-7ece-4bc4-aed0-7f75b6893fca)File(\EFI\fedora\shim.efi)..
Boot0006* Fedora	ACPI(a0341d0,0)PCI(1f,2)SATA(0,0,0)HD(1,800,64000,52393f3e-7935-485e-b9e2-bb1df505a4e6)File(\EFI\fedora\shim.efi)..
Boot0007* Fedora	HD(1,800,64000,628c5300-7ece-4bc4-aed0-7f75b6893fca)File(EFIfedorashim.efi)
Boot0008* Fedora	ACPI(a0341d0,0)PCI(1f,2)SATA(0,0,0)HD(1,800,64000,628c5300-7ece-4bc4-aed0-7f75b6893fca)File(\EFI\fedora\shim.efi)..
Boot0009* Fedora	ACPI(a0341d0,0)PCI(1f,2)SATA(0,0,0)HD(1,800,64000,628c5300-7ece-4bc4-aed0-7f75b6893fca)File(\EFI\fedora\shim.efi)..
Boot000A* Fedora	ACPI(a0341d0,0)PCI(1f,2)SATA(0,0,0)HD(1,800,64000,628c5300-7ece-4bc4-aed0-7f75b6893fca)File(\EFI\fedora\shim.efi)..
Boot000B* Fedora	ACPI(a0341d0,0)PCI(1f,2)SATA(0,0,0)HD(1,800,64000,628c5300-7ece-4bc4-aed0-7f75b6893fca)File(\EFI\fedora\shim.efi)..

Comment 16 Chris Murphy 2014-09-05 23:43:43 UTC
(In reply to patrick korsnick from comment #15)
ATA Secure Erase obliterates drive sector contents, whereas the efibootmgr entries reside in the firmware's NVRAM. You might have to dig around your firmware setup to see if there's some way to delete these entries, or reset NVRAM, I have no idea what that'd look like. But NVRAM confusion has been a big enough problem for Apple that more than 20 years ago they put in a keyboard shortcut to clear NVRAM at boot time, and it's still there.

It's unclear whether efibootmgr -B failing to remove entries is directly a failure of efibootmgr or the kernel. That bug 1114775 and bug 975537 and bug 1047993.

Comment 17 Adam Williamson 2014-09-06 00:55:50 UTC
Isn't this the bug with product name parsing? It was known to be broken in two places in tc5, uefi bootloader is one of them. It was supposed to get fixed in TC6, but the separator changed so I think it's still broken. More details later, check the anaconda change log.

Comment 18 patrick korsnick 2014-09-06 21:32:51 UTC
Found a solution: if I clear out all the BootXXXX entries reported by efibootmgr -v before trying to install then the install goes smoothly with no errors. For this task i ran 'efibootmgr -b X -B' and it worked every time.

This also works with the f20 Live USB which also didn't work correctly.

However, on reboot I get an error saying it the BootOrder isn't specified and it adds another Boot entry into to the list. Notice that the entries added by the firmware look diffent that the one added by anaconda (Boot0000) and that the BootOrder is indeed specified.

This is the output after rebooting twice after install:

[ppk@neuromancer ~]$ sudo efibootmgr -v
[sudo] password for ppk: 
BootCurrent: 0000
Timeout: 0 seconds
BootOrder: 0002,0001,0000
Boot0000* Fedora	HD(1,800,64000,56704b6b-402d-487d-84fa-d1162d837ce9)File(\EFI\fedora\shim.efi)
Boot0001* Fedora	ACPI(a0341d0,0)PCI(1f,2)03120a00000000000000HD(1,800,64000,56704b6b-402d-487d-84fa-d1162d837ce9)File(\EFI\fedora\shim.efi)..
Boot0002* Fedora	ACPI(a0341d0,0)PCI(1f,2)03120a00000000000000HD(1,800,64000,56704b6b-402d-487d-84fa-d1162d837ce9)File(\EFI\fedora\shim.efi)..

I guess that's the reason there were so many 'fedora' entries in there before- every reboot adds a new entry for some reason.

I looked in the UEFI firmware (i know you're not supposed to call it BIOS) and couldn't find anything that looked like it would clear it, so that's why I just used the efibootmgr -B command to do the job.

Comment 19 patrick korsnick 2014-09-06 21:58:58 UTC
Created attachment 935080 [details]
screenshot of the BootOrder not found error

Comment 20 patrick korsnick 2014-09-06 22:04:17 UTC
Created attachment 935081 [details]
much smaller file size version of screenshot.png

original upload was ~3MB. this is a smaller version for slower connections

Comment 21 Chris Murphy 2014-09-06 22:24:42 UTC
"System BootOrder not found" comes from fallback.efi. Changing component to shim.

efibootmgr reports BootCurrent is always 0000 even though BootOrder has it listed last. The firmware seems to be ignoring BootOrder and possibly using something else.

This sounds similar in part to bug 1083943, in particular comment 4 and comment 6 where entries are accumulating.

Comment 22 Chris Murphy 2014-09-06 22:30:01 UTC
I wonder if the firmware behaves differently when Secure Boot is enabled vs disabled.

Comment 23 patrick korsnick 2014-09-07 02:29:13 UTC
(In reply to Chris Murphy from comment #22)
> I wonder if the firmware behaves differently when Secure Boot is enabled vs
> disabled.

Machine won't boot with secure boot enabled- (see bug 1132309)

Comment 24 Fedora End Of Life 2015-11-04 15:10:43 UTC
This message is a reminder that Fedora 21 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 21. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as EOL if it remains open with a Fedora  'version'
of '21'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 21 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 25 Fedora End Of Life 2015-12-02 03:42:22 UTC
Fedora 21 changed to end-of-life (EOL) status on 2015-12-01. Fedora 21 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.


Note You need to log in before you can comment on or make changes to this bug.