Fix idle auto-suspend silently disabled by guest stderr warnings - #2
Merged
Conversation
`backend_cleanup_removes_residual_qcow2_after_flip` rewrites the instance
config to `backend = "avf"` to simulate a migrate-to-avf, then asserts
`agv backend cleanup` sweeps the residual qcow2. On non-macOS the config
loader refuses to load an AVF-backed instance ("avf is macOS-only"), so
the test panics at the first `agv backend cleanup` invocation.
The flip-then-clean workflow only exists on macOS Apple Silicon (an AVF
VM can't run elsewhere), so gate the test with a runtime `cfg!` check —
it still compiles and shows up as a fast skip on other platforms rather
than failing.
Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
`auto_suspend_idle_vm_suspends` slept a flat 100s then checked once for `suspended`. That window is fragile on slow or loaded machines: savevm latency on the 10G qcow2, or a watcher tick stretched past 2× the 60s probe interval — which trips the host-wake heuristic and resets the idle timer — can push the suspend past the deadline, failing the test even though auto-suspend works. Poll `agv inspect` every 10s up to a 240s ceiling, passing as soon as the status flips to `suspended`. This removes the arbitrary-window flake without masking a real bug — a VM that genuinely never suspends still fails, just after a fair wait. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
The idle watcher is spawned detached with stdout and stderr routed to /dev/null, so every line it emits — info, warn, and the per-tick debug decisions — is discarded, making "watcher alive but VM never suspended" impossible to diagnose after the fact. Redirect both of the watcher's stdio streams to `<instance>/idle_watcher.log`, truncated per spawn so it reflects the current watcher session. Both streams are captured (not just stderr) because `tracing_subscriber::fmt()` writes to stdout by default, so a stderr-only redirect leaves the log empty. Best-effort: falls back to /dev/null if the file can't be opened. With `RUST_LOG=agv=debug` the log then captures each tick's probe/idle accounting. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
The idle watcher decides a VM is active if `who` reports any session. Its probe read `who` via `ssh::run_cmd`, which folds stderr into the returned string — and when stdout is empty it returns stderr outright. On hosts whose SSH forwards `LC_*` to a guest that can't set that locale (common: a desktop Linux host + a minimal Debian cloud image), the guest shell prints `bash: warning: setlocale: LC_ALL: cannot change locale` to stderr. `who` itself prints nothing, so the probe got back the warning, counted it as one line, and saw `who_count = 1` — active — on every tick. `idle_secs` never left zero and the VM never auto-suspended. macOS didn't hit it because its SSH doesn't forward the offending locale, so `who` came back genuinely empty. Add `ssh::run_cmd_stdout`, which returns only stdout on success (stderr is used solely for the error message), and switch the `who` and `/proc/loadavg` probes to it — both are parsed, so stderr must stay out. `run_cmd` keeps its combined-output behaviour for display callers. Also log every active tick, not just when `idle_secs > 0`. The old gate meant a VM active from the very first probe logged nothing at all, which is precisely how this stayed invisible. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Two integration tests failed on Linux (
cargo test -- --include-ignored). Fixing them surfaced a real production bug in auto-suspend.The headline bug — auto-suspend never fired on Linux
The idle watcher marks a VM active if
whoreports any session. Its probe readwhoviassh::run_cmd, which folds stderr into the returned string (and returns stderr outright when stdout is empty).On hosts whose SSH forwards
LC_*to a guest that can't set that locale — a desktop Linux host + a minimal Debian cloud image is the common case — the guest shell printsbash: warning: setlocale: LC_ALL: cannot change localeto stderr.whoitself prints nothing, so the probe got back the warning, counted it as one line (who_count = 1), and saw the VM as active on every tick.idle_secsnever left zero and the VM never auto-suspended. macOS never hit it because its SSH doesn't forward the offending locale, sowhocame back genuinely empty.Fix: add
ssh::run_cmd_stdout(returns only stdout on success; stderr is used solely for the error message) and switch thewhoand/proc/loadavgprobes to it — both are parsed, so stderr must stay out.run_cmdkeeps its combined-output behaviour for display callers.Verified on the machine that reproduced it — the watcher now logs
tick idle ... who=0and suspends on the first threshold crossing.Commits
backend_cleanup_removes_residual_qcow2_after_fliprewrites the config tobackend = "avf", which the config loader refuses off macOS. The flip-then-clean workflow is macOS-only; gated with a runtimecfg!so it shows as a fast skip elsewhere./dev/null, making "alive but never suspended" undiagnosable. Now redirects both streams to<instance>/idle_watcher.log(truncated per spawn). This is what made the bug findable.idle_secs == 0, which is exactly how this stayed invisible).Verification
cargo clippy --all-targetsclean; 374 unit + 81 CLI + integration tests pass.idle_watcher.logshowswho=0→tick idle→suspending→status: suspended.🤖 Generated with Claude Code