From 221320bafbb6bb2f00727c93935884bc618a03b5 Mon Sep 17 00:00:00 2001 From: Mack Straight Date: Sun, 13 Sep 2026 04:01:43 -0400 Subject: [PATCH 01/14] ci: also build SarConfigure and SarCtl in the usermode job 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 Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp --- .github/workflows/build.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/build.yml b/.github/workflows/build.yml index 7a2cdbf..449f2ff 100644 --- a/.github/workflows/build.yml +++ b/.github/workflows/build.yml @@ -153,7 +153,7 @@ jobs: shell: pwsh run: | & msbuild SynchronousAudioRouter.sln ` - /t:SarAsio ` + '/t:SarAsio;SarConfigure;SarCtl' ` /p:Configuration=Release ` /p:Platform=${{ matrix.platform }} ` /m /verbosity:minimal /nologo From 932ff88923a4246c27e73b781b656d672636a43f Mon Sep 17 00:00:00 2001 From: Mack Straight Date: Sun, 13 Sep 2026 05:01:53 -0400 Subject: [PATCH 02/14] Add SarTest: a headless, hardware-free test harness for SAR 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 Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp --- .github/workflows/build.yml | 18 +- SarTest/SarTest.cpp | 415 ++++++++++++++ SarTest/SarTest.vcxproj | 112 ++++ SarTest/asiohost.cpp | 473 ++++++++++++++++ SarTest/asiohost.h | 116 ++++ SarTest/common.cpp | 350 ++++++++++++ SarTest/common.h | 127 +++++ SarTest/install.cpp | 278 +++++++++ SarTest/install.h | 49 ++ SarTest/wasapi.cpp | 913 ++++++++++++++++++++++++++++++ SarTest/wasapi.h | 90 +++ SarTestClock/SarTestClock.cpp | 604 ++++++++++++++++++++ SarTestClock/SarTestClock.def | 7 + SarTestClock/SarTestClock.vcxproj | 107 ++++ SarTestClock/clockstats.h | 49 ++ SynchronousAudioRouter.sln | 28 + tools/test/Invoke-SarTest.ps1 | 192 +++++++ tools/test/README.md | 118 ++++ 18 files changed, 4039 insertions(+), 7 deletions(-) create mode 100644 SarTest/SarTest.cpp create mode 100644 SarTest/SarTest.vcxproj create mode 100644 SarTest/asiohost.cpp create mode 100644 SarTest/asiohost.h create mode 100644 SarTest/common.cpp create mode 100644 SarTest/common.h create mode 100644 SarTest/install.cpp create mode 100644 SarTest/install.h create mode 100644 SarTest/wasapi.cpp create mode 100644 SarTest/wasapi.h create mode 100644 SarTestClock/SarTestClock.cpp create mode 100644 SarTestClock/SarTestClock.def create mode 100644 SarTestClock/SarTestClock.vcxproj create mode 100644 SarTestClock/clockstats.h create mode 100644 tools/test/Invoke-SarTest.ps1 create mode 100644 tools/test/README.md diff --git a/.github/workflows/build.yml b/.github/workflows/build.yml index 449f2ff..496d3d1 100644 --- a/.github/workflows/build.yml +++ b/.github/workflows/build.yml @@ -149,11 +149,11 @@ jobs: with: vs-version: "[17.0,18.0)" - - name: Build SarAsio + - name: Build user-mode projects shell: pwsh run: | & msbuild SynchronousAudioRouter.sln ` - '/t:SarAsio;SarConfigure;SarCtl' ` + '/t:SarAsio;SarConfigure;SarCtl;SarTest;SarTestClock' ` /p:Configuration=Release ` /p:Platform=${{ matrix.platform }} ` /m /verbosity:minimal /nologo @@ -165,11 +165,15 @@ jobs: $plat = "${{ matrix.platform }}" $stage = "artifacts/$plat" New-Item -ItemType Directory -Force -Path $stage | Out-Null - $dll = Get-ChildItem -Recurse -Filter 'SarAsio.dll' | - Where-Object { $_.FullName -match "\\Release\\" } | - Sort-Object LastWriteTime -Descending | Select-Object -First 1 - if (-not $dll) { throw "SarAsio.dll not found - did the build succeed?" } - Copy-Item $dll.FullName $stage -Force + foreach ($name in 'SarAsio.dll', 'SarConfigure.exe', 'SarTest.exe', 'SarTestClock.dll') { + $file = Get-ChildItem -Recurse -Filter $name | + Where-Object { $_.FullName -match "\\Release\\" } | + Sort-Object LastWriteTime -Descending | Select-Object -First 1 + if (-not $file) { throw "$name not found - did the build succeed?" } + Copy-Item $file.FullName $stage -Force + } + New-Item -ItemType Directory -Force -Path "$stage/test" | Out-Null + Copy-Item tools/test/* "$stage/test" -Force # Materialize the hash lines into a variable BEFORE opening the output # file, and skip the sums file itself - otherwise the same pipeline both # reads and writes SHA256SUMS.txt and Get-FileHash hits a file lock. diff --git a/SarTest/SarTest.cpp b/SarTest/SarTest.cpp new file mode 100644 index 0000000..31f845c --- /dev/null +++ b/SarTest/SarTest.cpp @@ -0,0 +1,415 @@ +// SynchronousAudioRouter +// Copyright (C) 2026 Mackenzie Straight +// +// This program is free software: you can redistribute it and/or modify +// it under the terms of the GNU General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// This program is distributed in the hope that it will be useful, +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU General Public License for more details. +// +// You should have received a copy of the GNU General Public License +// along with SynchronousAudioRouter. If not, see . + +// SarTest: a headless test harness for SynchronousAudioRouter. See +// tools/test/README.md for the workflow it is designed around. + +#include "common.h" +#include "install.h" +#include "asiohost.h" +#include "wasapi.h" +#include "clockstats.h" + +using namespace SarTest; + +namespace { + +int usage() +{ + printf( + "SarTest - SynchronousAudioRouter test harness\n" + "\n" + " SarTest install [--inf ] [--clock ] [--endpoints N] [--channels C]\n" + " Create the SAR device node, install the driver package from the INF,\n" + " register the software clock and write the SarAsio configuration.\n" + " SarTest uninstall [--clock ] [--remove-device]\n" + " SarTest config [--endpoints N] [--channels C] [--out ]\n" + " Write only the SarAsio configuration.\n" + " SarTest host [--iterations K] [--duration S] [--sarasio ]\n" + " Run the headless ASIO host: create SAR endpoints, tick, stop, repeat.\n" + " SarTest wasapi [--duration S] [--wait S] [--expect-invalidation]\n" + " Stream the test signal through the endpoints of a running host and\n" + " verify the loopback.\n" + " SarTest run [--iterations K] [--duration S]\n" + " host and wasapi in one process, with end-to-end verification.\n" + "\n" + "Layout options: --endpoints N (playback/recording pairs, default 2)\n" + " --channels C (per endpoint, default 2) --prefix \n" + "Other options: --results --phase-timeout S --no-sarasio-log\n" + " --keep-config (host/run: do not rewrite default.json)\n" + " --registered (use the COM-registered SarAsio instead of a path)\n" + " --wait S --wait-gone S --restart-delay MS --rate HZ\n" + " --min-valid RATIO --max-discontinuities N\n" + "\n" + "Exit codes: 0 pass, 1 setup or usage error, 2 test failure.\n"); + return 1; +} + +std::wstring sibling(const wchar_t *file) +{ + wchar_t path[MAX_PATH] = {}; + + GetModuleFileNameW(nullptr, path, MAX_PATH); + + std::wstring s = path; + auto slash = s.find_last_of(L"\\/"); + + if (slash == std::wstring::npos) { + return file; + } + + return s.substr(0, slash + 1) + file; +} + +AsioHostOptions hostOptions(const Args& args, const EndpointLayout& layout) +{ + AsioHostOptions options; + + options.layout = layout; + + if (!args.has(L"registered")) { + options.sarAsioPath = args.get(L"sarasio", sibling(L"SarAsio.dll").c_str()); + } + + options.sampleRate = args.getDouble(L"rate", 48000.0); + options.phaseTimeoutSeconds = args.getInt(L"phase-timeout", 30); + options.enableSarAsioLog = !args.has(L"no-sarasio-log"); + return options; +} + +WasapiOptions wasapiOptions(const Args& args, const EndpointLayout& layout) +{ + WasapiOptions options; + + options.layout = layout; + options.durationSeconds = args.getDouble(L"duration", 5.0); + options.expectInvalidation = args.has(L"expect-invalidation"); + options.minValidRatio = args.getDouble(L"min-valid", 0.9); + options.maxDiscontinuities = args.getInt(L"max-discontinuities", -1); + return options; +} + +// Writes default.json for the layout unless --keep-config, backing up an +// existing configuration the first time. +bool prepareConfig(const Args& args, const EndpointLayout& layout) +{ + if (args.has(L"keep-config")) { + return true; + } + + std::wstring path = configurationPath(); + std::wstring backup = path + L".sartest-backup"; + + if (GetFileAttributesW(path.c_str()) != INVALID_FILE_ATTRIBUTES && + GetFileAttributesW(backup.c_str()) == INVALID_FILE_ATTRIBUTES) { + if (CopyFileW(path.c_str(), backup.c_str(), TRUE)) { + logf("Backed up the existing configuration to %s", narrow(backup).c_str()); + } + } + + if (!writeDriverConfig(layout, SAR_TEST_CLOCK_CLSID_STR, + args.getInt(L"wavert-min-frames", 0), path)) { + return false; + } + + logf("Wrote configuration for %d endpoint pairs x %d channels to %s", + layout.pairs, layout.channels, narrow(path).c_str()); + return true; +} + +void writeResults(const Args& args, const std::string& json) +{ + std::wstring path = args.get(L"results", L"sartest-results.json"); + + if (writeTextFile(path, json + "\n")) { + logf("Results written to %s", narrow(path).c_str()); + } +} + +int cmdInstall(const Args& args) +{ + EndpointLayout layout = EndpointLayout::fromArgs(args); + std::wstring inf = args.get(L"inf"); + std::wstring clock = args.get(L"clock", sibling(L"SarTestClock.dll").c_str()); + + if (!inf.empty()) { + if (!deviceNodeExists() && !createDeviceNode()) { + return 1; + } + + bool reboot = false; + + if (!installDriverPackage(inf, &reboot)) { + return 1; + } + } else if (!deviceNodeExists()) { + logf("No SAR device node is present and no --inf was given"); + return 1; + } else { + logf("SAR device node present; leaving the installed driver alone (no --inf)"); + } + + if (!registerComServer(clock, false)) { + return 1; + } + + return prepareConfig(args, layout) ? 0 : 1; +} + +int cmdUninstall(const Args& args) +{ + std::wstring clock = args.get(L"clock", sibling(L"SarTestClock.dll").c_str()); + int rc = registerComServer(clock, true) ? 0 : 1; + + if (args.has(L"remove-device") && !removeDeviceNode()) { + rc = 1; + } + + return rc; +} + +int cmdConfig(const Args& args) +{ + EndpointLayout layout = EndpointLayout::fromArgs(args); + std::wstring out = args.get(L"out", configurationPath().c_str()); + + if (!writeDriverConfig(layout, SAR_TEST_CLOCK_CLSID_STR, + args.getInt(L"wavert-min-frames", 0), out)) { + return 1; + } + + logf("Wrote %s", narrow(out).c_str()); + return 0; +} + +int cmdHost(const Args& args) +{ + EndpointLayout layout = EndpointLayout::fromArgs(args); + int iterations = args.getInt(L"iterations", 1); + double duration = args.getDouble(L"duration", 5.0); + int restartDelay = args.getInt(L"restart-delay", 1000); + int waitGone = args.getInt(L"wait-gone", 30); + + if (!prepareConfig(args, layout)) { + return 1; + } + + AsioHost host(hostOptions(args, layout)); + std::vector iterationJson; + int rc = 0; + + if (!host.load() || !host.open()) { + rc = 1; + } + + for (int i = 0; rc == 0 && i < iterations; ++i) { + logf("--- host iteration %d of %d ---", i + 1, iterations); + + if (!host.start()) { + rc = 2; + break; + } + + Sleep((DWORD)(duration * 1000.0)); + + if (!host.stop()) { + rc = 2; + break; + } + + JsonObject iteration; + + iteration.setInt("iteration", i + 1) + .setDouble("startMs", host.stats().lastStartMs) + .setDouble("stopMs", host.stats().lastStopMs) + .setInt("ticks", host.stats().ticks); + iterationJson.push_back(iteration.str()); + + if (i + 1 < iterations) { + waitForEndpointsGone(layout, waitGone); + Sleep((DWORD)restartDelay); + } + } + + host.close(); + + JsonObject result; + + result.setString("command", "host") + .setBool("passed", rc == 0) + .setInt("exitCode", rc) + .setRaw("host", host.toJson()) + .setRaw("iterations", jsonArray(iterationJson)); + writeResults(args, result.str()); + return rc; +} + +int cmdWasapi(const Args& args) +{ + EndpointLayout layout = EndpointLayout::fromArgs(args); + WasapiOptions options = wasapiOptions(args, layout); + FoundEndpoints endpoints; + + if (!findEndpoints(layout, args.getInt(L"wait", 30), &endpoints)) { + JsonObject result; + + result.setString("command", "wasapi") + .setBool("passed", false) + .setInt("exitCode", 1) + .setString("failure", "endpoints not found"); + writeResults(args, result.str()); + return 1; + } + + WasapiResult result = runWasapi(options, endpoints); + JsonObject json; + int rc = result.passed ? 0 : 2; + + json.setString("command", "wasapi") + .setBool("passed", result.passed) + .setInt("exitCode", rc) + .setRaw("wasapi", result.toJson()); + writeResults(args, json.str()); + return rc; +} + +int cmdRun(const Args& args) +{ + EndpointLayout layout = EndpointLayout::fromArgs(args); + int iterations = args.getInt(L"iterations", 1); + int restartDelay = args.getInt(L"restart-delay", 1000); + int waitGone = args.getInt(L"wait-gone", 30); + int waitEndpoints = args.getInt(L"wait", 30); + WasapiOptions wasapi = wasapiOptions(args, layout); + + if (!prepareConfig(args, layout)) { + return 1; + } + + AsioHost host(hostOptions(args, layout)); + std::vector iterationJson; + int rc = 0; + + if (!host.load() || !host.open()) { + rc = 1; + } + + for (int i = 0; rc == 0 && i < iterations; ++i) { + JsonObject iteration; + + logf("--- iteration %d of %d ---", i + 1, iterations); + iteration.setInt("iteration", i + 1); + + if (!host.start()) { + rc = 2; + iteration.setString("failure", "start"); + iterationJson.push_back(iteration.str()); + break; + } + + iteration.setDouble("startMs", host.stats().lastStartMs); + + FoundEndpoints endpoints; + + if (!findEndpoints(layout, waitEndpoints, &endpoints)) { + rc = 2; + iteration.setString("failure", "endpoints not found"); + host.stop(); + iterationJson.push_back(iteration.str()); + break; + } + + WasapiResult result = runWasapi(wasapi, endpoints); + + endpoints.release(); + iteration.setRaw("wasapi", result.toJson()); + + if (!result.passed) { + rc = 2; + iteration.setString("failure", "verification"); + } + + if (!host.stop()) { + rc = 2; + iteration.setString("failure", "stop"); + } + + iteration.setDouble("stopMs", host.stats().lastStopMs); + iterationJson.push_back(iteration.str()); + + if (rc == 0 && i + 1 < iterations) { + if (!waitForEndpointsGone(layout, waitGone)) { + logf("Endpoints lingered after stop"); + } + + Sleep((DWORD)restartDelay); + } + } + + host.close(); + + JsonObject result; + + result.setString("command", "run") + .setBool("passed", rc == 0) + .setInt("exitCode", rc) + .setInt("endpointPairs", layout.pairs) + .setInt("channels", layout.channels) + .setRaw("host", host.toJson()) + .setRaw("iterations", jsonArray(iterationJson)); + writeResults(args, result.str()); + logf("%s", rc == 0 ? "PASSED" : "FAILED"); + return rc; +} + +} // namespace + +int wmain(int argc, wchar_t **argv) +{ + Args args = parseArgs(argc, argv); + + if (args.command.empty() || args.has(L"help")) { + return usage(); + } + + HRESULT hr = CoInitializeEx(nullptr, COINIT_MULTITHREADED); + + if (FAILED(hr)) { + logf("CoInitializeEx failed: %s", hresultText(hr).c_str()); + return 1; + } + + int rc; + + if (args.command == L"install") { + rc = cmdInstall(args); + } else if (args.command == L"uninstall") { + rc = cmdUninstall(args); + } else if (args.command == L"config") { + rc = cmdConfig(args); + } else if (args.command == L"host") { + rc = cmdHost(args); + } else if (args.command == L"wasapi") { + rc = cmdWasapi(args); + } else if (args.command == L"run") { + rc = cmdRun(args); + } else { + rc = usage(); + } + + CoUninitialize(); + return rc; +} diff --git a/SarTest/SarTest.vcxproj b/SarTest/SarTest.vcxproj new file mode 100644 index 0000000..b68c529 --- /dev/null +++ b/SarTest/SarTest.vcxproj @@ -0,0 +1,112 @@ + + + + + Debug + Win32 + + + Release + Win32 + + + Debug + x64 + + + Release + x64 + + + + {3C8F1E2A-7D4B-4A9E-B5C6-1D2E3F4A5B6C} + Win32Proj + SarTest + 10.0.22621.0 + + + + Application + true + v143 + Unicode + + + Application + false + v143 + true + Unicode + + + + + + + + + + + + $(VC_IncludePath);$(WindowsSDK_IncludePath);..\SynchronousAudioRouter;..\SarAsio;..\SarTestClock + + + true + + + false + + + + NotUsing + Level3 + true + stdcpp17 + _CONSOLE;%(PreprocessorDefinitions) + + + Console + true + setupapi.lib;newdev.lib;shlwapi.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;advapi32.lib;kernel32.lib;user32.lib;%(AdditionalDependencies) + + + + + + Disabled + _DEBUG;%(PreprocessorDefinitions) + MultiThreadedDebug + + + + + MaxSpeed + true + true + NDEBUG;%(PreprocessorDefinitions) + MultiThreaded + + + true + true + + + + + + + + + + + + + + + + + + + + + diff --git a/SarTest/asiohost.cpp b/SarTest/asiohost.cpp new file mode 100644 index 0000000..8f3e9fa --- /dev/null +++ b/SarTest/asiohost.cpp @@ -0,0 +1,473 @@ +// SynchronousAudioRouter +// Copyright (C) 2026 Mackenzie Straight +// +// This program is free software: you can redistribute it and/or modify +// it under the terms of the GNU General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// This program is distributed in the hope that it will be useful, +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU General Public License for more details. +// +// You should have received a copy of the GNU General Public License +// along with SynchronousAudioRouter. If not, see . + +#include "asiohost.h" + +#include +#include + +using namespace Sar; + +namespace SarTest { + +AsioHost *AsioHost::sInstance = nullptr; + +AsioHost::AsioHost(const AsioHostOptions& options) + : _options(options) +{ + _callbacks.tick = &AsioHost::tickStub; + _callbacks.sampleRateDidChange = &AsioHost::sampleRateStub; + _callbacks.asioMessage = &AsioHost::messageStub; + _callbacks.tickWithTime = nullptr; + sInstance = this; + _watchdogThread = std::thread([this] { watchdog(); }); +} + +AsioHost::~AsioHost() +{ + close(); + _watchdogStop = true; + + if (_watchdogThread.joinable()) { + _watchdogThread.join(); + } + + if (sInstance == this) { + sInstance = nullptr; + } + + // SarAsio.dll is deliberately left loaded: it owns logging state and + // COM objects, and the process is about to exit anyway. +} + +void AsioHost::setPhase(const char *phase) +{ + _phaseStartMs = (long long)nowMs(); + _phase = phase; +} + +void AsioHost::watchdog() +{ + long long lastReport = 0; + + while (!_watchdogStop) { + Sleep(250); + + const char *phase = _phase.load(); + + if (strcmp(phase, "idle") == 0) { + lastReport = 0; + continue; + } + + long long elapsed = (long long)nowMs() - _phaseStartMs.load(); + + if (elapsed > (long long)_options.phaseTimeoutSeconds * 1000 && + elapsed - lastReport > 10000) { + logf("HANG: IASIO::%s has not returned after %lld ms", phase, elapsed); + _stats.hangsReported++; + lastReport = elapsed; + } + } +} + +bool AsioHost::load() +{ + const GUID clsid = __uuidof(Sar::IASIO); + + if (_options.enableSarAsioLog) { + SetEnvironmentVariableW(L"SAR_ASIO_LOG", L"1"); + } + + setPhase("load"); + + if (!_options.sarAsioPath.empty()) { + typedef HRESULT (STDAPICALLTYPE *GetClassObjectFn)(REFCLSID, REFIID, LPVOID *); + + _module = LoadLibraryW(_options.sarAsioPath.c_str()); + + if (!_module) { + logf("LoadLibrary(%s) failed: %s", narrow(_options.sarAsioPath).c_str(), + lastErrorText(GetLastError()).c_str()); + setPhase("idle"); + return false; + } + + auto getClassObject = + (GetClassObjectFn)GetProcAddress(_module, "DllGetClassObject"); + + if (!getClassObject) { + logf("%s does not export DllGetClassObject", narrow(_options.sarAsioPath).c_str()); + setPhase("idle"); + return false; + } + + IClassFactory *factory = nullptr; + HRESULT hr = getClassObject(clsid, IID_IClassFactory, (void **)&factory); + + if (FAILED(hr) || !factory) { + logf("DllGetClassObject failed: %s", hresultText(hr).c_str()); + setPhase("idle"); + return false; + } + + // ASIO drivers use their CLSID as the interface ID. + hr = factory->CreateInstance(nullptr, clsid, (void **)&_asio); + factory->Release(); + + if (FAILED(hr) || !_asio) { + logf("IClassFactory::CreateInstance failed: %s", hresultText(hr).c_str()); + _asio = nullptr; + setPhase("idle"); + return false; + } + + logf("Loaded %s", narrow(_options.sarAsioPath).c_str()); + } else { + HRESULT hr = CoCreateInstance( + clsid, nullptr, CLSCTX_INPROC_SERVER, clsid, (void **)&_asio); + + if (FAILED(hr) || !_asio) { + logf("CoCreateInstance(SarAsio) failed: %s (is SarAsio registered?)", + hresultText(hr).c_str()); + _asio = nullptr; + setPhase("idle"); + return false; + } + + logf("Created the registered SarAsio driver"); + } + + setPhase("idle"); + return true; +} + +bool AsioHost::open() +{ + if (!_asio) { + return false; + } + + setPhase("init"); + + if (_asio->init(nullptr) != AsioBool::True) { + char message[124] = {}; + + _asio->getErrorMessage(message); + logf("IASIO::init failed: %s", message); + setPhase("idle"); + return false; + } + + char name[32] = {}; + + _asio->getDriverName(name); + logf("Driver: %s (version %ld)", name, _asio->getDriverVersion()); + + setPhase("getChannels"); + + if (_asio->getChannels(&_totalInputs, &_totalOutputs) != AsioStatus::OK) { + logf("IASIO::getChannels failed"); + setPhase("idle"); + return false; + } + + _stats.virtualInputs = _options.layout.totalChannels(); + _stats.virtualOutputs = _options.layout.totalChannels(); + _stats.physicalInputs = _totalInputs - _stats.virtualInputs; + _stats.physicalOutputs = _totalOutputs - _stats.virtualOutputs; + + if (_stats.physicalInputs < 0 || _stats.physicalOutputs < 0) { + logf("Driver reports %ld inputs and %ld outputs, fewer than the %d " + "channels per direction the layout needs. Run 'SarTest install' " + "or 'SarTest config' with the same layout first.", + _totalInputs, _totalOutputs, _options.layout.totalChannels()); + setPhase("idle"); + return false; + } + + logf("Channels: %ld inputs (%ld physical), %ld outputs (%ld physical)", + _totalInputs, _stats.physicalInputs, _totalOutputs, _stats.physicalOutputs); + + setPhase("getBufferSize"); + + long minSize = 0, maxSize = 0, preferredSize = 0, granularity = 0; + + if (_asio->getBufferSize(&minSize, &maxSize, &preferredSize, &granularity) != AsioStatus::OK) { + logf("IASIO::getBufferSize failed"); + setPhase("idle"); + return false; + } + + setPhase("setSampleRate"); + + if (_asio->setSampleRate(_options.sampleRate) != AsioStatus::OK) { + logf("setSampleRate(%.0f) rejected, continuing with the driver's rate", + _options.sampleRate); + } + + double sampleRate = 0.0; + + _asio->getSampleRate(&sampleRate); + _stats.sampleRate = sampleRate; + _stats.bufferFrames = preferredSize; + logf("Sample rate %.0f Hz, buffer %ld frames (min %ld, max %ld, granularity %ld)", + sampleRate, preferredSize, minSize, maxSize, granularity); + + setPhase("getChannelInfo"); + _infos.clear(); + + for (int direction = 0; direction < 2; ++direction) { + bool isInput = direction == 0; + long count = isInput ? _totalInputs : _totalOutputs; + + for (long i = 0; i < count; ++i) { + AsioChannelInfo info = {}; + + info.index = i; + info.isInput = isInput ? AsioBool::True : AsioBool::False; + + if (_asio->getChannelInfo(&info) != AsioStatus::OK) { + logf("getChannelInfo(%s %ld) failed", isInput ? "input" : "output", i); + setPhase("idle"); + return false; + } + + if (info.sampleType != Int32LSB) { + logf("Unsupported sample type %ld on %s %ld (%s)", + info.sampleType, isInput ? "input" : "output", i, info.name); + setPhase("idle"); + return false; + } + + AsioBufferInfo buffer = {}; + + buffer.isInput = info.isInput; + buffer.index = i; + _infos.push_back(buffer); + } + } + + _sampleSize = 4; + setPhase("createBuffers"); + + double t0 = nowMs(); + AsioStatus status = _asio->createBuffers( + _infos.data(), (long)_infos.size(), preferredSize, &_callbacks); + + _stats.createBuffersMs = nowMs() - t0; + setPhase("idle"); + + if (status != AsioStatus::OK) { + logf("IASIO::createBuffers failed: %ld", (long)status); + return false; + } + + _buffersCreated = true; + logf("createBuffers OK for %zu channels in %.1f ms", _infos.size(), _stats.createBuffersMs); + return true; +} + +bool AsioHost::start() +{ + if (!_buffersCreated) { + return false; + } + + setPhase("start"); + + double t0 = nowMs(); + AsioStatus status = _asio->start(); + double elapsed = nowMs() - t0; + + setPhase("idle"); + _stats.lastStartMs = elapsed; + _stats.maxStartMs = std::max(_stats.maxStartMs, elapsed); + + if (status != AsioStatus::OK) { + logf("IASIO::start failed: %ld after %.1f ms", (long)status, elapsed); + return false; + } + + _running = true; + _stats.starts++; + logf("start OK in %.1f ms", elapsed); + return true; +} + +bool AsioHost::stop() +{ + if (!_running) { + return true; + } + + readClockStats(); + setPhase("stop"); + + double t0 = nowMs(); + AsioStatus status = _asio->stop(); + double elapsed = nowMs() - t0; + + setPhase("idle"); + _running = false; + _stats.lastStopMs = elapsed; + _stats.maxStopMs = std::max(_stats.maxStopMs, elapsed); + _stats.ticks = _ticks.load(); + + if (status != AsioStatus::OK) { + logf("IASIO::stop failed: %ld after %.1f ms", (long)status, elapsed); + return false; + } + + logf("stop OK in %.1f ms (%lld ticks so far, clock late %llu of %llu)", + elapsed, _stats.ticks, + (unsigned long long)_stats.clock.lateTicks, + (unsigned long long)_stats.clock.ticks); + return true; +} + +void AsioHost::close() +{ + if (!_asio) { + return; + } + + stop(); + + if (_buffersCreated) { + setPhase("disposeBuffers"); + + double t0 = nowMs(); + + _asio->disposeBuffers(); + _stats.disposeBuffersMs = nowMs() - t0; + setPhase("idle"); + _buffersCreated = false; + } + + _asio->Release(); + _asio = nullptr; +} + +void AsioHost::readClockStats() +{ + SarTestClock::ClockStats stats = {}; + + stats.size = sizeof(stats); + + if (_asio && _asio->future(SarTestClock::kStatsSelector, &stats) == AsioStatus::OK) { + _stats.clock = stats; + } +} + +void AsioHost::onTick(long bufferIndex) +{ + long index = bufferIndex & 1; + long count = std::min(_stats.virtualInputs, _stats.virtualOutputs); + size_t bytes = (size_t)_stats.bufferFrames * (size_t)_sampleSize; + + for (long k = 0; k < count; ++k) { + const AsioBufferInfo& in = _infos[(size_t)(_stats.physicalInputs + k)]; + const AsioBufferInfo& out = _infos[(size_t)(_totalInputs + _stats.physicalOutputs + k)]; + + if (in.asioBuffers[index] && out.asioBuffers[index]) { + memcpy(out.asioBuffers[index], in.asioBuffers[index], bytes); + } + } + + _ticks++; +} + +void AsioHost::tickStub(long bufferIndex, AsioBool) +{ + AsioHost *host = sInstance; + + if (host) { + host->onTick(bufferIndex); + } +} + +void AsioHost::sampleRateStub(double sampleRate) +{ + logf("Driver reports sample rate change to %.0f Hz", sampleRate); +} + +long AsioHost::messageStub(AsioMessage selector, long value, void *, double *) +{ + switch (selector) { + case AsioMessage::SelectorSupported: + switch ((AsioMessage)value) { + case AsioMessage::EngineVersion: + case AsioMessage::ResetRequest: + case AsioMessage::BufferSizeChange: + case AsioMessage::ResyncRequest: + case AsioMessage::LatenciesChanged: + return 1; + default: + return 0; + } + case AsioMessage::EngineVersion: + return 2; + case AsioMessage::ResetRequest: + logf("Driver requested a reset"); + + if (sInstance) { + sInstance->_stats.resetRequests++; + } + + return 1; + case AsioMessage::BufferSizeChange: + case AsioMessage::ResyncRequest: + case AsioMessage::LatenciesChanged: + return 1; + default: + // Includes SupportsTimeInfo: we only implement the plain callback. + return 0; + } +} + +std::string AsioHost::toJson() const +{ + JsonObject clock; + + clock.setInt("ticks", (long long)_stats.clock.ticks) + .setInt("lateTicks", (long long)_stats.clock.lateTicks) + .setDouble("maxLatenessMs", _stats.clock.maxLatenessMs) + .setDouble("periodMs", _stats.clock.periodMs); + + JsonObject host; + + host.setInt("ticks", _ticks.load()) + .setInt("starts", _stats.starts) + .setInt("resetRequests", _stats.resetRequests) + .setInt("hangsReported", _stats.hangsReported) + .setDouble("lastStartMs", _stats.lastStartMs) + .setDouble("maxStartMs", _stats.maxStartMs) + .setDouble("lastStopMs", _stats.lastStopMs) + .setDouble("maxStopMs", _stats.maxStopMs) + .setDouble("createBuffersMs", _stats.createBuffersMs) + .setDouble("disposeBuffersMs", _stats.disposeBuffersMs) + .setInt("bufferFrames", _stats.bufferFrames) + .setDouble("sampleRate", _stats.sampleRate) + .setInt("physicalInputs", _stats.physicalInputs) + .setInt("physicalOutputs", _stats.physicalOutputs) + .setInt("virtualInputs", _stats.virtualInputs) + .setInt("virtualOutputs", _stats.virtualOutputs) + .setRaw("clock", clock.str()); + return host.str(); +} + +} // namespace SarTest diff --git a/SarTest/asiohost.h b/SarTest/asiohost.h new file mode 100644 index 0000000..5935211 --- /dev/null +++ b/SarTest/asiohost.h @@ -0,0 +1,116 @@ +// SynchronousAudioRouter +// Copyright (C) 2026 Mackenzie Straight +// +// This program is free software: you can redistribute it and/or modify +// it under the terms of the GNU General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// This program is distributed in the hope that it will be useful, +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU General Public License for more details. +// +// You should have received a copy of the GNU General Public License +// along with SynchronousAudioRouter. If not, see . + +#ifndef _SAR_TEST_ASIOHOST_H +#define _SAR_TEST_ASIOHOST_H + +#include "common.h" + +#include +#include +#include + +#include "tinyasio.h" +#include "clockstats.h" + +namespace SarTest { + +struct AsioHostOptions +{ + // Path of SarAsio.dll to load directly. Empty: CoCreateInstance the + // registered driver, the way a DAW does. + std::wstring sarAsioPath; + EndpointLayout layout; + double sampleRate = 48000.0; + // Watchdog: report a hang when a single driver call exceeds this. + int phaseTimeoutSeconds = 30; + bool enableSarAsioLog = true; +}; + +struct AsioHostStats +{ + long long ticks = 0; + long long starts = 0; + long long resetRequests = 0; + long long hangsReported = 0; + double lastStartMs = 0.0; + double maxStartMs = 0.0; + double lastStopMs = 0.0; + double maxStopMs = 0.0; + double createBuffersMs = 0.0; + double disposeBuffersMs = 0.0; + long bufferFrames = 0; + double sampleRate = 0.0; + long physicalInputs = 0; + long physicalOutputs = 0; + long virtualInputs = 0; + long virtualOutputs = 0; + SarTestClock::ClockStats clock = {}; +}; + +// A headless ASIO host around SarAsio. Every ASIO input (a SAR playback +// endpoint channel) is copied to the ASIO output with the same index (a SAR +// recording endpoint channel) on each callback, so the WASAPI side can verify +// audio end to end. +class AsioHost +{ +public: + explicit AsioHost(const AsioHostOptions& options); + ~AsioHost(); + + bool load(); + bool open(); + bool start(); + bool stop(); + void close(); + + bool running() const { return _running; } + const AsioHostStats& stats() const { return _stats; } + std::string toJson() const; + +private: + static AsioHost *sInstance; + static void tickStub(long bufferIndex, Sar::AsioBool directProcess); + static void sampleRateStub(double sampleRate); + static long messageStub( + Sar::AsioMessage selector, long value, void *message, double *opt); + + void onTick(long bufferIndex); + void setPhase(const char *phase); + void watchdog(); + void readClockStats(); + + AsioHostOptions _options; + AsioHostStats _stats; + HMODULE _module = nullptr; + Sar::IASIO *_asio = nullptr; + std::vector _infos; + long _totalInputs = 0; + long _totalOutputs = 0; + int _sampleSize = 4; + Sar::AsioCallbacks _callbacks = {}; + bool _buffersCreated = false; + bool _running = false; + std::atomic _ticks{ 0 }; + + std::atomic _phase{ "idle" }; + std::atomic _phaseStartMs{ 0 }; + std::atomic _watchdogStop{ false }; + std::thread _watchdogThread; +}; + +} // namespace SarTest +#endif // _SAR_TEST_ASIOHOST_H diff --git a/SarTest/common.cpp b/SarTest/common.cpp new file mode 100644 index 0000000..e4ca56c --- /dev/null +++ b/SarTest/common.cpp @@ -0,0 +1,350 @@ +// SynchronousAudioRouter +// Copyright (C) 2026 Mackenzie Straight +// +// This program is free software: you can redistribute it and/or modify +// it under the terms of the GNU General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// This program is distributed in the hope that it will be useful, +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU General Public License for more details. +// +// You should have received a copy of the GNU General Public License +// along with SynchronousAudioRouter. If not, see . + +#include "common.h" + +#include +#include +#include +#include +#include + +namespace SarTest { + +bool Args::has(const wchar_t *key) const +{ + return options.find(key) != options.end(); +} + +std::wstring Args::get(const wchar_t *key, const wchar_t *def) const +{ + auto it = options.find(key); + return it == options.end() ? std::wstring(def) : it->second; +} + +int Args::getInt(const wchar_t *key, int def) const +{ + auto it = options.find(key); + + if (it == options.end() || it->second.empty()) { + return def; + } + + return _wtoi(it->second.c_str()); +} + +double Args::getDouble(const wchar_t *key, double def) const +{ + auto it = options.find(key); + + if (it == options.end() || it->second.empty()) { + return def; + } + + return _wtof(it->second.c_str()); +} + +Args parseArgs(int argc, wchar_t **argv) +{ + Args args; + int i = 1; + + if (i < argc && wcsncmp(argv[i], L"--", 2) != 0) { + args.command = argv[i++]; + } + + while (i < argc) { + std::wstring token = argv[i++]; + + if (token.size() < 3 || token.compare(0, 2, L"--") != 0) { + logf("Ignoring unexpected argument: %s", narrow(token).c_str()); + continue; + } + + std::wstring key = token.substr(2); + std::wstring value; + auto eq = key.find(L'='); + + if (eq != std::wstring::npos) { + value = key.substr(eq + 1); + key = key.substr(0, eq); + } else if (i < argc && wcsncmp(argv[i], L"--", 2) != 0) { + value = argv[i++]; + } + + args.options[key] = value; + } + + return args; +} + +void logf(const char *fmt, ...) +{ + SYSTEMTIME st; + char buffer[2048]; + va_list ap; + + GetLocalTime(&st); + va_start(ap, fmt); + vsnprintf(buffer, sizeof(buffer), fmt, ap); + va_end(ap); + buffer[sizeof(buffer) - 1] = '\0'; + printf("[%02d:%02d:%02d.%03d] %s\n", + st.wHour, st.wMinute, st.wSecond, st.wMilliseconds, buffer); + fflush(stdout); +} + +std::string narrow(const std::wstring& s) +{ + if (s.empty()) { + return std::string(); + } + + int len = WideCharToMultiByte( + CP_UTF8, 0, s.c_str(), (int)s.size(), nullptr, 0, nullptr, nullptr); + + if (len <= 0) { + return std::string(); + } + + std::string out((size_t)len, '\0'); + WideCharToMultiByte( + CP_UTF8, 0, s.c_str(), (int)s.size(), &out[0], len, nullptr, nullptr); + return out; +} + +std::wstring widen(const std::string& s) +{ + if (s.empty()) { + return std::wstring(); + } + + int len = MultiByteToWideChar( + CP_UTF8, 0, s.c_str(), (int)s.size(), nullptr, 0); + + if (len <= 0) { + return std::wstring(); + } + + std::wstring out((size_t)len, L'\0'); + MultiByteToWideChar(CP_UTF8, 0, s.c_str(), (int)s.size(), &out[0], len); + return out; +} + +std::string hresultText(HRESULT hr) +{ + char buf[32]; + + sprintf_s(buf, "0x%08X", (unsigned int)hr); + return buf; +} + +std::string lastErrorText(DWORD error) +{ + char *message = nullptr; + DWORD len = FormatMessageA( + FORMAT_MESSAGE_ALLOCATE_BUFFER | FORMAT_MESSAGE_FROM_SYSTEM | + FORMAT_MESSAGE_IGNORE_INSERTS, + nullptr, error, 0, (LPSTR)&message, 0, nullptr); + std::string result; + + if (len && message) { + result.assign(message, len); + + while (!result.empty() && + (result.back() == '\r' || result.back() == '\n' || + result.back() == ' ')) { + result.pop_back(); + } + } + + if (message) { + LocalFree(message); + } + + char code[32]; + sprintf_s(code, " (error %lu)", (unsigned long)error); + return result + code; +} + +double nowMs() +{ + LARGE_INTEGER frequency, counter; + + QueryPerformanceFrequency(&frequency); + QueryPerformanceCounter(&counter); + return (double)counter.QuadPart * 1000.0 / (double)frequency.QuadPart; +} + +std::wstring EndpointLayout::playbackName(int pair) const +{ + return prefix + L" Out " + std::to_wstring(pair + 1); +} + +std::wstring EndpointLayout::recordingName(int pair) const +{ + return prefix + L" In " + std::to_wstring(pair + 1); +} + +std::string EndpointLayout::playbackId(int pair) const +{ + return narrow(prefix) + "-out-" + std::to_string(pair + 1); +} + +std::string EndpointLayout::recordingId(int pair) const +{ + return narrow(prefix) + "-in-" + std::to_string(pair + 1); +} + +EndpointLayout EndpointLayout::fromArgs(const Args& args) +{ + EndpointLayout layout; + + layout.pairs = args.getInt(L"endpoints", 2); + layout.channels = args.getInt(L"channels", 2); + layout.prefix = args.get(L"prefix", L"SarTest"); + + if (layout.pairs < 1) { + layout.pairs = 1; + } + + if (layout.pairs > 64) { + layout.pairs = 64; + } + + if (layout.channels < 1) { + layout.channels = 1; + } + + if (layout.channels > 32) { + layout.channels = 32; + } + + return layout; +} + +std::string jsonString(const std::string& value) +{ + std::string out = "\""; + + for (unsigned char c : value) { + switch (c) { + case '"': out += "\\\""; break; + case '\\': out += "\\\\"; break; + case '\n': out += "\\n"; break; + case '\r': out += "\\r"; break; + case '\t': out += "\\t"; break; + default: + if (c < 0x20) { + char buf[8]; + sprintf_s(buf, "\\u%04x", (unsigned int)c); + out += buf; + } else { + out += (char)c; + } + } + } + + out += "\""; + return out; +} + +std::string jsonArray(const std::vector& rawItems) +{ + std::string out = "["; + + for (size_t i = 0; i < rawItems.size(); ++i) { + if (i) { + out += ", "; + } + + out += rawItems[i]; + } + + out += "]"; + return out; +} + +JsonObject& JsonObject::setString(const std::string& key, const std::string& value) +{ + _members.emplace_back(key, jsonString(value)); + return *this; +} + +JsonObject& JsonObject::setInt(const std::string& key, long long value) +{ + _members.emplace_back(key, std::to_string(value)); + return *this; +} + +JsonObject& JsonObject::setDouble(const std::string& key, double value) +{ + char buf[64]; + + if (std::isfinite(value)) { + sprintf_s(buf, "%.3f", value); + } else { + sprintf_s(buf, "null"); + } + + _members.emplace_back(key, buf); + return *this; +} + +JsonObject& JsonObject::setBool(const std::string& key, bool value) +{ + _members.emplace_back(key, value ? "true" : "false"); + return *this; +} + +JsonObject& JsonObject::setRaw(const std::string& key, const std::string& rawJson) +{ + _members.emplace_back(key, rawJson); + return *this; +} + +std::string JsonObject::str() const +{ + std::string out = "{"; + + for (size_t i = 0; i < _members.size(); ++i) { + if (i) { + out += ", "; + } + + out += jsonString(_members[i].first); + out += ": "; + out += _members[i].second; + } + + out += "}"; + return out; +} + +bool writeTextFile(const std::wstring& path, const std::string& content) +{ + std::ofstream fp(path, std::ios::binary | std::ios::trunc); + + if (!fp) { + logf("Couldn't write %s", narrow(path).c_str()); + return false; + } + + fp << content; + return true; +} + +} // namespace SarTest diff --git a/SarTest/common.h b/SarTest/common.h new file mode 100644 index 0000000..2c161df --- /dev/null +++ b/SarTest/common.h @@ -0,0 +1,127 @@ +// SynchronousAudioRouter +// Copyright (C) 2026 Mackenzie Straight +// +// This program is free software: you can redistribute it and/or modify +// it under the terms of the GNU General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// This program is distributed in the hope that it will be useful, +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU General Public License for more details. +// +// You should have received a copy of the GNU General Public License +// along with SynchronousAudioRouter. If not, see . + +#ifndef _SAR_TEST_COMMON_H +#define _SAR_TEST_COMMON_H + +#define NOMINMAX +#define WIN32_LEAN_AND_MEAN +#include + +#include +#include +#include +#include +#include +#include +#include + +namespace SarTest { + +// Command line: SarTest [--key value | --key=value | --flag] ... +struct Args +{ + std::wstring command; + std::map options; + + bool has(const wchar_t *key) const; + std::wstring get(const wchar_t *key, const wchar_t *def = L"") const; + int getInt(const wchar_t *key, int def) const; + double getDouble(const wchar_t *key, double def) const; +}; + +Args parseArgs(int argc, wchar_t **argv); + +// Timestamped line on stdout, flushed immediately so the last line before a +// hang is always present in captured output. +void logf(const char *fmt, ...); + +std::string narrow(const std::wstring& s); +std::wstring widen(const std::string& s); +std::string hresultText(HRESULT hr); +std::string lastErrorText(DWORD error); +double nowMs(); + +// Endpoint layout shared by every command: `pairs` playback/recording pairs +// with `channels` channels each. Pair p is " Out p+1" (playback) and +// " In p+1" (recording). SarAsio exposes playback endpoints as ASIO +// inputs and recording endpoints as ASIO outputs in configuration order, so +// copying ASIO input k to ASIO output k loops every "Out" channel back to the +// matching "In" channel. +struct EndpointLayout +{ + int pairs = 2; + int channels = 2; + std::wstring prefix = L"SarTest"; + + std::wstring playbackName(int pair) const; + std::wstring recordingName(int pair) const; + std::string playbackId(int pair) const; + std::string recordingId(int pair) const; + int totalChannels() const { return pairs * channels; } + int channelId(int pair, int channel) const + { + return (pair * channels + channel) & 0x3F; + } + + static EndpointLayout fromArgs(const Args& args); +}; + +// Test signal. Each sample encodes (channel id, sequence number) as +// k = (id << 16) | (seq & 0xFFFF), carried as k / 2^23 in float, which stays +// under half scale, is exactly representable in float32, and survives the +// audio engine's float <-> int32 conversions. A capture stream can therefore +// verify which channel it receives and whether frames were dropped or +// repeated. +inline int32_t encodeSample(int channelId, uint32_t seq) +{ + return (int32_t)(((channelId & 0x3F) << 16) | (seq & 0xFFFF)); +} + +inline float encodeFloat(int channelId, uint32_t seq) +{ + return (float)encodeSample(channelId, seq) / 8388608.0f; +} + +inline int32_t decodeFloat(float value) +{ + return (int32_t)lroundf(value * 8388608.0f); +} + +inline int decodeChannel(int32_t k) { return (k >> 16) & 0x3F; } +inline uint32_t decodeSeq(int32_t k) { return (uint32_t)(k & 0xFFFF); } + +// Minimal JSON emitter for the results file. +class JsonObject +{ +public: + JsonObject& setString(const std::string& key, const std::string& value); + JsonObject& setInt(const std::string& key, long long value); + JsonObject& setDouble(const std::string& key, double value); + JsonObject& setBool(const std::string& key, bool value); + JsonObject& setRaw(const std::string& key, const std::string& rawJson); + std::string str() const; + +private: + std::vector> _members; +}; + +std::string jsonString(const std::string& value); +std::string jsonArray(const std::vector& rawItems); +bool writeTextFile(const std::wstring& path, const std::string& content); + +} // namespace SarTest +#endif // _SAR_TEST_COMMON_H diff --git a/SarTest/install.cpp b/SarTest/install.cpp new file mode 100644 index 0000000..18e1957 --- /dev/null +++ b/SarTest/install.cpp @@ -0,0 +1,278 @@ +// SynchronousAudioRouter +// Copyright (C) 2026 Mackenzie Straight +// +// This program is free software: you can redistribute it and/or modify +// it under the terms of the GNU General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// This program is distributed in the hope that it will be useful, +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU General Public License for more details. +// +// You should have received a copy of the GNU General Public License +// along with SynchronousAudioRouter. If not, see . + +#include "install.h" + +#include +#include +#include +#include + +namespace SarTest { + +// These must match SynchronousAudioRouter.inf and +// SarInstallerActions/devnode.cpp. +static const wchar_t kHardwareId[] = L"SW\\{0BCFFA5C-E754-48CF-A783-A64C0DC0BB2C}"; +static const wchar_t kClassName[] = L"MEDIA"; +static const GUID kMediaClassGuid = + { 0x4d36e96c, 0xe325, 0x11ce, { 0xbf, 0xc1, 0x08, 0x00, 0x2b, 0xe1, 0x03, 0x18 } }; + +std::wstring appDataDirectory() +{ + wchar_t path[MAX_PATH] = {}; + + if (FAILED(SHGetFolderPathW(nullptr, CSIDL_APPDATA, nullptr, 0, path))) { + return std::wstring(); + } + + PathAppendW(path, L"SynchronousAudioRouter"); + CreateDirectoryW(path, nullptr); + return std::wstring(path) + L"\\"; +} + +std::wstring configurationPath() +{ + return appDataDirectory() + L"default.json"; +} + +std::wstring loggingPath() +{ + std::wstring path = appDataDirectory() + L"logs\\"; + + CreateDirectoryW(path.c_str(), nullptr); + return path; +} + +bool writeDriverConfig( + const EndpointLayout& layout, const std::wstring& driverClsid, + int waveRtMinimumFrames, const std::wstring& path) +{ + std::vector endpoints; + + for (int pair = 0; pair < layout.pairs; ++pair) { + JsonObject playback, recording; + + playback.setString("id", layout.playbackId(pair)) + .setString("description", narrow(layout.playbackName(pair))) + .setString("type", "playback") + .setInt("channelCount", layout.channels); + recording.setString("id", layout.recordingId(pair)) + .setString("description", narrow(layout.recordingName(pair))) + .setString("type", "recording") + .setInt("channelCount", layout.channels); + endpoints.push_back(playback.str()); + endpoints.push_back(recording.str()); + } + + JsonObject root; + + root.setString("driverClsid", narrow(driverClsid)) + .setBool("enableApplicationRouting", false) + .setInt("waveRtMinimumFrames", waveRtMinimumFrames) + .setRaw("endpoints", jsonArray(endpoints)) + .setRaw("applications", "[]"); + + return writeTextFile(path, root.str() + "\n"); +} + +static bool hasSarHardwareId(HDEVINFO set, SP_DEVINFO_DATA *data) +{ + DWORD type = 0, size = 0; + + SetLastError(0); + SetupDiGetDeviceRegistryPropertyW( + set, data, SPDRP_HARDWAREID, &type, nullptr, 0, &size); + + if (GetLastError() != ERROR_INSUFFICIENT_BUFFER || size == 0) { + return false; + } + + std::vector buffer(size / sizeof(wchar_t) + 2, L'\0'); + + if (!SetupDiGetDeviceRegistryPropertyW( + set, data, SPDRP_HARDWAREID, &type, + (BYTE *)buffer.data(), size, nullptr)) { + return false; + } + + for (const wchar_t *p = buffer.data(); *p; p += wcslen(p) + 1) { + if (_wcsicmp(p, kHardwareId) == 0) { + return true; + } + } + + return false; +} + +// Enumerates the MEDIA class and returns how many SAR device nodes exist, +// removing them when `remove` is set. +static int visitSarDeviceNodes(bool remove) +{ + HDEVINFO set = SetupDiGetClassDevsW(&kMediaClassGuid, nullptr, nullptr, 0); + + if (set == INVALID_HANDLE_VALUE) { + logf("SetupDiGetClassDevs failed: %s", lastErrorText(GetLastError()).c_str()); + return -1; + } + + int found = 0; + SP_DEVINFO_DATA data = {}; + + data.cbSize = sizeof(data); + + for (DWORD i = 0; SetupDiEnumDeviceInfo(set, i, &data); ++i) { + if (!hasSarHardwareId(set, &data)) { + continue; + } + + found++; + + if (remove) { + BOOL needReboot = FALSE; + + if (!DiUninstallDevice(nullptr, set, &data, 0, &needReboot)) { + logf("DiUninstallDevice failed: %s", lastErrorText(GetLastError()).c_str()); + } else { + logf("Removed SAR device node%s", needReboot ? " (reboot required)" : ""); + } + } + } + + SetupDiDestroyDeviceInfoList(set); + return found; +} + +bool deviceNodeExists() +{ + return visitSarDeviceNodes(false) > 0; +} + +bool removeDeviceNode() +{ + return visitSarDeviceNodes(true) >= 0; +} + +bool createDeviceNode() +{ + HDEVINFO set = SetupDiCreateDeviceInfoList(&kMediaClassGuid, nullptr); + + if (set == INVALID_HANDLE_VALUE) { + logf("SetupDiCreateDeviceInfoList failed: %s", lastErrorText(GetLastError()).c_str()); + return false; + } + + SP_DEVINFO_DATA data = {}; + bool ok = false; + + data.cbSize = sizeof(data); + + // REG_MULTI_SZ: the ID plus a second terminator. + std::vector hardwareIds(kHardwareId, kHardwareId + wcslen(kHardwareId) + 1); + hardwareIds.push_back(L'\0'); + + if (!SetupDiCreateDeviceInfoW( + set, kClassName, &kMediaClassGuid, nullptr, nullptr, + DICD_GENERATE_ID, &data)) { + logf("SetupDiCreateDeviceInfo failed: %s", lastErrorText(GetLastError()).c_str()); + } else if (!SetupDiSetDeviceRegistryPropertyW( + set, &data, SPDRP_HARDWAREID, (const BYTE *)hardwareIds.data(), + (DWORD)(hardwareIds.size() * sizeof(wchar_t)))) { + logf("SetupDiSetDeviceRegistryProperty failed: %s", lastErrorText(GetLastError()).c_str()); + } else if (!SetupDiCallClassInstaller(DIF_REGISTERDEVICE, set, &data)) { + logf("DIF_REGISTERDEVICE failed: %s", lastErrorText(GetLastError()).c_str()); + } else { + logf("Created SAR device node"); + ok = true; + } + + SetupDiDestroyDeviceInfoList(set); + return ok; +} + +bool installDriverPackage(const std::wstring& infPath, bool *rebootRequired) +{ + wchar_t fullPath[MAX_PATH] = {}; + BOOL reboot = FALSE; + + if (!GetFullPathNameW(infPath.c_str(), MAX_PATH, fullPath, nullptr)) { + logf("Bad INF path: %s", narrow(infPath).c_str()); + return false; + } + + if (GetFileAttributesW(fullPath) == INVALID_FILE_ATTRIBUTES) { + logf("INF not found: %s", narrow(fullPath).c_str()); + return false; + } + + logf("Installing driver package %s", narrow(fullPath).c_str()); + + if (!UpdateDriverForPlugAndPlayDevicesW( + nullptr, kHardwareId, fullPath, + INSTALLFLAG_FORCE | INSTALLFLAG_NONINTERACTIVE, &reboot)) { + DWORD error = GetLastError(); + + if (error == ERROR_IN_WOW64) { + logf("Driver installation must run from a 64-bit SarTest on 64-bit Windows"); + } else { + logf("UpdateDriverForPlugAndPlayDevices failed: %s", lastErrorText(error).c_str()); + } + + return false; + } + + if (rebootRequired) { + *rebootRequired = reboot != FALSE; + } + + logf("Driver package installed%s", reboot ? " (reboot required)" : ""); + return true; +} + +bool registerComServer(const std::wstring& dllPath, bool unregister) +{ + typedef HRESULT (STDAPICALLTYPE *RegisterFn)(); + + HMODULE module = LoadLibraryW(dllPath.c_str()); + + if (!module) { + logf("LoadLibrary(%s) failed: %s", narrow(dllPath).c_str(), + lastErrorText(GetLastError()).c_str()); + return false; + } + + const char *name = unregister ? "DllUnregisterServer" : "DllRegisterServer"; + RegisterFn fn = (RegisterFn)GetProcAddress(module, name); + bool ok = false; + + if (!fn) { + logf("%s does not export %s", narrow(dllPath).c_str(), name); + } else { + HRESULT hr = fn(); + + if (FAILED(hr)) { + logf("%s in %s failed: %s", name, narrow(dllPath).c_str(), + hresultText(hr).c_str()); + } else { + logf("%s: %s", name, narrow(dllPath).c_str()); + ok = true; + } + } + + FreeLibrary(module); + return ok; +} + +} // namespace SarTest diff --git a/SarTest/install.h b/SarTest/install.h new file mode 100644 index 0000000..a029223 --- /dev/null +++ b/SarTest/install.h @@ -0,0 +1,49 @@ +// SynchronousAudioRouter +// Copyright (C) 2026 Mackenzie Straight +// +// This program is free software: you can redistribute it and/or modify +// it under the terms of the GNU General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// This program is distributed in the hope that it will be useful, +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU General Public License for more details. +// +// You should have received a copy of the GNU General Public License +// along with SynchronousAudioRouter. If not, see . + +#ifndef _SAR_TEST_INSTALL_H +#define _SAR_TEST_INSTALL_H + +#include "common.h" + +namespace SarTest { + +// %APPDATA%\SynchronousAudioRouter\, the directory SarAsio reads its +// configuration from and writes its logs to. Created if missing. +std::wstring appDataDirectory(); +std::wstring configurationPath(); +std::wstring loggingPath(); + +// Writes a SarAsio default.json describing the layout, with the given ASIO +// driver CLSID as the physical interface and application routing disabled. +bool writeDriverConfig( + const EndpointLayout& layout, const std::wstring& driverClsid, + int waveRtMinimumFrames, const std::wstring& path); + +// Software device node for the SAR driver, matching the INF's hardware ID. +bool deviceNodeExists(); +bool createDeviceNode(); +bool removeDeviceNode(); + +// Installs (or updates) the driver package for the device node from an INF. +// Requires an elevated 64-bit process on 64-bit Windows. +bool installDriverPackage(const std::wstring& infPath, bool *rebootRequired); + +// Calls DllRegisterServer / DllUnregisterServer in the given DLL. +bool registerComServer(const std::wstring& dllPath, bool unregister); + +} // namespace SarTest +#endif // _SAR_TEST_INSTALL_H diff --git a/SarTest/wasapi.cpp b/SarTest/wasapi.cpp new file mode 100644 index 0000000..46b4cb4 --- /dev/null +++ b/SarTest/wasapi.cpp @@ -0,0 +1,913 @@ +// SynchronousAudioRouter +// Copyright (C) 2026 Mackenzie Straight +// +// This program is free software: you can redistribute it and/or modify +// it under the terms of the GNU General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// This program is distributed in the hope that it will be useful, +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU General Public License for more details. +// +// You should have received a copy of the GNU General Public License +// along with SynchronousAudioRouter. If not, see . + +#include "wasapi.h" + +#include +#include +#include +#include +#include +#include + +#include +#include +#include + +namespace SarTest { + +namespace { + +template +class ComPtr +{ +public: + ComPtr() {} + ~ComPtr() { reset(); } + ComPtr(const ComPtr&) = delete; + ComPtr& operator=(const ComPtr&) = delete; + + T *get() const { return _p; } + T *operator->() const { return _p; } + explicit operator bool() const { return _p != nullptr; } + T **put() { reset(); return &_p; } + void **putVoid() { reset(); return (void **)&_p; } + T *detach() { T *p = _p; _p = nullptr; return p; } + + void reset() + { + if (_p) { + _p->Release(); + _p = nullptr; + } + } + +private: + T *_p = nullptr; +}; + +enum class SampleKind { Float32, Int32, Unsupported }; + +SampleKind classifyFormat(const WAVEFORMATEX *format, std::string *description) +{ + WORD tag = format->wFormatTag; + bool isFloat = tag == WAVE_FORMAT_IEEE_FLOAT; + bool isPcm = tag == WAVE_FORMAT_PCM; + + if (tag == WAVE_FORMAT_EXTENSIBLE && format->cbSize >= 22) { + auto *ext = (const WAVEFORMATEXTENSIBLE *)format; + + // KSDATAFORMAT_SUBTYPE_* GUIDs carry the classic tag in Data1. + isFloat = ext->SubFormat.Data1 == WAVE_FORMAT_IEEE_FLOAT; + isPcm = ext->SubFormat.Data1 == WAVE_FORMAT_PCM; + } + + char buf[128]; + + sprintf_s(buf, "%s %u-bit, %u ch, %lu Hz", + isFloat ? "float" : isPcm ? "pcm" : "unknown", + (unsigned)format->wBitsPerSample, (unsigned)format->nChannels, + (unsigned long)format->nSamplesPerSec); + *description = buf; + + if (isFloat && format->wBitsPerSample == 32) { + return SampleKind::Float32; + } + + if (isPcm && format->wBitsPerSample == 32) { + return SampleKind::Int32; + } + + return SampleKind::Unsupported; +} + +std::wstring propertyString(IPropertyStore *store, const PROPERTYKEY& key) +{ + PROPVARIANT value; + std::wstring result; + + PropVariantInit(&value); + + if (SUCCEEDED(store->GetValue(key, &value)) && + value.vt == VT_LPWSTR && value.pwszVal) { + result = value.pwszVal; + } + + PropVariantClear(&value); + return result; +} + +bool matchesName(IMMDevice *device, const std::wstring& name) +{ + ComPtr store; + + if (FAILED(device->OpenPropertyStore(STGM_READ, store.put()))) { + return false; + } + + if (propertyString(store.get(), PKEY_Device_DeviceDesc) == name) { + return true; + } + + std::wstring friendly = propertyString(store.get(), PKEY_Device_FriendlyName); + std::wstring prefix = name + L" ("; + + return friendly == name || + (friendly.size() >= prefix.size() && + friendly.compare(0, prefix.size(), prefix) == 0); +} + +// Returns the first active endpoint of the given flow whose name matches. +bool findActiveEndpoint( + IMMDeviceEnumerator *enumerator, EDataFlow flow, const std::wstring& name, + IMMDevice **found) +{ + ComPtr collection; + + if (FAILED(enumerator->EnumAudioEndpoints(flow, DEVICE_STATE_ACTIVE, collection.put()))) { + return false; + } + + UINT count = 0; + + collection->GetCount(&count); + + for (UINT i = 0; i < count; ++i) { + ComPtr device; + + if (FAILED(collection->Item(i, device.put()))) { + continue; + } + + if (matchesName(device.get(), name)) { + if (found) { + *found = device.detach(); + } + + return true; + } + } + + return false; +} + +bool createEnumerator(ComPtr *enumerator) +{ + HRESULT hr = CoCreateInstance( + __uuidof(MMDeviceEnumerator), nullptr, CLSCTX_ALL, + __uuidof(IMMDeviceEnumerator), enumerator->putVoid()); + + if (FAILED(hr)) { + logf("CoCreateInstance(MMDeviceEnumerator) failed: %s", hresultText(hr).c_str()); + return false; + } + + return true; +} + +void setUnityVolume(IMMDevice *device, IAudioClient *client) +{ + ComPtr endpointVolume; + + if (SUCCEEDED(device->Activate( + __uuidof(IAudioEndpointVolume), CLSCTX_ALL, nullptr, endpointVolume.putVoid()))) { + endpointVolume->SetMasterVolumeLevelScalar(1.0f, nullptr); + endpointVolume->SetMute(FALSE, nullptr); + } + + ComPtr sessionVolume; + + if (SUCCEEDED(client->GetService(__uuidof(ISimpleAudioVolume), sessionVolume.putVoid()))) { + sessionVolume->SetMasterVolume(1.0f, nullptr); + sessionVolume->SetMute(FALSE, nullptr); + } +} + +class Stream +{ +public: + Stream(const EndpointLayout& layout, int pair, IMMDevice *device, bool isCapture) + : _device(device), _isCapture(isCapture) + { + _device->AddRef(); + _stats.isCapture = isCapture; + _stats.name = narrow(isCapture ? layout.recordingName(pair) : layout.playbackName(pair)); + + for (int c = 0; c < layout.channels; ++c) { + _channelIds.push_back(layout.channelId(pair, c)); + } + } + + ~Stream() + { + end(); + _device->Release(); + } + + void begin() + { + _stopEvent = CreateEventW(nullptr, TRUE, FALSE, nullptr); + _thread = std::thread([this] { run(); }); + } + + void end() + { + if (_stopEvent) { + SetEvent(_stopEvent); + } + + if (_thread.joinable()) { + _thread.join(); + } + + if (_stopEvent) { + CloseHandle(_stopEvent); + _stopEvent = nullptr; + } + } + + const StreamStats& stats() const { return _stats; } + +private: + void run() + { + HRESULT hr = CoInitializeEx(nullptr, COINIT_MULTITHREADED); + + if (_isCapture) { + captureLoop(); + } else { + renderLoop(); + } + + if (SUCCEEDED(hr)) { + CoUninitialize(); + } + } + + bool fail(const char *stage, HRESULT hr) + { + if (hr == AUDCLNT_E_DEVICE_INVALIDATED) { + _stats.deviceInvalidated = true; + logf("%s: device invalidated during %s", _stats.name.c_str(), stage); + } else { + _stats.lastError = hr; + _stats.errorStage = stage; + logf("%s: %s failed: %s", _stats.name.c_str(), stage, hresultText(hr).c_str()); + } + + return false; + } + + // Shared-mode, event-driven client on the mix format. + bool initialize(ComPtr *client, UINT32 *bufferFrames, HANDLE *event) + { + HRESULT hr = _device->Activate( + __uuidof(IAudioClient), CLSCTX_ALL, nullptr, client->putVoid()); + + if (FAILED(hr)) { + return fail("Activate", hr); + } + + WAVEFORMATEX *mix = nullptr; + + hr = (*client)->GetMixFormat(&mix); + + if (FAILED(hr) || !mix) { + return fail("GetMixFormat", hr); + } + + _kind = classifyFormat(mix, &_stats.format); + _stats.channels = mix->nChannels; + + if (_kind == SampleKind::Unsupported) { + CoTaskMemFree(mix); + _stats.errorStage = "format"; + logf("%s: unsupported mix format %s", _stats.name.c_str(), _stats.format.c_str()); + return false; + } + + if ((int)mix->nChannels < (int)_channelIds.size()) { + logf("%s: engine format has %u channels but the endpoint was created with %zu", + _stats.name.c_str(), (unsigned)mix->nChannels, _channelIds.size()); + } + + hr = (*client)->Initialize( + AUDCLNT_SHAREMODE_SHARED, AUDCLNT_STREAMFLAGS_EVENTCALLBACK, + 0, 0, mix, nullptr); + CoTaskMemFree(mix); + + if (FAILED(hr)) { + return fail("Initialize", hr); + } + + hr = (*client)->GetBufferSize(bufferFrames); + + if (FAILED(hr)) { + return fail("GetBufferSize", hr); + } + + *event = CreateEventW(nullptr, FALSE, FALSE, nullptr); + hr = (*client)->SetEventHandle(*event); + + if (FAILED(hr)) { + return fail("SetEventHandle", hr); + } + + setUnityVolume(_device, client->get()); + return true; + } + + void fill(BYTE *data, UINT32 frames) + { + int channels = _stats.channels; + + for (UINT32 f = 0; f < frames; ++f, ++_sequence) { + for (int c = 0; c < channels; ++c) { + int id = c < (int)_channelIds.size() ? _channelIds[(size_t)c] : 0; + size_t index = (size_t)f * (size_t)channels + (size_t)c; + + if (_kind == SampleKind::Float32) { + ((float *)data)[index] = encodeFloat(id, _sequence); + } else { + ((int32_t *)data)[index] = encodeSample(id, _sequence) << 8; + } + } + } + } + + void decode(const BYTE *data, UINT32 frames) + { + int channels = _stats.channels; + int expectedChannels = std::min(channels, (int)_channelIds.size()); + + for (UINT32 f = 0; f < frames; ++f) { + bool allZero = true, channelsOk = true, sequenceConsistent = true; + uint32_t sequence = 0; + + for (int c = 0; c < expectedChannels; ++c) { + size_t index = (size_t)f * (size_t)channels + (size_t)c; + int32_t k; + + if (_kind == SampleKind::Float32) { + k = decodeFloat(((const float *)data)[index]); + } else { + k = ((const int32_t *)data)[index] >> 8; + } + + if (k != 0) { + allZero = false; + } + + if (decodeChannel(k) != _channelIds[(size_t)c]) { + channelsOk = false; + } + + if (c == 0) { + sequence = decodeSeq(k); + } else if (decodeSeq(k) != sequence) { + sequenceConsistent = false; + } + } + + if (allZero) { + _stats.silentFrames++; + + if (_stats.validFrames == 0) { + _stats.startupSilentFrames++; + } + + continue; + } + + if (!channelsOk || !sequenceConsistent) { + _stats.wrongChannelFrames++; + continue; + } + + if (_haveLastSequence && sequence != ((_lastSequence + 1) & 0xFFFF)) { + _stats.discontinuities++; + } + + _lastSequence = sequence; + _haveLastSequence = true; + _stats.validFrames++; + } + } + + void renderLoop() + { + ComPtr client; + UINT32 bufferFrames = 0; + HANDLE event = nullptr; + + if (!initialize(&client, &bufferFrames, &event)) { + if (event) { + CloseHandle(event); + } + + return; + } + + ComPtr render; + HRESULT hr = client->GetService(__uuidof(IAudioRenderClient), render.putVoid()); + + if (FAILED(hr)) { + fail("GetService(IAudioRenderClient)", hr); + CloseHandle(event); + return; + } + + BYTE *data = nullptr; + + if (SUCCEEDED(render->GetBuffer(bufferFrames, &data))) { + fill(data, bufferFrames); + render->ReleaseBuffer(bufferFrames, 0); + } + + hr = client->Start(); + + if (FAILED(hr)) { + fail("Start", hr); + CloseHandle(event); + return; + } + + _stats.started = true; + logf("%s: rendering %s, buffer %u frames", _stats.name.c_str(), + _stats.format.c_str(), (unsigned)bufferFrames); + + HANDLE handles[2] = { _stopEvent, event }; + + for (;;) { + DWORD wait = WaitForMultipleObjects(2, handles, FALSE, 2000); + + if (wait == WAIT_OBJECT_0) { + break; + } + + if (wait != WAIT_OBJECT_0 + 1) { + _stats.timeouts++; + + if (_stats.timeouts >= 5) { + _stats.errorStage = "event timeout"; + logf("%s: no buffer events for 10 s", _stats.name.c_str()); + break; + } + + continue; + } + + UINT32 padding = 0; + + hr = client->GetCurrentPadding(&padding); + + if (FAILED(hr)) { + fail("GetCurrentPadding", hr); + break; + } + + UINT32 available = padding < bufferFrames ? bufferFrames - padding : 0; + + if (available == 0) { + continue; + } + + hr = render->GetBuffer(available, &data); + + if (FAILED(hr)) { + fail("GetBuffer", hr); + break; + } + + fill(data, available); + hr = render->ReleaseBuffer(available, 0); + + if (FAILED(hr)) { + fail("ReleaseBuffer", hr); + break; + } + + _stats.framesProcessed += available; + } + + client->Stop(); + CloseHandle(event); + } + + void captureLoop() + { + ComPtr client; + UINT32 bufferFrames = 0; + HANDLE event = nullptr; + + if (!initialize(&client, &bufferFrames, &event)) { + if (event) { + CloseHandle(event); + } + + return; + } + + ComPtr capture; + HRESULT hr = client->GetService(__uuidof(IAudioCaptureClient), capture.putVoid()); + + if (FAILED(hr)) { + fail("GetService(IAudioCaptureClient)", hr); + CloseHandle(event); + return; + } + + hr = client->Start(); + + if (FAILED(hr)) { + fail("Start", hr); + CloseHandle(event); + return; + } + + _stats.started = true; + logf("%s: capturing %s, buffer %u frames", _stats.name.c_str(), + _stats.format.c_str(), (unsigned)bufferFrames); + + HANDLE handles[2] = { _stopEvent, event }; + + for (;;) { + DWORD wait = WaitForMultipleObjects(2, handles, FALSE, 2000); + + if (wait == WAIT_OBJECT_0) { + break; + } + + if (wait != WAIT_OBJECT_0 + 1) { + _stats.timeouts++; + + if (_stats.timeouts >= 5) { + _stats.errorStage = "event timeout"; + logf("%s: no capture events for 10 s", _stats.name.c_str()); + break; + } + + continue; + } + + UINT32 packet = 0; + + hr = capture->GetNextPacketSize(&packet); + + if (FAILED(hr)) { + fail("GetNextPacketSize", hr); + break; + } + + bool failed = false; + + while (packet > 0) { + BYTE *data = nullptr; + UINT32 frames = 0; + DWORD flags = 0; + + hr = capture->GetBuffer(&data, &frames, &flags, nullptr, nullptr); + + if (FAILED(hr)) { + fail("GetBuffer", hr); + failed = true; + break; + } + + if (flags & AUDCLNT_BUFFERFLAGS_DATA_DISCONTINUITY) { + _stats.engineDiscontinuities++; + } + + if (flags & AUDCLNT_BUFFERFLAGS_SILENT) { + _stats.silentFrames += frames; + + if (_stats.validFrames == 0) { + _stats.startupSilentFrames += frames; + } + } else { + decode(data, frames); + } + + hr = capture->ReleaseBuffer(frames); + + if (FAILED(hr)) { + fail("ReleaseBuffer", hr); + failed = true; + break; + } + + _stats.framesProcessed += frames; + hr = capture->GetNextPacketSize(&packet); + + if (FAILED(hr)) { + fail("GetNextPacketSize", hr); + failed = true; + break; + } + } + + if (failed) { + break; + } + } + + client->Stop(); + CloseHandle(event); + } + + IMMDevice *_device; + bool _isCapture; + StreamStats _stats; + std::vector _channelIds; + SampleKind _kind = SampleKind::Unsupported; + uint32_t _sequence = 0; + uint32_t _lastSequence = 0; + bool _haveLastSequence = false; + HANDLE _stopEvent = nullptr; + std::thread _thread; +}; + +} // namespace + +FoundEndpoints::~FoundEndpoints() +{ + release(); +} + +void FoundEndpoints::release() +{ + for (auto *device : render) { + if (device) { + device->Release(); + } + } + + for (auto *device : capture) { + if (device) { + device->Release(); + } + } + + render.clear(); + capture.clear(); +} + +bool findEndpoints(const EndpointLayout& layout, int timeoutSeconds, FoundEndpoints *out) +{ + ComPtr enumerator; + + if (!createEnumerator(&enumerator)) { + return false; + } + + out->release(); + out->render.assign((size_t)layout.pairs, nullptr); + out->capture.assign((size_t)layout.pairs, nullptr); + + double deadline = nowMs() + timeoutSeconds * 1000.0; + double nextReport = nowMs() + 5000.0; + + for (;;) { + int missing = 0; + + for (int pair = 0; pair < layout.pairs; ++pair) { + if (!out->render[(size_t)pair]) { + findActiveEndpoint(enumerator.get(), eRender, + layout.playbackName(pair), &out->render[(size_t)pair]); + } + + if (!out->capture[(size_t)pair]) { + findActiveEndpoint(enumerator.get(), eCapture, + layout.recordingName(pair), &out->capture[(size_t)pair]); + } + + missing += !out->render[(size_t)pair]; + missing += !out->capture[(size_t)pair]; + } + + if (missing == 0) { + logf("All %d endpoints are active", layout.pairs * 2); + return true; + } + + if (nowMs() > deadline) { + for (int pair = 0; pair < layout.pairs; ++pair) { + if (!out->render[(size_t)pair]) { + logf("Missing render endpoint: %s", narrow(layout.playbackName(pair)).c_str()); + } + + if (!out->capture[(size_t)pair]) { + logf("Missing capture endpoint: %s", narrow(layout.recordingName(pair)).c_str()); + } + } + + return false; + } + + if (nowMs() > nextReport) { + logf("Waiting for %d of %d endpoints to become active", missing, layout.pairs * 2); + nextReport = nowMs() + 5000.0; + } + + Sleep(500); + } +} + +bool waitForEndpointsGone(const EndpointLayout& layout, int timeoutSeconds) +{ + ComPtr enumerator; + + if (!createEnumerator(&enumerator)) { + return false; + } + + double deadline = nowMs() + timeoutSeconds * 1000.0; + + for (;;) { + int present = 0; + + for (int pair = 0; pair < layout.pairs; ++pair) { + present += findActiveEndpoint(enumerator.get(), eRender, layout.playbackName(pair), nullptr); + present += findActiveEndpoint(enumerator.get(), eCapture, layout.recordingName(pair), nullptr); + } + + if (present == 0) { + return true; + } + + if (nowMs() > deadline) { + logf("%d endpoints are still active after %d s", present, timeoutSeconds); + return false; + } + + Sleep(500); + } +} + +std::string StreamStats::toJson() const +{ + JsonObject o; + + o.setString("name", name) + .setString("direction", isCapture ? "capture" : "render") + .setBool("started", started) + .setBool("deviceInvalidated", deviceInvalidated) + .setString("error", lastError == S_OK ? "" : hresultText(lastError)) + .setString("errorStage", errorStage) + .setString("format", format) + .setInt("channels", channels) + .setInt("framesProcessed", framesProcessed) + .setInt("silentFrames", silentFrames) + .setInt("startupSilentFrames", startupSilentFrames) + .setInt("validFrames", validFrames) + .setInt("discontinuities", discontinuities) + .setInt("engineDiscontinuities", engineDiscontinuities) + .setInt("wrongChannelFrames", wrongChannelFrames) + .setInt("timeouts", timeouts) + .setBool("passed", passed) + .setString("failure", failure); + return o.str(); +} + +std::string WasapiResult::toJson() const +{ + std::vector items; + + for (const auto& s : streams) { + items.push_back(s.toJson()); + } + + JsonObject o; + + o.setBool("passed", passed).setRaw("streams", jsonArray(items)); + return o.str(); +} + +static void evaluate(StreamStats *s, const WasapiOptions& options) +{ + s->passed = false; + + if (!s->started) { + s->failure = "stream never started"; + return; + } + + if (s->lastError != S_OK) { + s->failure = "error in " + s->errorStage; + return; + } + + if (!s->errorStage.empty()) { + s->failure = s->errorStage; + return; + } + + if (s->deviceInvalidated && !options.expectInvalidation) { + s->failure = "device invalidated"; + return; + } + + if (s->framesProcessed == 0) { + s->failure = "no frames processed"; + return; + } + + if (s->isCapture) { + long long considered = s->framesProcessed - s->startupSilentFrames; + + if (s->validFrames == 0) { + s->failure = "no valid test signal received"; + return; + } + + if (s->wrongChannelFrames > 0) { + s->failure = "frames with the wrong channel id"; + return; + } + + if (considered > 0 && + (double)s->validFrames < options.minValidRatio * (double)considered) { + s->failure = "too few valid frames"; + return; + } + + if (options.maxDiscontinuities >= 0 && + s->discontinuities > options.maxDiscontinuities) { + s->failure = "too many discontinuities"; + return; + } + } + + s->passed = true; +} + +WasapiResult runWasapi(const WasapiOptions& options, const FoundEndpoints& endpoints) +{ + WasapiResult result; + std::vector> streams; + const EndpointLayout& layout = options.layout; + + for (int pair = 0; pair < layout.pairs; ++pair) { + streams.emplace_back(new Stream(layout, pair, endpoints.render[(size_t)pair], false)); + streams.emplace_back(new Stream(layout, pair, endpoints.capture[(size_t)pair], true)); + } + + for (auto& stream : streams) { + stream->begin(); + } + + logf("Streaming on %zu endpoints for %.1f s", streams.size(), options.durationSeconds); + Sleep((DWORD)(options.durationSeconds * 1000.0)); + + // Stop captures first so the tail of silence after playback ends is + // not counted against them. + for (auto& stream : streams) { + if (stream->stats().isCapture) { + stream->end(); + } + } + + for (auto& stream : streams) { + stream->end(); + } + + result.passed = true; + + for (auto& stream : streams) { + StreamStats stats = stream->stats(); + + evaluate(&stats, options); + + if (stats.isCapture) { + logf("%s: %lld frames, %lld valid, %lld silent (%lld at start), " + "%lld discontinuities, %lld wrong channel: %s", + stats.name.c_str(), stats.framesProcessed, stats.validFrames, + stats.silentFrames, stats.startupSilentFrames, + stats.discontinuities, stats.wrongChannelFrames, + stats.passed ? "PASS" : stats.failure.c_str()); + } else { + logf("%s: %lld frames rendered: %s", stats.name.c_str(), + stats.framesProcessed, stats.passed ? "PASS" : stats.failure.c_str()); + } + + result.passed = result.passed && stats.passed; + result.streams.push_back(stats); + } + + return result; +} + +} // namespace SarTest diff --git a/SarTest/wasapi.h b/SarTest/wasapi.h new file mode 100644 index 0000000..03d1724 --- /dev/null +++ b/SarTest/wasapi.h @@ -0,0 +1,90 @@ +// SynchronousAudioRouter +// Copyright (C) 2026 Mackenzie Straight +// +// This program is free software: you can redistribute it and/or modify +// it under the terms of the GNU General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// This program is distributed in the hope that it will be useful, +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU General Public License for more details. +// +// You should have received a copy of the GNU General Public License +// along with SynchronousAudioRouter. If not, see . + +#ifndef _SAR_TEST_WASAPI_H +#define _SAR_TEST_WASAPI_H + +#include "common.h" + +#include + +namespace SarTest { + +struct StreamStats +{ + std::string name; + bool isCapture = false; + bool started = false; + bool deviceInvalidated = false; + HRESULT lastError = S_OK; + std::string errorStage; + std::string format; + int channels = 0; + long long framesProcessed = 0; + long long silentFrames = 0; + long long startupSilentFrames = 0; + long long validFrames = 0; + long long discontinuities = 0; + long long engineDiscontinuities = 0; + long long wrongChannelFrames = 0; + long long timeouts = 0; + bool passed = false; + std::string failure; + + std::string toJson() const; +}; + +struct FoundEndpoints +{ + std::vector render; // [pair] + std::vector capture; // [pair] + + ~FoundEndpoints(); + void release(); +}; + +// Polls the MMDevice enumerator until every endpoint of the layout is active +// or the timeout passes. +bool findEndpoints(const EndpointLayout& layout, int timeoutSeconds, FoundEndpoints *out); + +// Polls until none of the layout's endpoints are active any more. +bool waitForEndpointsGone(const EndpointLayout& layout, int timeoutSeconds); + +struct WasapiOptions +{ + EndpointLayout layout; + double durationSeconds = 5.0; + // The ASIO host is going to be killed underneath the streams, so device + // invalidation is the expected outcome rather than a failure. + bool expectInvalidation = false; + double minValidRatio = 0.9; + long long maxDiscontinuities = -1; // -1: report only +}; + +struct WasapiResult +{ + std::vector streams; + bool passed = false; + + std::string toJson() const; +}; + +// Streams the test signal into every playback endpoint and verifies it on +// every recording endpoint for the configured duration. +WasapiResult runWasapi(const WasapiOptions& options, const FoundEndpoints& endpoints); + +} // namespace SarTest +#endif // _SAR_TEST_WASAPI_H diff --git a/SarTestClock/SarTestClock.cpp b/SarTestClock/SarTestClock.cpp new file mode 100644 index 0000000..5c65003 --- /dev/null +++ b/SarTestClock/SarTestClock.cpp @@ -0,0 +1,604 @@ +// SynchronousAudioRouter +// Copyright (C) 2026 Mackenzie Straight +// +// This program is free software: you can redistribute it and/or modify +// it under the terms of the GNU General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// This program is distributed in the hope that it will be useful, +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU General Public License for more details. +// +// You should have received a copy of the GNU General Public License +// along with SynchronousAudioRouter. If not, see . + +// A software-clock ASIO driver for testing SAR on machines with no audio +// hardware. It exposes a few dummy channels and delivers bufferSwitch +// callbacks from a timer thread at the configured period, so SarAsio can +// wrap it exactly like a real interface. Tunables (read at object creation): +// +// SAR_TEST_CLOCK_RATE sample rate in Hz (default 48000) +// SAR_TEST_CLOCK_FRAMES frames per callback (default 480, 10 ms) +// SAR_TEST_CLOCK_INPUTS dummy input channels (default 2) +// SAR_TEST_CLOCK_OUTPUTS dummy output channels (default 2) + +#define NOMINMAX +#define WIN32_LEAN_AND_MEAN +#include +#include +#include +#include + +#include +#include +#include +#include +#include +#include +#include +#include +#include + +#include "tinyasio.h" +#include "clockstats.h" + +#ifndef CREATE_WAITABLE_TIMER_HIGH_RESOLUTION +#define CREATE_WAITABLE_TIMER_HIGH_RESOLUTION 0x00000002 +#endif + +using namespace Sar; + +namespace { + +// {7A3C9E12-4B5D-4F6E-8A1B-2C3D4E5F6A7B} +const GUID kClsid = + { 0x7a3c9e12, 0x4b5d, 0x4f6e, { 0x8a, 0x1b, 0x2c, 0x3d, 0x4e, 0x5f, 0x6a, 0x7b } }; +const wchar_t kAsioKey[] = L"SOFTWARE\\ASIO\\SAR Test Clock"; +const wchar_t kClsidKey[] = L"CLSID\\" SAR_TEST_CLOCK_CLSID_STR; +const wchar_t kInprocKey[] = L"CLSID\\" SAR_TEST_CLOCK_CLSID_STR L"\\InProcServer32"; + +HMODULE gModule = nullptr; +std::atomic gObjectCount{ 0 }; +std::atomic gLockCount{ 0 }; + +long envLong(const wchar_t *name, long def) +{ + wchar_t buffer[64]; + DWORD len = GetEnvironmentVariableW(name, buffer, 64); + + if (len == 0 || len >= 64) { + return def; + } + + long value = _wtol(buffer); + return value > 0 ? value : def; +} + +int64_t fileTimeNow() +{ + FILETIME ft; + + GetSystemTimePreciseAsFileTime(&ft); + return ((int64_t)ft.dwHighDateTime << 32) | (int64_t)ft.dwLowDateTime; +} + +class SoftwareClock: public IASIO +{ +public: + SoftwareClock() + { + gObjectCount++; + _sampleRate = (double)envLong(L"SAR_TEST_CLOCK_RATE", 48000); + _bufferFrames = envLong(L"SAR_TEST_CLOCK_FRAMES", 480); + _inputCount = envLong(L"SAR_TEST_CLOCK_INPUTS", 2); + _outputCount = envLong(L"SAR_TEST_CLOCK_OUTPUTS", 2); + } + + virtual ~SoftwareClock() + { + disposeBuffers(); + gObjectCount--; + } + + // IUnknown. ASIO drivers answer their own CLSID as the interface ID. + HRESULT STDMETHODCALLTYPE QueryInterface(REFIID riid, void **ppv) override + { + if (!ppv) { + return E_POINTER; + } + + if (riid == IID_IUnknown || riid == kClsid) { + *ppv = static_cast(this); + AddRef(); + return S_OK; + } + + *ppv = nullptr; + return E_NOINTERFACE; + } + + ULONG STDMETHODCALLTYPE AddRef() override + { + return (ULONG)++_refs; + } + + ULONG STDMETHODCALLTYPE Release() override + { + long refs = --_refs; + + if (refs == 0) { + delete this; + } + + return (ULONG)refs; + } + + // IASIO + AsioBool init(void *) override + { + return AsioBool::True; + } + + void getDriverName(char name[32]) override + { + strcpy_s(name, 32, "SAR Test Clock"); + } + + long getDriverVersion() override + { + return 1; + } + + void getErrorMessage(char str[124]) override + { + strcpy_s(str, 124, _error.c_str()); + } + + AsioStatus start() override + { + if (_running) { + return AsioStatus::OK; + } + + if (!_callbacks.tick) { + _error = "createBuffers has not been called"; + return AsioStatus::NotPresent; + } + + _stopEvent = CreateEventW(nullptr, TRUE, FALSE, nullptr); + + if (!_stopEvent) { + return AsioStatus::HardwareMalfunction; + } + + _ticks = 0; + _lateTicks = 0; + _maxLatenessMs = 0.0; + _running = true; + _thread = std::thread([this] { tickThread(); }); + return AsioStatus::OK; + } + + AsioStatus stop() override + { + if (!_running) { + return AsioStatus::OK; + } + + _running = false; + SetEvent(_stopEvent); + + if (_thread.joinable()) { + _thread.join(); + } + + CloseHandle(_stopEvent); + _stopEvent = nullptr; + return AsioStatus::OK; + } + + AsioStatus getChannels(long *inputCount, long *outputCount) override + { + *inputCount = _inputCount; + *outputCount = _outputCount; + return AsioStatus::OK; + } + + AsioStatus getLatencies(long *inputLatency, long *outputLatency) override + { + *inputLatency = _bufferFrames; + *outputLatency = _bufferFrames; + return AsioStatus::OK; + } + + AsioStatus getBufferSize( + long *minSize, long *maxSize, long *preferredSize, long *granularity) override + { + *minSize = *maxSize = *preferredSize = _bufferFrames; + *granularity = 0; + return AsioStatus::OK; + } + + AsioStatus canSampleRate(double sampleRate) override + { + return sampleRate >= 8000.0 && sampleRate <= 192000.0 ? + AsioStatus::OK : AsioStatus::NoClock; + } + + AsioStatus getSampleRate(double *sampleRate) override + { + *sampleRate = _sampleRate; + return AsioStatus::OK; + } + + AsioStatus setSampleRate(double sampleRate) override + { + if (sampleRate == _sampleRate) { + return AsioStatus::OK; + } + + if (_running || canSampleRate(sampleRate) != AsioStatus::OK) { + return AsioStatus::NoClock; + } + + _sampleRate = sampleRate; + + if (_callbacks.sampleRateDidChange) { + _callbacks.sampleRateDidChange(sampleRate); + } + + return AsioStatus::OK; + } + + AsioStatus getClockSources(AsioClockSource *clocks, long *count) override + { + if (!clocks || !count || *count < 1) { + return AsioStatus::InvalidParameter; + } + + clocks[0].index = 0; + clocks[0].channel = 0; + clocks[0].group = 0; + clocks[0].isCurrentSource = AsioBool::True; + strcpy_s(clocks[0].name, 32, "Internal"); + *count = 1; + return AsioStatus::OK; + } + + AsioStatus setClockSource(long index) override + { + return index == 0 ? AsioStatus::OK : AsioStatus::InvalidParameter; + } + + AsioStatus getSamplePosition(int64_t *pos, int64_t *timestamp) override + { + *pos = _samplePosition.load(); + // ASIO timestamps are nanoseconds; FILETIME is 100 ns units. + *timestamp = fileTimeNow() * 100; + return AsioStatus::OK; + } + + AsioStatus getChannelInfo(AsioChannelInfo *info) override + { + bool isInput = info->isInput == AsioBool::True; + long limit = isInput ? _inputCount : _outputCount; + + if (info->index < 0 || info->index >= limit) { + return AsioStatus::InvalidParameter; + } + + info->isActive = _active ? AsioBool::True : AsioBool::False; + info->group = 0; + info->sampleType = Int32LSB; + sprintf_s(info->name, 32, "Clock %s %ld", isInput ? "In" : "Out", info->index + 1); + return AsioStatus::OK; + } + + AsioStatus createBuffers( + AsioBufferInfo *infos, long channelCount, long bufferSize, + AsioCallbacks *callbacks) override + { + if (_active) { + disposeBuffers(); + } + + if (!callbacks || !callbacks->tick) { + return AsioStatus::InvalidParameter; + } + + if (bufferSize < 16 || bufferSize > 65536) { + return AsioStatus::InvalidMode; + } + + for (long i = 0; i < channelCount; ++i) { + long limit = infos[i].isInput == AsioBool::True ? _inputCount : _outputCount; + + if (infos[i].index < 0 || infos[i].index >= limit) { + return AsioStatus::InvalidParameter; + } + } + + _bufferFrames = bufferSize; + _callbacks = *callbacks; + + for (long i = 0; i < channelCount; ++i) { + for (int half = 0; half < 2; ++half) { + void *memory = calloc((size_t)bufferSize, sizeof(int32_t)); + + if (!memory) { + disposeBuffers(); + return AsioStatus::NoMemory; + } + + infos[i].asioBuffers[half] = memory; + _buffers.push_back(memory); + } + } + + _active = true; + return AsioStatus::OK; + } + + AsioStatus disposeBuffers() override + { + stop(); + + for (void *buffer : _buffers) { + free(buffer); + } + + _buffers.clear(); + _callbacks = {}; + _active = false; + return AsioStatus::OK; + } + + AsioStatus controlPanel() override + { + return AsioStatus::OK; + } + + AsioStatus future(long selector, void *opt) override + { + if (selector == SarTestClock::kStatsSelector && opt) { + auto *stats = (SarTestClock::ClockStats *)opt; + + if (stats->size < sizeof(SarTestClock::ClockStats)) { + return AsioStatus::InvalidParameter; + } + + stats->running = _running ? 1 : 0; + stats->ticks = _ticks.load(); + stats->lateTicks = _lateTicks.load(); + stats->maxLatenessMs = _maxLatenessMs.load(); + stats->periodMs = _bufferFrames * 1000.0 / _sampleRate; + stats->sampleRate = _sampleRate; + stats->bufferFrames = (uint32_t)_bufferFrames; + stats->reserved = 0; + return AsioStatus::OK; + } + + return AsioStatus::NotPresent; + } + + AsioStatus outputReady() override + { + return AsioStatus::NotPresent; + } + +private: + void tickThread() + { + SetThreadPriority(GetCurrentThread(), THREAD_PRIORITY_TIME_CRITICAL); + timeBeginPeriod(1); + + HANDLE timer = CreateWaitableTimerExW( + nullptr, nullptr, CREATE_WAITABLE_TIMER_HIGH_RESOLUTION, TIMER_ALL_ACCESS); + + if (!timer) { + timer = CreateWaitableTimerW(nullptr, TRUE, nullptr); + } + + const double periodMs = _bufferFrames * 1000.0 / _sampleRate; + const int64_t period100ns = (int64_t)(_bufferFrames * 10000000.0 / _sampleRate + 0.5); + const DWORD waitTimeoutMs = (DWORD)(periodMs * 4.0 + 50.0); + int64_t origin = fileTimeNow(); + long bufferIndex = 0; + HANDLE handles[2] = { _stopEvent, timer }; + + for (uint64_t n = 1; _running; ++n) { + LARGE_INTEGER due; + + due.QuadPart = origin + (int64_t)n * period100ns; + SetWaitableTimer(timer, &due, 0, nullptr, nullptr, FALSE); + + DWORD wait = WaitForMultipleObjects(2, handles, FALSE, waitTimeoutMs); + + if (wait == WAIT_OBJECT_0 || !_running) { + break; + } + + double latenessMs = (double)(fileTimeNow() - due.QuadPart) / 10000.0; + + if (latenessMs > periodMs) { + _lateTicks++; + } + + if (latenessMs > _maxLatenessMs.load()) { + _maxLatenessMs = latenessMs; + } + + // Far behind (suspended VM, debugger): resynchronize the schedule + // rather than delivering a burst of catch-up callbacks. + if (latenessMs > periodMs * 8.0) { + origin = fileTimeNow() - (int64_t)n * period100ns; + } + + _samplePosition += _bufferFrames; + _callbacks.tick(bufferIndex, AsioBool::True); + bufferIndex ^= 1; + _ticks++; + } + + CloseHandle(timer); + timeEndPeriod(1); + } + + std::atomic _refs{ 1 }; + std::string _error; + double _sampleRate = 48000.0; + long _bufferFrames = 480; + long _inputCount = 2; + long _outputCount = 2; + bool _active = false; + std::atomic _running{ false }; + AsioCallbacks _callbacks = {}; + std::vector _buffers; + std::thread _thread; + HANDLE _stopEvent = nullptr; + std::atomic _samplePosition{ 0 }; + std::atomic _ticks{ 0 }; + std::atomic _lateTicks{ 0 }; + std::atomic _maxLatenessMs{ 0.0 }; +}; + +class ClassFactory: public IClassFactory +{ +public: + HRESULT STDMETHODCALLTYPE QueryInterface(REFIID riid, void **ppv) override + { + if (!ppv) { + return E_POINTER; + } + + if (riid == IID_IUnknown || riid == IID_IClassFactory) { + *ppv = static_cast(this); + return S_OK; + } + + *ppv = nullptr; + return E_NOINTERFACE; + } + + // Static lifetime; reference counting is a no-op. + ULONG STDMETHODCALLTYPE AddRef() override { return 2; } + ULONG STDMETHODCALLTYPE Release() override { return 1; } + + HRESULT STDMETHODCALLTYPE CreateInstance( + IUnknown *outer, REFIID riid, void **ppv) override + { + if (!ppv) { + return E_POINTER; + } + + *ppv = nullptr; + + if (outer) { + return CLASS_E_NOAGGREGATION; + } + + SoftwareClock *clock = new (std::nothrow) SoftwareClock(); + + if (!clock) { + return E_OUTOFMEMORY; + } + + HRESULT hr = clock->QueryInterface(riid, ppv); + + clock->Release(); + return hr; + } + + HRESULT STDMETHODCALLTYPE LockServer(BOOL lock) override + { + if (lock) { + gLockCount++; + } else { + gLockCount--; + } + + return S_OK; + } +}; + +ClassFactory gFactory; + +LSTATUS setRegistryString( + HKEY root, const wchar_t *key, const wchar_t *name, const wchar_t *value) +{ + HKEY handle = nullptr; + LSTATUS status = RegCreateKeyExW( + root, key, 0, nullptr, 0, KEY_WRITE, nullptr, &handle, nullptr); + + if (status != ERROR_SUCCESS) { + return status; + } + + status = RegSetValueExW( + handle, name, 0, REG_SZ, (const BYTE *)value, + (DWORD)((wcslen(value) + 1) * sizeof(wchar_t))); + RegCloseKey(handle); + return status; +} + +} // namespace + +extern "C" BOOL WINAPI DllMain(HINSTANCE instance, DWORD reason, LPVOID) +{ + if (reason == DLL_PROCESS_ATTACH) { + gModule = instance; + DisableThreadLibraryCalls(instance); + } + + return TRUE; +} + +STDAPI DllGetClassObject(REFCLSID rclsid, REFIID riid, LPVOID *ppv) +{ + if (!ppv) { + return E_POINTER; + } + + if (rclsid != kClsid) { + *ppv = nullptr; + return CLASS_E_CLASSNOTAVAILABLE; + } + + return gFactory.QueryInterface(riid, ppv); +} + +STDAPI DllCanUnloadNow() +{ + return gObjectCount == 0 && gLockCount == 0 ? S_OK : S_FALSE; +} + +STDAPI DllRegisterServer() +{ + wchar_t path[MAX_PATH] = {}; + + if (!GetModuleFileNameW(gModule, path, MAX_PATH)) { + return E_FAIL; + } + + if (setRegistryString(HKEY_CLASSES_ROOT, kClsidKey, nullptr, SAR_TEST_CLOCK_NAME) != ERROR_SUCCESS || + setRegistryString(HKEY_CLASSES_ROOT, kInprocKey, nullptr, path) != ERROR_SUCCESS || + setRegistryString(HKEY_CLASSES_ROOT, kInprocKey, L"ThreadingModel", L"Both") != ERROR_SUCCESS) { + return SELFREG_E_CLASS; + } + + if (setRegistryString(HKEY_LOCAL_MACHINE, kAsioKey, L"CLSID", SAR_TEST_CLOCK_CLSID_STR) != ERROR_SUCCESS || + setRegistryString(HKEY_LOCAL_MACHINE, kAsioKey, L"Description", SAR_TEST_CLOCK_NAME) != ERROR_SUCCESS) { + return SELFREG_E_CLASS; + } + + return S_OK; +} + +STDAPI DllUnregisterServer() +{ + RegDeleteTreeW(HKEY_LOCAL_MACHINE, kAsioKey); + RegDeleteTreeW(HKEY_CLASSES_ROOT, kClsidKey); + return S_OK; +} diff --git a/SarTestClock/SarTestClock.def b/SarTestClock/SarTestClock.def new file mode 100644 index 0000000..b5cd2d1 --- /dev/null +++ b/SarTestClock/SarTestClock.def @@ -0,0 +1,7 @@ +LIBRARY + +EXPORTS + DllCanUnloadNow PRIVATE + DllGetClassObject PRIVATE + DllRegisterServer PRIVATE + DllUnregisterServer PRIVATE diff --git a/SarTestClock/SarTestClock.vcxproj b/SarTestClock/SarTestClock.vcxproj new file mode 100644 index 0000000..e3959e0 --- /dev/null +++ b/SarTestClock/SarTestClock.vcxproj @@ -0,0 +1,107 @@ + + + + + Debug + Win32 + + + Release + Win32 + + + Debug + x64 + + + Release + x64 + + + + {9E5D2B7C-3A1F-4C8E-A2D4-6B7C8D9E0F1A} + Win32Proj + SarTestClock + 10.0.22621.0 + + + + DynamicLibrary + true + v143 + Unicode + + + DynamicLibrary + false + v143 + true + Unicode + + + + + + + + + + + + $(VC_IncludePath);$(WindowsSDK_IncludePath);..\SarAsio + + + true + + + false + + + + NotUsing + Level3 + true + stdcpp17 + _WINDOWS;_USRDLL;%(PreprocessorDefinitions) + + + Windows + true + ole32.lib;advapi32.lib;winmm.lib;uuid.lib;kernel32.lib;user32.lib;%(AdditionalDependencies) + SarTestClock.def + + + + + Disabled + _DEBUG;%(PreprocessorDefinitions) + MultiThreadedDebug + + + + + MaxSpeed + true + true + NDEBUG;%(PreprocessorDefinitions) + MultiThreaded + + + true + true + + + + + + + + + + + + + + + + diff --git a/SarTestClock/clockstats.h b/SarTestClock/clockstats.h new file mode 100644 index 0000000..3f89f9c --- /dev/null +++ b/SarTestClock/clockstats.h @@ -0,0 +1,49 @@ +// SynchronousAudioRouter +// Copyright (C) 2026 Mackenzie Straight +// +// This program is free software: you can redistribute it and/or modify +// it under the terms of the GNU General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// This program is distributed in the hope that it will be useful, +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU General Public License for more details. +// +// You should have received a copy of the GNU General Public License +// along with SynchronousAudioRouter. If not, see . + +#ifndef _SAR_TEST_CLOCK_STATS_H +#define _SAR_TEST_CLOCK_STATS_H + +#include + +// Shared between SarTestClock.dll and SarTest.exe. +namespace SarTestClock { + +// CLSID and ASIO registry name of the software clock driver. The string form +// must match what DllRegisterServer writes, because SarAsio compares it +// textually against the driverClsid in its configuration. +#define SAR_TEST_CLOCK_CLSID_STR L"{7A3C9E12-4B5D-4F6E-8A1B-2C3D4E5F6A7B}" +#define SAR_TEST_CLOCK_NAME L"SAR Test Clock" + +// IASIO::future selector that fills a ClockStats. SarAsio forwards unknown +// selectors to its inner driver, so a host reaches the clock through it. +const long kStatsSelector = 0x53415254; // 'SART' + +struct ClockStats +{ + uint32_t size; // sizeof(ClockStats), set by the caller + uint32_t running; + uint64_t ticks; + uint64_t lateTicks; // ticks delivered more than one period late + double maxLatenessMs; + double periodMs; + double sampleRate; + uint32_t bufferFrames; + uint32_t reserved; +}; + +} // namespace SarTestClock +#endif // _SAR_TEST_CLOCK_STATS_H diff --git a/SynchronousAudioRouter.sln b/SynchronousAudioRouter.sln index 0e3af5f..5852bb6 100644 --- a/SynchronousAudioRouter.sln +++ b/SynchronousAudioRouter.sln @@ -20,6 +20,10 @@ Project("{8BC9CEB8-8B4A-11D0-8D11-00A0C91BC942}") = "SarInstallerActions", "SarI EndProject Project("{8BC9CEB8-8B4A-11D0-8D11-00A0C91BC942}") = "SarConfigure", "SarConfigure\SarConfigure.vcxproj", "{E298CAAC-9EBF-4DF9-9161-9DD48199E31D}" EndProject +Project("{8BC9CEB8-8B4A-11D0-8D11-00A0C91BC942}") = "SarTest", "SarTest\SarTest.vcxproj", "{3C8F1E2A-7D4B-4A9E-B5C6-1D2E3F4A5B6C}" +EndProject +Project("{8BC9CEB8-8B4A-11D0-8D11-00A0C91BC942}") = "SarTestClock", "SarTestClock\SarTestClock.vcxproj", "{9E5D2B7C-3A1F-4C8E-A2D4-6B7C8D9E0F1A}" +EndProject Global GlobalSection(SolutionConfigurationPlatforms) = preSolution Debug|ARM = Debug|ARM @@ -107,6 +111,30 @@ Global {E298CAAC-9EBF-4DF9-9161-9DD48199E31D}.Release|x64.Build.0 = Release|x64 {E298CAAC-9EBF-4DF9-9161-9DD48199E31D}.Release|x86.ActiveCfg = Release|Win32 {E298CAAC-9EBF-4DF9-9161-9DD48199E31D}.Release|x86.Build.0 = Release|Win32 + {3C8F1E2A-7D4B-4A9E-B5C6-1D2E3F4A5B6C}.Debug|ARM.ActiveCfg = Debug|Win32 + {3C8F1E2A-7D4B-4A9E-B5C6-1D2E3F4A5B6C}.Debug|ARM64.ActiveCfg = Debug|Win32 + {3C8F1E2A-7D4B-4A9E-B5C6-1D2E3F4A5B6C}.Debug|x64.ActiveCfg = Debug|x64 + {3C8F1E2A-7D4B-4A9E-B5C6-1D2E3F4A5B6C}.Debug|x64.Build.0 = Debug|x64 + {3C8F1E2A-7D4B-4A9E-B5C6-1D2E3F4A5B6C}.Debug|x86.ActiveCfg = Debug|Win32 + {3C8F1E2A-7D4B-4A9E-B5C6-1D2E3F4A5B6C}.Debug|x86.Build.0 = Debug|Win32 + {3C8F1E2A-7D4B-4A9E-B5C6-1D2E3F4A5B6C}.Release|ARM.ActiveCfg = Release|Win32 + {3C8F1E2A-7D4B-4A9E-B5C6-1D2E3F4A5B6C}.Release|ARM64.ActiveCfg = Release|Win32 + {3C8F1E2A-7D4B-4A9E-B5C6-1D2E3F4A5B6C}.Release|x64.ActiveCfg = Release|x64 + {3C8F1E2A-7D4B-4A9E-B5C6-1D2E3F4A5B6C}.Release|x64.Build.0 = Release|x64 + {3C8F1E2A-7D4B-4A9E-B5C6-1D2E3F4A5B6C}.Release|x86.ActiveCfg = Release|Win32 + {3C8F1E2A-7D4B-4A9E-B5C6-1D2E3F4A5B6C}.Release|x86.Build.0 = Release|Win32 + {9E5D2B7C-3A1F-4C8E-A2D4-6B7C8D9E0F1A}.Debug|ARM.ActiveCfg = Debug|Win32 + {9E5D2B7C-3A1F-4C8E-A2D4-6B7C8D9E0F1A}.Debug|ARM64.ActiveCfg = Debug|Win32 + {9E5D2B7C-3A1F-4C8E-A2D4-6B7C8D9E0F1A}.Debug|x64.ActiveCfg = Debug|x64 + {9E5D2B7C-3A1F-4C8E-A2D4-6B7C8D9E0F1A}.Debug|x64.Build.0 = Debug|x64 + {9E5D2B7C-3A1F-4C8E-A2D4-6B7C8D9E0F1A}.Debug|x86.ActiveCfg = Debug|Win32 + {9E5D2B7C-3A1F-4C8E-A2D4-6B7C8D9E0F1A}.Debug|x86.Build.0 = Debug|Win32 + {9E5D2B7C-3A1F-4C8E-A2D4-6B7C8D9E0F1A}.Release|ARM.ActiveCfg = Release|Win32 + {9E5D2B7C-3A1F-4C8E-A2D4-6B7C8D9E0F1A}.Release|ARM64.ActiveCfg = Release|Win32 + {9E5D2B7C-3A1F-4C8E-A2D4-6B7C8D9E0F1A}.Release|x64.ActiveCfg = Release|x64 + {9E5D2B7C-3A1F-4C8E-A2D4-6B7C8D9E0F1A}.Release|x64.Build.0 = Release|x64 + {9E5D2B7C-3A1F-4C8E-A2D4-6B7C8D9E0F1A}.Release|x86.ActiveCfg = Release|Win32 + {9E5D2B7C-3A1F-4C8E-A2D4-6B7C8D9E0F1A}.Release|x86.Build.0 = Release|Win32 EndGlobalSection GlobalSection(SolutionProperties) = preSolution HideSolutionNode = FALSE diff --git a/tools/test/Invoke-SarTest.ps1 b/tools/test/Invoke-SarTest.ps1 new file mode 100644 index 0000000..d2c769f --- /dev/null +++ b/tools/test/Invoke-SarTest.ps1 @@ -0,0 +1,192 @@ +<# +.SYNOPSIS + Runs the SynchronousAudioRouter test harness on this machine. + +.DESCRIPTION + Installs the driver package, the software clock and the SarAsio test + configuration, then exercises endpoint creation and audio loopback across + a matrix of endpoint counts, plus a scenario where the ASIO host is killed + while WASAPI clients are streaming. Writes one JSON and one log per + scenario to -ResultsDir, a summary.json, and copies the SarAsio logs. + + Intended for a disposable VM with test signing enabled (see README.md). + Must run elevated. Exit code 0 when every scenario passed, 1 otherwise, + 2 when a scenario hung (SarTest.exe did not exit in time - usually a + kernel-side hang; look at the scenario log's last line). + +.EXAMPLE + .\Invoke-SarTest.ps1 -PackageDir C:\sar\driver -ToolsDir C:\sar\tools -CertPath C:\sar\test.cer +#> +[CmdletBinding()] +param( + # Directory with SynchronousAudioRouter.sys/.inf/.cat (the CI driver package). + [Parameter(Mandatory)] [string]$PackageDir, + # Directory with SarTest.exe, SarTestClock.dll and SarAsio.dll (the CI usermode package). + [Parameter(Mandatory)] [string]$ToolsDir, + # Certificate (.cer) the package was test-signed with; imported into Root and TrustedPublisher. + [string]$CertPath, + [string]$ResultsDir = (Join-Path (Get-Location) 'sartest-results'), + [int[]]$EndpointCounts = @(1, 4, 8, 16), + [int]$Channels = 2, + [int]$Iterations = 3, + [double]$Duration = 5, + # Per-scenario wall clock limit before it is declared hung. + [int]$TimeoutSeconds = 600, + [switch]$SkipInstall, + [switch]$SkipKillTest +) + +$ErrorActionPreference = 'Stop' + +$identity = [Security.Principal.WindowsIdentity]::GetCurrent() +$principal = New-Object Security.Principal.WindowsPrincipal $identity +if (-not $principal.IsInRole([Security.Principal.WindowsBuiltInRole]::Administrator)) { + throw 'Invoke-SarTest.ps1 must run elevated.' +} + +$sarTest = Join-Path $ToolsDir 'SarTest.exe' +$sarAsio = Join-Path $ToolsDir 'SarAsio.dll' +$clock = Join-Path $ToolsDir 'SarTestClock.dll' +$inf = Join-Path $PackageDir 'SynchronousAudioRouter.inf' +foreach ($required in $sarTest, $sarAsio, $clock) { + if (-not (Test-Path $required)) { throw "Missing: $required" } +} +if (-not $SkipInstall -and -not (Test-Path $inf)) { throw "Missing: $inf" } + +New-Item -ItemType Directory -Force -Path $ResultsDir | Out-Null +$ResultsDir = (Resolve-Path $ResultsDir).Path +$summary = [ordered]@{ + started = (Get-Date).ToString('o') + machine = $env:COMPUTERNAME + os = (Get-CimInstance Win32_OperatingSystem).Version + scenarios = @() +} + +# Runs one SarTest scenario, capturing stdout and the results JSON. +function Invoke-Scenario { + param([string]$Name, [string[]]$Arguments, [int]$Timeout = $TimeoutSeconds) + + $log = Join-Path $ResultsDir "$Name.log" + $json = Join-Path $ResultsDir "$Name.json" + $argList = @($Arguments) + @('--results', "`"$json`"") + Write-Host "==> $Name : SarTest $($argList -join ' ')" + + $proc = Start-Process -FilePath $sarTest -ArgumentList $argList -NoNewWindow -PassThru ` + -RedirectStandardOutput $log + $exited = $proc.WaitForExit($Timeout * 1000) + $record = [ordered]@{ name = $Name; arguments = ($argList -join ' '); log = $log; results = $json } + + if (-not $exited) { + Write-Warning "$Name did not exit within $Timeout s - treating as hung" + try { $proc.Kill() } catch { } + $record.outcome = 'hung' + $record.exitCode = $null + if (Test-Path $log) { $record.lastLine = (Get-Content $log -Tail 1) } + } else { + $record.exitCode = $proc.ExitCode + $record.outcome = if ($proc.ExitCode -eq 0) { 'passed' } else { 'failed' } + } + + if (Test-Path $json) { + try { $record.summary = (Get-Content $json -Raw | ConvertFrom-Json) } catch { } + } + + Write-Host " -> $($record.outcome)" + return $record +} + +# Windows Server images ship with the audio stack disabled. +foreach ($service in 'AudioEndpointBuilder', 'Audiosrv') { + try { + Set-Service -Name $service -StartupType Automatic + Start-Service -Name $service + } catch { + Write-Warning "Couldn't start $service : $_" + } +} + +if (-not $SkipInstall) { + if ($CertPath) { + Write-Host "==> Trusting $CertPath" + Import-Certificate -FilePath $CertPath -CertStoreLocation Cert:\LocalMachine\Root | Out-Null + Import-Certificate -FilePath $CertPath -CertStoreLocation Cert:\LocalMachine\TrustedPublisher | Out-Null + } + + $install = Invoke-Scenario 'install' @('install', '--inf', "`"$inf`"", '--clock', "`"$clock`"", + '--endpoints', $EndpointCounts[0], '--channels', $Channels) + $summary.scenarios += $install + + if ($install.outcome -ne 'passed') { + $summary.finished = (Get-Date).ToString('o') + $summary | ConvertTo-Json -Depth 8 | Set-Content (Join-Path $ResultsDir 'summary.json') + throw 'Installation failed; see install.log' + } +} else { + # Still make sure the clock is registered and the configuration is ours. + $summary.scenarios += Invoke-Scenario 'install' @('install', '--clock', "`"$clock`"", + '--endpoints', $EndpointCounts[0], '--channels', $Channels) +} + +$common = @('--sarasio', "`"$sarAsio`"", '--channels', $Channels) + +foreach ($count in $EndpointCounts) { + $summary.scenarios += Invoke-Scenario "run-${count}x${Channels}" ( + @('run', '--endpoints', $count, '--iterations', $Iterations, '--duration', $Duration) + $common) +} + +if (-not $SkipKillTest) { + # Kill the ASIO host while WASAPI clients are streaming, then check that a + # fresh host can still create endpoints afterwards. + $count = $EndpointCounts[-1] + $hostLog = Join-Path $ResultsDir 'kill-host.log' + $hostJson = Join-Path $ResultsDir 'kill-host.json' + Write-Host "==> kill-host : starting a host with $count endpoint pairs" + $hostProc = Start-Process -FilePath $sarTest -NoNewWindow -PassThru -RedirectStandardOutput $hostLog ` + -ArgumentList (@('host', '--endpoints', $count, '--duration', 120, '--results', "`"$hostJson`"") + $common) + Start-Sleep -Seconds 5 + + $wasapiLog = Join-Path $ResultsDir 'kill-host-wasapi.log' + $wasapiJson = Join-Path $ResultsDir 'kill-host-wasapi.json' + $wasapiProc = Start-Process -FilePath $sarTest -NoNewWindow -PassThru -RedirectStandardOutput $wasapiLog ` + -ArgumentList @('wasapi', '--endpoints', $count, '--channels', $Channels, '--duration', 15, + '--expect-invalidation', '--results', "`"$wasapiJson`"") + Start-Sleep -Seconds 5 + + Write-Host "==> kill-host : killing the host mid-stream" + try { Stop-Process -Id $hostProc.Id -Force } catch { } + $hostExited = $hostProc.WaitForExit(60000) + $wasapiExited = $wasapiProc.WaitForExit(60000) + if (-not $wasapiExited) { try { $wasapiProc.Kill() } catch { } } + + $summary.scenarios += [ordered]@{ + name = 'kill-host' + outcome = if ($hostExited -and $wasapiExited) { 'passed' } else { 'hung' } + hostExited = $hostExited + wasapiExited = $wasapiExited + wasapiExitCode = if ($wasapiExited) { $wasapiProc.ExitCode } else { $null } + log = $hostLog + wasapiLog = $wasapiLog + } + + $summary.scenarios += Invoke-Scenario 'recovery-after-kill' ( + @('run', '--endpoints', $count, '--iterations', 1, '--duration', $Duration) + $common) +} + +$sarLogs = Join-Path $env:APPDATA 'SynchronousAudioRouter\logs' +if (Test-Path $sarLogs) { + $dest = Join-Path $ResultsDir 'sarasio-logs' + New-Item -ItemType Directory -Force -Path $dest | Out-Null + Copy-Item (Join-Path $sarLogs '*') $dest -Force -ErrorAction SilentlyContinue +} + +$summary.finished = (Get-Date).ToString('o') +$outcomes = $summary.scenarios | ForEach-Object { $_.outcome } +$summary.passed = -not ($outcomes | Where-Object { $_ -ne 'passed' }) +$summary | ConvertTo-Json -Depth 8 | Set-Content (Join-Path $ResultsDir 'summary.json') + +Write-Host '' +Write-Host 'Scenario summary:' +$summary.scenarios | ForEach-Object { Write-Host (" {0,-24} {1}" -f $_.name, $_.outcome) } + +if ($outcomes -contains 'hung') { exit 2 } +if ($summary.passed) { exit 0 } else { exit 1 } diff --git a/tools/test/README.md b/tools/test/README.md new file mode 100644 index 0000000..963086f --- /dev/null +++ b/tools/test/README.md @@ -0,0 +1,118 @@ +# SAR test harness + +`SarTest.exe` and `SarTestClock.dll` exercise SynchronousAudioRouter end to +end without audio hardware or a DAW: a headless ASIO host drives SarAsio on a +software clock, WASAPI clients stream a known signal through every endpoint, +and the loopback is verified sample for sample. `Invoke-SarTest.ps1` runs a +scenario matrix and collects results. Nothing here needs a person at the +keyboard once the machine is prepared. + +Both binaries are built by the `usermode` CI job and shipped in the +`sar-asio-` artifact next to `SarAsio.dll`, with this directory +under `test/`. + +## How it works + +`SarTestClock.dll` is a minimal ASIO driver. It exposes two dummy input and +two dummy output channels and delivers `bufferSwitch` callbacks from a timer +thread every 480 frames at 48 kHz (10 ms, the audio engine's period). SarAsio +wraps it exactly like a real interface, so `SarAsioWrapper::start()` goes +through the full `SarClient` path: open the control device, set the buffer +layout, create the endpoints, poll the notification handle queue. + +`SarTest.exe host` loads `SarAsio.dll` directly through `DllGetClassObject` +(no COM registration needed), creates buffers for every channel, and on each +callback copies ASIO input *k* to ASIO output *k*. SarAsio presents playback +endpoints as ASIO inputs and recording endpoints as ASIO outputs in +configuration order, so with the layout the harness writes ("SarTest Out n" +paired with "SarTest In n", same channel count) that copy loops each playback +endpoint back to its recording twin, channel for channel. + +`SarTest.exe wasapi` opens every endpoint of the layout in shared mode. +Render streams emit a signal where each sample encodes its channel id and a +per-frame sequence number, chosen so it survives the engine's float/int32 +conversions exactly. Capture streams decode it and count valid frames, +silence, sequence discontinuities and frames carrying the wrong channel id. +A capture stream passes when it received the signal, never saw a wrong +channel, and at least 90% of the frames after the initial silence were +contiguous (`--min-valid`, `--max-discontinuities` tune this). + +`SarTest.exe run` does both in one process and repeats for `--iterations`, +which is the "start the DAW, stop the DAW" cycle that creates and tears down +all endpoints each time. A watchdog thread logs `HANG: IASIO:: has not +returned after N ms` when a driver call exceeds `--phase-timeout` (30 s), so +a kernel-side deadlock shows up in the log even though the process cannot +recover from it. + +## Commands + +``` +SarTest install --inf [--endpoints N] [--channels C] +SarTest uninstall [--remove-device] +SarTest config [--endpoints N] [--channels C] [--out ] +SarTest host [--iterations K] [--duration S] +SarTest wasapi [--duration S] [--wait S] [--expect-invalidation] +SarTest run [--iterations K] [--duration S] +``` + +`install` creates the SAR software device node if needed, installs the +driver package from the INF (64-bit SarTest only, elevated), registers the +clock under `HKLM\SOFTWARE\ASIO` and writes +`%APPDATA%\SynchronousAudioRouter\default.json` for the layout. `host` and +`run` rewrite that file for their own layout, backing up an existing one to +`default.json.sartest-backup` the first time; pass `--keep-config` to leave +it alone. Every command writes a JSON report to `--results` +(`sartest-results.json` by default). Exit codes: 0 pass, 1 setup error, +2 test failure. + +Layout options are shared by all commands: `--endpoints N` is the number of +playback/recording pairs (default 2), `--channels C` the channels per +endpoint (default 2). The reporter's 32-channel setup is roughly +`--endpoints 16 --channels 2` or `--endpoints 4 --channels 8`. + +The clock reads `SAR_TEST_CLOCK_RATE`, `SAR_TEST_CLOCK_FRAMES`, +`SAR_TEST_CLOCK_INPUTS` and `SAR_TEST_CLOCK_OUTPUTS` from the environment. +Set `--no-sarasio-log` to stop SarAsio from logging to +`%APPDATA%\SynchronousAudioRouter\logs`. + +## Preparing a test machine + +Use a disposable VM. A driver bug takes the whole machine down, and the +scripts assume they may overwrite the SAR configuration. + +1. Windows 10 or 11 x64. On Server, `Invoke-SarTest.ps1` enables the audio + services itself. +2. Enable test signing and reboot: `bcdedit /set testsigning on`. +3. Test-sign the CI package's `.sys` and `.cat` with a self-signed + certificate, and pass that certificate's `.cer` as `-CertPath` so the + script installs it into the Root and TrustedPublisher stores. Without it + the non-interactive driver install is refused. +4. Optionally enable Driver Verifier for the driver, including deadlock + detection, so a lock-order bug bugchecks with the exact cycle instead of + hanging: `verifier /flags 0x20 /driver SynchronousAudioRouter.sys`. +5. Enable kernel memory dumps so a bugcheck leaves `MEMORY.DMP` behind. +6. Take a checkpoint. Restore it before every run. + +Then, elevated: + +``` +.\Invoke-SarTest.ps1 -PackageDir -ToolsDir -CertPath test.cer +``` + +The script runs `run` for 1, 4, 8 and 16 endpoint pairs with three +start/stop iterations each, then a scenario that kills the host while WASAPI +clients are streaming and checks that a new host can still create endpoints +afterwards. Results land in `sartest-results\`: one `.log` and `.json` per +scenario, `summary.json`, and the SarAsio logs. Exit code 2 means a scenario +never exited, which is what a kernel hang looks like from user mode; the +scenario log's last line names the driver call that never returned. + +## Limitations + +- Shared-mode WASAPI only. Exclusive mode and 32-bit clients are not covered + yet (the x86 `SarTest.exe` builds and runs `host`/`wasapi`/`run`, but + driver installation must use the x64 binary). +- Timing comes from a Windows timer, so a loaded VM will show some + discontinuities. They are reported, not failed on, unless + `--max-discontinuities` is set. +- Application routing (the registry filter) is not exercised. From ef879304e79c7621d183aa1e969096a72694f0a5 Mon Sep 17 00:00:00 2001 From: Mack Straight Date: Sun, 13 Sep 2026 06:32:26 -0400 Subject: [PATCH 03/14] test: log fatal errors and use certutil for the test certificate 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 Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp --- tools/test/Invoke-SarTest.ps1 | 15 +++++++++++++-- 1 file changed, 13 insertions(+), 2 deletions(-) diff --git a/tools/test/Invoke-SarTest.ps1 b/tools/test/Invoke-SarTest.ps1 index d2c769f..9e8f2f4 100644 --- a/tools/test/Invoke-SarTest.ps1 +++ b/tools/test/Invoke-SarTest.ps1 @@ -38,6 +38,15 @@ param( $ErrorActionPreference = 'Stop' +# Any terminating error ends up in the log with its location, and the +# script exits non-zero instead of letting the exception escape the caller's +# output redirection. +trap { + Write-Host "FATAL: $_" + Write-Host $_.ScriptStackTrace + exit 1 +} + $identity = [Security.Principal.WindowsIdentity]::GetCurrent() $principal = New-Object Security.Principal.WindowsPrincipal $identity if (-not $principal.IsInRole([Security.Principal.WindowsBuiltInRole]::Administrator)) { @@ -108,8 +117,10 @@ foreach ($service in 'AudioEndpointBuilder', 'Audiosrv') { if (-not $SkipInstall) { if ($CertPath) { Write-Host "==> Trusting $CertPath" - Import-Certificate -FilePath $CertPath -CertStoreLocation Cert:\LocalMachine\Root | Out-Null - Import-Certificate -FilePath $CertPath -CertStoreLocation Cert:\LocalMachine\TrustedPublisher | Out-Null + foreach ($store in 'Root', 'TrustedPublisher') { + $out = & certutil.exe -addstore -f $store $CertPath 2>&1 + if ($LASTEXITCODE -ne 0) { throw "certutil -addstore $store failed: $($out -join ' ')" } + } } $install = Invoke-Scenario 'install' @('install', '--inf', "`"$inf`"", '--clock', "`"$clock`"", From acce743b66b7af763e303e946f5bf64f9fb415ac Mon Sep 17 00:00:00 2001 From: Mack Straight Date: Sun, 13 Sep 2026 06:34:17 -0400 Subject: [PATCH 04/14] test: read process exit codes reliably in Invoke-SarTest.ps1 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 Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp --- tools/test/Invoke-SarTest.ps1 | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/tools/test/Invoke-SarTest.ps1 b/tools/test/Invoke-SarTest.ps1 index 9e8f2f4..fdd9796 100644 --- a/tools/test/Invoke-SarTest.ps1 +++ b/tools/test/Invoke-SarTest.ps1 @@ -82,6 +82,8 @@ function Invoke-Scenario { $proc = Start-Process -FilePath $sarTest -ArgumentList $argList -NoNewWindow -PassThru ` -RedirectStandardOutput $log + # Without touching Handle first, ExitCode reads as null after WaitForExit. + $null = $proc.Handle $exited = $proc.WaitForExit($Timeout * 1000) $record = [ordered]@{ name = $Name; arguments = ($argList -join ' '); log = $log; results = $json } @@ -154,6 +156,7 @@ if (-not $SkipKillTest) { Write-Host "==> kill-host : starting a host with $count endpoint pairs" $hostProc = Start-Process -FilePath $sarTest -NoNewWindow -PassThru -RedirectStandardOutput $hostLog ` -ArgumentList (@('host', '--endpoints', $count, '--duration', 120, '--results', "`"$hostJson`"") + $common) + $null = $hostProc.Handle Start-Sleep -Seconds 5 $wasapiLog = Join-Path $ResultsDir 'kill-host-wasapi.log' @@ -161,6 +164,7 @@ if (-not $SkipKillTest) { $wasapiProc = Start-Process -FilePath $sarTest -NoNewWindow -PassThru -RedirectStandardOutput $wasapiLog ` -ArgumentList @('wasapi', '--endpoints', $count, '--channels', $Channels, '--duration', 15, '--expect-invalidation', '--results', "`"$wasapiJson`"") + $null = $wasapiProc.Handle Start-Sleep -Seconds 5 Write-Host "==> kill-host : killing the host mid-stream" From 3e6a34ae8186b421a34f641776606075d600b718 Mon Sep 17 00:00:00 2001 From: Mack Straight Date: Sun, 13 Sep 2026 14:46:21 -0400 Subject: [PATCH 05/14] test: settle and retry stream setup, classify undecodable frames 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) Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp --- SarTest/SarTest.cpp | 4 ++ SarTest/wasapi.cpp | 132 +++++++++++++++++++++++++++++++++++++------ SarTest/wasapi.h | 13 +++++ tools/test/README.md | 19 +++++-- 4 files changed, 148 insertions(+), 20 deletions(-) diff --git a/SarTest/SarTest.cpp b/SarTest/SarTest.cpp index 31f845c..e5caae0 100644 --- a/SarTest/SarTest.cpp +++ b/SarTest/SarTest.cpp @@ -53,6 +53,7 @@ int usage() " --registered (use the COM-registered SarAsio instead of a path)\n" " --wait S --wait-gone S --restart-delay MS --rate HZ\n" " --min-valid RATIO --max-discontinuities N\n" + " --settle S --setup-attempts N --max-transition FRAMES\n" "\n" "Exit codes: 0 pass, 1 setup or usage error, 2 test failure.\n"); return 1; @@ -99,6 +100,9 @@ WasapiOptions wasapiOptions(const Args& args, const EndpointLayout& layout) options.expectInvalidation = args.has(L"expect-invalidation"); options.minValidRatio = args.getDouble(L"min-valid", 0.9); options.maxDiscontinuities = args.getInt(L"max-discontinuities", -1); + options.settleSeconds = args.getDouble(L"settle", 2.0); + options.setupAttempts = args.getInt(L"setup-attempts", 4); + options.maxTransitionFrames = args.getInt(L"max-transition", 4800); return options; } diff --git a/SarTest/wasapi.cpp b/SarTest/wasapi.cpp index 46b4cb4..08b6425 100644 --- a/SarTest/wasapi.cpp +++ b/SarTest/wasapi.cpp @@ -199,10 +199,19 @@ void setUnityVolume(IMMDevice *device, IAudioClient *client) class Stream { public: - Stream(const EndpointLayout& layout, int pair, IMMDevice *device, bool isCapture) - : _device(device), _isCapture(isCapture) + Stream(const EndpointLayout& layout, int pair, IMMDevice *device, bool isCapture, + int setupAttempts) + : _device(device), _isCapture(isCapture), _setupAttempts(setupAttempts) { _device->AddRef(); + + LPWSTR id = nullptr; + + if (SUCCEEDED(_device->GetId(&id)) && id) { + _deviceId = id; + CoTaskMemFree(id); + } + _stats.isCapture = isCapture; _stats.name = narrow(isCapture ? layout.recordingName(pair) : layout.playbackName(pair)); @@ -246,10 +255,28 @@ class Stream { HRESULT hr = CoInitializeEx(nullptr, COINIT_MULTITHREADED); - if (_isCapture) { - captureLoop(); - } else { - renderLoop(); + for (int attempt = 1; ; ++attempt) { + _setupInvalidated = false; + + if (_isCapture) { + captureLoop(); + } else { + renderLoop(); + } + + if (!_setupInvalidated || attempt >= _setupAttempts || + WaitForSingleObject(_stopEvent, 500) == WAIT_OBJECT_0) { + break; + } + + _stats.setupRetries++; + logf("%s: retrying stream setup (attempt %d of %d)", + _stats.name.c_str(), attempt + 1, _setupAttempts); + refreshDevice(); + } + + if (_setupInvalidated) { + _stats.deviceInvalidated = true; } if (SUCCEEDED(hr)) { @@ -257,9 +284,29 @@ class Stream } } + // Re-resolves the endpoint by ID so a retry does not reuse a device + // object that belonged to the invalidated instance. + void refreshDevice() + { + ComPtr enumerator; + IMMDevice *fresh = nullptr; + + if (_deviceId.empty() || !createEnumerator(&enumerator)) { + return; + } + + if (SUCCEEDED(enumerator->GetDevice(_deviceId.c_str(), &fresh)) && fresh) { + _device->Release(); + _device = fresh; + } + } + bool fail(const char *stage, HRESULT hr) { - if (hr == AUDCLNT_E_DEVICE_INVALIDATED) { + if (hr == AUDCLNT_E_DEVICE_INVALIDATED && !_stats.started) { + _setupInvalidated = true; + logf("%s: device invalidated during %s (setup)", _stats.name.c_str(), stage); + } else if (hr == AUDCLNT_E_DEVICE_INVALIDATED) { _stats.deviceInvalidated = true; logf("%s: device invalidated during %s", _stats.name.c_str(), stage); } else { @@ -356,6 +403,7 @@ class Stream for (UINT32 f = 0; f < frames; ++f) { bool allZero = true, channelsOk = true, sequenceConsistent = true; uint32_t sequence = 0; + int32_t values[32] = {}; for (int c = 0; c < expectedChannels; ++c) { size_t index = (size_t)f * (size_t)channels + (size_t)c; @@ -367,6 +415,10 @@ class Stream k = ((const int32_t *)data)[index] >> 8; } + if (c < 32) { + values[c] = k; + } + if (k != 0) { allZero = false; } @@ -393,7 +445,29 @@ class Stream } if (!channelsOk || !sequenceConsistent) { - _stats.wrongChannelFrames++; + bool transition = _stats.validFrames == 0; + + if (transition) { + _stats.transitionFrames++; + } else { + _stats.wrongChannelFrames++; + } + + if (_stats.badFrameSamples.size() < 12) { + char buf[512]; + int len = sprintf_s(buf, "%s frame %lld (after %lld valid):", + transition ? "transition" : "corrupt", + _stats.framesProcessed + (long long)f, _stats.validFrames); + + for (int c = 0; c < expectedChannels && c < 32 && len > 0 && len < 480; ++c) { + len += sprintf_s(buf + len, sizeof(buf) - (size_t)len, + " %08X/%02X", (unsigned int)values[c], (unsigned int)_channelIds[(size_t)c]); + } + + _stats.badFrameSamples.push_back(buf); + logf("%s: %s", _stats.name.c_str(), buf); + } + continue; } @@ -636,6 +710,9 @@ class Stream uint32_t _sequence = 0; uint32_t _lastSequence = 0; bool _haveLastSequence = false; + std::wstring _deviceId; + int _setupAttempts = 1; + bool _setupInvalidated = false; HANDLE _stopEvent = nullptr; std::thread _thread; }; @@ -776,9 +853,19 @@ std::string StreamStats::toJson() const .setInt("discontinuities", discontinuities) .setInt("engineDiscontinuities", engineDiscontinuities) .setInt("wrongChannelFrames", wrongChannelFrames) + .setInt("transitionFrames", transitionFrames) + .setInt("setupRetries", setupRetries) .setInt("timeouts", timeouts) .setBool("passed", passed) .setString("failure", failure); + + std::vector bad; + + for (const auto& sample : badFrameSamples) { + bad.push_back(jsonString(sample)); + } + + o.setRaw("badFrames", jsonArray(bad)); return o.str(); } @@ -834,7 +921,12 @@ static void evaluate(StreamStats *s, const WasapiOptions& options) } if (s->wrongChannelFrames > 0) { - s->failure = "frames with the wrong channel id"; + s->failure = "corrupt frames after the signal locked in"; + return; + } + + if (s->transitionFrames > options.maxTransitionFrames) { + s->failure = "start-up transition too long"; return; } @@ -861,8 +953,15 @@ WasapiResult runWasapi(const WasapiOptions& options, const FoundEndpoints& endpo const EndpointLayout& layout = options.layout; for (int pair = 0; pair < layout.pairs; ++pair) { - streams.emplace_back(new Stream(layout, pair, endpoints.render[(size_t)pair], false)); - streams.emplace_back(new Stream(layout, pair, endpoints.capture[(size_t)pair], true)); + streams.emplace_back(new Stream( + layout, pair, endpoints.render[(size_t)pair], false, options.setupAttempts)); + streams.emplace_back(new Stream( + layout, pair, endpoints.capture[(size_t)pair], true, options.setupAttempts)); + } + + if (options.settleSeconds > 0) { + logf("Letting the endpoints settle for %.1f s", options.settleSeconds); + Sleep((DWORD)(options.settleSeconds * 1000.0)); } for (auto& stream : streams) { @@ -893,14 +992,15 @@ WasapiResult runWasapi(const WasapiOptions& options, const FoundEndpoints& endpo if (stats.isCapture) { logf("%s: %lld frames, %lld valid, %lld silent (%lld at start), " - "%lld discontinuities, %lld wrong channel: %s", + "%lld transition, %lld discontinuities, %lld corrupt, %d setup retries: %s", stats.name.c_str(), stats.framesProcessed, stats.validFrames, - stats.silentFrames, stats.startupSilentFrames, - stats.discontinuities, stats.wrongChannelFrames, + stats.silentFrames, stats.startupSilentFrames, stats.transitionFrames, + stats.discontinuities, stats.wrongChannelFrames, stats.setupRetries, stats.passed ? "PASS" : stats.failure.c_str()); } else { - logf("%s: %lld frames rendered: %s", stats.name.c_str(), - stats.framesProcessed, stats.passed ? "PASS" : stats.failure.c_str()); + logf("%s: %lld frames rendered, %d setup retries: %s", stats.name.c_str(), + stats.framesProcessed, stats.setupRetries, + stats.passed ? "PASS" : stats.failure.c_str()); } result.passed = result.passed && stats.passed; diff --git a/SarTest/wasapi.h b/SarTest/wasapi.h index 03d1724..d3859bc 100644 --- a/SarTest/wasapi.h +++ b/SarTest/wasapi.h @@ -39,8 +39,15 @@ struct StreamStats long long validFrames = 0; long long discontinuities = 0; long long engineDiscontinuities = 0; + // Undecodable frames after the first valid one: corruption. long long wrongChannelFrames = 0; + // Undecodable frames before the first valid one: the start of the + // signal, typically the engine ramping a new stream's volume in. + long long transitionFrames = 0; long long timeouts = 0; + int setupRetries = 0; + // The first undecodable frames, with their raw sample values. + std::vector badFrameSamples; bool passed = false; std::string failure; @@ -72,6 +79,12 @@ struct WasapiOptions bool expectInvalidation = false; double minValidRatio = 0.9; long long maxDiscontinuities = -1; // -1: report only + // Endpoints can be reconfigured right after they appear, invalidating + // streams opened in that window: wait before streaming, and retry + // stream setup when it is invalidated anyway. + double settleSeconds = 2.0; + int setupAttempts = 4; + long long maxTransitionFrames = 4800; }; struct WasapiResult diff --git a/tools/test/README.md b/tools/test/README.md index 963086f..dd618c1 100644 --- a/tools/test/README.md +++ b/tools/test/README.md @@ -32,10 +32,21 @@ endpoint back to its recording twin, channel for channel. Render streams emit a signal where each sample encodes its channel id and a per-frame sequence number, chosen so it survives the engine's float/int32 conversions exactly. Capture streams decode it and count valid frames, -silence, sequence discontinuities and frames carrying the wrong channel id. -A capture stream passes when it received the signal, never saw a wrong -channel, and at least 90% of the frames after the initial silence were -contiguous (`--min-valid`, `--max-discontinuities` tune this). +silence and sequence discontinuities. Frames that do not decode are split in +two: before the first valid frame they are the start of the signal +(typically the engine ramping a new stream's volume in) and count as +transition frames; after it they are corruption. A capture stream passes +when it received the signal, saw no corrupt frames, had a transition shorter +than 100 ms (`--max-transition`), and at least 90% of the frames after the +initial silence were valid (`--min-valid`; `--max-discontinuities` +optionally bounds sequence gaps). The first undecodable frames are recorded +in the results with their raw sample values and expected channel ids. + +Endpoints can be reconfigured right after they appear, which invalidates +streams opened in that window. Streams therefore start `--settle` seconds (2 +by default) after every endpoint is active, and stream setup is retried up to +`--setup-attempts` times when it is invalidated anyway; retries are counted +in the results so they stay visible. `SarTest.exe run` does both in one process and repeats for `--iterations`, which is the "start the DAW, stop the DAW" cycle that creates and tears down From a9863819c6e1b0434f9c3e82e7678d875d6b56ab Mon Sep 17 00:00:00 2001 From: Mack Straight Date: Sun, 13 Sep 2026 05:54:35 -0400 Subject: [PATCH 06/14] ci: also publish a test-signed driver package 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--testsigned next to the unsigned package, which is unchanged. Co-Authored-By: Claude Fable 5.1 Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp --- .github/workflows/build.yml | 41 +++++++++++++++++++++++++++++++++++++ 1 file changed, 41 insertions(+) diff --git a/.github/workflows/build.yml b/.github/workflows/build.yml index 496d3d1..bab9720 100644 --- a/.github/workflows/build.yml +++ b/.github/workflows/build.yml @@ -117,6 +117,47 @@ jobs: -DriverVersion ${{ steps.ver.outputs.numeric }} ` -Describe "${{ steps.ver.outputs.describe }}" + - name: Test-sign package + shell: pwsh + run: | + # A second copy of the package signed with a throwaway self-signed + # certificate, for test machines with test signing enabled. The + # certificate (.cer) ships alongside so the guest can trust it. + $plat = "${{ matrix.platform }}" + $stage = "artifacts/$plat" + $signed = "artifacts/$plat-testsigned" + New-Item -ItemType Directory -Force -Path $signed | Out-Null + foreach ($ext in 'sys', 'inf', 'cat') { + Copy-Item "$stage/SynchronousAudioRouter.$ext" $signed -Force + } + $cert = New-SelfSignedCertificate -Type CodeSigningCert -Subject 'CN=SAR CI test signing' ` + -CertStoreLocation Cert:\CurrentUser\My -HashAlgorithm SHA256 -NotAfter (Get-Date).AddYears(2) + Export-Certificate -Cert $cert -FilePath "$signed/testsign.cer" | Out-Null + $signtool = Get-ChildItem "${env:ProgramFiles(x86)}\Windows Kits\10\bin" -Recurse -Filter signtool.exe | + Where-Object { $_.FullName -match '\\x64\\' } | + Sort-Object FullName -Descending | Select-Object -First 1 + if (-not $signtool) { throw 'signtool.exe not found' } + & $signtool.FullName sign /fd SHA256 /sha1 $cert.Thumbprint /s My ` + "$signed/SynchronousAudioRouter.sys" "$signed/SynchronousAudioRouter.cat" + if ($LASTEXITCODE -ne 0) { throw "signtool failed (exit $LASTEXITCODE)" } + Remove-Item "Cert:\CurrentUser\My\$($cert.Thumbprint)" -Force + $lines = Get-ChildItem $signed -File | Where-Object { $_.Name -ne 'SHA256SUMS.txt' } | + Get-FileHash -Algorithm SHA256 | + ForEach-Object { '{0} {1}' -f $_.Hash, (Split-Path $_.Path -Leaf) } + $lines | Out-File "$signed/SHA256SUMS.txt" -Encoding ascii + @" + TEST-SIGNED package: only loads on machines with test signing enabled + (bcdedit /set testsigning on) that trust testsign.cer in both the Root and + TrustedPublisher stores. Not for distribution. + "@ | Out-File "$signed/README.txt" -Encoding ascii + + - name: Upload test-signed package + uses: actions/upload-artifact@v4 + with: + name: sar-driver-${{ matrix.platform }}-testsigned + path: artifacts/${{ matrix.platform }}-testsigned/ + if-no-files-found: error + - name: Attest build provenance if: github.event_name == 'push' # OIDC token isn't writable on fork PRs uses: actions/attest-build-provenance@v1 From cbd38599d951d306ae19d71f4e9ae80be2838c56 Mon Sep 17 00:00:00 2001 From: Mack Straight Date: Sun, 13 Sep 2026 14:47:58 -0400 Subject: [PATCH 07/14] test: point the README at the test-signed CI package Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp --- tools/test/README.md | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/tools/test/README.md b/tools/test/README.md index dd618c1..1f14a71 100644 --- a/tools/test/README.md +++ b/tools/test/README.md @@ -94,10 +94,11 @@ scripts assume they may overwrite the SAR configuration. 1. Windows 10 or 11 x64. On Server, `Invoke-SarTest.ps1` enables the audio services itself. 2. Enable test signing and reboot: `bcdedit /set testsigning on`. -3. Test-sign the CI package's `.sys` and `.cat` with a self-signed - certificate, and pass that certificate's `.cer` as `-CertPath` so the - script installs it into the Root and TrustedPublisher stores. Without it - the non-interactive driver install is refused. +3. Use the `sar-driver-x64-testsigned` CI artifact. It is signed with a + throwaway certificate generated for that build and ships it as + `testsign.cer`; pass that file as `-CertPath` so the script installs it + into the Root and TrustedPublisher stores. Without it the non-interactive + driver install is refused. 4. Optionally enable Driver Verifier for the driver, including deadlock detection, so a lock-order bug bugchecks with the exact cycle instead of hanging: `verifier /flags 0x20 /driver SynchronousAudioRouter.sys`. From daffc498f7a9c73a235597aed12e289c04dd8af8 Mon Sep 17 00:00:00 2001 From: Mack Straight Date: Sun, 13 Sep 2026 14:55:07 -0400 Subject: [PATCH 08/14] test: reopen invalidated streams and record dropouts 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) Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp --- SarTest/SarTest.cpp | 4 +- SarTest/wasapi.cpp | 136 ++++++++++++++++++++++++++++++++++--------- SarTest/wasapi.h | 23 +++++--- tools/test/README.md | 23 +++++--- 4 files changed, 139 insertions(+), 47 deletions(-) diff --git a/SarTest/SarTest.cpp b/SarTest/SarTest.cpp index e5caae0..9fd8898 100644 --- a/SarTest/SarTest.cpp +++ b/SarTest/SarTest.cpp @@ -53,7 +53,7 @@ int usage() " --registered (use the COM-registered SarAsio instead of a path)\n" " --wait S --wait-gone S --restart-delay MS --rate HZ\n" " --min-valid RATIO --max-discontinuities N\n" - " --settle S --setup-attempts N --max-transition FRAMES\n" + " --settle S --max-reopens N --max-transition FRAMES\n" "\n" "Exit codes: 0 pass, 1 setup or usage error, 2 test failure.\n"); return 1; @@ -101,7 +101,7 @@ WasapiOptions wasapiOptions(const Args& args, const EndpointLayout& layout) options.minValidRatio = args.getDouble(L"min-valid", 0.9); options.maxDiscontinuities = args.getInt(L"max-discontinuities", -1); options.settleSeconds = args.getDouble(L"settle", 2.0); - options.setupAttempts = args.getInt(L"setup-attempts", 4); + options.maxReopens = args.getInt(L"max-reopens", 3); options.maxTransitionFrames = args.getInt(L"max-transition", 4800); return options; } diff --git a/SarTest/wasapi.cpp b/SarTest/wasapi.cpp index 08b6425..6f87d82 100644 --- a/SarTest/wasapi.cpp +++ b/SarTest/wasapi.cpp @@ -61,6 +61,9 @@ class ComPtr enum class SampleKind { Float32, Int32, Unsupported }; +// Common time origin for every stream of a run, so gaps line up. +double g_runOriginMs = 0.0; + SampleKind classifyFormat(const WAVEFORMATEX *format, std::string *description) { WORD tag = format->wFormatTag; @@ -200,8 +203,8 @@ class Stream { public: Stream(const EndpointLayout& layout, int pair, IMMDevice *device, bool isCapture, - int setupAttempts) - : _device(device), _isCapture(isCapture), _setupAttempts(setupAttempts) + int maxReopens) + : _device(device), _isCapture(isCapture), _maxReopens(maxReopens) { _device->AddRef(); @@ -255,8 +258,10 @@ class Stream { HRESULT hr = CoInitializeEx(nullptr, COINIT_MULTITHREADED); - for (int attempt = 1; ; ++attempt) { - _setupInvalidated = false; + bool gaveUp = false; + + for (;;) { + _invalidated = false; if (_isCapture) { captureLoop(); @@ -264,18 +269,40 @@ class Stream renderLoop(); } - if (!_setupInvalidated || attempt >= _setupAttempts || - WaitForSingleObject(_stopEvent, 500) == WAIT_OBJECT_0) { + // Stopped normally, or failed for a reason reopening won't fix. + if (!_invalidated) { + break; + } + + // The run is over anyway. + if (WaitForSingleObject(_stopEvent, 0) == WAIT_OBJECT_0) { + break; + } + + if (_stats.reopens >= _maxReopens) { + gaveUp = true; break; } - _stats.setupRetries++; - logf("%s: retrying stream setup (attempt %d of %d)", - _stats.name.c_str(), attempt + 1, _setupAttempts); + if (WaitForSingleObject(_stopEvent, 500) == WAIT_OBJECT_0) { + break; + } + + _stats.reopens++; + logf("%s: reopening the stream (%d of %d)", + _stats.name.c_str(), _stats.reopens, _maxReopens); + flushSilentRun(" (then invalidated)"); + + // A reopened stream ramps in again and its sequence resumes from + // wherever the render side is by then. + _lockedIn = false; + _haveLastSequence = false; refreshDevice(); } - if (_setupInvalidated) { + flushSilentRun(" (until the end)"); + + if (gaveUp) { _stats.deviceInvalidated = true; } @@ -303,11 +330,9 @@ class Stream bool fail(const char *stage, HRESULT hr) { - if (hr == AUDCLNT_E_DEVICE_INVALIDATED && !_stats.started) { - _setupInvalidated = true; - logf("%s: device invalidated during %s (setup)", _stats.name.c_str(), stage); - } else if (hr == AUDCLNT_E_DEVICE_INVALIDATED) { - _stats.deviceInvalidated = true; + if (hr == AUDCLNT_E_DEVICE_INVALIDATED) { + _invalidated = true; + _stats.invalidations++; logf("%s: device invalidated during %s", _stats.name.c_str(), stage); } else { _stats.lastError = hr; @@ -338,6 +363,7 @@ class Stream _kind = classifyFormat(mix, &_stats.format); _stats.channels = mix->nChannels; + _rate = mix->nSamplesPerSec ? (double)mix->nSamplesPerSec : 48000.0; if (_kind == SampleKind::Unsupported) { CoTaskMemFree(mix); @@ -395,8 +421,28 @@ class Stream } } + void recordGap(const char *text) + { + if (_stats.gapSamples.size() < 16) { + _stats.gapSamples.push_back(text); + } + } + + void flushSilentRun(const char *suffix) + { + if (_silentRun > 0) { + char buf[192]; + + sprintf_s(buf, "dropout of %lld frames (%.1f ms) at %.3f s%s", + _silentRun, _silentRun * 1000.0 / _rate, _silentRunStartMs / 1000.0, suffix); + recordGap(buf); + _silentRun = 0; + } + } + void decode(const BYTE *data, UINT32 frames) { + double packetMs = nowMs() - g_runOriginMs; int channels = _stats.channels; int expectedChannels = std::min(channels, (int)_channelIds.size()); @@ -441,11 +487,21 @@ class Stream _stats.startupSilentFrames++; } + if (_lockedIn) { + _stats.midStreamSilentFrames++; + + if (_silentRun++ == 0) { + _silentRunStartMs = packetMs; + } + } + continue; } + flushSilentRun(""); + if (!channelsOk || !sequenceConsistent) { - bool transition = _stats.validFrames == 0; + bool transition = !_lockedIn; if (transition) { _stats.transitionFrames++; @@ -472,11 +528,17 @@ class Stream } if (_haveLastSequence && sequence != ((_lastSequence + 1) & 0xFFFF)) { + char buf[128]; + _stats.discontinuities++; + sprintf_s(buf, "sequence jump of %u frames at %.3f s", + (unsigned int)((sequence - _lastSequence - 1) & 0xFFFF), packetMs / 1000.0); + recordGap(buf); } _lastSequence = sequence; _haveLastSequence = true; + _lockedIn = true; _stats.validFrames++; } } @@ -710,9 +772,13 @@ class Stream uint32_t _sequence = 0; uint32_t _lastSequence = 0; bool _haveLastSequence = false; + bool _lockedIn = false; + long long _silentRun = 0; + double _silentRunStartMs = 0.0; + double _rate = 48000.0; std::wstring _deviceId; - int _setupAttempts = 1; - bool _setupInvalidated = false; + int _maxReopens = 0; + bool _invalidated = false; HANDLE _stopEvent = nullptr; std::thread _thread; }; @@ -854,7 +920,9 @@ std::string StreamStats::toJson() const .setInt("engineDiscontinuities", engineDiscontinuities) .setInt("wrongChannelFrames", wrongChannelFrames) .setInt("transitionFrames", transitionFrames) - .setInt("setupRetries", setupRetries) + .setInt("midStreamSilentFrames", midStreamSilentFrames) + .setInt("invalidations", invalidations) + .setInt("reopens", reopens) .setInt("timeouts", timeouts) .setBool("passed", passed) .setString("failure", failure); @@ -866,6 +934,14 @@ std::string StreamStats::toJson() const } o.setRaw("badFrames", jsonArray(bad)); + + std::vector gaps; + + for (const auto& gap : gapSamples) { + gaps.push_back(jsonString(gap)); + } + + o.setRaw("gaps", jsonArray(gaps)); return o.str(); } @@ -903,7 +979,7 @@ static void evaluate(StreamStats *s, const WasapiOptions& options) } if (s->deviceInvalidated && !options.expectInvalidation) { - s->failure = "device invalidated"; + s->failure = "device invalidated and not recovered"; return; } @@ -954,9 +1030,9 @@ WasapiResult runWasapi(const WasapiOptions& options, const FoundEndpoints& endpo for (int pair = 0; pair < layout.pairs; ++pair) { streams.emplace_back(new Stream( - layout, pair, endpoints.render[(size_t)pair], false, options.setupAttempts)); + layout, pair, endpoints.render[(size_t)pair], false, options.maxReopens)); streams.emplace_back(new Stream( - layout, pair, endpoints.capture[(size_t)pair], true, options.setupAttempts)); + layout, pair, endpoints.capture[(size_t)pair], true, options.maxReopens)); } if (options.settleSeconds > 0) { @@ -964,6 +1040,8 @@ WasapiResult runWasapi(const WasapiOptions& options, const FoundEndpoints& endpo Sleep((DWORD)(options.settleSeconds * 1000.0)); } + g_runOriginMs = nowMs(); + for (auto& stream : streams) { stream->begin(); } @@ -991,15 +1069,15 @@ WasapiResult runWasapi(const WasapiOptions& options, const FoundEndpoints& endpo evaluate(&stats, options); if (stats.isCapture) { - logf("%s: %lld frames, %lld valid, %lld silent (%lld at start), " - "%lld transition, %lld discontinuities, %lld corrupt, %d setup retries: %s", + logf("%s: %lld frames, %lld valid, %lld silent (%lld at start, %lld dropout), " + "%lld transition, %lld discontinuities, %lld corrupt, %d reopens: %s", stats.name.c_str(), stats.framesProcessed, stats.validFrames, - stats.silentFrames, stats.startupSilentFrames, stats.transitionFrames, - stats.discontinuities, stats.wrongChannelFrames, stats.setupRetries, - stats.passed ? "PASS" : stats.failure.c_str()); + stats.silentFrames, stats.startupSilentFrames, stats.midStreamSilentFrames, + stats.transitionFrames, stats.discontinuities, stats.wrongChannelFrames, + stats.reopens, stats.passed ? "PASS" : stats.failure.c_str()); } else { - logf("%s: %lld frames rendered, %d setup retries: %s", stats.name.c_str(), - stats.framesProcessed, stats.setupRetries, + logf("%s: %lld frames rendered, %d reopens: %s", stats.name.c_str(), + stats.framesProcessed, stats.reopens, stats.passed ? "PASS" : stats.failure.c_str()); } diff --git a/SarTest/wasapi.h b/SarTest/wasapi.h index d3859bc..4f39178 100644 --- a/SarTest/wasapi.h +++ b/SarTest/wasapi.h @@ -39,15 +39,22 @@ struct StreamStats long long validFrames = 0; long long discontinuities = 0; long long engineDiscontinuities = 0; - // Undecodable frames after the first valid one: corruption. + // Undecodable frames once the signal has locked in: corruption. long long wrongChannelFrames = 0; - // Undecodable frames before the first valid one: the start of the - // signal, typically the engine ramping a new stream's volume in. + // Undecodable frames before the signal locks in (at the start, and again + // after a reopen): the engine ramping a new stream's volume in. long long transitionFrames = 0; + // Silent frames once the signal has locked in: dropouts. + long long midStreamSilentFrames = 0; long long timeouts = 0; - int setupRetries = 0; + // AUDCLNT_E_DEVICE_INVALIDATED events, and how many times the stream + // was reopened after one, as a well-behaved client would. + int invalidations = 0; + int reopens = 0; // The first undecodable frames, with their raw sample values. std::vector badFrameSamples; + // The first dropouts and sequence jumps, timed from the start of the run. + std::vector gapSamples; bool passed = false; std::string failure; @@ -79,11 +86,11 @@ struct WasapiOptions bool expectInvalidation = false; double minValidRatio = 0.9; long long maxDiscontinuities = -1; // -1: report only - // Endpoints can be reconfigured right after they appear, invalidating - // streams opened in that window: wait before streaming, and retry - // stream setup when it is invalidated anyway. + // SarAsio broadcasts a format change whenever one of its endpoints + // becomes active, which invalidates open streams: wait before streaming, + // and reopen invalidated streams like a well-behaved client would. double settleSeconds = 2.0; - int setupAttempts = 4; + int maxReopens = 3; long long maxTransitionFrames = 4800; }; diff --git a/tools/test/README.md b/tools/test/README.md index 1f14a71..4a89173 100644 --- a/tools/test/README.md +++ b/tools/test/README.md @@ -33,20 +33,27 @@ Render streams emit a signal where each sample encodes its channel id and a per-frame sequence number, chosen so it survives the engine's float/int32 conversions exactly. Capture streams decode it and count valid frames, silence and sequence discontinuities. Frames that do not decode are split in -two: before the first valid frame they are the start of the signal -(typically the engine ramping a new stream's volume in) and count as -transition frames; after it they are corruption. A capture stream passes +two. Before the signal locks in (its first valid frame, and again after a +reopen) they are the engine ramping a new stream's volume in, the correct +samples scaled up from near zero, and count as transition frames; once it +has locked in they are corruption. A capture stream passes when it received the signal, saw no corrupt frames, had a transition shorter than 100 ms (`--max-transition`), and at least 90% of the frames after the initial silence were valid (`--min-valid`; `--max-discontinuities` optionally bounds sequence gaps). The first undecodable frames are recorded in the results with their raw sample values and expected channel ids. -Endpoints can be reconfigured right after they appear, which invalidates -streams opened in that window. Streams therefore start `--settle` seconds (2 -by default) after every endpoint is active, and stream setup is retried up to -`--setup-attempts` times when it is invalidated anyway; retries are counted -in the results so they stay visible. +SarAsio broadcasts a format change whenever one of its endpoints becomes +active, so streams that are open around the time the ASIO host starts get +invalidated (`AUDCLNT_E_DEVICE_INVALIDATED`). Streams therefore start +`--settle` seconds (2 by default) after every endpoint is active, and an +invalidated stream is reopened, as a well-behaved client would, up to +`--max-reopens` times (3). Invalidations and reopens are counted in the +results so they stay visible. + +Capture streams also record dropouts (silence after the signal locked in) +and sequence jumps, timed from the start of the run, so gaps can be lined up +across endpoints to tell a global stall from a per-endpoint one. `SarTest.exe run` does both in one process and repeats for `--iterations`, which is the "start the DAW, stop the DAW" cycle that creates and tears down From 1ad8de089c0be6521332d7793f39a2befcf22477 Mon Sep 17 00:00:00 2001 From: Mack Straight Date: Sun, 13 Sep 2026 15:01:41 -0400 Subject: [PATCH 09/14] test: add a start-up race scenario 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) Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp --- SarTest/SarTest.cpp | 103 ++++++++++++ SarTest/wasapi.cpp | 302 ++++++++++++++++++++++++++++++++++ SarTest/wasapi.h | 53 ++++++ tools/test/Invoke-SarTest.ps1 | 25 ++- tools/test/README.md | 14 +- 5 files changed, 491 insertions(+), 6 deletions(-) diff --git a/SarTest/SarTest.cpp b/SarTest/SarTest.cpp index 9fd8898..d77f8d7 100644 --- a/SarTest/SarTest.cpp +++ b/SarTest/SarTest.cpp @@ -45,6 +45,9 @@ int usage() " verify the loopback.\n" " SarTest run [--iterations K] [--duration S]\n" " host and wasapi in one process, with end-to-end verification.\n" + " SarTest race [--cycles K] [--up S] [--down MS] [--openers T] [--hold MS]\n" + " Start and stop the host repeatedly while threads keep opening and\n" + " closing streams on its endpoints; report any call that hangs.\n" "\n" "Layout options: --endpoints N (playback/recording pairs, default 2)\n" " --channels C (per endpoint, default 2) --prefix \n" @@ -290,6 +293,104 @@ int cmdWasapi(const Args& args) return rc; } +int cmdRace(const Args& args) +{ + EndpointLayout layout = EndpointLayout::fromArgs(args); + int cycles = args.getInt(L"cycles", 10); + double up = args.getDouble(L"up", 3.0); + int down = args.getInt(L"down", 200); + int threads = args.getInt(L"openers", 4); + int hold = args.getInt(L"hold", 250); + int hangTimeout = args.getInt(L"phase-timeout", 30); + + if (threads < 1) { + threads = 1; + } + + if (threads > 32) { + threads = 32; + } + + if (!prepareConfig(args, layout)) { + return 1; + } + + AsioHost host(hostOptions(args, layout)); + RaceOpeners openers(layout, threads, hold, hangTimeout); + std::vector cycleJson; + int rc = 0; + + if (!host.load() || !host.open()) { + rc = 1; + } + + if (rc == 0) { + logf("Starting %d stream openers on %d endpoint pairs", threads, layout.pairs); + openers.start(); + } + + for (int i = 0; rc == 0 && i < cycles; ++i) { + JsonObject cycle; + + logf("--- race cycle %d of %d ---", i + 1, cycles); + cycle.setInt("cycle", i + 1); + + if (!host.start()) { + rc = 2; + cycle.setString("failure", "start"); + cycleJson.push_back(cycle.str()); + break; + } + + cycle.setDouble("startMs", host.stats().lastStartMs); + Sleep((DWORD)(up * 1000.0)); + + if (!host.stop()) { + rc = 2; + cycle.setString("failure", "stop"); + } + + cycle.setDouble("stopMs", host.stats().lastStopMs); + cycleJson.push_back(cycle.str()); + Sleep((DWORD)down); + } + + bool clean = openers.stop(); + RaceStats race = openers.stats(); + + logf("Openers: %lld attempts, %lld streams opened, %lld without an active endpoint, " + "slowest call %s (%.0f ms)", race.attempts, race.opened, race.noEndpoint, + race.maxCallName.c_str(), race.maxCallMs); + + for (const auto& error : race.errors) { + logf(" %s: %lld", error.first.c_str(), error.second); + } + + if (!clean || race.hangsReported > 0 || host.stats().hangsReported > 0) { + rc = 2; + logf("A WASAPI or ASIO call hung"); + } else if (rc == 0 && race.opened == 0) { + rc = 2; + logf("No stream was ever opened; the openers never raced the host"); + } + + // Results first: closing the host can hang if the driver is wedged. + JsonObject result; + + result.setString("command", "race") + .setBool("passed", rc == 0) + .setInt("exitCode", rc) + .setInt("endpointPairs", layout.pairs) + .setInt("channels", layout.channels) + .setRaw("host", host.toJson()) + .setRaw("openers", race.toJson()) + .setRaw("cycles", jsonArray(cycleJson)); + writeResults(args, result.str()); + logf("%s", rc == 0 ? "PASSED" : "FAILED"); + host.close(); + return rc; +} + int cmdRun(const Args& args) { EndpointLayout layout = EndpointLayout::fromArgs(args); @@ -410,6 +511,8 @@ int wmain(int argc, wchar_t **argv) rc = cmdWasapi(args); } else if (args.command == L"run") { rc = cmdRun(args); + } else if (args.command == L"race") { + rc = cmdRace(args); } else { rc = usage(); } diff --git a/SarTest/wasapi.cpp b/SarTest/wasapi.cpp index 6f87d82..db3e3d3 100644 --- a/SarTest/wasapi.cpp +++ b/SarTest/wasapi.cpp @@ -25,6 +25,7 @@ #include #include +#include #include namespace SarTest { @@ -1088,4 +1089,305 @@ WasapiResult runWasapi(const WasapiOptions& options, const FoundEndpoints& endpo return result; } +// --------------------------------------------------------------------------- +// Start-up race: stream openers. + +static const char *const kIdlePhase = "idle"; + +struct RaceOpeners::Worker +{ + RaceOpeners *owner = nullptr; + int index = 0; + std::atomic phase{ kIdlePhase }; + std::atomic phaseStartMs{ 0.0 }; + std::atomic hangReported{ false }; + std::mutex lock; + RaceStats stats; +}; + +std::string RaceStats::toJson() const +{ + std::vector errorItems; + + for (const auto& error : errors) { + JsonObject item; + + item.setString("call", error.first).setInt("count", error.second); + errorItems.push_back(item.str()); + } + + JsonObject o; + + o.setInt("attempts", attempts) + .setInt("opened", opened) + .setInt("noEndpoint", noEndpoint) + .setInt("hangsReported", hangsReported) + .setDouble("maxCallMs", maxCallMs) + .setString("maxCall", maxCallName) + .setRaw("errors", jsonArray(errorItems)); + return o.str(); +} + +RaceOpeners::RaceOpeners( + const EndpointLayout& layout, int threads, int holdMs, int hangTimeoutSeconds) + : _layout(layout), _holdMs(holdMs), _hangTimeoutMs(hangTimeoutSeconds * 1000) +{ + for (int i = 0; i < threads; ++i) { + _workers.emplace_back(new Worker()); + _workers.back()->owner = this; + _workers.back()->index = i; + } +} + +RaceOpeners::~RaceOpeners() +{ + stop(); + + // A thread stuck inside a WASAPI call still references its worker. + if (!_clean) { + for (auto& worker : _workers) { + worker.release(); + } + } +} + +void RaceOpeners::start() +{ + if (!_threads.empty()) { + return; + } + + _stop = false; + _watchdogStop = false; + _stopped = false; + _clean = true; + + for (auto& worker : _workers) { + HANDLE thread = CreateThread( + nullptr, 0, &RaceOpeners::threadMain, worker.get(), 0, nullptr); + + if (thread) { + _threads.push_back(thread); + } + } + + _watchdog = CreateThread(nullptr, 0, &RaceOpeners::watchdogMain, this, 0, nullptr); +} + +bool RaceOpeners::stop() +{ + if (_stopped) { + return _clean; + } + + _stopped = true; + _stop = true; + + if (!_threads.empty()) { + DWORD wait = WaitForMultipleObjects( + (DWORD)_threads.size(), _threads.data(), TRUE, (DWORD)_hangTimeoutMs + 5000); + + _clean = wait != WAIT_TIMEOUT && wait != WAIT_FAILED; + + if (!_clean) { + logf("Stream openers did not finish within %d s", _hangTimeoutMs / 1000 + 5); + } + } + + _watchdogStop = true; + + if (_watchdog) { + WaitForSingleObject(_watchdog, 5000); + CloseHandle(_watchdog); + _watchdog = nullptr; + } + + if (_clean) { + for (HANDLE thread : _threads) { + CloseHandle(thread); + } + + _threads.clear(); + } + + return _clean; +} + +RaceStats RaceOpeners::stats() +{ + RaceStats total; + + for (auto& worker : _workers) { + std::lock_guard guard(worker->lock); + const RaceStats& s = worker->stats; + + total.attempts += s.attempts; + total.opened += s.opened; + total.noEndpoint += s.noEndpoint; + total.hangsReported += s.hangsReported; + + if (s.maxCallMs > total.maxCallMs) { + total.maxCallMs = s.maxCallMs; + total.maxCallName = s.maxCallName; + } + + for (const auto& error : s.errors) { + total.errors[error.first] += error.second; + } + } + + return total; +} + +DWORD WINAPI RaceOpeners::threadMain(LPVOID param) +{ + Worker *worker = (Worker *)param; + + worker->owner->work(worker); + return 0; +} + +DWORD WINAPI RaceOpeners::watchdogMain(LPVOID param) +{ + ((RaceOpeners *)param)->watch(); + return 0; +} + +void RaceOpeners::watch() +{ + while (!_watchdogStop) { + Sleep(250); + + double now = nowMs(); + + for (auto& worker : _workers) { + const char *phase = worker->phase.load(); + + if (phase == kIdlePhase) { + continue; + } + + double elapsed = now - worker->phaseStartMs.load(); + + if (elapsed > (double)_hangTimeoutMs && !worker->hangReported.exchange(true)) { + logf("HANG: stream opener %d stuck in %s for %.0f ms", worker->index, phase, elapsed); + + std::lock_guard guard(worker->lock); + worker->stats.hangsReported++; + } + } + } +} + +void RaceOpeners::work(Worker *worker) +{ + HRESULT co = CoInitializeEx(nullptr, COINIT_MULTITHREADED); + ComPtr enumerator; + std::vector names; + unsigned int cursor = (unsigned int)worker->index; + unsigned int rng = 0x9E3779B9u * (unsigned int)(worker->index + 1); + + // Even indices are playback (render) endpoints, odd ones recording (capture). + for (int pair = 0; pair < _layout.pairs; ++pair) { + names.push_back(_layout.playbackName(pair)); + names.push_back(_layout.recordingName(pair)); + } + + auto enter = [worker](const char *phase) { + worker->phaseStartMs = nowMs(); + worker->phase = phase; + }; + + auto leave = [worker](const char *call, HRESULT hr) { + double elapsed = nowMs() - worker->phaseStartMs.load(); + + worker->phase = kIdlePhase; + + std::lock_guard guard(worker->lock); + + if (elapsed > worker->stats.maxCallMs) { + worker->stats.maxCallMs = elapsed; + worker->stats.maxCallName = call; + } + + if (FAILED(hr)) { + worker->stats.errors[std::string(call) + " " + hresultText(hr)]++; + } + }; + + if (createEnumerator(&enumerator)) { + while (!_stop) { + size_t which = cursor++ % names.size(); + EDataFlow flow = (which % 2 == 0) ? eRender : eCapture; + ComPtr device; + + { + std::lock_guard guard(worker->lock); + worker->stats.attempts++; + } + + enter("EnumAudioEndpoints"); + bool found = findActiveEndpoint(enumerator.get(), flow, names[which], device.put()); + leave("EnumAudioEndpoints", S_OK); + + if (!found) { + std::lock_guard guard(worker->lock); + worker->stats.noEndpoint++; + Sleep(5); + continue; + } + + ComPtr client; + + enter("Activate"); + HRESULT hr = device->Activate(__uuidof(IAudioClient), CLSCTX_ALL, nullptr, client.putVoid()); + leave("Activate", hr); + + if (SUCCEEDED(hr)) { + WAVEFORMATEX *mix = nullptr; + + enter("GetMixFormat"); + hr = client->GetMixFormat(&mix); + leave("GetMixFormat", hr); + + if (SUCCEEDED(hr) && mix) { + enter("Initialize"); + hr = client->Initialize(AUDCLNT_SHAREMODE_SHARED, 0, 200000, 0, mix, nullptr); + leave("Initialize", hr); + CoTaskMemFree(mix); + + if (SUCCEEDED(hr)) { + enter("Start"); + hr = client->Start(); + leave("Start", hr); + + if (SUCCEEDED(hr)) { + rng = rng * 1664525u + 1013904223u; + Sleep(_holdMs > 0 ? (DWORD)(rng % (unsigned int)(2 * _holdMs)) : 0); + + enter("Stop"); + hr = client->Stop(); + leave("Stop", hr); + + std::lock_guard guard(worker->lock); + worker->stats.opened++; + } + } + } + } + + enter("Release"); + client.reset(); + device.reset(); + leave("Release", S_OK); + Sleep(2); + } + } + + if (SUCCEEDED(co)) { + CoUninitialize(); + } +} + + } // namespace SarTest diff --git a/SarTest/wasapi.h b/SarTest/wasapi.h index 4f39178..be7115f 100644 --- a/SarTest/wasapi.h +++ b/SarTest/wasapi.h @@ -21,6 +21,9 @@ #include +#include +#include + namespace SarTest { struct StreamStats @@ -106,5 +109,55 @@ struct WasapiResult // every recording endpoint for the configured duration. WasapiResult runWasapi(const WasapiOptions& options, const FoundEndpoints& endpoints); +struct RaceStats +{ + long long attempts = 0; + long long opened = 0; + long long noEndpoint = 0; + long long hangsReported = 0; + double maxCallMs = 0.0; + std::string maxCallName; + std::map errors; // " " -> count + + std::string toJson() const; +}; + +// Threads that keep finding the layout's endpoints and opening, starting, +// holding and closing shared-mode streams on them while the ASIO host starts +// and stops underneath, the way applications that use a SAR endpoint as their +// default device behave while a DAW starts. A watchdog reports any WASAPI +// call that does not return within the timeout as a hang. +class RaceOpeners +{ +public: + RaceOpeners(const EndpointLayout& layout, int threads, int holdMs, int hangTimeoutSeconds); + ~RaceOpeners(); + RaceOpeners(const RaceOpeners&) = delete; + RaceOpeners& operator=(const RaceOpeners&) = delete; + + void start(); + // Stops the threads; false when one did not finish within the timeout. + bool stop(); + RaceStats stats(); + +private: + struct Worker; + static DWORD WINAPI threadMain(LPVOID param); + static DWORD WINAPI watchdogMain(LPVOID param); + void work(Worker *worker); + void watch(); + + EndpointLayout _layout; + int _holdMs; + int _hangTimeoutMs; + std::vector> _workers; + std::vector _threads; + HANDLE _watchdog = nullptr; + std::atomic _stop{ false }; + std::atomic _watchdogStop{ false }; + bool _stopped = false; + bool _clean = true; +}; + } // namespace SarTest #endif // _SAR_TEST_WASAPI_H diff --git a/tools/test/Invoke-SarTest.ps1 b/tools/test/Invoke-SarTest.ps1 index fdd9796..f1d501b 100644 --- a/tools/test/Invoke-SarTest.ps1 +++ b/tools/test/Invoke-SarTest.ps1 @@ -33,7 +33,10 @@ param( # Per-scenario wall clock limit before it is declared hung. [int]$TimeoutSeconds = 600, [switch]$SkipInstall, - [switch]$SkipKillTest + [switch]$SkipKillTest, + # Any of matrix, race, kill. Installation always runs. + [string[]]$Scenarios = @('matrix', 'race', 'kill'), + [int]$RaceCycles = 10 ) $ErrorActionPreference = 'Stop' @@ -142,12 +145,24 @@ if (-not $SkipInstall) { $common = @('--sarasio', "`"$sarAsio`"", '--channels', $Channels) -foreach ($count in $EndpointCounts) { - $summary.scenarios += Invoke-Scenario "run-${count}x${Channels}" ( - @('run', '--endpoints', $count, '--iterations', $Iterations, '--duration', $Duration) + $common) +if ($Scenarios -contains 'matrix') { + foreach ($count in $EndpointCounts) { + $summary.scenarios += Invoke-Scenario "run-${count}x${Channels}" ( + @('run', '--endpoints', $count, '--iterations', $Iterations, '--duration', $Duration) + $common) + } +} + +if ($Scenarios -contains 'race') { + # Start and stop the host over and over while other threads keep opening + # streams on its endpoints: the start-up race reported against + # many-endpoint setups. + $count = $EndpointCounts[-1] + $summary.scenarios += Invoke-Scenario "race-${count}x${Channels}" ( + @('race', '--endpoints', $count, '--cycles', $RaceCycles, '--up', 3, '--down', 200, + '--openers', 4) + $common) } -if (-not $SkipKillTest) { +if (-not $SkipKillTest -and $Scenarios -contains 'kill') { # Kill the ASIO host while WASAPI clients are streaming, then check that a # fresh host can still create endpoints afterwards. $count = $EndpointCounts[-1] diff --git a/tools/test/README.md b/tools/test/README.md index 4a89173..2b370f6 100644 --- a/tools/test/README.md +++ b/tools/test/README.md @@ -62,6 +62,17 @@ returned after N ms` when a driver call exceeds `--phase-timeout` (30 s), so a kernel-side deadlock shows up in the log even though the process cannot recover from it. +`SarTest.exe race` is the start-up race. It starts and stops the host +`--cycles` times (10 by default; 3 s up, 200 ms down) while `--openers` +threads (4) keep finding the layout's endpoints and opening, starting, +holding for up to twice `--hold` ms (250) and closing shared-mode streams on +them, which is what applications that use a SAR endpoint as their default +device do while a DAW starts. Every WASAPI call and every host call is +watched; one that does not return within `--phase-timeout` is reported as +`HANG`. The scenario fails if any call hung, the host failed to start or +stop, or no stream was ever opened. `Invoke-SarTest.ps1 -Scenarios` selects +any of `matrix`, `race` and `kill`. + ## Commands ``` @@ -71,6 +82,7 @@ SarTest config [--endpoints N] [--channels C] [--out ] SarTest host [--iterations K] [--duration S] SarTest wasapi [--duration S] [--wait S] [--expect-invalidation] SarTest run [--iterations K] [--duration S] +SarTest race [--cycles K] [--up S] [--down MS] [--openers T] [--hold MS] ``` `install` creates the SAR software device node if needed, installs the @@ -119,7 +131,7 @@ Then, elevated: ``` The script runs `run` for 1, 4, 8 and 16 endpoint pairs with three -start/stop iterations each, then a scenario that kills the host while WASAPI +start/stop iterations each, `race` on the largest layout, then a scenario that kills the host while WASAPI clients are streaming and checks that a new host can still create endpoints afterwards. Results land in `sartest-results\`: one `.log` and `.json` per scenario, `summary.json`, and the SarAsio logs. Exit code 2 means a scenario From 23abf98037a83558a671eeda81d43b55911c204d Mon Sep 17 00:00:00 2001 From: Mack Straight Date: Sun, 13 Sep 2026 15:08:23 -0400 Subject: [PATCH 10/14] test: classify ramps by position, retry setup errors, time SarAsio's 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) Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp --- SarTest/SarTest.cpp | 12 ++- SarTest/asiohost.cpp | 11 ++- SarTest/wasapi.cpp | 133 ++++++++++++++++++++++++++++------ SarTest/wasapi.h | 9 ++- SarTestClock/SarTestClock.cpp | 19 +++++ SarTestClock/clockstats.h | 5 ++ tools/test/README.md | 36 +++++---- 7 files changed, 178 insertions(+), 47 deletions(-) diff --git a/SarTest/SarTest.cpp b/SarTest/SarTest.cpp index d77f8d7..cd94627 100644 --- a/SarTest/SarTest.cpp +++ b/SarTest/SarTest.cpp @@ -101,10 +101,10 @@ WasapiOptions wasapiOptions(const Args& args, const EndpointLayout& layout) options.layout = layout; options.durationSeconds = args.getDouble(L"duration", 5.0); options.expectInvalidation = args.has(L"expect-invalidation"); - options.minValidRatio = args.getDouble(L"min-valid", 0.9); + options.minValidRatio = args.getDouble(L"min-valid", 0.5); options.maxDiscontinuities = args.getInt(L"max-discontinuities", -1); options.settleSeconds = args.getDouble(L"settle", 2.0); - options.maxReopens = args.getInt(L"max-reopens", 3); + options.maxReopens = args.getInt(L"max-reopens", 20); options.maxTransitionFrames = args.getInt(L"max-transition", 4800); return options; } @@ -350,7 +350,9 @@ int cmdRace(const Args& args) cycle.setString("failure", "stop"); } - cycle.setDouble("stopMs", host.stats().lastStopMs); + cycle.setDouble("stopMs", host.stats().lastStopMs) + .setDouble("maxCallbackMs", host.stats().clock.maxCallbackMs) + .setInt("slowCallbacks", (long long)host.stats().clock.slowCallbacks); cycleJson.push_back(cycle.str()); Sleep((DWORD)down); } @@ -452,7 +454,9 @@ int cmdRun(const Args& args) iteration.setString("failure", "stop"); } - iteration.setDouble("stopMs", host.stats().lastStopMs); + iteration.setDouble("stopMs", host.stats().lastStopMs) + .setDouble("maxCallbackMs", host.stats().clock.maxCallbackMs) + .setInt("slowCallbacks", (long long)host.stats().clock.slowCallbacks); iterationJson.push_back(iteration.str()); if (rc == 0 && i + 1 < iterations) { diff --git a/SarTest/asiohost.cpp b/SarTest/asiohost.cpp index 8f3e9fa..90dfed1 100644 --- a/SarTest/asiohost.cpp +++ b/SarTest/asiohost.cpp @@ -332,10 +332,13 @@ bool AsioHost::stop() return false; } - logf("stop OK in %.1f ms (%lld ticks so far, clock late %llu of %llu)", + logf("stop OK in %.1f ms (%lld ticks so far, clock late %llu of %llu, " + "slowest callback %.1f ms, %llu slow)", elapsed, _stats.ticks, (unsigned long long)_stats.clock.lateTicks, - (unsigned long long)_stats.clock.ticks); + (unsigned long long)_stats.clock.ticks, + _stats.clock.maxCallbackMs, + (unsigned long long)_stats.clock.slowCallbacks); return true; } @@ -446,7 +449,9 @@ std::string AsioHost::toJson() const clock.setInt("ticks", (long long)_stats.clock.ticks) .setInt("lateTicks", (long long)_stats.clock.lateTicks) .setDouble("maxLatenessMs", _stats.clock.maxLatenessMs) - .setDouble("periodMs", _stats.clock.periodMs); + .setDouble("periodMs", _stats.clock.periodMs) + .setDouble("maxCallbackMs", _stats.clock.maxCallbackMs) + .setInt("slowCallbacks", (long long)_stats.clock.slowCallbacks); JsonObject host; diff --git a/SarTest/wasapi.cpp b/SarTest/wasapi.cpp index db3e3d3..dda451f 100644 --- a/SarTest/wasapi.cpp +++ b/SarTest/wasapi.cpp @@ -204,8 +204,9 @@ class Stream { public: Stream(const EndpointLayout& layout, int pair, IMMDevice *device, bool isCapture, - int maxReopens) - : _device(device), _isCapture(isCapture), _maxReopens(maxReopens) + int maxReopens, long long maxTransitionFrames) + : _device(device), _isCapture(isCapture), _maxReopens(maxReopens), + _maxTransitionFrames(maxTransitionFrames) { _device->AddRef(); @@ -263,6 +264,7 @@ class Stream for (;;) { _invalidated = false; + _attemptStarted = false; if (_isCapture) { captureLoop(); @@ -292,6 +294,7 @@ class Stream _stats.reopens++; logf("%s: reopening the stream (%d of %d)", _stats.name.c_str(), _stats.reopens, _maxReopens); + endBadRun(true); flushSilentRun(" (then invalidated)"); // A reopened stream ramps in again and its sequence resumes from @@ -301,6 +304,7 @@ class Stream refreshDevice(); } + endBadRun(true); flushSilentRun(" (until the end)"); if (gaveUp) { @@ -332,9 +336,22 @@ class Stream bool fail(const char *stage, HRESULT hr) { if (hr == AUDCLNT_E_DEVICE_INVALIDATED) { + char buf[128]; + _invalidated = true; _stats.invalidations++; + sprintf_s(buf, "invalidated during %s at %.3f s", stage, (nowMs() - g_runOriginMs) / 1000.0); + recordGap(buf); logf("%s: device invalidated during %s", _stats.name.c_str(), stage); + } else if (!_attemptStarted) { + // A setup call can fail while the endpoint is being reconfigured + // (the mix format goes stale, for one); retry it like an + // invalidation. The error sticks only if the retries run out. + _invalidated = true; + _stats.setupErrors++; + _stats.lastError = hr; + _stats.errorStage = stage; + logf("%s: %s failed during setup: %s", _stats.name.c_str(), stage, hresultText(hr).c_str()); } else { _stats.lastError = hr; _stats.errorStage = stage; @@ -441,6 +458,57 @@ class Stream } } + // Classifies a finished run of frames that did not decode. The engine + // fades a stream in and out, so a run that borders silence or the start + // of the stream is the right samples scaled: a ramp. A run between valid + // frames, or longer than any ramp, is corruption. + void endBadRun(bool bordersGap) + { + if (_badRun == 0) { + return; + } + + bool ramp = bordersGap && _badRun <= _maxTransitionFrames; + char head[128]; + + if (ramp) { + _stats.transitionFrames += _badRun; + _stats.rampRuns++; + } else { + _stats.wrongChannelFrames += _badRun; + _stats.corruptRuns++; + } + + sprintf_s(head, "%s run of %lld frames at %.3f s", ramp ? "ramp" : "corrupt", + _badRun, _badRunStartMs / 1000.0); + + if (!ramp) { + logf("%s: %s", _stats.name.c_str(), head); + } + + // Keep room for corruption: ramps only get the first half of the list. + size_t limit = ramp ? 8 : 16; + + if (_stats.badFrameSamples.size() < limit) { + _stats.badFrameSamples.push_back(head); + + for (const auto& sample : _badRunSamples) { + if (_stats.badFrameSamples.size() >= limit) { + break; + } + + _stats.badFrameSamples.push_back(" " + sample); + + if (!ramp) { + logf("%s: %s", _stats.name.c_str(), sample.c_str()); + } + } + } + + _badRun = 0; + _badRunSamples.clear(); + } + void decode(const BYTE *data, UINT32 frames) { double packetMs = nowMs() - g_runOriginMs; @@ -482,6 +550,9 @@ class Stream } if (allZero) { + // Silence right after undecodable frames: the engine faded out. + endBadRun(true); + _prevSilent = true; _stats.silentFrames++; if (_stats.validFrames == 0) { @@ -502,18 +573,17 @@ class Stream flushSilentRun(""); if (!channelsOk || !sequenceConsistent) { - bool transition = !_lockedIn; - - if (transition) { - _stats.transitionFrames++; - } else { - _stats.wrongChannelFrames++; + if (_badRun == 0) { + _badRunBordersGap = !_lockedIn || _prevSilent; + _badRunStartMs = packetMs; } - if (_stats.badFrameSamples.size() < 12) { + _badRun++; + _prevSilent = false; + + if (_badRunSamples.size() < 3) { char buf[512]; - int len = sprintf_s(buf, "%s frame %lld (after %lld valid):", - transition ? "transition" : "corrupt", + int len = sprintf_s(buf, "frame %lld (after %lld valid):", _stats.framesProcessed + (long long)f, _stats.validFrames); for (int c = 0; c < expectedChannels && c < 32 && len > 0 && len < 480; ++c) { @@ -521,13 +591,17 @@ class Stream " %08X/%02X", (unsigned int)values[c], (unsigned int)_channelIds[(size_t)c]); } - _stats.badFrameSamples.push_back(buf); - logf("%s: %s", _stats.name.c_str(), buf); + _badRunSamples.push_back(buf); } continue; } + // A valid frame ends a run that started after silence (fade in) + // as a ramp, and one that started after valid frames as corruption. + endBadRun(_badRunBordersGap); + _prevSilent = false; + if (_haveLastSequence && sequence != ((_lastSequence + 1) & 0xFFFF)) { char buf[128]; @@ -583,6 +657,9 @@ class Stream } _stats.started = true; + _attemptStarted = true; + _stats.lastError = S_OK; + _stats.errorStage.clear(); logf("%s: rendering %s, buffer %u frames", _stats.name.c_str(), _stats.format.c_str(), (unsigned)bufferFrames); @@ -676,6 +753,9 @@ class Stream } _stats.started = true; + _attemptStarted = true; + _stats.lastError = S_OK; + _stats.errorStage.clear(); logf("%s: capturing %s, buffer %u frames", _stats.name.c_str(), _stats.format.c_str(), (unsigned)bufferFrames); @@ -779,7 +859,14 @@ class Stream double _rate = 48000.0; std::wstring _deviceId; int _maxReopens = 0; + long long _maxTransitionFrames = 4800; bool _invalidated = false; + bool _attemptStarted = false; + bool _prevSilent = false; + long long _badRun = 0; + bool _badRunBordersGap = false; + double _badRunStartMs = 0.0; + std::vector _badRunSamples; HANDLE _stopEvent = nullptr; std::thread _thread; }; @@ -924,6 +1011,9 @@ std::string StreamStats::toJson() const .setInt("midStreamSilentFrames", midStreamSilentFrames) .setInt("invalidations", invalidations) .setInt("reopens", reopens) + .setInt("setupErrors", setupErrors) + .setInt("rampRuns", rampRuns) + .setInt("corruptRuns", corruptRuns) .setInt("timeouts", timeouts) .setBool("passed", passed) .setString("failure", failure); @@ -998,12 +1088,7 @@ static void evaluate(StreamStats *s, const WasapiOptions& options) } if (s->wrongChannelFrames > 0) { - s->failure = "corrupt frames after the signal locked in"; - return; - } - - if (s->transitionFrames > options.maxTransitionFrames) { - s->failure = "start-up transition too long"; + s->failure = "corrupt frames"; return; } @@ -1031,9 +1116,11 @@ WasapiResult runWasapi(const WasapiOptions& options, const FoundEndpoints& endpo for (int pair = 0; pair < layout.pairs; ++pair) { streams.emplace_back(new Stream( - layout, pair, endpoints.render[(size_t)pair], false, options.maxReopens)); + layout, pair, endpoints.render[(size_t)pair], false, options.maxReopens, + options.maxTransitionFrames)); streams.emplace_back(new Stream( - layout, pair, endpoints.capture[(size_t)pair], true, options.maxReopens)); + layout, pair, endpoints.capture[(size_t)pair], true, options.maxReopens, + options.maxTransitionFrames)); } if (options.settleSeconds > 0) { @@ -1071,11 +1158,11 @@ WasapiResult runWasapi(const WasapiOptions& options, const FoundEndpoints& endpo if (stats.isCapture) { logf("%s: %lld frames, %lld valid, %lld silent (%lld at start, %lld dropout), " - "%lld transition, %lld discontinuities, %lld corrupt, %d reopens: %s", + "%lld ramp, %lld discontinuities, %lld corrupt, %d reopens, %d setup errors: %s", stats.name.c_str(), stats.framesProcessed, stats.validFrames, stats.silentFrames, stats.startupSilentFrames, stats.midStreamSilentFrames, stats.transitionFrames, stats.discontinuities, stats.wrongChannelFrames, - stats.reopens, stats.passed ? "PASS" : stats.failure.c_str()); + stats.reopens, stats.setupErrors, stats.passed ? "PASS" : stats.failure.c_str()); } else { logf("%s: %lld frames rendered, %d reopens: %s", stats.name.c_str(), stats.framesProcessed, stats.reopens, diff --git a/SarTest/wasapi.h b/SarTest/wasapi.h index be7115f..046c977 100644 --- a/SarTest/wasapi.h +++ b/SarTest/wasapi.h @@ -47,6 +47,8 @@ struct StreamStats // Undecodable frames before the signal locks in (at the start, and again // after a reopen): the engine ramping a new stream's volume in. long long transitionFrames = 0; + long long rampRuns = 0; + long long corruptRuns = 0; // Silent frames once the signal has locked in: dropouts. long long midStreamSilentFrames = 0; long long timeouts = 0; @@ -54,6 +56,9 @@ struct StreamStats // was reopened after one, as a well-behaved client would. int invalidations = 0; int reopens = 0; + // Setup calls that failed and were retried (e.g. a mix format that went + // stale because the endpoint was reconfigured in between). + int setupErrors = 0; // The first undecodable frames, with their raw sample values. std::vector badFrameSamples; // The first dropouts and sequence jumps, timed from the start of the run. @@ -87,13 +92,13 @@ struct WasapiOptions // The ASIO host is going to be killed underneath the streams, so device // invalidation is the expected outcome rather than a failure. bool expectInvalidation = false; - double minValidRatio = 0.9; + double minValidRatio = 0.5; long long maxDiscontinuities = -1; // -1: report only // SarAsio broadcasts a format change whenever one of its endpoints // becomes active, which invalidates open streams: wait before streaming, // and reopen invalidated streams like a well-behaved client would. double settleSeconds = 2.0; - int maxReopens = 3; + int maxReopens = 20; long long maxTransitionFrames = 4800; }; diff --git a/SarTestClock/SarTestClock.cpp b/SarTestClock/SarTestClock.cpp index 5c65003..fdc8c67 100644 --- a/SarTestClock/SarTestClock.cpp +++ b/SarTestClock/SarTestClock.cpp @@ -176,6 +176,8 @@ class SoftwareClock: public IASIO _ticks = 0; _lateTicks = 0; _maxLatenessMs = 0.0; + _maxCallbackMs = 0.0; + _slowCallbacks = 0; _running = true; _thread = std::thread([this] { tickThread(); }); return AsioStatus::OK; @@ -377,6 +379,8 @@ class SoftwareClock: public IASIO stats->sampleRate = _sampleRate; stats->bufferFrames = (uint32_t)_bufferFrames; stats->reserved = 0; + stats->maxCallbackMs = _maxCallbackMs.load(); + stats->slowCallbacks = _slowCallbacks.load(); return AsioStatus::OK; } @@ -437,7 +441,20 @@ class SoftwareClock: public IASIO } _samplePosition += _bufferFrames; + + int64_t callbackStart = fileTimeNow(); + _callbacks.tick(bufferIndex, AsioBool::True); + + double callbackMs = (double)(fileTimeNow() - callbackStart) / 10000.0; + + if (callbackMs > _maxCallbackMs.load()) { + _maxCallbackMs = callbackMs; + } + + if (callbackMs > periodMs / 2.0) { + _slowCallbacks++; + } bufferIndex ^= 1; _ticks++; } @@ -462,6 +479,8 @@ class SoftwareClock: public IASIO std::atomic _ticks{ 0 }; std::atomic _lateTicks{ 0 }; std::atomic _maxLatenessMs{ 0.0 }; + std::atomic _maxCallbackMs{ 0.0 }; + std::atomic _slowCallbacks{ 0 }; }; class ClassFactory: public IClassFactory diff --git a/SarTestClock/clockstats.h b/SarTestClock/clockstats.h index 3f89f9c..29a5fe6 100644 --- a/SarTestClock/clockstats.h +++ b/SarTestClock/clockstats.h @@ -43,6 +43,11 @@ struct ClockStats double sampleRate; uint32_t bufferFrames; uint32_t reserved; + // Time spent inside the host's bufferSwitch callback, which runs on the + // clock thread and includes SarAsio's whole tick. A blocking call in + // there stalls every endpoint at once. + double maxCallbackMs; + uint64_t slowCallbacks; // callbacks that took more than half a period }; } // namespace SarTestClock diff --git a/tools/test/README.md b/tools/test/README.md index 2b370f6..92f92fb 100644 --- a/tools/test/README.md +++ b/tools/test/README.md @@ -18,7 +18,10 @@ two dummy output channels and delivers `bufferSwitch` callbacks from a timer thread every 480 frames at 48 kHz (10 ms, the audio engine's period). SarAsio wraps it exactly like a real interface, so `SarAsioWrapper::start()` goes through the full `SarClient` path: open the control device, set the buffer -layout, create the endpoints, poll the notification handle queue. +layout, create the endpoints, poll the notification handle queue. The clock +also times each callback into the host, which includes SarAsio's whole tick, +and reports the slowest one and how many took longer than half a period: a +blocking call inside SarAsio's tick stalls every endpoint at once. `SarTest.exe host` loads `SarAsio.dll` directly through `DllGetClassObject` (no COM registration needed), creates buffers for every channel, and on each @@ -32,23 +35,26 @@ endpoint back to its recording twin, channel for channel. Render streams emit a signal where each sample encodes its channel id and a per-frame sequence number, chosen so it survives the engine's float/int32 conversions exactly. Capture streams decode it and count valid frames, -silence and sequence discontinuities. Frames that do not decode are split in -two. Before the signal locks in (its first valid frame, and again after a -reopen) they are the engine ramping a new stream's volume in, the correct -samples scaled up from near zero, and count as transition frames; once it -has locked in they are corruption. A capture stream passes -when it received the signal, saw no corrupt frames, had a transition shorter -than 100 ms (`--max-transition`), and at least 90% of the frames after the -initial silence were valid (`--min-valid`; `--max-discontinuities` -optionally bounds sequence gaps). The first undecodable frames are recorded -in the results with their raw sample values and expected channel ids. +silence and sequence discontinuities. A run of frames that do not decode is +a ramp when it borders silence or the start of the stream: the engine fades +streams in and out, so those are the right samples scaled, which the raw +values recorded in the results show. A run between valid frames, or longer +than `--max-transition` frames (100 ms), is corruption. A capture stream +passes when it received the signal, saw no corruption, and at least half of +the frames after the initial silence were valid (`--min-valid`; +`--max-discontinuities` optionally bounds sequence gaps). Dropouts, +discontinuities, ramps, invalidations and reopens are reported for every +stream; on a VM they vary from run to run, so compare them with a baseline +run rather than reading one run's numbers as absolute. SarAsio broadcasts a format change whenever one of its endpoints becomes active, so streams that are open around the time the ASIO host starts get -invalidated (`AUDCLNT_E_DEVICE_INVALIDATED`). Streams therefore start -`--settle` seconds (2 by default) after every endpoint is active, and an -invalidated stream is reopened, as a well-behaved client would, up to -`--max-reopens` times (3). Invalidations and reopens are counted in the +invalidated (`AUDCLNT_E_DEVICE_INVALIDATED`); with many endpoints the +broadcasts repeat for seconds. Streams therefore start `--settle` seconds (2 +by default) after every endpoint is active, and an invalidated stream is +reopened, as a well-behaved client would, up to `--max-reopens` times (20). +A setup call that fails while the endpoint is being reconfigured is retried +the same way. Invalidations, setup errors and reopens are counted in the results so they stay visible. Capture streams also record dropouts (silence after the signal locked in) From 458202c1353237db5f2c1ea03c9e27c4d5b50896 Mon Sep 17 00:00:00 2001 From: Mack Straight Date: Sun, 13 Sep 2026 15:18:23 -0400 Subject: [PATCH 11/14] ci: ship PDBs with the test packages 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) Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp --- .github/workflows/build.yml | 12 ++++++++++++ tools/test/README.md | 3 +++ 2 files changed, 15 insertions(+) diff --git a/.github/workflows/build.yml b/.github/workflows/build.yml index bab9720..2ff6df7 100644 --- a/.github/workflows/build.yml +++ b/.github/workflows/build.yml @@ -130,6 +130,11 @@ jobs: foreach ($ext in 'sys', 'inf', 'cat') { Copy-Item "$stage/SynchronousAudioRouter.$ext" $signed -Force } + # Driver symbols, for reading crash dumps from test machines. + $pdb = Get-ChildItem -Recurse -Filter 'SynchronousAudioRouter.pdb' | + Where-Object { $_.FullName -match "\\$plat\\Release\\" } | + Sort-Object LastWriteTime -Descending | Select-Object -First 1 + if ($pdb) { Copy-Item $pdb.FullName $signed -Force } else { Write-Warning 'SynchronousAudioRouter.pdb not found' } $cert = New-SelfSignedCertificate -Type CodeSigningCert -Subject 'CN=SAR CI test signing' ` -CertStoreLocation Cert:\CurrentUser\My -HashAlgorithm SHA256 -NotAfter (Get-Date).AddYears(2) Export-Certificate -Cert $cert -FilePath "$signed/testsign.cer" | Out-Null @@ -213,6 +218,13 @@ jobs: if (-not $file) { throw "$name not found - did the build succeed?" } Copy-Item $file.FullName $stage -Force } + # Symbols, for reading crash dumps from test machines. + foreach ($name in 'SarAsio.pdb', 'SarTest.pdb', 'SarTestClock.pdb') { + $file = Get-ChildItem -Recurse -Filter $name | + Where-Object { $_.FullName -match "\\Release\\" } | + Sort-Object LastWriteTime -Descending | Select-Object -First 1 + if ($file) { Copy-Item $file.FullName $stage -Force } else { Write-Warning "$name not found" } + } New-Item -ItemType Directory -Force -Path "$stage/test" | Out-Null Copy-Item tools/test/* "$stage/test" -Force # Materialize the hash lines into a variable BEFORE opening the output diff --git a/tools/test/README.md b/tools/test/README.md index 92f92fb..53c26f9 100644 --- a/tools/test/README.md +++ b/tools/test/README.md @@ -128,6 +128,9 @@ scripts assume they may overwrite the SAR configuration. detection, so a lock-order bug bugchecks with the exact cycle instead of hanging: `verifier /flags 0x20 /driver SynchronousAudioRouter.sys`. 5. Enable kernel memory dumps so a bugcheck leaves `MEMORY.DMP` behind. + The test packages carry the PDBs (`SynchronousAudioRouter.pdb` in the + test-signed driver package, the user-mode ones next to their binaries) + needed to read it. 6. Take a checkpoint. Restore it before every run. Then, elevated: From d332ac684e3800a0042208851abd98294d8c27d6 Mon Sep 17 00:00:00 2001 From: Mack Straight Date: Sun, 13 Sep 2026 15:25:57 -0400 Subject: [PATCH 12/14] test: recognize ramps by their gain, not their position 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) Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp --- SarTest/wasapi.cpp | 69 +++++++++++++++++++++++++++++++++++++------- tools/test/README.md | 12 ++++---- 2 files changed, 66 insertions(+), 15 deletions(-) diff --git a/SarTest/wasapi.cpp b/SarTest/wasapi.cpp index dda451f..a66e3a3 100644 --- a/SarTest/wasapi.cpp +++ b/SarTest/wasapi.cpp @@ -458,29 +458,72 @@ class Stream } } - // Classifies a finished run of frames that did not decode. The engine - // fades a stream in and out, so a run that borders silence or the start - // of the stream is the right samples scaled: a ramp. A run between valid - // frames, or longer than any ramp, is corruption. + // True when the frame is the test signal scaled by one gain on every + // channel: the engine ramping a stream's volume, not corrupted data. + // Sample k on a channel with id i is i * 65536 + seq, so two channels + // give the gain from their difference and every channel must agree. + bool isScaledSignal(const int32_t *values, int count) const + { + if (count < 2 || _channelIds[0] == _channelIds[1]) { + return false; + } + + double ida = (double)_channelIds[0], idb = (double)_channelIds[1]; + double gain = (double)(values[1] - values[0]) / ((idb - ida) * 65536.0); + + if (!(gain > 0.0 && gain < 1.0)) { + return false; + } + + double seq = (double)values[0] / gain - ida * 65536.0; + + if (seq < -2.0 || seq > 65537.0) { + return false; + } + + for (int c = 0; c < count && c < 32; ++c) { + double expected = gain * ((double)_channelIds[(size_t)c] * 65536.0 + seq); + + if (fabs((double)values[c] - expected) > 3.0 + fabs(expected) * 0.002) { + return false; + } + } + + return true; + } + + // Classifies a finished run of frames that did not decode. Frames that + // are the signal scaled by one gain are a ramp wherever they occur (a + // reopened stream can fade in with no silence before it). Other frames + // are corruption, unless the run borders silence or the start of the + // stream, where the gain is too small for the scaling to survive + // rounding. A run longer than any ramp is corruption regardless. void endBadRun(bool bordersGap) { if (_badRun == 0) { return; } - bool ramp = bordersGap && _badRun <= _maxTransitionFrames; - char head[128]; + long long corrupt = bordersGap ? 0 : _badRunUnscaled; + + if (_badRun > _maxTransitionFrames) { + corrupt = _badRun; + } + + bool ramp = corrupt == 0; + char head[160]; + + _stats.transitionFrames += _badRun - corrupt; + _stats.wrongChannelFrames += corrupt; if (ramp) { - _stats.transitionFrames += _badRun; _stats.rampRuns++; } else { - _stats.wrongChannelFrames += _badRun; _stats.corruptRuns++; } - sprintf_s(head, "%s run of %lld frames at %.3f s", ramp ? "ramp" : "corrupt", - _badRun, _badRunStartMs / 1000.0); + sprintf_s(head, "%s run of %lld frames (%lld not a scaled signal) at %.3f s", + ramp ? "ramp" : "corrupt", _badRun, _badRunUnscaled, _badRunStartMs / 1000.0); if (!ramp) { logf("%s: %s", _stats.name.c_str(), head); @@ -506,6 +549,7 @@ class Stream } _badRun = 0; + _badRunUnscaled = 0; _badRunSamples.clear(); } @@ -581,6 +625,10 @@ class Stream _badRun++; _prevSilent = false; + if (!isScaledSignal(values, expectedChannels)) { + _badRunUnscaled++; + } + if (_badRunSamples.size() < 3) { char buf[512]; int len = sprintf_s(buf, "frame %lld (after %lld valid):", @@ -864,6 +912,7 @@ class Stream bool _attemptStarted = false; bool _prevSilent = false; long long _badRun = 0; + long long _badRunUnscaled = 0; bool _badRunBordersGap = false; double _badRunStartMs = 0.0; std::vector _badRunSamples; diff --git a/tools/test/README.md b/tools/test/README.md index 53c26f9..57b626d 100644 --- a/tools/test/README.md +++ b/tools/test/README.md @@ -35,11 +35,13 @@ endpoint back to its recording twin, channel for channel. Render streams emit a signal where each sample encodes its channel id and a per-frame sequence number, chosen so it survives the engine's float/int32 conversions exactly. Capture streams decode it and count valid frames, -silence and sequence discontinuities. A run of frames that do not decode is -a ramp when it borders silence or the start of the stream: the engine fades -streams in and out, so those are the right samples scaled, which the raw -values recorded in the results show. A run between valid frames, or longer -than `--max-transition` frames (100 ms), is corruption. A capture stream +silence and sequence discontinuities. Frames that do not decode but are the +signal scaled by one gain on every channel are a ramp: the engine fades +streams in and out, including a reopened stream that fades in with no +silence before it, and the raw values recorded in the results show the +scaling. Other undecodable frames are corruption, except right next to +silence where the gain is too small for the scaling to survive rounding. A +run longer than `--max-transition` frames (100 ms) is corruption regardless. A capture stream passes when it received the signal, saw no corruption, and at least half of the frames after the initial silence were valid (`--min-valid`; `--max-discontinuities` optionally bounds sequence gaps). Dropouts, From 9b10e1b80d1dbdca7f57c10b8f8e01c6c300946c Mon Sep 17 00:00:00 2001 From: Mack Straight Date: Sun, 13 Sep 2026 15:44:19 -0400 Subject: [PATCH 13/14] test: time every stream's WASAPI calls 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) Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp --- SarTest/wasapi.h | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/SarTest/wasapi.h b/SarTest/wasapi.h index 046c977..18e5f10 100644 --- a/SarTest/wasapi.h +++ b/SarTest/wasapi.h @@ -59,6 +59,10 @@ struct StreamStats // Setup calls that failed and were retried (e.g. a mix format that went // stale because the endpoint was reconfigured in between). int setupErrors = 0; + // The slowest WASAPI call the stream made, to name stalls in the audio + // stack; calls over a second are also recorded in gapSamples. + double slowestCallMs = 0.0; + std::string slowestCall; // The first undecodable frames, with their raw sample values. std::vector badFrameSamples; // The first dropouts and sequence jumps, timed from the start of the run. From cea7ed808c4c9b3375100abc0500345aadd5f8f7 Mon Sep 17 00:00:00 2001 From: Mack Straight Date: Sun, 13 Sep 2026 15:45:54 -0400 Subject: [PATCH 14/14] test: finish timing stream WASAPI calls 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) Claude-Session: https://claude.ai/code/session_015Ae1KbSGxTuh8F6i85MGxp --- SarTest/wasapi.cpp | 76 +++++++++++++++++++++++++++++++++----------- tools/test/README.md | 4 ++- 2 files changed, 60 insertions(+), 20 deletions(-) diff --git a/SarTest/wasapi.cpp b/SarTest/wasapi.cpp index a66e3a3..3654bbf 100644 --- a/SarTest/wasapi.cpp +++ b/SarTest/wasapi.cpp @@ -316,6 +316,32 @@ class Stream } } + // Times a WASAPI call; one that takes over a second is logged and + // recorded with the time it returned, so a stall is named, not guessed. + template + HRESULT timed(const char *name, Call call) + { + double start = nowMs(); + HRESULT hr = call(); + double elapsed = nowMs() - start; + + if (elapsed > _stats.slowestCallMs) { + _stats.slowestCallMs = elapsed; + _stats.slowestCall = name; + } + + if (elapsed > 1000.0) { + char buf[160]; + + sprintf_s(buf, "slow %s: %.0f ms, returned at %.3f s", name, elapsed, + (nowMs() - g_runOriginMs) / 1000.0); + recordGap(buf); + logf("%s: %s", _stats.name.c_str(), buf); + } + + return hr; + } + // Re-resolves the endpoint by ID so a retry does not reuse a device // object that belonged to the invalidated instance. void refreshDevice() @@ -364,8 +390,9 @@ class Stream // Shared-mode, event-driven client on the mix format. bool initialize(ComPtr *client, UINT32 *bufferFrames, HANDLE *event) { - HRESULT hr = _device->Activate( - __uuidof(IAudioClient), CLSCTX_ALL, nullptr, client->putVoid()); + HRESULT hr = timed("Activate", [&] { + return _device->Activate(__uuidof(IAudioClient), CLSCTX_ALL, nullptr, client->putVoid()); + }); if (FAILED(hr)) { return fail("Activate", hr); @@ -373,7 +400,7 @@ class Stream WAVEFORMATEX *mix = nullptr; - hr = (*client)->GetMixFormat(&mix); + hr = timed("GetMixFormat", [&] { return (*client)->GetMixFormat(&mix); }); if (FAILED(hr) || !mix) { return fail("GetMixFormat", hr); @@ -395,29 +422,31 @@ class Stream _stats.name.c_str(), (unsigned)mix->nChannels, _channelIds.size()); } - hr = (*client)->Initialize( - AUDCLNT_SHAREMODE_SHARED, AUDCLNT_STREAMFLAGS_EVENTCALLBACK, - 0, 0, mix, nullptr); + hr = timed("Initialize", [&] { + return (*client)->Initialize( + AUDCLNT_SHAREMODE_SHARED, AUDCLNT_STREAMFLAGS_EVENTCALLBACK, + 0, 0, mix, nullptr); + }); CoTaskMemFree(mix); if (FAILED(hr)) { return fail("Initialize", hr); } - hr = (*client)->GetBufferSize(bufferFrames); + hr = timed("GetBufferSize", [&] { return (*client)->GetBufferSize(bufferFrames); }); if (FAILED(hr)) { return fail("GetBufferSize", hr); } *event = CreateEventW(nullptr, FALSE, FALSE, nullptr); - hr = (*client)->SetEventHandle(*event); + hr = timed("SetEventHandle", [&] { return (*client)->SetEventHandle(*event); }); if (FAILED(hr)) { return fail("SetEventHandle", hr); } - setUnityVolume(_device, client->get()); + timed("SetVolume", [&] { setUnityVolume(_device, client->get()); return S_OK; }); return true; } @@ -681,7 +710,9 @@ class Stream } ComPtr render; - HRESULT hr = client->GetService(__uuidof(IAudioRenderClient), render.putVoid()); + HRESULT hr = timed("GetService", [&] { + return client->GetService(__uuidof(IAudioRenderClient), render.putVoid()); + }); if (FAILED(hr)) { fail("GetService(IAudioRenderClient)", hr); @@ -696,7 +727,7 @@ class Stream render->ReleaseBuffer(bufferFrames, 0); } - hr = client->Start(); + hr = timed("Start", [&] { return client->Start(); }); if (FAILED(hr)) { fail("Start", hr); @@ -765,7 +796,7 @@ class Stream _stats.framesProcessed += available; } - client->Stop(); + timed("Stop", [&] { return client->Stop(); }); CloseHandle(event); } @@ -784,7 +815,9 @@ class Stream } ComPtr capture; - HRESULT hr = client->GetService(__uuidof(IAudioCaptureClient), capture.putVoid()); + HRESULT hr = timed("GetService", [&] { + return client->GetService(__uuidof(IAudioCaptureClient), capture.putVoid()); + }); if (FAILED(hr)) { fail("GetService(IAudioCaptureClient)", hr); @@ -792,7 +825,7 @@ class Stream return; } - hr = client->Start(); + hr = timed("Start", [&] { return client->Start(); }); if (FAILED(hr)) { fail("Start", hr); @@ -889,7 +922,7 @@ class Stream } } - client->Stop(); + timed("Stop", [&] { return client->Stop(); }); CloseHandle(event); } @@ -1063,6 +1096,8 @@ std::string StreamStats::toJson() const .setInt("setupErrors", setupErrors) .setInt("rampRuns", rampRuns) .setInt("corruptRuns", corruptRuns) + .setDouble("slowestCallMs", slowestCallMs) + .setString("slowestCall", slowestCall) .setInt("timeouts", timeouts) .setBool("passed", passed) .setString("failure", failure); @@ -1207,14 +1242,17 @@ WasapiResult runWasapi(const WasapiOptions& options, const FoundEndpoints& endpo if (stats.isCapture) { logf("%s: %lld frames, %lld valid, %lld silent (%lld at start, %lld dropout), " - "%lld ramp, %lld discontinuities, %lld corrupt, %d reopens, %d setup errors: %s", + "%lld ramp, %lld discontinuities, %lld corrupt, %d reopens, %d setup errors, " + "slowest call %s %.0f ms: %s", stats.name.c_str(), stats.framesProcessed, stats.validFrames, stats.silentFrames, stats.startupSilentFrames, stats.midStreamSilentFrames, stats.transitionFrames, stats.discontinuities, stats.wrongChannelFrames, - stats.reopens, stats.setupErrors, stats.passed ? "PASS" : stats.failure.c_str()); + stats.reopens, stats.setupErrors, stats.slowestCall.c_str(), stats.slowestCallMs, + stats.passed ? "PASS" : stats.failure.c_str()); } else { - logf("%s: %lld frames rendered, %d reopens: %s", stats.name.c_str(), - stats.framesProcessed, stats.reopens, + logf("%s: %lld frames rendered, %d reopens, slowest call %s %.0f ms: %s", + stats.name.c_str(), stats.framesProcessed, stats.reopens, + stats.slowestCall.c_str(), stats.slowestCallMs, stats.passed ? "PASS" : stats.failure.c_str()); } diff --git a/tools/test/README.md b/tools/test/README.md index 57b626d..57f1a79 100644 --- a/tools/test/README.md +++ b/tools/test/README.md @@ -61,7 +61,9 @@ results so they stay visible. Capture streams also record dropouts (silence after the signal locked in) and sequence jumps, timed from the start of the run, so gaps can be lined up -across endpoints to tell a global stall from a per-endpoint one. +across endpoints to tell a global stall from a per-endpoint one. Every stream +also times its WASAPI calls and records any that take longer than a second +with the time it returned, so a stall in the audio stack is named. `SarTest.exe run` does both in one process and repeats for `--iterations`, which is the "start the DAW, stop the DAW" cycle that creates and tears down