Problem: TPM 2.0 event log by OVMF is shown empty in Linux kernel versions after 5.8


Thore Sommer <public@...>
 

Dear Maintainers,

during my testing with OVMF and swtpm I found out that kernel versions newer than 5.8 don't show any information in "/sys/kernel/security/tpm0/binary_bios_measurements" if swtpm emulates a TPM 2.0 device.
The file is still created but is empty.
The expected result would be that "/sys/kernel/security/tpm0/binary_bios_measurements" contains the TPM event log. TPM 1.2 devices are not affected.

With the help of git bisect I found out that the breaking kernel commit is 85467f63a05c43364ba0b90d0c05bb89191543fa.
Reverting this on top the 5.12 release restores the expected functionality.

Thanks to apalos and leiflindholm on the #edk2 IRC channel for helping me with that.

I don't know if this is a bug in OVMF or in the Linux kernel, because on a real device with a TPM 2.0 the output was as expected.

Tested with edk2-ovmf 202102, swtpm 0.5.2 and qemu 5.2.0 on Ubuntu 20.04.

If further information is needed to resolve this problem, I'd be happy to provide them.

Best regards
Thore Sommer

efi and TPM dmesg output
...
[ 0.000000] efi: EFI v2.70 by EDK II
[ 0.000000] efi: SMBIOS=0x7e9d8000 TPMFinalLog=0x7ebf7000 ACPI=0x7eb7e000 ACPI 2.0=0x7eb7e014 MEMATTR=0x7da77298 RNG=0x7e9c4a98 TPMEventLog=0x7da6f018
[ 0.000000] efi: seeding entropy pool
[ 0.000000] random: fast init done
[ 0.000000] SMBIOS 2.8 present.
...
[ 0.017241] ACPI: Early table checksum verification disabled
[ 0.017275] ACPI: RSDP 0x000000007EB7E014 000024 (v02 BOCHS )
[ 0.017284] ACPI: XSDT 0x000000007EB7D0E8 000054 (v01 BOCHS BXPCFACP 00000001 01000013)
[ 0.017295] ACPI: FACP 0x000000007EB79000 0000F4 (v03 BOCHS BXPCFACP 00000001 BXPC 00000001)
[ 0.017308] ACPI: DSDT 0x000000007EB7A000 0021C8 (v01 BOCHS BXPCDSDT 00000001 BXPC 00000001)
[ 0.017321] ACPI: FACS 0x000000007EBC5000 000040
[ 0.017326] ACPI: APIC 0x000000007EB78000 000088 (v01 BOCHS BXPCAPIC 00000001 BXPC 00000001)
[ 0.017333] ACPI: TPM2 0x000000007EB77000 00004C (v04 BOCHS BXPCTPM2 00000001 BXPC 00000001)
[ 0.017338] ACPI: MCFG 0x000000007EB76000 00003C (v01 BOCHS BXPCMCFG 00000001 BXPC 00000001)
[ 0.017343] ACPI: WAET 0x000000007EB75000 000028 (v01 BOCHS BXPCWAET 00000001 BXPC 00000001)
[ 0.017347] ACPI: BGRT 0x000000007EB74000 000038 (v01 INTEL EDK2 00000002 01000013)
[ 0.017351] ACPI: Reserving FACP table memory at [mem 0x7eb79000-0x7eb790f3]
[ 0.017354] ACPI: Reserving DSDT table memory at [mem 0x7eb7a000-0x7eb7c1c7]
[ 0.017355] ACPI: Reserving FACS table memory at [mem 0x7ebc5000-0x7ebc503f]
[ 0.017356] ACPI: Reserving APIC table memory at [mem 0x7eb78000-0x7eb78087]
[ 0.017358] ACPI: Reserving TPM2 table memory at [mem 0x7eb77000-0x7eb7704b]
[ 0.017359] ACPI: Reserving MCFG table memory at [mem 0x7eb76000-0x7eb7603b]
[ 0.017360] ACPI: Reserving WAET table memory at [mem 0x7eb75000-0x7eb75027]
[ 0.017361] ACPI: Reserving BGRT table memory at [mem 0x7eb74000-0x7eb74037]
[ 0.017390] ACPI: Local APIC address 0xfee00000


