diff --git a/quest/m1/audio-jitter-target/opus-isolated-target.md b/quest/m1/audio-jitter-target/opus-isolated-target.md index 429fa3d1a1f..3f075623ae1 100644 --- a/quest/m1/audio-jitter-target/opus-isolated-target.md +++ b/quest/m1/audio-jitter-target/opus-isolated-target.md @@ -35,6 +35,28 @@ ceilings in `test/audio-quality/budgets.json` from re-measured nightly runs. Public API: none expected. Wire: none. +The 2026-10-15 ARM comparison still reproduces the defect with Opus warmup +#5569 included. [The untraced controls](https://github.com/moq-dev/moq/actions/runs/38807783281) +run `isolated,plain` and then `plain,isolated`, each in a fresh harness run. +Isolated-first reaches a 560 ms target with two underrun episodes; the other +three rows hold 60 ms with no episodes. Configuration is identical within +each pair, including 80 ms codec warmup. Row order remains a confound. + +The failing row's arrival gaps coincide with 227–320 ms main-thread long +tasks. A [GC profile](https://github.com/moq-dev/moq/actions/runs/38809803022) +reproduces the pauses with no recorded GC work overlapping the longest tasks. +A [sampled CPU profile](https://github.com/moq-dev/moq/actions/runs/38811094714) +has 100–315 ms sampling gaps across the pauses, with boundary samples in +`Stream.Reader` awaiting native `ReadableStreamDefaultReader.read()`. This +locates the browser read/scheduling boundary but does not establish its cause. +Recorded arrival replay produces the same target with either ring. + +Use `--capture` to preserve arrivals and native long tasks; `--trace` also +saves GC events and a sampled CPU profile. Tracing can perturb playback, so +compare separate untraced controls and never calibrate budgets from traced +rows. The original fix and budget-tightening goals remain open; the diagnostic +change does not alter the estimator, ring, or ceilings. + ## Related - [Watch](/quest/m1/audio-jitter-target/watch.md) - the manual browser proof that follows this fix diff --git a/test/audio-quality/README.md b/test/audio-quality/README.md index ac5525516e3..029fdc2dcfe 100644 --- a/test/audio-quality/README.md +++ b/test/audio-quality/README.md @@ -85,7 +85,11 @@ asks, not the target), so it adds no upstream subscription demand and still sees the target. Groups drain concurrently, so an earlier stalled group cannot hide a later arrival. Capture errors void the row. Capture adds local decoding and recording work; it is off by default and -on in nightly so a run preserves the inputs for diagnosis. +on in nightly so a run preserves the inputs for diagnosis. It also records native main-thread +long tasks in `.longtasks.json`, on the same viewer clock. `--trace` implies capture and adds a +Chromium GC timeline in `.trace.json` and sampled CPU profile in `.profile.json`. +Tracing can perturb playback; compare it with a separate +untraced control and never use traced rows to calibrate quality budgets. To replay a capture, put its arrivals and final environment configuration into the version 2 `Trace` below, subtract the first arrival's `at` from every arrival and from the last sample's diff --git a/test/audio-quality/clients/js/cli.test.ts b/test/audio-quality/clients/js/cli.test.ts new file mode 100644 index 00000000000..78bb0e758f0 --- /dev/null +++ b/test/audio-quality/clients/js/cli.test.ts @@ -0,0 +1,19 @@ +import { expect, test } from "bun:test"; +import { fileURLToPath } from "node:url"; + +test("trace is accepted through the audio-quality wrapper", () => { + const result = Bun.spawnSync([ + "bash", + fileURLToPath(new URL("../../run.sh", import.meta.url)), + "--list", + "--profiles", + "near-zero", + "--codecs", + "opus", + "--rings", + "isolated", + "--trace", + ]); + expect(result.exitCode).toBe(0); + expect(result.stdout.toString().trim()).toBe("chromium-opus-48000-near-zero-isolated"); +}); diff --git a/test/audio-quality/clients/js/driver.ts b/test/audio-quality/clients/js/driver.ts index 99b89d843be..3c5e3802621 100644 --- a/test/audio-quality/clients/js/driver.ts +++ b/test/audio-quality/clients/js/driver.ts @@ -36,6 +36,7 @@ const { values } = parseArgs({ tag: { type: "string" }, out: { type: "string" }, capture: { type: "boolean", default: false }, + trace: { type: "boolean", default: false }, }, }); @@ -51,10 +52,11 @@ if ( !out || !Number.isFinite(durationMs) || durationMs <= 0 || - (ring !== "plain" && ring !== "isolated") + (ring !== "plain" && ring !== "isolated") || + (values.trace && !values.capture) ) { console.error( - "usage: driver.ts --url U --fingerprint F --broadcast B --page DIR --ring plain|isolated --tag T --out DIR [--delay auto] [--duration S>0] [--capture]", + "usage: driver.ts --url U --fingerprint F --broadcast B --page DIR --ring plain|isolated --tag T --out DIR [--delay auto] [--duration S>0] [--capture] [--trace]", ); process.exit(2); } @@ -129,8 +131,40 @@ const browser = await launch(["--autoplay-policy=no-user-gesture-required"]); let environment: Environment | undefined; let notes: string[] = []; let failed = false; +let finishTrace: (() => Promise) | undefined; try { const page = await browser.newPage(); + if (values.capture) { + await page.addInitScript(() => { + const tasks: { at: number; duration: number }[] = []; + Object.defineProperty(globalThis, "audioQualityLongTasks", { value: tasks }); + new PerformanceObserver((entries) => { + for (const task of entries.getEntries()) tasks.push({ at: task.startTime, duration: task.duration }); + }).observe({ type: "longtask", buffered: true }); + }); + } + if (values.trace) { + const session = await page.context().newCDPSession(page); + await session.send("Profiler.enable"); + await session.send("Profiler.start"); + const events: unknown[] = []; + session.on("Tracing.dataCollected", (event: { value: unknown[] }) => events.push(...event.value)); + const complete = new Promise((resolve) => session.once("Tracing.tracingComplete", () => resolve())); + await session.send("Tracing.start", { + categories: "disabled-by-default-v8.gc,blink.user_timing", + transferMode: "ReportEvents", + }); + finishTrace = async () => { + finishTrace = undefined; + await session.send("Tracing.end"); + await complete; + const { profile } = await session.send("Profiler.stop"); + await Bun.write(join(out, `${tag}.profile.json`), JSON.stringify(profile)); + await Bun.write(join(out, `${tag}.trace.json`), JSON.stringify({ traceEvents: events })); + await session.detach(); + }; + } + page.on("pageerror", (error) => console.error(`[page error] ${error.message}`)); await page.route(new URL("/certificate.sha256", url).href, (route) => route.fulfill({ body: hash, headers: { "access-control-allow-origin": "*" } }), @@ -162,11 +196,26 @@ try { // The context rate is only known once the graph exists, which is after the catalog. environment = (await page.evaluate(() => globalThis.audioQuality.environment())) ?? environment; notes = await page.evaluate(() => globalThis.audioQuality.notes()); + if (values.capture) { + const tasks = await page.evaluate( + () => + (globalThis as typeof globalThis & { audioQualityLongTasks: { at: number; duration: number }[] }) + .audioQualityLongTasks, + ); + await Bun.write(join(out, `${tag}.longtasks.json`), JSON.stringify(tasks)); + } + await finishTrace?.(); await page.close(); } catch (err) { failed = true; refuse("driver", err instanceof Error ? err.message : String(err)); } finally { + try { + await finishTrace?.(); + } catch (error) { + failed = true; + refuse("trace", error instanceof Error ? error.message : String(error)); + } await browser.close().catch(() => {}); server.stop(true); } diff --git a/test/audio-quality/run.sh b/test/audio-quality/run.sh index e7377edf725..3bd6e349bc3 100755 --- a/test/audio-quality/run.sh +++ b/test/audio-quality/run.sh @@ -34,6 +34,7 @@ OUT="" LIST=0 ENFORCE=0 CAPTURE=0 +TRACE=0 PROFILE="${AQ_PROFILE:-debug}" split() { @@ -97,6 +98,11 @@ while [[ $# -gt 0 ]]; do CAPTURE=1 shift ;; + --trace) + TRACE=1 + CAPTURE=1 + shift + ;; --enforce) ENFORCE=1 shift @@ -306,6 +312,7 @@ if [[ ${#ROWS[@]} -gt 0 ]]; then status=0 capture_args=() [[ $CAPTURE -eq 0 ]] || capture_args=(--capture) + [[ $TRACE -eq 0 ]] || capture_args+=(--trace) harness_spawn "driver-$tag" "$HARNESS_RUN/driver-$tag.log" bun "$CLIENT/driver.ts" \ --url "http://127.0.0.1:$SHAPER_PORT" \ --fingerprint "$RELAY_URL/certificate.sha256" \