diff --git a/deps/cloudxr/webxr_client/helpers/react/CloudXRComponent.tsx b/deps/cloudxr/webxr_client/helpers/react/CloudXRComponent.tsx index 9a7b184a36..3526eccadc 100644 --- a/deps/cloudxr/webxr_client/helpers/react/CloudXRComponent.tsx +++ b/deps/cloudxr/webxr_client/helpers/react/CloudXRComponent.tsx @@ -74,6 +74,14 @@ const WARMUP_COMPLETE_LOG_PATTERN = // override via the streamAttachTimeoutMs prop, not by lowering this default. const STREAM_ATTACH_BASE_TIMEOUT_MS = 120000; // 2 minutes +// Debug log for each keep-alive "idle" frame the server sends while no OpenXR app is submitting +// frames. Not currently emitted by CloudXR.js: until a release that emits it is consumed, and the +// session logLevel includes Debug, none of the idle-frame handling below runs. +const IDLE_FRAME_LOG_MESSAGE = 'Received idle frame'; +// Idle frames are sent about every 250 ms; this long with none means real frames have started +// (or the stream stalled), so the warm-up watchdogs resume. +const IDLE_FRAMES_QUIET_MS = 1000; + // Defaults for the warmupBeginTimeoutMs/warmupEndTimeoutMs props below. Both shorter than // STREAM_ATTACH_BASE_TIMEOUT_MS and, unlike it, neither grows per reconnect attempt (see // armWarmupBeginTimer/armWarmupEndTimer): once the stream has attached at all, decoder warm-up @@ -105,6 +113,20 @@ export interface WarmupStatus { completed: boolean; } +/** + * Server keep-alive ("idle") frame status for the current connection attempt, derived from the + * SDK's 'Received idle frame' debug log (see IDLE_FRAME_LOG_MESSAGE). Idle frames mean the server + * is alive but no OpenXR app is submitting frames. Reset at the start of each connection attempt. + */ +export interface IdleStatus { + /** Idle frames received so far this connection attempt. */ + framesSeen: number; + /** `Date.now()` when this status last changed. */ + timestamp: number; + /** True while idle frames keep arriving; false once none has arrived for IDLE_FRAMES_QUIET_MS. */ + active: boolean; +} + /** * Props for the CloudXRComponent. */ @@ -217,6 +239,13 @@ interface CloudXRComponentProps { */ onWarmupStatus?: (status: WarmupStatus) => void; + /** + * Callback fired on each idle frame (active: true) and when idle frames stop (active: false). + * Parsed from an SDK Debug log, so it only fires when the SDK emits that log and the session + * log level includes Debug - see {@link IdleStatus}. + */ + onIdleStatus?: (status: IdleStatus) => void; + /** * Pre-stream network test. When set, the SDK measures link quality before streaming * starts. Leave undefined to skip the test entirely (the IsaacTeleop default): a teleop @@ -279,6 +308,7 @@ export default function CloudXRComponent({ onNetworkPerformanceMetrics, onLog, onWarmupStatus, + onIdleStatus, streamTest, onStreamTestStarted, onStreamTestStopped, @@ -306,6 +336,17 @@ export default function CloudXRComponent({ const streamAttachTimerRef = useRef | null>(null); const warmupBeginTimerRef = useRef | null>(null); const warmupEndTimerRef = useRef | null>(null); + // Fires IDLE_FRAMES_QUIET_MS after the last idle-frame log; see noteIdleFrame. + const idleQuietTimerRef = useRef | null>(null); + // True from an idle-frame log until idleQuietTimerRef fires or the attempt ends. + const idleFramesActiveRef = useRef(false); + const idleStatusRef = useRef({ framesSeen: 0, timestamp: 0, active: false }); + // Per attempt: a RenderFramerate tick showed real, pose-backed video, so warm-up is over even if + // the SDK never logged its completion line (a stream that starts warmed up). + const realVideoSeenRef = useRef(false); + // Latest onIdleStatus, so idle bookkeeping that outlives a render never calls a stale prop. + const onIdleStatusRef = useRef(onIdleStatus); + onIdleStatusRef.current = onIdleStatus; /** Clears the attach and both warm-up watchdogs - the three fire a synthetic error if left * pending past an attempt that's already been handled some other way (success, a real error, @@ -457,6 +498,71 @@ export default function CloudXRComponent({ [warmupEndBaseTimeoutMs] ); + /** + * Ends the idle state and reports `active: false`. Called when the quiet period elapses, real + * video arrives, or the attempt ends (stream stop, WebXR session end) - not from + * clearStartupTimers, which also runs on config-change re-registration and unmount. + */ + const endIdle = useCallback(() => { + if (idleQuietTimerRef.current !== null) { + clearTimeout(idleQuietTimerRef.current); + idleQuietTimerRef.current = null; + } + if (!idleFramesActiveRef.current) return; + idleFramesActiveRef.current = false; + idleStatusRef.current = { ...idleStatusRef.current, timestamp: Date.now(), active: false }; + onIdleStatusRef.current?.(idleStatusRef.current); + }, []); + + /** + * Handles one idle-frame log: the server is alive but no app is submitting frames, so warm-up + * can't be stuck yet. Cancels the warm-up watchdogs and (re)starts a quiet-period timer; when no + * idle frame has arrived for IDLE_FRAMES_QUIET_MS, resumes the watchdog for whichever warm-up + * phase is still pending. Idle frames also reach the decoder as warm-up frames, so without this + * the end timer would start on them. + */ + const noteIdleFrame = useCallback(() => { + idleFramesActiveRef.current = true; + idleStatusRef.current = { + framesSeen: idleStatusRef.current.framesSeen + 1, + timestamp: Date.now(), + active: true, + }; + onIdleStatusRef.current?.(idleStatusRef.current); + if (warmupBeginTimerRef.current !== null) { + clearTimeout(warmupBeginTimerRef.current); + warmupBeginTimerRef.current = null; + } + if (warmupEndTimerRef.current !== null) { + clearTimeout(warmupEndTimerRef.current); + warmupEndTimerRef.current = null; + } + if (idleQuietTimerRef.current !== null) { + clearTimeout(idleQuietTimerRef.current); + } + idleQuietTimerRef.current = setTimeout(() => { + endIdle(); + const cxrSession = cxrSessionRef.current; + if (!cxrSession || warmupStatusRef.current.completed || realVideoSeenRef.current) return; + if (warmupBegunRef.current) { + armWarmupEndTimer(cxrSession); + } else { + armWarmupBeginTimer(cxrSession); + } + }, IDLE_FRAMES_QUIET_MS); + }, [armWarmupBeginTimer, armWarmupEndTimer, endIdle]); + + // The quiet timer outlives clearStartupTimers; drop it on unmount without reporting. + useEffect( + () => () => { + if (idleQuietTimerRef.current !== null) { + clearTimeout(idleQuietTimerRef.current); + idleQuietTimerRef.current = null; + } + }, + [] + ); + // Metrics trackers for averaging performance metrics // Use prop values if provided, otherwise use defaults const renderFpsTrackerRef = useRef( @@ -658,6 +764,14 @@ export default function CloudXRComponent({ : console.info; printFn(`[CloudXR] ${message}`); + if (message === IDLE_FRAME_LOG_MESSAGE) { + // Only once streaming: before that, the attach timer owns the deadline. + if (!headless && cxrSessionRef.current && hasStreamStartedRef.current) { + noteIdleFrame(); + } + continue; + } + const progressMatch = message.match(WARMUP_PROGRESS_LOG_PATTERN); const completeMatch = message.match(WARMUP_COMPLETE_LOG_PATTERN); if ((progressMatch || completeMatch) && !warmupBegunRef.current) { @@ -674,7 +788,13 @@ export default function CloudXRComponent({ // completion either (onMetrics' RenderFramerate never fires). A progress log // without a matching complete log shouldn't be possible when nothing ever // begins watching for it, but skip arming regardless, for the same reason. - if (!completeMatch && !headless && cxrSessionRef.current) { + // Not while idle frames are arriving: noteIdleFrame arms it once they stop. + if ( + !completeMatch && + !headless && + cxrSessionRef.current && + !idleFramesActiveRef.current + ) { armWarmupEndTimer(cxrSessionRef.current); } } @@ -695,6 +815,8 @@ export default function CloudXRComponent({ clearTimeout(warmupEndTimerRef.current); warmupEndTimerRef.current = null; } + // A pose-backed frame rendered, so the server is no longer sending idle frames. + endIdle(); onWarmupStatus?.(warmupStatusRef.current); } } @@ -765,6 +887,7 @@ export default function CloudXRComponent({ // dispatch through this same delegate) means we're no longer "waiting to attach" or // "warming up" - clear any pending timer so it can't fire again after this attempt // has already been handled. + endIdle(); clearStartupTimers(); if (error) { // Display user-friendly error message with error code if available @@ -831,6 +954,10 @@ export default function CloudXRComponent({ clearTimeout(warmupEndTimerRef.current); warmupEndTimerRef.current = null; } + // Real video also ends any idle period, and keeps the idle quiet timer from + // re-arming a watchdog afterwards. + realVideoSeenRef.current = true; + endIdle(); reconnectAttemptRef.current = 0; } if (onRenderPerformanceMetrics) { @@ -946,6 +1073,8 @@ export default function CloudXRComponent({ cxrSessionRef.current = cxrSession; hasStreamStartedRef.current = false; warmupStatusRef.current = { framesSeen: 0, timestamp: 0, completed: false }; + idleStatusRef.current = { framesSeen: 0, timestamp: 0, active: false }; + realVideoSeenRef.current = false; warmupBegunRef.current = false; // Notify parent that session is ready @@ -997,6 +1126,7 @@ export default function CloudXRComponent({ clearTimeout(reconnectTimerRef.current); reconnectTimerRef.current = null; } + endIdle(); clearStartupTimers(); if (cxrSessionRef.current) { cxrSessionRef.current.disconnect(); diff --git a/deps/cloudxr/webxr_client/tests/mock/MockCloudXR.ts b/deps/cloudxr/webxr_client/tests/mock/MockCloudXR.ts index 78c5e6a915..02b03ea18c 100644 --- a/deps/cloudxr/webxr_client/tests/mock/MockCloudXR.ts +++ b/deps/cloudxr/webxr_client/tests/mock/MockCloudXR.ts @@ -53,6 +53,8 @@ const WARMUP_LOG_INTERVAL = 10; // setWarmupFirstStatusFrame() so a test can get fast confirmation that warm-up has begun without // waiting for 10 real rendered frames. const DEFAULT_WARMUP_FIRST_STATUS_FRAME = WARMUP_LOG_INTERVAL; +// The server sends a keep-alive idle frame about this often while no app is submitting frames. +const IDLE_FRAME_INTERVAL_MS = 250; /** * Sentinel `gl` value for {@link CloudXR.SessionOptions.gl}: a MockCloudXR constructed with this @@ -116,6 +118,10 @@ export class MockCloudXR implements CloudXR.Session { private connectTimer: ReturnType | null = null; private streamTestTimer: ReturnType | null = null; private networkMetricsTimer: ReturnType | null = null; + private idleFrameTimer: ReturnType | null = null; + // Opt-in (setEmitRenderFramerate): the real SDK reports RenderFramerate on each rendered, + // pose-backed frame, which CloudXRComponent treats as "real video is flowing". + private emitRenderFramerate = false; private frameCount = 0; private lastRenderTimestamp: DOMHighResTimeStamp | null = null; // Monotonic per-render() counter, reset to 0 at the top of each connect()'s Connected @@ -302,11 +308,12 @@ export class MockCloudXR implements CloudXR.Session { this.processPendingFrame(); } - if (this.warmupSimulationEnabled && !this.warmupComplete) { + if ((this.warmupSimulationEnabled && !this.warmupComplete) || this.idleFrameTimer !== null) { // Decoder warm-up frames carry no pose-backed video to show - see processPendingFrame, // which counts warm-up frames (from a frame videoFrameReceived() queued) and flips this // flag. Gated on warmupSimulationEnabled too: a demo that never opted into warm-up // simulation (see that field's doc comment) should render normally, not black forever. + // Idle frames (startIdleFrames) likewise carry no pose-backed video. if (this.options.gl !== NullWebGLContext) { const gl = this.options.gl; this.delegates.onWebGLStateChangeBegin?.(); @@ -354,6 +361,17 @@ export class MockCloudXR implements CloudXR.Session { }, CloudXR.MetricsCadence.PerFrame ); + if (this.emitRenderFramerate) { + this.delegates.onMetrics?.( + { [CloudXR.MetricsName.RenderFramerate]: this.estimateFps(timestamp) }, + CloudXR.MetricsCadence.PerRender + ); + } + } + + /** Makes render() also report RenderFramerate for each rendered frame; off by default. */ + setEmitRenderFramerate(enabled: boolean): void { + this.emitRenderFramerate = enabled; } sendServerMessage(): void { @@ -484,6 +502,31 @@ export class MockCloudXR implements CloudXR.Session { ); } + /** + * Emulates the server's keep-alive frames sent while no app is submitting frames: logs the Debug + * line 'Received idle frame' immediately, then every IDLE_FRAME_INTERVAL_MS, until + * stopIdleFrames(), disconnect or failure. Only logs - it does not feed warm-up frames; call + * videoFrameReceived(0) for those, as the real stream also counts idle frames as warm-up. + * No-op unless Connected. Real CloudXR.js does not currently emit this log. + */ + startIdleFrames(): void { + if (this.sessionState !== CloudXR.SessionState.Connected) { + return; + } + this.stopIdleFrames(); + const emit = () => this.log(CloudXR.LogLevel.Debug, 'Received idle frame'); + emit(); + this.idleFrameTimer = setInterval(emit, IDLE_FRAME_INTERVAL_MS); + } + + /** Stops the emulation started by startIdleFrames(). */ + stopIdleFrames(): void { + if (this.idleFrameTimer !== null) { + clearInterval(this.idleFrameTimer); + this.idleFrameTimer = null; + } + } + /** Delivers `data` through `onServerMessageReceived`, as if the server had sent it. */ sendFakeServerMessage(data: Uint8Array): void { this.delegates.onServerMessageReceived?.(data); @@ -573,6 +616,7 @@ export class MockCloudXR implements CloudXR.Session { clearInterval(this.networkMetricsTimer); this.networkMetricsTimer = null; } + this.stopIdleFrames(); } private emitNetworkMetrics(): void { diff --git a/deps/cloudxr/webxr_client/tests/mock/StreamAttachTimeoutTest.tsx b/deps/cloudxr/webxr_client/tests/mock/StreamAttachTimeoutTest.tsx index 2f17267ced..a5ff150800 100644 --- a/deps/cloudxr/webxr_client/tests/mock/StreamAttachTimeoutTest.tsx +++ b/deps/cloudxr/webxr_client/tests/mock/StreamAttachTimeoutTest.tsx @@ -18,16 +18,18 @@ /** * StreamAttachTimeoutTest - mounts the real CloudXRComponent against MockCloudXR (see * CloudXRComponentTest.tsx's header for the general approach) to exercise its three - * connection-phase deadlines back-to-back in one continuous 4-attempt retry sequence: + * connection-phase deadlines back-to-back in one continuous 5-attempt retry sequence: * streamAttachTimeoutMs (attempt 1: stream never attaches), warmupBeginTimeoutMs (attempt 2: * attaches but no warm-up log ever arrives), warmupEndTimeoutMs (attempt 3: warm-up begins but - * never completes), then a normal attempt 4 proving none of the timers fire once attach and - * warm-up genuinely succeed. Each attempt drives MockCloudXR via setWarmupTotalFrames() + + * never completes), attempt 4 (keep-alive idle frames running when the session fails: the idle + * status must be reported inactive before the retry), then a normal attempt 5 that rides out idle + * frames for 3x the warm-up budgets, proving none of the timers fire once attach and warm-up + * genuinely succeed. Each attempt drives MockCloudXR via setWarmupTotalFrames() + * videoFrameReceived() (test-driven, no background clock) on a schedule relative to Connected. * * Also asserts a real diagnostic signal: streaming/render metrics (MetricsCadence.PerFrame) * must not fire during a stalled warm-up (attempt 3) and must fire once warm-up completes - * (attempt 4) - a frozen frame count while the session reads Connected is what a stuck warm-up + * (attempt 5) - a frozen frame count while the session reads Connected is what a stuck warm-up * looks like from the outside, and MockCloudXR.render() reproduces that. * * Click the button (or press "S") to run it. @@ -39,7 +41,7 @@ import { useCallback, useEffect, useRef, useState } from 'react'; import ReactDOM from 'react-dom/client'; import { loadIWERIfNeeded } from '@helpers/LoadIWER'; -import CloudXRComponent, { WarmupStatus } from '@helpers/react/CloudXRComponent'; +import CloudXRComponent, { IdleStatus, WarmupStatus } from '@helpers/react/CloudXRComponent'; import type { CloudXRConfig } from '@helpers/utils'; import type { MockCloudXR } from './MockCloudXR'; @@ -73,6 +75,18 @@ interface AttemptConfig { warmupTotalFrames?: number | null; /** How many no-arg videoFrameReceived() calls to make, at FRAME_CALL_DELAYS_MS after Connected. */ frameCallCount: number; + /** + * Idle-frame scenario: emulate the server's keep-alive frames from Connected until this many + * ms later, with one warm-up frame arriving while they run (the real stream counts idle frames + * as warm-up), then one pose-backed frame at `completeWarmupAtMs` to finish warm-up. + */ + idleFramesForMs?: number; + /** With idleFramesForMs: feed a warm-up frame at the start and a pose-backed one at this time. */ + completeWarmupAtMs?: number; + /** With idleFramesForMs: fail the session this many ms after Connected, mid-idle. */ + failAtMs?: number; + /** Report RenderFramerate from each rendered frame (real video, without a warm-up log). */ + emitRenderFramerate?: boolean; } // Per-attempt mock configuration - see the module doc comment for what each attempt tests. @@ -83,7 +97,23 @@ const ATTEMPT_CONFIGS: AttemptConfig[] = [ // emits streaming metrics, which trips the "no metrics during warm-up" check below. { connectWaitMs: 100, warmupTotalFrames: null, frameCallCount: 0 }, { connectWaitMs: 100, warmupTotalFrames: null, frameCallCount: 1 }, // 3: warm-up begins, then stalls -> warmup-end timeout - { connectWaitMs: 100, warmupTotalFrames: 2, frameCallCount: 3 }, // 4: warm-up begins and completes fast -> success + // 4: idle frames running when the session fails -> idle must be reported inactive before the retry. + { + connectWaitMs: 100, + warmupTotalFrames: null, + frameCallCount: 0, + idleFramesForMs: 5000, + failAtMs: 700, + }, + // 5: idle frames run for 3x the 500ms warm-up budgets, with warm-up frames among them, then stop; + // warm-up completes after the watchdog resumes but within its budget -> success, no timeout. + { + connectWaitMs: 100, + warmupTotalFrames: 2, + frameCallCount: 0, + idleFramesForMs: 1500, + completeWarmupAtMs: 2400, + }, ]; const config: CloudXRConfig = { @@ -128,8 +158,16 @@ let activeSession: MockCloudXR | null = null; // fires (see onStatusChange). let attemptConfigQueue: AttemptConfig[] = []; let pendingFrameCallCount = 0; +let pendingIdleConfig: Pick< + AttemptConfig, + 'idleFramesForMs' | 'completeWarmupAtMs' | 'failAtMs' +> | null = null; +// Status and idle events in the order they happened, for ordering assertions. +let timeline: string[] = []; +let streamingMetricsCount = 0; let statusMessages: string[] = []; let warmupStatuses: WarmupStatus[] = []; +let idleStatuses: IdleStatus[] = []; // Set the moment an onStreamingPerformanceMetrics event is observed to fire while warm-up // hadn't completed yet (checked against warmupStatuses at that instant - see onStatusChange's // use of the same pattern) - a real CloudXR.js bug repro, not something this test should ever @@ -145,12 +183,13 @@ function Scene() { config={config} applicationName="StreamAttachTimeoutTest" iceServers={{ iceServers: [{ urls: 'stun:stun.l.google.com:19302' }] }} - reconnect={{ maxAttempts: 3, delayMs: 300 }} + reconnect={{ maxAttempts: 4, delayMs: 300 }} streamAttachTimeoutMs={STREAM_ATTACH_TIMEOUT_MS} warmupBeginTimeoutMs={WARMUP_BEGIN_TIMEOUT_MS} warmupEndTimeoutMs={WARMUP_END_TIMEOUT_MS} onStatusChange={(isConnected, status) => { statusMessages.push(status); + timeline.push(`status:${status}`); appendLog(`[status] connected=${isConnected} ${status}`); if (status === 'Connected') { // Capture the session in this attempt's closure - by the time a later timeout fires @@ -164,13 +203,38 @@ function Scene() { ); } pendingFrameCallCount = 0; + const idleConfig = pendingIdleConfig; + pendingIdleConfig = null; + if (idleConfig && idleConfig.idleFramesForMs !== undefined) { + sessionForThisAttempt?.startIdleFrames(); + setTimeout(() => sessionForThisAttempt?.stopIdleFrames(), idleConfig.idleFramesForMs); + if (idleConfig.completeWarmupAtMs !== undefined) { + setTimeout( + () => sessionForThisAttempt?.videoFrameReceived(0), + FRAME_CALL_DELAYS_MS[0] + ); + setTimeout( + () => sessionForThisAttempt?.videoFrameReceived(1), + idleConfig.completeWarmupAtMs + ); + } + if (idleConfig.failAtMs !== undefined) { + setTimeout(() => sessionForThisAttempt?.triggerFailure(), idleConfig.failAtMs); + } + } } }} onWarmupStatus={status => { warmupStatuses.push(status); appendLog(`[warmup] framesSeen=${status.framesSeen} completed=${status.completed}`); }} + onIdleStatus={status => { + idleStatuses.push(status); + timeline.push(`idle:${status.active}`); + appendLog(`[idle] framesSeen=${status.framesSeen} active=${status.active}`); + }} onStreamingPerformanceMetrics={() => { + streamingMetricsCount++; // warmupStatuses already reflects this instant: onWarmupStatus (pushed synchronously // from MockCloudXR's onLog handling inside render()) always fires before this same // render() call reaches its own onMetrics(PerFrame) emission - see @@ -205,6 +269,17 @@ function Scene() { // armed in the first place. activeSession.setWarmupFirstStatusFrame(1); pendingFrameCallCount = attemptConfig.frameCallCount; + pendingIdleConfig = + attemptConfig.idleFramesForMs !== undefined + ? { + idleFramesForMs: attemptConfig.idleFramesForMs, + completeWarmupAtMs: attemptConfig.completeWarmupAtMs, + failAtMs: attemptConfig.failAtMs, + } + : null; + if (attemptConfig.emitRenderFramerate) { + activeSession.setEmitRenderFramerate(true); + } } } appendLog(`[event] onSessionReady ${session ? 'session' : 'null'}`); @@ -233,26 +308,31 @@ async function runTest(): Promise { appendLog('=== Attempt 1 (1.25s wait, 1s attach budget) should time out on attach, ==='); appendLog('=== attempt 2 (attaches, no frame ever) should time out on warmup begin, ==='); appendLog('=== attempt 3 (warm-up begins, then stalls) should time out on warmup end, ==='); - appendLog('=== attempt 4 (warm-up begins and completes fast) should succeed ==='); + appendLog('=== attempt 4 (session fails while idle frames run) should report idle inactive, ==='); + appendLog('=== attempt 5 (idle frames for 3x the warm-up budgets, then warm-up completes) ==='); + appendLog('=== should succeed: idle frames must not start the warm-up watchdogs ==='); statusMessages = []; warmupStatuses = []; + idleStatuses = []; + timeline = []; streamingMetricsFiredDuringWarmup = false; streamingMetricsFiredAfterWarmupComplete = false; attemptConfigQueue = [...ATTEMPT_CONFIGS]; pendingFrameCallCount = 0; + pendingIdleConfig = null; await startSession(); // Staged waits mirroring the component's own three-phase progression: Connected (attach done) // -> warm-up begun (first onWarmupStatus event) -> warm-up finished (completed: true). Each // condition is monotonic over the whole run's accumulated statusMessages/warmupStatuses, so // this naturally spans attempts 2-3 (which each reach a subset of the stages, then fail and - // retry) and attempt 4 (which reaches all three). Total timeout budget: 1s attach budget fail + // retry) and attempt 5 (which reaches all three). Total timeout budget: 1s attach budget fail // + 300ms retry + 500ms warmup-begin budget fail + 300ms retry + 500ms warmup-end budget fail // + 300ms retry + fast success, plus margin. const reachedConnected = await waitUntil(() => statusMessages.includes('Connected'), 3000); const warmupBegan = await waitUntil(() => warmupStatuses.length > 0, 3000); - const warmupCompleted = await waitUntil(() => warmupStatuses.some(s => s.completed), 3000); - // A little extra time after warm-up completes for attempt 4's render loop to actually emit at + const warmupCompleted = await waitUntil(() => warmupStatuses.some(s => s.completed), 9000); + // A little extra time after warm-up completes for attempt 5's render loop to actually emit at // least one PerFrame metrics tick - proving the pipe resumes once warm-up ends, not just that // it stayed silent throughout (which sawStalledWarmupProgress alone wouldn't distinguish from // a metrics pipe that's permanently broken). @@ -260,22 +340,34 @@ async function runTest(): Promise { const retryCount = statusMessages.filter(s => s.startsWith('Reconnecting')).length; const sawStalledWarmupProgress = warmupStatuses.some(s => !s.completed); + // Attempt 4's idle frames are reported as active, then as inactive once they stop. + // The idle period running when attempt 4 failed was reported inactive before the retry began. + const retry4 = timeline.indexOf('status:Reconnecting (4/4)'); + const idleEndedBeforeRetry = retry4 > 0 && timeline[retry4 - 1] === 'idle:false'; + const reportedIdleFrames = + idleStatuses.some(s => s.active && s.framesSeen > 1) && + idleStatuses[idleStatuses.length - 1]?.active === false; const pass = reachedConnected && warmupBegan && warmupCompleted && - retryCount === 3 && + retryCount === 4 && + idleEndedBeforeRetry && sawStalledWarmupProgress && + reportedIdleFrames && !streamingMetricsFiredDuringWarmup && streamingMetricsFiredAfterWarmupComplete; appendLog( pass ? '[result] PASS: attempt 1 attach-timed-out, attempt 2 warmup-begin-timed-out, ' + - 'attempt 3 warmup-end-timed-out, attempt 4 attached and warmed up, streaming metrics ' + + 'attempt 3 warmup-end-timed-out, attempt 4 reported idle inactive when it failed, attempt 5 ' + + 'rode out idle frames then warmed up, streaming metrics ' + 'stayed frozen throughout warm-up and resumed once it completed' : `[result] FAIL: reachedConnected=${reachedConnected} warmupBegan=${warmupBegan} ` + `warmupCompleted=${warmupCompleted} retryCount=${retryCount} ` + `sawStalledWarmupProgress=${sawStalledWarmupProgress} ` + + `idleEndedBeforeRetry=${idleEndedBeforeRetry} timeline=${JSON.stringify(timeline)} ` + + `reportedIdleFrames=${reportedIdleFrames} idleStatuses=${JSON.stringify(idleStatuses)} ` + `streamingMetricsFiredDuringWarmup=${streamingMetricsFiredDuringWarmup} ` + `streamingMetricsFiredAfterWarmupComplete=${streamingMetricsFiredAfterWarmupComplete} ` + `statusMessages=${JSON.stringify(statusMessages)} warmupStatuses=${JSON.stringify(warmupStatuses)}` @@ -285,6 +377,49 @@ async function runTest(): Promise { store.getState().session?.end(); } +// Scenario ?scenario=real-video-after-idle: idle frames stop, then real video renders with no +// warm-up completion log (a stream that starts warmed up). Idle frames then resume briefly and +// stop with no further video. The idle quiet timer must not re-arm a warm-up watchdog after real +// video was seen, so the session stays Connected well past the watchdog budgets. +async function runRealVideoAfterIdleTest(): Promise { + appendLog('=== idle frames then real video without a warm-up log: no watchdog may fire ==='); + statusMessages = []; + warmupStatuses = []; + idleStatuses = []; + timeline = []; + streamingMetricsCount = 0; + attemptConfigQueue = [ + { connectWaitMs: 100, frameCallCount: 0, idleFramesForMs: 600, emitRenderFramerate: true }, + ]; + pendingFrameCallCount = 0; + pendingIdleConfig = null; + await startSession(); + const connected = await waitUntil(() => statusMessages.includes('Connected'), 3000); + const session = activeSession; + setTimeout(() => session?.startIdleFrames(), 1200); + setTimeout(() => { + session?.stopIdleFrames(); + session?.setEmitRenderFramerate(false); + }, 1700); + // After the second idle burst ends (~1.7 s), 1 s of quiet then the 500 ms begin budget: a wrongly + // re-armed watchdog would have disconnected by about 3.2 s after Connected. + await sleep(5000); + const stayedConnected = !statusMessages.some(s => s.startsWith('Reconnecting') || s === 'Error'); + const sawRealVideo = streamingMetricsCount > 0; + const idleEnded = + idleStatuses.some(s => s.active) && idleStatuses[idleStatuses.length - 1]?.active === false; + const pass = connected && stayedConnected && sawRealVideo && idleEnded; + appendLog( + pass + ? '[result] PASS: real video after idle frames kept the session connected' + : `[result] FAIL: connected=${connected} stayedConnected=${stayedConnected} ` + + `sawRealVideo=${sawRealVideo} idleEnded=${idleEnded} ` + + `timeline=${JSON.stringify(timeline)}` + ); + await sleep(300); + store.getState().session?.end(); +} + function App() { const [running, setRunning] = useState(false); const runningRef = useRef(false); @@ -296,7 +431,11 @@ function App() { runningRef.current = true; setRunning(true); try { - await runTest(); + if (new URLSearchParams(window.location.search).get('scenario') === 'real-video-after-idle') { + await runRealVideoAfterIdleTest(); + } else { + await runTest(); + } } finally { runningRef.current = false; setRunning(false); diff --git a/deps/cloudxr/webxr_client/tests/playwright/StreamAttachTimeoutTest.spec.js b/deps/cloudxr/webxr_client/tests/playwright/StreamAttachTimeoutTest.spec.js index 0b51e0e9f1..a7d36b48ae 100644 --- a/deps/cloudxr/webxr_client/tests/playwright/StreamAttachTimeoutTest.spec.js +++ b/deps/cloudxr/webxr_client/tests/playwright/StreamAttachTimeoutTest.spec.js @@ -14,7 +14,7 @@ const { test, expect } = require('@playwright/test'); */ const LOG_PREFIX = '[StreamAttachTimeoutTest] '; -const SEQUENCE_TIMEOUT_MS = 15000; +const SEQUENCE_TIMEOUT_MS = 20000; function collectLogLines(page) { const lines = []; @@ -44,3 +44,23 @@ test('StreamAttachTimeoutTest: attach timeout, warmup timeout, then success', as const resultLine = lines.find(l => l.startsWith('[result]')); expect(resultLine, `captured lines:\n${lines.join('\n')}`).toContain('[result] PASS'); }); + +test('StreamAttachTimeoutTest: real video after idle frames does not re-arm a warm-up watchdog', async ({ + page, +}) => { + test.setTimeout(30000); + + const lines = collectLogLines(page); + await page.goto('/StreamAttachTimeoutTest.html?scenario=real-video-after-idle'); + await page.click('#startButton'); + + await expect + .poll(() => lines.some(l => l.startsWith('[result]')), { + timeout: 15000, + message: () => `scenario did not complete; captured so far:\n${lines.join('\n')}`, + }) + .toBe(true); + + const resultLine = lines.find(l => l.startsWith('[result]')); + expect(resultLine, `captured lines:\n${lines.join('\n')}`).toContain('[result] PASS'); +});