James Bottomley
 

On Mon, 2021-04-26 at 21:56 +0200, Thore Sommer wrote:
Dear Maintainers,

during my testing with OVMF and swtpm I found out that kernel
versions newer than 5.8 don't show any information in
"/sys/kernel/security/tpm0/binary_bios_measurements" if swtpm
emulates a TPM 2.0 device. The file is still created but is empty.
The expected result would be that
"/sys/kernel/security/tpm0/binary_bios_measurements" contains the
TPM event log. TPM 1.2 devices are not affected.
I don't confirm this. I have Linux version 5.12.0-rc5+ installed and I
see the attached in my binary_bios_measurements (I've run it through
tpm2-eventlog so you can see the actual events).

With the help of git bisect I found out that the breaking kernel
commit is 85467f63a05c43364ba0b90d0c05bb89191543fa.
Reverting this on top the 5.12 release restores the expected
functionality.

Thanks to apalos and leiflindholm on the #edk2 IRC channel for
helping me with that.

I don't know if this is a bug in OVMF or in the Linux kernel, because
on a real device with a TPM 2.0 the output was as expected.

Tested with edk2-ovmf 202102, swtpm 0.5.2 and qemu 5.2.0 on Ubuntu
20.04.

If further information is needed to resolve this problem, I'd be
happy to provide them.
What that commit did was to allow the event log to be provided by the
ACPI table if one existed rather than always defaulting to it being
provided by the EFI configuration table. What I suspect has happened
from this:

[ 0.017358] ACPI: Reserving TPM2 table memory at [mem
0x7eb77000-0x7eb7704b]
Is that somehow you've got an empty TPM2 table installed in ACPI but I
don't know how you've done this. On my OVMF boot I'm using the direct
kernel command line and I have secure boot enabled but not activated,
which is why you only see PCRs 0-7 in the log.

James


Thore Sommer <public@...>
 

I don't confirm this. I have Linux version 5.12.0-rc5+ installed and I
see the attached in my binary_bios_measurements (I've run it through
tpm2-eventlog so you can see the actual events).
Ok that is interesting.

Here are the steps to reproduce my findings.
Necessary tools: Build chain for edk2, swtpm 0.5.2 and qemu 5.2.0

1. Build OVMF from edk2-stable202102 with
-a X64 -a IA32 \
-b RELEASE \
-D NETWORK_IP6_ENABLE \
-D TPM_ENABLE \
-D FD_SIZE_4MB \
-D TLS_ENABLE \
-D HTTP_BOOT_ENABLE \
-D SECURE_BOOT_ENABLE \
-D SMM_REQUIRE \
-D EXCLUDE_SHELL_FROM_FD

2. Copy OVMF_CODE.fd and OVMF_VARS.fd into an empty directory
3. Download Ubuntu 21.04 desktop iso (which has a 5.11 Linux kernel) and copy it into that directory
(I can provide a custom Debian build with a patched and unpatched vanilla kernel if needed)
4. Create dir for swtpm: mkdir mytpm1
5. Start swtpm with
swtpm socket \
--tpm2 \
--tpmstate dir=mytpm1 \
--ctrl type=unixio,path=mytpm1/swtpm-sock \
--log level=4 &
6. Start qemu with
qemu-system-x86_64 \
-enable-kvm \
-machine q35,smm=on \
-global driver=cfi.pflash01,property=secure,value=on \
-drive if=pflash,format=raw,unit=0,file=OVMF_CODE.fd,readonly=on \
-drive if=pflash,format=raw,unit=1,readonly=off,file=OVMF_VARS.fd \
-chardev socket,id=chrtpm,path=mytpm1/swtpm-sock \
-tpmdev emulator,id=tpm0,chardev=chrtpm \
-device tpm-crb,tpmdev=tpm0 \
-boot d \
-cdrom "ubuntu-21.04-desktop-amd64.iso" \
-m 3G \
-vga virtio
7. Start Ubuntu normally and choose "Try Ubuntu"
8. Open a Terminal and check that
"/sys/kernel/security/tpm0/binary_bios_measurements" is empty

