mirror of
https://github.com/kuhyx/utils.git
synced 2026-11-10 20:07:18 +01:00
vmbox: fix the settle gate breaking shutdown verdicts on the serial transport
The previous commit skipped the poweroff settle when `ssh_rc != 255`, on the
reasoning that a successful poweroff kills the ssh connection and ssh reports
255. That holds for the ssh transport and for nothing else. `_run_transport`
falls back to the serial console whenever ssh does not answer -- and the
README calls serial "the transport of record for shutdown tests" -- where the
exit code comes from serial_exec.py and is 0 even while the machine is already
on its way down.
Result, reproduced: `VMBOX_TRANSPORT=serial vm run <vm> 'sudo systemctl
poweroff'` reported "still running" for a guest that had cleanly powered off,
with SHUTDOWN{guest:true} in events.jsonl and "reboot: Power down" in the
serial log. The one thing this tool exists to get right, silently wrong. My
five verdict re-tests all went through ssh, so none of them caught it.
Grepping the serial log for shutdown markers instead does not work either:
they land a second or two after the command returns, so the check loses the
race. The fix waits a short grace period (default 3s) for any sign of a stop
before committing to the 30s wait. Warm runs go from 0s to 3s; that is the
honest price of a correct verdict.
Re-tested: clean poweroff, reboot and panic on BOTH transports, plus
tests/destructive_demo.sh 7/7.
Also, per "a fix that needs a human to remember a flag is not a fix": the X
session wait is now automatic on the branch that actually boots the guest --
the only one that can race tty1's autologin -- instead of requiring
VMBOX_X_WAIT. Warm runs never reach that branch. The env var remains an
override. README numbers corrected to the measured 14s/3s and ~100s.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VdyMBGCrGVGDWtJ9xe48f3
This commit is contained in:
parent
b9e2abad2d
commit
ab8227e23f
@ -6,7 +6,7 @@ host**. Break it as thoroughly as you like; reset takes under a second.
|
||||
|
||||
```bash
|
||||
./install.sh # installs deps (libisoburn), links `vm` onto PATH
|
||||
vm build # builds the golden image, once (~90s)
|
||||
vm build # builds the golden image, once (~100s)
|
||||
vm new demo # instant: a ~200 KB overlay on the sealed base
|
||||
vm run demo 'sudo systemctl poweroff'
|
||||
vm reset demo # back to pristine
|
||||
@ -140,14 +140,17 @@ Measured on this host, all with the cloud image already downloaded:
|
||||
|
||||
| | before | after |
|
||||
|---|---|---|
|
||||
| `vm run` (cold sandbox) | 41s | 12s |
|
||||
| `vm run` (warm sandbox) | 30s | 0s |
|
||||
| `vm run` (cold sandbox) | 41s | 14s |
|
||||
| `vm run` (warm sandbox) | 30s | 3s |
|
||||
|
||||
Neither number was the guest being slow. `_run_settle` waited up to 30s for a
|
||||
poweroff marker on EVERY run, including the majority that leave the guest
|
||||
running, and the ssh readiness poll used a 5s connect timeout against a
|
||||
forwarded port QEMU accepts before the guest is listening on it.
|
||||
|
||||
A cold `vm run` also waits for the guest's X session, because sshd now answers
|
||||
before tty1's autologin has started Xorg; `VMBOX_X_WAIT=<seconds>` overrides it.
|
||||
|
||||
The build reads packages from the host's own `/var/cache/pacman/pkg`, mounted
|
||||
read-only, rather than fetching 396 MiB over the internet. The guest keeps its
|
||||
own writable cache, so a package the host lacks is downloaded as usual. See
|
||||
|
||||
@ -116,8 +116,8 @@ boot, and I did not find the mechanism. NOT DONE -- see "still open".
|
||||
### The real win was elsewhere: `vm run` got 3-4x faster
|
||||
Chasing the build number turned up two flat taxes on EVERY sandbox command:
|
||||
|
||||
vm run, cold sandbox 41s -> 12s
|
||||
vm run, warm sandbox 30s -> 0s
|
||||
vm run, cold sandbox 41s -> 14s (includes waiting for the X session)
|
||||
vm run, warm sandbox 30s -> 3s
|
||||
|
||||
- `_run_settle` waited up to 30s for the kernel's "reboot: Power down" marker
|
||||
unconditionally, including on the majority of runs that leave the guest
|
||||
@ -127,8 +127,16 @@ Chasing the build number turned up two flat taxes on EVERY sandbox command:
|
||||
probe blocked for the full timeout instead of failing fast: a guest
|
||||
reachable at ~10s was reported up at ~45s.
|
||||
|
||||
All five shutdown verdicts re-tested afterwards (clean poweroff / dirty /
|
||||
reboot / panic / still-running) -- unchanged.
|
||||
All five shutdown verdicts re-tested on BOTH transports (ssh and serial), plus
|
||||
tests/destructive_demo.sh 7/7.
|
||||
|
||||
A first attempt at this gated the skip on the transport's exit code, which
|
||||
BROKE the serial path: ssh returns 255 for a poweroff but serial_exec returns
|
||||
0 while the machine is already going down, so a clean serial-driven poweroff
|
||||
was reported as "still running" -- vmbox's whole purpose, silently wrong.
|
||||
Grepping the serial log at that instant does not work either (the markers
|
||||
appear a second or two later). The shipped version waits a short grace period
|
||||
for any sign of a stop before committing to the long wait.
|
||||
|
||||
### Host cache safety (Q7's gate)
|
||||
Fingerprinted before and after FOUR full builds: 45427 files,
|
||||
|
||||
@ -52,6 +52,13 @@ run_in_vm() {
|
||||
else
|
||||
serial_n="$(launch_vm "$name")"
|
||||
vm_wait_ssh "$name" 150 || die "sandbox '$name' did not become reachable"
|
||||
# This run booted the guest, so it is the ONLY one that can race the
|
||||
# tty1 autologin that starts Xorg -- sshd answers first. Give the X
|
||||
# session a default window to appear here rather than requiring the
|
||||
# caller to remember a flag; a warm run never reaches this branch and
|
||||
# so never pays for it. Explicit VMBOX_X_WAIT still wins.
|
||||
: "${VMBOX_X_WAIT:=${VMBOX_X_WAIT_ON_BOOT:-20}}"
|
||||
export VMBOX_X_WAIT
|
||||
fi
|
||||
serial="$(vm_serial "$name" "$serial_n")"
|
||||
events="$(vm_events "$name")"
|
||||
@ -109,22 +116,34 @@ _run_exec_serial() {
|
||||
"$(_guest_env_setup) { $cmd ; } ; echo \$? > $RC_PATH"
|
||||
}
|
||||
|
||||
# Give a guest that is SHUTTING DOWN time to finish writing its serial log.
|
||||
# Give a guest that is shutting down time to finish writing its serial log.
|
||||
#
|
||||
# Only a guest that is actually stopping needs this. The first loop used to
|
||||
# run unconditionally, so every ordinary `vm run` -- the overwhelming majority,
|
||||
# which leave the guest running -- paid a flat 30s waiting for a poweroff
|
||||
# marker that was never going to appear. That single wait was most of the
|
||||
# wall-clock cost of running anything at all in a sandbox: 41s for a `true`,
|
||||
# of which 31s was this. Measured before/after: 41s -> 11s.
|
||||
# The hard part is deciding, cheaply, whether this run IS a shutdown. The
|
||||
# transport's exit code cannot answer it: ssh returns 255 for a poweroff but
|
||||
# serial_exec returns 0 while the machine is already on its way down, so
|
||||
# keying on that reported a clean serial-driven poweroff as "still running".
|
||||
# The serial log cannot answer it either at this instant -- the shutdown
|
||||
# markers appear a second or two later, so grepping for them here just loses
|
||||
# the race.
|
||||
#
|
||||
# The ssh transport reports a dropped connection as 255, which is what a
|
||||
# successful poweroff looks like from the host; a guest that is merely still
|
||||
# running gives a real exit code. So: settle only when the guest has already
|
||||
# stopped, or when the connection died in the way a shutdown would cause.
|
||||
# So: wait a SHORT fixed grace period for any sign of a stop, and only then
|
||||
# commit to the long wait. Runs that leave the guest up (the overwhelming
|
||||
# majority) pay the grace period and nothing more; the old code paid the full
|
||||
# 30s on every one of them, which was most of the wall-clock cost of running
|
||||
# anything in a sandbox at all -- 41s for a `true`, of which 31s was this.
|
||||
_run_settle() {
|
||||
local name="$1" serial="$2" ssh_rc="${3:-0}" waited=0
|
||||
if vm_is_running "$name" && (( ssh_rc != 255 )); then
|
||||
local name="$1" serial="$2" ssh_rc="${3:-0}" waited=0 grace="${VMBOX_SETTLE_GRACE:-3}"
|
||||
while (( grace > 0 )); do
|
||||
vm_is_running "$name" || break
|
||||
grep -qa 'System Power Off\|systemd-shutdown\|reboot: ' "$serial" 2>/dev/null && break
|
||||
(( ssh_rc == 255 )) && break
|
||||
sleep 1; grace=$(( grace - 1 ))
|
||||
done
|
||||
# Nothing suggests a stop: the guest is up, its log is quiet, and the
|
||||
# transport returned normally. Do not pay the 30s poweroff wait.
|
||||
if vm_is_running "$name" &&
|
||||
! grep -qa 'System Power Off\|systemd-shutdown\|reboot: ' "$serial" 2>/dev/null &&
|
||||
(( ssh_rc != 255 )); then
|
||||
return 0
|
||||
fi
|
||||
while vm_is_running "$name" && (( waited < 30 )); do
|
||||
|
||||
Loading…
Reference in New Issue
Block a user