Project

General

Profile

Actions

action #112226

open

[sporadic] swtpm socket not found anymore after loading from snapshot size:M

Added by okurz over 2 years ago. Updated over 2 years ago.

Status:
Workable
Priority:
Normal
Assignee:
-
Category:
Regressions/Crashes
Target version:
Start date:
2022-06-09
Due date:
% Done:

0%

Estimated time:

Description

Observation

This was brought up in https://suse.slack.com/archives/C02CANHLANP/p1654758713739949 by dimstar.

https://openqa.opensuse.org/tests/2407873/logfile?filename=autoinst-log.txt shows a failure with

[2022-06-09T09:07:44.838696+02:00] [debug] ||| finished unlock_luks2_vol_tpm2 security/luks2 (runtime: 714 s)
[2022-06-09T09:07:44.838778+02:00] [debug] ||| post fail hooks runtime: 688 s
[2022-06-09T09:07:44.844049+02:00] [debug] Loading a VM snapshot lastgood
[2022-06-09T09:07:44.845497+02:00] [debug] Loading snapshot (Current VM state is running)
…
[2022-06-09T09:07:46.560562+02:00] [debug] starting: /usr/bin/qemu-system-x86_64 -only-migratable -chardev ringbuf,id=serial0,logfile=serial0,logappend=on -serial chardev:serial0 -audiodev none,id=snd0 -device intel-hda -device hda-output,audiodev=snd0 -global isa-fdc.fdtypeA=none -m 4096 -cpu qemu64 -netdev user,id=qanet0 -device virtio-net,netdev=qanet0,mac=52:54:00:12:34:56 -object rng-random,filename=/dev/urandom,id=rng0 -device virtio-rng-pci,rng=rng0 -chardev socket,id=chrtpm,path=/tmp/mytpm14/swtpm-sock -tpmdev emulator,id=tpm0,chardev=chrtpm -device tpm-tis,tpmdev=tpm0 -boot once=d -device qemu-xhci -device usb-tablet -smp 1 -enable-kvm -no-shutdown -vnc :104,share=force-shared -device virtio-serial -chardev pipe,id=virtio_console,path=virtio_console,logfile=virtio_console.log,logappend=on -device virtconsole,chardev=virtio_console,name=org.openqa.console.virtio_console -chardev pipe,id=virtio_console1,path=virtio_console1,logfile=virtio_console1.log,logappend=on -device virtconsole,chardev=virtio_console1,name=org.openqa.console.virtio_console1 -chardev socket,path=qmp_socket,server=on,wait=off,id=qmp_socket,logfile=qmp_socket.log,logappend=on -qmp chardev:qmp_socket -S -device virtio-scsi-pci,id=scsi0 -blockdev driver=file,node-name=hd0-overlay2-file,filename=/var/lib/openqa/pool/14/raid/hd0-overlay2,cache.no-flush=on -blockdev driver=qcow2,node-name=hd0-overlay2,file=hd0-overlay2-file,cache.no-flush=on -device virtio-blk,id=hd0-device,drive=hd0-overlay2,serial=hd0 -blockdev driver=file,node-name=cd0-overlay2-file,filename=/var/lib/openqa/pool/14/raid/cd0-overlay2,cache.no-flush=on -blockdev driver=qcow2,node-name=cd0-overlay2,file=cd0-overlay2-file,cache.no-flush=on -device scsi-cd,id=cd0-device,drive=cd0-overlay2,serial=cd0 -incoming defer
[2022-06-09T09:07:46.580017+02:00] [debug] Waiting for 0 attempts
[2022-06-09T09:07:46.791292+02:00] [debug] Waiting for 1 attempts
[2022-06-09T09:07:46.791498+02:00] [info] ::: backend::baseclass::die_handler: Backend process died, backend errors are reported below in the following lines:
  QEMU terminated before QMP connection could be established. Check for errors below
[2022-06-09T09:07:46.791908+02:00] [info] ::: OpenQA::Qemu::Proc::save_state: Saving QEMU state to qemu_state.json
[2022-06-09T09:07:46.792932+02:00] [debug] Passing remaining frames to the video encoder
[2022-06-09T09:07:46.841168+02:00] [debug] Waiting for video encoder to finalize the video
[2022-06-09T09:07:46.841296+02:00] [debug] The built-in video encoder (pid 20448) terminated
[2022-06-09T09:07:46.841511+02:00] [debug] QEMU: QEMU emulator version 5.2.0 (SUSE Linux Enterprise 15)
[2022-06-09T09:07:46.841565+02:00] [debug] QEMU: Copyright (c) 2003-2020 Fabrice Bellard and the QEMU Project developers
[2022-06-09T09:07:46.841647+02:00] [warn] !!! : qemu-system-x86_64: -chardev socket,id=chrtpm,path=/tmp/mytpm14/swtpm-sock: Failed to connect to '/tmp/mytpm14/swtpm-sock': No such file or directory

Suggestions

  • Investigate how zypper fails because of packagekit retaining the lock, see https://openqa.opensuse.org/tests/2407873/#step/unlock_luks2_vol_tpm2/10 should not be relevant as the problem is very likely just that we load a snapshot
  • Confirm if the missing tpm socket is relevant for the specific failure '/tmp/mytpm14/swtpm-sock': No such file or directory; maybe the socket was closed here since this is a snapshot which loads a new qemu instance
  • Check if the warning message does not already show up in maybe even passed jobs
  • Try to reproduce the problem, e.g. with os-autoinst t/99-full-stack.t when adding corresponding SWTPM variables and loading qemu snapshots
  • Ensure that such message about swtpm is only shown if there is a relevant, related error
  • Confirm the fix in the related ticket #112241

Related issues 1 (0 open1 closed)

Related to openQA Tests (public) - action #112241: [tw][security]unlock_luks2_vol_tpm2: interaction with zypper blocked by PKResolvedrfan12022-06-09

Actions
Actions #1

Updated by okurz over 2 years ago

  • Related to action #112241: [tw][security]unlock_luks2_vol_tpm2: interaction with zypper blocked by PK added
Actions #2

Updated by okurz over 2 years ago

  • Status changed from New to Blocked
  • Assignee set to okurz
Actions #3

Updated by okurz over 2 years ago

  • Status changed from Blocked to New
  • Assignee deleted (okurz)
Actions #4

Updated by livdywan over 2 years ago

  • Subject changed from [sporadic] swtpm socket not found anymore after loading from snapshot to [sporadic] swtpm socket not found anymore after loading from snapshot size:M
  • Description updated (diff)
  • Status changed from New to Workable
Actions #5

Updated by okurz over 2 years ago

  • Target version changed from Ready to future

We can't currently solve this. Needs to be followed up by someone else.

Actions

Also available in: Atom PDF