On my OVMF boot I'm using the direct
kernel command line and I have secure boot enabled but not activated,
which is why you only see PCRs 0-7 in the log.
The Kernel here is loaded by Grub which itself is loaded by Shim. But that should not make a difference regarding the event log via ACPI right?

I've attached the event log from a Ubuntu 20.04 machine with a 5.12 patched kernel and my kernel build config.

Best regards
Thore Sommer


Lendacky, Thomas
 

On 4/27/21 2:40 AM, Thore Sommer via groups.io wrote:

I don't confirm this.  I have Linux version 5.12.0-rc5+ installed and I
see the attached in my binary_bios_measurements (I've run it through
tpm2-eventlog so you can see the actual events).
Ok that is interesting.

Here are the steps to reproduce my findings.
Necessary tools: Build chain for edk2, swtpm 0.5.2 and qemu 5.2.0

1. Build OVMF from edk2-stable202102 with
-a X64 -a IA32 \
-b RELEASE \
-D NETWORK_IP6_ENABLE \
-D TPM_ENABLE \
Shouldn't you also have '-D TPM_CONFIG_ENABLE' ?

Thanks,
Tom

-D FD_SIZE_4MB \
-D TLS_ENABLE \
-D HTTP_BOOT_ENABLE \
-D SECURE_BOOT_ENABLE \
-D SMM_REQUIRE \
-D EXCLUDE_SHELL_FROM_FD

2. Copy OVMF_CODE.fd and OVMF_VARS.fd into an empty directory
3. Download Ubuntu 21.04 desktop iso (which has a 5.11 Linux kernel) and
copy it into that directory
(I can provide a custom Debian build with a patched and unpatched vanilla
kernel if needed)
4. Create dir for swtpm: mkdir mytpm1
5. Start swtpm with
swtpm socket \
    --tpm2 \
    --tpmstate dir=mytpm1 \
    --ctrl type=unixio,path=mytpm1/swtpm-sock \
    --log level=4 &
6. Start qemu with
qemu-system-x86_64 \
        -enable-kvm \
        -machine q35,smm=on \
        -global driver=cfi.pflash01,property=secure,value=on \
        -drive if=pflash,format=raw,unit=0,file=OVMF_CODE.fd,readonly=on \
        -drive if=pflash,format=raw,unit=1,readonly=off,file=OVMF_VARS.fd \
        -chardev socket,id=chrtpm,path=mytpm1/swtpm-sock \
        -tpmdev emulator,id=tpm0,chardev=chrtpm \
        -device tpm-crb,tpmdev=tpm0 \
        -boot d \
        -cdrom "ubuntu-21.04-desktop-amd64.iso" \
        -m 3G \
        -vga virtio
7. Start Ubuntu normally and choose "Try Ubuntu"
8. Open a Terminal and check that
"/sys/kernel/security/tpm0/binary_bios_measurements" is empty

On my OVMF boot I'm using the direct
kernel command line and I have secure boot enabled but not activated,
which is why you only see PCRs 0-7 in the log.
The Kernel here is loaded by Grub which itself is loaded by Shim. But that
should not make a difference regarding the event log via ACPI right?

I've attached the event log from a Ubuntu 20.04 machine with a 5.12
patched kernel and my kernel build config.

Best regards
Thore Sommer





James Bottomley
 

On Tue, 2021-04-27 at 09:00 -0500, Lendacky, Thomas wrote:
On 4/27/21 2:40 AM, Thore Sommer via groups.io wrote:
I don't confirm this. I have Linux version 5.12.0-rc5+ installed
and I
see the attached in my binary_bios_measurements (I've run it
through
tpm2-eventlog so you can see the actual events).
Ok that is interesting.

