Skip to content

Add SarTest: headless, hardware-free test harness - #147

Open
eiz-claude wants to merge 14 commits into
eiz:masterfrom
eiz-claude:mack/test-harness
Open

eiz-claude wants to merge 14 commits into
eiz:masterfrom
eiz-claude:mack/test-harness

Conversation

@eiz-claude

@eiz-claude eiz-claude commented Sep 13, 2026

Copy link
Copy Markdown
Collaborator

Tooling for automated SAR testing on a machine with no audio hardware and nobody at the keyboard, plus the CI change the test machine needs. Built to check #145 and the start-up hang reported against many-endpoint setups; it has since run the full scenario matrix against master and #145 on a disposable Windows 11 VM.

Branch includes the one-line commit from #146; rebasing after that merges drops it.

What's in it

SarTestClock.dll, a minimal ASIO driver that ticks from a timer thread (480 frames at 48 kHz by default). SarAsio never starts SarClient without an inner driver, so without a software clock there are no SAR endpoints at all. It also times each callback into the host, which includes SarAsio's whole tick, so a blocking call inside the tick shows up as a number.

SarTest.exe:

  • install creates the SAR software device node, installs the driver package from a CI-built INF non-interactively, registers the clock, and writes default.json for an endpoint layout.
  • host loads SarAsio.dll through DllGetClassObject and loops each playback endpoint back to its recording twin, channel for channel.
  • wasapi streams a self-describing signal (channel id plus sequence number per sample) through every endpoint and verifies it on the capture side. Runs of undecodable frames are classified by what borders them: next to silence they are the engine fading a stream in or out, between valid frames they are corruption. Dropouts and sequence jumps are timed so gaps can be lined up across endpoints. Invalidated streams are reopened the way a real client would, and counted.
  • run does both, repeating the create/stream/tear-down cycle.
  • race starts and stops the host back to back while threads keep opening, starting, holding and closing streams on its endpoints, which is what applications with a SAR endpoint as their default device do while a DAW starts. Every WASAPI and ASIO call runs under a watchdog.

tools/test/Invoke-SarTest.ps1 runs the scenarios on a prepared machine (-Scenarios matrix,race,kill): 1, 4, 8 and 16 endpoint pairs with three start/stop iterations each, the race on the largest layout, and the ASIO host killed while streams are open followed by a recovery check. One JSON and log per scenario plus summary.json.

CI: both projects build in the usermode job and ship with tools/test in sar-asio-<platform>. The driver job also publishes sar-driver-<platform>-testsigned, a copy of the package signed with a throwaway certificate generated for that build, with the certificate as testsign.cer, so a test machine with test signing enabled can install the CI build with no manual step. The unsigned package is unchanged.

tools/test/README.md covers the design, commands, pass criteria and how to prepare a test machine.

What running it found

