RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 1443351 - [svvp][ovmf] job "Secure Boot Logo Test" failed with q35&ovmf
Summary: [svvp][ovmf] job "Secure Boot Logo Test" failed with q35&ovmf
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: ovmf
Version: 7.4
Hardware: Unspecified
OS: Unspecified
high
high
Target Milestone: rc
: ---
Assignee: Laszlo Ersek
QA Contact: FuXiangChun
URL:
Whiteboard:
Depends On:
Blocks: 1443361
TreeView+ depends on / blocked
 
Reported: 2017-04-19 06:57 UTC by lijin
Modified: 2017-11-28 20:14 UTC (History)
11 users (show)

Fixed In Version: ovmf-20170228-5.gitc325e41585e3.el7
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-08-01 22:22:15 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)
win2016 svvp test logs under q35 and ovmf (12.48 MB, application/zip)
2017-04-19 06:57 UTC, lijin
no flags Details
complete report in HTML format, exported as described in comment 20 (483.32 KB, text/html)
2017-04-28 01:20 UTC, Laszlo Ersek
no flags Details
Secure Boot Logo Test report (100% pass) (510.38 KB, text/html)
2017-04-29 17:38 UTC, Laszlo Ersek
no flags Details
EnrollDefaultKeys.efi patches (for Fedora's & Gerd's pkgs) (4.19 KB, application/x-xz)
2017-04-29 18:55 UTC, Laszlo Ersek
no flags Details
FD_SIZE_4MB patches (for Fedora's & Gerd's pkgs) (4.10 KB, application/x-xz)
2017-05-01 19:05 UTC, Laszlo Ersek
no flags Details
latest failed report - html format (1.56 MB, text/html)
2017-05-03 08:31 UTC, lijin
no flags Details
the passed job log (2.00 MB, text/html)
2017-05-18 07:39 UTC, lijin
no flags Details


Links
System ID Private Priority Status Summary Last Updated
Red Hat Bugzilla 1514537 1 None None None 2021-01-20 06:05:38 UTC
Red Hat Product Errata RHEA-2017:2056 0 normal SHIPPED_LIVE new packages: OVMF 2017-08-01 19:34:11 UTC

Internal Links: 1514537

Description lijin 2017-04-19 06:57:35 UTC
Created attachment 1272503 [details]
win2016 svvp test logs under q35 and ovmf

Description of problem:


Version-Release number of selected component (if applicable):
OVMF-20170228-3.gitc325e41585e3.el7.noarch
kernel-3.10.0-640.el7.x86_64
qemu-kvm-rhev-2.8.0-6.el7.x86_64
virtio-win-prewhql-135 & virtio-win-1.9.0-3.el7.noarch

How reproducible:
100%

Steps to Reproduce:
1.boot guest with q35 and ovmf:
/usr/libexec/qemu-kvm -M q35 -device ioh3420,bus=pcie.0,id=root1.0,slot=1 -device ioh3420,bus=pcie.0,id=root2.0,slot=2 -drive file=./signed/OVMF_CODE.secboot.fd,if=pflash,format=raw,unit=0,readonly=on -drive file=./signed/OVMF_VARS.fd,if=pflash,format=raw,unit=1 -drive file=./signed/UefiShell.iso,if=none,cache=none,snapshot=off,aio=native,media=cdrom,id=cdrom1 -device ide-cd,drive=cdrom1,id=ide-cd1 -cpu Westmere -enable-kvm -m 2G -smp 2 -nodefconfig -rtc base=localtime,driftfix=none \
-object iothread,id=thread0 -drive file=win2016-signed.raw,if=none,format=raw,cache=none,werror=stop,rerror=stop,id=drive-virtio-disk0,aio=native -device virtio-blk-pci,scsi=off,iothread=thread0,bus=root1.0,drive=drive-virtio-disk0,id=virtio-disk0 -netdev tap,script=/etc/qemu-ifup1,id=hostnet0,vhost=on,queues=2 -device virtio-net-pci,netdev=hostnet0,id=net0,mac=00:52:54:48:f8:90,bus=root2.0,mq=on,vectors=6 -device piix3-usb-uhci,id=usb -device usb-tablet,id=tablet0 -vnc 0.0.0.0:1 -k en-us -vga std -monitor stdio -qmp tcp:0:4448,server,nowait -boot menu=on -rtc base=localtime,clock=host,driftfix=slew -uuid 2d04af6b-32f2-4884-b917-54ed2856f021 \
-device usb-ehci,id=ehci0 \
-drive file=usb-disk.raw,if=none,id=drive-usb-2-0,media=disk,format=raw,cache=none,werror=stop,rerror=stop,aio=threads -device usb-storage,bus=ehci0.0,drive=drive-usb-2-0,id=usb-2-0,removable=on \
-drive file=usb-disk-1.raw,if=none,id=drive-usb-2-1,media=disk,format=raw,cache=none,werror=stop,rerror=stop,aio=threads -device usb-storage,bus=ehci0.0,drive=drive-usb-2-1,id=usb-2-1,removable=on \

2.enable secure boot
 Shell>fs0:
 FS0:\>EnrollDeafultKeys.efi
 FS0:\> reset -c

3.submit hlk svvp job "Secure Boot Logo Test"