Here are the steps to reproduce my findings.
Necessary tools: Build chain for edk2, swtpm 0.5.2 and qemu 5.2.0

1. Build OVMF from edk2-stable202102 with
-a X64 -a IA32 \
-b RELEASE \
-D NETWORK_IP6_ENABLE \
-D TPM_ENABLE \
Shouldn't you also have '-D TPM_CONFIG_ENABLE' ?
You only need that if you want the TPM configuration option for the
bios menu. Without it the TPM should self configure ... I tried it
without and it still works for me (produces the bios log).

James


Thore Sommer <public@...>
 

Shouldn't you also have '-D TPM_CONFIG_ENABLE' ?
I've rebuild it with '-D TPM_CONFIG_ENABLE' added and the same issue occurs.
This enables the configuration menu. TPM support should be already enabled with '-D TPM_ENABLE' if I saw that correctly.

Best regards
Thore Sommer


Laszlo Ersek
 

On 04/27/21 01:44, James Bottomley wrote:
On Mon, 2021-04-26 at 21:56 +0200, Thore Sommer wrote:
Dear Maintainers,

during my testing with OVMF and swtpm I found out that kernel
versions newer than 5.8 don't show any information in
"/sys/kernel/security/tpm0/binary_bios_measurements" if swtpm
emulates a TPM 2.0 device. The file is still created but is empty.
The expected result would be that
"/sys/kernel/security/tpm0/binary_bios_measurements" contains the
TPM event log. TPM 1.2 devices are not affected.
I don't confirm this. I have Linux version 5.12.0-rc5+ installed and I
see the attached in my binary_bios_measurements (I've run it through
tpm2-eventlog so you can see the actual events).

With the help of git bisect I found out that the breaking kernel
commit is 85467f63a05c43364ba0b90d0c05bb89191543fa.
Reverting this on top the 5.12 release restores the expected
functionality.

Thanks to apalos and leiflindholm on the #edk2 IRC channel for
helping me with that.

I don't know if this is a bug in OVMF or in the Linux kernel, because
on a real device with a TPM 2.0 the output was as expected.

Tested with edk2-ovmf 202102, swtpm 0.5.2 and qemu 5.2.0 on Ubuntu
20.04.

If further information is needed to resolve this problem, I'd be
happy to provide them.
What that commit did was to allow the event log to be provided by the
ACPI table if one existed rather than always defaulting to it being
provided by the EFI configuration table. What I suspect has happened
from this:

[ 0.017358] ACPI: Reserving TPM2 table memory at [mem
0x7eb77000-0x7eb7704b]
Is that somehow you've got an empty TPM2 table installed in ACPI but I
don't know how you've done this. On my OVMF boot I'm using the direct
kernel command line and I have secure boot enabled but not activated,
which is why you only see PCRs 0-7 in the log.
IIRC the QEMU ACPI linker/loader exposes a TPM2 ACPI table as well;
maybe that conflicts with the edk2 TPM2 machinery built into OVMF,
somehow. An OVMF log (enabling DEBUG_VERBOSE) might help. Running
acpidump + iasl in the guest might help as well (for determining some
inconsistency). My gut feeling is that it's a fight between QEMU's ACPI
generator and the edk2 TPM infrastructure, over the ownership of the
TPM-related ACPI table(s).

Laszlo


Thore Sommer <public@...>
 

IIRC the QEMU ACPI linker/loader exposes a TPM2 ACPI table as well;
maybe that conflicts with the edk2 TPM2 machinery built into OVMF,
somehow. An OVMF log (enabling DEBUG_VERBOSE) might help. Running
acpidump + iasl in the guest might help as well (for determining some
inconsistency).
I've rebuild OVMF with '-D DEBUG_VERBOSE' and without '-b RELEASE'.
I've attached the generated logs and acpidump output.

It seems that for the kernel the eventlog is there with the correct header to not try to parse the efi log, but the log provided via ACPI has no entries.

Thore


James Bottomley
 

