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

[mobileskyfi]

Status 2026-07-31 — the symptom is fixed; the mechanism is not explained. B9 of #110 bisected this cleanly to #111 (the console-reader sentinel framing). What remains, and all this issue now tracks, is why a host-side console-reader defect wedged a guest service. Demoted to P3 research: nothing is failing, but an unexplained fix is a fix that can come back.

What was happening

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

The #101/#105/#107 forensics localized it precisely:

• QEMU stays alive and the serial console answers quickly;
• DHCP has 10.0.2.15, uptime reaches 8+ minutes, 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.

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

The bisect (B9 of #110)

Holding RouterOS 7.21.5 (pinned by version, not channel), arm64, TCG and the test constant, and varying only the system emulator, QEMU 8.2.2 → 11.0.2 moved the failing test by ~1 second (81.9/83.4/75.1 s vs 82.5 s). The QEMU/virtio hypothesis below is dead: the "every observed failure ran 8.2.2" correlation was confounded by code state, because every observed failure also ran pre-#111 code.

The baseline did not reproduce on current code, so B9 bisected code state instead:

ref	code state	clean() test
9ce1932	pre-#111, pre-#112	fail 543.0 s / fail 544.5 s
2808143	#111 in, #112 out	pass 79.9 s / pass 79.8 s
HEAD	both in	pass ×3

Old code 4/4 fail, new code 7/7 pass, on current runner images. Both 9ce1932 failures reproduce this issue byte-identically — 96 probes [probe-timeout=96], BOOT_TIMEOUT at 478 s. So it was deterministic all along, and #111 fixed it. #112 was right to disclaim it: 2808143 has #111 but not #112 and already passes.

Full result: #79 (comment)

The open question

Why does correcting a host-side console reader fix a guest-side www black hole?

Until that is answered, #111 is a fix by coincidence as far as this issue is concerned, and any future change to console reply framing could reintroduce this without anyone connecting the two.

Hypothesis A — the clean()/provisioning sequence silently mis-executed

Pre-#111, waitForFinalPrompt could end a read on a prompt redraw and hand back a truncated or empty payload for a large reply. The test provisions over the serial console before the clean(). If a command in that sequence was believed to have run — or its reply was parsed into a wrong branch — the guest could be left with www disabled, bound elsewhere, or otherwise not serving, while every other service is untouched.

This fits the evidence best. It is the only hypothesis on the table that explains why exactly one service failed while ssh/API/WinBox stayed up, HTTPS refused cleanly, and the guest was otherwise healthy for 8+ minutes.

Hypothesis B — serial chardev backpressure

Raised in the B9 comment: consoleExec sessions persist across calls (console.ts:290) and the serial chardev is a server socket, so a client that connects and stops draining blocks QEMU's chardev write and can stall the guest. That would explain a SYN-accepted-but-never-answered signature and the empty console reply forensic.

It does not fit the selective failure. A stalled guest does not keep serving ssh, API, API-SSL and WinBox, and does not cleanly RST on 443. Backpressure is a real hazard worth knowing about — it is reachable from any future code that attaches to serial and stops reading — but as an explanation for this wedge it is contradicted by the host-side port probes, which do not depend on the console at all.

The experiment that discriminates them

Cheap, and the repro is known-good: reproduce the wedge on 9ce1932 (4/4 today), then query the wedged guest over ssh, not serial — ssh is unaffected by the console-reader defect and was demonstrably being served throughout.

# on a wedged pre-#111 guest
/ip/service/print detail        # is www disabled / bound to a different address?
/log/print where topics~"web"
/system/resource/print

• www disabled, misbound, or absent → Hypothesis A, and the follow-up is which command in the provisioning/clean() sequence mis-executed under a truncated reply.
• www enabled, listening, on the right address, and still not answering → A is out; look harder at B or at a RouterOS www state bug after factory reset, and note that the console reader would then be affecting the guest through a path nobody has identified.

Everything else stays constant: same ref, same 7.21.5, arm64, TCG, same test.

Corrections to earlier hypotheses (kept so they are not re-derived)

• QEMU version was never the variable — measured, above.
• clean() leaving state.user naming the erased user was a real defect (fixed in fix(clean): drop the credential state factory reset erased (#79) #112) but not the cause; a deleted user returns 401, which is enough for readiness.
• The local www-abort-damage lab does not explain this. It proved abort→completed-request alternation can cause resets, but aborts without completions were harmless — and this report has 96 aborts and zero completions. That lab remains relevant to REST: first post-credential-change request intermittently resets on linux-arm64 #69's reset family, not here.
• Read the pre-fix(test): one REST client, and forensics for a reset after readiness (#69) #114 forensics with care. The guest snapshot instrument was blind before fix(test): one REST client, and forensics for a reset after readiness (#69) #114 (unbudgeted ~10.2 s serial login, then divided across credential candidates). The host-side port/conntrack observations above are unaffected — they never used the console — but any guest-derived field from a pre-fix(test): one REST client, and forensics for a reset after readiness (#69) #114 report is only as trustworthy as its size, and the decisive /ip/service field was blank for exactly that reason (console: waitForFinalPrompt can match the prompt redraw, so large replies return empty — blanks the #79 guest snapshot #109).

Done-when

• The mechanism connecting the console-reader defect to the www black hole is identified, or the discriminating experiment above returns a documented negative and this issue closes as "symptom fixed, mechanism not reproducible on current code".
• The durable RouterOS/QEMU fact — including a negative — is recorded in the governing lab/design/instruction doc, not only in this issue.
• If Hypothesis B survives at all, serial-chardev backpressure is written down where the next person attaching to serial will see it (qemu.instructions.md), independent of whether it caused this.

No regression test is owed here: #111 shipped the anchor test that keeps the reader honest, and B9's bisect is the regression evidence for this symptom.

Tracked in Wave 2 of #110 (B9, done). Correlated with #69 but not merged — see #69's own mechanism boundary. 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.