QEMU/RouterOS: post-clean() relaunch leaves www nonresponsive on linux-arm64 (7.21.5)

[mobileskyfi]

Current signature

start-stop.test.ts → clean() resets disk to factory defaults reproducibly reaches a healthy post-reset RouterOS 7.21.5 guest on linux-arm64, but REST never becomes ready during the 480 s boot envelope.

The #101/#105/#107 forensics localize the failure:

• QEMU stays alive and the serial console answers quickly;
• DHCP has 10.0.2.15, uptime reaches 8+ minutes, and there are no firewall filter rules;
• ssh, API, API-SSL, and WinBox are served;
• HTTPS/443 cleanly refuses, proving the guest TCP stack can answer;
• only HTTP/80 black-holes;
• conntrack proves the forwarded SYNs reach RouterOS and receive no reply;
• all 96 REST probes time out and zero HTTP requests complete.

This is a guest-side, service-specific www failure after clean(), not a generic boot, DHCP, slirp, hostfwd, or firewall failure.

Corrections to earlier hypotheses

clean() does leave state.user naming the user erased by factory reset; that should be corrected, but a deleted user normally returns 401, which is enough for readiness. It is a trigger/confound, not a demonstrated cause of the permanent black hole.

The local www-abort-damage lab proved that abort→completed-request alternation can cause resets/wrong replies, but aborts without any completions were harmless. This CI report contains 96 aborts and no completion, so that lab mechanism does not explain this #79 wedge. It remains relevant to #69's reset/wrong-answer family.

Current hypothesis boundary

Every observed #79/#69 failure ran linux-arm64 under QEMU 8.2.2. In the same matrix, macos-arm64 (same guest arch + TCG, QEMU 11.0.2) passed all targets. QEMU/virtio feature negotiation is therefore a useful hypothesis, but host OS also changes; it is not yet causal evidence.

The decisive /ip/service snapshot field was blank because waitForFinalPrompt matched the console prompt redraw before the large reply arrived. That reader defect is #109.

Dependency-ordered experiment

1. Fix console: waitForFinalPrompt can match the prompt redraw, so large replies return empty — blanks the #79 guest snapshot #109 first so /ip/service and the full guest log cannot disappear from the next report.
2. Correct clean() credential state independently and retain an anchor test for factory-admin fallback.
3. Re-run the exact linux-arm64 · long-term · start-stop.test.ts case on QEMU 8.2.2 and a newer QEMU while holding RouterOS version, guest arch, accelerator, and test constant.
4. Compare www service configuration/state, conntrack, negotiated virtio-net features if observable, and the first readiness request.
5. Do not lower the outer timeout as the root-cause fix; CI: retune oversized boot envelopes from path-specific timing data without losing forensic headroom #106 owns envelope retuning after this operation is safely diagnosable.

Done-when

