From 866d327f0bad3a0730801a22654bac45e02ee14b Mon Sep 17 00:00:00 2001 From: Craig Jennings Date: Mon, 20 Jul 2026 23:40:56 -0500 Subject: fix(test): harden four VM-framework paths from the S5 audit init_vm_paths suffixed the disk and NVRAM by FS_PROFILE but left PID_FILE, MONITOR_SOCK, and SERIAL_LOG shared. A concurrent btrfs and zfs run read each other's PID file, so the second run's stop logic could kill the first run's VM. All runtime paths now carry the suffix. kill_qemu sent kill -9 and returned without waiting, so the force-kill fallback could run qemu-img snapshot against a qcow2 the dying qemu still held locked (the restore failed silently behind || true, leaving the base image dirty). It now reaps or polls the process to death before returning. debug-vm.sh hardcoded the btrfs base-disk name, so FS_PROFILE=zfs booted the wrong base or fatalled. It now takes DISK_PATH from init_vm_paths. Both runners reported a completion-marker grep as "ArchSetup Exit Code," but the installer runs detached with set -e off, so its real exit status was never captured -- a run that errored mid-way and still reached its last line reported exit 0. The flag is now ARCHSETUP_COMPLETED with the report labeled honestly; Testinfra stays the pass/fail authority. --- scripts/testing/debug-vm.sh | 4 +- scripts/testing/lib/vm-utils.sh | 21 +++++- scripts/testing/run-test-baremetal.sh | 17 +++-- scripts/testing/run-test.sh | 18 ++--- tests/vm-framework/test_vm_utils.py | 130 ++++++++++++++++++++++++++++++++++ 5 files changed, 171 insertions(+), 19 deletions(-) create mode 100644 tests/vm-framework/test_vm_utils.py diff --git a/scripts/testing/debug-vm.sh b/scripts/testing/debug-vm.sh index b0fa2b9..d05ed59 100755 --- a/scripts/testing/debug-vm.sh +++ b/scripts/testing/debug-vm.sh @@ -46,7 +46,6 @@ fi # Configuration TIMESTAMP=$(date +'%Y%m%d-%H%M%S') VM_IMAGES_DIR="$PROJECT_ROOT/vm-images" -BASE_DISK="$VM_IMAGES_DIR/archsetup-base.qcow2" ROOT_PASSWORD="archsetup" OVERLAY_DISK="" @@ -54,6 +53,9 @@ OVERLAY_DISK="" LOGFILE="/tmp/debug-vm-$TIMESTAMP.log" init_logging "$LOGFILE" init_vm_paths "$VM_IMAGES_DIR" +# The profile-correct base image comes from init_vm_paths; a hardcoded +# archsetup-base.qcow2 booted the btrfs base under FS_PROFILE=zfs. +BASE_DISK="$DISK_PATH" cleanup_debug() { if declare -f vm_is_running >/dev/null 2>&1 && vm_is_running; then diff --git a/scripts/testing/lib/vm-utils.sh b/scripts/testing/lib/vm-utils.sh index b85e773..b6686e9 100755 --- a/scripts/testing/lib/vm-utils.sh +++ b/scripts/testing/lib/vm-utils.sh @@ -66,9 +66,12 @@ init_vm_paths() { # let a zfs run's ZFSBootMenu entries clobber the btrfs GRUB entry, leaving # the btrfs base unbootable (no removable ESP fallback to recover from). OVMF_VARS="$VM_IMAGES_DIR/OVMF_VARS${img_suffix}.fd" - PID_FILE="$VM_IMAGES_DIR/qemu.pid" - MONITOR_SOCK="$VM_IMAGES_DIR/qemu-monitor.sock" - SERIAL_LOG="$VM_IMAGES_DIR/qemu-serial.log" + # Runtime paths carry the same suffix: a concurrent btrfs and zfs run + # sharing one PID file let the second run's stop logic kill the first + # run's VM, and both truncated the same serial log. + PID_FILE="$VM_IMAGES_DIR/qemu${img_suffix}.pid" + MONITOR_SOCK="$VM_IMAGES_DIR/qemu-monitor${img_suffix}.sock" + SERIAL_LOG="$VM_IMAGES_DIR/qemu-serial${img_suffix}.log" mkdir -p "$VM_IMAGES_DIR" } @@ -287,6 +290,18 @@ kill_qemu() { pid=$(cat "$PID_FILE" 2>/dev/null) if [ -n "$pid" ]; then kill -9 "$pid" 2>/dev/null || true + # Wait for the process to actually die before returning: the + # force-kill fallback is followed by restore_snapshot, and + # qemu-img refuses a qcow2 the dying qemu still holds locked. + # `wait` reaps it when it's our child; otherwise poll until the + # /proc entry is gone or a zombie (fds released either way). + wait "$pid" 2>/dev/null || true + local i state + for i in $(seq 1 50); do + state=$(awk '{print $3}' "/proc/$pid/stat" 2>/dev/null) || state="" + [ -z "$state" ] || [ "$state" = "Z" ] && break + sleep 0.1 + done fi fi _cleanup_qemu_files diff --git a/scripts/testing/run-test-baremetal.sh b/scripts/testing/run-test-baremetal.sh index d22c424..d837389 100755 --- a/scripts/testing/run-test-baremetal.sh +++ b/scripts/testing/run-test-baremetal.sh @@ -228,14 +228,17 @@ if ! $VALIDATE_ONLY; then if [ $POLL_COUNT -ge $MAX_POLLS ]; then error "ArchSetup timed out after 90 minutes" - ARCHSETUP_EXIT_CODE=124 + ARCHSETUP_COMPLETED=timeout else - step "Retrieving archsetup exit status" + # The installer runs detached with set -e off, so its real exit + # status is unavailable; the marker only proves the script reached + # its last line. Testinfra is the pass/fail authority. + step "Checking for the archsetup completion marker" if ssh_cmd "grep -q 'ARCHSETUP_EXECUTION_COMPLETE' /var/log/archsetup-*.log 2>/dev/null"; then - ARCHSETUP_EXIT_CODE=0 + ARCHSETUP_COMPLETED=yes success "ArchSetup completed successfully" else - ARCHSETUP_EXIT_CODE=1 + ARCHSETUP_COMPLETED=no error "ArchSetup may have encountered errors" fi fi @@ -259,7 +262,7 @@ if ! $VALIDATE_ONLY; then capture_post_install_state "$TEST_RESULTS_DIR" else info "Skipping archsetup (--validate-only)" - ARCHSETUP_EXIT_CODE=0 + ARCHSETUP_COMPLETED=yes mkdir -p "$TEST_RESULTS_DIR/pre-install" "$TEST_RESULTS_DIR/post-install" fi @@ -302,7 +305,7 @@ Target: $TARGET_HOST Test Method: Bare Metal ZFS Results: - ArchSetup Exit Code: $ARCHSETUP_EXIT_CODE + ArchSetup Completed: $ARCHSETUP_COMPLETED (completion marker, not the installer's exit code) Validation: $(if $TEST_PASSED; then echo "PASSED"; else echo "FAILED"; fi) Validation Summary: @@ -335,7 +338,7 @@ fi # Final summary section "Test Complete" -if [ "$ARCHSETUP_EXIT_CODE" -eq 0 ] && $TEST_PASSED; then +if [ "$ARCHSETUP_COMPLETED" = "yes" ] && $TEST_PASSED; then success "TEST PASSED" exit 0 else diff --git a/scripts/testing/run-test.sh b/scripts/testing/run-test.sh index f962df3..a5c3691 100755 --- a/scripts/testing/run-test.sh +++ b/scripts/testing/run-test.sh @@ -280,15 +280,17 @@ done if [ $POLL_COUNT -ge $MAX_POLLS ]; then error "ArchSetup timed out after 150 minutes" - ARCHSETUP_EXIT_CODE=124 + ARCHSETUP_COMPLETED=timeout else - # Get exit code from the remote log - step "Retrieving archsetup exit status..." - ARCHSETUP_EXIT_CODE=$(vm_exec "$ROOT_PASSWORD" \ - "grep -q 'ARCHSETUP_EXECUTION_COMPLETE' /var/log/archsetup-*.log 2>/dev/null && echo 0 || echo 1" \ + # The installer runs detached with set -e off, so its real exit status + # is unavailable here; the completion marker only proves the script ran + # to its last line. Testinfra below is the actual pass/fail authority. + step "Checking for the archsetup completion marker..." + ARCHSETUP_COMPLETED=$(vm_exec "$ROOT_PASSWORD" \ + "grep -q 'ARCHSETUP_EXECUTION_COMPLETE' /var/log/archsetup-*.log 2>/dev/null && echo yes || echo no" \ 2>/dev/null) - if [ "$ARCHSETUP_EXIT_CODE" = "0" ]; then + if [ "$ARCHSETUP_COMPLETED" = "yes" ]; then success "ArchSetup completed successfully" else error "ArchSetup may have encountered errors (check logs)" @@ -370,7 +372,7 @@ VM Configuration: SSH: localhost:$SSH_PORT Results: - ArchSetup Exit Code: $ARCHSETUP_EXIT_CODE + ArchSetup Completed: $ARCHSETUP_COMPLETED (completion marker, not the installer's exit code) Validation: $(if $TEST_PASSED; then echo "PASSED"; else echo "FAILED"; fi) Validation Summary: @@ -424,7 +426,7 @@ CLEANUP_DONE=1 # Final summary section "Test Complete" -if [ "$ARCHSETUP_EXIT_CODE" = "0" ] && $TEST_PASSED; then +if [ "$ARCHSETUP_COMPLETED" = "yes" ] && $TEST_PASSED; then success "TEST PASSED" exit 0 else diff --git a/tests/vm-framework/test_vm_utils.py b/tests/vm-framework/test_vm_utils.py new file mode 100644 index 0000000..579955b --- /dev/null +++ b/tests/vm-framework/test_vm_utils.py @@ -0,0 +1,130 @@ +"""Tests for the VM test framework's vm-utils helpers. + +Two robustness bugs under test: + +1. init_vm_paths suffixed DISK_PATH and OVMF_VARS by FS_PROFILE but left + PID_FILE, MONITOR_SOCK, and SERIAL_LOG unsuffixed, so a concurrent btrfs + and zfs run shared them -- the second run's stop/is-running logic read the + first run's PID and could kill the other VM. All runtime paths now carry + the profile suffix. +2. kill_qemu sent kill -9 and deleted the PID file without waiting for the + process to die, so a force-kill fallback could run qemu-img snapshot + against a qcow2 the dying qemu still held locked. kill_qemu now waits for + the process to be dead (or reaped) before returning. + +Method: sed-extract init_vm_paths / kill_qemu / _cleanup_qemu_files from +lib/vm-utils.sh and drive them with temp dirs and real background processes. + +Run from repo root: + python3 -m unittest tests.vm-framework.test_vm_utils +""" + +import os +import subprocess +import tempfile +import textwrap +import unittest + +REPO_ROOT = os.path.abspath(os.path.join(os.path.dirname(__file__), "..", "..")) +VM_UTILS = os.path.join(REPO_ROOT, "scripts", "testing", "lib", "vm-utils.sh") + +EXTRACT = ( + "source <(sed -n '/^init_vm_paths() {{/,/^}}/p;" + "/^kill_qemu() {{/,/^}}/p;" + "/^_cleanup_qemu_files() {{/,/^}}/p' \"{lib}\")" +).format(lib=VM_UTILS) + + +def run(body): + script = f"fatal() {{ echo \"FATAL: $*\"; exit 1; }}\nwarn() {{ :; }}\n{EXTRACT}\n{body}\n" + return subprocess.run( + ["bash", "-c", script], capture_output=True, text=True, timeout=30, + ) + + +class InitVmPaths(unittest.TestCase): + def paths_for(self, profile): + with tempfile.TemporaryDirectory() as d: + body = textwrap.dedent(f"""\ + FS_PROFILE={profile} + init_vm_paths "{d}" + echo "DISK=$DISK_PATH" + echo "VARS=$OVMF_VARS" + echo "PID=$PID_FILE" + echo "MON=$MONITOR_SOCK" + echo "SER=$SERIAL_LOG" + """) + return run(body).stdout + + def test_zfs_profile_suffixes_all_runtime_paths(self): + out = self.paths_for("zfs") + self.assertIn("archsetup-base-zfs.qcow2", out) + self.assertIn("OVMF_VARS-zfs.fd", out) + # The bug: these three shared one name across profiles. + self.assertIn("PID=", out) + self.assertRegex(out, r"PID=.*-zfs", + "PID_FILE must carry the profile suffix") + self.assertRegex(out, r"MON=.*-zfs", + "MONITOR_SOCK must carry the profile suffix") + self.assertRegex(out, r"SER=.*-zfs", + "SERIAL_LOG must carry the profile suffix") + + def test_btrfs_profile_keeps_legacy_unsuffixed_names(self): + out = self.paths_for("btrfs") + self.assertIn("DISK=", out) + self.assertIn("archsetup-base.qcow2", out) + self.assertNotIn("-btrfs", out) + + def test_invalid_profile_fatals(self): + out = self.paths_for("ext4") + self.assertIn("FATAL", out) + + +class KillQemu(unittest.TestCase): + def test_process_is_dead_before_return(self): + # Contract pin for the snapshot-restore race: when kill_qemu returns, + # the process must be dead or reaped -- state Z or /proc entry gone -- + # so a following qemu-img call can't hit a still-held qcow2 lock. + with tempfile.TemporaryDirectory() as d: + body = textwrap.dedent(f"""\ + PID_FILE="{d}/qemu.pid" + MONITOR_SOCK="{d}/qemu-monitor.sock" + sleep 60 & victim=$! + echo "$victim" > "$PID_FILE" + kill_qemu + state=$(awk '{{print $3}}' "/proc/$victim/stat" 2>/dev/null || echo GONE) + echo "STATE=$state" + [ -f "$PID_FILE" ] && echo "PIDFILE=present" || echo "PIDFILE=removed" + """) + r = run(body) + self.assertRegex(r.stdout, r"STATE=(Z|GONE)", + f"process still live after kill_qemu: {r.stdout}") + self.assertIn("PIDFILE=removed", r.stdout) + + def test_stale_pid_file_is_cleaned_quietly(self): + with tempfile.TemporaryDirectory() as d: + body = textwrap.dedent(f"""\ + PID_FILE="{d}/qemu.pid" + MONITOR_SOCK="{d}/qemu-monitor.sock" + echo 99999999 > "$PID_FILE" + kill_qemu + echo "RC=$?" + [ -f "$PID_FILE" ] && echo "PIDFILE=present" || echo "PIDFILE=removed" + """) + r = run(body) + self.assertIn("RC=0", r.stdout) + self.assertIn("PIDFILE=removed", r.stdout) + + def test_no_pid_file_is_a_noop(self): + with tempfile.TemporaryDirectory() as d: + body = textwrap.dedent(f"""\ + PID_FILE="{d}/qemu.pid" + MONITOR_SOCK="{d}/qemu-monitor.sock" + kill_qemu + echo "RC=$?" + """) + self.assertIn("RC=0", run(body).stdout) + + +if __name__ == "__main__": + unittest.main() -- cgit v1.2.3