diff --git a/electron/native/wgc-capture/src/audio_sample_utils.cpp b/electron/native/wgc-capture/src/audio_sample_utils.cpp index 6b503250..5e60860c 100644 --- a/electron/native/wgc-capture/src/audio_sample_utils.cpp +++ b/electron/native/wgc-capture/src/audio_sample_utils.cpp @@ -374,66 +374,104 @@ bool AudioMixer::pop(std::vector& queue, std::vector& chunk, size_t return copiedBytes > 0; } +/** + * Emits one mixed chunk every `chunkFrames`, for as long as the timeline runs. + * + * On the clock, and not on the data. Timestamps here are derived from + * `emittedFrames_`, so the output timeline only means anything if a chunk goes + * out for every chunk of real time -- and it used to `continue` whenever both + * queues were empty, leaving `emittedFrames_` where it was. WASAPI loopback + * delivers nothing at all while nothing is playing, so a recording that begins + * in silence emitted nothing, and the first sound to play landed at timestamp + * zero. Measured: a sound played four seconds in was heard from the start, and + * the audio track came out two seconds shorter than the take. + * + * A working microphone hid this, because it streams continuously and kept the + * queue non-empty -- which is why a microphone failing at the OS level appeared + * to cause a system-audio desync it merely stopped concealing + * (getopenscreen/openscreen#406). + * + * `audioClockStart` is anchored so that `emittedFrames_` always describes the + * time elapsed since the timeline began; re-deriving it on resume is what lets a + * pause interrupt the clock without shifting everything recorded after it. + */ void AudioMixer::mixLoop() { const uint32_t chunkFrames = std::max(1, format_.sampleRate / 100); const size_t chunkBytes = static_cast(chunkFrames) * format_.blockAlign; std::vector mixedChunk; std::vector sourceChunk; std::chrono::steady_clock::time_point audioClockStart; - bool audioClockStarted = false; + bool audioClockAnchored = false; + + const auto framesToDuration = [&](uint64_t frames) { + return std::chrono::duration_cast( + std::chrono::duration(static_cast(frames) / format_.sampleRate)); + }; while (true) { { std::unique_lock lock(mutex_); cv_.wait_for(lock, std::chrono::milliseconds(20), [&] { - const bool hasSystem = !includeSystem_ || systemQueue_.size() >= chunkBytes; - const bool hasMicrophone = !includeMicrophone_ || microphoneQueue_.size() >= chunkBytes; - const bool hasAnySource = !systemQueue_.empty() || !microphoneQueue_.empty(); - return stopRequested_.load() || - (timelineStarted_ && !paused_ && (hasSystem || hasMicrophone) && hasAnySource); + return stopRequested_.load() || (timelineStarted_ && !paused_); }); if (stopRequested_) { break; } if (!timelineStarted_ || paused_) { + // A pause stops the clock rather than resetting it: the anchor is + // re-derived from `emittedFrames_` on resume, so what follows keeps + // the position it would have had. + audioClockAnchored = false; continue; } + } - const bool hasAnyQueuedAudio = !systemQueue_.empty() || !microphoneQueue_.empty(); - if (!hasAnyQueuedAudio) { - continue; - } + const auto now = std::chrono::steady_clock::now(); + if (!audioClockAnchored) { + audioClockStart = now - framesToDuration(emittedFrames_); + audioClockAnchored = true; + } - mixedChunk.assign(chunkBytes, 0); - if (includeSystem_) { - pop(systemQueue_, sourceChunk, chunkBytes); - mixAudioInPlace(mixedChunk, sourceChunk.data(), static_cast(sourceChunk.size()), format_); + // How much of the timeline real time has covered. Emitting up to here -- + // from the queues where they have data, from silence where they do not -- + // is what keeps the audio clock pinned to the take rather than to whether + // anything happened to be playing. + const auto elapsed = std::chrono::duration(now - audioClockStart).count(); + const uint64_t targetFrames = static_cast(elapsed * format_.sampleRate); + + while (emittedFrames_ + chunkFrames <= targetFrames) { + { + std::scoped_lock lock(mutex_); + if (stopRequested_ || !timelineStarted_ || paused_) { + break; + } + mixedChunk.assign(chunkBytes, 0); + if (includeSystem_) { + pop(systemQueue_, sourceChunk, chunkBytes); + mixAudioInPlace(mixedChunk, sourceChunk.data(), static_cast(sourceChunk.size()), format_); + } + if (includeMicrophone_) { + pop(microphoneQueue_, sourceChunk, chunkBytes); + mixAudioInPlace(mixedChunk, sourceChunk.data(), static_cast(sourceChunk.size()), format_); + } } - if (includeMicrophone_) { - pop(microphoneQueue_, sourceChunk, chunkBytes); - mixAudioInPlace(mixedChunk, sourceChunk.data(), static_cast(sourceChunk.size()), format_); - } - } - if (!audioClockStarted) { - audioClockStart = std::chrono::steady_clock::now(); - audioClockStarted = true; + const int64_t timestampHns = + static_cast((emittedFrames_ * HnsPerSecond) / format_.sampleRate); + const int64_t durationHns = + static_cast((static_cast(chunkFrames) * HnsPerSecond) / format_.sampleRate); + if (!output_(mixedChunk.data(), static_cast(mixedChunk.size()), timestampHns, durationHns)) { + stopRequested_ = true; + break; + } + emittedFrames_ += chunkFrames; } - const int64_t timestampHns = - static_cast((emittedFrames_ * HnsPerSecond) / format_.sampleRate); - const int64_t durationHns = - static_cast((static_cast(chunkFrames) * HnsPerSecond) / format_.sampleRate); - if (!output_(mixedChunk.data(), static_cast(mixedChunk.size()), timestampHns, durationHns)) { - stopRequested_ = true; + if (stopRequested_) { break; } - emittedFrames_ += chunkFrames; - const auto nextDeadline = audioClockStart + - std::chrono::duration_cast( - std::chrono::duration(static_cast(emittedFrames_) / format_.sampleRate)); - std::this_thread::sleep_until(nextDeadline); + std::this_thread::sleep_until(audioClockStart + framesToDuration(emittedFrames_ + chunkFrames)); } } diff --git a/package.json b/package.json index 67cd2585..9a7c4135 100644 --- a/package.json +++ b/package.json @@ -68,6 +68,7 @@ "test:wgc-audio:win": "node scripts/test-windows-wgc-helper.mjs --system-audio", "test:wgc-mic:win": "node scripts/test-windows-wgc-helper.mjs --microphone", "test:wgc-mixed-audio:win": "node scripts/test-windows-wgc-helper.mjs --system-audio --microphone", + "test:wgc-audio-timeline:win": "node scripts/test-windows-audio-timeline.mjs", "test:wgc-webcam:win": "node scripts/test-windows-wgc-helper.mjs --webcam", "test:wgc-full:win": "node scripts/test-windows-wgc-helper.mjs --webcam --system-audio --microphone", "capture:openscreen-preview": "node scripts/capture-openscreen-preview.mjs", diff --git a/scripts/test-windows-audio-timeline.mjs b/scripts/test-windows-audio-timeline.mjs new file mode 100644 index 00000000..6dc44133 --- /dev/null +++ b/scripts/test-windows-audio-timeline.mjs @@ -0,0 +1,243 @@ +/** + * Does a sound land where it happened? + * + * The helper's audio timestamps come from a running count of emitted frames, so + * they only describe the take if a chunk goes out for every chunk of real time. + * When that count advanced only while a source had samples queued, a recording + * that began in silence emitted nothing until something played — and the first + * sound landed at timestamp zero, with the track shorter than the take by the + * silence it skipped (getopenscreen/openscreen#406). + * + * A working microphone hid it, streaming continuously and keeping the queue + * non-empty, which is why it surfaced as a system-audio desync on a machine + * whose microphone had failed. + * + * WASAPI cannot run on Linux CI, so this drives the real helper: record in + * silence, play a tone at a known instant, and measure where the tone actually + * sits in the file. + * + * npm run test:wgc-audio-timeline:win + * + * Plays through the default render endpoint, so that device has to be working + * and audible — this measures the machine as much as the code. + */ +import { spawn, spawnSync } from "node:child_process"; +import fs from "node:fs"; +import os from "node:os"; +import path from "node:path"; +import { fileURLToPath } from "node:url"; + +const __dirname = path.dirname(fileURLToPath(import.meta.url)); +const ROOT = path.join(__dirname, ".."); +const HELPER = + process.env.OPENSCREEN_WGC_CAPTURE_EXE ?? + path.join(ROOT, "electron", "native", "bin", "win32-x64", "wgc-capture.exe"); +const FFMPEG = path.join(ROOT, "electron", "native", "bin", "win32-x64", "ffmpeg.exe"); +const PLAY_AT_MS = Number(process.env.OPENSCREEN_WGC_TEST_PLAY_AT_MS ?? 4000); +const TONE_MS = 6000; +/** How far the tone may sit from where it was played before this is a failure. */ +const TOLERANCE_S = 1.0; + +if (process.platform !== "win32") { + console.log("Windows only — skipping."); + process.exit(0); +} +for (const [what, where] of [ + ["helper", HELPER], + ["ffmpeg", FFMPEG], +]) { + if (!fs.existsSync(where)) { + console.error(`No ${what} at ${where}. Run: npm run build:native:win && npm run fetch:ffmpeg`); + process.exit(1); + } +} + +const tonePath = path.join(os.tmpdir(), "openscreen-audio-timeline-tone.wav"); +const madeTone = spawnSync( + FFMPEG, + // deno-fmt-ignore + [ + "-hide_banner", + "-loglevel", + "error", + "-f", + "lavfi", + "-i", + `sine=frequency=440:duration=${TONE_MS / 1000}`, + "-ac", + "2", + "-ar", + "48000", + "-acodec", + "pcm_s16le", + "-y", + tonePath, + ], + { windowsHide: true }, +); +if (madeTone.status !== 0 || !fs.existsSync(tonePath)) { + console.error("Could not synthesise the test tone."); + process.exit(1); +} + +const outputPath = path.join(os.tmpdir(), "openscreen-audio-timeline.mp4"); +fs.rmSync(outputPath, { force: true }); + +const config = { + schemaVersion: 2, + recordingId: Date.now(), + outputPath, + sourceType: "display", + sourceId: "screen:0:0", + displayId: 0, + fps: 30, + videoWidth: 1280, + videoHeight: 720, + hasDisplayBounds: false, + captureSystemAudio: true, + // No microphone on purpose: it is the state a failed one leaves behind, and + // a working one masks the bug by keeping the mixer's queue fed. + captureMic: false, + webcamEnabled: false, + cursorCaptureMode: "editable-overlay", +}; + +console.log(`Recording in silence, playing a ${TONE_MS / 1000}s tone at ${PLAY_AT_MS / 1000}s...`); +const proc = spawn(HELPER, [JSON.stringify(config)], { windowsHide: true }); +let helperOutput = ""; +let spawnError = null; +let playbackArmed = false; +proc.on("error", (error) => { + spawnError = error.message; +}); + +/** + * Arms the tone once the helper says it is recording, never from spawn. + * + * Everything measured here is relative to the audio timeline, which starts when + * the helper does — after it has opened WGC, the encoder and WASAPI. Counting + * from spawn would fold that setup time into the offset and fail the test on a + * slow machine, with nothing wrong with the timestamps. + */ +function armPlaybackOnce() { + if (playbackArmed || !helperOutput.includes("Recording started")) { + return; + } + playbackArmed = true; + setTimeout(() => { + // Blocking on purpose: it guarantees the tone really played before the + // stop below is sent, which is the premise of the measurement. The path + // goes into a PowerShell single-quoted string, where an apostrophe — legal + // in a Windows user name, and so in %TEMP% — ends the string early and + // silently plays nothing; doubling it is how that quoting escapes. + const quotedTonePath = tonePath.replaceAll("'", "''"); + spawnSync( + "powershell.exe", + [ + "-NoProfile", + "-Command", + `(New-Object System.Media.SoundPlayer '${quotedTonePath}').PlaySync()`, + ], + { windowsHide: true }, + ); + try { + proc.stdin.write("stop\n"); + } catch { + // Already gone; the close handler reports how it ended. + } + }, PLAY_AT_MS); +} + +proc.stdout.on("data", (chunk) => { + helperOutput += chunk.toString(); + armPlaybackOnce(); +}); +proc.stderr.on("data", (chunk) => { + helperOutput += chunk.toString(); + armPlaybackOnce(); +}); + +// If the helper never announces itself, nothing would ever stop it. +const startTimeout = setTimeout(() => { + if (!playbackArmed) { + console.error("The helper never reported that recording had started."); + proc.kill(); + } +}, 30_000); + +proc.on("close", (code, signal) => { + clearTimeout(startTimeout); + const problems = []; + if (!playbackArmed) problems.push("recording never started, so no tone was played"); + if (spawnError) problems.push(`could not start the helper: ${spawnError}`); + if (signal) problems.push(`helper killed by ${signal}`); + if (code !== 0 && code !== null) problems.push(`helper exited ${code}`); + + const decoded = spawnSync( + FFMPEG, + // deno-fmt-ignore + [ + "-hide_banner", + "-nostats", + "-i", + outputPath, + "-map", + "0:a", + "-f", + "s16le", + "-ac", + "1", + "-ar", + "16000", + "-", + ], + { maxBuffer: 1 << 28, windowsHide: true }, + ); + const pcm = decoded.stdout ?? Buffer.alloc(0); + const rate = 16000; + const samples = pcm.length / 2; + const windowSamples = rate / 10; + const audible = []; + for (let index = 0; index * windowSamples < samples; index += 1) { + let peak = 0; + const from = index * windowSamples; + const to = Math.min(from + windowSamples, samples); + for (let at = from; at < to; at += 1) { + peak = Math.max(peak, Math.abs(pcm.readInt16LE(at * 2))); + } + // Well above dither, well below a real tone. + if (peak > 1200) audible.push(index / 10); + } + + const trackSeconds = samples / rate; + const startedAt = audible.length ? audible[0] : null; + if (startedAt === null) { + problems.push( + "no audible tone in the recording — check the default playback device is on and unmuted", + ); + } else if (Math.abs(startedAt - PLAY_AT_MS / 1000) > TOLERANCE_S) { + problems.push( + `the tone sits at ${startedAt.toFixed(1)}s, and was played at ${(PLAY_AT_MS / 1000).toFixed(1)}s`, + ); + } + // The silence before the tone has to be IN the file, not skipped over. + if (trackSeconds < PLAY_AT_MS / 1000) { + problems.push( + `the track is ${trackSeconds.toFixed(2)}s, shorter than the silence that preceded the tone`, + ); + } + + fs.rmSync(outputPath, { force: true }); + console.log( + `\n${problems.length ? "FAIL" : "PASS"} track=${trackSeconds.toFixed(2)}s tone at ${startedAt === null ? "(none)" : `${startedAt.toFixed(1)}s`}, played at ${(PLAY_AT_MS / 1000).toFixed(1)}s`, + ); + for (const problem of problems) console.log(` -> ${problem}`); + if (problems.length) { + const complaints = helperOutput + .split("\n") + .map((line) => line.trim()) + .filter((line) => line.startsWith("ERROR:") || line.startsWith("WARNING:")); + for (const complaint of complaints.slice(-5)) console.log(` helper: ${complaint}`); + } + process.exit(problems.length ? 1 : 0); +}); diff --git a/technical-documentation/architecture/recording.md b/technical-documentation/architecture/recording.md index 21375d89..2f00df4b 100644 --- a/technical-documentation/architecture/recording.md +++ b/technical-documentation/architecture/recording.md @@ -67,6 +67,8 @@ Windows and macOS both write their screen video as a fragmented MP4 — `MFCreat A session writes a screen video and a `.session.json` manifest. Windows normally muxes the webcam into that MP4; when `webcamPath` is supplied, it writes a separate webcam video. macOS currently writes the webcam as a separate Electron sidecar (`webcamVideoPath`) because native webcam composition is not part of the helper. Linux follows the Electron recorder's separate media-path convention. Audio that the selected backend captures is encoded into its screen output. +The Windows helper mixes system loopback and microphone into one track, and timestamps it from a running count of emitted frames. That count is advanced by a clock rather than by the arrival of samples: a chunk goes out every 10 ms for as long as the recording runs, filled from whichever source has data and with silence where neither does. Advancing it only when a queue held samples is what made a take that began in silence emit nothing at all — WASAPI loopback delivers no packets while nothing is playing — so the first sound landed at timestamp zero and the track came out shorter than the take. A working microphone concealed it by streaming continuously, which is why it appeared as a system-audio desync on a machine whose microphone had failed. `npm run test:wgc-audio-timeline:win` measures where a tone played at a known instant actually lands. + Cursor samples are persisted as cursor telemetry rather than baked into editable-overlay recordings. The loader resolves the sidecar at `.cursor.json` or through the recording links; see [cursor.md](cursor.md) for the telemetry format and rendering path. ## Known gaps