diff --git a/SarTest/SarTest.cpp b/SarTest/SarTest.cpp index fbb19e4..5321622 100644 --- a/SarTest/SarTest.cpp +++ b/SarTest/SarTest.cpp @@ -62,6 +62,10 @@ int usage() " SarTest endpoint-names\n" " Rename an endpoint keeping its ID, then give it a new ID, and report\n" " the name Windows shows each time (issues #15, #66).\n" + " SarTest meter [--duration S] [--process ] [--min-peak P]\n" + " Watch the audio sessions on every active playback endpoint and\n" + " report which processes played and how loud; with --process, fail\n" + " unless that process reached --min-peak (default 0.01).\n" "\n" "Layout options: --endpoints N (playback/recording pairs, default 2)\n" " --channels C (per endpoint, default 2) --prefix \n" @@ -822,6 +826,35 @@ int cmdEndpointNames(const Args& args) return rc; } +int cmdMeter(const Args& args) +{ + SessionMeterOptions options; + + options.durationSeconds = args.getDouble(L"duration", 10.0); + options.process = args.get(L"process", L""); + options.minPeak = args.getDouble(L"min-peak", 0.01); + + SessionMeterResult meter = runSessionMeter(options); + int rc = meter.passed ? 0 : 2; + JsonObject result; + + result.setString("command", "meter") + .setBool("passed", meter.passed) + .setInt("exitCode", rc) + .setString("process", narrow(options.process)) + .setDouble("processPeak", meter.processPeak) + .setRaw("sessions", meter.sessionsJson); + + if (!meter.failure.empty()) { + result.setString("failure", meter.failure); + logf("%s", meter.failure.c_str()); + } + + writeResults(args, result.str()); + logf("%s", rc == 0 ? "PASSED" : "FAILED"); + return rc; +} + } // namespace int wmain(int argc, wchar_t **argv) @@ -861,6 +894,8 @@ int wmain(int argc, wchar_t **argv) rc = cmdNoInterface(args); } else if (args.command == L"endpoint-names") { rc = cmdEndpointNames(args); + } else if (args.command == L"meter") { + rc = cmdMeter(args); } else { rc = usage(); } diff --git a/SarTest/wasapi.cpp b/SarTest/wasapi.cpp index 3654bbf..1429dad 100644 --- a/SarTest/wasapi.cpp +++ b/SarTest/wasapi.cpp @@ -1564,4 +1564,173 @@ void RaceOpeners::work(Worker *worker) } +namespace { + +std::wstring processImageName(DWORD pid) +{ + HANDLE process = OpenProcess(PROCESS_QUERY_LIMITED_INFORMATION, FALSE, pid); + std::wstring name; + + if (!process) { + return name; + } + + wchar_t path[MAX_PATH] = {}; + DWORD size = MAX_PATH; + + if (QueryFullProcessImageNameW(process, 0, path, &size)) { + name = path; + + auto slash = name.find_last_of(L"\\/"); + + if (slash != std::wstring::npos) { + name = name.substr(slash + 1); + } + } + + CloseHandle(process); + return name; +} + +struct SessionSeen +{ + std::string endpoint; + DWORD pid = 0; + std::wstring process; + bool active = false; + float maxPeak = 0.0f; +}; + +} // namespace + +SessionMeterResult runSessionMeter(const SessionMeterOptions& options) +{ + SessionMeterResult result; + ComPtr enumerator; + + if (!createEnumerator(&enumerator)) { + result.failure = "no device enumerator"; + result.sessionsJson = "[]"; + return result; + } + + // Keyed by endpoint and process ID. + std::map seen; + double deadline = nowMs() + options.durationSeconds * 1000.0; + + while (nowMs() < deadline) { + ComPtr devices; + UINT count = 0; + + if (SUCCEEDED(enumerator->EnumAudioEndpoints( + eRender, DEVICE_STATE_ACTIVE, devices.put()))) { + devices->GetCount(&count); + } + + for (UINT i = 0; i < count; ++i) { + ComPtr device; + ComPtr store; + ComPtr manager; + ComPtr sessions; + std::string endpoint; + int sessionCount = 0; + + if (FAILED(devices->Item(i, device.put()))) { + continue; + } + + if (SUCCEEDED(device->OpenPropertyStore(STGM_READ, store.put()))) { + endpoint = narrow(propertyString(store.get(), PKEY_Device_FriendlyName)); + } + + if (FAILED(device->Activate(__uuidof(IAudioSessionManager2), + CLSCTX_ALL, nullptr, manager.putVoid())) || + FAILED(manager->GetSessionEnumerator(sessions.put()))) { + continue; + } + + sessions->GetCount(&sessionCount); + + for (int k = 0; k < sessionCount; ++k) { + ComPtr control; + ComPtr control2; + ComPtr meter; + AudioSessionState state = AudioSessionStateInactive; + DWORD pid = 0; + float peak = 0.0f; + + if (FAILED(sessions->GetSession(k, control.put())) || + FAILED(control->QueryInterface( + __uuidof(IAudioSessionControl2), control2.putVoid()))) { + continue; + } + + control2->GetProcessId(&pid); + + if (pid == 0) { + continue; // system sounds + } + + control->GetState(&state); + + if (SUCCEEDED(control->QueryInterface( + __uuidof(IAudioMeterInformation), meter.putVoid()))) { + meter->GetPeakValue(&peak); + } + + SessionSeen& entry = seen[endpoint + "|" + std::to_string(pid)]; + + if (entry.pid == 0) { + entry.endpoint = endpoint; + entry.pid = pid; + entry.process = processImageName(pid); + logf("Session of %s (pid %lu) on %s", + narrow(entry.process).c_str(), pid, endpoint.c_str()); + } + + entry.active = entry.active || state == AudioSessionStateActive; + entry.maxPeak = std::max(entry.maxPeak, peak); + } + } + + Sleep(100); + } + + std::vector items; + + for (auto& pair : seen) { + const SessionSeen& entry = pair.second; + JsonObject item; + + logf("%s (pid %lu) on %s: %s, peak %.3f", narrow(entry.process).c_str(), + entry.pid, entry.endpoint.c_str(), entry.active ? "active" : "never active", + entry.maxPeak); + item.setString("endpoint", entry.endpoint) + .setInt("pid", entry.pid) + .setString("process", narrow(entry.process)) + .setBool("active", entry.active) + .setDouble("maxPeak", entry.maxPeak); + items.push_back(item.str()); + + if (!options.process.empty() && + _wcsicmp(entry.process.c_str(), options.process.c_str()) == 0) { + result.processPeak = std::max(result.processPeak, (double)entry.maxPeak); + } + } + + result.sessionsJson = jsonArray(items); + + if (options.process.empty() || result.processPeak >= options.minPeak) { + result.passed = true; + } else { + char buf[160]; + + sprintf_s(buf, "%s never played louder than %.3f (needs %.3f)", + narrow(options.process).c_str(), result.processPeak, options.minPeak); + result.failure = buf; + } + + return result; +} + } // namespace SarTest diff --git a/SarTest/wasapi.h b/SarTest/wasapi.h index 18e5f10..2b163c8 100644 --- a/SarTest/wasapi.h +++ b/SarTest/wasapi.h @@ -168,5 +168,27 @@ class RaceOpeners bool _clean = true; }; +// Watches the audio sessions on every active playback endpoint for a while: +// which process each belongs to and how loud it got. Tells whether an +// application outside the harness (a browser) produced audio at all. +struct SessionMeterOptions +{ + double durationSeconds = 10.0; + // Image name (e.g. msedge.exe) that must reach minPeak; empty to only + // report. + std::wstring process; + double minPeak = 0.01; +}; + +struct SessionMeterResult +{ + bool passed = false; + double processPeak = 0.0; + std::string failure; + std::string sessionsJson; +}; + +SessionMeterResult runSessionMeter(const SessionMeterOptions& options); + } // namespace SarTest #endif // _SAR_TEST_WASAPI_H diff --git a/SynchronousAudioRouter/entry.cpp b/SynchronousAudioRouter/entry.cpp index 62f9936..6a0e6ee 100644 --- a/SynchronousAudioRouter/entry.cpp +++ b/SynchronousAudioRouter/entry.cpp @@ -746,8 +746,60 @@ VOID SarUnload(PDRIVER_OBJECT driverObject) } } +// The buffer of a ProcessMitigationPolicy query (what user mode's +// GetProcessMitigationPolicy uses): the policy to read, then its flags. +typedef struct SarProcessMitigationPolicyInformation +{ + ULONG policy; + ULONG flags; +} SarProcessMitigationPolicyInformation; + +// Exported by the kernel and documented, but not declared by the headers +// this driver includes. +extern "C" NTSYSAPI NTSTATUS NTAPI ZwQueryInformationProcess( + _In_ HANDLE ProcessHandle, + _In_ PROCESSINFOCLASS ProcessInformationClass, + _Out_writes_bytes_(ProcessInformationLength) PVOID ProcessInformation, + _In_ ULONG ProcessInformationLength, + _Out_opt_ PULONG ReturnLength); + +#define SAR_PROCESS_MITIGATION_POLICY_CLASS ((PROCESSINFOCLASS)52) +#define SAR_PROCESS_SIGNATURE_POLICY 8 +// PROCESS_MITIGATION_BINARY_SIGNATURE_POLICY's MicrosoftSignedOnly, +// StoreSignedOnly and MitigationOptIn (Microsoft, Store or WHQL) flags. +#define SAR_SIGNATURE_POLICY_RESTRICTIONS 0x7 + +// Whether the current process may only load images signed by Microsoft (or +// the Store, or WHQL). SarAsio.dll is none of those. +static BOOL SarCurrentProcessRequiresMicrosoftSignedImages() +{ + SarProcessMitigationPolicyInformation info = {}; + + info.policy = SAR_PROCESS_SIGNATURE_POLICY; + + NTSTATUS status = ZwQueryInformationProcess( + ZwCurrentProcess(), SAR_PROCESS_MITIGATION_POLICY_CLASS, + &info, sizeof(info), nullptr); + + if (!NT_SUCCESS(status)) { + return FALSE; + } + + return (info.flags & SAR_SIGNATURE_POLICY_RESTRICTIONS) != 0; +} + BOOL SarFilterMatchesCurrentProcess(SarDriverExtension *extension) { + // Pointing a process that may only load Microsoft-signed images at + // SarAsio.dll makes Code Integrity refuse the load, so the audio classes + // can't be created there at all: Chromium's sandboxed audio service + // (Chrome, Edge, Discord) does this and then plays nothing. Leave such a + // process with the system's classes; it loses application routing but + // keeps its audio. + if (SarCurrentProcessRequiresMicrosoftSignedImages()) { + return FALSE; + } + PTOKEN_USER tokenUser = nullptr; NTSTATUS status = SarCopyProcessUser(PsGetCurrentProcess(), &tokenUser); diff --git a/tools/test/Invoke-SarTest.ps1 b/tools/test/Invoke-SarTest.ps1 index 1cf8f9c..e944685 100644 --- a/tools/test/Invoke-SarTest.ps1 +++ b/tools/test/Invoke-SarTest.ps1 @@ -34,8 +34,8 @@ param( [int]$TimeoutSeconds = 600, [switch]$SkipInstall, [switch]$SkipKillTest, - # Any of issues, matrix, race, kill. Installation always runs. - [string[]]$Scenarios = @('issues', 'matrix', 'race', 'kill'), + # Any of issues, matrix, race, kill, browser. Installation always runs. + [string[]]$Scenarios = @('issues', 'matrix', 'race', 'kill', 'browser'), [int]$RaceCycles = 10 ) @@ -119,6 +119,158 @@ function Set-SarAsioRegistered { if ($proc.ExitCode -ne 0) { Write-Warning "regsvr32 $($regArgs -join ' ') exited with $($proc.ExitCode)" } } +# Plays tools\test\tone.html in Edge with application routing on and Edge's +# audio sandbox on or off, and checks that Edge's audio session is heard. +# Also records what the sandboxed audio service is allowed to load. +function Invoke-BrowserScenario { + param([string]$Name, [bool]$Sandbox) + + $record = [ordered]@{ name = $Name; sandbox = $Sandbox } + $edge = @("${env:ProgramFiles(x86)}\Microsoft\Edge\Application\msedge.exe", + "$env:ProgramFiles\Microsoft\Edge\Application\msedge.exe") | + Where-Object { Test-Path $_ } | Select-Object -First 1 + + if (-not $edge) { + Write-Host "==> $Name : skipped, Edge is not installed" + $record.outcome = 'skipped' + return $record + } + + $policy = 'HKLM:\SOFTWARE\Policies\Microsoft\Edge' + New-Item -Path $policy -Force | Out-Null + Set-ItemProperty $policy HideFirstRunExperience 1 -Type DWord + Set-ItemProperty $policy AutoplayAllowed 1 -Type DWord + Set-ItemProperty $policy AudioSandboxEnabled ([int]$Sandbox) -Type DWord + Get-Process msedge -ErrorAction SilentlyContinue | Stop-Process -Force + + # An Edge started while its installer replaces it exits without playing + # (seen in long runs before Edge updates were turned off at the start). + # Wait for an Edge installer still running. + $updateWait = Get-Date + $installers = @() + while (((Get-Date) - $updateWait).TotalMinutes -lt 2) { + $installers = @(Get-Process setup -ErrorAction SilentlyContinue | + Where-Object { $_.Path -like '*\Microsoft\Edge\Application\*' }) + if (-not $installers) { break } + Start-Sleep -Seconds 2 + } + $record.edgeInstallerWaitSeconds = [math]::Round(((Get-Date) - $updateWait).TotalSeconds, 1) + if ($installers) { $record.edgeInstallers = @($installers | ForEach-Object { $_.Path }) } + $started = Get-Date + + Set-SarAsioRegistered $true + + $hostLog = Join-Path $ResultsDir "$Name-host.log" + $hostJson = Join-Path $ResultsDir "$Name-host.json" + Write-Host "==> $Name : host with application routing, Edge audio sandbox $(if ($Sandbox) { 'on' } else { 'off' })" + $hostProc = Start-Process -FilePath $sarTest -NoNewWindow -PassThru -RedirectStandardOutput $hostLog ` + -ArgumentList (@('host', '--endpoints', 1, '--duration', 120, '--app-routing', + '--results', "`"$hostJson`"") + $common) + $null = $hostProc.Handle + Start-Sleep -Seconds 8 + + # Edge as the logged-on user without elevation, like a user starts it. + $page = 'file:///' + ((Join-Path $PSScriptRoot 'tone.html') -replace '\\', '/') + $userData = Join-Path $env:TEMP "sartest-edge-$Name" + $edgeArgs = "--user-data-dir=`"$userData`" --no-first-run --no-default-browser-check " + + "--autoplay-policy=no-user-gesture-required --enable-logging --v=0 `"$page`"" + $me = [Security.Principal.WindowsIdentity]::GetCurrent().Name + Register-ScheduledTask -TaskName 'SarTestEdge' -Force ` + -Action (New-ScheduledTaskAction -Execute $edge -Argument $edgeArgs) ` + -Principal (New-ScheduledTaskPrincipal -UserId $me -LogonType Interactive -RunLevel Limited) ` + -Settings (New-ScheduledTaskSettingsSet -MultipleInstances Parallel) | Out-Null + + # Wait for Edge's audio service to start (the page plays right away). + # Edge once didn't come up at all, so a launch that produced no audio + # service is retried once and then reported as such, not as silence. + $record.edgeStarted = $false + foreach ($attempt in 1..2) { + Start-ScheduledTask -TaskName 'SarTestEdge' + $deadline = (Get-Date).AddSeconds(20) + while (-not $record.edgeStarted -and (Get-Date) -lt $deadline) { + Start-Sleep -Milliseconds 500 + $record.edgeStarted = [bool](Get-CimInstance Win32_Process -Filter "Name='msedge.exe'" | + Where-Object { $_.CommandLine -match 'audio\.mojom\.AudioService' }) + } + if ($record.edgeStarted) { break } + $taskResult = (Get-ScheduledTaskInfo -TaskName 'SarTestEdge').LastTaskResult + Write-Warning "$Name : Edge's audio service didn't start (attempt $attempt, task result $taskResult)" + Stop-ScheduledTask -TaskName 'SarTestEdge' -ErrorAction SilentlyContinue + Get-Process msedge -ErrorAction SilentlyContinue | Stop-Process -Force + Start-Sleep -Seconds 2 + } + + if (-not $record.edgeStarted) { + $record.outcome = 'error' + $record.error = "Edge's audio service never started" + # What Edge was doing instead, for working out why. + $record.edgeProcesses = @(Get-CimInstance Win32_Process | + Where-Object { $_.Name -match '^(msedge|MicrosoftEdgeUpdate|setup|elevation_service)' } | + ForEach-Object { "$($_.ProcessId) $($_.Name) $($_.CommandLine)" }) + $record.edgeVersion = (Get-Item $edge).VersionInfo.ProductVersion + $debugLog = Join-Path $userData 'chrome_debug.log' + if (Test-Path $debugLog) { Copy-Item $debugLog (Join-Path $ResultsDir "$Name-chrome_debug.log") } + $record.edgeProcesses | ForEach-Object { Write-Host " $_" } + Unregister-ScheduledTask -TaskName 'SarTestEdge' -Confirm:$false -ErrorAction SilentlyContinue + try { Stop-Process -Id $hostProc.Id -Force } catch { } + $null = $hostProc.WaitForExit(60000) + Set-SarAsioRegistered $false + return $record + } + + $meter = Invoke-Scenario $Name @('meter', '--duration', 20, '--process', 'msedge.exe') -Timeout 120 + foreach ($key in $meter.Keys) { if (-not $record.Contains($key)) { $record[$key] = $meter[$key] } } + + # Facts about Edge's audio service: its sandbox, its mitigation policies, + # whether SarAsio.dll got loaded, and any Code Integrity block events. + $record.audioProcesses = @(Get-CimInstance Win32_Process -Filter "Name='msedge.exe'" | + Where-Object { $_.CommandLine -match 'audio\.mojom\.AudioService' } | ForEach-Object { + $info = [ordered]@{ + pid = $_.ProcessId + sandboxType = if ($_.CommandLine -match '--service-sandbox-type=(\S+)') { $Matches[1] } else { $null } + } + try { + $m = Get-ProcessMitigation -Id $_.ProcessId + $info.microsoftSignedOnly = "$($m.BinarySignature.MicrosoftSignedOnly)" + $info.blockLowLabelImageLoads = "$($m.ImageLoad.BlockLowLabelImageLoads)" + $info.blockRemoteImageLoads = "$($m.ImageLoad.BlockRemoteImageLoads)" + $info.blockDynamicCode = "$($m.DynamicCode.BlockDynamicCode)" + } catch { $info.mitigationError = "$_" } + try { + $info.sarAsioLoaded = [bool]((Get-Process -Id $_.ProcessId).Modules | + Where-Object ModuleName -eq 'SarAsio.dll') + } catch { $info.modulesError = "$_" } + [pscustomobject]$info + }) + $record.sarAsioLoadedIn = @(Get-Process msedge -ErrorAction SilentlyContinue | Where-Object { + try { $_.Modules | Where-Object ModuleName -eq 'SarAsio.dll' } catch { $false } + } | ForEach-Object { $_.Id }) + $record.codeIntegrityEvents = @(Get-WinEvent -ErrorAction SilentlyContinue -FilterHashtable @{ + LogName = 'Microsoft-Windows-CodeIntegrity/Operational'; StartTime = $started } | + Where-Object { $_.Message -match 'SarAsio' } | Select-Object -First 5 | + ForEach-Object { "$($_.Id): $($_.Message)" }) + $record.audioProcesses | ForEach-Object { Write-Host " audio service: $($_ | ConvertTo-Json -Compress)" } + Write-Host " SarAsio.dll loaded in msedge pids: $($record.sarAsioLoadedIn -join ', ')" + $record.codeIntegrityEvents | ForEach-Object { Write-Host " CI: $_" } + + Stop-ScheduledTask -TaskName 'SarTestEdge' -ErrorAction SilentlyContinue + Unregister-ScheduledTask -TaskName 'SarTestEdge' -Confirm:$false -ErrorAction SilentlyContinue + Get-Process msedge -ErrorAction SilentlyContinue | Stop-Process -Force + try { Stop-Process -Id $hostProc.Id -Force } catch { } + $null = $hostProc.WaitForExit(60000) + Set-SarAsioRegistered $false + Start-Sleep -Seconds 5 + return $record +} + +# Edge updates itself some minutes after boot, and an Edge started while it +# does exits without playing. Turn its updates off before they start. +if ($Scenarios -contains 'browser') { + $updatePolicy = 'HKLM:\SOFTWARE\Policies\Microsoft\EdgeUpdate' + New-Item -Path $updatePolicy -Force | Out-Null + Set-ItemProperty $updatePolicy UpdateDefault 0 -Type DWord +} + # Windows Server images ship with the audio stack disabled. foreach ($service in 'AudioEndpointBuilder', 'Audiosrv') { try { @@ -235,6 +387,16 @@ if (-not $SkipKillTest -and $Scenarios -contains 'kill') { @('run', '--endpoints', $count, '--iterations', 1, '--duration', $Duration) + $common) } +if ($Scenarios -contains 'browser') { + # With application routing on, the driver points the audio device + # enumerator's COM registration at SarAsio.dll for every process of the + # user, Chromium's sandboxed audio service included, which then played + # nothing (#80, #102, #121, #127). Runs last, since Edge is slow and the + # rest of the run doesn't need it. + $summary.scenarios += Invoke-BrowserScenario 'browser-audio-unsandboxed' $false + $summary.scenarios += Invoke-BrowserScenario 'browser-audio-sandboxed' $true +} + $sarLogs = Join-Path $env:APPDATA 'SynchronousAudioRouter\logs' if (Test-Path $sarLogs) { $dest = Join-Path $ResultsDir 'sarasio-logs' @@ -244,7 +406,7 @@ if (Test-Path $sarLogs) { $summary.finished = (Get-Date).ToString('o') $outcomes = $summary.scenarios | ForEach-Object { $_.outcome } -$summary.passed = -not ($outcomes | Where-Object { $_ -ne 'passed' }) +$summary.passed = -not ($outcomes | Where-Object { $_ -ne 'passed' -and $_ -ne 'skipped' }) $summary | ConvertTo-Json -Depth 8 | Set-Content (Join-Path $ResultsDir 'summary.json') Write-Host '' diff --git a/tools/test/README.md b/tools/test/README.md index d6d668b..43b445d 100644 --- a/tools/test/README.md +++ b/tools/test/README.md @@ -95,8 +95,16 @@ runs a host whose endpoint names are longer than the driver's 63-character limit. `app-routing` runs a loopback with application routing on and SarAsio's COM classes registered, which turns on the driver's registry filter. -`Invoke-SarTest.ps1 -Scenarios` selects any of `issues`, `matrix`, `race` -and `kill`. + +The `browser-audio-*` scenarios (#80, #102, #121, #127) register SarAsio's +COM classes, run a host with application routing on, play `tone.html` in +Edge (with its audio sandbox off, then on) and use `SarTest.exe meter` to +check that Edge's audio session was heard. They also record the sandboxed +audio service's mitigation policies, whether `SarAsio.dll` was loaded into +it, and Code Integrity events naming it. They run last, and are skipped +without Edge. +`Invoke-SarTest.ps1 -Scenarios` selects any of `issues`, `matrix`, `race`, +`kill` and `browser`. ## Commands @@ -111,6 +119,7 @@ SarTest race [--cycles K] [--up S] [--down MS] [--openers T] [--hold MS] SarTest control-panel SarTest no-interface SarTest endpoint-names +SarTest meter [--duration S] [--process ] [--min-peak P] ``` `install` creates the SAR software device node if needed, installs the diff --git a/tools/test/tone.html b/tools/test/tone.html new file mode 100644 index 0000000..f8db510 --- /dev/null +++ b/tools/test/tone.html @@ -0,0 +1,21 @@ + + +SarTest tone + +

starting

+