From 3162bc44c67b280a8d283f5823b04b29d927bd3c Mon Sep 17 00:00:00 2001 From: Wooseong Kim Date: Fri, 2 Oct 2026 02:03:15 +0900 Subject: [PATCH 1/3] fix(mobile): do not call a suspended dial an unreachable host iOS freezes setTimeout, so a 12s connect timer can fire hours later and the diagnostics log says the endpoint is unreachable. A deadline that fires more than a minute past its budget is logged as suspension, then the socket is closed so the existing retry runs. A timer that fires on its budget still reports connect-timeout or handshake-timeout. Fixes #18829 --- .../connection-diagnostics-analysis.test.ts | 20 ++++ .../transport/rpc-client-socket-session.ts | 67 +++++------ .../socket-deadline-suspension.test.ts | 104 ++++++++++++++++++ .../transport/socket-deadline-suspension.ts | 92 ++++++++++++++++ mobile/src/transport/types.ts | 1 + 5 files changed, 252 insertions(+), 32 deletions(-) create mode 100644 mobile/src/transport/socket-deadline-suspension.test.ts create mode 100644 mobile/src/transport/socket-deadline-suspension.ts diff --git a/mobile/src/diagnostics/connection-diagnostics-analysis.test.ts b/mobile/src/diagnostics/connection-diagnostics-analysis.test.ts index ab40b3511b27..a1599d2af511 100644 --- a/mobile/src/diagnostics/connection-diagnostics-analysis.test.ts +++ b/mobile/src/diagnostics/connection-diagnostics-analysis.test.ts @@ -195,6 +195,26 @@ describe('diagnoseConnection', () => { }) }) + it('does not blame the host when a dial timer fires after suspension', () => { + expect( + diagnoseConnection({ + endpoint: 'ws://100.88.90.25:6768', + state: 'connecting', + activePath: 'tailscale', + entries: [ + { + ...event( + 'WebSocket connect interrupted', + 'App suspended for 2h44m; connection state unknown, re-dialing' + ), + level: 'warn', + code: 'suspended-dial' + } + ] + }).likelyCause + ).toBe('No single failure cause can be determined from the recorded events.') + }) + it('keys reportability to the current structured incident', () => { const args = { endpoint: 'ws://192.168.1.2:6768', diff --git a/mobile/src/transport/rpc-client-socket-session.ts b/mobile/src/transport/rpc-client-socket-session.ts index bc8f9d13e2cd..c6020c30447c 100644 --- a/mobile/src/transport/rpc-client-socket-session.ts +++ b/mobile/src/transport/rpc-client-socket-session.ts @@ -9,6 +9,7 @@ import { import { isRpcResponse } from './rpc-response-shape' import { isStaleRpcSocketEvent, logRpcSocketClose } from './rpc-socket-close-evidence' import { describeSocketEvent, redactSocketEndpoint } from './socket-event-debug' +import { reportSocketDeadline, type SocketDeadlineKind } from './socket-deadline-suspension' import type { ConnectionLogEmitter, ConnectionState, RpcResponse } from './types' import { websocketPayloadToUint8 } from './websocket-payload-bytes' @@ -248,44 +249,46 @@ export class RpcClientSocketSession { } private armConnectTimeout(): void { - this.connectTimer = setTimeout(() => { - this.connectTimer = null - if ( - this.options.getCurrentSocket() === this.socket && - this.socket.readyState === WEBSOCKET_CONNECTING_STATE - ) { - console.log('[net] connect-timeout fired (onopen never arrived)', { - attempt: this.options.getReconnectAttempt(), - timeoutMs: CONNECT_TIMEOUT_MS - }) - this.options.emitLog( - 'error', - 'WebSocket connect timeout', - `No TCP/WS handshake within ${CONNECT_TIMEOUT_MS / 1000}s — endpoint unreachable?`, - { code: 'connect-timeout' } - ) - this.options.onForcedClose(this) - } - }, CONNECT_TIMEOUT_MS) + this.armSocketDeadline('connect', CONNECT_TIMEOUT_MS) } private armHandshakeTimeout(): void { - this.handshakeTimer = setTimeout(() => { - this.handshakeTimer = null - if (this.options.getCurrentSocket() !== this.socket || this.authenticated) { + this.armSocketDeadline('handshake', HANDSHAKE_TIMEOUT_MS) + } + + private armSocketDeadline(kind: SocketDeadlineKind, timeoutMs: number): void { + const armedAtMs = Date.now() + const timer = setTimeout(() => { + if (kind === 'connect') { + this.connectTimer = null + } else { + this.handshakeTimer = null + } + const current = this.options.getCurrentSocket() === this.socket + const pending = + kind === 'connect' + ? current && this.socket.readyState === WEBSOCKET_CONNECTING_STATE + : current && !this.authenticated + if (!pending) { return } - console.log('[net] handshake-timeout fired (e2ee_authenticated never arrived)', { - timeoutMs: HANDSHAKE_TIMEOUT_MS - }) - this.options.emitLog( - 'error', - 'Handshake timeout', - `No e2ee_ready/e2ee_authenticated within ${HANDSHAKE_TIMEOUT_MS / 1000}s`, - { code: 'handshake-timeout' } + reportSocketDeadline( + { + kind, + armedAtMs, + firedAtMs: Date.now(), + timeoutMs, + ...(kind === 'connect' ? { attempt: this.options.getReconnectAttempt() } : {}) + }, + this.options.emitLog, + () => this.options.onForcedClose(this) ) - this.options.onForcedClose(this) - }, HANDSHAKE_TIMEOUT_MS) + }, timeoutMs) + if (kind === 'connect') { + this.connectTimer = timer + } else { + this.handshakeTimer = timer + } } private clearConnectTimer(): void { diff --git a/mobile/src/transport/socket-deadline-suspension.test.ts b/mobile/src/transport/socket-deadline-suspension.test.ts new file mode 100644 index 000000000000..940e5bf8535e --- /dev/null +++ b/mobile/src/transport/socket-deadline-suspension.test.ts @@ -0,0 +1,104 @@ +import { describe, expect, it, vi } from 'vitest' +import { describeSocketDeadline, reportSocketDeadline } from './socket-deadline-suspension' + +const CONNECT_TIMEOUT_MS = 12_000 +const HANDSHAKE_TIMEOUT_MS = 5_000 +const SUSPENSION_SLACK_MS = 60_000 + +describe('describeSocketDeadline', () => { + it('keeps a deadline that fires on its budget as a host timeout', () => { + const armedAtMs = 1_000 + const report = describeSocketDeadline({ + kind: 'connect', + armedAtMs, + firedAtMs: armedAtMs + CONNECT_TIMEOUT_MS, + timeoutMs: CONNECT_TIMEOUT_MS, + attempt: 2 + }) + + expect(report).toMatchObject({ + suspended: false, + level: 'error', + code: 'connect-timeout', + title: 'WebSocket connect timeout', + detail: 'No TCP/WS handshake within 12s — endpoint unreachable?', + consoleMessage: '[net] connect-timeout fired (onopen never arrived)' + }) + }) + + it('keeps a handshake that fires just past its budget as a handshake timeout', () => { + const armedAtMs = 5_000 + const report = describeSocketDeadline({ + kind: 'handshake', + armedAtMs, + firedAtMs: armedAtMs + HANDSHAKE_TIMEOUT_MS + SUSPENSION_SLACK_MS, + timeoutMs: HANDSHAKE_TIMEOUT_MS + }) + + expect(report.suspended).toBe(false) + expect(report.code).toBe('handshake-timeout') + expect(report.detail).toBe('No e2ee_ready/e2ee_authenticated within 5s') + }) + + it('treats a timer that fires hours late as suspension, not an unreachable host', () => { + const armedAtMs = Date.parse('2026-09-04T12:56:55.512Z') + const firedAtMs = Date.parse('2026-09-04T15:40:52.242Z') + const report = describeSocketDeadline({ + kind: 'connect', + armedAtMs, + firedAtMs, + timeoutMs: CONNECT_TIMEOUT_MS, + attempt: 2 + }) + + expect(report).toMatchObject({ + suspended: true, + level: 'warn', + code: 'suspended-dial', + title: 'WebSocket connect interrupted', + detail: 'App suspended for 2h44m; connection state unknown, re-dialing' + }) + expect(report.detail).not.toContain('endpoint unreachable') + expect(report.consoleMessage).not.toContain('connect-timeout') + }) + + it('uses the same suspension reading for a frozen handshake timer', () => { + const armedAtMs = 0 + const report = describeSocketDeadline({ + kind: 'handshake', + armedAtMs, + firedAtMs: HANDSHAKE_TIMEOUT_MS + SUSPENSION_SLACK_MS + 1, + timeoutMs: HANDSHAKE_TIMEOUT_MS + }) + + expect(report.code).toBe('suspended-dial') + expect(report.title).toBe('Handshake interrupted') + expect(report.detail).not.toContain('handshake timeout') + }) +}) + +describe('reportSocketDeadline', () => { + it('still closes the socket after logging a suspended dial', () => { + const emitLog = vi.fn() + const close = vi.fn() + + reportSocketDeadline( + { + kind: 'connect', + armedAtMs: 0, + firedAtMs: CONNECT_TIMEOUT_MS + SUSPENSION_SLACK_MS + 1, + timeoutMs: CONNECT_TIMEOUT_MS + }, + emitLog, + close + ) + + expect(emitLog).toHaveBeenCalledWith( + 'warn', + 'WebSocket connect interrupted', + expect.stringContaining('connection state unknown, re-dialing'), + { code: 'suspended-dial' } + ) + expect(close).toHaveBeenCalledOnce() + }) +}) diff --git a/mobile/src/transport/socket-deadline-suspension.ts b/mobile/src/transport/socket-deadline-suspension.ts new file mode 100644 index 000000000000..a133912efad5 --- /dev/null +++ b/mobile/src/transport/socket-deadline-suspension.ts @@ -0,0 +1,92 @@ +import type { ConnectionDiagnosticCode, ConnectionLogEmitter, ConnectionLogLevel } from './types' + +/** + * A timer that fires this far past its budget was frozen with the process. + * A live 12s connect timeout still lands near its budget, so it stays a host miss. + */ +const SUSPENSION_SLACK_MS = 60_000 + +export type SocketDeadlineKind = 'connect' | 'handshake' + +export type SocketDeadlineInput = { + kind: SocketDeadlineKind + armedAtMs: number + firedAtMs: number + timeoutMs: number + attempt?: number +} + +export type SocketDeadlineReport = { + suspended: boolean + level: ConnectionLogLevel + code: ConnectionDiagnosticCode + title: string + detail: string + consoleMessage: string + consoleFields: { timeoutMs: number; elapsedMs: number; attempt?: number } +} + +export function describeSocketDeadline(input: SocketDeadlineInput): SocketDeadlineReport { + const elapsedMs = input.firedAtMs - input.armedAtMs + const suspended = elapsedMs > input.timeoutMs + SUSPENSION_SLACK_MS + const consoleFields = { + timeoutMs: input.timeoutMs, + elapsedMs, + ...(input.attempt === undefined ? {} : { attempt: input.attempt }) + } + if (suspended) { + return { + suspended: true, + level: 'warn', + code: 'suspended-dial', + title: input.kind === 'connect' ? 'WebSocket connect interrupted' : 'Handshake interrupted', + detail: `App suspended for ${formatSuspendedElapsed(elapsedMs)}; connection state unknown, re-dialing`, + consoleMessage: `[net] ${input.kind} deadline fired after suspension`, + consoleFields + } + } + if (input.kind === 'connect') { + return { + suspended: false, + level: 'error', + code: 'connect-timeout', + title: 'WebSocket connect timeout', + detail: `No TCP/WS handshake within ${input.timeoutMs / 1000}s — endpoint unreachable?`, + consoleMessage: '[net] connect-timeout fired (onopen never arrived)', + consoleFields + } + } + return { + suspended: false, + level: 'error', + code: 'handshake-timeout', + title: 'Handshake timeout', + detail: `No e2ee_ready/e2ee_authenticated within ${input.timeoutMs / 1000}s`, + consoleMessage: '[net] handshake-timeout fired (e2ee_authenticated never arrived)', + consoleFields + } +} + +export function reportSocketDeadline( + input: SocketDeadlineInput, + emitLog: ConnectionLogEmitter, + close: () => void +): void { + const report = describeSocketDeadline(input) + console.log(report.consoleMessage, report.consoleFields) + emitLog(report.level, report.title, report.detail, { code: report.code }) + close() +} + +function formatSuspendedElapsed(elapsedMs: number): string { + const totalMinutes = Math.max(1, Math.round(elapsedMs / 60_000)) + const hours = Math.floor(totalMinutes / 60) + const minutes = totalMinutes % 60 + if (hours > 0 && minutes > 0) { + return `${hours}h${minutes}m` + } + if (hours > 0) { + return `${hours}h` + } + return `${minutes}m` +} diff --git a/mobile/src/transport/types.ts b/mobile/src/transport/types.ts index d9c9271c79d0..4cb2027d3c9a 100644 --- a/mobile/src/transport/types.ts +++ b/mobile/src/transport/types.ts @@ -54,6 +54,7 @@ export type ConnectionDiagnosticCode = | 'network-changed' | 'connect-timeout' | 'handshake-timeout' + | 'suspended-dial' | 'authentication-rejected' | 'socket-closed' | 'liveness-timeout' From 9c2906b4a2e31ba8753e8cfdb273f5d8eb930d1f Mon Sep 17 00:00:00 2001 From: Wooseong Kim Date: Fri, 2 Oct 2026 07:54:22 +0900 Subject: [PATCH 2/3] fix(mobile): do not treat a wall-clock jump as a suspended dial The deadline now keeps a monotonic elapsed time and whether the app left the foreground. A jump while the app stays active remains a host timeout, and leaving the foreground is still suspension even if the wall clock jumps backward. Co-authored-by: Cursor --- .../transport/rpc-client-socket-session.ts | 32 +++---- .../transport/socket-deadline-clock.test.ts | 79 ++++++++++++++++ mobile/src/transport/socket-deadline-clock.ts | 92 +++++++++++++++++++ .../socket-deadline-suspension.test.ts | 46 ++++++++++ .../transport/socket-deadline-suspension.ts | 21 ++++- 5 files changed, 249 insertions(+), 21 deletions(-) create mode 100644 mobile/src/transport/socket-deadline-clock.test.ts create mode 100644 mobile/src/transport/socket-deadline-clock.ts diff --git a/mobile/src/transport/rpc-client-socket-session.ts b/mobile/src/transport/rpc-client-socket-session.ts index c6020c30447c..4ebbf4899713 100644 --- a/mobile/src/transport/rpc-client-socket-session.ts +++ b/mobile/src/transport/rpc-client-socket-session.ts @@ -9,6 +9,12 @@ import { import { isRpcResponse } from './rpc-response-shape' import { isStaleRpcSocketEvent, logRpcSocketClose } from './rpc-socket-close-evidence' import { describeSocketEvent, redactSocketEndpoint } from './socket-event-debug' +import { + releaseSocketTimer, + rememberSocketDeadlineClock, + startSocketDeadlineClock, + takeSocketDeadline +} from './socket-deadline-clock' import { reportSocketDeadline, type SocketDeadlineKind } from './socket-deadline-suspension' import type { ConnectionLogEmitter, ConnectionState, RpcResponse } from './types' import { websocketPayloadToUint8 } from './websocket-payload-bytes' @@ -88,14 +94,8 @@ export class RpcClientSocketSession { } clearTimers(): void { - if (this.connectTimer) { - clearTimeout(this.connectTimer) - this.connectTimer = null - } - if (this.handshakeTimer) { - clearTimeout(this.handshakeTimer) - this.handshakeTimer = null - } + this.connectTimer = releaseSocketTimer(this.connectTimer) + this.handshakeTimer = releaseSocketTimer(this.handshakeTimer) } clearKey(): void { @@ -257,8 +257,8 @@ export class RpcClientSocketSession { } private armSocketDeadline(kind: SocketDeadlineKind, timeoutMs: number): void { - const armedAtMs = Date.now() const timer = setTimeout(() => { + const sample = takeSocketDeadline(timer) if (kind === 'connect') { this.connectTimer = null } else { @@ -275,8 +275,7 @@ export class RpcClientSocketSession { reportSocketDeadline( { kind, - armedAtMs, - firedAtMs: Date.now(), + ...sample, timeoutMs, ...(kind === 'connect' ? { attempt: this.options.getReconnectAttempt() } : {}) }, @@ -284,6 +283,7 @@ export class RpcClientSocketSession { () => this.options.onForcedClose(this) ) }, timeoutMs) + rememberSocketDeadlineClock(timer, startSocketDeadlineClock()) if (kind === 'connect') { this.connectTimer = timer } else { @@ -292,17 +292,11 @@ export class RpcClientSocketSession { } private clearConnectTimer(): void { - if (this.connectTimer) { - clearTimeout(this.connectTimer) - this.connectTimer = null - } + this.connectTimer = releaseSocketTimer(this.connectTimer) } private clearHandshakeTimer(): void { - if (this.handshakeTimer) { - clearTimeout(this.handshakeTimer) - this.handshakeTimer = null - } + this.handshakeTimer = releaseSocketTimer(this.handshakeTimer) } private isStale(eventName: string): boolean { diff --git a/mobile/src/transport/socket-deadline-clock.test.ts b/mobile/src/transport/socket-deadline-clock.test.ts new file mode 100644 index 000000000000..59397aa78210 --- /dev/null +++ b/mobile/src/transport/socket-deadline-clock.test.ts @@ -0,0 +1,79 @@ +import { describe, expect, it, vi } from 'vitest' +import { + releaseSocketTimer, + rememberSocketDeadlineClock, + startSocketDeadlineClock, + takeSocketDeadline +} from './socket-deadline-clock' +import { describeSocketDeadline } from './socket-deadline-suspension' + +const listeners = vi.hoisted(() => new Set<(state: string) => void>()) + +vi.mock('react-native', () => ({ + AppState: { + addEventListener: (_event: string, listener: (state: string) => void) => { + listeners.add(listener) + return { + remove: () => { + listeners.delete(listener) + } + } + } + } +})) + +describe('startSocketDeadlineClock', () => { + it('reports a wall-clock jump while the app stays active as a host timeout', () => { + listeners.clear() + let wallMs = 1_000 + let monotonicMs = 50 + const clock = startSocketDeadlineClock( + () => wallMs, + () => monotonicMs + ) + wallMs += 3 * 60 * 60 * 1000 + monotonicMs += 12_000 + const report = describeSocketDeadline({ + kind: 'connect', + timeoutMs: 12_000, + ...clock.finish() + }) + + expect(report.code).toBe('connect-timeout') + expect(listeners.size).toBe(0) + }) + + it('reports suspension when the app leaves the foreground during the dial', () => { + listeners.clear() + let wallMs = 50_000 + let monotonicMs = 10 + const clock = startSocketDeadlineClock( + () => wallMs, + () => monotonicMs + ) + for (const listener of listeners) { + listener('background') + } + wallMs -= 5_000 + monotonicMs += 12_000 + const report = describeSocketDeadline({ + kind: 'connect', + timeoutMs: 12_000, + ...clock.finish() + }) + + expect(report.code).toBe('suspended-dial') + expect(report.detail).not.toContain('endpoint unreachable') + }) + + it('drops the foreground watch when the timer is cleared', () => { + listeners.clear() + const timer = setTimeout(() => undefined, 60_000) + rememberSocketDeadlineClock(timer, startSocketDeadlineClock()) + expect(listeners.size).toBe(1) + + expect(releaseSocketTimer(timer)).toBeNull() + expect(listeners.size).toBe(0) + expect(takeSocketDeadline(timer).leftForeground).toBe(false) + }) +}) diff --git a/mobile/src/transport/socket-deadline-clock.ts b/mobile/src/transport/socket-deadline-clock.ts new file mode 100644 index 000000000000..955a8a0b4d0d --- /dev/null +++ b/mobile/src/transport/socket-deadline-clock.ts @@ -0,0 +1,92 @@ +import { AppState } from 'react-native' + +export type SocketDeadlineSample = { + armedAtMs: number + firedAtMs: number + monotonicElapsedMs: number + leftForeground: boolean +} + +type DeadlineTimer = ReturnType + +type SocketDeadlineClock = { + finish: () => SocketDeadlineSample +} + +const boundClocks = new Map() + +function defaultMonotonicNow(): number { + if (typeof performance !== 'undefined' && typeof performance.now === 'function') { + return performance.now() + } + return Date.now() +} + +function watchForegroundLoss(onLeave: () => void): () => void { + const subscription = AppState.addEventListener('change', (state) => { + if (state === 'background' || state === 'inactive') { + onLeave() + } + }) + return () => { + subscription.remove() + } +} + +export function startSocketDeadlineClock( + now: () => number = Date.now, + monotonicNow: () => number = defaultMonotonicNow, + watchLeave: (onLeave: () => void) => () => void = watchForegroundLoss +): SocketDeadlineClock { + const armedAtMs = now() + const armedMonotonicMs = monotonicNow() + let leftForeground = false + let stopped = false + const stopWatch = watchLeave(() => { + leftForeground = true + }) + return { + finish() { + if (!stopped) { + stopped = true + stopWatch() + } + return { + armedAtMs, + firedAtMs: now(), + monotonicElapsedMs: monotonicNow() - armedMonotonicMs, + leftForeground + } + } + } +} + +export function rememberSocketDeadlineClock( + timer: DeadlineTimer, + clock: SocketDeadlineClock +): void { + boundClocks.set(timer, clock) +} + +export function takeSocketDeadline(timer: DeadlineTimer): SocketDeadlineSample { + const clock = boundClocks.get(timer) + boundClocks.delete(timer) + if (!clock) { + const firedAtMs = Date.now() + return { + armedAtMs: firedAtMs, + firedAtMs, + monotonicElapsedMs: 0, + leftForeground: false + } + } + return clock.finish() +} + +export function releaseSocketTimer(timer: DeadlineTimer | null): null { + if (timer) { + clearTimeout(timer) + takeSocketDeadline(timer) + } + return null +} diff --git a/mobile/src/transport/socket-deadline-suspension.test.ts b/mobile/src/transport/socket-deadline-suspension.test.ts index 940e5bf8535e..6844c49c67f2 100644 --- a/mobile/src/transport/socket-deadline-suspension.test.ts +++ b/mobile/src/transport/socket-deadline-suspension.test.ts @@ -62,6 +62,52 @@ describe('describeSocketDeadline', () => { expect(report.consoleMessage).not.toContain('connect-timeout') }) + it('keeps a wall-clock jump as a host timeout when the monotonic clock stays on budget', () => { + const armedAtMs = 1_000 + const report = describeSocketDeadline({ + kind: 'connect', + armedAtMs, + firedAtMs: armedAtMs + 3 * 60 * 60 * 1000, + timeoutMs: CONNECT_TIMEOUT_MS, + monotonicElapsedMs: CONNECT_TIMEOUT_MS, + leftForeground: false + }) + + expect(report.suspended).toBe(false) + expect(report.code).toBe('connect-timeout') + }) + + it('still reads a foreground loss as suspension when the wall clock jumps backward', () => { + const armedAtMs = 50_000 + const report = describeSocketDeadline({ + kind: 'connect', + armedAtMs, + firedAtMs: armedAtMs - 5_000, + timeoutMs: CONNECT_TIMEOUT_MS, + monotonicElapsedMs: CONNECT_TIMEOUT_MS, + leftForeground: true + }) + + expect(report.code).toBe('suspended-dial') + expect(report.detail).toBe('App suspended; connection state unknown, re-dialing') + expect(report.detail).not.toContain('endpoint unreachable') + }) + + it('reads suspension when the wall clock and the monotonic clock both run long', () => { + const armedAtMs = 0 + const report = describeSocketDeadline({ + kind: 'connect', + armedAtMs, + firedAtMs: CONNECT_TIMEOUT_MS + SUSPENSION_SLACK_MS + 1, + timeoutMs: CONNECT_TIMEOUT_MS, + monotonicElapsedMs: CONNECT_TIMEOUT_MS + SUSPENSION_SLACK_MS + 1, + leftForeground: false + }) + + expect(report.code).toBe('suspended-dial') + expect(report.detail).toContain('App suspended for') + }) + it('uses the same suspension reading for a frozen handshake timer', () => { const armedAtMs = 0 const report = describeSocketDeadline({ diff --git a/mobile/src/transport/socket-deadline-suspension.ts b/mobile/src/transport/socket-deadline-suspension.ts index a133912efad5..28a935ee161b 100644 --- a/mobile/src/transport/socket-deadline-suspension.ts +++ b/mobile/src/transport/socket-deadline-suspension.ts @@ -14,6 +14,10 @@ export type SocketDeadlineInput = { firedAtMs: number timeoutMs: number attempt?: number + /** Elapsed on a clock that ignores wall-clock steps. Omitted keeps the wall-clock reading. */ + monotonicElapsedMs?: number + /** The app left the foreground while this deadline was armed. */ + leftForeground?: boolean } export type SocketDeadlineReport = { @@ -26,21 +30,34 @@ export type SocketDeadlineReport = { consoleFields: { timeoutMs: number; elapsedMs: number; attempt?: number } } +function elapsedLooksFrozen(elapsedMs: number, timeoutMs: number): boolean { + return elapsedMs > timeoutMs + SUSPENSION_SLACK_MS +} + export function describeSocketDeadline(input: SocketDeadlineInput): SocketDeadlineReport { const elapsedMs = input.firedAtMs - input.armedAtMs - const suspended = elapsedMs > input.timeoutMs + SUSPENSION_SLACK_MS + const wallFrozen = elapsedLooksFrozen(elapsedMs, input.timeoutMs) + const monotonicFrozen = + input.monotonicElapsedMs !== undefined && + elapsedLooksFrozen(input.monotonicElapsedMs, input.timeoutMs) + // A wall-clock step while the app stays up moves only the wall elapsed. + // Suspension still shows up as a foreground loss, or as both clocks running long. + const suspended = + input.leftForeground === true || + (input.monotonicElapsedMs === undefined ? wallFrozen : wallFrozen && monotonicFrozen) const consoleFields = { timeoutMs: input.timeoutMs, elapsedMs, ...(input.attempt === undefined ? {} : { attempt: input.attempt }) } if (suspended) { + const duration = wallFrozen ? ` for ${formatSuspendedElapsed(elapsedMs)}` : '' return { suspended: true, level: 'warn', code: 'suspended-dial', title: input.kind === 'connect' ? 'WebSocket connect interrupted' : 'Handshake interrupted', - detail: `App suspended for ${formatSuspendedElapsed(elapsedMs)}; connection state unknown, re-dialing`, + detail: `App suspended${duration}; connection state unknown, re-dialing`, consoleMessage: `[net] ${input.kind} deadline fired after suspension`, consoleFields } From d2c52a081e0d1b6f3c712a1c40b0ae5d7f12f33a Mon Sep 17 00:00:00 2001 From: Wooseong Kim Date: Sun, 4 Oct 2026 17:46:23 +0900 Subject: [PATCH 3/3] fix(mobile): classify delayed deadlines as suspension --- .../transport/socket-deadline-clock.test.ts | 80 ++++++++++++++++--- mobile/src/transport/socket-deadline-clock.ts | 3 + .../socket-deadline-suspension.test.ts | 22 ++++- .../transport/socket-deadline-suspension.ts | 6 +- 4 files changed, 92 insertions(+), 19 deletions(-) diff --git a/mobile/src/transport/socket-deadline-clock.test.ts b/mobile/src/transport/socket-deadline-clock.test.ts index 59397aa78210..e62ab4691006 100644 --- a/mobile/src/transport/socket-deadline-clock.test.ts +++ b/mobile/src/transport/socket-deadline-clock.test.ts @@ -7,15 +7,21 @@ import { } from './socket-deadline-clock' import { describeSocketDeadline } from './socket-deadline-suspension' -const listeners = vi.hoisted(() => new Set<(state: string) => void>()) +const appState = vi.hoisted(() => ({ + currentState: 'active', + listeners: new Set<(state: string) => void>() +})) vi.mock('react-native', () => ({ AppState: { + get currentState() { + return appState.currentState + }, addEventListener: (_event: string, listener: (state: string) => void) => { - listeners.add(listener) + appState.listeners.add(listener) return { remove: () => { - listeners.delete(listener) + appState.listeners.delete(listener) } } } @@ -24,7 +30,8 @@ vi.mock('react-native', () => ({ describe('startSocketDeadlineClock', () => { it('reports a wall-clock jump while the app stays active as a host timeout', () => { - listeners.clear() + appState.currentState = 'active' + appState.listeners.clear() let wallMs = 1_000 let monotonicMs = 50 const clock = startSocketDeadlineClock( @@ -40,18 +47,19 @@ describe('startSocketDeadlineClock', () => { }) expect(report.code).toBe('connect-timeout') - expect(listeners.size).toBe(0) + expect(appState.listeners.size).toBe(0) }) - it('reports suspension when the app leaves the foreground during the dial', () => { - listeners.clear() + it('keeps a host timeout when a short foreground loss does not delay the clocks', () => { + appState.currentState = 'active' + appState.listeners.clear() let wallMs = 50_000 let monotonicMs = 10 const clock = startSocketDeadlineClock( () => wallMs, () => monotonicMs ) - for (const listener of listeners) { + for (const listener of appState.listeners) { listener('background') } wallMs -= 5_000 @@ -62,18 +70,66 @@ describe('startSocketDeadlineClock', () => { ...clock.finish() }) + expect(report.code).toBe('connect-timeout') + expect(report.detail).toContain('endpoint unreachable') + }) + + it('keeps an on-budget timeout when a transient inactive state has ended', () => { + appState.currentState = 'active' + appState.listeners.clear() + let wallMs = 1_000 + let monotonicMs = 50 + const clock = startSocketDeadlineClock( + () => wallMs, + () => monotonicMs + ) + for (const listener of appState.listeners) { + listener('inactive') + listener('active') + } + wallMs += 12_000 + monotonicMs += 12_000 + + const report = describeSocketDeadline({ + kind: 'connect', + timeoutMs: 12_000, + ...clock.finish() + }) + + expect(report.code).toBe('connect-timeout') + }) + + it('detects suspension when the watcher starts after the app is already backgrounded', () => { + appState.currentState = 'background' + appState.listeners.clear() + let wallMs = 1_000 + let monotonicMs = 50 + const clock = startSocketDeadlineClock( + () => wallMs, + () => monotonicMs + ) + wallMs += 3 * 60 * 60 * 1000 + monotonicMs += 12_000 + + const report = describeSocketDeadline({ + kind: 'handshake', + timeoutMs: 5_000, + ...clock.finish() + }) + expect(report.code).toBe('suspended-dial') - expect(report.detail).not.toContain('endpoint unreachable') + expect(appState.listeners.size).toBe(0) }) it('drops the foreground watch when the timer is cleared', () => { - listeners.clear() + appState.currentState = 'active' + appState.listeners.clear() const timer = setTimeout(() => undefined, 60_000) rememberSocketDeadlineClock(timer, startSocketDeadlineClock()) - expect(listeners.size).toBe(1) + expect(appState.listeners.size).toBe(1) expect(releaseSocketTimer(timer)).toBeNull() - expect(listeners.size).toBe(0) + expect(appState.listeners.size).toBe(0) expect(takeSocketDeadline(timer).leftForeground).toBe(false) }) }) diff --git a/mobile/src/transport/socket-deadline-clock.ts b/mobile/src/transport/socket-deadline-clock.ts index 955a8a0b4d0d..d7f28469ce06 100644 --- a/mobile/src/transport/socket-deadline-clock.ts +++ b/mobile/src/transport/socket-deadline-clock.ts @@ -28,6 +28,9 @@ function watchForegroundLoss(onLeave: () => void): () => void { onLeave() } }) + if (AppState.currentState === 'background' || AppState.currentState === 'inactive') { + onLeave() + } return () => { subscription.remove() } diff --git a/mobile/src/transport/socket-deadline-suspension.test.ts b/mobile/src/transport/socket-deadline-suspension.test.ts index 6844c49c67f2..0226e7bb7e1f 100644 --- a/mobile/src/transport/socket-deadline-suspension.test.ts +++ b/mobile/src/transport/socket-deadline-suspension.test.ts @@ -26,6 +26,20 @@ describe('describeSocketDeadline', () => { }) }) + it('does not classify an on-budget deadline as suspension after foreground loss', () => { + const report = describeSocketDeadline({ + kind: 'connect', + armedAtMs: 1_000, + firedAtMs: 1_000 + CONNECT_TIMEOUT_MS, + timeoutMs: CONNECT_TIMEOUT_MS, + monotonicElapsedMs: CONNECT_TIMEOUT_MS, + leftForeground: true + }) + + expect(report.suspended).toBe(false) + expect(report.code).toBe('connect-timeout') + }) + it('keeps a handshake that fires just past its budget as a handshake timeout', () => { const armedAtMs = 5_000 const report = describeSocketDeadline({ @@ -77,7 +91,7 @@ describe('describeSocketDeadline', () => { expect(report.code).toBe('connect-timeout') }) - it('still reads a foreground loss as suspension when the wall clock jumps backward', () => { + it('does not treat foreground loss and a backward wall-clock step as suspension alone', () => { const armedAtMs = 50_000 const report = describeSocketDeadline({ kind: 'connect', @@ -88,9 +102,9 @@ describe('describeSocketDeadline', () => { leftForeground: true }) - expect(report.code).toBe('suspended-dial') - expect(report.detail).toBe('App suspended; connection state unknown, re-dialing') - expect(report.detail).not.toContain('endpoint unreachable') + expect(report.suspended).toBe(false) + expect(report.code).toBe('connect-timeout') + expect(report.detail).toContain('endpoint unreachable') }) it('reads suspension when the wall clock and the monotonic clock both run long', () => { diff --git a/mobile/src/transport/socket-deadline-suspension.ts b/mobile/src/transport/socket-deadline-suspension.ts index 28a935ee161b..e5f920283797 100644 --- a/mobile/src/transport/socket-deadline-suspension.ts +++ b/mobile/src/transport/socket-deadline-suspension.ts @@ -40,10 +40,10 @@ export function describeSocketDeadline(input: SocketDeadlineInput): SocketDeadli const monotonicFrozen = input.monotonicElapsedMs !== undefined && elapsedLooksFrozen(input.monotonicElapsedMs, input.timeoutMs) - // A wall-clock step while the app stays up moves only the wall elapsed. - // Suspension still shows up as a foreground loss, or as both clocks running long. + // A foreground loss supports suspension only when at least one clock also ran long. + // Without an AppState event, both clocks must run long to distinguish a wall-clock step. const suspended = - input.leftForeground === true || + (input.leftForeground === true && (wallFrozen || monotonicFrozen)) || (input.monotonicElapsedMs === undefined ? wallFrozen : wallFrozen && monotonicFrozen) const consoleFields = { timeoutMs: input.timeoutMs,