diff --git a/CHANGELOG.md b/CHANGELOG.md index 30cfcb16d2..d8c8d4dcf5 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -27,6 +27,10 @@ ### Fixes +- Measure callback-style native module calls until their completion callback fires ([#6561](https://github.com/getsentry/sentry-react-native/pull/6561)) + + Bridge methods that report completion through success/failure callbacks instead of a Promise return `undefined`, so they were recorded as sync calls with a near-zero duration. Their `turbo_module.*` durations are now correct, and slow ones produce a `native.turbo_module` breadcrumb. On the Old Architecture a failure callback is also counted as an error, following React Native's own `(failure, success)` trailing-argument convention. + - Attach `debug_meta` to JS error events on Hermes when the Debug ID stack match fails ([#6545](https://github.com/getsentry/sentry-react-native/pull/6545)) - `sentry-expo-upload-sourcemaps` now reads plugin config when the plugin is registered as `@sentry/react-native` ([#6543](https://github.com/getsentry/sentry-react-native/pull/6543)) - Make the `RNSentry` SPEC CHECKSUM in `Podfile.lock` machine-independent ([#6534](https://github.com/getsentry/sentry-react-native/pull/6534)) diff --git a/packages/core/src/js/turbomodule/turboModuleCallbacks.ts b/packages/core/src/js/turbomodule/turboModuleCallbacks.ts new file mode 100644 index 0000000000..f6d7996da7 --- /dev/null +++ b/packages/core/src/js/turbomodule/turboModuleCallbacks.ts @@ -0,0 +1,257 @@ +/** + * Instrumentation for callback-style native module methods. + * + * `wrapTurboModule` can only close a call record on its own for two shapes: a + * plain sync return, and a thenable return. Bridge methods that report + * completion through success/failure callbacks return `undefined` — the + * dominant async shape on the Old Architecture, and still used by some + * TurboModules — so without this layer they collapse to ~0ms sync calls. + * + * See https://github.com/getsentry/sentry-react-native/issues/6542. + */ + +import { debug } from '@sentry/core'; + +import type { TurboModuleCallKind } from './turboModuleTracker'; + +import { recordTurboModuleCall, type TurboModuleArch } from './turboModuleAggregator'; + +/** + * Cap on callback-style calls awaiting their completion callback. A callback + * that is never invoked would otherwise pin its state forever, so the oldest + * entry is closed out without a duration once the cap is reached. + */ +export const MAX_PENDING_CALLBACK_CALLS = 1024; + +/** + * A completion callback that fires later than this is treated as not being a + * completion callback at all (e.g. a long-lived subscription handler on the New + * Architecture, where no `(failure, success)` convention is enforced). The call + * is still counted, but with a zero duration, so a multi-minute "duration" + * can't poison the aggregate or fire a bogus slow-call breadcrumb. + */ +export const CALLBACK_MAX_AGE_MS = 60_000; + +/** + * How many stale entries a single insert may sweep. Keeps the age sweep + * amortised O(1) on the wrap hot path. + */ +const CALLBACK_SWEEP_BUDGET = 8; + +interface PendingCallbackCall { + startedAtMs: number; + /** Closes the call without a trustworthy duration; later callbacks no-op. */ + expire: () => void; +} + +/** Insertion-ordered, so the first entry is always the oldest. */ +let pendingCallbackCalls = new Map(); +let nextPendingCallbackId = 0; + +/** Tests only. */ +export function _resetPendingCallbackCalls(): void { + pendingCallbackCalls = new Map(); + nextPendingCallbackId = 0; +} + +export interface CallbackCallHandle { + /** Called once the instrumented method returned without a thenable. */ + markReturned: () => void; + /** + * Drops the bookkeeping: later callback invocations become no-ops. Returns + * `true` if a record was already emitted, so the caller doesn't double-count. + */ + abandon: () => boolean; +} + +/** + * Records a TurboModule invocation, isolated so a failure inside Sentry only + * drops the data instead of breaking the user's call. + */ +export function safeRecordTurboModuleCall( + name: string, + method: string, + kind: TurboModuleCallKind, + durationMs: number, + errored: boolean, + recordId: number | undefined, + arch: TurboModuleArch, +): void { + try { + recordTurboModuleCall({ + name, + method, + kind, + durationMs, + errored, + recordId, + arch, + }); + } catch (e) { + debug.warn(`[TurboModuleTracker] record failed for ${name}.${method}: ${String(e)}`); + } +} + +/** + * Wraps the trailing completion callbacks of `args` in place so the call's + * record is emitted when the callback fires rather than when the method + * returns. Returns `undefined` when the method isn't callback-shaped, which is + * the common case — nothing is allocated on that path. + * + * React Native's bridge fixes the shape: the last argument is the success + * callback, the second-to-last the failure callback, and a non-function + * argument may never follow a function one (see `genMethod` in RN's + * `Libraries/BatchedBridge/NativeModules.js`). `'promise'`-typed methods never + * receive callbacks and are already covered by the thenable path, so they are + * skipped outright. + */ +export function instrumentTrailingCallbacks( + args: unknown[], + originalFn: (...a: unknown[]) => unknown, + name: string, + method: string, + startedAtMs: number, + recordId: number | undefined, + arch: TurboModuleArch, +): CallbackCallHandle | undefined { + const methodType = (originalFn as { type?: unknown }).type; + if (methodType === 'promise') { + return undefined; + } + + const lastIndex = args.length - 1; + if (lastIndex < 0 || typeof args[lastIndex] !== 'function') { + return undefined; + } + const failureIndex = lastIndex > 0 && typeof args[lastIndex - 1] === 'function' ? lastIndex - 1 : -1; + + // Only the Old Architecture bridge guarantees that the second-to-last + // function is the failure callback. New Architecture TurboModules take + // arbitrary callbacks with no such convention, so guessing there would + // corrupt `errorCount` — close the record without flagging an error instead. + const failureIsError = failureIndex >= 0 && arch === 'legacy' && typeof methodType === 'string'; + + let settled = false; + let returned = false; + let pendingId: number | undefined; + + const settle = (errored: boolean, durationMs: number): void => { + if (settled) { + return; + } + settled = true; + if (pendingId !== undefined) { + pendingCallbackCalls.delete(pendingId); + pendingId = undefined; + } + safeRecordTurboModuleCall( + name, + method, + // A callback that already fired before the method returned means the work + // was synchronous (RN's `'sync'` method type invokes callbacks inline). + returned ? 'async' : 'sync', + durationMs, + errored, + recordId, + arch, + ); + }; + + const emit = (errored: boolean): void => { + const durationMs = Date.now() - startedAtMs; + // A callback firing this late is not a completion callback (e.g. a + // long-lived subscription handler), so its "duration" is meaningless. + // Still record the call itself — dropping it would hide the method from + // the aggregate entirely, which is worse than the pre-fix ~0ms. + settle(errored, returned && durationMs > CALLBACK_MAX_AGE_MS ? 0 : durationMs); + }; + + args[lastIndex] = instrumentCallback(args[lastIndex] as (...a: unknown[]) => unknown, false, emit); + if (failureIndex >= 0) { + args[failureIndex] = instrumentCallback(args[failureIndex] as (...a: unknown[]) => unknown, failureIsError, emit); + } + + return { + markReturned: (): void => { + returned = true; + if (settled) { + return; + } + evictStalePendingCallbackCalls(startedAtMs); + pendingId = nextPendingCallbackId++; + pendingCallbackCalls.set(pendingId, { + startedAtMs, + // Closed out before the callback fired: keep the call in the aggregate, + // but with no duration we can stand behind. + expire: (): void => { + pendingId = undefined; + settle(false, 0); + }, + }); + }, + abandon: (): boolean => { + const alreadyRecorded = settled; + settled = true; + if (pendingId !== undefined) { + pendingCallbackCalls.delete(pendingId); + pendingId = undefined; + } + return alreadyRecorded; + }, + }; +} + +/** + * Returns a stand-in for `callback` that closes the pending record before + * handing control to the original. The bookkeeping runs first so the callback's + * own body isn't counted as native time, and is isolated so a tracker failure + * can never break the user's callback. + */ +function instrumentCallback( + callback: (...a: unknown[]) => unknown, + errored: boolean, + emit: (errored: boolean) => void, +): (...a: unknown[]) => unknown { + return function sentryTurboModuleCallback(this: unknown, ...callbackArgs: unknown[]): unknown { + try { + emit(errored); + } catch (e) { + debug.warn(`[TurboModuleTracker] callback record failed: ${String(e)}`); + } + return callback.apply(this, callbackArgs); + }; +} + +/** + * Closes out pending callback calls that aged out, plus the oldest entry when + * the cap is reached. Bounded per invocation so the sweep stays amortised O(1) + * on the wrap hot path. + * + * `nowMs` is the current call's start timestamp — taken microseconds ago, so it + * saves a `Date.now()` on the hot path at the cost of an imperceptibly + * conservative cutoff. + */ +function evictStalePendingCallbackCalls(nowMs: number): void { + let budget = CALLBACK_SWEEP_BUDGET; + for (const [id, pending] of pendingCallbackCalls) { + if (budget-- <= 0 || nowMs - pending.startedAtMs <= CALLBACK_MAX_AGE_MS) { + break; + } + pendingCallbackCalls.delete(id); + pending.expire(); + } + + while (pendingCallbackCalls.size >= MAX_PENDING_CALLBACK_CALLS) { + const oldest = pendingCallbackCalls.entries().next(); + if (oldest.done) { + break; + } + const [id, pending] = oldest.value; + pendingCallbackCalls.delete(id); + pending.expire(); + debug.log( + `[TurboModuleTracker] More than ${MAX_PENDING_CALLBACK_CALLS} callback-style calls awaiting completion — ` + + `closing the oldest one without a duration.`, + ); + } +} diff --git a/packages/core/src/js/turbomodule/wrapTurboModule.ts b/packages/core/src/js/turbomodule/wrapTurboModule.ts index fd8251217f..9f5785f9cc 100644 --- a/packages/core/src/js/turbomodule/wrapTurboModule.ts +++ b/packages/core/src/js/turbomodule/wrapTurboModule.ts @@ -2,7 +2,12 @@ import { logger } from '@sentry/core'; import type { TurboModuleCallKind } from './turboModuleTracker'; -import { notifyTurboModuleCallStart, recordTurboModuleCall, type TurboModuleArch } from './turboModuleAggregator'; +import { notifyTurboModuleCallStart, type TurboModuleArch } from './turboModuleAggregator'; +import { + _resetPendingCallbackCalls, + instrumentTrailingCallbacks, + safeRecordTurboModuleCall, +} from './turboModuleCallbacks'; import { popTurboModuleCall, pushTurboModuleCall, relabelTurboModuleCallKind } from './turboModuleTracker'; /** @@ -14,6 +19,7 @@ let wrappedModules = new WeakSet(); /** Tests only. */ export function _resetWrappedModules(): void { wrappedModules = new WeakSet(); + _resetPendingCallbackCalls(); } /** @@ -24,6 +30,11 @@ export function _resetWrappedModules(): void { * - Sync methods are tracked as `kind: 'sync'` and popped right after the call. * - Async methods (those returning a thenable) are relabelled to `kind: 'async'` * right after the call dispatches and popped when the returned promise settles. + * - Callback-style methods (trailing function arguments, no thenable return — + * the dominant async shape on the Old Architecture bridge) have their + * completion callbacks wrapped, so the recorded duration spans until the + * callback fires instead of collapsing to ~0ms. See + * https://github.com/getsentry/sentry-react-native/issues/6542. * * `skip` can be used to opt specific method names out of tracking (e.g. very * hot, no-op methods like RN's `addListener`/`removeListeners` event-emitter @@ -98,33 +109,59 @@ export function wrapTurboModule( logger.warn(`[TurboModuleTracker] notifyStart failed for ${name}.${key}: ${String(e)}`); } + // Must happen before the call: the wrapped callbacks have to be the ones + // handed to the native side. Mutates `args` in place, leaving arity and + // argument types untouched. + const callbackCall = instrumentTrailingCallbacks(args, originalFn, name, key, startedAtMs, recordId, arch); + let result: unknown; try { result = originalFn.apply(this, args); } catch (e) { + // A callback that already fired emitted the record itself. + const alreadyRecorded = callbackCall?.abandon() === true; safePop(callId, name, key); - safeRecord(name, key, 'sync', startedAtMs, true, recordId, arch); + if (!alreadyRecorded) { + safeRecordTurboModuleCall(name, key, 'sync', Date.now() - startedAtMs, true, recordId, arch); + } throw e; } if (isThenable(result)) { + // A callback that already fired emitted the record itself — the promise + // handlers must not add a second one for the same invocation. + const alreadyRecorded = callbackCall?.abandon() === true; safeRelabel(callId, 'async', name, key); return (result as Promise).then( value => { safePop(callId, name, key); - safeRecord(name, key, 'async', startedAtMs, false, recordId, arch); + if (!alreadyRecorded) { + safeRecordTurboModuleCall(name, key, 'async', Date.now() - startedAtMs, false, recordId, arch); + } return value; }, err => { safePop(callId, name, key); - safeRecord(name, key, 'async', startedAtMs, true, recordId, arch); + if (!alreadyRecorded) { + safeRecordTurboModuleCall(name, key, 'async', Date.now() - startedAtMs, true, recordId, arch); + } throw err; }, ); } + if (callbackCall) { + // The crash-attribution frame is popped synchronously either way: a + // frame held until a callback that may never fire would risk blaming + // this module for an unrelated later native crash. Only the timing + // record is deferred. + safePop(callId, name, key); + callbackCall.markReturned(); + return result; + } + safePop(callId, name, key); - safeRecord(name, key, 'sync', startedAtMs, false, recordId, arch); + safeRecordTurboModuleCall(name, key, 'sync', Date.now() - startedAtMs, false, recordId, arch); return result; }; @@ -200,30 +237,6 @@ function safeRelabel(callId: number | undefined, kind: TurboModuleCallKind, name } } -function safeRecord( - name: string, - method: string, - kind: TurboModuleCallKind, - startedAtMs: number, - errored: boolean, - recordId: number | undefined, - arch: TurboModuleArch, -): void { - try { - recordTurboModuleCall({ - name, - method, - kind, - durationMs: Date.now() - startedAtMs, - errored, - recordId, - arch, - }); - } catch (e) { - logger.warn(`[TurboModuleTracker] record failed for ${name}.${method}: ${String(e)}`); - } -} - function isThenable(value: unknown): value is PromiseLike { if (!value || (typeof value !== 'object' && typeof value !== 'function')) { return false; diff --git a/packages/core/test/integrations/turboModuleContext.test.ts b/packages/core/test/integrations/turboModuleContext.test.ts index e3801e2699..12e16edc95 100644 --- a/packages/core/test/integrations/turboModuleContext.test.ts +++ b/packages/core/test/integrations/turboModuleContext.test.ts @@ -18,6 +18,7 @@ import { notifyTurboModuleCallStart, recordTurboModuleCall, } from '../../src/js/turbomodule/turboModuleAggregator'; +import { _resetWrappedModules, wrapTurboModule } from '../../src/js/turbomodule/wrapTurboModule'; import * as spanUtils from '../../src/js/utils/span'; import * as wrapper from '../../src/js/wrapper'; @@ -916,5 +917,77 @@ describe('turboModuleContextIntegration', () => { expect(attributes['turbo_module.Long.req.call_count']).toBe(1); expect(attributes['turbo_module.Long.req.duration_ms']).toBe(42); }); + + describe('callback-style methods, end to end through wrapTurboModule', () => { + beforeEach(() => { + _resetWrappedModules(); + }); + + afterEach(() => { + _resetWrappedModules(); + }); + + it('emits a slow-call breadcrumb once the completion callback fires', () => { + const integration = turboModuleContextIntegration({ aggregateFlushIntervalMs: 0 }); + integration.setupOnce?.(); + const { client } = makeClientWithSpanHooks(); + integration.setup?.(client); + + let fireSuccess: () => void = () => undefined; + const module = { + slowWork: (onSuccess: () => void): void => { + fireSuccess = onSuccess; + }, + }; + const nowSpy = jest.spyOn(Date, 'now').mockReturnValue(10_000); + wrapTurboModule('Legacy', module, { arch: 'legacy' }); + + module.slowWork(() => undefined); + // Pre-fix this call closed on return and never crossed the threshold. + expect(addBreadcrumbSpy).not.toHaveBeenCalled(); + + nowSpy.mockReturnValue(10_000 + DEFAULT_SLOW_CALL_THRESHOLD_MS + 50); + fireSuccess(); + + expect(addBreadcrumbSpy).toHaveBeenCalledTimes(1); + expect(addBreadcrumbSpy.mock.calls[0]?.[0]).toMatchObject({ + category: TURBO_MODULE_BREADCRUMB_CATEGORY, + data: expect.objectContaining({ + module: 'Legacy', + method: 'slowWork', + kind: 'async', + duration_ms: DEFAULT_SLOW_CALL_THRESHOLD_MS + 50, + }), + }); + }); + + it('credits the span that was open at call start, not the one open when the callback fires', () => { + const integration = turboModuleContextIntegration({ aggregateFlushIntervalMs: 0 }); + integration.setupOnce?.(); + const { client, emit } = makeClientWithSpanHooks(); + integration.setup?.(client); + + let fireSuccess: () => void = () => undefined; + const module = { + work: (onSuccess: () => void): void => { + fireSuccess = onSuccess; + }, + }; + const nowSpy = jest.spyOn(Date, 'now').mockReturnValue(10_000); + wrapTurboModule('Legacy', module, { arch: 'legacy' }); + + const span = makeFakeSpan(); + emit('spanStart', span); + module.work(() => undefined); + emit('spanEnd', span); + + nowSpy.mockReturnValue(10_030); + fireSuccess(); + + const attributes = span.setAttributes.mock.calls.at(-1)?.[0] as Record; + expect(attributes['turbo_module.Legacy.work.call_count']).toBe(1); + expect(attributes['turbo_module.Legacy.work.duration_ms']).toBe(30); + }); + }); }); }); diff --git a/packages/core/test/turbomodule/wrapTurboModule.test.ts b/packages/core/test/turbomodule/wrapTurboModule.test.ts index 4567a31792..891e5385da 100644 --- a/packages/core/test/turbomodule/wrapTurboModule.test.ts +++ b/packages/core/test/turbomodule/wrapTurboModule.test.ts @@ -2,6 +2,7 @@ import * as SentryCore from '@sentry/core'; import { Scope } from '@sentry/core'; import { _resetTurboModuleAggregator, drainTurboModuleAggregate } from '../../src/js/turbomodule/turboModuleAggregator'; +import { CALLBACK_MAX_AGE_MS, MAX_PENDING_CALLBACK_CALLS } from '../../src/js/turbomodule/turboModuleCallbacks'; import * as tracker from '../../src/js/turbomodule/turboModuleTracker'; import { _resetTurboModuleTracker, getTurboModuleCallStack } from '../../src/js/turbomodule/turboModuleTracker'; import { _resetWrappedModules, wrapTurboModule } from '../../src/js/turbomodule/wrapTurboModule'; @@ -350,4 +351,344 @@ describe('wrapTurboModule', () => { ]), ); }); + + describe('callback-style methods', () => { + /** Mimics an Old Architecture bridge method: RN tags every generated method with `type`. */ + const asBridgeMethod = unknown>(fn: T, type = 'async'): T => { + (fn as unknown as { type: string }).type = type; + return fn; + }; + + it('measures the duration until the success callback fires, not until return', () => { + let fireSuccess: () => void = () => undefined; + const module = { + doWork: (_arg: string, onSuccess: () => void): void => { + fireSuccess = onSuccess; + }, + }; + const nowSpy = jest.spyOn(Date, 'now').mockReturnValue(1_000); + wrapTurboModule('Mod', module); + + module.doWork('x', () => undefined); + // Nothing recorded yet — the call is still in flight. + expect(drainTurboModuleAggregate()).toEqual([]); + + nowSpy.mockReturnValue(1_750); + fireSuccess(); + + const snapshot = drainTurboModuleAggregate(); + expect(snapshot).toHaveLength(1); + expect(snapshot[0]).toMatchObject({ + method: 'doWork', + kind: 'async', + callCount: 1, + errorCount: 0, + totalDurationMs: 750, + }); + }); + + it('pops the crash-attribution frame synchronously, before the callback fires', () => { + let fireSuccess: () => void = () => undefined; + const module = { + doWork: (onSuccess: () => void): void => { + fireSuccess = onSuccess; + }, + }; + wrapTurboModule('Mod', module); + + module.doWork(() => undefined); + + expect(getTurboModuleCallStack()).toEqual([]); + expect(scope.getScopeData().contexts.turbo_module).toBeUndefined(); + + fireSuccess(); + expect(getTurboModuleCallStack()).toEqual([]); + }); + + it('keeps kind="sync" when the callback fires inline', () => { + const module = { + doWork: (onSuccess: () => void): void => onSuccess(), + }; + wrapTurboModule('Mod', module); + + module.doWork(() => undefined); + + const snapshot = drainTurboModuleAggregate(); + expect(snapshot).toHaveLength(1); + expect(snapshot[0]).toMatchObject({ method: 'doWork', kind: 'sync', callCount: 1 }); + }); + + it('counts a failure callback as an error on the legacy bridge', () => { + let fireFailure: () => void = () => undefined; + const module = { + doWork: asBridgeMethod((onFail: () => void, _onSuccess: () => void): void => { + fireFailure = onFail; + }), + }; + wrapTurboModule('Mod', module, { arch: 'legacy' }); + + module.doWork( + () => undefined, + () => undefined, + ); + fireFailure(); + + const snapshot = drainTurboModuleAggregate(); + expect(snapshot).toHaveLength(1); + expect(snapshot[0]).toMatchObject({ method: 'doWork', callCount: 1, errorCount: 1 }); + }); + + it('does not guess error attribution on the New Architecture', () => { + let fireFirst: () => void = () => undefined; + const module = { + doWork: (first: () => void, _second: () => void): void => { + fireFirst = first; + }, + }; + wrapTurboModule('Mod', module, { arch: 'new' }); + + module.doWork( + () => undefined, + () => undefined, + ); + fireFirst(); + + const snapshot = drainTurboModuleAggregate(); + expect(snapshot).toHaveLength(1); + expect(snapshot[0]).toMatchObject({ method: 'doWork', callCount: 1, errorCount: 0 }); + }); + + it('records the call once even when the callback is invoked repeatedly', () => { + let fireSuccess: () => void = () => undefined; + const module = { + doWork: (onSuccess: () => void): void => { + fireSuccess = onSuccess; + }, + }; + wrapTurboModule('Mod', module); + + module.doWork(() => undefined); + fireSuccess(); + fireSuccess(); + fireSuccess(); + + const snapshot = drainTurboModuleAggregate(); + expect(snapshot).toHaveLength(1); + expect(snapshot[0]).toMatchObject({ callCount: 1 }); + }); + + it('passes through the callback receiver, arguments and return value', () => { + let invoke: (...args: unknown[]) => unknown = () => undefined; + const module = { + doWork: (onSuccess: (...args: unknown[]) => unknown): void => { + invoke = onSuccess; + }, + }; + wrapTurboModule('Mod', module); + + const receiver = { marker: 'receiver' }; + const original = jest.fn(function (this: unknown, ...args: unknown[]): string { + expect(this).toBe(receiver); + expect(args).toEqual([1, 'two']); + return 'returned'; + }); + + module.doWork(original); + const result = invoke.call(receiver, 1, 'two'); + + expect(original).toHaveBeenCalledTimes(1); + expect(result).toBe('returned'); + }); + + it('propagates a throwing callback after recording the call', () => { + let fireSuccess: () => void = () => undefined; + const module = { + doWork: (onSuccess: () => void): void => { + fireSuccess = onSuccess; + }, + }; + wrapTurboModule('Mod', module); + + module.doWork(() => { + throw new Error('callback boom'); + }); + + expect(() => fireSuccess()).toThrow('callback boom'); + expect(drainTurboModuleAggregate()).toHaveLength(1); + }); + + it('records nothing while the callback has not fired', () => { + const module = { + doWork: (_onSuccess: () => void): void => undefined, + }; + wrapTurboModule('Mod', module); + + module.doWork(() => undefined); + + expect(drainTurboModuleAggregate()).toEqual([]); + }); + + it('closes the oldest pending call without a duration once the cap is reached', () => { + const pending: Array<() => void> = []; + const module = { + doWork: (onSuccess: () => void): void => { + pending.push(onSuccess); + }, + }; + const nowSpy = jest.spyOn(Date, 'now').mockReturnValue(1_000); + wrapTurboModule('Mod', module); + + for (let i = 0; i < MAX_PENDING_CALLBACK_CALLS; i++) { + module.doWork(() => undefined); + } + expect(drainTurboModuleAggregate()).toEqual([]); + + // One over the cap evicts the oldest, which is counted with no duration. + nowSpy.mockReturnValue(3_000); + module.doWork(() => undefined); + + const snapshot = drainTurboModuleAggregate(); + expect(snapshot).toHaveLength(1); + expect(snapshot[0]).toMatchObject({ callCount: 1, totalDurationMs: 0 }); + + // The evicted call's callback is now inert. + pending[0]?.(); + expect(drainTurboModuleAggregate()).toEqual([]); + }); + + it('sweeps out aged pending calls when a later call comes in', () => { + const pending: Array<() => void> = []; + const module = { + doWork: (onSuccess: () => void): void => { + pending.push(onSuccess); + }, + }; + const nowSpy = jest.spyOn(Date, 'now').mockReturnValue(1_000); + wrapTurboModule('Mod', module); + + module.doWork(() => undefined); + expect(drainTurboModuleAggregate()).toEqual([]); + + // A later call past the max age sweeps the stale entry, counting it + // without a duration, and records itself normally once it settles. + nowSpy.mockReturnValue(1_000 + CALLBACK_MAX_AGE_MS + 1); + module.doWork(() => undefined); + + let snapshot = drainTurboModuleAggregate(); + expect(snapshot).toHaveLength(1); + expect(snapshot[0]).toMatchObject({ callCount: 1, totalDurationMs: 0 }); + + // The swept call's callback is inert; the second call still settles. + pending[0]?.(); + expect(drainTurboModuleAggregate()).toEqual([]); + + pending[1]?.(); + snapshot = drainTurboModuleAggregate(); + expect(snapshot).toHaveLength(1); + expect(snapshot[0]).toMatchObject({ callCount: 1, totalDurationMs: 0 }); + }); + + it('counts a callback that fires implausibly late without its duration', () => { + let fireSuccess: () => void = () => undefined; + const module = { + doWork: (onSuccess: () => void): void => { + fireSuccess = onSuccess; + }, + }; + const nowSpy = jest.spyOn(Date, 'now').mockReturnValue(1_000); + wrapTurboModule('Mod', module); + + module.doWork(() => undefined); + nowSpy.mockReturnValue(1_000 + CALLBACK_MAX_AGE_MS + 1); + fireSuccess(); + + const snapshot = drainTurboModuleAggregate(); + expect(snapshot).toHaveLength(1); + expect(snapshot[0]).toMatchObject({ callCount: 1, totalDurationMs: 0 }); + }); + + it('leaves promise-typed bridge methods to the thenable path', async () => { + const onSuccess = jest.fn(); + const module = { + doWork: asBridgeMethod((cb: () => void): Promise => { + // A `'promise'`-typed method never receives callbacks; assert we didn't + // substitute the argument anyway. + expect(cb).toBe(onSuccess); + return Promise.resolve('done'); + }, 'promise'), + }; + wrapTurboModule('Mod', module, { arch: 'legacy' }); + + await module.doWork(onSuccess); + + const snapshot = drainTurboModuleAggregate(); + expect(snapshot).toHaveLength(1); + expect(snapshot[0]).toMatchObject({ kind: 'async', callCount: 1 }); + }); + + it('prefers the promise signal when a method both returns a thenable and takes a callback', async () => { + let fireSuccess: () => void = () => undefined; + const module = { + doWork: (onSuccess: () => void): Promise => { + fireSuccess = onSuccess; + return Promise.resolve('done'); + }, + }; + wrapTurboModule('Mod', module); + + await module.doWork(() => undefined); + fireSuccess(); + + const snapshot = drainTurboModuleAggregate(); + expect(snapshot).toHaveLength(1); + expect(snapshot[0]).toMatchObject({ kind: 'async', callCount: 1 }); + }); + + it('records once when a thenable-returning method fires its callback inline', async () => { + const module = { + doWork: (onSuccess: () => void): Promise => { + onSuccess(); + return Promise.resolve('done'); + }, + }; + wrapTurboModule('Mod', module); + + await module.doWork(() => undefined); + + // The inline callback closed the record as `sync` before the thenable was + // seen; the promise handler must not add a second `async` entry. + const snapshot = drainTurboModuleAggregate(); + expect(snapshot).toHaveLength(1); + expect(snapshot[0]).toMatchObject({ kind: 'sync', callCount: 1 }); + }); + + it('ignores a function argument that is not in a trailing position', () => { + const module = { + doWork: (_fn: () => void, _tail: string): void => undefined, + }; + wrapTurboModule('Mod', module); + + module.doWork(() => undefined, 'tail'); + + const snapshot = drainTurboModuleAggregate(); + expect(snapshot).toHaveLength(1); + expect(snapshot[0]).toMatchObject({ kind: 'sync', callCount: 1 }); + }); + + it('records a synchronous throw once when the callback already fired', () => { + const module = { + doWork: (onSuccess: () => void): void => { + onSuccess(); + throw new Error('boom'); + }, + }; + wrapTurboModule('Mod', module); + + expect(() => module.doWork(() => undefined)).toThrow('boom'); + + const snapshot = drainTurboModuleAggregate(); + expect(snapshot).toHaveLength(1); + expect(snapshot[0]).toMatchObject({ callCount: 1, errorCount: 0 }); + }); + }); });