diff --git a/.changeset/heartbeat-blocking-phase.md b/.changeset/heartbeat-blocking-phase.md new file mode 100644 index 00000000..c64321a3 --- /dev/null +++ b/.changeset/heartbeat-blocking-phase.md @@ -0,0 +1,8 @@ +--- +'@react-native-harness/bridge': patch +'@react-native-harness/runtime': patch +'@react-native-harness/config': minor +'@react-native-harness/jest': patch +--- + +Stop test runs from failing with `app heartbeat timed out` while the app is evaluating a large test bundle. The runtime now tells the bridge it is about to block the JS thread before the synchronous `eval()` of a bundled module, and the bridge suspends the heartbeat for that phase (bounded, so a real crash is still detected). Heartbeat timing is also configurable via the new `heartbeatInterval` and `heartbeatTimeout` options, and the timeout error now explains that a blocked JS thread — not only a crash — can cause it. diff --git a/actions/shared/index.cjs b/actions/shared/index.cjs index cee93346..fcfed0be 100644 --- a/actions/shared/index.cjs +++ b/actions/shared/index.cjs @@ -4448,6 +4448,8 @@ var ConfigSchema = external_exports.object({ metroPort: external_exports.number().int("Metro port must be an integer").min(1, "Metro port must be at least 1").max(65535, "Metro port must be at most 65535").optional().default(DEFAULT_METRO_PORT), webSocketPort: external_exports.number().optional().describe("Deprecated. Bridge traffic now uses metroPort and this value is ignored."), bridgeTimeout: external_exports.number().min(1e3, "Bridge timeout must be at least 1 second").default(6e4), + heartbeatInterval: external_exports.number().min(100, "Heartbeat interval must be at least 100ms").default(5e3).describe("How often the harness pings the app to check that its JS thread is still alive."), + heartbeatTimeout: external_exports.number().min(1e3, "Heartbeat timeout must be at least 1 second").default(2e4).describe("How long the app may go without answering a heartbeat ping before the run fails as unresponsive. The harness suspends the heartbeat around phases the app reports as blocking (such as evaluating a test bundle), so raise this only if a run still times out with no crash report."), testTimeout: external_exports.number().min(1e3, "Test timeout must be at least 1 second").default(5e3), platformReadyTimeout: external_exports.number().min(1e3, "Platform ready timeout must be at least 1 second").default(3e5), bundleStartTimeout: external_exports.number().min(1e3, "Bundle start timeout must be at least 1 second").default(6e4), diff --git a/actions/shared/plan-restore.cjs b/actions/shared/plan-restore.cjs index 3525d74c..c81a8118 100644 --- a/actions/shared/plan-restore.cjs +++ b/actions/shared/plan-restore.cjs @@ -4782,6 +4782,8 @@ var ConfigSchema = external_exports.object({ metroPort: external_exports.number().int("Metro port must be an integer").min(1, "Metro port must be at least 1").max(65535, "Metro port must be at most 65535").optional().default(DEFAULT_METRO_PORT), webSocketPort: external_exports.number().optional().describe("Deprecated. Bridge traffic now uses metroPort and this value is ignored."), bridgeTimeout: external_exports.number().min(1e3, "Bridge timeout must be at least 1 second").default(6e4), + heartbeatInterval: external_exports.number().min(100, "Heartbeat interval must be at least 100ms").default(5e3).describe("How often the harness pings the app to check that its JS thread is still alive."), + heartbeatTimeout: external_exports.number().min(1e3, "Heartbeat timeout must be at least 1 second").default(2e4).describe("How long the app may go without answering a heartbeat ping before the run fails as unresponsive. The harness suspends the heartbeat around phases the app reports as blocking (such as evaluating a test bundle), so raise this only if a run still times out with no crash report."), testTimeout: external_exports.number().min(1e3, "Test timeout must be at least 1 second").default(5e3), platformReadyTimeout: external_exports.number().min(1e3, "Platform ready timeout must be at least 1 second").default(3e5), bundleStartTimeout: external_exports.number().min(1e3, "Bundle start timeout must be at least 1 second").default(6e4), diff --git a/actions/shared/plan-save.cjs b/actions/shared/plan-save.cjs index 5e69267e..c0acc2ca 100644 --- a/actions/shared/plan-save.cjs +++ b/actions/shared/plan-save.cjs @@ -4782,6 +4782,8 @@ var ConfigSchema = external_exports.object({ metroPort: external_exports.number().int("Metro port must be an integer").min(1, "Metro port must be at least 1").max(65535, "Metro port must be at most 65535").optional().default(DEFAULT_METRO_PORT), webSocketPort: external_exports.number().optional().describe("Deprecated. Bridge traffic now uses metroPort and this value is ignored."), bridgeTimeout: external_exports.number().min(1e3, "Bridge timeout must be at least 1 second").default(6e4), + heartbeatInterval: external_exports.number().min(100, "Heartbeat interval must be at least 100ms").default(5e3).describe("How often the harness pings the app to check that its JS thread is still alive."), + heartbeatTimeout: external_exports.number().min(1e3, "Heartbeat timeout must be at least 1 second").default(2e4).describe("How long the app may go without answering a heartbeat ping before the run fails as unresponsive. The harness suspends the heartbeat around phases the app reports as blocking (such as evaluating a test bundle), so raise this only if a run still times out with no crash report."), testTimeout: external_exports.number().min(1e3, "Test timeout must be at least 1 second").default(5e3), platformReadyTimeout: external_exports.number().min(1e3, "Platform ready timeout must be at least 1 second").default(3e5), bundleStartTimeout: external_exports.number().min(1e3, "Bundle start timeout must be at least 1 second").default(6e4), diff --git a/actions/shared/snapshot-metro.cjs b/actions/shared/snapshot-metro.cjs index c39358e8..fd41a55e 100644 --- a/actions/shared/snapshot-metro.cjs +++ b/actions/shared/snapshot-metro.cjs @@ -4705,6 +4705,8 @@ var ConfigSchema = external_exports.object({ metroPort: external_exports.number().int("Metro port must be an integer").min(1, "Metro port must be at least 1").max(65535, "Metro port must be at most 65535").optional().default(DEFAULT_METRO_PORT), webSocketPort: external_exports.number().optional().describe("Deprecated. Bridge traffic now uses metroPort and this value is ignored."), bridgeTimeout: external_exports.number().min(1e3, "Bridge timeout must be at least 1 second").default(6e4), + heartbeatInterval: external_exports.number().min(100, "Heartbeat interval must be at least 100ms").default(5e3).describe("How often the harness pings the app to check that its JS thread is still alive."), + heartbeatTimeout: external_exports.number().min(1e3, "Heartbeat timeout must be at least 1 second").default(2e4).describe("How long the app may go without answering a heartbeat ping before the run fails as unresponsive. The harness suspends the heartbeat around phases the app reports as blocking (such as evaluating a test bundle), so raise this only if a run still times out with no crash report."), testTimeout: external_exports.number().min(1e3, "Test timeout must be at least 1 second").default(5e3), platformReadyTimeout: external_exports.number().min(1e3, "Platform ready timeout must be at least 1 second").default(3e5), bundleStartTimeout: external_exports.number().min(1e3, "Bundle start timeout must be at least 1 second").default(6e4), diff --git a/packages/bridge/src/__tests__/heartbeat.test.ts b/packages/bridge/src/__tests__/heartbeat.test.ts index e32a2973..f3481066 100644 --- a/packages/bridge/src/__tests__/heartbeat.test.ts +++ b/packages/bridge/src/__tests__/heartbeat.test.ts @@ -44,4 +44,92 @@ describe('bridge heartbeat', () => { heartbeat.dispose(); vi.useRealTimers(); }); + + it('does not time out while suspended for a blocking phase', () => { + vi.useFakeTimers(); + + const sendPing = vi.fn(); + const onTimeout = vi.fn(); + const heartbeat = createHeartbeat({ + sendPing, + onTimeout, + intervalMs: 5, + timeoutMs: 10, + maxSuspendMs: 1_000, + }); + + // A ping is already in flight when the app announces it is about to block. + vi.advanceTimersByTime(5); + expect(sendPing).toHaveBeenCalledTimes(1); + + heartbeat.suspend(); + vi.advanceTimersByTime(500); + + expect(onTimeout).not.toHaveBeenCalled(); + expect(sendPing).toHaveBeenCalledTimes(1); + + // Pinging restarts once the blocking phase is over, and the app gets a + // full timeout window to answer the next ping. + heartbeat.resume(); + vi.advanceTimersByTime(5); + expect(sendPing).toHaveBeenLastCalledWith(2); + + heartbeat.notifyPong(2); + vi.advanceTimersByTime(5); + expect(onTimeout).not.toHaveBeenCalled(); + + heartbeat.dispose(); + vi.useRealTimers(); + }); + + it('resumes on its own if the app never reports the blocking phase ended', () => { + vi.useFakeTimers(); + + const onSuspendExpired = vi.fn(); + const onTimeout = vi.fn(); + const heartbeat = createHeartbeat({ + sendPing: vi.fn(), + onTimeout, + onSuspendExpired, + intervalMs: 5, + timeoutMs: 10, + maxSuspendMs: 100, + }); + + heartbeat.suspend(); + expect(heartbeat.suspended).toBe(true); + + vi.advanceTimersByTime(100); + expect(onSuspendExpired).toHaveBeenCalledTimes(1); + expect(heartbeat.suspended).toBe(false); + + // Still blocked: liveness detection is back and the session fails as before. + vi.advanceTimersByTime(15); + expect(onTimeout).toHaveBeenCalledTimes(1); + + heartbeat.dispose(); + vi.useRealTimers(); + }); + + it('ignores suspend and resume after disposal', () => { + vi.useFakeTimers(); + + const sendPing = vi.fn(); + const heartbeat = createHeartbeat({ + sendPing, + onTimeout: vi.fn(), + intervalMs: 5, + timeoutMs: 10, + }); + + heartbeat.dispose(); + heartbeat.suspend(); + heartbeat.resume(); + vi.advanceTimersByTime(50); + + expect(sendPing).not.toHaveBeenCalled(); + expect(heartbeat.suspended).toBe(false); + + vi.useRealTimers(); + }); }); diff --git a/packages/bridge/src/__tests__/protocol.test.ts b/packages/bridge/src/__tests__/protocol.test.ts index 9a26d628..e1b788a1 100644 --- a/packages/bridge/src/__tests__/protocol.test.ts +++ b/packages/bridge/src/__tests__/protocol.test.ts @@ -43,6 +43,30 @@ describe('bridge protocol', () => { }); }); + it('round-trips busy messages', () => { + const raw = serializeBridgeMessage({ + type: 'busy', + busy: true, + label: 'evaluating example.harness.tsx', + }); + + expect(parseBridgeMessage(raw)).toEqual({ + type: 'busy', + busy: true, + label: 'evaluating example.harness.tsx', + }); + + expect( + parseBridgeMessage(serializeBridgeMessage({ type: 'busy', busy: false })), + ).toEqual({ type: 'busy', busy: false }); + }); + + it('rejects busy messages without a boolean flag', () => { + expect(() => parseBridgeMessage('{"type":"busy","busy":"yes"}')).toThrow( + 'Invalid bridge message: busy must be a boolean', + ); + }); + it('rejects malformed messages', () => { expect(() => parseBridgeMessage('{"type":"invoke","id":"1"}')).toThrow( 'Invalid bridge message: id must be a number', diff --git a/packages/bridge/src/client.ts b/packages/bridge/src/client.ts index 02d019a4..d6d2bf29 100644 --- a/packages/bridge/src/client.ts +++ b/packages/bridge/src/client.ts @@ -35,6 +35,15 @@ export type HarnessHandle = { options: ImageSnapshotOptions, runner: string, ) => Promise<{ pass: boolean; message: string }>; + /** + * Tell the harness that the JS thread is about to block (or has stopped + * blocking). Heartbeat pings cannot be answered from a blocked thread, so + * the server suspends the heartbeat for the duration. + * + * Must be called *before* the blocking work starts, and the caller must yield + * to the event loop afterwards so the message actually reaches the socket. + */ + setBusy: (busy: boolean, label?: string) => void; disconnect: () => void; }; @@ -192,6 +201,13 @@ export const connectToHarness = ( options, runner, ), + setBusy: (busy, label) => { + if (transport.state !== 'open') { + return; + } + + transport.send(serializeBridgeMessage({ type: 'busy', busy, label })); + }, disconnect: () => { closePeer(new Error('Harness connection closed by client')); transport.close(); diff --git a/packages/bridge/src/errors.ts b/packages/bridge/src/errors.ts index b70b5c9b..91849585 100644 --- a/packages/bridge/src/errors.ts +++ b/packages/bridge/src/errors.ts @@ -24,7 +24,7 @@ const appBridgeDisconnectedMessage = ( case 'app-replaced': return 'The app bridge was replaced by a newer app connection. This can happen when the app reloads, restarts, or reconnects while a test file is still running.'; case 'heartbeat-timeout': - return 'The app bridge stopped responding during test execution. This can happen if the app was killed, crashed, became unresponsive, or lost its WebSocket connection.'; + return 'The app stopped answering harness heartbeats during test execution. The connection itself stayed open, so the most likely cause is a blocked JS thread — for example evaluating a very large test bundle — but the app may also have been killed, crashed, or lost its WebSocket connection. If no crash report was written to .harness/crash-reports, the app did not crash; raise `heartbeatTimeout` in your harness config to give the JS thread more room.'; case 'socket-error': return 'The app bridge connection failed during test execution. This can happen if the app was killed, crashed, or the underlying WebSocket connection closed unexpectedly.'; case 'bridge-disposed': @@ -35,8 +35,15 @@ const appBridgeDisconnectedMessage = ( }; export class AppBridgeDisconnectedError extends HarnessError { - constructor(public readonly reason: AppBridgeDisconnectedReason) { - super(appBridgeDisconnectedMessage(reason)); + constructor( + public readonly reason: AppBridgeDisconnectedReason, + public readonly detail?: string + ) { + super( + detail + ? `${appBridgeDisconnectedMessage(reason)} ${detail}` + : appBridgeDisconnectedMessage(reason) + ); this.name = 'AppBridgeDisconnectedError'; this.stack = `${this.name}: ${this.message}`; } diff --git a/packages/bridge/src/heartbeat.ts b/packages/bridge/src/heartbeat.ts index 17d3b9f8..cd83ac43 100644 --- a/packages/bridge/src/heartbeat.ts +++ b/packages/bridge/src/heartbeat.ts @@ -1,8 +1,22 @@ export const DEFAULT_HEARTBEAT_INTERVAL_MS = 5_000; export const DEFAULT_HEARTBEAT_TIMEOUT_MS = 20_000; +/** + * Upper bound on how long a single `suspend()` may silence the heartbeat. + * Suspension is driven by the app (see `BridgeBusyMessage`), so a crash or a + * lost `busy: false` message must not disable liveness detection forever. + */ +export const DEFAULT_HEARTBEAT_MAX_SUSPEND_MS = 300_000; export type BridgeHeartbeat = { notifyPong: (id: number) => void; + /** + * Stop pinging and drop any in-flight ping. Used while the app reports that + * it is blocking its JS thread and therefore cannot answer. Automatically + * lifted after `maxSuspendMs`. + */ + suspend: () => void; + resume: () => void; + readonly suspended: boolean; dispose: () => void; }; @@ -11,13 +25,18 @@ export const createHeartbeat = (options: { onTimeout: () => void; intervalMs?: number; timeoutMs?: number; + maxSuspendMs?: number; + onSuspendExpired?: () => void; }): BridgeHeartbeat => { const intervalMs = options.intervalMs ?? DEFAULT_HEARTBEAT_INTERVAL_MS; const timeoutMs = options.timeoutMs ?? DEFAULT_HEARTBEAT_TIMEOUT_MS; + const maxSuspendMs = options.maxSuspendMs ?? DEFAULT_HEARTBEAT_MAX_SUSPEND_MS; let nextPingId = 1; let pendingPingId: number | null = null; let disposed = false; + let suspended = false; let timeoutHandle: ReturnType | null = null; + let suspendHandle: ReturnType | null = null; const clearPendingTimeout = () => { if (timeoutHandle) { @@ -26,8 +45,15 @@ export const createHeartbeat = (options: { } }; + const clearSuspendTimeout = () => { + if (suspendHandle) { + clearTimeout(suspendHandle); + suspendHandle = null; + } + }; + const intervalHandle = setInterval(() => { - if (disposed || pendingPingId !== null) { + if (disposed || suspended || pendingPingId !== null) { return; } @@ -45,6 +71,18 @@ export const createHeartbeat = (options: { }, timeoutMs); }, intervalMs); + const resume = () => { + if (disposed || !suspended) { + return; + } + + clearSuspendTimeout(); + suspended = false; + // Any ping sent before the suspension is unanswerable by now; start clean + // so the app gets a full `timeoutMs` to reply to the next one. + pendingPingId = null; + }; + return { notifyPong: (id) => { if (id !== pendingPingId) { @@ -54,6 +92,28 @@ export const createHeartbeat = (options: { pendingPingId = null; clearPendingTimeout(); }, + suspend: () => { + if (disposed || suspended) { + return; + } + + suspended = true; + pendingPingId = null; + clearPendingTimeout(); + suspendHandle = setTimeout(() => { + suspendHandle = null; + if (disposed || !suspended) { + return; + } + + options.onSuspendExpired?.(); + resume(); + }, maxSuspendMs); + }, + resume, + get suspended() { + return suspended; + }, dispose: () => { if (disposed) { return; @@ -62,6 +122,7 @@ export const createHeartbeat = (options: { disposed = true; clearInterval(intervalHandle); clearPendingTimeout(); + clearSuspendTimeout(); }, }; }; diff --git a/packages/bridge/src/protocol.ts b/packages/bridge/src/protocol.ts index 6d3b9e32..7e211515 100644 --- a/packages/bridge/src/protocol.ts +++ b/packages/bridge/src/protocol.ts @@ -48,10 +48,23 @@ export type BridgePongMessage = { id: number; }; +/** + * Sent by the app right before (and right after) a phase that blocks the JS + * thread, such as the synchronous `eval()` of a freshly bundled test module. + * While the app is busy it cannot answer pings, so the server suspends the + * heartbeat instead of treating the silence as a dead app. + */ +export type BridgeBusyMessage = { + type: 'busy'; + busy: boolean; + label?: string; +}; + export type BridgeControlMessage = | BridgeReadyMessage | BridgePingMessage - | BridgePongMessage; + | BridgePongMessage + | BridgeBusyMessage; export type BridgeMessage = | BridgeInvokeMessage @@ -176,6 +189,17 @@ export const parseBridgeMessage = (raw: string): BridgeMessage => { readNumber(parsed.id, 'id'); return parsed as BridgePingMessage | BridgePongMessage; } + case 'busy': { + if (typeof parsed.busy !== 'boolean') { + throw new Error('Invalid bridge message: busy must be a boolean'); + } + + if (parsed.label !== undefined) { + readString(parsed.label, 'label'); + } + + return parsed as BridgeBusyMessage; + } default: throw new Error(`Invalid bridge message: unknown type ${messageType}`); } diff --git a/packages/bridge/src/rpc-peer.ts b/packages/bridge/src/rpc-peer.ts index ed0dbe58..3ca5a1f6 100644 --- a/packages/bridge/src/rpc-peer.ts +++ b/packages/bridge/src/rpc-peer.ts @@ -219,6 +219,7 @@ export const createRpcPeer = < case 'ready': case 'ping': case 'pong': + case 'busy': return message; } }, diff --git a/packages/bridge/src/server.ts b/packages/bridge/src/server.ts index 990e221e..d45dcff5 100644 --- a/packages/bridge/src/server.ts +++ b/packages/bridge/src/server.ts @@ -58,8 +58,18 @@ type TransportOptions = | { port: number; host?: string } | { server: HttpServer | HttpsServer; path?: string }; +export type HarnessBridgeHeartbeatOptions = { + /** How often to ping the app. Defaults to 5s. */ + intervalMs?: number; + /** How long to wait for a pong before declaring the app unresponsive. Defaults to 20s. */ + timeoutMs?: number; + /** Upper bound on a single app-requested heartbeat suspension. Defaults to 5min. */ + maxSuspendMs?: number; +}; + export type HarnessBridgeOptions = TransportOptions & { timeout?: number; + heartbeat?: HarnessBridgeHeartbeatOptions; context: HarnessContext; }; @@ -111,7 +121,7 @@ const receiveScreenshot = async ( export const createHarnessBridge = async ( options: HarnessBridgeOptions, ): Promise => { - const { timeout, context, ...transportOptions } = options; + const { timeout, heartbeat: heartbeatOptions, context, ...transportOptions } = options; const wss = await createWss(transportOptions); bridgeLogger.debug('bridge server ready'); @@ -167,13 +177,33 @@ export const createHarnessBridge = async ( }, }); + // Tracks the app-reported blocking phase (see `BridgeBusyMessage`), so a + // heartbeat timeout can name what the JS thread was busy with. + let busyLabel: string | null = null; + const heartbeat = createHeartbeat({ + intervalMs: heartbeatOptions?.intervalMs, + timeoutMs: heartbeatOptions?.timeoutMs, + maxSuspendMs: heartbeatOptions?.maxSuspendMs, sendPing: (id) => { transport.send(serializeBridgeMessage({ type: 'ping', id })); }, + onSuspendExpired: () => { + bridgeLogger.warn( + 'app has been busy for too long%s, resuming heartbeat', + busyLabel ? ` (${busyLabel})` : '', + ); + }, onTimeout: () => { bridgeLogger.warn('app heartbeat timed out'); - disconnect(new AppBridgeDisconnectedError('heartbeat-timeout')); + disconnect( + new AppBridgeDisconnectedError( + 'heartbeat-timeout', + busyLabel + ? `The app last reported it was busy with: ${busyLabel}.` + : undefined, + ), + ); }, }); @@ -251,6 +281,24 @@ export const createHarnessBridge = async ( heartbeat.notifyPong(controlMessage.id); return; } + case 'busy': { + if (controlMessage.busy) { + busyLabel = controlMessage.label ?? null; + bridgeLogger.debug( + 'app entering blocking phase%s, suspending heartbeat', + busyLabel ? `: ${busyLabel}` : '', + ); + heartbeat.suspend(); + } else { + bridgeLogger.debug( + 'app left blocking phase%s, resuming heartbeat', + busyLabel ? `: ${busyLabel}` : '', + ); + busyLabel = null; + heartbeat.resume(); + } + return; + } } }; diff --git a/packages/cli/src/__tests__/jest-platform-ignore-pattern.test.ts b/packages/cli/src/__tests__/jest-platform-ignore-pattern.test.ts index 6b3d19a3..6f9f39b7 100644 --- a/packages/cli/src/__tests__/jest-platform-ignore-pattern.test.ts +++ b/packages/cli/src/__tests__/jest-platform-ignore-pattern.test.ts @@ -33,6 +33,8 @@ const makeConfig = (): Config => ({ metroPort: 8081, webSocketPort: undefined, bridgeTimeout: 60000, + heartbeatInterval: 5000, + heartbeatTimeout: 20000, testTimeout: 5000, platformReadyTimeout: 300000, bundleStartTimeout: 60000, diff --git a/packages/cli/src/__tests__/platform-commands.test.ts b/packages/cli/src/__tests__/platform-commands.test.ts index 41486e2b..4090fdff 100644 --- a/packages/cli/src/__tests__/platform-commands.test.ts +++ b/packages/cli/src/__tests__/platform-commands.test.ts @@ -44,6 +44,8 @@ describe('platform CLI command discovery', () => { metroPort: 8081, webSocketPort: undefined, bridgeTimeout: 60000, + heartbeatInterval: 5000, + heartbeatTimeout: 20000, testTimeout: 5000, platformReadyTimeout: 300000, bundleStartTimeout: 60000, @@ -109,6 +111,8 @@ describe('platform CLI command discovery', () => { metroPort: 8081, webSocketPort: undefined, bridgeTimeout: 60000, + heartbeatInterval: 5000, + heartbeatTimeout: 20000, testTimeout: 5000, platformReadyTimeout: 300000, bundleStartTimeout: 60000, @@ -152,6 +156,8 @@ describe('platform CLI command discovery', () => { metroPort: 8081, webSocketPort: undefined, bridgeTimeout: 60000, + heartbeatInterval: 5000, + heartbeatTimeout: 20000, testTimeout: 5000, platformReadyTimeout: 300000, bundleStartTimeout: 60000, @@ -217,6 +223,8 @@ describe('platform CLI command discovery', () => { metroPort: 8081, webSocketPort: undefined, bridgeTimeout: 60000, + heartbeatInterval: 5000, + heartbeatTimeout: 20000, testTimeout: 5000, platformReadyTimeout: 300000, bundleStartTimeout: 60000, diff --git a/packages/config/src/types.ts b/packages/config/src/types.ts index 3a4eb1d0..663b859d 100644 --- a/packages/config/src/types.ts +++ b/packages/config/src/types.ts @@ -56,6 +56,24 @@ export const ConfigSchema = z .min(1000, 'Bridge timeout must be at least 1 second') .default(60000), + heartbeatInterval: z + .number() + .min(100, 'Heartbeat interval must be at least 100ms') + .default(5000) + .describe( + 'How often the harness pings the app to check that its JS thread is still alive.' + ), + + heartbeatTimeout: z + .number() + .min(1000, 'Heartbeat timeout must be at least 1 second') + .default(20000) + .describe( + 'How long the app may go without answering a heartbeat ping before the run fails as unresponsive. ' + + 'The harness suspends the heartbeat around phases the app reports as blocking (such as evaluating a ' + + 'test bundle), so raise this only if a run still times out with no crash report.' + ), + testTimeout: z .number() .min(1000, 'Test timeout must be at least 1 second') diff --git a/packages/jest/src/__tests__/bridge.test.ts b/packages/jest/src/__tests__/bridge.test.ts index af61c426..c3019a43 100644 --- a/packages/jest/src/__tests__/bridge.test.ts +++ b/packages/jest/src/__tests__/bridge.test.ts @@ -6,8 +6,14 @@ import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest'; import type { HarnessBridge } from '@react-native-harness/bridge/server'; import { createHarnessBridge } from '@react-native-harness/bridge/server'; -import { connectToHarness } from '@react-native-harness/bridge/client'; -import type { HarnessContext } from '@react-native-harness/bridge'; +import { + connectToHarness, + createWebSocketClientTransport, +} from '@react-native-harness/bridge/client'; +import type { + BridgeTransport, + HarnessContext, +} from '@react-native-harness/bridge'; import type { TestSuiteResult } from '@react-native-harness/bridge'; const makeContext = (): HarnessContext => ({ @@ -211,6 +217,166 @@ describe('bridge: createHarnessBridge + connectToHarness', () => { }); }); + describe('heartbeat and blocking phases', () => { + /** + * Simulates an app whose JS thread is blocked: the socket stays open, but + * no `pong` is produced. A real app blocks inside the synchronous `eval()` + * of a freshly bundled test module, which can easily outlast the heartbeat + * timeout on a large module graph. We cannot block the event loop here -- + * server and client share it in this test -- so we drop the pongs instead. + */ + const connectBlockable = async ( + port: number, + callbacks: Parameters[1], + ) => { + const inner = createWebSocketClientTransport(`ws://127.0.0.1:${port}`); + let jsThreadBlocked = false; + + const transport: BridgeTransport = { + get state() { + return inner.state; + }, + send: (message) => { + if ( + jsThreadBlocked && + typeof message === 'string' && + (JSON.parse(message) as { type: string }).type === 'pong' + ) { + return; + } + + inner.send(message); + }, + close: (code, reason) => inner.close(code, reason), + onOpen: (listener) => inner.onOpen(listener), + onMessage: (listener) => inner.onMessage(listener), + onClose: (listener) => inner.onClose(listener), + onError: (listener) => inner.onError(listener), + }; + + const handle = await connectToHarness( + `ws://127.0.0.1:${port}`, + callbacks, + { transport }, + ); + + return { + handle, + blockJsThread: () => { + jsThreadBlocked = true; + }, + unblockJsThread: () => { + jsThreadBlocked = false; + }, + }; + }; + + const createHeartbeatBridge = () => + createHarnessBridge({ + port: 0, + heartbeat: { intervalMs: 20, timeoutMs: 60, maxSuspendMs: 5_000 }, + context: makeContext(), + }); + + const suiteResult: TestSuiteResult = { + name: 'suite', + tests: [{ name: 'passes', status: 'passed', duration: 1 }], + suites: [], + status: 'passed', + duration: 1, + }; + + it('fails the run when the app goes silent without announcing a blocking phase', async () => { + const hbBridge = await createHeartbeatBridge(); + const port = (hbBridge.ws.address() as { port: number }).port; + + try { + const app = await connectBlockable(port, { + runTests: async () => { + app.blockJsThread(); + await new Promise((r) => setTimeout(r, 300)); + return suiteResult; + }, + resetEnvironment: vi.fn(), + }); + app.handle.reportReady(device); + + const conn = await hbBridge.nextConnection(); + + await expect( + conn.runTests('example.ts', { runner: '/runner.js' }), + ).rejects.toThrow('The app stopped answering harness heartbeats'); + } finally { + hbBridge.dispose(); + } + }); + + it('completes the run when the app announces the blocking phase first', async () => { + const hbBridge = await createHeartbeatBridge(); + const port = (hbBridge.ws.address() as { port: number }).port; + + try { + const app = await connectBlockable(port, { + runTests: async () => { + // Sent *before* the thread blocks, exactly as the runtime does + // around `eval()` of a bundled module. + app.handle.setBusy(true, 'evaluating example.harness.tsx'); + app.blockJsThread(); + // Several heartbeat timeouts' worth of silence. + await new Promise((r) => setTimeout(r, 300)); + app.unblockJsThread(); + app.handle.setBusy(false); + return suiteResult; + }, + resetEnvironment: vi.fn(), + }); + app.handle.reportReady(device); + + const conn = await hbBridge.nextConnection(); + const result = await conn.runTests('example.ts', { + runner: '/runner.js', + }); + + expect(result.tests[0].name).toBe('passes'); + app.handle.disconnect(); + } finally { + hbBridge.dispose(); + } + }); + + it('names the blocking phase when the app stays blocked past the suspension limit', async () => { + const hbBridge = await createHarnessBridge({ + port: 0, + heartbeat: { intervalMs: 20, timeoutMs: 60, maxSuspendMs: 100 }, + context: makeContext(), + }); + const port = (hbBridge.ws.address() as { port: number }).port; + + try { + const app = await connectBlockable(port, { + runTests: async () => { + app.handle.setBusy(true, 'evaluating example.harness.tsx'); + app.blockJsThread(); + await new Promise((r) => setTimeout(r, 1_000)); + return suiteResult; + }, + resetEnvironment: vi.fn(), + }); + app.handle.reportReady(device); + + const conn = await hbBridge.nextConnection(); + + await expect( + conn.runTests('example.ts', { runner: '/runner.js' }), + ).rejects.toThrow( + 'The app last reported it was busy with: evaluating example.harness.tsx.', + ); + } finally { + hbBridge.dispose(); + } + }); + }); + describe('dispose', () => { it('rejects pending nextConnection() waiters', async () => { const pending = bridge.nextConnection(); diff --git a/packages/jest/src/harness-session.ts b/packages/jest/src/harness-session.ts index aab2a6ef..088cdd9f 100644 --- a/packages/jest/src/harness-session.ts +++ b/packages/jest/src/harness-session.ts @@ -601,6 +601,10 @@ export const createHarnessSession = async ( createHarnessBridge({ noServer: true, timeout: runtimeConfig.bridgeTimeout, + heartbeat: { + intervalMs: runtimeConfig.heartbeatInterval, + timeoutMs: runtimeConfig.heartbeatTimeout, + }, context, }) ); diff --git a/packages/runtime/src/bundler/evaluate.test.ts b/packages/runtime/src/bundler/evaluate.test.ts new file mode 100644 index 00000000..14da9179 --- /dev/null +++ b/packages/runtime/src/bundler/evaluate.test.ts @@ -0,0 +1,62 @@ +import { afterEach, describe, expect, it, vi } from 'vitest'; +// `vi.mock` is hoisted above this import by Vitest. +import { evaluateModuleAsync } from './evaluate.js'; + +const mocks = vi.hoisted(() => ({ + handle: null as { setBusy: ReturnType } | null, +})); + +vi.mock('../client/store.js', () => ({ + tryGetHandle: () => mocks.handle, +})); + +const MODULE_JS = 'globalThis.__evaluated = (globalThis.__evaluated ?? 0) + 1; __r(0);'; + +afterEach(() => { + mocks.handle = null; + delete (globalThis as Record).__evaluated; + delete (globalThis as Record).__resetModule; + delete (globalThis as Record).__r; +}); + +describe('evaluateModuleAsync', () => { + it('announces the blocking phase before evaluating and clears it after', async () => { + const setBusy = vi.fn(); + mocks.handle = { setBusy }; + (globalThis as Record).__resetModule = vi.fn(); + (globalThis as Record).__r = vi.fn(); + + await evaluateModuleAsync(MODULE_JS, 'example.harness.tsx'); + + expect((globalThis as Record).__evaluated).toBe(1); + expect(setBusy.mock.calls).toEqual([ + [true, 'evaluating example.harness.tsx'], + [false], + ]); + }); + + it('clears the blocking phase even when evaluation throws', async () => { + const setBusy = vi.fn(); + mocks.handle = { setBusy }; + (globalThis as Record).__resetModule = vi.fn(); + (globalThis as Record).__r = vi.fn(); + + await expect( + evaluateModuleAsync('no require calls here', 'example.harness.tsx'), + ).rejects.toThrow(); + + expect(setBusy.mock.calls).toEqual([ + [true, 'evaluating example.harness.tsx'], + [false], + ]); + }); + + it('evaluates without a bridge handle', async () => { + (globalThis as Record).__resetModule = vi.fn(); + (globalThis as Record).__r = vi.fn(); + + await evaluateModuleAsync(MODULE_JS, 'example.harness.tsx'); + + expect((globalThis as Record).__evaluated).toBe(1); + }); +}); diff --git a/packages/runtime/src/bundler/evaluate.ts b/packages/runtime/src/bundler/evaluate.ts index 2546a355..c78c8faa 100644 --- a/packages/runtime/src/bundler/evaluate.ts +++ b/packages/runtime/src/bundler/evaluate.ts @@ -1,5 +1,45 @@ +import { tryGetHandle } from '../client/store.js'; import { MalformedModuleError } from './errors.js'; +/** + * Yield to the host so queued native calls (notably the `busy` bridge message) + * are flushed before we block the JS thread. On React Native a `setTimeout` + * boundary is what returns control to native and drains the message queue -- + * anything sent in the same tick as a blocking `eval()` would otherwise sit in + * the queue until the `eval()` finishes, which is exactly what we are trying to + * avoid. + */ +const flushPendingMessages = (): Promise => + new Promise((resolve) => setTimeout(resolve, 0)); + +/** + * `evaluateModule`, wrapped so the harness knows the JS thread is about to be + * blocked. Hermes parses the entire module bundle before running a single line + * of it, and for large test graphs that parse can easily outlive the bridge + * heartbeat timeout -- a run would then fail with "app heartbeat timed out" + * without anything having actually crashed. + */ +export const evaluateModuleAsync = async ( + moduleJs: string, + modulePath: string +): Promise => { + const handle = tryGetHandle(); + + if (!handle) { + evaluateModule(moduleJs, modulePath); + return; + } + + handle.setBusy(true, `evaluating ${modulePath}`); + await flushPendingMessages(); + + try { + evaluateModule(moduleJs, modulePath); + } finally { + handle.setBusy(false); + } +}; + export const evaluateModule = (moduleJs: string, modulePath: string): void => { const __rMatches = Array.from(moduleJs.matchAll(/__r\((\d+)\)/g)); diff --git a/packages/runtime/src/bundler/index.ts b/packages/runtime/src/bundler/index.ts index 3c91e0ac..e99d09b9 100644 --- a/packages/runtime/src/bundler/index.ts +++ b/packages/runtime/src/bundler/index.ts @@ -1,3 +1,3 @@ -export { evaluateModule } from './evaluate.js'; +export { evaluateModule, evaluateModuleAsync } from './evaluate.js'; export { getBundler } from './factory.js'; export type { Bundler } from './types.js'; diff --git a/packages/runtime/src/client/factory.ts b/packages/runtime/src/client/factory.ts index d80da700..9a729bf6 100644 --- a/packages/runtime/src/client/factory.ts +++ b/packages/runtime/src/client/factory.ts @@ -14,7 +14,11 @@ import { getTestRunner, TestRunner } from '../runner/index.js'; import { getTestCollector, TestCollector } from '../collector/index.js'; import { combineEventEmitters, EventEmitter } from '../utils/emitter.js'; import { getWSServer } from './getWSServer.js'; -import { getBundler, evaluateModule, Bundler } from '../bundler/index.js'; +import { + getBundler, + evaluateModuleAsync, + Bundler, +} from '../bundler/index.js'; import { markTestsAsSkippedByName } from '../filtering/index.js'; import { setup } from '../render/setup.js'; import { runSetupFiles } from './setup-files.js'; @@ -77,7 +81,7 @@ export const getClient = async (): Promise => { setupFilesAfterEnv: [], events: events as EventEmitter, bundler: bundler as Bundler, - evaluateModule, + evaluateModule: evaluateModuleAsync, }); const moduleJs = await bundler.getModule(path); @@ -87,11 +91,11 @@ export const getClient = async (): Promise => { setupFilesAfterEnv: options.setupFilesAfterEnv ?? [], events: events as EventEmitter, bundler: bundler as Bundler, - evaluateModule, + evaluateModule: evaluateModuleAsync, }); setup(); - evaluateModule(moduleJs, path); + await evaluateModuleAsync(moduleJs, path); }, path); const processedTestSuite = options.testNamePattern diff --git a/packages/runtime/src/client/setup-files.ts b/packages/runtime/src/client/setup-files.ts index 100b3659..8bda17ef 100644 --- a/packages/runtime/src/client/setup-files.ts +++ b/packages/runtime/src/client/setup-files.ts @@ -7,7 +7,7 @@ export type RunSetupFilesOptions = { setupFilesAfterEnv: string[]; events: EventEmitter; bundler: Bundler; - evaluateModule: (moduleJs: string, filePath: string) => void; + evaluateModule: (moduleJs: string, filePath: string) => void | Promise; }; export const runSetupFiles = async ({ @@ -33,7 +33,7 @@ export const runSetupFiles = async ({ setupType: 'setupFiles', duration: Date.now() - startTime, }); - evaluateModule(setupModuleJs, setupFile); + await evaluateModule(setupModuleJs, setupFile); } catch (error) { const errorMessage = error instanceof Error ? error.message : 'Unknown error'; @@ -64,7 +64,7 @@ export const runSetupFiles = async ({ setupType: 'setupFilesAfterEnv', duration: Date.now() - startTime, }); - evaluateModule(setupModuleJs, setupFile); + await evaluateModule(setupModuleJs, setupFile); } catch (error) { const errorMessage = error instanceof Error ? error.message : 'Unknown error'; diff --git a/packages/runtime/src/client/store.ts b/packages/runtime/src/client/store.ts index b6714af4..495e8ba9 100644 --- a/packages/runtime/src/client/store.ts +++ b/packages/runtime/src/client/store.ts @@ -6,6 +6,8 @@ export const setHandle = (h: HarnessHandle): void => { handle = h; }; +export const tryGetHandle = (): HarnessHandle | null => handle; + export const getHandle = (): HarnessHandle => { if (!handle) { throw new Error( diff --git a/website/src/docs/getting-started/configuration.mdx b/website/src/docs/getting-started/configuration.mdx index 72449980..0f03200b 100644 --- a/website/src/docs/getting-started/configuration.mdx +++ b/website/src/docs/getting-started/configuration.mdx @@ -98,6 +98,8 @@ For Expo projects, the `entryPoint` should be set to the path specified in the ` | `webSocketPort` | Deprecated. Bridge traffic now uses `metroPort`; this option is ignored. | | `platformReadyTimeout` | Platform-ready timeout in milliseconds (default: `300000`). | | `bridgeTimeout` | Bridge timeout in milliseconds (default: `60000`). | +| `heartbeatInterval` | How often Harness pings the app to check that its JS thread is alive, in milliseconds (default: `5000`). | +| `heartbeatTimeout` | How long the app may go without answering a heartbeat ping before the run fails as unresponsive, in milliseconds (default: `20000`). | | `testTimeout` | Runtime timeout for each test case and suite hook in milliseconds (default: `5000`). Harness config takes precedence over Jest `testTimeout`. | | `bundleStartTimeout` | Bundle start timeout in milliseconds (default: `60000`). | | `maxAppRestarts` | Maximum number of automatic app relaunch attempts while Harness is waiting for startup (default: `2`). | @@ -235,6 +237,23 @@ Increase this value if Harness times out before the app runtime reports ready, e - Slower app startup after launch - Apps that take longer to load the Metro bundle and initialize the Harness runtime +## Heartbeat + +While a test file runs, Harness pings the app every `heartbeatInterval` milliseconds and expects a reply within `heartbeatTimeout` milliseconds. The reply is produced on the app's JS thread, so a missing reply means the app was killed, crashed, lost its connection, or blocked its JS thread. + +```javascript +{ + heartbeatInterval: 5000, // ping every 5 seconds + heartbeatTimeout: 30000, // fail after 30 seconds of silence +} +``` + +**Defaults:** `heartbeatInterval` 5000 (5 seconds), `heartbeatTimeout` 20000 (20 seconds) + +Harness automatically suspends the heartbeat around phases where the runtime knows it is about to block the JS thread — most importantly the synchronous evaluation of a freshly bundled test file, which on a large module graph can take longer than the heartbeat timeout on its own. You should not need to change these values. + +Raise `heartbeatTimeout` if a run still fails with `app heartbeat timed out` even though no crash report was written to `.harness/crash-reports`, which means the app never actually crashed. + ## Test Timeout The test timeout controls how long the runtime allows each test case and suite hook to run before reporting a timeout failure.