Skip to content

C: Stop waiting for a guest whose QEMU has already exited - #167

Closed
markg-github wants to merge 1 commit into
mainfrom
fix/launch-detect-qemu-exit
Closed

C: Stop waiting for a guest whose QEMU has already exited#167
markg-github wants to merge 1 commit into
mainfrom
fix/launch-detect-qemu-exit

Conversation

@markg-github

Copy link
Copy Markdown
Owner

Review-preview PR against the fork. Independent of PRs A and B — based on main, touches only vm_profile.py and guest_vsock.py, no overlap with either.

The bug

vm_launch checks whether QEMU is still alive exactly once, at wait_ready_seconds, and never again. wait_for_guest then polls vsock until vsock_boot_timeout (180s) with no reference to the process at all. If QEMU exits after that single check, the harness spends the remainder of the boot timeout pinging a VM that no longer exists.

Measurement

EPYC 9654, ID block with a deliberately corrupted measurement, process sampled at 1 Hz:

+14.6s ..  +17.2s   QEMU alive (pid 13732)
+17.2s ..           gone
step ran +13.8s .. +195.9s

QEMU lived 2.6s; the step took 182.1s. ~179 seconds spent waiting on a dead process. Reproduced identically under two different BIOS versions.

Policy violations are rejected at SNP_LAUNCH_START, before guest memory is loaded, so QEMU dies inside the initial check and those launches already fail in ~2s. That is why only the measurement case was slow — it cannot be detected until SNP_LAUNCH_FINISH, after ~271MB has been loaded and measured.

The fix

Pass the process handle into wait_for_guest and abort as soon as it exits. process defaults to None, preserving existing behavior for any caller that does not supply it.

The step drops from 182.1s to ~3s; the id-block suite from ~200s to ~21s.

The diagnostics matter more than the speed

Firmware had already reported the exact cause:

qemu-system-x86_64: SNP_LAUNCH_FINISH ret=-5 fw_error=11 'Bad measurement'

The harness discarded that in favour of Vsock agent on CID ... not ready after 180.0s.

A negative test asserting exit_code:1 is satisfied by that timeout just as well as by a real rejection — so it would pass identically if the guest merely hung, or if the ID block were ignored entirely. The test could not fail for the right reason. The failure message now carries QEMU’s exit code and stderr tail, so a rejected launch states the firmware’s reason.

Verification

Unit-tested with a fake process: dies at 2s → wait aborts at 2.0s with QEMU exited with code 1 before the guest became ready; no process handle → full 20s timeout and the original message. Backward compatible.

Possible follow-up, not included

/tmp/guest-error.log is a single fixed path clobbered by every launch — recovering the evidence above required sampling it externally at 1 Hz. Writing it per-launch into ctx.artifact_dir would make this diagnosable from artifacts alone.

vm_launch checks whether QEMU is still alive exactly once, at
wait_ready_seconds, and never again. wait_for_guest then polls vsock
until vsock_boot_timeout with no reference to the process at all. If
QEMU exits after that single check, the harness spends the rest of the
boot timeout pinging a VM that no longer exists.

Measured on an EPYC 9654 with a deliberately corrupted ID block
measurement, sampling the process at 1 Hz:

  +14.6s .. +17.2s   QEMU alive
  +17.2s ..          gone
  step ran +13.8s .. +195.9s

QEMU lived 2.6s; the step took 182.1s. ~179s was spent waiting on a
dead process. Policy violations are rejected at SNP_LAUNCH_START before
guest memory is loaded, so QEMU dies inside the initial check and those
launches already fail in ~2s — which is why only the measurement case
was slow.

Pass the process handle into wait_for_guest and abort as soon as it
exits. The step drops from 182.1s to ~3s and the id-block suite from
~200s to ~21s.

The diagnostics matter more than the speed. Firmware had already
reported the exact cause:

  SNP_LAUNCH_FINISH ret=-5 fw_error=11 'Bad measurement'

and the harness discarded it in favour of "Vsock agent on CID ... not
ready after 180.0s". A negative test asserting exit_code:1 is satisfied
by that timeout just as well as by a real rejection, so it would pass
identically if the guest merely hung or if the ID block were ignored
entirely. The failure message now carries QEMU's exit code and its
stderr tail, so a rejected launch states the firmware's reason.

process defaults to None, preserving the old behavior for any caller
that does not supply it.
@markg-github

Copy link
Copy Markdown
Owner Author

Absorbed into PR 0 (#168), which bundles this with three other ID-block-independent harness fixes so they can merge together and ahead of the ID block work. The commit is carried over unchanged.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant