[Bug 1968131] Re: Starting VM with UEFI firmware fails with swtpm

Thu Apr 7 10:59:46 UTC 2022

# clean
$ sudo apt remove --purge swtpm swtpm-tools
$ sudo rm -rf /var/lib/libvirt/swtpm /var/lib/swtpm-localca /var/log/swtpm

# re-create  a clean env by re-installing swtpm
$ sudo apt install swtpm swtpm-tools

# Status after install
$ sudo ls -laF /var/lib/libvirt/swtpm /var/lib/swtpm-localca /var/log/swtpm /run/libvirt/qemu/swtpm
ls: cannot access '/var/lib/libvirt/swtpm': No such file or directory
ls: cannot access '/var/log/swtpm': No such file or directory
/run/libvirt/qemu/swtpm:
total 0
drwxrwx--- 2 libvirt-qemu swtpm  40 Apr  7 10:33 ./
drwxr-xr-x 5 root         root  140 Apr  7 10:33 ../

/var/lib/swtpm-localca:
total 8
drwxr-x---  2 swtpm root 4096 Apr  7 10:48 ./
drwxr-xr-x 43 root  root 4096 Apr  7 10:48 ../

# then failing a start of a VM with swtpm configured
$ virsh start testguest --console

# File/Dir status after this
$ sudo ls -laF /var/lib/libvirt/swtpm /var/lib/swtpm-localca /var/log/swtpm /run/libvirt/qemu/swtpm /var/log/swtpm/libvirt/qemu /var/log/swtpm/libvirt
/run/libvirt/qemu/swtpm:
total 0
drwxrwx--- 2 libvirt-qemu swtpm  40 Apr  7 10:33 ./
drwxr-xr-x 5 root         root  140 Apr  7 10:33 ../

/var/lib/libvirt/swtpm:
total 8
drwx--x--x 2 root root 4096 Apr  7 10:50 ./
drwxr-xr-x 8 root root 4096 Apr  7 10:50 ../

/var/lib/swtpm-localca:
total 20
drwxr-x---  2 swtpm root  4096 Apr  7 10:50 ./
drwxr-xr-x 43 root  root  4096 Apr  7 10:48 ../
-rwxr-xr-x  1 swtpm swtpm    0 Apr  7 10:50 .lock.swtpm-localca*
-rw-r--r--  1 swtpm swtpm    0 Apr  7 10:50 index.txt
-rw-r--r--  1 swtpm swtpm    3 Apr  7 10:50 serial
-rw-r--r--  1 swtpm swtpm 1468 Apr  7 10:50 swtpm-localca-rootca-cert.pem
-rw-r-----  1 swtpm swtpm 2455 Apr  7 10:50 swtpm-localca-rootca-privkey.pem

/var/log/swtpm:
total 12
drwx--x--x  3 root root   4096 Apr  7 10:50 ./
drwxrwxr-x 10 root syslog 4096 Apr  7 10:50 ../
drwx--x--x  3 root root   4096 Apr  7 10:50 libvirt/

/var/log/swtpm/libvirt:
total 12
drwx--x--x 3 root  root  4096 Apr  7 10:50 ./
drwx--x--x 3 root  root  4096 Apr  7 10:50 ../
drwx-wx--- 2 swtpm swtpm 4096 Apr  7 10:50 qemu/

/var/log/swtpm/libvirt/qemu:
total 12
drwx-wx--- 2 swtpm swtpm 4096 Apr  7 10:50 ./
drwx--x--x 3 root  root  4096 Apr  7 10:50 ../
-rw-r--r-- 1 swtpm swtpm 1730 Apr  7 10:50 testguest-swtpm.log

---

After this failed try - since the guest is abandoned we have some
differences for a retry

- /var/lib/libvirt/swtpm/202a34a9-2ee2-4826-b206-c249f535be90/tpm2 no more exists
- /var/log/swtpm/libvirt/qemu/testguest-swtpm.log can't be written

$ sudo rm -rf /tmp/test2
$ mkdir /tmp/test2
$ sudo chown swtpm:swtpm /tmp/test2
$ sudo -u swtpm /usr/lib/x86_64-linux-gnu/swtpm/swtpm-localca --type ek --ek b2e69cdcfc19832f9d174ef4c3af14cf9843efed4e986f35d011a4ac0af4a84adf93a24937bf00da5519272a1f722ae3aa33b8efbe44b3bcde8ac2cf781302801643791f379eab400482f0c4b8a9aba1676eb7b0ae45792d39746a82164c247d4d348aecba70025d74f7025d2e1896743617396337f6221bd81429c3498069056635f9ddf288fe32d9759fa6a825665e56d819b5657f5ce828e72db17e6073cf4e4c7f9dfd8ea18eebae28e9cffa6ff406d03a8a15e48a3f5acd7a3cca7d64b9aef250cc40a301132d466f346843f9a3e084bf9e19fe48b31d2512f39ddd6bc324d22db77dad619158efa5680ff4816c7fc645014e6fa03fb11ede6bc720bbd7 --dir /tmp/test --logfile /tmp/test/testguest-swtpm.log --vmid testguest:202a34a9-2ee2-4826-b206-c249f535be90 --tpm-spec-family 2.0 --tpm-spec-level 0 --tpm-spec-revision 164 --tpm-manufacturer id:00001014 --tpm-model swtpm --tpm-version id:20191023 --tpm2 --configfile /etc/swtpm-localca.conf --optsfile /etc/swtpm-localca.options

