Skip to content

Commit 12ef784

Browse files
fix(call): debounce Daily join + orphaned join cleanup + recording retry (#1235)
* fix(call): add diagnostic logging for orphaned Daily join race condition Add console.warn/log at three key points to trace the stale-data race where VideoCall mounts spuriously during stage transitions, initiating a join() that completes orphaned after unmount. This leaves the callObject stuck on the wrong room for subsequent video stages. Logs added: - joinRoom skip (already joined or joining) - cleanup skip of leave() during mid-join state - recording attempt on already-joined callObject Ref: DELIBERATION-EMPIRICA-R1, #1226 Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com> * fix(call): retry startRecording after 500ms + add trigger/room tracking startRecording() returns non-Promise when called in the same tick as joined-meeting (DELIBERATION-EMPIRICA-RK). Add a single 500ms retry so the Daily SDK has time to settle. Also: - Tag each startRecording call with its trigger source (joined-meeting-event vs already-joined-at-effect-start) - Track joinedRoomUrl in useCallLifecycle so the skip-join log shows which room the callObject is actually connected to Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com> * fix(call): detect player.stage / useStage() desync in SubmissionConditionalRender Add diagnostic logging to verify the hypothesis that player.stage updates before useStage() during stage transitions, creating a window where isSubmitted is falsy (new stage) but discussion config is stale (old stage), causing a spurious VideoCall mount. Logs playerStageId vs stageHookId when they differ — if this appears in Sentry breadcrumbs before AudioContext creation, the hypothesis is confirmed. Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com> * fix(call): debounce Daily join to prevent spurious joins during stage transitions During stage transitions, Empirica can briefly render a VideoCall component (~36ms) for a non-video stage before React unmounts it. This caused callObject.join() to fire on a component that immediately unmounts, corrupting the Daily call state for subsequent video stages. Add a 150ms debounce before join() with an unmount check, plus orphaned join detection as a safety net. Remove broken stage desync diagnostic from ConditionalRender (compared independent ULIDs that could never match). Closes #1236 Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com> * chore: remove joinedRoomUrlRef cruft and stale test comment Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com> * chore: add meetingState to join error log, add context to cleanup leave log Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com> * chore: remove redundant roomUrl from lifecycle logs roomUrl is game-level and never changes — no diagnostic value in per-event logs. Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com> * fix: address PR review feedback - Add meetingState === "joining" to joinRoom skip guard (prevents double-join) - Fix debounce timer: don't push to inlineTimers (avoids hung promise on cleanup) - Fix issue reference: #1226 not #1236 - Update cleanup comment to reflect actual behavior (skip leave during joining) - Preserve "non-promise return" error string (matches existing test REC-005b) - MockDailyProvider: transition state on non-delayed join path Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com> --------- Co-authored-by: Claude Opus 4.6 <noreply@anthropic.com>
1 parent 1a94ab8 commit 12ef784

6 files changed

Lines changed: 269 additions & 40 deletions

File tree

.gitignore

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@ tajriba.json
33
.vscode/
44

55
reference/
6+
sentry-exports/
67

78
# Logs
89
logs

CLAUDE.md

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -31,7 +31,7 @@ Admin UI: `http://localhost:3000/admin`
3131
## Tools
3232

3333
- **GitHub**: Use `gh` CLI for all GitHub workflows — viewing issues, creating PRs, reading and responding to PR review comments. Paste issue/PR URLs or numbers directly into the conversation.
34-
- **Sentry**: Sentry MCP is installed. Use it to fetch error events, look up issues by ID, search for recent errors, etc.
34+
- **Sentry**: `sentry-cli` is installed and authenticated (`~/.sentryclirc`). Org: `watts-lab`, project: `deliberation-empirica`. Use it to list events, query issues, etc. For full event JSON exports, use the Sentry web API with the same auth token. Sentry MCP is also configured but may need re-authentication.
3535

3636
## Component Tests (Playwright)
3737

client/src/call/hooks/useCallLifecycle.js

Lines changed: 49 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -24,6 +24,7 @@ import { useCallback, useEffect, useRef, useState } from "react";
2424
*/
2525
export function useCallLifecycle(callObject, roomUrl, player) {
2626
const joiningMeetingRef = useRef(false);
27+
const unmountedRef = useRef(false); // track unmount to handle orphaned joins (#1226)
2728
// For stall detection (issue #1187) - track if join is taking too long due to blur
2829
const joinStartTimeRef = useRef(null);
2930
const blurredDuringJoinRef = useRef(false);
@@ -49,6 +50,8 @@ export function useCallLifecycle(callObject, roomUrl, player) {
4950
// When both flags are false we skip Daily entirely (handy for layout demos), so this
5051
// effect bails before trying to join a non-existent room.
5152

53+
unmountedRef.current = false;
54+
5255
// Track blur events during join to detect stalled joins
5356
// Track inline timeout IDs so cleanup can clear them on unmount
5457
const inlineTimers = [];
@@ -77,9 +80,31 @@ export function useCallLifecycle(callObject, roomUrl, player) {
7780
}, 5000);
7881

7982
const joinRoom = async () => {
83+
// Debounce: wait briefly before joining to avoid spurious joins during
84+
// transient mounts. During stage transitions, Empirica can briefly render
85+
// a VideoCall component (~36ms) for a non-video stage before React
86+
// reconciliation unmounts it. Without this delay, the transient mount
87+
// calls join() while the previous stage's cleanup is mid-leave(),
88+
// corrupting the callObject state for subsequent video stages.
89+
// 150ms is imperceptible to users but longer than any observed transient
90+
// mount, and long enough for the previous leave() to complete.
91+
// See issue #1226.
92+
await new Promise((resolve) => {
93+
setTimeout(resolve, 150);
94+
});
95+
if (unmountedRef.current) {
96+
console.log("[VideoCall] Join debounce: component unmounted during delay, skipping join");
97+
return;
98+
}
99+
80100
const meetingState = callObject.meetingState?.();
81-
if (meetingState === "joined-meeting" || joiningMeetingRef.current)
101+
if (meetingState === "joined-meeting" || meetingState === "joining" || joiningMeetingRef.current) {
102+
console.warn("[VideoCall] joinRoom skipped", {
103+
meetingState,
104+
joiningMeetingRef: joiningMeetingRef.current,
105+
});
82106
return;
107+
}
83108

84109
const joinStartTime = Date.now();
85110
joinStartTimeRef.current = joinStartTime;
@@ -111,11 +136,23 @@ export function useCallLifecycle(callObject, roomUrl, player) {
111136
userData: position != null ? { position } : undefined,
112137
});
113138
const joinDuration = Date.now() - joinStartTime;
139+
140+
// Orphaned join detection (#1226): if the component unmounted while
141+
// join() was in flight, the cleanup couldn't call leave() because
142+
// meetingState was "joining". Now that join completed, leave immediately
143+
// so the callObject doesn't stay stuck in "joined-meeting" on a stale room.
144+
if (unmountedRef.current) {
145+
console.warn("[VideoCall] Orphaned join detected — leaving immediately", {
146+
durationMs: joinDuration,
147+
});
148+
callObject.leave();
149+
return;
150+
}
151+
114152
// Join succeeded - clear stalled state
115153
setJoinStalled(false);
116154
blurredDuringJoinRef.current = false;
117155
console.log("[VideoCall] Joined Daily room", {
118-
roomUrl,
119156
durationMs: joinDuration,
120157
hasFocus: document.hasFocus(),
121158
visibilityState: document.visibilityState,
@@ -167,7 +204,9 @@ export function useCallLifecycle(callObject, roomUrl, player) {
167204
console.warn("Failed to attempt AGC disable:", agcErr);
168205
}
169206
} catch (err) {
170-
console.error("Error joining Daily room", roomUrl, err);
207+
console.error("Error joining Daily room", err, {
208+
meetingState: callObject.meetingState?.(),
209+
});
171210
} finally {
172211
joiningMeetingRef.current = false;
173212
}
@@ -177,6 +216,7 @@ export function useCallLifecycle(callObject, roomUrl, player) {
177216

178217
return () => {
179218
// cleanup on unmount or roomUrl change
219+
unmountedRef.current = true;
180220
clearTimeout(stallTimer);
181221
inlineTimers.forEach(clearTimeout);
182222
window.removeEventListener("blur", handleBlurDuringJoin);
@@ -185,13 +225,16 @@ export function useCallLifecycle(callObject, roomUrl, player) {
185225
const state = callObject.meetingState?.();
186226

187227
if (
188-
// state === "joining" ||
189228
state === "joined-meeting" ||
190229
state === "loaded"
191230
) {
192-
// only leave if we are in the process of joining or already joined
193-
console.log("Leaving Daily room");
231+
// Only call leave() once the meeting has fully joined/loaded; we skip
232+
// leave() for state === "joining" (handled below) to avoid forcing a
233+
// leave mid-join.
234+
console.log("[VideoCall] Leaving Daily room", { state });
194235
callObject.leave();
236+
} else if (state === "joining") {
237+
console.warn("[VideoCall] Cleanup: callObject is mid-join, leave() skipped");
195238
}
196239
};
197240
// `player` is intentionally excluded: position is read once at join time and

client/src/call/hooks/useCallStartSignaling.js

Lines changed: 58 additions & 31 deletions
Original file line numberDiff line numberDiff line change
@@ -31,44 +31,60 @@ export function useCallStartSignaling(callObject, recordingEnabled, stageId) {
3131
// Track deferred Sentry timers so we can cancel on cleanup
3232
const pendingTimers = [];
3333

34-
const startRecordingIfNeeded = () => {
35-
if (recordingEnabled && !recordingStartedRef.current) {
36-
recordingStartedRef.current = true;
37-
const result = callObject.startRecording({ type: "raw-tracks" });
38-
if (result && typeof result.then === "function") {
39-
result.then(
40-
() => console.log("[Recording] Started raw-tracks recording from client"),
41-
(err) => {
42-
console.warn("[Recording] Failed to start recording:", err.message);
43-
recordingStartedRef.current = false;
34+
const attemptStartRecording = (trigger, attempt = 1) => {
35+
const result = callObject.startRecording({ type: "raw-tracks" });
36+
if (result && typeof result.then === "function") {
37+
result.then(
38+
() => console.log("[Recording] Started raw-tracks recording from client", {
39+
trigger, attempt,
40+
}),
41+
(err) => {
42+
console.warn("[Recording] Failed to start recording:", err.message, {
43+
trigger, attempt,
44+
});
45+
recordingStartedRef.current = false;
46+
47+
// Defer Sentry alert: wait 5s and check if another participant
48+
// successfully started recording (indicated by recording-started
49+
// event setting recordingConfirmedRef). This avoids false alarms
50+
// when one client fails but another succeeds — Daily broadcasts
51+
// recording-started to all participants regardless of who initiated.
52+
const timer = setTimeout(() => {
53+
if (!recordingConfirmedRef.current) {
54+
Sentry.captureMessage("Recording not started for stage", {
55+
level: "error",
56+
extra: { triggeringError: err.message, stageId, trigger, attempt },
57+
});
58+
}
59+
}, 5000);
60+
pendingTimers.push(timer);
61+
}
62+
);
63+
} else {
64+
console.warn("[Recording] startRecording() returned non-Promise; call may be in transitional state", {
65+
trigger, attempt, meetingState: callObject.meetingState?.(),
66+
});
67+
recordingStartedRef.current = false;
4468

45-
// Defer Sentry alert: wait 5s and check if another participant
46-
// successfully started recording (indicated by recording-started
47-
// event setting recordingConfirmedRef). This avoids false alarms
48-
// when one client fails but another succeeds — Daily broadcasts
49-
// recording-started to all participants regardless of who initiated.
50-
const timer = setTimeout(() => {
51-
if (!recordingConfirmedRef.current) {
52-
Sentry.captureMessage("Recording not started for stage", {
53-
level: "error",
54-
extra: { triggeringError: err.message, stageId },
55-
});
56-
}
57-
}, 5000);
58-
pendingTimers.push(timer);
69+
// Retry once after 500ms — Daily's recording API may not be ready
70+
// at the same tick as joined-meeting (see DELIBERATION-EMPIRICA-RK).
71+
if (attempt < 2) {
72+
const retryTimer = setTimeout(() => {
73+
if (!recordingConfirmedRef.current && !recordingStartedRef.current) {
74+
console.log("[Recording] Retrying startRecording", { trigger, attempt: attempt + 1 });
75+
recordingStartedRef.current = true;
76+
attemptStartRecording(trigger, attempt + 1);
5977
}
60-
);
78+
}, 500);
79+
pendingTimers.push(retryTimer);
6180
} else {
62-
console.warn("[Recording] startRecording() returned non-Promise; call may be in transitional state");
63-
recordingStartedRef.current = false;
64-
6581
// Defer Sentry alert: if no participant confirms recording within 5s,
6682
// surface the issue so we don't silently miss a whole stage of recording.
6783
const timer = setTimeout(() => {
6884
if (!recordingConfirmedRef.current) {
6985
Sentry.captureMessage("Recording not started for stage", {
7086
level: "error",
71-
extra: { triggeringError: "non-promise return", stageId },
87+
extra: { triggeringError: "non-promise return", stageId, trigger },
7288
});
7389
}
7490
}, 5000);
@@ -77,8 +93,15 @@ export function useCallStartSignaling(callObject, recordingEnabled, stageId) {
7793
}
7894
};
7995

96+
const startRecordingIfNeeded = (trigger) => {
97+
if (recordingEnabled && !recordingStartedRef.current) {
98+
recordingStartedRef.current = true;
99+
attemptStartRecording(trigger);
100+
}
101+
};
102+
80103
const handleJoined = () => {
81-
startRecordingIfNeeded();
104+
startRecordingIfNeeded("joined-meeting-event");
82105
};
83106

84107
const handleRecordingStarted = () => {
@@ -109,7 +132,11 @@ export function useCallStartSignaling(callObject, recordingEnabled, stageId) {
109132

110133
// If already joined (effect ran after joined-meeting fired), start immediately
111134
if (callObject.meetingState?.() === "joined-meeting") {
112-
startRecordingIfNeeded();
135+
console.log("[Recording] Already joined at effect start, attempting recording", {
136+
stageId,
137+
meetingState: callObject.meetingState?.(),
138+
});
139+
startRecordingIfNeeded("already-joined-at-effect-start");
113140
}
114141

115142
return () => {
Lines changed: 134 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,134 @@
1+
import React from 'react';
2+
import { test, expect } from '@playwright/experimental-ct-react';
3+
import { VideoCall } from '../../../../client/src/call/VideoCall';
4+
5+
/**
6+
* Component Tests for Orphaned Daily Join Race Condition (Issue #1226)
7+
*
8+
* Tests: ORPHAN-001 to ORPHAN-003
9+
*
10+
* The race condition: During Empirica stage transitions, a ~70ms desync window
11+
* can cause VideoCall to mount spuriously on a non-video stage. It calls
12+
* callObject.join(), then unmounts when the stage data resolves. But cleanup
13+
* skips leave() when meetingState is "joining", so the join completes orphaned
14+
* and the callObject is stuck in "joined-meeting" on the wrong room.
15+
*
16+
* Infrastructure:
17+
* - window.__mockInitialMeetingState: set BEFORE mount to override initial state
18+
* - window.__mockJoinBehavior: 'delayed' makes join() return a manually-resolvable promise
19+
* - window.mockCallObject._resolveJoin(): resolve the pending delayed join
20+
* - window.mockCallObject._leaveCalls: array of leave() call logs
21+
*/
22+
23+
const baseConfig = {
24+
empirica: {
25+
currentPlayerId: 'p0',
26+
players: [{ id: 'p0', attrs: { position: '0', dailyId: 'daily-p0', name: 'Test User' } }],
27+
game: { attrs: { dailyUrl: 'https://test.daily.co/room-a' } },
28+
stage: { attrs: {}, id: 'stage-1' },
29+
stageTimer: { elapsed: 0 },
30+
},
31+
daily: {
32+
localSessionId: 'daily-p0',
33+
participantIds: ['daily-p0'],
34+
videoTracks: { 'daily-p0': { isOff: false, subscribed: true } },
35+
audioTracks: { 'daily-p0': { isOff: false, subscribed: true } },
36+
},
37+
};
38+
39+
test.describe('Orphaned Join Cleanup (useCallLifecycle)', () => {
40+
/**
41+
* ORPHAN-001: When component unmounts during "joining" state, leave() must be
42+
* called after the join completes.
43+
*
44+
* This is the core bug from issue #1226:
45+
* 1. VideoCall mounts spuriously during stage desync window
46+
* 2. callObject.join() starts (meetingState → "joining")
47+
* 3. Component unmounts when stage data resolves (not a video stage)
48+
* 4. Cleanup sees "joining" and skips leave() ← BUG
49+
* 5. Join completes → callObject stuck in "joined-meeting" on wrong room
50+
*
51+
* Expected: cleanup arranges for leave() after the pending join resolves.
52+
*/
53+
test('ORPHAN-001: leave() called after orphaned join completes on unmount', async ({ mount, page }) => {
54+
// Setup: delayed join so we can unmount while "joining"
55+
await page.evaluate(() => {
56+
window.__mockInitialMeetingState = 'new';
57+
window.__mockJoinBehavior = 'delayed';
58+
});
59+
60+
const component = await mount(<VideoCall showSelfView />, {
61+
hooksConfig: baseConfig,
62+
});
63+
64+
// Wait for join to start (state should transition to 'joining')
65+
await expect(async () => {
66+
const state = await page.evaluate(() => window.mockCallObject?.meetingState());
67+
expect(state).toBe('joining');
68+
}).toPass({ timeout: 3000 });
69+
70+
// Save reference to mock before unmount (provider cleanup deletes window.mockCallObject)
71+
await page.evaluate(() => {
72+
window._savedMock = window.mockCallObject;
73+
});
74+
75+
// Verify no leave() calls yet
76+
const leavesBefore = await page.evaluate(() => window._savedMock._leaveCalls.length);
77+
expect(leavesBefore).toBe(0);
78+
79+
// Unmount while join is in progress — this is the critical moment.
80+
// Current behavior: cleanup sees "joining", skips leave() → BUG
81+
// Fixed behavior: cleanup arranges for leave() after join resolves
82+
await component.unmount();
83+
84+
// Resolve the pending join (simulates Daily SDK completing the join)
85+
await page.evaluate(() => window._savedMock._resolveJoin());
86+
87+
// Give the post-join cleanup a tick to run
88+
await page.waitForTimeout(100);
89+
90+
// Verify leave() was called after the orphaned join completed
91+
const leaveCalls = await page.evaluate(() => window._savedMock._leaveCalls);
92+
expect(leaveCalls.length).toBeGreaterThanOrEqual(1);
93+
});
94+
95+
/**
96+
* ORPHAN-002: Normal unmount from "joined-meeting" calls leave() immediately.
97+
*
98+
* Regression test: existing cleanup behavior must not break.
99+
*/
100+
test('ORPHAN-002: normal cleanup calls leave() when joined', async ({ mount, page }) => {
101+
const component = await mount(<VideoCall showSelfView />, {
102+
hooksConfig: baseConfig,
103+
});
104+
await expect(component).toBeVisible({ timeout: 15000 });
105+
106+
// Save reference before unmount
107+
await page.evaluate(() => {
108+
window._savedMock = window.mockCallObject;
109+
});
110+
111+
// Unmount — cleanup should call leave() since state is "joined-meeting"
112+
await component.unmount();
113+
114+
const leaveCalls = await page.evaluate(() => window._savedMock._leaveCalls);
115+
expect(leaveCalls.length).toBeGreaterThanOrEqual(1);
116+
expect(leaveCalls[0].fromState).toBe('joined-meeting');
117+
});
118+
119+
/**
120+
* ORPHAN-003: joinRoom skips when callObject is already in "joined-meeting".
121+
*
122+
* Existing guard behavior — join() should NOT be called redundantly.
123+
*/
124+
test('ORPHAN-003: joinRoom skips when already joined', async ({ mount, page }) => {
125+
const component = await mount(<VideoCall showSelfView />, {
126+
hooksConfig: baseConfig,
127+
});
128+
await expect(component).toBeVisible({ timeout: 15000 });
129+
130+
// Mock starts in "joined-meeting" — joinRoom() should have skipped join()
131+
const joinCalled = await page.evaluate(() => window.mockCallObject._joinCalled);
132+
expect(joinCalled).toBe(false);
133+
});
134+
});

0 commit comments

Comments
 (0)