Setup: Windows 11 25H2 guest, test signing on, Driver Verifier standard flags (deadlock detection, IRQL checking, special pool, I/O verification) on SynchronousAudioRouter.sys, kernel dumps on, restored to a clean checkpoint before every run.

  • It found a BSOD on master. The start-up race bugchecked the master driver: 0x3B in SarKsPinRtGetBufferCore, where master dereferences the endpoint before its NULL check and the compiler drops the check. Fix double IRP completion, filter factory error handling, and other bugs from patch review #145 fixes it and ran the same suite without a crash; the dump analysis is in the Fix double IRP completion, filter factory error handling, and other bugs from patch review #145 comment. It is a separate bug from the reported start-up freeze, which an immediate crash does not explain.
  • SarAsio's format-change broadcast invalidates streams. Every SAR endpoint activation makes SarAsio send KSEVENT_PINCAPS_FORMATCHANGE. Its comment says brand-new endpoints are skipped, but the code doesn't skip them. So any stream open while the host starts is invalidated, repeatedly for seconds at 16 endpoint pairs, and Initialize sometimes fails with AUDCLNT_E_UNSUPPORTED_FORMAT because the mix format changed underneath it. The harness reopens streams the way a real client would and counts all of it.
  • Stream setup stalls after repeated host restarts, on master too. After the race's 30 host restarts, killing the host and starting a new one leaves IAudioClient::Activate on SAR endpoints blocked for 4 s to 36 s, with many streams released at the same instant; stopping the host during the race also occasionally takes 6 to 7 s while a concurrent Initialize blocks for as long. A master build with only Fix double IRP completion, filter factory error handling, and other bugs from patch review #145's NULL-check fix does the same, so it predates Fix double IRP completion, filter factory error handling, and other bugs from patch review #145. A plain kill and restart doesn't trigger it. This is the closest match to the reported start-up freeze so far; the harness names the blocked call but not yet what it waits on inside the audio stack.
  • Dropouts line up across endpoints. Gaps of 8 to 40 ms hit many endpoints at the same instant, which points at a shared stall. SarAsio's own tick stayed at or under about 20 ms, so the stall isn't only in its callback.
  • Nothing else tripped. No hang, and no Driver Verifier report other than the crash above, on either build in any scenario, including the host killed mid-stream.

Final runs, each from a clean checkpoint:

Scenario master master + #145's NULL check only #145
Matrix, 1 to 16 endpoint pairs, 3 start/stop cycles each passed not run passed
Start-up race, 30 host restarts bugcheck, 2 of 2 runs passed passed, 2 of 2 runs
Host killed with streams open passed passed passed
Recovery after the kill, run on its own passed not run passed
Recovery after the kill, following the race not reached (crashed in the race) fails: setup stalls up to 36 s fails: setup stalls up to 22–38 s

Not covered yet

Exclusive-mode WASAPI, application routing (the registry filter), and driver installation from the x86 binary. Dropout and invalidation counts vary between runs on a VM, so they are reported for comparison with a baseline rather than gated on.

🤖 Generated with Claude Code

https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp

eiz and others added 14 commits September 13, 2026 04:06
Both are plain MSVC projects with no WiX dependency, so they cost nothing
extra on the runner and a compile break in them no longer goes unnoticed.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp
SarTestClock.dll is a minimal ASIO driver that ticks from a timer thread, so
SarAsio can wrap it like a real interface on a machine with no audio device.
SarTest.exe drives SarAsio through it as a headless ASIO host (looping every
playback endpoint back to its recording twin), streams a self-describing test
signal through every endpoint with shared-mode WASAPI clients, and verifies
the loopback sample for sample. `run` repeats the create/stream/tear-down
cycle, and a watchdog logs any driver call that fails to return, which is the
signature of the kernel hang reported against many-endpoint setups.

It also installs the driver package from a CI-built INF, creates the SAR
device node, and writes the SarAsio configuration for a given endpoint
layout, so a test VM needs nothing but the CI artifacts.

tools/test/Invoke-SarTest.ps1 runs the scenario matrix (1/4/8/16 endpoint
pairs, repeated start/stop, host killed mid-stream, recovery) and collects
JSON results, logs and SarAsio logs. README.md documents the design, the
commands and how to prepare a test VM.