$ echo $?
1
$ cat /tmp/test/testguest-swtpm.log
Creating root CA and a local CA's signing key and issuer cert.
Could not create root-CA:Can't load ./.rnd into RNG
40D7E55E677F0000:error:12000079:random number generator:RAND_load_file:Cannot open file:../crypto/rand/randfile.c:106:Filename=./.rnd
Cannot write random bytes:
40D7E55E677F0000:error:12000079:random number generator:RAND_write_file:Cannot open file:../crypto/rand/randfile.c:240:Filename=./.rnd

Error creating local CA's signing key and cert.

That is kind of the same error, so it really is the user/group and some permissions.
This way we can repro it outside of libvirt, track which access exactly fails and debug/fix it.

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to swtpm in Ubuntu.
https://bugs.launchpad.net/bugs/1968131

Title:
  Starting VM with UEFI firmware fails with swtpm

Status in libvirt package in Ubuntu:
  New
Status in swtpm package in Ubuntu:
  New
Status in virt-manager package in Ubuntu:
  New
Status in libvirt source package in Jammy:
  New
Status in swtpm source package in Jammy:
  New
Status in virt-manager source package in Jammy:
  New

Bug description:
  https://launchpad.net/ubuntu/+source/libvirt/8.0.0-1ubuntu6 introduced
  a recommendation to "swtpm", so this package now gets installed by
  default when installing libvirt. But this broke UEFI:

    touch /var/lib/libvirt/empty.iso
    virt-install --name t1 --os-variant fedora28 --memory 128 --wait -1 --noautoconsole --disk 'size=0.25,format=qcow2' --cdrom /var/lib/libvirt/empty.iso --boot uefi

  This fails:

  WARNING  Requested memory 128 MiB is less than the recommended 1024
  MiB for OS fedora28

  Starting install...
  Allocating 't1.qcow2'                                                                                                          |    0 B  00:00:00 ... 
  Removing disk 't1.qcow2'                                                                                                       |    0 B  00:00:00     
  ERROR    internal error: Could not run '/usr/bin/swtpm_setup'. exitstatus: 1; Check error log '/var/log/swtpm/libvirt/qemu/t1-swtpm.log' for details.
  Domain installation does not appear to have been successful.

  # cat /var/log/swtpm/libvirt/qemu/t1-swtpm.log
  Starting vTPM manufacturing as swtpm:swtpm @ Thu 07 Apr 2022 07:11:55 AM UTC
  Successfully created RSA 2048 EK with handle 0x81010001.
    Invoking /usr/lib/x86_64-linux-gnu/swtpm/swtpm-localca --type ek --ek 91863a7321edf06c0feb6f388950774acca7813f0d595a78463c1ce29798ab015bebb70da8a1fb8c4c353507240d32afd0e51ff173068e86e40c8f71bfa311919dd8f840e7a11576515eff08739822cfe7d3c4cc0e228623f140fc2948a0c519bc2b3d06d0a7f5bd9add9d27d9d2132459ae7911dc441dd156c842ac7b8fcb5611e589fde7ca9516eaf3a32b64b7ece348b023a6567e64a9ad491c12b1309624f7fcaa4dc9f69387bc59a743c64db664f78258dccda63635e5e934f22e594e073906e737486268601fd812979a16db23faf0512d3b714d832d69a80fc01b31cec1d5603ee06544338907f38164636df6cfbdc1168ac5eda01ff5def64076e5e7 --dir /var/lib/libvirt/swtpm/ade6145c-3d22-46d8-8bbc-29792e4cfa0c/tpm2 --logfile /var/log/swtpm/libvirt/qemu/t1-swtpm.log --vmid t1:ade6145c-3d22-46d8-8bbc-29792e4cfa0c --tpm-spec-family 2.0 --tpm-spec-level 0 --tpm-spec-revision 164 --tpm-manufacturer id:00001014 --tpm-model swtpm --tpm-version id:20191023 --tpm2 --configfile /etc/swtpm-localca.conf --optsfile /etc/swtpm-localca.options
  Creating root CA and a local CA's signing key and issuer cert.
  Could not create root-CA:Can't load ./.rnd into RNG
  40D7AD231A7F0000:error:12000079:random number generator:RAND_load_file:Cannot open file:../crypto/rand/randfile.c:106:Filename=./.rnd
  Cannot write random bytes:
  40D7AD231A7F0000:error:12000079:random number generator:RAND_write_file:Cannot open file:../crypto/rand/randfile.c:240:Filename=./.rnd

  Error creating local CA's signing key and cert.
  swtpm-localca exit with status 1: 
  An error occurred. Authoring the TPM state failed.
  Ending vTPM manufacturing @ Thu 07 Apr 2022 07:11:56 AM UTC

  When I uninstall swtpm, the domain creation/starting works (of course
  it does not actually do anything due to the fake empty iso, but it
  does get past that bug).

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/libvirt/+bug/1968131/+subscriptions