• The decisive guest snapshot fields are reliable (console: waitForFinalPrompt can match the prompt redraw, so large replies return empty — blanks the #79 guest snapshot #109).
• A controlled repro identifies why www alone fails after clean() and distinguishes RouterOS state, quickchr credential state, and QEMU/virtio behavior.
• The narrow fix has an integration regression and passes repeated targeted linux-arm64 · long-term runs before a full matrix run.
• Any durable RouterOS/QEMU fact, including negative results, is recorded in the governing lab/design/instruction doc.

Tracked in Wave 2 of #110; correlated with #69 but not merged without a reproduced shared mechanism. Historical evidence remains in the comments.

[mobileskyfi]

Local Intel Mac repro attempt — no repro

Local host:

• macOS/Darwin x86_64 (process.platform=darwin, process.arch=x64)
• Bun 1.3.13
• qemu-system-aarch64 11.0.0
• forced CHR arch: arm64
• quickchr detected accel=tcg, crossArch=true, timeoutFactor=15
• isolated state/cache: /tmp/quickchr-issue79-data

Probe path matched the failing test’s lifecycle but forced ARM64 on the Intel Mac:

1. QuickCHR.start({ channel, arch: "arm64", user: cleanuser })
2. verify cleanuser REST auth works
3. stop()
4. clean()
5. QuickCHR.start({ name })
6. verify cleanuser is gone (401) and factory admin: works (200)

Results:

target      version   first start ms   first boot ms   post-clean start ms   post-clean boot ms   old user   admin
long-term   7.21.4   48362            34014           35000                 34313                401        200
long-term   7.21.4   42165            34014           34757                 34103                401        200
long-term   7.21.4   42789            34346           39761                 39113                401        200
long-term   7.21.4   47675            39167           87634                 86916                401        200
stable      7.23.1   48361            34078           34795                 34126                401        200
testing     7.24rc1  49351            34075           34727                 34071                401        200

The exact local x86/HVF baseline also passed:

QUICKCHR_DATA_DIR=/tmp/quickchr-issue79-x86-data \
HOME=/tmp/quickchr-issue79-x86-home \
QUICKCHR_TEST_TARGET=long-term \
QUICKCHR_INTEGRATION=1 \
bun test test/integration/start-stop.test.ts --test-name-pattern 'clean\(\)'

Result: 1 pass, clean test completed in 84564.90ms.

No leftover machine files in either isolated data dir after success, and no QEMU processes were left running.

Interpretation

This argues against a generic clean() bug, a generic 7.21.4 ARM64 CHR clean/reboot bug, or preserved efi-vars.qcow2 being fundamentally broken. The local post-clean ARM64 boots were normally ~34-40s, with one slower ~87s run, still far below the CI 480s timeout.

It does not rule out the CI failure. The failing job was a different execution bucket:

• CI: Linux arm64 host, same-arch TCG, QEMU 8.2.2, after many prior full-suite boots in the same job.
• Local: Intel macOS host, cross-arch TCG, QEMU 11.0.0, focused clean repro only.

Next useful check

Run focused CI repeats on the actual failing bucket before changing code:

gh workflow run integration.yml --ref main \
  -f platforms=linux-arm64 \
  -f routeros-targets=long-term \
  -f test-filter=start-stop.test.ts \
  -f run-examples=false

If start-stop.test.ts alone passes repeatedly on linux-arm64/long-term, then the failure is probably full-suite interaction / cumulative runner state / load. Next narrowed matrix would be provisioning.test.ts,start-stop.test.ts, then a lab variant that preserves the post-clean machine dir and serial output on timeout.

[mobileskyfi]

Reproduced narrowly — scope in the title is wrong (not arm64, not TCG, not a timeout envelope)

Part of the ci:slow-platform-flake series (#76 #79 #80 #91). Evidence below comes from two runs:

• Run A — full matrix, all platforms × stable,long-term,testing, examples on: 30279318703
• Run B — narrow confirm, linux-x86,linux-arm64,windows-x86,macos-x86 × long-term,stable, test-filter=start-stop.test.ts,disk.test.ts, run-examples=false: 30289164062

Baseline: the last green full run was 29669706663 at 5f0fac2 (2026-07-19), where this test passed in 57.9 s on linux/x86_64 · long-term with the same RouterOS 7.21.5. Code delta from 5f0fac2 to a4af432 is #98/#99 (macOS accel policy), docs, and .gitignore; detectAccel() / isCrossArchEmulation() resolve identically on Linux and Windows across that delta. This is not a code regression.

Result grid

Leg	Accel	Run A	Run B (2 files only)
linux/x86_64 · long-term	kvm	fail	fail
linux/x86_64 · stable	kvm	pass	pass
linux/aarch64 · long-term	tcg	fail	pass
linux/aarch64 · stable	tcg	pass	pass
windows/x86_64 · long-term	tcg	pass (clean() OK)	pass (clean() OK, 80 s)
macos/x86_64 · long-term	tcg	(runner lost, #76)	pass
macos/arm64 · long-term	tcg	pass	not run

What this rules out

1. Not arm64-specific. It fails on linux/x86_64 under KVM with the 180 s budget.
2. Not TCG-specific. Same as above — KVM.
3. Not a timeout envelope. In Run A every other file on the linux-x86 long-term leg matched the 07-19 green run within a few percent (device-mode 162→157 s, exec 123→116 s, provisioning 369→366 s). Only this test moved: 57.9 s → 213 s (timeout). The runner was not slower.
4. Not cumulative suite load — on linux-x86. Run B ran only start-stop.test.ts + disk.test.ts and still failed. (The linux-aarch64 leg is load-sensitive: fails in the full suite, passes narrow. Two different sensitivities under one issue.)
5. Not the 7.21.5 image on its own. windows/x86_64 · long-term boots the same chr-7.21.5 through the same clean() and passes, logging two boot records (33868 ms, 33866 ms).

The sharpest metric

integration-clean-test logs exactly one boot record on the failing leg, identical across both independent runs:

{"run_id":"30279318703","name":"integration-clean-test","version":"7.21.5","arch":"x86","accel":"kvm","boot_ms":23757}
{"run_id":"30289164062","name":"integration-clean-test","version":"7.21.5","arch":"x86","accel":"kvm","boot_ms":23757}

That is the first boot (with the custom user) — healthy, 23.8 s. The post-clean() boot never registers. QEMU is alive for the full 180 s (it takes the SIGTERM during cleanup at _launchExisting, src/lib/quickchr.ts:1894), but REST never answers. Note waitForBoot() counts 401/403 as ready, so stale credentials after deleteInstanceCredentials() cannot explain it — the REST layer never responded at all.

Contrast the same machine name on the passing Windows leg, which logs two records ~33.9 s apart.

Local control (does not reproduce)

Intel Mac, x86 guest, RouterOS 7.21.5, current main:

QUICKCHR_INTEGRATION=1 QUICKCHR_TEST_TARGET=long-term \
  bun test test/integration/start-stop.test.ts -t "resets disk to factory"
# 1 pass — 104.27s

QUICKCHR_INTEGRATION=1 QUICKCHR_TEST_TARGET=long-term QUICKCHR_ACCEL=tcg \
  bun test test/integration/start-stop.test.ts -t "resets disk to factory"
# 1 pass — 69.45s

Forcing TCG (via the QUICKCHR_ACCEL override added in #99) does not reproduce it either. So this is Linux-host-specific and needs CI or a Linux host to chase.

Restated bucket

Narrowed to Linux host + long-term (7.21.5) + post-clean() relaunch. Since Windows boots the identical image fine, the suspect is the Linux-host side of the clean() → _launchExisting() path rather than the guest image. Untested candidates, in the order I'd probe them:

• hostfwd / port rebinding after stop() — the new QEMU stays alive, so if this is it, QEMU accepted the args but the forward is dead;
• stale unix-socket channel state under cleanupQemuSockets() (Windows uses TCP channels, which is exactly the axis that differs between pass and fail);
• ensureConfiguredDisks() re-run against a just-recopied raw disk.

Next step (per this issue's original plan, step 2)

A preserving probe is now the blocking need: on _launchExisting timeout, keep the machine dir and dump qemu.log in full, serial output, the QEMU command line, and ss -ltnp for the forwarded port. Today the error only embeds qemu.log.slice(-1200), which on every failure so far contains nothing but the cleanup SIGTERM line — that is the single biggest reason this is still unresolved.

Suggested retitle: CI: post-clean() relaunch never becomes REST-ready on Linux hosts (long-term / 7.21.5).

[mobileskyfi]

Instrumentation landed — branch ci/boot-failure-forensics, and one prior assumption corrected

Building the preserving probe this issue's investigation plan (step 2) called for. Commit dda5b47, narrow instrumented run dispatched: 30308608464 (linux-x86,windows-x86 × long-term, start-stop.test.ts,disk.test.ts).

What a BOOT_TIMEOUT now carries

src/lib/diagnostics.ts. On failure, <dataDir>/failures/boot-failure-<machine>-<ts>.json — collected before cleanup, and written outside the machine dir. That last part matters more than it sounds: this test ends in finally { cleanupMachine("integration-clean-test") } → remove(), so a report written next to qemu.log would be deleted before the artifact upload regardless of any preserve flag. The report embeds log text rather than pointing at it.

Contents: REST-probe tally, hostfwd TCP probe, monitor info status / info block / info chardev, QEMU liveness + argv, machine-dir listing, full qemu.log, full serial.log.

waitForBoot() now classifies every probe instead of returning a bare boolean — refused / reset / probe-timeout / unauthorized / wrong-body / http-error, with counts, first/last, and firstHttpAtMs. That is the field to read first on the next failure.

QUICKCHR_SERIAL_LOG=1 tees the guest console via QEMU's chardev logfile=. Verified on QEMU 11.0.3: a healthy 7.21.4 boot captured MikroTik 7.21.4 (long-term) + MikroTik Login: with no client attached to the socket — so this works for exactly the case we need, where nobody was listening when the boot died. Opt-in only: serial provisioning types the generated password in cleartext. Both knobs are on for every CI leg.

Correcting an assumption — refused is not the host-side signal

I wrote the first draft of the diagnosis guidance around "all refused → the hostfwd never bound", then reproduced a real BOOT_TIMEOUT locally to check it (QuickCHR.start({ mem: 32 }) — too little RAM for CHR, Intel Mac, HVF, 7.21.4). Result:

REST probe: 72 probes [probe-timeout=72] — forwarded port never produced an HTTP response; last: probe-timeout at 178s
QEMU process: alive (pid 74428)
hostfwd 127.0.0.1:9170: accepting
monitor info status: VM status: running
serial.log: (empty)

Under the default user/slirp network mode QEMU's hostfwd listen()s for the whole life of the process and accepts before it ever tries to reach the guest. A completely dead guest therefore reports accepting and classifies as probe-timeout, never refused. So:

• probe-timeout throughout + accepting → guest-side. Read serialLog next. This is the ordinary dead-boot shape.
• refused → QEMU itself is gone / never bound. Genuinely host-side.
• reset or firstHttpAtMs set but never ready → guest answered, RouterOS still settling (the REST: first post-credential-change request intermittently resets on linux-arm64 #69 shape).

Worth stating plainly because this issue's leading untested candidate is "hostfwd / port rebinding after stop()" — and had the failing run been read with my original rule, accepting would have been taken as evidence against that hypothesis when it is no evidence either way. The discriminating field is restProbe, not hostfwd.

What this does and does not resolve

Does not resolve the issue. It makes the next failure legible: serial.log will show whether RouterOS printed anything after the post-clean() relaunch, which is the fact that has been missing across two full runs. Local control still does not reproduce — -t "resets disk to factory" passes in 53 s on the Intel Mac against 7.21.5, consistent with the earlier non-repro.

Guidance is in ci.instructions.md ("Boot failure diagnosis checklist", step 0) and DESIGN.md ("Boot-Failure Forensics"), with the slirp caveat and the repro recorded in both.