Actual results:
job failed,following sub tests are failed:
Microsoft.UefiSecureBootLogo.Tests.OutOfBoxConfirmDBXisPresent
Microsoft.UefiSecureBootLogo.Tests.OutOfBoxVerifyMicrosoftKEKpresent 
Microsoft.UefiSecureBootLogo.Tests.OutOfBoxConfirmMicrosoftSignatureInDB 
Microsoft.UefiSecureBootLogo.Tests.OutOfBoxVerifyRevocationSignatures 
Microsoft.UefiSecureBootLogo.Tests.Confirm64KilobytesOfUnauthenticatedVariableStorage 
Microsoft.UefiSecureBootLogo.Tests.ConfirmSetOfLargeVariable 

According to the description in [1]:
Before you run the test, Secure Boot option should be in the default shipping (out-of-box) configuration, specifically:
    Secure Boot option must be ON.
    Microsoft Keys are in Key-Exchange key (KEK) and signature database (db).
    No Microsoft test keys are allowed in the Public Key (PK), KEK or signature database.

[1] https://msdn.microsoft.com/en-us/library/windows/hardware/jj123823%28v=vs.85%29.aspx

Comment 1 Laszlo Ersek 2017-04-24 15:49:39 UTC
This is almost certainly a duplicate of bug 1443361 (thanks Amnon for the See Also reference).

Note that the MSDN article at [1] does not mention DBX at all. Let me go through the listed test cases one by one:

> Before you run the test, Secure Boot option should be in the default shipping
> (out-of-box) configuration, specifically:
>    Secure Boot option must be ON.

should be OK

>   Microsoft Keys are in Key-Exchange key (KEK) and signature database (db).

* EnrollDefaultKeys.efi adds "Microsoft Corporation KEK CA 2011", with SHA1 31:59:0b:fd:89:c9:d7:4e:d0:87:df:ac:66:33:4b:39:31:25:4b:30, to the KEK.

* EnrollDefaultKeys.efi also adds:

- "Microsoft Windows Production PCA 2011" (58:0a:6f:4c:c4:e4:b6:69:b9:eb:dc:1b:2b:3e:08:7b:80:d0:67:8d), and
- "Microsoft Corporation UEFI CA 2011" (46:de:f6:3b:5c:e6:1c:f8:ba:0d:e2:e6:63:9c:10:19:d0:ed:14:f3)

to "db", so this should be covered.

>   No Microsoft test keys are allowed in the Public Key (PK), KEK or
> signature database.

Should be OK as well.


... However, judging from the names of the individual test cases:

> Microsoft.UefiSecureBootLogo.Tests.OutOfBoxConfirmDBXisPresent

This is the same as in bug 1443361.

> Microsoft.UefiSecureBootLogo.Tests.OutOfBoxVerifyMicrosoftKEKpresent

See above near "Microsoft Corporation KEK CA 2011", I guess.
 
> Microsoft.UefiSecureBootLogo.Tests.OutOfBoxConfirmMicrosoftSignatureInDB

See above near "Microsoft Windows Production PCA 2011" and "Microsoft Corporation UEFI CA 2011", I guess.
 
> Microsoft.UefiSecureBootLogo.Tests.OutOfBoxVerifyRevocationSignatures

No clue what contents this one looks for, in the "dbx" variable.
 
> Microsoft.UefiSecureBootLogo.Tests.
> Confirm64KilobytesOfUnauthenticatedVariableStorage

Sorry, this won't work. OVMF's entire variable store is smaller than 64KB (it provides 56 KB), and this test case (based on its name at least) wants 64KB just for unauthenticated variables.

I have zero clue where this requirement comes from; to me it looks arbitrary.

> Microsoft.UefiSecureBootLogo.Tests.ConfirmSetOfLargeVariable

I guess this is a variant of the previous test.

Comment 12 lijin 2017-04-26 06:45:07 UTC
After windows update,there is one more sub-test failed:
Microsoft.UefiSecureBootLogo.Tests.VerifyBootServicesVariableBehavior:
Error 4/25/2017 2:07:39.661 PM AreNotEqual(0, 0) - After ExitBootServices(), attempting to call GetVariable() on an existing variable with attributes "NV,BS" should fail.

Comment 13 Laszlo Ersek 2017-04-26 09:22:16 UTC
(In reply to lijin from comment #12)
> After windows update,there is one more sub-test failed:
> Microsoft.UefiSecureBootLogo.Tests.VerifyBootServicesVariableBehavior:
> Error 4/25/2017 2:07:39.661 PM AreNotEqual(0, 0) - After ExitBootServices(),
> attempting to call GetVariable() on an existing variable with attributes
> "NV,BS" should fail.

The statement in the error message is correct, and OVMF should indeed work like that. Too bad that the error message doesn't bother to *name* the actual darn variable (and variable namespace GUID) that were used for the check!

It is interesting that this test only failed after Windows Update. Are MS actively developing SVVP test cases? In that case, it's a pretty safe assumption that some of the new test cases could be buggy. (This is a constant problem with all test suites, not just SVVP.) To my knowledge, the variable driver stack in edk2 (and used by OVMF) implements "boot time only" variables correctly. If not, that's a generic edk2 failure then that has to be fixed (and Intel will be happy to receive the issue report), but again, we need to know the actual variable namespace and name used for the test.

Comment 14 Laszlo Ersek 2017-04-26 09:26:22 UTC
Re: comment 12 and comment 13:

https://social.msdn.microsoft.com/Forums/sqlserver/en-US/1238a44d-1deb-44b3-86aa-2b112b754161/secure-boot-logo-test-verifybootservicesvariablebehavior-failure

"After configuring and enabling Secure Boot, did you perform a Windows restart?  If you did not, then please restart Windows ("shutdown /r") and re-run the test.  If you did, this is a firmware bug.  It existed in older builds of Tiano Core and the EDK/UDK."

So this should really work now. Perhaps the test fails because some other SB-related test fail earlier.

Comment 15 lijin 2017-04-27 02:27:40 UTC
(In reply to Laszlo Ersek from comment #14)
> Re: comment 12 and comment 13:
> 
> https://social.msdn.microsoft.com/Forums/sqlserver/en-US/1238a44d-1deb-44b3-
> 86aa-2b112b754161/secure-boot-logo-test-verifybootservicesvariablebehavior-
> failure
> 
> "After configuring and enabling Secure Boot, did you perform a Windows
> restart?  If you did not, then please restart Windows ("shutdown /r") and
> re-run the test.  If you did, this is a firmware bug.  It existed in older
> builds of Tiano Core and the EDK/UDK."
 
I tried after guest reboot;

> So this should really work now. Perhaps the test fails because some other
> SB-related test fail earlier.

And I also ran this job on a fresh installed latest 2016(en_windows_server_2016_x64_dvd_9718492.iso),still hit this error.

Comment 20 Laszlo Ersek 2017-04-28 01:17:47 UTC
I managed to run the Secure Boot Logo Test myself, and I'm seeing the reported failures.

The test output / logs that are generated are actually helpful, it's just that this tool seems to make everything possible to *hide* the useful bits of information (namely, the actual test executable's messages) in a heap of garbage.

I find the "hlkx" format (see the attachment on comment 0) entirely useless / unpenetrable as well. Here's the only method I found to read the useful messages:

(1) After running the test, navigate to Results | ... | Run Test | Logs | Te.wtl

(2) Double click "Te.wtl". The HCK Manager comes up. The trick is that the test
    results are recorded in a large XML file, and the HCK Manager offers several
    XSLT files to process the XML into HTML, for display. These options are
    listed under "View", near the top left corner, and in my experience,
    every option except for "Complete" is fully useless, because they all hide
    the actual test executable messages. So ignore every option here, just
    stick with Complete.

(3) Once the HTML-like view is rendered (which is still extremely hard to
    navigate in this viewer thing), right-click on the report anywhere, and
    select View Source from the context menu. A Notepad window will open
    with the generated HTML source in it. Now we are making progress!

(4) Still using notepad, save the HTML file to some comfortable location.

(5) Transfer the saved HTML file from the guest to the host. The tool used
    for this can be anything at all, I prefer Cygwin + scp.

(6) On the host, open the HTML file with firefox, and search it for the string
    "Result:". This will jump from test-end to test-end, immediately showing
    the verdict. In case of failure, it is very easy to scroll up a little
    bit, and see (a) the test name, and (b) the actual complaints that the
    test executable emitted. Those messages are the *only* useful parts of
    the entire humongous report, and they are in fact detailed and helpful.
    They might even allow developers to fix errors.

I'll analyze the report in more detail later.

Comment 21 Laszlo Ersek 2017-04-28 01:20:48 UTC
Created attachment 1274808 [details]
complete report in HTML format, exported as described in comment 20

Comment 22 lijin 2017-04-28 03:14:37 UTC
I saw some different result from your HTML format report:
1.you use "Windows Server 2016 Standard" and  we use "Windows Server 2016 Datacenter";
We should test svvp with datacenter 

2.Microsoft.UefiSecureBootLogo.Tests.OutOfBoxConfirmDBXisPresent
This sub-test passed from your side ,but we failed 
I don't know if it's due to datacenter issue or sth,but we'd like to see it's passed.
Did you do some extra operation before the test?
Could you paste your qemu command here?Maybe I can try with similar cli to see if it can pass from my side.
Thanks

3.Microsoft.UefiSecureBootLogo.Tests.OutOfBoxVerifyRevocationSignatures
I don't find this sub-test from your report

4.Microsoft.UefiSecureBootLogo.Tests.OutOfBoxAllowCorrectlySignedSetVariable
this sub-test failed from our side,but you failed 

5.Following four errors are similar:
Microsoft.UefiSecureBootLogo.Tests.OutOfBoxVerifyMicrosoftKEKpresent 
Microsoft.UefiSecureBootLogo.Tests.OutOfBoxConfirmMicrosoftSignatureInDB 
Microsoft.UefiSecureBootLogo.Tests.Confirm64KilobytesOfUnauthenticatedVariableStorage 
Microsoft.UefiSecureBootLogo.Tests.ConfirmSetOfLargeVariable

Comment 23 Laszlo Ersek 2017-04-28 08:34:55 UTC
(In reply to lijin from comment #22)
> I saw some different result from your HTML format report:
> 1.you use "Windows Server 2016 Standard" and  we use "Windows Server 2016
> Datacenter";
> We should test svvp with datacenter

See, this is the kind of information I should have *before* I spend several hours on setting up a new guest.

For now, Standard will have to do on my side. I'll use it for local development and testing.
 
> 2.Microsoft.UefiSecureBootLogo.Tests.OutOfBoxConfirmDBXisPresent
> This sub-test passed from your side ,but we failed 
> I don't know if it's due to datacenter issue or sth,but we'd like to see
> it's passed.

I agree, it should pass. Since it fails on your side, please attach the report for it, in the format I described in comment 20.

> Did you do some extra operation before the test?
> Could you paste your qemu command here?Maybe I can try with similar cli to
> see if it can pass from my side.
> Thanks

I don't use the raw QEMU command line, I exclusively rely on libvirt for testing. Anyway, I don't think it's up to a command line difference; hopefully we'll know more after you please attach your results (in the rendered HTML format, with the test executable's messages).

> 3.Microsoft.UefiSecureBootLogo.Tests.OutOfBoxVerifyRevocationSignatures
> I don't find this sub-test from your report

Right, not sure why. I used the latest HCK filters as instructed in <https://github.com/daynix/VirtHCK/wiki>, maybe that makes a difference. Perhaps they removed the test case.

> 
> 4.Microsoft.UefiSecureBootLogo.Tests.OutOfBoxAllowCorrectlySignedSetVariable
> this sub-test failed from our side,but you failed 

No clue why it failed for me. I'll retry later with a fresh variable store.

> 
> 5.Following four errors are similar:
> Microsoft.UefiSecureBootLogo.Tests.OutOfBoxVerifyMicrosoftKEKpresent 
> Microsoft.UefiSecureBootLogo.Tests.OutOfBoxConfirmMicrosoftSignatureInDB 
> Microsoft.UefiSecureBootLogo.Tests.
> Confirm64KilobytesOfUnauthenticatedVariableStorage 
> Microsoft.UefiSecureBootLogo.Tests.ConfirmSetOfLargeVariable

Right, the most important ones (that are urgent to fix) are:
- Confirm64KilobytesOfUnauthenticatedVariableStorage
- ConfirmSetOfLargeVariable

Thanks.

Comment 24 Laszlo Ersek 2017-04-28 08:57:18 UTC
(In reply to Laszlo Ersek from comment #21)
> Created attachment 1274808 [details]
> complete report in HTML format, exported as described in comment 20

So here's my analysis / extracts for the failed cases:

(1) OutOfBoxVerifyMicrosoftKEKpresent

The relevant tool messages are:

> Parsing signatureList 1
> Parsing signatureList 2
> IsGreaterThanOrEqual(2, 1) - "KEK": At least 1 signature present.
> Searching for Microsoft signatureOwners...
> Found Non-Microsoft signatureOwner = d5c1df0b-1bac-4edf-ba48-08834009ca5a
> Found Non-Microsoft signatureOwner = d5c1df0b-1bac-4edf-ba48-08834009ca5a
> IsGreaterThanOrEqual(0, 1) - "KEK": At least 1 Microsoft-owned signature
> present.

This test case iterates over the X509 certificate entries in the KEK, and
checks the OwnerGUID value associated with each of them.

From the two certs that EnrollDefaultKeys.efi puts in the KEK, one is
"Microsoft Corporation KEK CA 2011". The issue is that EnrollDefaultKeys.efi
uses its own FILE_GUID (through gEfiCallerIdGuid), namely
D5C1DF0B-1BAC-4EDF-BA48-08834009CA5A, as SignatureOwner for it:

>   Status = EnrollListOfX509Certs (
>              EFI_KEY_EXCHANGE_KEY_NAME,
>              &gEfiGlobalVariableGuid,
>              RedHatPkKek1, sizeof RedHatPkKek1, &gEfiCallerIdGuid,
>              MicrosoftKEK, sizeof MicrosoftKEK, &gEfiCallerIdGuid, <--- HERE
>              NULL);

    According to the UEFI specification 2.6, "30.4.1 Signature Database":

> SignatureOwner -- An identifier which identifies the agent which added the
> signature to the list.
>
> [...]
>
> Each signature has an owner SignatureOwner, which is a GUID identifying
> the agent which inserted the signature in the database. Agents might
> include the operating system or an OEM- supplied driver or application.
> Agents may examine this field to understand whether they should manage the
> signature or not.

    And then in "30.5.3 Signature Database Update":

> 9. [...] The algorithm by which an agent decides which signatures may be
> safely removed is agent-specific. In most cases, agents should not remove
> signatures where the SignatureOwner field is not the agent's. [...]

Since EnrollDefaultKeys.efi is the agent that enrolls the MS cert in
question into KEK, it is *obviously* correct to use its FILE_GUID as
SignatureOwner. SignatureOwner does not stand for the issuer of the
certificate or anything like that, it stands for the program that puts the
cert in place.

Either way, this test bug should not be hard to work around, as the log from
comment 20 has hints elsewhere what the expected SignatureOwner GUID is.
Namely, in the output of
"Confirm64KilobytesOfUnauthenticatedVariableStorage", we see:

> Microsoft variables under VendorGuid
> {77fa9abd-0359-4d32-bd60-28f4e78f784b}: 17 bytes

By googling the GUID, the following results confirm the idea:

https://blog.uncooperative.org/blog/2014/10/23/uefi-security-databases/

> [...] 77fa9abd-0359-4d32-bd60-28f4e78f784b , which is the GUID Microsoft
> uses to identify themselves [...]

https://firmware.intel.com/messages/219

> The Microsoft DB entries are specific to Microsoft Windows 8. The GUID
> associated with these certificates is 77fa9abd-0359-4d32-bd60-28f4e78f784b

http://blog.fpmurphy.com/2012/11/list-secure-boot-certificates.html

> Type: X509  (GUID: 77FA9ABD-0359-4D32-BD60-28F4E78F784B)
> ...
> Subject: CN=US ST=Washington L=Redmond O=Microsoft Corporation
> CN=Microsoft Corporation KEK CA 2011

So, for this, the expected fix is to add the GUID in question as a static
variable to EnrollDefaultKeys.efi, and use it in the call quoted above.

Comment 25 Laszlo Ersek 2017-04-28 09:00:52 UTC
(2) OutOfBoxConfirmMicrosoftSignatureInDB

Messages:

> Parsing signatureList 1
> Parsing signatureList 2
> IsGreaterThanOrEqual(2, 1) - "db": At least 1 signature present.
> Searching for Microsoft signatureOwners...
> Found Non-Microsoft signatureOwner = d5c1df0b-1bac-4edf-ba48-08834009ca5a
> Found Non-Microsoft signatureOwner = d5c1df0b-1bac-4edf-ba48-08834009ca5a
> IsGreaterThanOrEqual(0, 1) - "db": At least 1 Microsoft-owned signature
> present.

The code from EnrollDefaultKeys.efi:

>   Status = EnrollListOfX509Certs (
>              EFI_IMAGE_SECURITY_DATABASE,
>              &gEfiImageSecurityDatabaseGuid,
>              MicrosoftPCA,    sizeof MicrosoftPCA,    &gEfiCallerIdGuid,
>              MicrosoftUefiCA, sizeof MicrosoftUefiCA, &gEfiCallerIdGuid,
>              NULL);

So this is the exact same issue as (1) in comment 24, just for "db", not
"KEK", and should be fixable similarly.

Comment 26 Laszlo Ersek 2017-04-28 10:22:31 UTC
(3) Confirm64KilobytesOfUnauthenticatedVariableStorage

Messages:

> NOTE: if this testcase fails, try restarting the machine and then running
> this test case on its own, for example: "te.exe UefiSecureBootLogo.dll
> /name:Microsoft.UefiSecureBootLogo.Tests.Confirm64KilobytesOfUnauthenticatedVariableStorage"
>
> Initializing HighResolutionTimer - 100000000 Hz
>
> Computing bytes to test... Variable space consumed by PK, KEK, db, & dbx:
> 10379 bytes
>
> Calculating the size of variables within the Microsoft Secure Boot
> namespace...
>
> Offset 000002B0 Next 000002C8
> Offset 00000604 Next 00000620
> Microsoft variables under VendorGuid
> {77fa9abd-0359-4d32-bd60-28f4e78f784b}: 17 bytes
> Total bytes consumed: 10396
> Kilobytes to test: 43

OK, so the idea is apparently: measure how much varstore is used already,
genuinely, and then add enough stuff temporarily so that the varstore usage
peaks at ~64KB?

But, the actual sum doesn't seem to be 64KB. It's 10379 B + 43 KB ~= 53 KB.
Where does that target come from? OVMF's live area in the varstore is 56 KB,
so this is a similar number, but I don't know how Windows can know about it,
plus the test name says "64 Kilobytes".

The log goes on -- we manage to create 14 variables, each 1KB in size:

> Deleting variables from prior test runs. Creating 43 1kB variables.
>
> AreEqual(7, 7) - testKilobyte1: Attributes from GetVariable() match
> SetVariable()
>
> AreEqual(1024, 1024) - testKilobyte1: DataSize from GetVariable() matches
> SetVariable()
>
> AreEqual(7, 7) - testKilobyte2: Attributes from GetVariable() match
> SetVariable()
>
> AreEqual(1024, 1024) - testKilobyte2: DataSize from GetVariable() matches
> SetVariable()
>
> ... AreEqual(7, 7) - testKilobyte14: Attributes from GetVariable() match
> SetVariable()
>
> AreEqual(1024, 1024) - testKilobyte14: DataSize from GetVariable() matches
> SetVariable()

And then we run out of space:

> Test creation of testKilobyte15 Insufficient Variable Storage -
> SetVariable failed with status 0xC0000454
> STATUS_INSUFFICIENT_NVRAM_RESOURCES (EFI_OUT_OF_RESOURCES) Try rebooting
> your system to allow the firmware to reclaim unused space. The test should
> pass on its first execution after a reboot. If this error appears on the
> first test execution after a reboot, your firmware has a bug. VariableName
> "testKilobyte15" VendorGuid 77fa9abd-0359-4d32-bd60-28f4e78f784b
> Attributes 0x00000007 DataSize 0x00000400
>
> Failure to create 43kB of variables. Could only successfully create 14kB
> for a total of 25kB

This does look like a fragmentation issue. OVMF (and other, generic parts of
BDS) do some heavy variable munging on each boot.

The variable driver has a function called ReclaimForOS()
[MdeModulePkg/Universal/Variable/RuntimeDxe/Variable.c], called at
Ready-To-Boot. (The reclaim attempt could be moved to an earlier point, by
setting PcdReclaimVariableSpaceAtEndOfDxe, but that would be worse, actually
-- QemuBootOrderLib massages the Boot#### variables way later than we signal
End-Of-Dxe. So Ready-To-Boot is definitely the best spot to call
ReclaimForOS().)

ReclaimForOS() employs the following logic:

>   //
>   // Check if the free area is below a threshold.
>   //
>   if (((RemainingCommonRuntimeVariableSpace < mVariableModuleGlobal->MaxVariableSize) ||
>        (RemainingCommonRuntimeVariableSpace < mVariableModuleGlobal->MaxAuthVariableSize)) ||
>       ((PcdGet32 (PcdHwErrStorageSize) != 0) &&
>        (RemainingHwErrVariableSpace < PcdGet32 (PcdMaxHardwareErrorVariableSize)))){
>     Status = Reclaim (
>             mVariableModuleGlobal->VariableGlobal.NonVolatileVariableBase,
>             &mVariableModuleGlobal->NonVolatileLastVariableOffset,
>             FALSE,
>             NULL,
>             NULL,
>             0
>             );
>     ASSERT_EFI_ERROR (Status);
>   }

OVMF currently sets the limits like this:

>   gEfiMdeModulePkgTokenSpaceGuid.PcdMaxVariableSize|0x2000
>   gEfiMdeModulePkgTokenSpaceGuid.PcdMaxAuthVariableSize|0x2800

(8KB and 10KB, respectively). The first limit comes from:

> commit fd4ba547a13a4e3ddfb820de59887875bf86c5de
> Author: Jordan Justen <jordan.l.justen>
> Date:   Fri Jun 14 21:37:44 2013 +0000
>
>     OvmfPkg: Reduce PcdMaxVariableSize with secure boot to avoid assert
>
>     r14252 causes OVMF to crash if SECURE_BOOT_ENABLE is set,
>     because PcdMaxVariableSize is set to a larger value than
>     required. In other platforms, 0x2000 seems to be sufficient.
>
>     Reported-by: Gary Ching-Pang Lin <glin>
>     Signed-off-by: Jordan Justen <jordan.l.justen>
>     Reviewed-by: Laszlo Ersek <lersek>
>     Tested-by: Laszlo Ersek <lersek>

The second limit comes from:

> commit f5404a3eba1d3bae54e6b02be0a87f8f471eb732
> Author: James Bottomley <James.Bottomley>
> Date:   Thu Mar 24 21:38:41 2016 -0400
>
>     OvmfPkg: Increase the maximum size for Authenticated variables
>
>     During real world testing I was getting an error with too many entries
>     in db: On my Secure boot laptop, I currently have seven certificates:
>     two Microsoft ones, Three Kernel ones from various distributions, my
>     own Secure Key and a temporary test key.  That gives a total EFI
>     Signature List size of 8317 which is over the 0x2000 maximum.
>
>     Fix this by setting the PcdMaxAuthVariableSize to 0x2800 (10K) which
>     isn't much of an increase but allows for 9-10 certificates.
>
>     Contributed-under: TianoCore Contribution Agreement 1.0
>     Signed-off-by: James Bottomley <James.Bottomley>
>     Regression-tested-by: Laszlo Ersek <lersek>
>     Reviewed-by: Laszlo Ersek <lersek>
>     Reviewed-by: Star Zeng <star.zeng>

And the limit checking in ReclaimForOS() goes back to the following commits:

- 0c18794ea428 ("Add security package to repository.", 2011-09-02)
- 952ba83c4781 ("SecurityPkg Variable: Implement variable quota
                management.", 2015-01-27)
- 13af4ab06516 ("SecurityPkg Variable: Support the new introduced
                PcdMaxAuthVariableSize.", 2015-06-10)

The variable quota management looks a bit suspicious, but OVMF inherits 0
values for PcdMaxUserNvVariableSpaceSize and
PcdBoottimeReservedNvVariableSpaceSize, so quota management is disabled.

To me, neither making the limit checking logic more aggressive, nor raising
the limits for the current checking, look attractive. Regarding the latter,
we even had to *lower* PcdMaxAuthVariableSize in commit fd4ba547a13a (see
above). And regarding the former (-> more frequent reclaims on OS boots), I
don't want Reclaim() to be called more frequently. Reclaim() has a visible
boot performance impact.

I'll have to experiment with this; I think I'll start with enlarging the
varstore.

Comment 27 Laszlo Ersek 2017-04-28 10:32:37 UTC
(4) ConfirmSetOfLargeVariable

Messages:

> NOTE: if this testcase fails, try restarting the machine and then running
> this test case on its own, for example: "te.exe UefiSecureBootLogo.dll
> /name:Microsoft.UefiSecureBootLogo.Tests.ConfirmSetOfLargeVariable"
>
> Test creation of 1 large variable of size 32768 bytes.
>
> Test creation of testLargeVariable Unexpected Error - SetVariable failed
> with status 0xC000000D VariableName "testLargeVariable" VendorGuid
> 77fa9abd-0359-4d32-bd60-28f4e78f784b Attributes 0x00000007 DataSize
> 0x00008000

This has a direct root cause, and perhaps a less direct one as well.

The direct cause is:

>  gEfiMdeModulePkgTokenSpaceGuid.PcdMaxVariableSize|0x2000

from commit fd4ba547a13a ("OvmfPkg: Reduce PcdMaxVariableSize with secure
boot to avoid assert", 2013-06-14).

The indirect cause is that, similarly to case (3) in comment 26, we simply
might not have enough contiguous room in the varstore.

Enlarging the varstore should eliminate the indirect cause, and also enable
us to bump PcdMaxVariableSize (and then PcdMaxAuthVariableSize too) to
0x8000 -- the issue described in commit fd4ba547a13a should no longer hit
against a larger varstore.

Comment 28 Laszlo Ersek 2017-04-28 10:43:15 UTC
(5) OutOfBoxAllowCorrectlySignedSetVariable

Messages:

> Unexpected Powershell Exception:
> System.Management.Automation.CmdletInvocationException: Unexpected Result,
> status error: 0xC0000454 --->
> Microsoft.SecureBoot.Commands.StatusException: Unexpected Result, status
> error: 0xC0000454 at
> System.Management.Automation.MshCommandRuntime.ThrowTerminatingError(ErrorRecord
> errorRecord) --- End of inner exception stack trace --- at
> System.Management.Automation.Runspaces.PipelineBase.Invoke(IEnumerable
> input) at
> System.Management.Automation.PowerShell.Worker.ConstructPipelineAndDoWork(Runspace
> rs, Boolean performSyncInvoke) at
> System.Management.Automation.PowerShell.Worker.CreateRunspaceIfNeededAndDoWork(Runspace
> rsToUse, Boolean isSync) at
> System.Management.Automation.PowerShell.CoreInvokeHelper[TInput,TOutput](PSDataCollection`1
> input, PSDataCollection`1 output, PSInvocationSettings settings) at
> System.Management.Automation.PowerShell.CoreInvoke[TInput,TOutput](PSDataCollection`1
> input, PSDataCollection`1 output, PSInvocationSettings settings) at
> System.Management.Automation.PowerShell.Invoke(IEnumerable input,
> PSInvocationSettings settings) at
> Microsoft.UefiSecureBootLogo.Tests.OutOfBoxAllowCorrectlySignedSetVariable()
>
> IsTrue - SetVariable() that appends using valid Out-of-Box AuthInfo should
> succeed.

Honestly, I have no clue what this is. I understand what the test is trying
to do, but it says "Unexpected Powershell Exception", so maybe it doesn't
even get as far as calling gRT->SetVariable()?

I found other reports on the web:

https://social.msdn.microsoft.com/Forums/windowsdesktop/en-US/3f6b2460-4edd-4acd-a078-77c579a73496/secure-boot-logo-test
https://social.msdn.microsoft.com/Forums/en-US/868c4853-57a1-40f4-bf50-a31725173a80/whck-system-secure-boot-logo-test

In the first report, MS indicates "OutOfBoxAllowCorrectlySignedSetVariable"
may depend on "OutOfBoxVerifyMicrosoftKEKpresent" (see case (1) in comment
24):

> if testcase "OutOfBoxVerifyMicrosoftKEKpresent" fails, then your system is
> misconfigured.  If "OutOfBoxVerifyMicrosoftKEKpresent" passes, then this
> failure in "OutOfBoxAllowCorrectlySignedSetVariable" is a firmware bug

So maybe if we fix that, this could work too.

Comment 29 Laszlo Ersek 2017-04-28 19:36:56 UTC
(In reply to lijin from comment #15)
> (In reply to Laszlo Ersek from comment #14)
> > Re: comment 12 and comment 13:
> >
> > https://social.msdn.microsoft.com/Forums/sqlserver/en-US/1238a44d-1deb-44b3-
> > 86aa-2b112b754161/secure-boot-logo-test-verifybootservicesvariablebehavior-
> > failure
> >
> > "After configuring and enabling Secure Boot, did you perform a Windows
> > restart?  If you did not, then please restart Windows ("shutdown /r")
> > and re-run the test.  If you did, this is a firmware bug.  It existed in
> > older builds of Tiano Core and the EDK/UDK."
>
> I tried after guest reboot;
>
> > So this should really work now. Perhaps the test fails because some
> > other SB-related test fail earlier.
>
> And I also ran this job on a fresh installed latest
> 2016(en_windows_server_2016_x64_dvd_9718492.iso),still hit this error.

It is now confirmed that the VerifyBootServicesVariableBehavior test failure
is due to a test bug / Windows bug:

> Filter 19238
>
>         Version: 1
>
>         Expires on: 06/30/2017 17:00:00
>
>         Issue Description: The test case in question is attempting to
>         verify that UEFI variables with attributes BS (not RunTime) are
>         not visible/modifiable from within the OS.  It assumes that
>         "CurrentPolicy" variable will be NV+BS.  The recent Windows Update
>         to patch "Golden Key" changed the attribute of "CurrentPolicy"
>         from NV+BS to NV+BS+RT+AT.  The WU change to a RunTime attribute
>         breaks the assumptions made by this test case. 
>
>         Issue Resolution: This is an acceptable failure

Comment 30 Laszlo Ersek 2017-04-29 17:38:07 UTC
Created attachment 1275172 [details]
Secure Boot Logo Test report (100% pass)

I have 100.00% Pass Rate for the Secure Boot Logo Test.

I'm soon going to post / attach patches.

Comment 31 Laszlo Ersek 2017-04-29 18:55:46 UTC
Created attachment 1275191 [details]
EnrollDefaultKeys.efi patches (for Fedora's & Gerd's pkgs)

There are six patches:

  1 6be3d53093cd OvmfPkg/EnrollDefaultKeys: update SignatureOwner GUID for
                 Windows HCK
  2 09096ead3078 OvmfPkg/EnrollDefaultKeys: expose CertType parameter of
                 EnrollListOfCerts
  3 8ca585b76148 OvmfPkg/EnrollDefaultKeys: blacklist empty file in dbx for
                 Windows HCK
  4 136d73d3a531 OvmfPkg/OvmfPkg.fdf.inc: extract VARS_LIVE_SIZE and
                 VARS_SPARE_SIZE macros
  5 cb4efd58838c OvmfPkg: introduce FD_SIZE_4MB (mainly) for Windows HCK
  6 47c1fe8ada3a OvmfPkg: raise max variable size (auth & non-auth) to 33KB
                 for FD_SIZE_4MB

The first three are for EnrollDefaultKeys.efi, and are therefore downstream
only. I'm going to post their RHEL7 ports to rhvirt-patches soon, but for
users of Fedora and Gerd's RPMs, I'm attaching them here. The patches apply
to the Fedora "edk2" package, at dist-git commit ad70d15d1cad ("Ship
ovmf-ia32 package (bz 1424722)", 2017-03-15).

The last three patches are upstreamable; I'll post them to edk2-devel.

Comment 32 Laszlo Ersek 2017-04-29 19:00:27 UTC
(In reply to Laszlo Ersek from comment #31)

> The first three are for EnrollDefaultKeys.efi, and are therefore downstream
> only. I'm going to post their RHEL7 ports to rhvirt-patches soon, but for
> users of Fedora and Gerd's RPMs, I'm attaching them here. The patches apply
> to the Fedora "edk2" package, at dist-git commit ad70d15d1cad ("Ship
> ovmf-ia32 package (bz 1424722)", 2017-03-15).

NB, CRLF -> LF conversion might be necessary first.

Comment 33 Laszlo Ersek 2017-04-29 20:17:25 UTC
(In reply to Laszlo Ersek from comment #31)
>
> There are six patches:
>
> [...]
>
> The last three patches are upstreamable; I'll post them to edk2-devel.

Subject: [edk2] [PATCH 0/3] OvmfPkg: add FD_SIZE_4MB for Windows HCK SB
                            tests, and for future proofing
Message-Id: <20170429201500.18496-1-lersek>
URL: https://lists.01.org/pipermail/edk2-devel/2017-April/010334.html

Comment 34 Laszlo Ersek 2017-05-01 19:05:34 UTC
Created attachment 1275464 [details]
FD_SIZE_4MB patches (for Fedora's & Gerd's pkgs)

(In reply to Laszlo Ersek from comment #33)
> (In reply to Laszlo Ersek from comment #31)
> >
> > There are six patches:
> >
> > [...]
> >
> > The last three patches are upstreamable; I'll post them to edk2-devel.
> 
> Subject: [edk2] [PATCH 0/3] OvmfPkg: add FD_SIZE_4MB for Windows HCK SB
>                             tests, and for future proofing
> Message-Id: <20170429201500.18496-1-lersek>
> URL: https://lists.01.org/pipermail/edk2-devel/2017-April/010334.html

After a thorough discussion on edk2-devel (see also the May archive!), these patches (the direction of them) are not appropriate for upstream at this time. So I'm attaching them too.

They apply to upstream edk2 at commit 65ed9d7ff55a ("StdLib: GCC 6 build fixes", 2017-04-26).

Comment 37 lijin 2017-05-03 08:31:09 UTC
Created attachment 1275847 [details]
latest failed report - html format

(In reply to Laszlo Ersek from comment #23)
> (In reply to lijin from comment #22)
> > I saw some different result from your HTML format report:
> > 1.you use "Windows Server 2016 Standard" and  we use "Windows Server 2016
> > Datacenter";
> > We should test svvp with datacenter
> 
> See, this is the kind of information I should have *before* I spend several
> hours on setting up a new guest.
> 
> For now, Standard will have to do on my side. I'll use it for local
> development and testing.
>  
> > 2.Microsoft.UefiSecureBootLogo.Tests.OutOfBoxConfirmDBXisPresent
> > This sub-test passed from your side ,but we failed 
> > I don't know if it's due to datacenter issue or sth,but we'd like to see
> > it's passed.
> 
> I agree, it should pass. Since it fails on your side, please attach the
> report for it, in the format I described in comment 20.

Thanks.
This is the latest failed test result

Comment 38 Laszlo Ersek 2017-05-03 13:30:41 UTC
Sorry, we have another misunderstanding here. It's my fault -- I apologize.

When I said

  OutOfBoxConfirmDBXisPresent should pass

I meant that

  I agree that the expectations of this test case for OVMF are valid

I did not mean that

  I expect OVMF to pass this test case right now

Please wait until we move this BZ to MODIFIED, and fill in the Fixed-in-Version field, before repeating the test. Thank you.

Comment 39 Laszlo Ersek 2017-05-03 21:44:25 UTC
Posted upstream v2:
Subject: [PATCH v2 0/5] OvmfPkg: add FD_SIZE_4MB for Windows HCK SB tests, and
                        for future proofing
Message-Id: <20170503213947.32290-1-lersek>
URL: https://lists.01.org/pipermail/edk2-devel/2017-May/010423.html

Comment 40 Laszlo Ersek 2017-05-04 23:04:03 UTC
(In reply to Laszlo Ersek from comment #39)
> Posted upstream v2:
> Subject: [PATCH v2 0/5] OvmfPkg: add FD_SIZE_4MB for Windows HCK SB tests,
> and
>                         for future proofing
> Message-Id: <20170503213947.32290-1-lersek>
> URL: https://lists.01.org/pipermail/edk2-devel/2017-May/010423.html

These patches have been committed. They replace the (now obsolete)
attachment added in comment 34. Commits to backport:

  1 210270730c0e OvmfPkg: introduce the FD_SIZE_IN_KB macro / build flag
  2 636cda51903b OvmfPkg/OvmfPkg.fdf.inc: extract VARS_LIVE_SIZE and
                 VARS_SPARE_SIZE macros
  3 b24fca05751f OvmfPkg: introduce 4MB flash image (mainly) for Windows HCK
  4 88a30bbc0a3c OvmfPkg: raise max variable size (auth & non-auth) to 33KB
                 for FD_SIZE_4MB
  5 bba8dfbec3bb OvmfPkg: make the 4MB flash size the default

Comment 41 Laszlo Ersek 2017-05-05 16:59:06 UTC
  6  6e49d01cfb43 Revert "OvmfPkg: make the 4MB flash size the default"
  7  0c79471d6a98 OvmfPkg/PlatformPei: handle non-power-of-two spare
                  size for emu variables

Comment 43 Miroslav Rezanina 2017-05-12 09:38:52 UTC
Fix included in ovmf-20170228-5.gitc325e41585e3.el7

Comment 45 lijin 2017-05-18 07:37:55 UTC
Job can pass with ovmf-20170228-5.gitc325e41585e3.el7
So this issue has been fix,thanks

Comment 46 lijin 2017-05-18 07:39:15 UTC
Created attachment 1279885 [details]
the passed job log

Comment 47 errata-xmlrpc 2017-08-01 22:22:15 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHEA-2017:2056


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