fix(harness): drain sidecar stderr from spawn so a failed boot names its cause - #74
Merged
Merged
Conversation
…its cause `startSidecar` attached its stderr drain only after the ready-line arrived, so for the whole startup window stderr — where a dying engine says why — went unread and was then discarded. Both pipes are now drained from the moment of spawn and split at the ready-line into `bootLines`/`logLines`, and `SidecarExitedError`/`SidecarReadyTimeoutError` carry the stream-tagged transcript in their message. A boot that fails also reaps its child.
…on Windows The regression test pointed `MAXIMAL_E2E_BINARY` at an extensionless shebang script, which Windows cannot execute — `spawn` threw ENOENT before any of the diagnostic ran. `superviseSidecar` splits the supervise half of `startSidecar` out from the spawn half, so the test drives the real drain path with a child it launches portably, by naming the running interpreter. Also from the same platform gap: line drains strip a trailing CR, and the transcript barrier now waits on both pipes running dry as well as the child's close, rather than assuming an ordering between them.
stuffbucket
force-pushed
the
fix/harness-drain-stderr-from-spawn
branch
from
August 6, 2026 04:19
5e543bd to
fe55838
Compare
This was referenced Aug 6, 2026
stuffbucket
added a commit
that referenced
this pull request
Aug 11, 2026
* feat(dev): add a local Windows 11 ARM64 test VM on QEMU `ci.yml`'s `windows` job is the only Windows this repo has, and it is a batch loop: push, wait, read a log. Every Windows defect here was found that way -- #38, #55, #71, #74, and a `RegExp` built from an interpolated `os.tmpdir()` that is harmless on POSIX and a hard SyntaxError on Windows. This is the same platform with an edit-run-observe loop. `scripts/dev/win11/` is self-contained and project-agnostic: it reads no manifest and no version file, so the directory can be copied to another repo, or to no repo. Project-specific inputs are passed in -- `--payload` for what to stage in the guest, `--expect-file` for what `smoke` should assert, which is why this repo's smoke names `.bun-version` rather than the tool reading it. One base image, many thin instances. A Windows install is ~26 GB, so each instance is a qcow2 overlay backed by a sealed read-only base and holds only its own deltas -- measured at 192 MB after a boot. Reset is `rm overlay && qemu-img create`, measured at 1.3 s, and also discards firmware variables and TPM state, which live outside the disk image and would otherwise survive. Instances get their own sockets and VNC display, so several run concurrently without colliding; verified by writing a file in one and confirming its absence in the other. Device choices follow UTM's source, which is the best record of what works for this guest on this hardware: NVMe for the boot disk (in-box on Windows ARM64, so no driver injection and no WinPE drive-letter bet), usb-storage CDs, and an external swtpm. UTM's guest-tools ISO is the practical source of WHQL-signed ARM64 virtio drivers plus qemu-ga, which is the command channel -- `guest-exec` over virtio-serial, so no SSH and no listening port. `utmctl` is deliberately not used: it drives UTM.app over Apple Events and needs a logged-in Aqua session plus an interactive TCC grant. Two answer-file details are load-bearing and cost an install cycle each: `SkipMachineOOBE`/`SkipUserOOBE` silently suppress FirstLogonCommands on 25H2, and UAC must be off or the guest-tools installer raises a consent dialog that nothing can answer. The guest is ARM64 and CI is x64, so this cannot settle timing-sensitive questions and `bun:ffi` is unavailable there. The doc says so prominently. * fix(dev): make the Windows base-image build actually run unattended Three defects, all found by running `winvm build` end to end rather than assuming the path worked. Each one stalled the install at firmware with no error, which is the worst shape for a 20-minute operation. 1. Boot order. The empty NVMe disk carried `bootindex=0` during a build, so EDK2 tried it, failed, and dropped to a UEFI shell before USB enumeration had produced any filesystem -- the mapping table listed the NVMe block device and nothing else, so `startup.nsh` was never even found. The install media now takes index 0 and the disk index 1, but only while installing. 2. QMP socket race. The key-sender connected the instant QEMU was spawned, but QEMU creates its socket a moment later, so the connect failed with ENOENT and the boot prompt went unanswered. It now retries for 30s. 3. The boot selector had lost its only working loader. `cdboot_noprompt.efi` is valid only as an El Torito boot image; launched from the shell it returns `Invalid Parameter`. `BOOTAA64.EFI` does boot, but prints "Press any key to boot from CD or DVD" and returns EFI_TIMEOUT unanswered -- which is what the key-sender is for. It is restored as the final fallback. The shell path is not a fallback in the usual sense: on this firmware the install CD is never registered as a boot option at all, so `startup.nsh` is the ONLY route to the installer. The comment there says so, because the noprompt loop looks tidier and is the obvious thing to "simplify" toward. `sendkey` is an HMP command; issued as plain QMP it returns CommandNotFound. An earlier revision ignored that response, so hundreds of keystrokes were sent and none arrived, and the symptom was indistinguishable from a storage fault. qmp.ts now checks, and records why. * fix(dev): make the Windows base-image build reproducible from scratch Found by rebuilding from an empty state repeatedly. Each defect stalled the install with no error, which is the worst shape for a 25-minute operation. Setup ignores autounattend.xml on the hdiutil-built ISO9660 seed on 25H2. It came up interactively at "Select language settings" with the file present at the ISO root -- indistinguishable from supplying no answer file at all. The answer file now also rides the FAT removable volume, which Setup has always honoured. Microsoft-Windows-International-Core was missing from the oobeSystem pass. The same component under windowsPE only covers Setup itself, so Windows installed perfectly and then parked forever on "Is this the right country or region?". Provisioning moved from FirstLogonCommands to SetupComplete.cmd, which Windows runs as SYSTEM at the end of Setup before any logon. FirstLogonCommands needs a user session, runs unelevated (so the guest-tools installer raises a UAC dialog nothing can answer -- and that dialog focuses No, so blind Enter denies it), and on 25H2 is silently suppressed by the deprecated Skip*OOBE settings. provision.ps1 located the payload relative to "the volume containing provision.ps1", but copies of that script exist on the seed, on the result volume, and in C:\Windows\Setup\Scripts -- so it matched the wrong one and staged nothing while reporting success. It now finds the payload directory, which only ever exists on the seed. The boot-prompt key-sender now stops as soon as the installer is writing. Holding Enter down longer put keystrokes into Setup's GUI, where Enter lands on Cancel and opens "Are you sure you want to quit?" -- wedging a build at 35%. The prompt only needs answering on the first boot; later reboots find Windows Boot Manager on the ESP and never reach it. `smoke` reported the guest as AMD64 on an ARM64 machine. qemu-ga is the x86-64 build, so every process it spawns inherits an emulated x64 environment and PROCESSOR_ARCHITECTURE lies. Architecture now comes from Win32_Processor, and the emulated environment is reported alongside it because anything run through `winvm exec` inherits it. Verified from an empty state: build completes unattended, base seals read-only at 13G, an instance boots to a live guest agent, smoke matches .bun-version, bun self-reports arm64, npm is reachable, and reset restores the base. * fix(dev): make the Windows VM build and boot deterministically Every failure this harness had looked identical from outside: a QEMU process alive, a valid pidfile, and a monitor answering "VM status: running". Each fix below is a cause found in an artifact, not a timing guess. The guest now boots to AUDIT MODE rather than OOBE (Microsoft-Windows-Deployment | Reseal | Mode = Audit). OOBE was not merely slow, it was undetectable: it runs a temporary account called defaultuser0, and throughout it qemu-ga answers guest-ping, guest-exec works, and Windows reports OOBEInProgress=0, SystemSetupInProgress=0 and a running explorer.exe while the OOBE screen is still displayed. There is no probe that returns "not yet". Snapshotting in that window livelocked the guest -- all vCPUs at 100%, no disk I/O, recoverable only by killing it -- and the post-OOBE reboot hung at the firmware splash indefinitely. Audit mode deletes the phase: every boot lands on a desktop logged in as the built-in Administrator in about 35 seconds. The oobeSystem pass now contains ONLY Reseal. The documentation says oobeSystem settings "do not appear in audit mode", which reads as "they are harmless". They are not. Left in place, UserAccounts and AutoLogon still created an account and signed IT in, so the audit logon that audit.exe had arranged to be re-called on (audit.exe /user) never happened, the auditUser pass never ran, provisioning never ran, and the guest sat on a finished desktop with no agent and nothing anywhere explaining why. The install media's boot prompt is answered on a handshake instead of by holding Enter down. startup.nsh prints winvm-keypress-needed immediately before launching the one image that waits for a key; the host waits for that line and sends five keystrokes. It used to press Enter every 400ms until the disk grew past 300MB -- roughly 250 keystrokes for a prompt that consumes one. Surplus keystrokes are not discarded: they queue and are handed to Windows Setup's GUI, where Enter activates Cancel and opens "Are you sure you want to quit?", freezing the install with no error at whatever percentage it reached. A running instance now attaches no USB storage at all, and the CD device lines follow Linaro's published reference for this guest (qemu-xhci, media=cdrom, no removable= flag). EDK2 hung enumerating USB with the console stopped dead on "UsbBootExecCmd: Success to Exec 0x0 Cmd (Result = 1)" and a core pegged; it did so on an instance carrying only one USB disk, so it is not about how many are attached. nec-usb-xhci is replaced by qemu-xhci, which QEMU's documentation recommends and which has no open "broken" bug against it. Live snapshots are available: winvm snapshot / rewind / snapshots. Three device changes were required, each announced by savevm refusing and naming the device: the NVMe boot disk is non-migratable (the disk now runs on virtio-blk, with a scratch virtio disk attached during the build so viostor installs boot-start); raw pflash firmware variables cannot hold a snapshot (now qcow2); and the writable raw result volume could not either (now attached only while building). Snapshot is deliberately explicit -- start does not take one, because snapshotting a guest that has not finished starting wedges it. Builds are verified rather than assumed. "QEMU exited" used to mean success, so a crash, a kill, or a launch that never happened all sealed whatever the disk contained into a read-only base image; a silent launch failure sealed an empty one in 15 seconds. The guest now states its own verdict and the host shuts it down through the guest agent, because Microsoft warns that terminating the machine from a Setup script "will put the system in a bad state". launch() confirms the guest started. QEMU reports a bad command line or an unreachable socket on stderr and then exits 0, which made a launch that never happened indistinguishable from a slow boot. Also: builds refuse to run over a previous build's live guest, reap it on Ctrl-C and on timeout, and start from a clean scratch directory; serial.log rotates rather than being erased by the retry that needs it; and provisioning tolerates the guest agent dropping, which it does when it installs vioserial underneath itself. Measured, repeatedly: 3/3 builds clean at ~8 min; boots at 31/31/30/33/34.5s; rewind at 10.4/10.2/10.3s with the post-snapshot change discarded every time. winvm diagnose is added in this commit but still misreports some cases; it is corrected next. * fix(dev): correct winvm diagnose and hold it to recorded traces Two defects in the checks, both of which would have taught people to ignore the tool. It reported "provisioning left no transcript" against perfectly healthy instances. Provisioning runs once, in the scratch instance a build creates; ordinary instances inherit the result in the base image and no longer attach the result volume at all, so there is nothing to find. Scoped to build scratch instances. It called a running build hung. "Firmware stopped at USB enumeration" and "the boot prompt went unanswered" are claims about time, and both descriptions also fit a healthy guest ten seconds into an install. Confirmed the hard way: a successful build's console sits at exactly the same 4180 bytes, ending on the same UsbBootExecCmd line, as the two genuine hangs -- a live guest passes through that state and continues to 4883. Those checks now require progress to have actually stopped: a guest that is not running qualifies by definition, a running one has to have gone quiet on both its console and its disk. Adds the check that would have found the worst bug here in seconds instead of hours: an answer file requesting audit mode while leaving AutoLogon or UserAccounts in the oobeSystem pass. Windows honours both halves, so audit.exe enables the built-in Administrator and arranges to be re-called on the audit logon, and AutoLogon then signs in the answer file's account instead. The audit logon never happens, the auditUser pass never runs, provisioning never runs, and the guest reaches a working desktop with no agent and nothing anywhere saying why. It took reading audit.exe's own log inside the guest disk to find; it is a static check on a file. The checks are now held to recorded artifacts in scripts/dev/win11/tests/traces.zip, run by `bun run test:winvm`. Ten traces, each a complete state directory: serial logs, QEMU's stderr, image and instance metadata. Most are captured from real runs; one is reconstructed and says so. Half are of guests that were FINE, because several signatures here are states a healthy guest passes straight through and a check that cannot tell the difference is worse than no check. The archive is a zip, not a folder, and that is deliberate. These are frozen pictures of BROKEN configurations, and loose in the tree they sit next to the working code as a trap for anyone -- or anything -- reading it to learn how this is supposed to work. Zipped they stay retrievable while diagnosing and invisible otherwise. It also carries index.md and the long-form notes, which move out of the tree for the same reason. Standard zip, no macOS extended attributes, so it opens on Windows and Linux too. The test logic is deliberately thin: every expectation lives with its trace in that trace's expected.json, so this never grows a second copy of the knowledge in diagnose.ts. Adding a failure mode means adding a directory to the archive. Also drops snapshot.hasLive, dead since start stopped taking an automatic snapshot, and routes `winvm snapshots` through the same row parser whether the guest is up or down so its output does not change shape. * fix(dev): locate QEMU's firmware instead of assuming a Homebrew prefix The binaries were already found through PATH, and then their data files were read from a hard-coded `/opt/homebrew/share/qemu`. That is the one place the tool assumed where QEMU lives, and it is wrong on an Intel Mac (`/usr/local`), under MacPorts or Nix, or against a QEMU built from source — cases where `qemu-system-aarch64` itself resolves perfectly well and only the firmware lookup fails. It was also wrong here, and silently. `doctor` now reports /opt/homebrew/Cellar/qemu-spice/11.0.3/share/qemu/edk2-aarch64-code.fd because this machine runs qemu-spice; the old path only worked by symlink. `qemu-system-aarch64 -L help` prints the directories QEMU searches, which is the authoritative answer and costs one process. Falling back to the binary's own location covers a QEMU too old to support it, and WINVM_QEMU_DATA overrides both. Debian's and Linaro's names for the same images are checked alongside QEMU's, which is free and harmless when absent. When nothing is found the error names what was looked for and where, instead of reaching QEMU as the string "null" and returning `Could not open 'null'`. Verified: doctor reports the discovered path; an explicit override is honoured; a bad override produces an actionable message; and the guest boots (33s), smokes, snapshots and rewinds on the firmware found this way. * feat(dev): vendor the UEFI firmware, pin the guest tools, and manage disk Three gaps, all of them friction rather than defects. VENDOR THE FIRMWARE. `firmware/` now carries the EDK2 AArch64 images, so the harness no longer depends on a system QEMU having laid its data files out any particular way. They are BSD-2-Clause-Patent, which permits binary redistribution with the notice reproduced; `THIRD-PARTY-LICENSE.md` lives beside them rather than at the repository root, because this tool is meant to be copied out on its own and its obligations should travel with it. Stored gzipped: the images are ~99% zero padding, so 128 MiB becomes 1.6 MB, and they are expanded into the state directory on first use. Verified byte-identical to QEMU's own copies, and a guest boots on them (34s, smoke, snapshot, rewind). WINVM_QEMU_DATA still overrides, and discovery via `-L help` remains the fallback. PIN THE GUEST TOOLS RATHER THAN VENDOR THEM. The UTM ISO is ~121 MB, does not compress (98 MB gzipped — its payload is already compressed), and its installer bundles qemu-ga under GPL-2.0. Shipping it would oblige this project to keep corresponding source available for as long as it did, which is a standing duty for a developer test fixture. It is downloaded and verified against TOOLS_SHA256 instead. The URL says "latest", so upstream will eventually publish a new build and the digest will stop matching: the error names both digests and says to review and update the pin, because the pin's job is to DETECT drift, not to pretend it cannot happen. MANAGE IMAGES AND DISK. Instances had a full lifecycle and images had none — bases are sealed 444, so removing one meant `rm -rf` by hand, which is what building this branch actually required four times. winvm rmi <image> undoes the seal and removes it; refuses while an instance still names it as its backing file, since deleting it leaves an overlay that cannot be opened winvm prune drops leftover build scratch instances; --media also clears the cached tools ISO and seed, both of which are re-fetched or rebuilt winvm ls now accounts for media and prints a total `winvm setup` installs missing prerequisites and fetches the pinned media, and is deliberately separate from `doctor`, which stays a pure check — as this repository's own preflight puts it, "A check that silently mutates the environment is its own defect". Fixes a bug the new listing exposed: `du()` took the first line of `du -h`, which for a directory is a subdirectory rather than the total, so a state directory holding a 14 GB image reported 128 MB. It only ever measured single files before. * feat(dev): find the Windows ISO instead of demanding it every time `build` accepted `--iso` and otherwise failed. The path was already remembered after the first run — it is symlinked into the state directory, never copied and never committed — but there was no way to declare it, nothing looked for it, and nothing asked. It now resolves in order: `--iso`, `WINVM_ISO`, whatever a previous build recorded, then `~/Downloads`, `~/Desktop` and `~/vm` for a file whose name says arm64, and only then a prompt. The prompt is gated on a TTY: a scripted build should fail saying what it needed, not block forever on input nobody can give. Several candidates are listed rather than guessed between. The ISO stays the user's file wherever they keep it. At ~8 GB it is symlinked, so configuring this never puts a path into the repository — `WINVM_ISO` in a shell profile, or answer once and forget. Also checks the media before starting: Windows ARM64 install media carries \efi\boot\bootaa64.efi and an x64 ISO does not, so pointing at the wrong download now fails in about a second instead of twelve minutes into an install. A mount that fails proves nothing and passes with a warning. Directory listing during discovery cannot throw. `~/Downloads` and `~/Desktop` are TCC-protected on macOS: scanning them from a terminal without Full Disk Access raises EPERM rather than returning nothing, which aborted the search with a stack trace — in exactly the folder people keep the ISO in, on a first run. Found by running it. * fix(dev): stop searching TCC-protected folders for the Windows ISO ISO discovery looked in ~/Downloads and ~/Desktop, which are TCC-protected on macOS. Merely attempting to read them raises a consent dialog against whichever terminal is running the build — a background build asking for permission to your Downloads folder is not acceptable behaviour from a dev tool, and catching the EPERM afterwards does not prevent the prompt, only the crash. It now searches ~/vm, ~/isos and the state directory, none of which are protected. Anywhere else is named with --iso or WINVM_ISO, which was always the supported way to keep the ISO somewhere of your own choosing. The non-throwing directory listing stays: a missing root, a dangling symlink or an odd permission bit should skip that folder rather than abort someone's first run with a stack trace. * fix(dev): resolve the CodeQL findings on the winvm harness Four alerts, all real, all in code this branch added. Dead code in `build`. Rewriting the completion path left the previous hour-timeout tail sitting after a `return`, so several lines including a `reap()` were unreachable. Harmless only by luck — `guestFailed` already reaps before it reports — but it read as though the timeout path did its own cleanup, which is exactly the confusion that lets a guest be left running. Two time-of-check/time-of-use races. `existsSync` followed by `readFileSync` or `statSync` is a window, and these particular files are written by a QEMU process running concurrently: the firmware console, QEMU's stderr, and the expanded firmware images. Attempting the operation and handling failure has no window and is shorter. Incomplete comment stripping in the answer-file check. Removing `<!-- ... -->` in a single pass can splice the surrounding text into a fresh `<!--`, leaving a comment behind that the check then reads as live configuration. That matters here specifically: the check exists to match ELEMENTS rather than mentions, and this answer file discusses AutoLogon and UserAccounts by name at length in its comments, so a surviving comment produces a false report of the exact conflict it is looking for. Demonstrated: input <!<!-- x -->-- <AutoLogon> --> single pass <!-- <AutoLogon> --> (check would fire) repeated (empty) (correct) Stripping now repeats until nothing changes, which terminates because every pass strictly shortens the string.
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.
A sidecar that dies during boot now says why.
SidecarExitedErrorand the ready-line timeout carry a stream-tagged transcript of everything the child wrote — stderr included — so a red harness leg is diagnosable from the log alone instead of only from a re-run. Previously the log heldSidecar stdout closed before it emitted a ready-lineand nothing else, becausestartSidecarattached its stderr drain only after the ready-line arrived and discarded the startup window unread.Both pipes are now drained from the moment of spawn.
bootLines/logLinesstill split pre- and post-ready, now covering both pipes; the sink flips synchronously on the ready-line, line drains strip a trailing CR, and a failed boot reaps its child rather than leaking an engine holding a port.superviseSidecarsplits the supervise half ofstartSidecarfrom the spawn half so the regression test drives the real drain path with a child it launches portably.tests/sidecar-harness.test.tspins the diagnostic on both platforms: a child that writes a sentinel to stderr and exits before ready must produce an error containing it.Measured, not assumed — the undrained pipe was not also a hang here. Under the Bun parent every harness runs as, 4 MB of unread pre-ready stderr passes without the child blocking once (a Node parent wedges between 128 KB and 160 KB), and the engine writes 95 bytes to stderr before ready. The blindness was the whole of it.