diff --git a/.github/workflows/diagnostic-artifact.yml b/.github/workflows/diagnostic-artifact.yml index bdf9bde9d5..4c408a68aa 100644 --- a/.github/workflows/diagnostic-artifact.yml +++ b/.github/workflows/diagnostic-artifact.yml @@ -2,9 +2,12 @@ name: Diagnostic artifact on: push: - branches: [main] + branches: [main, "release/**"] + # Release branches too: a recording fix targeting a release is exactly when a + # reviewer needs the compiled helper, and filtering on main alone meant + # retargeting a PR silently removed the artifact its own test steps ask for. pull_request: - branches: [main] + branches: [main, "release/**"] workflow_dispatch: permissions: diff --git a/electron/ipc/handlers.ts b/electron/ipc/handlers.ts index 5fae3cbeb9..7d63b934b1 100644 --- a/electron/ipc/handlers.ts +++ b/electron/ipc/handlers.ts @@ -71,6 +71,10 @@ import { createCursorRecordingSession } from "../native-bridge/cursor/recording/ import { requestMacCursorAccessibilityAccess } from "../native-bridge/cursor/recording/macNativeCursorRecordingSession"; import { findPipeWireCursorHelperPath } from "../native-bridge/cursor/recording/pipeWireCursorRecordingSession"; import type { CursorRecordingSession } from "../native-bridge/cursor/recording/session"; +import { + terminateNativeWindowsCapture, + waitForNativeWindowsCaptureStop, +} from "../recording/nativeWindowsCaptureStop"; import { patchWebmDurationOnDisk } from "../recording/webm-duration"; import { reindexRecordingOnDisk } from "../recording/webm-seek-index"; import { registerNativeBridgeHandlers } from "./nativeBridge"; @@ -533,7 +537,74 @@ let nativeWindowsCursorRecordingStartMs = 0; let nativeWindowsPauseStartedAtMs: number | null = null; let nativeWindowsPauseRanges: Array<{ startMs: number; endMs: number }> = []; let nativeWindowsIsPaused = false; -const NATIVE_WINDOWS_CAPTURE_STOP_TIMEOUT_MS = 60_000; +/** Cuts a surviving helper's output loose so it cannot pollute the next recording. */ +let nativeWindowsCaptureDrainCleanup: (() => void) | null = null; + +function detachNativeWindowsCaptureOutputDrain() { + nativeWindowsCaptureDrainCleanup?.(); + nativeWindowsCaptureDrainCleanup = null; +} + +function resetNativeWindowsCaptureState() { + nativeWindowsCaptureDrainCleanup = null; + nativeWindowsCaptureProcess = null; + nativeWindowsCaptureTargetPath = null; + nativeWindowsCaptureWebcamTargetPath = null; + nativeWindowsCaptureRecordingId = null; + nativeWindowsCursorOffsetMs = 0; + nativeWindowsCursorCaptureMode = "editable-overlay"; + nativeWindowsCursorRecordingStartMs = 0; + nativeWindowsPauseStartedAtMs = null; + nativeWindowsPauseRanges = []; + nativeWindowsIsPaused = false; +} + +/** + * An MP4 the helper never indexed is a few bytes of header at most. Anything + * larger might be a real recording, and deleting one of those to tidy up after + * a failed stop is a far worse outcome than leaving a stray file behind. + */ +const NATIVE_WINDOWS_SALVAGEABLE_OUTPUT_BYTES = 64 * 1024; + +/** + * Best-effort removal of the files a failed or discarded native Windows capture + * left behind. Each removal is isolated: a helper that outlived its kill still + * holds the MP4 open on Windows, and an EBUSY there must not mask why we were + * cleaning up in the first place. + */ +async function removeNativeWindowsCaptureOutputs( + screenVideoPath: string | null, + webcamVideoPath: string | null, + options: { onlyIfUnusable?: boolean } = {}, +) { + const targets = [ + screenVideoPath, + webcamVideoPath, + screenVideoPath ? `${screenVideoPath}.cursor.json` : null, + ]; + + for (const target of targets) { + if (!target || !isPathWithinDir(target, RECORDINGS_DIR)) { + continue; + } + try { + if (options.onlyIfUnusable && target !== `${screenVideoPath}.cursor.json`) { + const stats = await fs.stat(target).catch(() => null); + if (stats && stats.size >= NATIVE_WINDOWS_SALVAGEABLE_OUTPUT_BYTES) { + console.warn( + "[native-wgc] keeping a capture output that may still be playable:", + target, + stats.size, + ); + continue; + } + } + await fs.rm(target, { force: true }); + } catch (error) { + console.warn("[native-wgc] could not remove leftover capture output:", target, error); + } + } +} let nativeMacCaptureProcess: ChildProcessWithoutNullStreams | null = null; let nativeMacCaptureOutput = ""; let nativeMacCaptureTargetPath: string | null = null; @@ -1138,8 +1209,10 @@ function waitForNativeWindowsCaptureStart(proc: ChildProcessWithoutNullStreams) reject(new Error("Timed out waiting for native Windows capture to start")); }, 12000); - const onOutput = (chunk: Buffer) => { - nativeWindowsCaptureOutput += chunk.toString(); + // Observes only. `attachNativeWindowsCaptureOutputDrain` is the single + // writer of `nativeWindowsCaptureOutput` and is registered first, so the + // chunk that triggers this call is already in the buffer. + const onOutput = () => { if (nativeWindowsCaptureOutput.includes("Recording started")) { cleanup(); resolve(); @@ -1173,59 +1246,70 @@ function waitForNativeWindowsCaptureStart(proc: ChildProcessWithoutNullStreams) }); } -function waitForNativeWindowsCaptureStop(proc: ChildProcessWithoutNullStreams) { - return new Promise((resolve, reject) => { - const timer = setTimeout(() => { - cleanup(); - if (!proc.killed) { - proc.kill(); - } - reject( - new Error( - `Timed out waiting for native Windows capture to stop. Output path: ${ - nativeWindowsCaptureTargetPath ?? "unknown" - }. Output: ${nativeWindowsCaptureOutput.trim()}`, - ), - ); - }, NATIVE_WINDOWS_CAPTURE_STOP_TIMEOUT_MS); - const onOutput = (chunk: Buffer) => { - nativeWindowsCaptureOutput += chunk.toString(); - }; - const onClose = (code: number | null) => { - cleanup(); - const match = nativeWindowsCaptureOutput.match(/Recording stopped\. Output path: (.+)/); - if (match?.[1]) { - resolve(match[1].trim()); - return; - } - if (code === 0 && nativeWindowsCaptureTargetPath) { - resolve(nativeWindowsCaptureTargetPath); - return; - } - reject( - new Error( - nativeWindowsCaptureOutput.trim() || - `Native Windows capture exited with code=${code ?? "unknown"}`, - ), - ); - }; - const onError = (error: Error) => { - cleanup(); - reject(error); - }; - const cleanup = () => { - clearTimeout(timer); - proc.stdout.off("data", onOutput); - proc.stderr.off("data", onOutput); - proc.off("close", onClose); - proc.off("error", onError); - }; +/** + * Keeps reading the helper for as long as it lives. + * + * `waitForNativeWindowsCaptureStart` drops every listener the moment it sees + * "Recording started", so until this existed the whole recording ran unobserved: + * helper warnings and `[stop-timing]` diagnostics were discarded, which is why + * issue #252 had no helper-side evidence from a real app run and had to be + * reproduced by driving the .exe by hand. macOS has had this since it shipped + * (`attachNativeMacCaptureOutputDrain`); Windows never did. + */ +function attachNativeWindowsCaptureOutputDrain(proc: ChildProcessWithoutNullStreams) { + const drain = (chunk: Buffer) => { + nativeWindowsCaptureOutput += chunk.toString(); + }; + const cleanup = () => { + proc.stdout.off("data", drain); + proc.stderr.off("data", drain); + }; - proc.stdout.on("data", onOutput); - proc.stderr.on("data", onOutput); - proc.once("close", onClose); - proc.once("error", onError); - }); + proc.stdout.on("data", drain); + proc.stderr.on("data", drain); + proc.once("close", cleanup); + // An 'error' event with no listener throws, and in the main process that is + // an uncaught exception rather than a rejected promise. Both streams need a + // sink for the whole life of the helper: stdin raises EPIPE when the helper + // died before we wrote to it, and `kill()` on a wedged process re-emits its + // failure on the ChildProcess itself. + // All four emitters, not just stdin: `cleanup` only drops 'data', so an + // abandoned-but-still-alive helper leaves these pipes open with no consumer, + // and an ECONNRESET when the OS finally reaps it would take down the main + // process. + proc.stdin.on("error", (error) => { + console.warn("[native-wgc] helper stdin error:", error); + }); + proc.stdout.on("error", (error) => { + console.warn("[native-wgc] helper stdout error:", error); + }); + proc.stderr.on("error", (error) => { + console.warn("[native-wgc] helper stderr error:", error); + }); + proc.on("error", (error) => { + console.warn("[native-wgc] helper process error:", error); + }); + + // Returned so an abandoned helper can be cut loose. A process that survived + // both kill attempts keeps writing, and `nativeWindowsCaptureOutput` is + // shared with whatever recording starts next. + return cleanup; +} + +/** + * Sends `stop` and closes the command channel behind it. + * + * The helper treats stdin EOF as a stop too, so ending the stream is a free + * second signal if the write itself is lost. + */ +function sendNativeWindowsStopCommand(proc: ChildProcessWithoutNullStreams) { + if (!proc.stdin.writable) { + return false; + } + + proc.stdin.write("stop\n"); + proc.stdin.end(); + return true; } function readNativeWindowsWebcamFormat(output: string) { @@ -2329,6 +2413,8 @@ export function registerIpcHandlers( windowsHide: true, }); nativeWindowsCaptureProcess = proc; + nativeWindowsCaptureDrainCleanup = attachNativeWindowsCaptureOutputDrain(proc); + console.info("[native-wgc] helper spawned", { pid: proc.pid }); await waitForNativeWindowsCaptureStart(proc); const captureStartedAtMs = Date.now(); @@ -2360,16 +2446,8 @@ export function registerIpcHandlers( } catch (error) { console.error("Failed to start native Windows recording:", error); nativeWindowsCaptureProcess?.kill(); - nativeWindowsCaptureProcess = null; - nativeWindowsCaptureTargetPath = null; - nativeWindowsCaptureWebcamTargetPath = null; - nativeWindowsCaptureRecordingId = null; - nativeWindowsCursorOffsetMs = 0; - nativeWindowsCursorCaptureMode = "editable-overlay"; - nativeWindowsCursorRecordingStartMs = 0; - nativeWindowsPauseStartedAtMs = null; - nativeWindowsPauseRanges = []; - nativeWindowsIsPaused = false; + detachNativeWindowsCaptureOutputDrain(); + resetNativeWindowsCaptureState(); await stopCursorRecording(); return { success: false, error: String(error) }; } @@ -2627,12 +2705,84 @@ export function registerIpcHandlers( return { success: false, error: "Native Windows capture is not running." }; } + // Discarding does not need a finalized file, so it must not wait for one. + // Cancel and Restart both route here, and making them sit through the + // full stop handshake meant a wedged helper could not be escaped from at + // all -- the user waited out the timeout only to be told the recording + // failed, then waited it out again to cancel. Linux has always done this; + // Windows never did. + if (discard) { + try { + completeNativeWindowsCursorPauseRange(); + await stopCursorRecording(); + pendingCursorRecordingData = null; + const exited = await terminateNativeWindowsCapture(proc); + if (!exited) { + detachNativeWindowsCaptureOutputDrain(); + } + await removeNativeWindowsCaptureOutputs(preferredPath, preferredWebcamPath); + return { success: true, discarded: true }; + } finally { + // Unconditional. Killing a wedged helper can itself throw, and + // leaving the handle set would make every later recording fail + // with "already running" against a process nobody can stop. + resetNativeWindowsCaptureState(); + if (onRecordingStateChange) { + onRecordingStateChange(false, (selectedSource || { name: "Screen" }).name); + } + } + } + try { completeNativeWindowsCursorPauseRange(); - const stoppedPathPromise = waitForNativeWindowsCaptureStop(proc); - proc.stdin.write("stop\n"); - const stoppedPath = await stoppedPathPromise; - const screenVideoPath = stoppedPath || preferredPath; + const stopPromise = waitForNativeWindowsCaptureStop({ + proc, + targetPath: preferredPath, + readOutput: () => nativeWindowsCaptureOutput, + }); + if (!sendNativeWindowsStopCommand(proc)) { + console.warn("[native-wgc] stop command channel was already closed"); + } + const stopResult = await stopPromise; + if (!stopResult.ok) { + console.error("[native-wgc] stop failed", { + reason: stopResult.reason, + exited: stopResult.exited, + pid: proc.pid, + output: stopResult.message, + }); + if (!stopResult.exited) { + detachNativeWindowsCaptureOutputDrain(); + } + await stopCursorRecording(); + // Same as the discard path. `startCursorRecording` clears this on + // the next recording anyway, so this is not what keeps the samples + // from being written next to someone else's video -- it just stops + // a lost take's telemetry from sitting in memory until then. + pendingCursorRecordingData = null; + // The helper never announced a finalized file, so what is on disk + // is almost certainly an unindexed stub, and leaving those behind + // just accumulates unplayable recordings the user cannot explain. + // Almost: size-gate it, because throwing away a recording to tidy + // up after a failed stop is the worse mistake of the two. + await removeNativeWindowsCaptureOutputs(preferredPath, preferredWebcamPath, { + onlyIfUnusable: true, + }); + // The helper log goes to console/diagnostics above, not into this + // string: it ends up in a toast, and pasting an entire capture log + // into the HUD tells the user nothing they can act on. + return { + success: false, + reason: stopResult.reason, + error: + stopResult.reason === "stop-timeout" + ? "Timed out waiting for native Windows capture to stop. The recording could not be saved." + : stopResult.message.split(/\r?\n/).filter(Boolean).at(-1) || + "Native Windows capture failed.", + }; + } + + const screenVideoPath = stopResult.screenVideoPath || preferredPath; if (!screenVideoPath) { throw new Error("Native Windows capture did not return an output path."); } @@ -2642,15 +2792,6 @@ export function registerIpcHandlers( } else { pendingCursorRecordingData = null; } - if (discard) { - pendingCursorRecordingData = null; - await Promise.all([ - fs.rm(screenVideoPath, { force: true }), - preferredWebcamPath ? fs.rm(preferredWebcamPath, { force: true }) : Promise.resolve(), - fs.rm(`${screenVideoPath}.cursor.json`, { force: true }), - ]); - return { success: true, discarded: true }; - } if (cursorCaptureMode === "editable-overlay") { compactPendingCursorTelemetryPauseRanges(nativeWindowsPauseRanges); @@ -2690,16 +2831,7 @@ export function registerIpcHandlers( await stopCursorRecording(); return { success: false, error: String(error) }; } finally { - nativeWindowsCaptureProcess = null; - nativeWindowsCaptureTargetPath = null; - nativeWindowsCaptureWebcamTargetPath = null; - nativeWindowsCaptureRecordingId = null; - nativeWindowsCursorOffsetMs = 0; - nativeWindowsCursorCaptureMode = "editable-overlay"; - nativeWindowsCursorRecordingStartMs = 0; - nativeWindowsPauseStartedAtMs = null; - nativeWindowsPauseRanges = []; - nativeWindowsIsPaused = false; + resetNativeWindowsCaptureState(); const source = selectedSource || { name: "Screen" }; if (onRecordingStateChange) { onRecordingStateChange(false, source.name); diff --git a/electron/native/wgc-capture/src/main.cpp b/electron/native/wgc-capture/src/main.cpp index f8036c24a0..63cbcbba7f 100644 --- a/electron/native/wgc-capture/src/main.cpp +++ b/electron/native/wgc-capture/src/main.cpp @@ -58,6 +58,23 @@ struct CaptureControl { std::atomic paused = false; std::mutex mutex; std::condition_variable cv; + // Stop is signalled on its own mutex/CV pair, deliberately not on `mutex` + // (the frame-state lock in main) and not on this struct's `mutex` either. + // + // The frame lock is held across GPU work that cannot be interrupted: the + // WGC frame callback's CopyResource, and the video writer's staging-texture + // Map/readback. Waiting for a stop behind it made shutdown depend on the + // capture pipeline still being healthy -- and a `condition_variable` has to + // re-acquire its mutex before `wait` can return, so one wedged driver call + // left the main thread parked forever without emitting a single + // [stop-timing] line (issue #252). Nothing on this pair touches either + // frame lock, so a stop is always observed no matter what the GPU is doing. + // + // Threads that already hold the frame lock do call requestStop(), so the + // lock order is frame mutex -> stopMutex. Nothing ever takes them the other + // way round. + std::mutex stopMutex; + std::condition_variable stopCv; std::chrono::steady_clock::time_point pauseStartedAt; std::chrono::steady_clock::duration totalPausedDuration{}; // Shared T0 for every stream's timeline (screen video, audio, webcam). @@ -86,8 +103,48 @@ struct CaptureControl { } paused = nextPaused; } + + // The single way to ask for a stop. Every caller goes through here so that + // a future one cannot forget half of the handshake. + void requestStop() { + { + std::scoped_lock lock(stopMutex); + stopRequested = true; + } + // Publishing the flag under `stopMutex` before notifying is what makes + // waitForStop() immune to a wakeup landing between its predicate check + // and its enqueue on the CV. + stopCv.notify_all(); + // The frame pipeline parks on `cv`; wake it too so the video writer + // notices on this pass instead of after its next 100 ms timeout. + cv.notify_all(); + } + + void waitForStop() { + std::unique_lock lock(stopMutex); + // Bounded even though requestStop() publishes under `stopMutex`. This + // is the one wait in the helper that must never be able to hang, and + // re-reading an atomic every 200 ms costs nothing to guarantee it. + while (!stopRequested.load()) { + stopCv.wait_for(lock, std::chrono::milliseconds(200)); + } + } }; +int readEnvInt(const char* name, int fallback) { + char raw[32]{}; + const DWORD length = GetEnvironmentVariableA(name, raw, static_cast(sizeof(raw))); + if (length == 0 || length >= sizeof(raw)) { + return fallback; + } + + try { + return std::stoi(raw); + } catch (...) { + return fallback; + } +} + std::wstring utf8ToWide(const std::string& value) { if (value.empty()) { return {}; @@ -361,9 +418,19 @@ bool parseConfig(const std::string& json, CaptureConfig& config) { void readCaptureCommands(CaptureControl& control, const std::function& onPauseChanged) { std::string line; while (std::getline(std::cin, line)) { + // The comparisons below are exact, so a stray carriage return would + // drop the command in total silence -- the one command this helper + // must never fail to act on. + while (!line.empty() && (line.back() == '\r' || line.back() == '\n')) { + line.pop_back(); + } if (line == "stop" || line == "q" || line == "quit") { - control.stopRequested = true; - control.cv.notify_all(); + // Acknowledged before anything else runs. Issue #252 was reported + // with no way to tell "the helper never saw the stop" apart from + // "the helper saw it and then wedged"; this line settles that in + // every future report. + std::cerr << "[stop-timing] step=command-received elapsed_ms=0" << std::endl; + control.requestStop(); return; } if (line == "pause") { @@ -381,8 +448,10 @@ void readCaptureCommands(CaptureControl& control, const std::functionCreateTexture2D(&desc, nullptr, &latestFrameTexture))) { encodeFailed = true; - control.stopRequested = true; - control.cv.notify_all(); + control.requestStop(); return; } } @@ -711,8 +786,7 @@ int main(int argc, char* argv[]) { hasWebcamSample = webcamEncoder.captureBgraSample(webcamFrame, webcamTimestampHns, webcamSample); if (!hasWebcamSample) { encodeFailed = true; - control.stopRequested = true; - control.cv.notify_all(); + control.requestStop(); break; } lastWebcamTimestampHns = webcamTimestampHns; @@ -724,6 +798,9 @@ int main(int argc, char* argv[]) { } } } + if (testStallReadbackMs > 0) { + std::this_thread::sleep_for(std::chrono::milliseconds(testStallReadbackMs)); + } if (latestFrameTexture) { // captureVideoSample performs the GPU readback // (CopyResource/Map) from latestFrameTexture, which must @@ -737,8 +814,7 @@ int main(int argc, char* argv[]) { videoSample); if (!hasVideoSample) { encodeFailed = true; - control.stopRequested = true; - control.cv.notify_all(); + control.requestStop(); break; } lastEncodedVideoTimestampHns = frameTimestampHns; @@ -748,22 +824,22 @@ int main(int argc, char* argv[]) { // Submit the captured samples to their sink writers OUTSIDE // `mutex`. IMFSinkWriter::WriteSample runs the H.264 encode // synchronously and can be slow (especially the software encoder - // fallback used when preferSoftwareEncoder is set). Holding - // `mutex` across it would block the main thread's stop-wait - // (which locks the same mutex to check control.stopRequested) - // for as long as this thread keeps re-acquiring the lock faster - // than the main thread can, hanging the helper indefinitely - // after a stop request (issue #115). + // fallback used when preferSoftwareEncoder is set), and every + // millisecond it holds `mutex` is a millisecond the WGC frame + // callback spends queued behind it dropping frames (issue #115). + // + // This no longer has anything to do with noticing a stop -- that + // moved off `mutex` entirely (see CaptureControl::stopMutex) after + // issue #252 showed the readback below can wedge inside the lock + // regardless of how briefly WriteSample is held. if (hasWebcamSample && !webcamEncoder.submitVideoSample(webcamSample.Get())) { encodeFailed = true; - control.stopRequested = true; - control.cv.notify_all(); + control.requestStop(); break; } if (hasVideoSample && !encoder.submitVideoSample(videoSample.Get())) { encodeFailed = true; - control.stopRequested = true; - control.cv.notify_all(); + control.requestStop(); break; } @@ -800,8 +876,7 @@ int main(int argc, char* argv[]) { [&](const BYTE* data, DWORD byteCount, int64_t timestampHns, int64_t durationHns) { if (!encoder.writeAudio(data, byteCount, timestampHns, durationHns)) { encodeFailed = true; - control.stopRequested = true; - control.cv.notify_all(); + control.requestStop(); return false; } return true; @@ -899,27 +974,33 @@ int main(int argc, char* argv[]) { } }); + // The lock covers the wait and the decision, and nothing else. Every + // teardown call below runs outside it, because session.stop() waits for any + // in-flight WGC callback to finish -- and those callbacks block on this very + // mutex. Tearing down while holding it deadlocks the two against each other, + // on the one path the shutdown watchdog does not cover. + bool firstFrameArrived = false; { std::unique_lock lock(mutex); const bool started = control.cv.wait_for(lock, std::chrono::seconds(10), [&] { return firstFrameWritten.load() || control.stopRequested.load(); }); - if (!started || !firstFrameWritten) { - control.stopRequested = true; - control.cv.notify_all(); - if (stdinThread.joinable()) { - stdinThread.detach(); - } - microphoneCapture.stop(); - loopbackCapture.stop(); - webcamCapture.stop(); - if (audioMixer) { - audioMixer->stop(); - } - session.stop(); - std::cerr << "ERROR: Timed out waiting for first WGC frame" << std::endl; - return 1; + firstFrameArrived = started && firstFrameWritten.load(); + } + if (!firstFrameArrived) { + control.requestStop(); + if (stdinThread.joinable()) { + stdinThread.detach(); + } + microphoneCapture.stop(); + loopbackCapture.stop(); + webcamCapture.stop(); + if (audioMixer) { + audioMixer->stop(); } + session.stop(); + std::cerr << "ERROR: Timed out waiting for first WGC frame" << std::endl; + return 1; } if (audioMixer) { @@ -931,44 +1012,176 @@ int main(int argc, char* argv[]) { std::cout << "{\"event\":\"recording-started\",\"schemaVersion\":2}" << std::endl; std::cout << "Recording started" << std::endl; - { - std::unique_lock lock(mutex); - control.cv.wait(lock, [&] { - return control.stopRequested.load(); - }); - } + control.waitForStop(); const auto stopStart = std::chrono::steady_clock::now(); - auto logStopStep = [&](const char* step) { - const auto ms = std::chrono::duration_cast( + auto stopElapsedMs = [&] { + return std::chrono::duration_cast( std::chrono::steady_clock::now() - stopStart).count(); - std::cerr << "[stop-timing] step=" << step << " elapsed_ms=" << ms << std::endl; }; + // Which step we are inside right now, as opposed to which ones finished. + // Issue #252 was reported with an empty [stop-timing] log precisely because + // the old instrumentation only spoke after a step returned, which is the + // one thing a hung step never does. + std::atomic currentStopStep{"stop-wait"}; + std::atomic shutdownComplete = false; + + // A ceiling on the whole shutdown, and a tighter one per step. + // + // The ceiling exists because the app is waiting on the other end of the + // pipe: NATIVE_WINDOWS_CAPTURE_STOP_TIMEOUT_MS in + // electron/recording/nativeWindowsCaptureStop.ts must stay comfortably + // above this, so the helper always ends itself rather than being killed + // mid-finalize by a parent that ran out of patience. Change one and change + // the other. + // + // The per-step budget is tighter because most steps fail differently: + // stopping threads and closing WGC either completes in milliseconds or is + // wedged inside a driver, and there is no slow-but-working case worth + // waiting for -- waiting is exactly what cost issue #252 a minute of the + // user's time. Finalizing is the opposite. IMFSinkWriter::Finalize drains + // the encoder and writes the MP4 index, which on a long recording through + // the software encoder legitimately takes seconds (issue #34 raised the + // app-side timeout for precisely this), so it gets whatever is left of the + // ceiling rather than a step budget of its own. + const int shutdownBudgetMs = std::max(2000, readEnvInt("OPENSCREEN_WGC_STOP_BUDGET_MS", 50000)); + const int stepBudgetMs = + std::min(shutdownBudgetMs, std::max(1000, readEnvInt("OPENSCREEN_WGC_STEP_BUDGET_MS", 8000))); + std::atomic currentStepDeadlineMs{stepBudgetMs}; + + auto beginStopStep = [&](const char* step, int budgetMs) { + currentStopStep = step; + // Clamped to the ceiling: no sequence of individually-patient steps can + // add up to a shutdown the app has already given up on. + currentStepDeadlineMs = + std::min(stopElapsedMs() + budgetMs, shutdownBudgetMs); + std::cerr << "[stop-timing] step=" << step << " elapsed_ms=" << stopElapsedMs() + << " phase=begin" << std::endl; + }; + // `step= elapsed_ms=` has to stay the leading shape of every line: + // scripts/diagnostic-tool/diagnostic.mjs matches on it, so a trailing + // `phase=` is additive but a leading one would hide the line from the tool. + auto logStopStep = [&](const char* step) { + std::cerr << "[stop-timing] step=" << step << " elapsed_ms=" << stopElapsedMs() << std::endl; + }; + + // None of the steps below can be interrupted: a wedged GPU readback, a + // camera that stops delivering samples, or a WinRT Close() that never + // returns would each leave the helper alive forever, which the app sees as a + // freeze ending in a lost recording (issue #252). Give each step a deadline + // and end the process if one blows through it, naming the step so the next + // bug report starts where this one had to guess. Joinable rather than + // detached: it references main's locals, and its poll interval makes the + // join at the end cost at most one tick. + std::thread shutdownWatchdog([&] { + while (!shutdownComplete.load()) { + // Re-read the flag as part of the same decision as the deadline. + // Checking them separately let a shutdown that completed during the + // sleep still be killed. + if (stopElapsedMs() >= currentStepDeadlineMs.load() && !shutdownComplete.load()) { + const char* step = currentStopStep.load(); + std::cerr << "[stop-timing] step=" << step << " elapsed_ms=" << stopElapsedMs() + << " phase=abandoned" << std::endl; + std::cout << "{\"event\":\"stop-timeout\",\"schemaVersion\":2,\"step\":\"" << step + << "\"}" << std::endl; + std::cout.flush(); + std::cerr.flush(); + // TerminateProcess rather than exit(): exit() runs static + // destructors on this thread, and ~MFEncoder finalizes the sink + // writer behind the very lock a wedged encoder would be holding. + // This thread exists to end the process, not to queue behind the + // hang it is reporting. + TerminateProcess(GetCurrentProcess(), 3); + } + std::this_thread::sleep_for(std::chrono::milliseconds(50)); + } + }); + // Quiesce the frame producer first. Until WGC is closed, callbacks keep + // arriving and keep taking the frame lock, racing the writer's last pass on + // the shared D3D context at exactly the moment we can least afford a stall. + beginStopStep("wgc-quiesce", stepBudgetMs); + // The drain outcome decides the shape of the whole rest of the shutdown: + // a callback that never came back makes wgc-session-close skip the device + // release, so a report that does not say which happened cannot be read. + const bool wgcDrained = session.quiesceCapture(); + std::cerr << "[stop-timing] step=wgc-quiesce elapsed_ms=" << stopElapsedMs() + << " drained=" << (wgcDrained ? "true" : "false") << std::endl; + beginStopStep("microphone", stepBudgetMs); microphoneCapture.stop(); logStopStep("microphone"); + beginStopStep("loopback", stepBudgetMs); loopbackCapture.stop(); logStopStep("loopback"); + beginStopStep("webcam", stepBudgetMs); webcamCapture.stop(); logStopStep("webcam"); + beginStopStep("audio-mixer", stepBudgetMs); if (audioMixer) { audioMixer->stop(); } logStopStep("audio-mixer"); + beginStopStep("video-writer-join", stepBudgetMs); stopVideoWriter(); logStopStep("video-writer-join"); - session.stop(); - logStopStep("wgc-session-close"); - { - std::scoped_lock lock(mutex); - encoder.finalize(); - logStopStep("encoder-finalize"); + // No frame lock here, and the ordering above is what makes that safe rather + // than incidental: stopVideoWriter() joined the only thread that calls into + // the encoder's GPU readback, and audioMixer->stop() joined the only other + // thread that writes to it. MFEncoder's own writerMutex_ deliberately does + // NOT cover copyFrameToBuffer, so finalizing before those joins would race + // the staging texture -- do not reorder these. + beginStopStep("encoder-finalize", shutdownBudgetMs); + const bool screenFinalized = encoder.finalize(); + logStopStep("encoder-finalize"); + if (!screenFinalized) { + std::cerr << "ERROR: Failed to finalize the recording" << std::endl; + } + + // Report success the moment the screen file is durable, not at the end of + // the process's life. Finalize is what writes the MP4 index; everything + // after it is housekeeping that cannot improve that file but can still + // wedge on a bad driver. Announcing here means a watchdog kill during + // teardown costs the user nothing -- the app reads this line and keeps the + // recording. + // + // Gated on the SCREEN finalize alone, and printed before the webcam's. + // The app treats this line as proof the screen file is playable, so a + // failed screen Finalize must not reach it. The webcam is a second, + // optional file and must not be able to veto the first: letting it decide + // meant one bad camera clip discarded a complete capture, and because both + // finalizes share the same ceiling, a slow screen finalize could leave the + // webcam step no budget at all and get the process killed before this line + // ever ran. A webcam that fails below is an error on stderr and a non-zero + // exit -- not a lost recording. + if (!encodeFailed && screenFinalized) { + std::cout << "{\"event\":\"recording-stopped\",\"schemaVersion\":2,\"screenPath\":\"" + << jsonEscape(config.outputPath) << "\""; if (writeSeparateWebcam) { - webcamEncoder.finalize(); - logStopStep("webcam-encoder-finalize"); + std::cout << ",\"webcamPath\":\"" << jsonEscape(config.webcamOutputPath) << "\""; + } + std::cout << "}" << std::endl; + std::cout << "Recording stopped. Output path: " << config.outputPath << std::endl; + } + + bool webcamFinalized = true; + if (writeSeparateWebcam) { + beginStopStep("webcam-encoder-finalize", shutdownBudgetMs); + webcamFinalized = webcamEncoder.finalize(); + logStopStep("webcam-encoder-finalize"); + if (!webcamFinalized) { + std::cerr << "ERROR: Failed to finalize the webcam recording" << std::endl; } } + // Releasing the device goes last: by now no thread can still be holding the + // D3D context. + beginStopStep("wgc-session-close", stepBudgetMs); + session.stop(); + logStopStep("wgc-session-close"); + + shutdownComplete = true; + shutdownWatchdog.join(); + if (stdinThread.joinable()) { stdinThread.detach(); } @@ -977,13 +1190,9 @@ int main(int argc, char* argv[]) { std::cerr << "ERROR: Failed to encode WGC frame" << std::endl; return 1; } - - std::cout << "{\"event\":\"recording-stopped\",\"schemaVersion\":2,\"screenPath\":\"" - << jsonEscape(config.outputPath) << "\""; - if (writeSeparateWebcam) { - std::cout << ",\"webcamPath\":\"" << jsonEscape(config.webcamOutputPath) << "\""; + if (!screenFinalized || !webcamFinalized) { + return 1; } - std::cout << "}" << std::endl; - std::cout << "Recording stopped. Output path: " << config.outputPath << std::endl; + return 0; } diff --git a/electron/native/wgc-capture/src/wgc_session.cpp b/electron/native/wgc-capture/src/wgc_session.cpp index 89f0b55fe0..ccab06727e 100644 --- a/electron/native/wgc-capture/src/wgc_session.cpp +++ b/electron/native/wgc-capture/src/wgc_session.cpp @@ -5,7 +5,9 @@ #include #include +#include #include +#include namespace wf = winrt::Windows::Foundation; namespace wgcap = winrt::Windows::Graphics::Capture; @@ -273,23 +275,81 @@ bool WgcSession::start() { return true; } -void WgcSession::stop() { - if (framePool_) { - framePool_.FrameArrived(frameArrivedToken_); +bool WgcSession::quiesceCapture(int drainTimeoutMs) { + if (quiesced_) { + return callbacksInFlight_.load() == 0; + } + quiesced_ = true; + + try { + if (framePool_) { + framePool_.FrameArrived(frameArrivedToken_); + } + } catch (...) { + // Revoking a handler the runtime has already torn down is not a reason + // to abandon the rest of the shutdown. } - if (session_) { - session_.Close(); - session_ = nullptr; + { + // Drop the callback under the same lock onFrameArrived copies it under, + // so any handler that has not read it yet becomes a no-op... + std::scoped_lock lock(callbackMutex_); + frameCallback_ = nullptr; + } + // ...then wait out the handlers that already read it. Without this, stop() + // could Reset() the D3D context while a callback was still issuing + // CopyResource on it. + // + // Bounded, because a callback wedged inside the display driver never + // finishes and this runs on paths that have no watchdog above them (the + // first-frame timeout in main.cpp). Giving up is reported rather than + // papered over: the caller keeps the device alive instead, which leaks it + // until the process exits and is the lesser of the two failures. + const auto drainDeadline = + std::chrono::steady_clock::now() + std::chrono::milliseconds(drainTimeoutMs); + while (callbacksInFlight_.load() > 0) { + if (std::chrono::steady_clock::now() >= drainDeadline) { + std::cerr << "WARNING: A WGC frame callback did not finish; leaving the device alive" + << std::endl; + return false; + } + std::this_thread::sleep_for(std::chrono::milliseconds(1)); + } + + // Close() is a C++/WinRT projection and throws hresult_error on failure. + // Letting that escape would take the process down through std::terminate + // mid-shutdown, discarding a recording that is already finalized by the time + // this runs. There is nothing to do about a capture session that refuses to + // close except stop caring about it. + try { + if (session_) { + session_.Close(); + } + if (framePool_) { + framePool_.Close(); + } + } catch (winrt::hresult_error const& error) { + std::cerr << "WARNING: Failed to close the WGC session (hr=0x" << std::hex + << static_cast(error.code()) << std::dec << ")" << std::endl; + } catch (...) { + std::cerr << "WARNING: Failed to close the WGC session" << std::endl; } - if (framePool_) { - framePool_.Close(); - framePool_ = nullptr; + session_ = nullptr; + framePool_ = nullptr; + started_ = false; + return true; +} + +void WgcSession::stop() { + if (!quiesceCapture()) { + // A callback is still inside the driver holding this context. Releasing + // it now would pull the device out from under a live CopyResource, so + // leak it and let process exit reclaim it. + return; } item_ = nullptr; winrtDevice_ = nullptr; d3dContext_.Reset(); d3dDevice_.Reset(); - started_ = false; } void WgcSession::onFrameArrived( @@ -312,10 +372,30 @@ void WgcSession::onFrameArrived( { std::scoped_lock lock(callbackMutex_); callback = frameCallback_; + if (callback) { + // Counted under the same lock quiesceCapture() clears the callback + // under, so once it has cleared it no new callback can start and + // the counter it then drains cannot go back up. + callbacksInFlight_ += 1; + } } if (callback) { + // Scoped rather than a bare decrement after the call, for two reasons: + // a callback that left by exception would otherwise strand + // quiesceCapture()'s drain forever, and the guard has to outlive + // frame.Close() -- dropping the count first would let quiesce return and + // close the frame pool while this handler is still closing a frame that + // pool owns. + struct InFlightGuard { + std::atomic& counter; + ~InFlightGuard() { + counter -= 1; + } + } guard{callbacksInFlight_}; callback(texture.Get(), timeSpanToHns(frame.SystemRelativeTime())); + frame.Close(); + return; } frame.Close(); } diff --git a/electron/native/wgc-capture/src/wgc_session.h b/electron/native/wgc-capture/src/wgc_session.h index 43de21a87a..33aba29b41 100644 --- a/electron/native/wgc-capture/src/wgc_session.h +++ b/electron/native/wgc-capture/src/wgc_session.h @@ -9,6 +9,7 @@ #include #include +#include #include #include @@ -26,6 +27,14 @@ class WgcSession { bool initialize(HWND window, int fps, bool captureCursor); void setFrameCallback(FrameCallback callback); bool start(); + // Stops frame delivery and waits out any callback already running, without + // touching the D3D device. Split out of stop() so a caller can quiesce the + // producer early in a shutdown and only release the device once nothing can + // still be using it. Idempotent; stop() calls it. + // + // Returns false if a callback was still running when `drainTimeoutMs` + // expired -- releasing the device after that is unsafe, so stop() skips it. + bool quiesceCapture(int drainTimeoutMs = 5000); void stop(); int captureWidth() const; @@ -51,6 +60,8 @@ class WgcSession { winrt::event_token frameArrivedToken_{}; FrameCallback frameCallback_; std::mutex callbackMutex_; + std::atomic callbacksInFlight_ = 0; + bool quiesced_ = false; int width_ = 0; int height_ = 0; int fps_ = 60; diff --git a/electron/recording/nativeWindowsCaptureStop.test.ts b/electron/recording/nativeWindowsCaptureStop.test.ts new file mode 100644 index 0000000000..7ba34317c5 --- /dev/null +++ b/electron/recording/nativeWindowsCaptureStop.test.ts @@ -0,0 +1,363 @@ +import type { ChildProcessWithoutNullStreams } from "node:child_process"; +import { EventEmitter } from "node:events"; +import { PassThrough, Writable } from "node:stream"; +import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; +import { + readStoppedPath, + terminateNativeWindowsCapture, + waitForNativeWindowsCaptureStop, +} from "./nativeWindowsCaptureStop"; + +/** + * Stands in for wgc-capture.exe. `exitCode`/`signalCode` are real properties on + * `ChildProcess` and the code under test reads them to decide whether waiting + * for 'close' can still pay off, so the fake has to model them honestly. + */ +class FakeHelper extends EventEmitter { + stdout = new PassThrough(); + stderr = new PassThrough(); + stdin: Writable; + exitCode: number | null = null; + signalCode: string | null = null; + pid: number | undefined = 4242; + killCalls = 0; + /** When false, kill() is recorded but the process refuses to die. */ + diesOnKill = true; + + constructor() { + super(); + this.stdin = new Writable({ + write(_chunk, _encoding, callback) { + callback(); + }, + }); + } + + kill() { + this.killCalls += 1; + if (this.diesOnKill) { + this.exit(1); + } + return true; + } + + exit(code: number) { + this.exitCode = code; + this.emit("close", code); + } +} + +function asProc(helper: FakeHelper) { + return helper as unknown as ChildProcessWithoutNullStreams; +} + +let helper: FakeHelper; + +beforeEach(() => { + vi.useFakeTimers(); + helper = new FakeHelper(); +}); + +afterEach(() => { + vi.useRealTimers(); + vi.restoreAllMocks(); +}); + +describe("readStoppedPath", () => { + it("reads the finalized path out of the helper log", () => { + expect(readStoppedPath("Recording stopped. Output path: C:\\rec\\a.mp4\n")).toBe( + "C:\\rec\\a.mp4", + ); + }); + + it("is null when the helper never reported a finalized file", () => { + expect(readStoppedPath("Recording started\n[stop-timing] step=microphone elapsed_ms=0\n")).toBe( + null, + ); + }); +}); + +describe("waitForNativeWindowsCaptureStop", () => { + it("resolves with the path the helper reported", async () => { + let output = "Recording started\n"; + const pending = waitForNativeWindowsCaptureStop({ + proc: asProc(helper), + targetPath: "C:\\rec\\a.mp4", + readOutput: () => output, + }); + + output += "Recording stopped. Output path: C:\\rec\\a.mp4\n"; + helper.exit(0); + + await expect(pending).resolves.toEqual({ ok: true, screenVideoPath: "C:\\rec\\a.mp4" }); + }); + + it("falls back to the requested path when the helper exits 0 quietly", async () => { + const pending = waitForNativeWindowsCaptureStop({ + proc: asProc(helper), + targetPath: "C:\\rec\\a.mp4", + readOutput: () => "", + }); + + helper.exit(0); + + await expect(pending).resolves.toEqual({ ok: true, screenVideoPath: "C:\\rec\\a.mp4" }); + }); + + /** + * The helper can be gone before the stop IPC even runs -- it force-exits on + * its own shutdown watchdog, and a lost D3D device kills it outright. Node + * never re-emits 'close' for a process that already exited, so waiting for + * one burned the entire stop timeout and reported it as a hang (issue #252). + */ + it("settles immediately when the helper has already exited", async () => { + helper.exitCode = 0; + + const result = await waitForNativeWindowsCaptureStop({ + proc: asProc(helper), + targetPath: "C:\\rec\\a.mp4", + readOutput: () => "Recording stopped. Output path: C:\\rec\\a.mp4\n", + }); + + expect(result).toEqual({ ok: true, screenVideoPath: "C:\\rec\\a.mp4" }); + // No timers were needed: nothing was ever scheduled to wait on. + expect(vi.getTimerCount()).toBe(0); + }); + + /** + * The helper announces a finalized recording before it releases the GPU + * device, so its own watchdog killing it during teardown must still count as + * a success -- the MP4 on disk is complete, and the caller deletes files it + * is told are failures. + */ + it("keeps the recording when the helper was killed after finalizing", async () => { + const pending = waitForNativeWindowsCaptureStop({ + proc: asProc(helper), + targetPath: "C:\\rec\\a.mp4", + readOutput: () => + "[stop-timing] step=encoder-finalize elapsed_ms=400\n" + + "Recording stopped. Output path: C:\\rec\\a.mp4\n" + + "[stop-timing] step=wgc-session-close elapsed_ms=8001 phase=abandoned\n" + + '{"event":"stop-timeout","schemaVersion":2,"step":"wgc-session-close"}\n', + }); + + helper.exit(3); + + await expect(pending).resolves.toEqual({ ok: true, screenVideoPath: "C:\\rec\\a.mp4" }); + }); + + /** + * The webcam is a second, optional file, and the helper announces the screen + * recording before finalizing it precisely so a bad camera clip cannot veto a + * complete capture. The exit code is non-zero and the reason is on stderr; + * the screen MP4 is still finished and must still be kept. + */ + it("keeps the screen recording when only the webcam failed to finalize", async () => { + const pending = waitForNativeWindowsCaptureStop({ + proc: asProc(helper), + targetPath: "C:\\rec\\a.mp4", + readOutput: () => + "Recording stopped. Output path: C:\\rec\\a.mp4\n" + + "[stop-timing] step=webcam-encoder-finalize elapsed_ms=900\n" + + "ERROR: Failed to finalize the webcam recording\n", + }); + + helper.exit(1); + + await expect(pending).resolves.toEqual({ ok: true, screenVideoPath: "C:\\rec\\a.mp4" }); + }); + + it("classifies the helper's own shutdown watchdog as a stop timeout", async () => { + const pending = waitForNativeWindowsCaptureStop({ + proc: asProc(helper), + targetPath: "C:\\rec\\a.mp4", + readOutput: () => + "[stop-timing] step=video-writer-join elapsed_ms=8001 phase=abandoned\n" + + '{"event":"stop-timeout","schemaVersion":2,"step":"video-writer-join"}\n', + }); + + helper.exit(3); + + await expect(pending).resolves.toEqual({ + ok: false, + reason: "stop-timeout", + message: "The recorder stalled while shutting down (video-writer-join).", + exited: true, + }); + }); + + it("reports a helper failure with its output rather than a timeout", async () => { + const pending = waitForNativeWindowsCaptureStop({ + proc: asProc(helper), + targetPath: "C:\\rec\\a.mp4", + readOutput: () => "ERROR: Failed to encode WGC frame\n", + }); + + helper.exit(1); + + await expect(pending).resolves.toEqual({ + ok: false, + reason: "helper-failed", + message: "ERROR: Failed to encode WGC frame", + exited: true, + }); + }); + + /** Every run ends with diagnostics, so "the last line" is never the cause. */ + it("skips diagnostic noise when picking the user-facing failure message", async () => { + const pending = waitForNativeWindowsCaptureStop({ + proc: asProc(helper), + targetPath: "C:\\rec\\a.mp4", + readOutput: () => + "ERROR: Failed to initialize Media Foundation encoder\n" + + "[stop-timing] step=microphone elapsed_ms=2\n" + + '{"event":"warning","code":"webcam-unavailable"}\n', + }); + + helper.exit(1); + + await expect(pending).resolves.toMatchObject({ + reason: "helper-failed", + message: "ERROR: Failed to initialize Media Foundation encoder", + }); + }); + + it("still settles when killing the wedged helper throws", async () => { + helper.diesOnKill = false; + const forceKill = vi.fn(async () => { + throw new Error("EPERM"); + }); + + const pending = waitForNativeWindowsCaptureStop({ + proc: asProc(helper), + targetPath: "C:\\rec\\a.mp4", + readOutput: () => "", + timeoutMs: 20_000, + killGraceMs: 2_000, + forceKill, + }); + + await vi.advanceTimersByTimeAsync(20_000); + await vi.advanceTimersByTimeAsync(4_000); + + await expect(pending).resolves.toMatchObject({ + ok: false, + reason: "stop-timeout", + exited: false, + }); + }); + + it("kills the helper and reports a timeout when it never finalizes", async () => { + const pending = waitForNativeWindowsCaptureStop({ + proc: asProc(helper), + targetPath: "C:\\rec\\a.mp4", + readOutput: () => "[stop-timing] step=video-writer-join phase=begin elapsed_ms=0\n", + timeoutMs: 20_000, + }); + + await vi.advanceTimersByTimeAsync(20_000); + + await expect(pending).resolves.toEqual({ + ok: false, + reason: "stop-timeout", + // A short sentence, not the log: this ends up in a toast. + message: "The recorder did not shut down in time.", + exited: true, + }); + expect(helper.killCalls).toBe(1); + }); + + /** The timeout path is the likeliest place for an already-finalized file. */ + it("keeps a recording the helper finalized before the parent gave up", async () => { + const pending = waitForNativeWindowsCaptureStop({ + proc: asProc(helper), + targetPath: "C:\\rec\\a.mp4", + readOutput: () => + "Recording stopped. Output path: C:\\rec\\a.mp4\n" + + "[stop-timing] step=wgc-session-close elapsed_ms=1 phase=begin\n", + timeoutMs: 20_000, + }); + + await vi.advanceTimersByTimeAsync(20_000); + + await expect(pending).resolves.toEqual({ ok: true, screenVideoPath: "C:\\rec\\a.mp4" }); + }); + + it("reports the exit code rather than a progress line when nothing failed loudly", async () => { + const pending = waitForNativeWindowsCaptureStop({ + proc: asProc(helper), + targetPath: "C:\\rec\\a.mp4", + readOutput: () => 'Recording started\n{"event":"ready","schemaVersion":2}\n', + }); + + helper.exit(9); + + await expect(pending).resolves.toMatchObject({ + reason: "helper-failed", + message: "Native Windows capture exited with code=9", + }); + }); + + it("escalates to a forced tree kill when the helper survives kill()", async () => { + helper.diesOnKill = false; + const forceKill = vi.fn(async () => { + helper.exit(1); + }); + + const pending = waitForNativeWindowsCaptureStop({ + proc: asProc(helper), + targetPath: "C:\\rec\\a.mp4", + readOutput: () => "", + timeoutMs: 20_000, + killGraceMs: 2_000, + forceKill, + }); + + await vi.advanceTimersByTimeAsync(20_000); + await vi.advanceTimersByTimeAsync(2_000); + + const result = await pending; + expect(forceKill).toHaveBeenCalledWith(4242); + expect(result).toMatchObject({ ok: false, reason: "stop-timeout", exited: true }); + }); + + it("reports the helper as surviving when even the forced kill fails", async () => { + helper.diesOnKill = false; + // taskkill returns, but the helper is wedged below user mode and survives. + const forceKill = vi.fn(async () => undefined); + + const pending = waitForNativeWindowsCaptureStop({ + proc: asProc(helper), + targetPath: "C:\\rec\\a.mp4", + readOutput: () => "", + timeoutMs: 20_000, + killGraceMs: 2_000, + forceKill, + }); + + await vi.advanceTimersByTimeAsync(20_000); + await vi.advanceTimersByTimeAsync(4_000); + + await expect(pending).resolves.toMatchObject({ + ok: false, + reason: "stop-timeout", + exited: false, + }); + }); +}); + +describe("terminateNativeWindowsCapture", () => { + it("is a no-op for a helper that already exited", async () => { + helper.exitCode = 0; + + await expect(terminateNativeWindowsCapture(asProc(helper))).resolves.toBe(true); + expect(helper.killCalls).toBe(0); + }); + + it("does not wait out the grace period when kill() works", async () => { + const pending = terminateNativeWindowsCapture(asProc(helper), { graceMs: 2_000 }); + + await expect(pending).resolves.toBe(true); + expect(helper.killCalls).toBe(1); + }); +}); diff --git a/electron/recording/nativeWindowsCaptureStop.ts b/electron/recording/nativeWindowsCaptureStop.ts new file mode 100644 index 0000000000..95da2c19ac --- /dev/null +++ b/electron/recording/nativeWindowsCaptureStop.ts @@ -0,0 +1,275 @@ +import { type ChildProcessWithoutNullStreams, execFile } from "node:child_process"; + +/** + * Stopping a native Windows (WGC) recording, as a unit that can be tested. + * + * This lives outside `electron/ipc/handlers.ts` for one reason: that module + * calls `app.getPath()` while it is being imported, so nothing in it can be + * loaded from a test. The stop path shipped broken twice (issues #115, #252) + * with no test able to see it, so it moved here. + */ + +/** + * The outer bound on a stop, and deliberately not the lever. + * + * This was raised from 15s to 60s for issue #34 so `IMFSinkWriter::Finalize` + * had room to drain on slow encoders, and it stays at 60s for the same reason: + * a parent that gave up first would kill a working save. + * + * It must stay above the helper's own shutdown ceiling + * (`OPENSCREEN_WGC_STOP_BUDGET_MS`, 50s — see the stop sequence in + * `electron/native/wgc-capture/src/main.cpp`), which is what guarantees the + * helper always ends itself rather than being killed mid-finalize from here. + * Raise one and raise the other. + * + * What changed for issue #252 is that reaching this timeout is no longer how a + * wedged recorder is caught: the helper bounds every shutdown step itself and + * force-exits within seconds, so 'close' arrives long before this fires. + * Getting here means the helper is stuck somewhere even `TerminateProcess` + * could not reach. + */ +export const NATIVE_WINDOWS_CAPTURE_STOP_TIMEOUT_MS = 60_000; + +/** How long a killed helper gets to actually die before we escalate. */ +const NATIVE_WINDOWS_CAPTURE_KILL_GRACE_MS = 2_000; + +const RECORDING_STOPPED_PATTERN = /Recording stopped\. Output path: (.+)/; +const STOP_TIMEOUT_EVENT_PATTERN = /"event":"stop-timeout"[^\n]*"step":"([^"]+)"/; + +export type NativeWindowsCaptureStopReason = "stop-timeout" | "helper-failed"; + +export type NativeWindowsCaptureStopResult = + | { ok: true; screenVideoPath: string } + | { + ok: false; + reason: NativeWindowsCaptureStopReason; + message: string; + /** False when a wedged helper survived even the forced kill. */ + exited: boolean; + }; + +export function readStoppedPath(output: string) { + return output.match(RECORDING_STOPPED_PATTERN)?.[1]?.trim() || null; +} + +/** The step the helper's shutdown watchdog gave up on, if it fired. */ +export function readAbandonedStep(output: string) { + return output.match(STOP_TIMEOUT_EVENT_PATTERN)?.[1] ?? null; +} + +/** + * The most useful line of a failed helper run, for a toast. + * + * The log ends with `[stop-timing]` and JSON protocol lines on every run, so + * "the last line" is reliably a diagnostic rather than a cause. Prefer what the + * helper actually complained about. + */ +export function readHelperFailureMessage(output: string, code: number | null) { + const complaints = output + .split(/\r?\n/) + .map((line) => line.trim()) + .filter((line) => line.startsWith("ERROR:") || line.startsWith("WARNING:")); + + // Only lines that describe a failure. The rest of a helper log is progress + // ("Recording started") and diagnostics, and reporting the last of those as + // the error reads like a success message on a red toast. + return complaints.at(-1) ?? `Native Windows capture exited with code=${code ?? "unknown"}`; +} + +function hasExited(proc: ChildProcessWithoutNullStreams) { + return proc.exitCode !== null || proc.signalCode !== null; +} + +/** + * `taskkill /T /F` on the helper. `ChildProcess.kill()` maps to + * `TerminateProcess` on Windows, which is already forceful but cannot touch a + * thread that is stuck below user mode -- the exact state a wedged display + * driver leaves the helper in. Escalating gives us a second chance, and an + * orphan that survives both is worth reporting rather than pretending away. + */ +function forceKillProcessTree(pid: number) { + return new Promise((resolve) => { + // Bounded: taskkill walks the process tree and opens handles, both of + // which can block on exactly the wedged process it is being asked to + // kill. Nothing else can settle the stop promise by this point, so a + // taskkill that never returns would recreate the unbounded wait this + // whole path exists to end. + execFile( + "taskkill", + ["/PID", String(pid), "/T", "/F"], + { timeout: NATIVE_WINDOWS_CAPTURE_KILL_GRACE_MS, windowsHide: true }, + () => resolve(), + ); + }); +} + +function waitForExit(proc: ChildProcessWithoutNullStreams, timeoutMs: number) { + if (hasExited(proc)) { + return Promise.resolve(true); + } + + return new Promise((resolve) => { + const settle = (exited: boolean) => { + clearTimeout(timer); + proc.off("close", onClose); + resolve(exited); + }; + const onClose = () => settle(true); + const timer = setTimeout(() => settle(false), timeoutMs); + proc.once("close", onClose); + }); +} + +/** + * Kills the helper and confirms it actually died, escalating once. Resolves to + * whether the process is gone. + */ +export async function terminateNativeWindowsCapture( + proc: ChildProcessWithoutNullStreams, + options: { + graceMs?: number; + forceKill?: (pid: number) => Promise; + } = {}, +) { + if (hasExited(proc)) { + return true; + } + + const graceMs = options.graceMs ?? NATIVE_WINDOWS_CAPTURE_KILL_GRACE_MS; + const forceKill = options.forceKill ?? forceKillProcessTree; + + proc.kill(); + if (await waitForExit(proc, graceMs)) { + return true; + } + + if (typeof proc.pid === "number") { + await forceKill(proc.pid); + return waitForExit(proc, graceMs); + } + + return false; +} + +/** + * Waits for the helper to report a finalized recording. + * + * Resolves rather than rejects on failure: the caller needs to tell a stop + * timeout apart from a helper error to pick the right message, and an `Error` + * carrying the whole accumulated helper log is not something to put in front of + * a user. + */ +export function waitForNativeWindowsCaptureStop(options: { + proc: ChildProcessWithoutNullStreams; + /** Path we asked the helper to write, used when it exits 0 without saying so. */ + targetPath: string | null; + /** The accumulated helper output; read lazily so late chunks are included. */ + readOutput: () => string; + timeoutMs?: number; + killGraceMs?: number; + forceKill?: (pid: number) => Promise; +}): Promise { + const { proc, targetPath, readOutput } = options; + const timeoutMs = options.timeoutMs ?? NATIVE_WINDOWS_CAPTURE_STOP_TIMEOUT_MS; + + const settleFromOutput = (code: number | null): NativeWindowsCaptureStopResult => { + const output = readOutput(); + // The helper announces this as soon as the MP4 index is written, before + // it releases the GPU device. So a helper that was killed during teardown + // still reports a recording that is complete and playable -- taking its + // word for that is what keeps the file (issue #252). + const stoppedPath = readStoppedPath(output); + if (stoppedPath) { + return { ok: true, screenVideoPath: stoppedPath }; + } + if (code === 0 && targetPath) { + return { ok: true, screenVideoPath: targetPath }; + } + // The helper's own shutdown watchdog gave up. That is a stop timeout, not + // a generic failure, and it knows which step stalled. + const abandonedStep = readAbandonedStep(output); + if (abandonedStep) { + return { + ok: false, + reason: "stop-timeout", + message: `The recorder stalled while shutting down (${abandonedStep}).`, + exited: true, + }; + } + return { + ok: false, + reason: "helper-failed", + message: readHelperFailureMessage(output, code), + exited: true, + }; + }; + + // The helper may already be gone -- it force-exits on its own shutdown + // watchdog, and a DXGI device loss can kill it outright mid-recording. Node + // does not re-emit 'close' for a process that has already exited, so + // registering a listener first would burn the whole timeout waiting for an + // event that can never arrive. + if (hasExited(proc)) { + return Promise.resolve(settleFromOutput(proc.exitCode)); + } + + return new Promise((resolve) => { + const onClose = (code: number | null) => { + cleanup(); + resolve(settleFromOutput(code)); + }; + const onError = (error: Error) => { + cleanup(); + resolve({ + ok: false, + reason: "helper-failed", + message: error.message, + exited: hasExited(proc), + }); + }; + const cleanup = () => { + clearTimeout(timer); + proc.off("close", onClose); + proc.off("error", onError); + }; + + const timer = setTimeout(() => { + cleanup(); + void (async () => { + let exited = false; + try { + exited = await terminateNativeWindowsCapture(proc, { + graceMs: options.killGraceMs, + forceKill: options.forceKill, + }); + } catch (error) { + // Killing a wedged, possibly protected process can itself + // fail. `cleanup()` has already dropped this promise's only + // other path to settling, so swallowing the rejection here + // would hang the stop handler forever -- the very failure + // this timeout exists to end. + console.warn("[native-wgc] could not terminate the wedged helper:", error); + } + // Check for a finalized recording before calling this a loss. The + // helper announces the file as soon as its index is written and + // only then does its GPU teardown, so the run most likely to end + // up here is also the one most likely to have already produced a + // perfectly playable MP4. + const stoppedPath = readStoppedPath(readOutput()); + if (stoppedPath) { + resolve({ ok: true, screenVideoPath: stoppedPath }); + return; + } + resolve({ + ok: false, + reason: "stop-timeout", + message: "The recorder did not shut down in time.", + exited, + }); + })(); + }, timeoutMs); + + proc.once("close", onClose); + proc.once("error", onError); + }); +} diff --git a/scripts/diagnostic-tool/diagnostic.mjs b/scripts/diagnostic-tool/diagnostic.mjs index 3b08d798cc..f19020ae51 100644 --- a/scripts/diagnostic-tool/diagnostic.mjs +++ b/scripts/diagnostic-tool/diagnostic.mjs @@ -149,8 +149,12 @@ function buildConfig(opts) { function parseStopTiming(stderrText) { const lines = []; for (const line of stderrText.split(/\r?\n/)) { - const m = line.match(/\[stop-timing\]\s+step=(\S+)\s+elapsed_ms=(\d+)/); - if (m) lines.push({ step: m[1], elapsedMs: Number(m[2]) }); + // `phase` is the point of the whole log: `begin` is the step being + // entered, `abandoned` names the step the shutdown watchdog gave up on. + // Dropping it left the report unable to say which step hung -- the one + // question a #252 bug report has to answer. + const m = line.match(/\[stop-timing\]\s+step=(\S+)\s+elapsed_ms=(\d+)(?:\s+phase=(\S+))?/); + if (m) lines.push({ step: m[1], elapsedMs: Number(m[2]), phase: m[3] ?? "end" }); } return lines; } @@ -303,7 +307,14 @@ async function main() { console.log(`[diag] stop elapsed: ${report.stopElapsedMs}ms`); console.log(`[diag] stop timing steps:`); for (const entry of report.stopTiming) { - console.log(`[diag] ${entry.step.padEnd(28)} ${entry.elapsedMs}ms`); + // Only the outcome of each step, so the summary reads as one line per + // step rather than an entry-and-exit pair, and an abandoned step is + // impossible to miss. + if (entry.phase === "begin") { + continue; + } + const suffix = entry.phase === "end" ? "" : ` <-- ${entry.phase.toUpperCase()}`; + console.log(`[diag] ${entry.step.padEnd(28)} ${entry.elapsedMs}ms${suffix}`); } console.log(`[diag] report: ${outputPath}`); } diff --git a/scripts/test-windows-wgc-helper.mjs b/scripts/test-windows-wgc-helper.mjs index c6c69441e7..849bbd6e9e 100644 --- a/scripts/test-windows-wgc-helper.mjs +++ b/scripts/test-windows-wgc-helper.mjs @@ -35,18 +35,47 @@ const WITH_SOFTWARE_FALLBACK = const INJECT_DEFAULT_SINK_WRITER_FAILURE_ENV = "OPENSCREEN_WGC_TEST_INJECT_DEFAULT_SINK_WRITER_FAILURE_ONCE"; const INJECTION_MARKER = "TEST-ONLY: Injected default MFCreateSinkWriterFromURL failure"; +const STALL_READBACK_ENV = "OPENSCREEN_WGC_TEST_STALL_READBACK_MS"; +/** + * Reproduces issue #252 on ordinary hardware: holds the frame lock across a + * stall the way a wedged GPU readback does. Before the fix the helper hung + * forever with no `[stop-timing]` output at all; it must now always exit. + */ +const WITH_STALLED_READBACK = + process.env.OPENSCREEN_WGC_TEST_STALL_READBACK === "true" || + process.argv.includes("--stall-readback"); +const STALL_READBACK_MS = Number(process.env[STALL_READBACK_ENV] ?? 60_000); +const STOP_BUDGET_ENV = "OPENSCREEN_WGC_STOP_BUDGET_MS"; +/** + * The helper's global shutdown ceiling, pinned into its environment below so + * the harness and the helper cannot drift apart. It matters because the + * encoder-finalize step is the one allowed to spend the whole ceiling — issue + * #34 exists because a long software-encoder finalize legitimately takes + * seconds — so a limit below it would kill a helper that was still working and + * report it as the #252 hang. + */ +const STOP_BUDGET_MS = Number(process.env[STOP_BUDGET_ENV] ?? 50_000); +/** Past the helper's own ceiling it never ended itself, which IS issue #252. */ +const STOP_HANG_LIMIT_MS = STOP_BUDGET_MS + 15_000; +/** A healthy stop is well under a second. */ +const STOP_LATENCY_BUDGET_MS = 15_000; if (WITH_SOFTWARE_ENCODER && WITH_SOFTWARE_FALLBACK) { throw new Error("--software-encoder and --software-fallback are mutually exclusive"); } -function runHelper(config, { injectDefaultSinkWriterFailure = false } = {}) { +function runHelper(config, { injectDefaultSinkWriterFailure = false, stallReadbackMs = 0 } = {}) { return new Promise((resolve, reject) => { const env = { ...process.env }; delete env[INJECT_DEFAULT_SINK_WRITER_FAILURE_ENV]; + delete env[STALL_READBACK_ENV]; + env[STOP_BUDGET_ENV] = String(STOP_BUDGET_MS); if (injectDefaultSinkWriterFailure) { env[INJECT_DEFAULT_SINK_WRITER_FAILURE_ENV] = "1"; } + if (stallReadbackMs > 0) { + env[STALL_READBACK_ENV] = String(stallReadbackMs); + } const child = spawn(HELPER_PATH, [JSON.stringify(config)], { env, stdio: ["pipe", "pipe", "pipe"], @@ -56,12 +85,23 @@ function runHelper(config, { injectDefaultSinkWriterFailure = false } = {}) { let stdout = ""; let stderr = ""; let stopTimer = null; + let stopSentAt = null; + let stopHung = false; + let hangTimer = null; const scheduleStop = () => { if (stopTimer) { return; } stopTimer = setTimeout(() => { + stopSentAt = Date.now(); child.stdin.write("stop\n"); + // The whole point of issues #115 and #252 was a helper that never + // came back from `stop`. Without a bound here the harness inherits + // the hang instead of reporting it. + hangTimer = setTimeout(() => { + stopHung = true; + child.kill(); + }, STOP_HANG_LIMIT_MS); }, DURATION_MS); }; const fallbackTimer = setTimeout(scheduleStop, 15_000); @@ -81,11 +121,57 @@ function runHelper(config, { injectDefaultSinkWriterFailure = false } = {}) { if (stopTimer) { clearTimeout(stopTimer); } - resolve({ code, stdout, stderr }); + if (hangTimer) { + clearTimeout(hangTimer); + } + resolve({ + code, + stdout, + stderr, + stopHung, + stopLatencyMs: stopSentAt === null ? null : Date.now() - stopSentAt, + }); }); }); } +/** + * Every `[stop-timing]` step the helper *finished*, in order. + * + * `phase=begin` is the same step announced on entry, so counting both listed + * every step twice. `phase=abandoned` is kept: that step did end, just badly. + */ +function readStopTimingSteps(stderr) { + return [...stderr.matchAll(/\[stop-timing\]\s+step=(\S+)\s+elapsed_ms=\d+(?:\s+phase=(\S+))?/g)] + .filter((match) => match[2] !== "begin") + .map((match) => match[1]); +} + +function assertStopWasClean(result) { + if (result.stopHung) { + throw new Error( + `Helper did not exit within ${STOP_HANG_LIMIT_MS}ms of "stop" (issue #252). ` + + `stop-timing steps seen: ${readStopTimingSteps(result.stderr).join(", ") || "none"}`, + ); + } + const steps = readStopTimingSteps(result.stderr); + if (!steps.includes("command-received")) { + throw new Error( + 'Helper never acknowledged the stop command ("[stop-timing] step=command-received").', + ); + } + if (steps.includes("wgc-session-close") === false) { + throw new Error( + `Helper stopped without completing its shutdown sequence. Steps: ${steps.join(", ")}`, + ); + } + if (result.stopLatencyMs !== null && result.stopLatencyMs > STOP_LATENCY_BUDGET_MS) { + throw new Error( + `Stop took ${result.stopLatencyMs}ms, over the ${STOP_LATENCY_BUDGET_MS}ms budget.`, + ); + } +} + function startFixtureWindow() { return new Promise((resolve, reject) => { const child = spawn("mspaint.exe", [], { @@ -294,12 +380,44 @@ let result; try { result = await runHelper(config, { injectDefaultSinkWriterFailure: WITH_SOFTWARE_FALLBACK, + stallReadbackMs: WITH_STALLED_READBACK ? STALL_READBACK_MS : 0, }); } finally { if (fixtureWindow) { fixtureWindow.child.kill(); } } + +// The regression check for issue #252. With the frame lock deliberately wedged +// there is no usable recording to assert on -- what matters is only that the +// helper still noticed the stop and still died, naming the step it died in. +if (WITH_STALLED_READBACK) { + if (result.stopHung) { + throw new Error( + `Helper survived ${STOP_HANG_LIMIT_MS}ms past "stop" with a stalled readback. ` + + "Its shutdown watchdog did not fire (issue #252).", + ); + } + const steps = readStopTimingSteps(result.stderr); + if (!steps.includes("command-received")) { + throw new Error(`Helper never acknowledged "stop". Steps seen: ${steps.join(", ") || "none"}`); + } + if (!/phase=abandoned/.test(result.stderr)) { + throw new Error( + `Helper exited without reporting an abandoned shutdown step. stderr:\n${result.stderr}`, + ); + } + console.log("WGC helper stalled-readback stop check passed", { + stopLatencyMs: result.stopLatencyMs, + steps, + abandoned: result.stderr.match(/step=(\S+)\s+elapsed_ms=\d+\s+phase=abandoned/)?.[1] ?? null, + }); + fs.rmSync(outputPath, { force: true }); + process.exit(0); +} + +assertStopWasClean(result); + if (result.code !== 0) { if ( WITH_WEBCAM && @@ -451,6 +569,8 @@ console.log( JSON.stringify( { success: true, + stopLatencyMs: result.stopLatencyMs, + stopTimingSteps: readStopTimingSteps(result.stderr), outputPath, webcamOutputPath, bytes: fs.statSync(outputPath).size, diff --git a/src/hooks/useScreenRecorder.nativeStopFailure.test.tsx b/src/hooks/useScreenRecorder.nativeStopFailure.test.tsx new file mode 100644 index 0000000000..52c786be4d --- /dev/null +++ b/src/hooks/useScreenRecorder.nativeStopFailure.test.tsx @@ -0,0 +1,139 @@ +import { act, renderHook } from "@testing-library/react"; +import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; + +vi.mock("@/contexts/I18nContext", () => ({ + useScopedT: () => (key: string) => key, +})); + +vi.mock("sonner", () => ({ + toast: { error: vi.fn(), success: vi.fn(), info: vi.fn(), warning: vi.fn() }, +})); + +import { toast } from "sonner"; +import { useScreenRecorder } from "./useScreenRecorder"; + +type ElectronAPI = Window["electronAPI"]; + +const SOURCE = { id: "screen:0:0", name: "Screen 1", display_id: "1", thumbnail: "" }; + +let api: Record>; + +/** + * Only what the native-Windows record/stop round trip touches. Anything the + * hook reaches for that is not stubbed will throw loudly, which is the point. + */ +function stubElectronAPI(overrides: Record = {}) { + api = { + getRecordingPrefs: vi.fn(async () => null), + getPlatform: vi.fn(() => "win32"), + getSelectedSource: vi.fn(async () => SOURCE), + isNativeWindowsCaptureAvailable: vi.fn(async () => ({ success: true, available: true })), + startNativeWindowsRecording: vi.fn(async () => ({ success: true, recordingId: 7 })), + stopNativeWindowsRecording: vi.fn(async () => ({ success: true })), + showCountdownOverlay: vi.fn(async () => true), + setCountdownOverlayValue: vi.fn(async () => true), + hideCountdownOverlay: vi.fn(async () => true), + setCurrentRecordingSession: vi.fn(async () => undefined), + setCurrentVideoPath: vi.fn(async () => undefined), + switchToEditor: vi.fn(async () => undefined), + }; + window.electronAPI = { ...api, ...overrides } as unknown as ElectronAPI; +} + +type RecorderView = { result: { current: ReturnType } }; + +/** + * Runs every pending timer and microtask. `waitFor` is unusable here: it polls + * on the same timers this suite fakes, so it can only ever time out. + */ +async function settle(ms = 0) { + await act(async () => { + await vi.advanceTimersByTimeAsync(ms); + }); +} + +/** Drives the hook through the 3s countdown into an active native recording. */ +async function startNativeRecording(view: RecorderView) { + await act(async () => { + view.result.current.toggleRecording(); + }); + await settle(3_500); + expect(view.result.current.recording).toBe(true); +} + +async function pressStop(view: RecorderView) { + await act(async () => { + view.result.current.toggleRecording(); + }); + await settle(); +} + +beforeEach(() => { + vi.useFakeTimers(); + stubElectronAPI(); +}); + +afterEach(() => { + vi.useRealTimers(); + vi.restoreAllMocks(); +}); + +describe("useScreenRecorder native Windows stop failure", () => { + /** + * Issue #252's second symptom. When the helper wedges, the main process + * releases its handle in a `finally` regardless, so a renderer that kept its + * own handle left the HUD showing a stop button that could only ever send a + * second stop -- answered with "Native Windows capture is not running." + */ + it("leaves the recorder able to start again after a failed stop", async () => { + api.stopNativeWindowsRecording.mockResolvedValue({ + success: false, + reason: "stop-timeout", + error: "Timed out waiting for native Windows capture to stop.", + }); + + const view = renderHook(() => useScreenRecorder()); + await startNativeRecording(view); + await pressStop(view); + + expect(view.result.current.recording).toBe(false); + expect(toast.error).toHaveBeenCalledWith( + "Timed out waiting for native Windows capture to stop.", + ); + expect(view.result.current.saving).toBe(false); + // The failure must not be mistaken for a successful recording. + expect(api.switchToEditor).not.toHaveBeenCalled(); + + // The next press starts a NEW recording instead of re-sending a stop. + api.stopNativeWindowsRecording.mockClear(); + await startNativeRecording(view); + + expect(api.startNativeWindowsRecording).toHaveBeenCalledTimes(2); + expect(api.stopNativeWindowsRecording).not.toHaveBeenCalled(); + }); + + it("leaves the recorder able to start again when the stop IPC throws", async () => { + api.stopNativeWindowsRecording.mockRejectedValue(new Error("IPC channel closed")); + + const view = renderHook(() => useScreenRecorder()); + await startNativeRecording(view); + await pressStop(view); + + expect(view.result.current.recording).toBe(false); + expect(toast.error).toHaveBeenCalledWith("IPC channel closed"); + }); + + it("still opens the editor when the stop succeeds", async () => { + api.stopNativeWindowsRecording.mockResolvedValue({ + success: true, + path: "C:\\rec\\a.mp4", + }); + + const view = renderHook(() => useScreenRecorder()); + await startNativeRecording(view); + await pressStop(view); + + expect(api.switchToEditor).toHaveBeenCalled(); + expect(view.result.current.recording).toBe(false); + }); +}); diff --git a/src/hooks/useScreenRecorder.ts b/src/hooks/useScreenRecorder.ts index 7a35fca773..a40fa3a31f 100644 --- a/src/hooks/useScreenRecorder.ts +++ b/src/hooks/useScreenRecorder.ts @@ -578,7 +578,14 @@ export function useScreenRecorder(): UseScreenRecorderReturn { if (!result.success) { console.error("Failed to stop native Windows recording:", result.error); toast.error(result.error ?? "Failed to stop native Windows recording"); - activeNativeRecording.finalizing = false; + // Clear anyway. The main process releases its helper handle + // unconditionally, so holding on here left the two sides + // disagreeing about whether anything was recording: the HUD kept + // showing a stop button, and pressing it sent a second stop that + // came back "Native Windows capture is not running." (issue #252). + // The recording is already lost either way -- what the user needs + // is to be able to start a new one. + clearNativeRecordingState(); return true; } @@ -596,7 +603,7 @@ export function useScreenRecorder(): UseScreenRecorderReturn { toast.error( error instanceof Error ? error.message : "Failed to save native Windows recording", ); - activeNativeRecording.finalizing = false; + clearNativeRecordingState(); return true; } finally { if (discardRecordingId.current === activeNativeRecording.recordingId) { @@ -660,7 +667,11 @@ export function useScreenRecorder(): UseScreenRecorderReturn { if (!result.success) { console.error("Failed to stop native macOS recording:", result.error); toast.error(result.error ?? "Failed to stop native macOS recording"); - activeNativeRecording.finalizing = false; + // See the Windows finalizer: the main process has already + // released its helper handle, so keeping ours leaves the HUD + // stuck in a recording state the app can never be stopped out + // of (issue #252). + clearNativeRecordingState(); return true; } @@ -702,7 +713,7 @@ export function useScreenRecorder(): UseScreenRecorderReturn { toast.error( error instanceof Error ? error.message : "Failed to save native macOS recording", ); - activeNativeRecording.finalizing = false; + clearNativeRecordingState(); return true; } finally { // A webcam stream that wasn't folded into a saved session has to be closed @@ -774,7 +785,11 @@ export function useScreenRecorder(): UseScreenRecorderReturn { if (!result.success) { console.error("Failed to stop native Linux recording:", result.error); toast.error(result.error ?? "Failed to stop native Linux recording"); - activeNativeRecording.finalizing = false; + // See the Windows finalizer: the main process has already + // released its helper handle, so keeping ours leaves the HUD + // stuck in a recording state the app can never be stopped out + // of (issue #252). + clearNativeRecordingState(); return true; } @@ -816,7 +831,7 @@ export function useScreenRecorder(): UseScreenRecorderReturn { toast.error( error instanceof Error ? error.message : "Failed to save native Linux recording", ); - activeNativeRecording.finalizing = false; + clearNativeRecordingState(); return true; } finally { // A webcam stream that wasn't folded into a saved session has to be closed diff --git a/technical-documentation/architecture/recording.md b/technical-documentation/architecture/recording.md index 96e99824af..01337f210b 100644 --- a/technical-documentation/architecture/recording.md +++ b/technical-documentation/architecture/recording.md @@ -36,6 +36,8 @@ The division is an invariant: the native helper owns capture, timing, and encodi A native session is a child process boundary. Electron starts the platform helper with one structured JSON request and sends runtime commands on stdin; `stop` finalizes the output. The helper emits newline-delimited JSON events on stdout. The shared shape contains `schemaVersion`, `recordingId`, a `source` (display or window and its bounds), `video`, `audio`, optional `webcam`, optional cursor mode, and `outputs` paths. The helper reports `ready`, `recording-started`, warnings, errors, and `recording-stopped` events. Windows accepts legacy textual start/stop messages during compatibility handling; the structured events are the reference contract. +Stopping is the part of that boundary that has broken repeatedly (issues #34, #115, #252), so the Windows helper is explicit about it. On stderr it prints `[stop-timing] step=command-received` the moment it reads `stop`, then a `phase=begin` and a completion line per shutdown step; a step that never completes gets `phase=abandoned` and the process force-exits with code 3, plus a `stop-timeout` event on stdout naming the step. The distinction the older instrumentation could not make — "the helper never saw the stop" versus "it saw the stop and wedged" — is the first line of that log. Electron keeps a listener on the helper for the whole recording (`attachNativeWindowsCaptureOutputDrain`) so those lines reach the diagnostics bundle rather than being dropped between start and stop. + | Contract field or behavior | Windows | macOS | Linux | | --- | --- | --- | --- | | Schema | `schemaVersion: 2` | `schemaVersion: 1` | `schemaVersion: 1` | @@ -66,7 +68,7 @@ Cursor samples are persisted as cursor telemetry rather than baked into editable ## Known gaps - A window with odd client dimensions can produce black video: H.264 encoding requires even dimensions (`electron/native/wgc-capture/src/wgc_session.cpp:38`). -- Stopping a recording can hang on the software encoder path (`electron/native/wgc-capture/src/main.cpp:755`). +- The Windows helper's frame lock (`electron/native/wgc-capture/src/main.cpp`) is still held across blocking, uninterruptible D3D11 work: the WGC callback's `CopyResource`, and the video writer's `Map(D3D11_MAP_READ)` readback in `mf_encoder.cpp`. A driver that stalls inside either one still costs the recording. What no longer happens is a hang: stop detection runs on `CaptureControl::stopMutex`, which no frame thread ever touches, and a shutdown watchdog force-exits the helper when a step overruns its budget, naming the step it died in. Each step gets `OPENSCREEN_WGC_STEP_BUDGET_MS` (8s by default) and that is the bound which normally fires; the whole shutdown is capped by `OPENSCREEN_WGC_STOP_BUDGET_MS` (50s by default), which the encoder-finalize step alone is allowed to spend in full because a long software-encoder finalize legitimately takes seconds (issue #34). Getting the readback out of the lock, and picking the D3D adapter that actually drives the captured monitor instead of adapter 0, are the outstanding fixes (issue #252). - Linux/Wayland can produce no usable frames on the `getDisplayMedia` fallback because Chromium initializes Vulkan against the Ozone Wayland backend. The PipeWire helper path is unaffected. - On Linux the compositor's source picker appears on every recording. That is deliberate — see "Why Linux sends no source identity" — but it is an interruption, and there is currently no way to reuse a previous choice without also making it impossible to change. - Holding a portal session across the countdown means the compositor's "screen is being shared" indicator is up before recording begins. That is honest — access really has been granted — but the user can click it to revoke, or close the window they picked. The helper's exit surfaces as a rejected `waitUntilSourceSelected`; the session is not yet subscribed to the portal's `Session::Closed` signal, so a revocation is reported as a failed start rather than a specific message.