From 8bb4d3a60da36e51d244ab596a381d6e7fcc8428 Mon Sep 17 00:00:00 2001 From: Krzysztof kuhy Rudnicki Date: Sat, 22 Aug 2026 22:31:39 +0200 Subject: [PATCH] vmbox: bound every wait, so an unbootable guest fails instead of hanging Testing boot_recovery produced a guest that cannot boot: boot-repair read /boot/vmlinuz-linux and initramfs-linux.img on this BIOS/GRUB guest as "orphaned kernel files shadowing the ESP" and deleted them, leaving the sandbox at a GRUB prompt. That is a legitimate sandbox outcome -- destroying the guest is what the tool is for -- but vmbox handled it by hanging. Two independent unbounded waits, both fixed: - vm_wait_ssh counted only its `sleep 2` calls, ignoring the up-to-5s ConnectTimeout each failed probe spends inside ssh. A nominal 150s wait ran past 400s (measured, then cut short by the harness). It now works to a wall clock deadline: the same guest is now reported unreachable in 156s. - _run_recover_rc reboots the stopped guest to read the recorded exit code, and fell through to an unbounded serial console read: 180s for a prompt that never comes plus 300s for a command that never runs, all AFTER the verdict had already been printed. Recovery is best-effort by definition, so both bounds are now short (60s/30s) and overridable. serial_exec's timeouts become env-overridable to make that possible. Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01VdyMBGCrGVGDWtJ9xe48f3 --- vmbox/lib/run.sh | 20 +++++++++++++++++--- vmbox/lib/serial_exec.py | 11 +++++++++-- vmbox/lib/ssh.sh | 20 +++++++++++++++----- 3 files changed, 41 insertions(+), 10 deletions(-) diff --git a/vmbox/lib/run.sh b/vmbox/lib/run.sh index 9d2a93b..f3e2a16 100644 --- a/vmbox/lib/run.sh +++ b/vmbox/lib/run.sh @@ -30,6 +30,9 @@ readonly GUEST_ENV_SETUP='[ -f /etc/profile.d/vmbox-x11.sh ] && . /etc/profile.d # sshd does not. ssh stays available as the faster path for bulk work. readonly VMBOX_TRANSPORT="${VMBOX_TRANSPORT:-auto}" readonly VMBOX_RUN_TIMEOUT="${VMBOX_RUN_TIMEOUT:-600}" +# Bounds for the post-verdict exit-code recovery boot (see _run_recover_rc). +readonly RECOVER_SSH_TIMEOUT="${VMBOX_RECOVER_SSH_TIMEOUT:-60}" +readonly RECOVER_SERIAL_TIMEOUT="${VMBOX_RECOVER_SERIAL_TIMEOUT:-30}" run_in_vm() { local name @@ -153,18 +156,29 @@ _run_finish() { # Boot the sandbox again just far enough to read the recorded exit code. # The overlay survives the poweroff, so the value written before the machine # stopped is still there. +# +# Every wait here is BOUNDED, because this runs after the verdict has already +# been printed: it is a best-effort nicety, never a reason to hang. The guest +# being tested may well be unbootable -- that is a normal outcome for a +# sandbox, not an error. A boot-repair run that deleted /boot/vmlinuz left a +# guest sitting at a GRUB prompt, and the unbounded console read then blocked +# for 480s AFTER "VERDICT: clean poweroff" had been reported, which reads as +# a hung tool rather than a recovered exit code. _run_recover_rc() { local name="$1" rc="" console launch_vm "$name" >/dev/null 2>&1 || return 0 - if vm_wait_ssh "$name" 90; then + if vm_wait_ssh "$name" "$RECOVER_SSH_TIMEOUT"; then rc="$(vm_ssh_exec "$name" "cat $RC_PATH 2>/dev/null" 2>/dev/null | tr -dc '0-9')" else # ssh may be broken or simply slower than the console; the serial - # shell can read the file just as well. + # shell can read the file just as well -- but only give it a short + # window, since an unbootable guest never produces a prompt at all. console="$(vm_console "$name")" if [[ -S "$console" ]]; then - rc="$(python3 "$VMBOX_LIB_DIR/serial_exec.py" "$console" \ + rc="$(VMBOX_SERIAL_PROMPT_TIMEOUT="$RECOVER_SERIAL_TIMEOUT" \ + VMBOX_SERIAL_RUN_TIMEOUT="$RECOVER_SERIAL_TIMEOUT" \ + python3 "$VMBOX_LIB_DIR/serial_exec.py" "$console" \ "cat $RC_PATH 2>/dev/null" 2>/dev/null | grep -oE '^[0-9]+' | head -1)" fi fi diff --git a/vmbox/lib/serial_exec.py b/vmbox/lib/serial_exec.py index 7ec521a..795125f 100755 --- a/vmbox/lib/serial_exec.py +++ b/vmbox/lib/serial_exec.py @@ -19,6 +19,7 @@ Usage: from __future__ import annotations +import os import re import socket import sys @@ -26,6 +27,12 @@ import time import uuid PROMPT = "[root@vmbox" +# Both timeouts are env-overridable so a caller that already knows the guest +# may be unbootable can bound its own wait. Without that, a guest stuck in +# GRUB (no kernel) makes a "quick" console read block for 180+300s -- long +# enough to look like a hang rather than a failure. +PROMPT_TIMEOUT = float(os.environ.get("VMBOX_SERIAL_PROMPT_TIMEOUT", "180")) +RUN_TIMEOUT = float(os.environ.get("VMBOX_SERIAL_RUN_TIMEOUT", "300")) # Strip ANSI CSI sequences and the OSC 3008 shell-integration blocks that # systemd's login emits, both of which otherwise corrupt marker matching. _ANSI = re.compile(r"\x1b\[[0-9;?]*[a-zA-Z]") @@ -64,7 +71,7 @@ class Console: return True return False - def wait_prompt(self, timeout: float = 180) -> bool: + def wait_prompt(self, timeout: float = PROMPT_TIMEOUT) -> bool: # Nudge with a newline: if the shell is already up we get a fresh # prompt immediately instead of waiting for unrelated output. self.sock.sendall(b"\n") @@ -93,7 +100,7 @@ class Console: self.buf += chunk return clean(self.buf).count(needle) >= count - def run(self, cmd: str, timeout: float = 300) -> str: + def run(self, cmd: str, timeout: float = RUN_TIMEOUT) -> str: # Markers are plain alphanumerics: shell metacharacters like < and > # are echoed back by the tty and can be reordered or line-wrapped, # which makes them unreliable to match on. diff --git a/vmbox/lib/ssh.sh b/vmbox/lib/ssh.sh index b05089d..516fd11 100644 --- a/vmbox/lib/ssh.sh +++ b/vmbox/lib/ssh.sh @@ -70,14 +70,24 @@ vm_scp_to() { # Poll until the guest answers. ssh is its own port prober, so this needs no # nc/socat (neither is installed on this host). vm_wait_ssh() { - local name="$1" timeout="${2:-120}" waited=0 - while (( waited < timeout )); do + local name="$1" timeout="${2:-120}" deadline start now + # Deadline is WALL CLOCK, not a count of sleeps. Each failed probe also + # burns up to ConnectTimeout seconds inside ssh itself, so counting only + # the sleeps under-measures badly: a guest that never boots (no kernel, + # stuck in GRUB) made a nominal 150s wait run for well over 10 minutes, + # which reads as a hung tool rather than an unreachable sandbox. + printf -v start '%(%s)T' -1 + deadline=$(( start + timeout )) + while :; do + printf -v now '%(%s)T' -1 + (( now < deadline )) || return 1 if vm_is_running "$name" && vm_ssh_exec "$name" -o BatchMode=yes true 2>/dev/null; then return 0 fi # A qemu that has exited means the guest will never answer. - vm_is_running "$name" || { (( waited > 3 )) && return 1; } - sleep 2; waited=$(( waited + 2 )) + if ! vm_is_running "$name"; then + (( now - start > 3 )) && return 1 + fi + sleep 2 done - return 1 }