On Wed, 2021-04-28 at 16:56 +0200, Thore Sommer wrote:
TPM2 @ 0x0000000000000000
0000: 54 50 4D 32 4C 00 00 00 04 7F 42 4F 43 48 53 20 TPM2L.....BOCHS
0010: 42 58 50 43 54 50 4D 32 01 00 00 00 42 58 50 43 BXPCTPM2....BXPC
0020: 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
0030: 06 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
0040: 00 00 01 00 00 C0 BB 7E 00 00 00 00 .......~....
This is actually pretty much exactly what I see in the working OVMF

TPM2 @ 0x0000000000000000
0000: 54 50 4D 32 4C 00 00 00 04 DB 42 4F 43 48 53 20 TPM2L.....BOCHS
0010: 42 58 50 43 54 50 4D 32 01 00 00 00 42 58 50 43 BXPCTPM2....BXPC
0020: 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
0030: 06 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
0040: 00 00 01 00 00 60 BE 7F 00 00 00 00 .....`......

So it looks like the empty acpi table theory doesn't fly.

James


James Bottomley
 

On Wed, 2021-04-28 at 10:19 -0700, James Bottomley wrote:
On Wed, 2021-04-28 at 16:56 +0200, Thore Sommer wrote:
TPM2 @ 0x0000000000000000
0000: 54 50 4D 32 4C 00 00 00 04 7F 42 4F 43 48 53
20 TPM2L.....BOCHS
0010: 42 58 50 43 54 50 4D 32 01 00 00 00 42 58 50
43 BXPCTPM2....BXPC
0020: 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 ................
0030: 06 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 ................
0040: 00 00 01 00 00 C0 BB 7E 00 00 00
00 .......~....
This is actually pretty much exactly what I see in the working OVMF

TPM2 @ 0x0000000000000000
0000: 54 50 4D 32 4C 00 00 00 04 DB 42 4F 43 48 53
20 TPM2L.....BOCHS
0010: 42 58 50 43 54 50 4D 32 01 00 00 00 42 58 50
43 BXPCTPM2....BXPC
0020: 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 ................
0030: 06 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 ................
0040: 00 00 01 00 00 60 BE 7F 00 00 00
00 .....`......

So it looks like the empty acpi table theory doesn't fly.
Actually, there's another possibility, which is that you're not booting
via the efi stub. This is somewhat tricky to get right in grub, so you
can rule this out by booting ovmf to a shell and then executing vmlinuz
directly from the shell.

James


Thore Sommer <public@...>
 

So it looks like the empty acpi table theory doesn't fly.
What I meant was that the header of the tpm eventlog table is there, but table itself has no entries.
The ACPI "TPM2" table points to a valid tpm eventlog table.

I think my first attempt to create a OVMF debug output had not all information, so I attached a new one.

Thore


Thore Sommer <public@...>
 

This is somewhat tricky to get right in grub, so you
can rule this out by booting ovmf to a shell and then executing vmlinuz
directly from the shell.
I've now tried this and unfortunately it produces the same result.
The ACPI "TPM2" table is there and the tpm eventlog is empty.

Thore


Thore Sommer <public@...>
 

I think I found my problem.
The latest kernel from master probes if the table actually includes some values. This was introduced in 3dcd15665aca80197333500a4be3900948afccc1
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=3dcd15665aca80197333500a4be3900948afccc1

This commit is not in the 5.12 release, but is in the latest master branch.

Thank you for helping me troubleshoot this problem.
I've learned a lot over the last few days.

Thore


Laszlo Ersek
 

On 04/29/21 11:43, Thore Sommer wrote:
I think I found my problem.
The latest kernel from master probes if the table actually includes some
values. This was introduced in 3dcd15665aca80197333500a4be3900948afccc1
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=3dcd15665aca80197333500a4be3900948afccc1


This commit is not in the 5.12 release, but is in the latest master branch.

Thank you for helping me troubleshoot this problem.
I've learned a lot over the last few days.
Thanks for reporting back -- the kernel patch is from Stefan Berger; I'm
relieved he knows about this.

Thanks
Laszlo