diff --git a/apps/mobile/components/native/RoomDiagnostics.tsx b/apps/mobile/components/native/RoomDiagnostics.tsx index 15c5e9b..cbc6971 100644 --- a/apps/mobile/components/native/RoomDiagnostics.tsx +++ b/apps/mobile/components/native/RoomDiagnostics.tsx @@ -78,6 +78,10 @@ const KIND_COLOR: Partial> = { error: RED, dead: RED, retry: AMBER, + background: GRAY, + foreground: GREEN, + suspend: AMBER, + 'stale-send': RED, }; function ago(now: number, t: number | null): string { @@ -108,7 +112,8 @@ function buildDump(apiUrl: string, roomTarget: string, snap: RoomSnapshot, log: lines.push( `lastInbound=${ago(now, snap.lastInboundAt)} lastPong=${ago(now, snap.lastPongAt)} ` + `openFor=${snap.lastOpenAt ? Math.round((now - snap.lastOpenAt) / 1000) + 's' : '—'} ` + - `unansweredKA=${snap.keepalivesSinceProof} pongsSeen=${snap.pongsSeen}`, + `unansweredKA=${snap.keepalivesSinceProof} pongsSeen=${snap.pongsSeen} ` + + `maxInboundGap=${Math.round(snap.longestInboundGapMs / 1000)}s`, ); lines.push(`counters: ${Object.entries(snap.counters).map(([k, v]) => `${k}=${v}`).join(' ')}`); lines.push('--- log (newest last) ---'); @@ -230,6 +235,11 @@ export function RoomDiagnostics({ 0 ? AMBER : undefined} /> + 30_000 ? AMBER : undefined} + /> 0 ? AMBER : undefined} /> diff --git a/apps/mobile/hooks/useLucidAsk.tsx b/apps/mobile/hooks/useLucidAsk.tsx index 4f71951..8dc00d7 100644 --- a/apps/mobile/hooks/useLucidAsk.tsx +++ b/apps/mobile/hooks/useLucidAsk.tsx @@ -147,7 +147,9 @@ function useLucidAskState() { // instead and forces a fresh dial before the user can send onto a dead socket. React.useEffect(() => { const sub = AppState.addEventListener('change', (state) => { - if (state === 'active') clientRef.current?.resumeForeground(); + const client = clientRef.current; + if (state === 'active') client?.resumeForeground(); + else if (state === 'background') client?.noteBackground(); }); return () => sub.remove(); }, []); diff --git a/apps/mobile/lib/roomClient.ts b/apps/mobile/lib/roomClient.ts index ad5bb31..d1c41b8 100644 --- a/apps/mobile/lib/roomClient.ts +++ b/apps/mobile/lib/roomClient.ts @@ -17,7 +17,12 @@ export type RoomStatus = 'idle' | 'connecting' | 'open' | 'closed'; export type RoomDiagKind = | 'connect' | 'open' | 'close' | 'reconnect' | 'keepalive' | 'pong' - | 'presence' | 'send' | 'timeout' | 'lost' | 'recover' | 'retry' | 'error' | 'dead'; + | 'presence' | 'send' | 'timeout' | 'lost' | 'recover' | 'retry' | 'error' | 'dead' + // App-lifecycle + freeze visibility: `background`/`foreground` AppState transitions, a + // `suspend` keepalive that fired long-late (JS timers were frozen), and a `stale-send` + // routed to the outbox because the socket only looked open. These turn the tell-tale + // "silent hole in the log" of a background freeze into named, legible events. + | 'background' | 'foreground' | 'suspend' | 'stale-send'; /** One connection-lifecycle event for the dev diagnostics panel. */ export interface RoomDiagEvent { @@ -46,6 +51,10 @@ export interface RoomSnapshot { lastOpenAt: number | null; keepalivesSinceProof: number; pongsSeen: number; + /** The longest gap ever seen between two inbound frames (ms). A large value flags a + * window where the socket went silent — e.g. an iOS background freeze — even after it + * has since recovered, so a past stall is still visible in the summary. */ + longestInboundGapMs: number; counters: Record; } @@ -188,6 +197,13 @@ export class LucidRoomClient { // How many keepalive echoes we've ever seen — proves the server echoes, which is what // makes acting on "silence = dead" safe (vs. an older server that never echoes). private pongsSeen = 0; + // Longest gap ever observed between inbound frames (ms) — a past-stall marker for the + // diagnostics summary. Grows monotonically; a big value means the socket went quiet. + private longestInboundGapMs = 0; + // When the keepalive interval last actually fired. A gap far larger than KEEPALIVE_MS + // between fires means the JS timers were suspended (backgrounded/locked) — the freeze + // fingerprint we surface as a `suspend` diag event. + private lastKeepaliveAt: number | null = null; // Server-pushed daemon presence, mirrored for the diagnostics snapshot. private daemonConnected = false; private daemonMachine: string | null = null; @@ -219,6 +235,7 @@ export class LucidRoomClient { * send made in the meantime is routed there by `enqueue` instead of vanishing. */ resumeForeground(): void { if (this.closedByUser) return; + this.diag('foreground'); if (this.status !== 'open') { this.reconnect(); return; @@ -230,6 +247,13 @@ export class LucidRoomClient { } } + /** Log the app going to the background, so a gap in the event log reads as + * `background … foreground` instead of an unexplained hole. No socket action — iOS + * freezes our timers regardless; `resumeForeground` owns the recovery on return. */ + noteBackground(): void { + this.diag('background'); + } + /** A point-in-time view of the connection's internals — for the dev diagnostics panel. */ snapshot(): RoomSnapshot { return { @@ -247,6 +271,7 @@ export class LucidRoomClient { lastOpenAt: this.lastOpenAt, keepalivesSinceProof: this.keepalivesSinceProof, pongsSeen: this.pongsSeen, + longestInboundGapMs: this.longestInboundGapMs, counters: { ...this.counters }, }; } @@ -329,8 +354,18 @@ export class LucidRoomClient { * drops it as an unrecognized request. */ private startKeepalive(): void { this.stopKeepalive(); + this.lastKeepaliveAt = null; // fresh socket — don't inherit the previous one's clock this.keepaliveTimer = setInterval(() => { if (!this.ws || this.status !== 'open') return; + // Timer-suspension fingerprint: if this fire is far later than KEEPALIVE_MS after the + // previous one, the JS event loop was frozen (backgrounded/locked). Surface it so the + // tell-tale multi-minute hole in the keepalive log reads as an explicit + // "resumed after Ns suspended" instead of an unexplained gap. + const now = Date.now(); + if (this.lastKeepaliveAt != null && now - this.lastKeepaliveAt > KEEPALIVE_MS * 2) { + this.diag('suspend', `resumed after ${Math.round((now - this.lastKeepaliveAt) / 1000)}s suspended`); + } + this.lastKeepaliveAt = now; // Half-open watchdog: if the server has proven it echoes (pongsSeen > 0) yet a run of // our keepalives has gone unanswered with no other inbound, the socket is dead in a // way iOS never surfaced as a close — force a fresh dial instead of sitting wedged @@ -426,6 +461,9 @@ export class LucidRoomClient { if (this.ws && this.status === 'open' && !this.isSocketLikelyDead()) { this.ws.send(payload); } else { + // A losable event made legible: a send while the socket only looked open would have + // been orphaned before the fix — count it so a lost message shows up in diagnostics. + if (this.status === 'open') this.diag('stale-send', 'socket looked open but was dead'); this.outbox.push(payload); // A user send is a retry intent: reconnect if auto-reconnect gave up OR the socket // only looked open (dead-frozen); otherwise connect from a clean idle/closed state. @@ -489,7 +527,11 @@ export class LucidRoomClient { const msg = json as Record; // Any inbound frame is proof the socket is alive → reset the half-open watchdog. - this.lastInboundAt = Date.now(); + const nowIn = Date.now(); + if (this.lastInboundAt != null) { + this.longestInboundGapMs = Math.max(this.longestInboundGapMs, nowIn - this.lastInboundAt); + } + this.lastInboundAt = nowIn; this.keepalivesSinceProof = 0; this.counters['recv'] = (this.counters['recv'] ?? 0) + 1;