[systemd-devel] systemd-repart failure

Tue Jun 25 15:03:06 UTC 2024

Hi,

I've got a systemd repart config for rootfs with TPM encryption:

[Partition]
Type=root
Weight=100
Format=ext4
Encrypt=tpm2
FactoryReset=yes
MakeDirectories=/boot /usr /home /home/root
# copying etc from build time /usr image
CopyFiles=/usr/etc:/etc

/usr partition is a dm-verity one. But for some reason on AVA Developer
Platform this is not working. The systemd has nvme storage for ESP and
dm-verity paritions and plenty of space for the new rootfs, but it
also has a separate sda disk which we use as rescue system with Debian
on it.

Non-verbose boot log https://ledge.validation.linaro.org/scheduler/job/89753
shows the partitions after flashing:

sh-5.2# blkid
Waiting for 'sh-(.*)#', 'Press Enter for maintenance'
blkid
/dev/nvme0n1p3: UUID="c11f0c5f-bb2e-4dbc-906d-6a6089634e82" TYPE="DM_verity_hash" PARTLABEL="verityhash" PARTUUID="dc8ec8c9-25fc-0390-25b4-93a55f09a971"
/dev/nvme0n1p1: SEC_TYPE="msdos" LABEL_FATBOOT="bootfs" LABEL="bootfs" UUID="7819-74F8" BLOCK_SIZE="512" TYPE="vfat" PARTLABEL="ESP" PARTUUID="00112233-1234-1111-2222-000123456789"
/dev/nvme0n1p2: UUID="729df0a0-beb0-4981-9d0f-c707ced22ba2" BLOCK_SIZE="4096" TYPE="ext4" PARTLABEL="verityroot" PARTUUID="161608c4-eb17-2afb-f07c-1c2f0d2d07d1"
/dev/mapper/usr: UUID="729df0a0-beb0-4981-9d0f-c707ced22ba2" BLOCK_SIZE="4096" TYPE="ext4"
/dev/sda2: UUID="b60723a9-a342-401b-b0a4-194e661ccd0d" BLOCK_SIZE="4096" TYPE="ext4" PARTLABEL="primary" PARTUUID="441849f4-4f6a-420d-9d85-95048f5a2fcf"
/dev/sda1: SEC_TYPE="msdos" UUID="6AEA-E17B" BLOCK_SIZE="512" TYPE="vfat" PARTLABEL="primary" PARTUUID="a3462a88-510c-4a58-9796-e2c7f04a83a6"

and then systemd-repart is getting started but finishes without providing
/dev/gpt-auto-root:

         Starting [0;1;39mRepartition Root Disk[0m...
[[0;32m  OK  [0m] Reached target [0;1;39mSystem Initialization[0m.
[[0;32m  OK  [0m] Reached target [0;1;39mTimer Units[0m.
[[0;32m  OK  [0m] Listening on [0;1;39mD-Bus System Message Bus Socket[0m.
[[0;32m  OK  [0m] Reached target [0;1;39mSocket Units[0m.
[[0;32m  OK  [0m] Reached target [0;1;39mBasic System[0m.
[[0;32m  OK  [0m] Finished [0;1;39mRepartition Root Disk[0m.
         Starting [0;1;39mD-Bus System Message Bus[0m...
[[0;32m  OK  [0m] Started [0;1;39mD-Bus System Message Bus[0m.
[   11.736184] critical medium error, dev sda, sector 31266568 op 0x0:(READ) flags 0x80700 phys_seg 10 prio class 2
[   11.781616] critical medium error, dev sda, sector 31266680 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2
[   11.791360] Buffer I/O error on dev sda, logical block 3908335, async page read
[[0m[0;31m*     [0m] A start job is running for /dev/gpt-auto-root (5s / 1min 30s)
M
[K[[0;1;31m*[0m[0;31m*    [0m] A start job is running for /dev/gpt-auto-root (5s / 1min 30s)
M
[K[[0;31m*[0;1;31m*[0m[0;31m*   [0m] A start job is running for /dev/gpt-auto-root (6s / 1min 30s)
M
[K[ [0;31m*[0;1;31m*[0m[0;31m*  [0m] A start job is running for /dev/gpt-auto-root (6s / 1min 30s)
M
[K[  [0;31m*[0;1;31m*[0m[0;31m* [0m] A start job is running for /dev/gpt-auto-root (7s / 1min 30s)
M
[K[   [0;31m*[0;1;31m*[0m[0;31m*[0m] A start job is running for /dev/gpt-auto-root (7s / 1min 30s)
M
[K[    [0;31m*[0;1;31m*[0m] A start job is running for /dev/gpt-auto-root (8s / 1min 30s)
M
[K[     [0;31m*[0m] A start job is running for /dev/gpt-auto-root (9s / 1min 30s)
M
[K[    [0;31m*[0;1;31m*[0m] A start job is running for /dev/gpt-auto-root (9s / 1min 30s)
M
[K[   [0;31m*[0;1;31m*[0m[0;31m*[0m] A start job is running for /dev/gpt-auto-root (10s / 1min 30s)

What could be breaking systemd-repart on this box? The two ESP partitions possibly, or
the errors from sda?

I fired a systemd debug output run in https://ledge.validation.linaro.org/scheduler/job/89755
and this shows a different looking error from systemd-repart:

[0;38;5;245mChild 602 (systemd-repart) died (code=exited, status=1/FAILURE)[0m"}
[0;38;5;245msystemd-repart.service: Child 602 belongs to systemd-repart.service.[0m"}
[0;1;39msystemd-repart.service: Main process exited, code=exited, status=1/FAILURE[0m"}
[  105.387844] systemd-repart[602]: Failed to find TPM2 pcrlock policy file 'pcrlock.json': No such file or directory"}
[  105.387915] systemd-repart[602]: Reading EFI variable /sys/firmware/efi/efivars/FactoryReset-8cf2644b-4b0b-428f-9387-6d876050dc67."}
[  105.387970] systemd-repart[602]: open(\"/sys/firmware/efi/efivars/FactoryReset-8cf2644b-4b0b-428f-9387-6d876050dc67\") failed: No such file or directory"}
[0;1;38;5;185msystemd-repart.service: Failed with result 'exit-code'.[0m"}
[  105.388047] systemd-repart[602]: Failed to determine backing device of /: No such file or directory"}
[0;38;5;245msystemd-repart.service: Service will not restart (restart setting)[0m"}
[0;38;5;245msystemd-repart.service: Changed start -> failed[0m"}

>From what I can read the logs, the TPM2 devices is there, drivers are loaded and working.
But why is systemd-repart failing then?

The same kernel, initramfs and rootfs combo works on other discrete TPM and fTPM devices,
except this AVA box.

Cheers,

-Mikko