Both new projects build in the usermode CI job and ship in its artifact.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp
A terminating error inside Invoke-SarTest.ps1 escaped the caller's output
redirection, leaving the log without the reason for the failure. Trap it,
print it with its location, and exit non-zero. Import the certificate
with certutil, which exists everywhere, instead of the PKI module.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp
Start-Process -PassThru returns a Process whose ExitCode is null after
WaitForExit unless its Handle was accessed first, so every scenario was
reported as failed even when SarTest exited 0.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp
The first run on a real machine showed two things the verifier handled
badly. SarAsio broadcasts a format change whenever one of its endpoints
becomes active, which invalidated streams opened in the first ~100 ms; wait
for the endpoints to settle, retry setup on invalidation, and count the
retries. Capture streams started before their render twin saw a few dozen
undecodable frames at the very start of the signal, consistent with the
engine ramping a new stream's volume in; count frames before the first
valid one as transition frames, fail only on corruption after lock-in or a
transition longer than 100 ms, and record the first bad frames with their
raw values and expected channel ids.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp
A second copy of the driver package, signed with a throwaway self-signed
certificate generated on the runner, plus the certificate itself, so a test
machine with test signing enabled can install the CI build without any
manual signing step. Uploaded as sar-driver-<platform>-testsigned next to
the unsigned package, which is unchanged.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp
Runs on the VM showed SarAsio's format-change broadcast on endpoint
re-activation invalidating streams ~2.6 s after the host starts, past the
settle delay. Reopen an invalidated stream, bounded by --max-reopens, the
way a real client would, and count invalidations and reopens instead of
failing. After a reopen the signal must lock in again, so its start-up ramp
counts as transition rather than corruption.

The 8- and 16-endpoint runs also showed captures going silent for up to
0.8 s mid-stream. Record each dropout and sequence jump with its time from
the start of the run, so gaps can be lined up across endpoints.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp
The reported hang happened while Ardour started with many endpoints, when
applications that use SAR endpoints as their default devices race the
driver as it creates them. The run scenario deliberately opens streams only
after the endpoints have settled, so it never exercises that window.

`SarTest race` starts and stops the ASIO host repeatedly with short gaps
while several threads keep finding the layout's endpoints and opening,
starting, holding and closing shared-mode streams on them. Every WASAPI call
runs under a watchdog, so a call stuck in the driver is reported as a hang
with the call's name, alongside the existing watchdog on the host's calls.
Invoke-SarTest.ps1 runs it on the largest layout and gains -Scenarios to
select any of matrix, race and kill.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp
…tick

The v2 runs showed the engine fading a stream out when it is invalidated,
which the verifier counted as corruption because the capture side had
already locked in. Classify each run of undecodable frames by what borders
it: next to silence or the start of the stream it is a fade (ramp); between
valid frames, or longer than any ramp, it is corruption.

Setup calls also failed with AUDCLNT_E_UNSUPPORTED_FORMAT when the mix
format went stale during SarAsio's format-change broadcasts; retry them like
invalidations. With 16 endpoint pairs a stream saw four or more broadcasts,
so allow 20 reopens, and gate on correctness rather than VM-dependent
dropout rates (valid ratio 0.5 by default); the rates stay in the results
for comparison with a baseline.

Dropouts lined up across endpoints to the millisecond, so SarTestClock now
times each callback into the host, which includes SarAsio's whole tick, and
reports the slowest one and how many overran half a period.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp
The first bugcheck the VM rig caught left a kernel dump that could not be
symbolized, because no CI artifact carries the driver's PDB. Add
SynchronousAudioRouter.pdb to the test-signed driver package and the
SarAsio, SarTest and SarTestClock PDBs to the user-mode package.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp
A reopened render stream can fade in with no silence before it, which the
position-based rule counted as corruption on the 8-endpoint run. The raw
samples were the right channels and sequence scaled by ~0.78. Treat a frame
as a ramp when one gain explains every channel (two channels give the gain
from their difference and the rest must agree), keep the silence rule only
for gains too small to survive rounding, and keep the length bound.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp
After the ASIO host was killed with streams open, stream setup on the next
host's endpoints stalled for up to ~35 s and every stuck stream released at
the same instant, but the logs could only show when setup finished, not
which call was blocked. Time each setup call, Start and Stop; record the
slowest per stream, and log any call over a second with the time it
returned.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp
The previous commit only added the fields: its edit script stopped when an
anchor also matched the race openers' Start call. This adds the timing
itself around each stream's setup calls, Start and Stop, reports the slowest
call per stream, and documents it.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants