FYI, this bug has an impact on keylime measured boot. Keylime is not able to read event log and fails with

               out: Aug 02 17:14:03 localhost.localdomain keylime_agent[12124]:  ERROR keylime_agent::revocation            > Invalid revocation message signature {"msg":"{\"type\": \"revocation\", \"ip\": \"127.0.0.1\", \"agent_id\": \"d432fbb3-d2f1-4a97-9ef7-75bd81c00000\", \"port\": 9002, \"tpm_policy\": \"{\\\"mask\\\": \\\"0xffff\\\"}\", \"meta_data\": \"{}\", \"event_time\": \"Tue Aug  2 17:14:03 2022\", \"event_id\": \"measured_boot.parser.tpm2_eventlog\", \"severity_label\": \"emergency\", \"context\": \"{\\\"message\\\": \\\"running tpm2_eventlog failed\\\"}\"}","signature":"none"}

That looks like maybe a problem with the event itself:

        } else if (type == EV_EFI_VARIABLE_AUTHORITY) {
            free(ret);
            tpm2_tool_output("    VariableData:\n");
            
            EFI_SIGNATURE_DATA *s= (EFI_SIGNATURE_DATA *)&data->UnicodeName[
                data->UnicodeNameLength];
            char *sdata = calloc (1,
                BYTES_TO_HEX_STRING_SIZE(data->VariableDataLength - 16));            <<<<< data->VariableDataLength is 1 according to what it managed to print out for you.
            if (sdata == NULL) {
                LOG_ERR("Failled to allocate data: %s\n", strerror(errno));
                return false;
            }
            bytes_to_str(s->SignatureData, data->VariableDataLength - 16,
                sdata, BYTES_TO_HEX_STRING_SIZE(data->VariableDataLength - 16));
            guid_unparse_lower(s->SignatureOwner, uuidstr);
            tpm2_tool_output("    - SignatureOwner: %s\n"
                             "      SignatureData: %s\n",
                             uuidstr, sdata);
            free(sdata);
            return true;

That really should be cleaned up with s/16/sizeof(EFI_GUID)/ to make it clearer as to what they are subtracting there.

Karel, are you seeing this on multiple systems?

I have a virtual (QEMU) system with Secure Boot enabled. I do not have access to other system (e.g. bare metal) with Secure Boot enabled where I could test it. Would installing a different OS on a host make a difference?

I doubt it in that case. Perhaps and issue in the bios qemu is using or swtpm. I'm taking a look at SecurityPkg/Library/DxeImageVerificationLib/Measurement.c in edk2.

I guess maybe trying with a physical system could help point at the problem, but probably not worth the effort yet.

It seems to me like shim is not generating the entry in the right format (and tpm2_eventlog not being ready for a bad format). The entry contains only a value 1, which should be a correct one, looking at [1]. There is this older pull request [2], which talks about the problem, but it is already merged and the version in RHEL-9.1 should be newer.

[1]: https://github.com/rhboot/shim/blob/main/MokVars.txt
[2]: https://github.com/rhboot/shim/pull/236

The bad format being that the owner is left out, and only the data are there.

That fix should be there, since it went in to 5.13, and 9.0 looks like it has 5.15.

The size it is passing isn't chopping off the size of the size of EFI_GUID though, so it seems there is something else going on if the SignatureSize is 1. The EFI_GUID for the owner has a size of 16. So even if the it messed up the signature data it was passing if it passed a correct signature size value the alloc would have succeeded, and then failed looking at the messed up data.

Peter,

any idea what is happening here?

Hi Stepan, Jerry, Peter,
is there anything I can do to help you to troubleshoot the issue? I can e.g. provide you with the measured boot log.

Hi Karel, I am not sure if this is really an issue on the tpm2-tools side. The tool parses the data correctly, and the problem seems to be that the data contains an invalid structure for event type EV_EFI_VARIABLE_AUTHORITY. According to the standard [1], the EV_EFI_VARIABLE_AUTHORITY event should have an EFI_SIGNATURE_DATA structure, which should consist of the GUID of the owner and the data. Since the GUID is 16 bytes, having a VariableDataLength of 1 means the structure is badly constructed.

But the VariableData does contain a byte '1', which is, according to [2], the correct content. So, I would say that the problem is not in the parsing but in the generation, which uses the wrong event type. And in case of bad data, I would expect the tool to throw an error.

[1]: https://trustedcomputinggroup.org/wp-content/uploads/TCG_PCClient_PFP_r1p05_v23_pub.pdf
[2]: https://github.com/rhboot/shim/blob/main/MokVars.txt

Hi Stepan,
thank you for the response. Would you be able to suggest where the actual issue lies? Is it kernel? QEMU/KVM?

Robbie & Peter,

Can you take a look at what the shim is doing?

I am switching this bug to shim component as I can confirm it starts appearing after shim update from shim-x64-15.5-2.el9 to shim-x64-15.6-1.el9.

Tested on RHEL-9.0 GA in Secure Boot on an x86_64 virtual system:
  # tpm2_eventlog --eventlog-version=2 /sys/kernel/security/tpm0/binary_bios_measurements

1. updated with the latest tpm2-tools-5.2-1.el9 & reboot... works OK
2. updated with the latest kernel 5.14.0-162.3.1.el9 & reboot ... still OK
3. updated to shim-x64-15.6-1.el9 & reboot ... error appears

No other packages have been updated.

(In reply to Karel Srot from comment #15)
> I am switching this bug to shim component as I can confirm it starts
> appearing after shim update from shim-x64-15.5-2.el9 to shim-x64-15.6-1.el9.
> 
> Tested on RHEL-9.0 GA in Secure Boot on an x86_64 virtual system:
>   # tpm2_eventlog --eventlog-version=2
> /sys/kernel/security/tpm0/binary_bios_measurements
> 
> 1. updated with the latest tpm2-tools-5.2-1.el9 & reboot... works OK
> 2. updated with the latest kernel 5.14.0-162.3.1.el9 & reboot ... still OK
> 3. updated to shim-x64-15.6-1.el9 & reboot ... error appears
> 
> No other packages have been updated.

Can you provide the full event log from each of these?

Hi Peter,
binary measured boot log is attached to the last comment in the upstream issue
https://github.com/tpm2-software/tpm2-tools/issues/3050
Please, let me know if you need something else. I need to provision new test system in order to get any new log.

Hi Karel, thanks for he link.  However, Peter asked in #c19 for each event log, not just the last one.

(To reduce effort, I don't think we need all three, but one from before upgrading shim would be helpful.)

Created attachment 1916303 [details]
Archive with two binary_bios_measurements logs

I am sorry, I clearly misunderstood the request. I am attaching an archive with two logs from my virtual machine:
  binary_bios_measurements-shim_v15.5
  binary_bios_measurements-shim_v15.6

(In reply to Štěpán Horáček from comment #12)
> Hi Karel, I am not sure if this is really an issue on the tpm2-tools side. The tool parses the data correctly, and the problem seems to be that the data contains an invalid structure for event type EV_EFI_VARIABLE_AUTHORITY. According to the standard [1], the EV_EFI_VARIABLE_AUTHORITY event should have an EFI_SIGNATURE_DATA structure, which should consist of the GUID of the owner and the data. Since the GUID is 16 bytes, having a VariableDataLength of 1 means the structure is badly constructed.
>
> But the VariableData does contain a byte '1', which is, according to [2], the correct content. So, I would say that the problem is not in the parsing but in the generation, which uses the wrong event type. And in case of bad data, I would expect the tool to throw an error.

(Please cite sections in standards when you refer to them.  We're all trying to work together here to solve the problem.)

It's a SecureBoot variable, so per 10.4.1 of the TCG PC Client Platform Firmware Profile Specification you linked, it does need to be an EFI_VARIABLE_AUTHORITY event.  The digests field we expect to be handled by the call to hash_log_extend_event - see TCG's EFI Protocol Specification ( https://trustedcomputinggroup.org/wp-content/uploads/EFI-Protocol-Specification-rev13-160330final.pdf ) section 6.6 ("The digest that is computed from the DataToHash is used to fill the Digests field in the log entry." from 6.6.3).  So if that reading is right, then shim is generating the event correctly.

Regardless of whether shim is correct here, I think there is a bug in tpm2_eventlog as well - if it believes the structure malformed, it shouldn't be trying to allocate so much memory that it fails.  Specifically, as pointed out in #c2, tpm2_eventlog_yaml.c:376 on master is underflowing and shouldn't be allowed to:

```C
                        char *sdata = calloc (1,
                            BYTES_TO_HEX_STRING_SIZE(slist->SignatureSize - sizeof(EFI_GUID)));
```

(Also a typo - it should be "Failed", not "Failled", which wouldn't matter except that I was grepping for it.)

(In reply to Karel Srot from comment #23)
> I am attaching an archive with two logs from my virtual machine:

Thanks, that's helpful.

What I don't understand at this point is why SbatLevel is fine in both 15.5 and 15.6, but when MokListTrusted is added in 15.6, it's not fine.

I ran across this tonight while looking at this some more:

https://github.com/google/go-attestation/issues/283

It appears they were tripping over this as well.


Looking at the code it seems like both the tpm2-tools code, and the go-attestation code assume the following to be true for any EV_EFI_VARIABLE_AUTHORITY events being measured into pcr7:

    From Section 3.3.4.8 of the TCG PC Client Platform Firmware Profile Specification linked above

    11. For entries in the UEFI_IMAGE_SECURITY_DATABASE, as defined in normative 9, the eventType SHALL be EV_EFI_VARIABLE_AUTHORITY.
        a. The event value SHALL be the value of the UEFI_VARIABLE_DATA structure.
        b. The UEFI_VARIABLE_DATA.VariableData value SHALL be the EFI_SIGNATURE_DATA value from the EFI_SIGNATURE_LIST that contained the authority that was used to validate the image.
        c. The UEFI_VARIABLE_DATA.VariableName SHALL be set to UEFI_IMAGE_SECURITY_DATABASE_GUID.
        d. The UEFI_VARIABLE_DATA.UnicodeName SHALL be set to the value of UEFI_IMAGE_SECURITY_DATABASE. The value MUST NOT include the terminating NUL.

Yeah.  I don't think that applies though because we're not measuring the security database.

@shoracek can you please comment on the above and #c24?

On a deeper look, it does look like it is generated correctly after all. I have misunderstood Section 3.3.4.8 before, thinking it applies here. There's no other mention of the correct contents of VariableData for EV_EFI_VARIABLE_AUTHORITY that I could find.

For comparison, I tried looking at how the tss2 code handles the event file:
"""
$ tsseventextend -sim -if /tmp/binary_bios_measurements-shim_v15.6 -v
...
eventextend: line 29
TSS_EVENT2_Line_Trace: PCR index 7
TSS_EVENT_EventType_Trace: 800000e0 EV_EFI_VARIABLE_AUTHORITY
TSS_EVENT2_Line_Trace: digest count 1
TSS_EVENT2_Line_Trace: digest 0 algorithm 000b
 TSS_EVENT2_Line_Trace: PCR length 32
 5f 62 a2 10 7f a1 1c e0 48 5f d2 52 d2 e6 c6 03
 cb 8e d0 75 86 1f 95 13 bf ed 0a 26 bf 6e d6 2b
 TSS_EVENT2_Line_Trace: event length 61
 50 ab 5d 60 46 e0 00 43 ab b6 3d d8 10 dd 8b 23
 0e 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00
 4d 00 6f 00 6b 00 4c 00 69 00 73 00 74 00 54 00
 72 00 75 00 73 00 74 00 65 00 64 00 01
  Variable GUID: 605dab50-e046-4300-abb6-3dd810dd8b23
  Variable: MokListTrusted
  VariableDataLength: 1
  SignatureLength: 128

...
"""
And for MokListTrusted, it does not parse VariableData at all.
When processing EV_EFI_VARIABLE_AUTHORITY, it seems to parse the contents of VariableData only for "db", "Shim", and "MokList" events, so "MokListTrusted" is left out.
In functions TSS_EfiVariableAuthority_ReadBuffer and similarly in TSS_EfiVariableAuthority_Trace:
"""
        /* db has an owner, shim does not */
        if (uefiVariableData->variableDataTag == TSS_VAR_DB) {
            /* unmarshal the signature owner */
            if (rc == 0) {
                rc = TSS_Array_Unmarshalu(authoritySignatureData->SignatureOwner,
                                          sizeof(authoritySignatureData->SignatureOwner),
                                          &tmpVarData, &tmpVarDataLength);
            }
        }
        /* intentional fall through for DB */
        if ((uefiVariableData->variableDataTag == TSS_VAR_DB) ||
            (uefiVariableData->variableDataTag == TSS_VAR_SHIM) ||
            (uefiVariableData->variableDataTag == TSS_VAR_MOKLIST)) {

            /* assume the rest of the event is the certificate since there is no SignatureSize
               field */
...
        rc = TSS_Array_Unmarshalu(authoritySignatureData->SignatureData,
                      authoritySignatureData->SignatureLength,
                      &tmpVarData, &tmpVarDataLength);
"""

If I did not miss anything, then it does look like the fault lies in tpm2-tools, which assumes that every EV_EFI_VARIABLE_AUTHORITY has the same content as EFI_IMAGE_SECURITY_DATABASE.

I haven't heard back from Ken yet.

My question is why Ken doesn't attempt to handle anything that doesn't contain TSS_AUTHORITY_SIGNATURE_DATA in there? He knows the length and could just dump whatever it is.
Or why that whole section where it starts with assigning authoritySignatureData isn't just wrapped with the TSS_VAR_DB, TSS_VAR_SHIM, TSS_VAR_MOKLIST check instead?

Funnily tpm2_eventlog does just dump them if it thinks it is a sha1 format log instead of crypto agile. It just looks at the length, and then spits it out:

- EventNum: 28
  PCRIndex: 7
  EventType: EV_EFI_VARIABLE_AUTHORITY
  DigestCount: 1
  Digests:
  - AlgorithmId: sha256
    Digest: "922e939a5565798a5ef12fe09d8b49bf951a8e7f89a0cca7a51636693d41a34d"
  EventSize: 68
  Event:
    VariableName: 605dab50-e046-4300-abb6-3dd810dd8b23
    UnicodeNameLength: 9
    VariableDataLength: 18
    UnicodeName: SbatLevel
    VariableData: "736261742c312c323032313033303231380a"

- EventNum: 29
  PCRIndex: 7
  EventType: EV_EFI_VARIABLE_AUTHORITY
  DigestCount: 1
  Digests:
  - AlgorithmId: sha256
    Digest: "5f62a2107fa11ce0485fd252d2e6c603cb8ed075861f9513bfed0a26bf6ed62b"
  EventSize: 61
  Event:
    VariableName: 605dab50-e046-4300-abb6-3dd810dd8b23
    UnicodeNameLength: 14
    VariableDataLength: 1
    UnicodeName: MokListTrusted
    VariableData: "01"

This was posted to the upstream tpm2-tools project 2 days ago:

https://github.com/tpm2-software/tpm2-tools/pull/3144

I'm guessing it needs the same for sbatlevel, yes?

Or should be more general than a specific case each time one of these pops up.

List of commits I used in the mockbuild I posted to the email thread:

508420e0538a ("lib/tpm2_eventlog_yaml: use char16_t for UEFI characters")
9f4c4290de08 ("Patch set for handling of new event types in tpm2_eventlog: EV_EFI_PLATFORM_FIRMWARE_BLOB2, EV_EFI_HANDOFF_TABLES2, EV_EFI_VARIABLE_BOOT2")
bf0c73101c2e ("Code clarity fix for calculation of data member addresses when printing out UEFI_PLATFORM_FIRMWARE_BLOB2 structures.")
4441faf13d86 ("tpm2_eventlog: clean up some magic numbers")
c78d258b2588 ("tpm2_eventlog_yaml: fix malformed YAML for EV_IPL data")
85be19f4705f ("tpm2_eventlog_yaml: fix parsing for MokListTrusted")
3674c75887c0 ("tpm2_eventlog_yaml: use defines for Unicode variables")

There also is the following commit which I didn't backport yet, because it contains a binary file so I need to go look at how to make rpm not hate that kind of patch:

2bd1bb87d6be ("tests: add eventlog for parsing MokListTrusted")

The problem with patching binary files can be solved by using git as patching tool: 

-%autosetup -p1 -n %{name}-%{version}%{?candidate:-%{candidate}}
+%autosetup -S git -p1 -n %{name}-%{version}%{?candidate:-%{candidate}}

(Which means also adding "BuildRequires: git")

And for the last commit you mentioned there also needs to be two other commits for clean apply:

09facdc38380 # test: track expected YAML output for eventlog
31041ea78b35 # test: add eventlog from a Fedora 37 VM with sd-

Reproduced with tpm2-tools-5.2-1.el9.x86_64 on latest-RHEL-9.1.0 :
# tpm2_eventlog --eventlog-version=2 /sys/kernel/security/tpm0/binary_bios_measurements
(...)
ERROR: Failled to allocate data: Cannot allocate memory

ERROR: failed to parse tpm2 eventlog
ERROR: Unable to run tpm2_eventlog

Please move to MODIFIED and provide a fixed build to continue.

--- 

Note: following had to be done for installation to work:
* replacing the hardcoded and undocumented root password hash in easy_virt_install/kickstart.py
* modifying the hardcoded VM size in easy_vit_install/libvirt.py to something that fits into a Beaker machine
* installing libvirt,libvirt-install,qemu-kvm
* starting libvirt.service

The bug was fixed in tpm2-tools-5.2-2.el9_1.x86_64 for RHEL-9.1 and the updated package is now also mirrored into RHEL-9.2.

[root@localhost ~]# cat /etc/redhat-release
Red Hat Enterprise Linux release 9.2 Beta (Plow)
[root@localhost ~]# dnf list tpm2-tools
Last metadata expiration check: 0:01:07 ago on Wed 23 Nov 2022 12:51:40 PM CET.
Available Packages
tpm2-tools.x86_64                      5.2-2.el9_1                       primary

And I cannot reproduce the bug on RHEL-9.2 with the updated package.

[root@localhost ~]# tpm2_eventlog --eventlog-version=2 /sys/kernel/security/tpm0/binary_bios_measurements
---
version: 2
events:
- EventNum: 0
  PCRIndex: 0
...
    6  : 0x3d458cfe55cc03ea1f443f1562beec8df51c75e14a9fcf9a7234a13f198e7969
    7  : 0x2a19ab6b3b9d9ad34ead01c1159f733aa3acebe8ea91c8cecc0ba6420e98ac50
    8  : 0x0d1684d9284b4d97fba068324a9bd47292ac698f5d5518bf84b593c51ace742c
    9  : 0x4643e2f5034f93e5a3d9fda3e38a8a925728e78944474e98b0fd27adfb3be954
    14 : 0xa4dad77fb3b6cacbd20f556986c5d917f5e322c123af82d12c5e5b7ef7ae9938
[root@localhost ~]# echo $?
0