Skip to content

Commit 75735f9

Browse files
alwxlucas-zimerman
andauthored
fix(core): Measure callback-style native module calls until completion (#6561)
* fix(core): Measure callback-style native module calls until completion `wrapTurboModule` only knew two completion signals: a plain return and a thenable return. Bridge methods that report completion through success/failure callbacks return `undefined`, so they were closed on return and recorded as sync calls with a near-zero duration. RN's `genMethod` confirms the shape — for `type: 'async'` the generated wrapper returns nothing and hands the trailing callbacks to `enqueueNativeCall`. The same source fixes the argument convention: last argument is the success callback, second-to-last the failure one, and a non-function may never follow a function. Only the Old Architecture bridge guarantees that, so failure callbacks are counted as errors there and left unflagged on the New Architecture rather than guessing and corrupting `errorCount`. The crash-attribution frame is still popped synchronously. Holding it until a callback that may never fire would risk blaming this module for an unrelated later native crash — a regression on the very feature the frame exists for. Only the timing record is deferred. Records are bounded without timers: a cap plus an amortised age sweep on insert. A call closed out that way is still counted, with a zero duration — dropping it would hide the method from the aggregate entirely, which is worse than the ~0ms this fixes. The same clamp covers a callback firing implausibly late, which on the New Architecture may well be a long-lived subscription handler rather than a completion callback. The callback machinery lives in its own module because `wrapTurboModule.ts` would otherwise exceed oxlint's `max-lines`. Fixes #6542 * chore: point changelog entry to PR * fix(core): Do not double-record a thenable call whose callback fired inline A method that invokes its trailing callback inline and then returns a thenable produced two aggregate rows for one invocation: the callback closed the record as `sync`, and the promise handlers recorded it again as `async`. The throw path already consulted `abandon()`'s return value; the thenable path discarded it. Whichever completion signal lands first now wins. Reported by Warden on #6561. * fix(core): Isolate callback instrumentation from the user's call `instrumentTrailingCallbacks` reads RN's `type` tag off the bridge method, which can be a throwing accessor, and it ran before `originalFn.apply` outside any `try` — a throw there would have blocked the native call with the crash-attribution frame already pushed. `markReturned` ran after a successful return, so a throw would have surfaced to the caller after the real work had completed. `instrumentTrailingCallbacks` is now a guarded shell that warns and returns `undefined`. It also marks the call settled on failure, so callbacks it had already swapped into `args` stay inert and the caller's own close path emits exactly one record instead of zero or two. That is why `settled`/`returned`/ `pendingId` move out of closure variables into a shared state object: the outer catch has to reach them. `markReturned` guards the pending-call registration, whose eviction path is the only part of the bookkeeping that calls out of the module. A failure there costs only the in-flight cap for that call; the callback still closes the record when it fires. `abandon` is left unguarded on purpose — a local flag plus a `Map.delete` cannot throw, and a catch there would be unreachable and untestable. * chore: Move changelog entry back to Unreleased The 8.22.0 release was cut on main underneath this entry, so merging main left it inside an already-published section. --------- Co-authored-by: LucasZF <lucas-zimerman1@hotmail.com>
1 parent aab34e2 commit 75735f9

5 files changed

Lines changed: 838 additions & 29 deletions

File tree

CHANGELOG.md

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -23,6 +23,10 @@
2323
2424
### Fixes
2525

26+
- Measure callback-style native module calls until their completion callback fires ([#6561](https://github.com/getsentry/sentry-react-native/pull/6561))
27+
28+
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.
29+
2630
- Resolve `config-plugins` through the `expo` package in the Expo config plugin ([#6581](https://github.com/getsentry/sentry-react-native/pull/6581))
2731

2832
- Make the `RNSentry` SPEC CHECKSUM in `Podfile.lock` machine-independent ([#6534](https://github.com/getsentry/sentry-react-native/pull/6534))
Lines changed: 305 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,305 @@
1+
/**
2+
* Instrumentation for callback-style native module methods.
3+
*
4+
* `wrapTurboModule` can only close a call record on its own for two shapes: a
5+
* plain sync return, and a thenable return. Bridge methods that report
6+
* completion through success/failure callbacks return `undefined` — the
7+
* dominant async shape on the Old Architecture, and still used by some
8+
* TurboModules — so without this layer they collapse to ~0ms sync calls.
9+
*
10+
* See https://github.com/getsentry/sentry-react-native/issues/6542.
11+
*/
12+
13+
import { debug } from '@sentry/core';
14+
15+
import type { TurboModuleCallKind } from './turboModuleTracker';
16+
17+
import { recordTurboModuleCall, type TurboModuleArch } from './turboModuleAggregator';
18+
19+
/**
20+
* Cap on callback-style calls awaiting their completion callback. A callback
21+
* that is never invoked would otherwise pin its state forever, so the oldest
22+
* entry is closed out without a duration once the cap is reached.
23+
*/
24+
export const MAX_PENDING_CALLBACK_CALLS = 1024;
25+
26+
/**
27+
* A completion callback that fires later than this is treated as not being a
28+
* completion callback at all (e.g. a long-lived subscription handler on the New
29+
* Architecture, where no `(failure, success)` convention is enforced). The call
30+
* is still counted, but with a zero duration, so a multi-minute "duration"
31+
* can't poison the aggregate or fire a bogus slow-call breadcrumb.
32+
*/
33+
export const CALLBACK_MAX_AGE_MS = 60_000;
34+
35+
/**
36+
* How many stale entries a single insert may sweep. Keeps the age sweep
37+
* amortised O(1) on the wrap hot path.
38+
*/
39+
const CALLBACK_SWEEP_BUDGET = 8;
40+
41+
interface PendingCallbackCall {
42+
startedAtMs: number;
43+
/** Closes the call without a trustworthy duration; later callbacks no-op. */
44+
expire: () => void;
45+
}
46+
47+
/** Insertion-ordered, so the first entry is always the oldest. */
48+
let pendingCallbackCalls = new Map<number, PendingCallbackCall>();
49+
let nextPendingCallbackId = 0;
50+
51+
/** Tests only. */
52+
export function _resetPendingCallbackCalls(): void {
53+
pendingCallbackCalls = new Map();
54+
nextPendingCallbackId = 0;
55+
}
56+
57+
export interface CallbackCallHandle {
58+
/** Called once the instrumented method returned without a thenable. */
59+
markReturned: () => void;
60+
/**
61+
* Drops the bookkeeping: later callback invocations become no-ops. Returns
62+
* `true` if a record was already emitted, so the caller doesn't double-count.
63+
*/
64+
abandon: () => boolean;
65+
}
66+
67+
/**
68+
* State shared between the wrapped callbacks and the returned handle. Held in an
69+
* object rather than closure variables so `instrumentTrailingCallbacks` can
70+
* neutralise callbacks it had already installed if it fails part-way through.
71+
*/
72+
interface CallbackCallState {
73+
settled: boolean;
74+
returned: boolean;
75+
pendingId: number | undefined;
76+
}
77+
78+
/**
79+
* Records a TurboModule invocation, isolated so a failure inside Sentry only
80+
* drops the data instead of breaking the user's call.
81+
*/
82+
export function safeRecordTurboModuleCall(
83+
name: string,
84+
method: string,
85+
kind: TurboModuleCallKind,
86+
durationMs: number,
87+
errored: boolean,
88+
recordId: number | undefined,
89+
arch: TurboModuleArch,
90+
): void {
91+
try {
92+
recordTurboModuleCall({
93+
name,
94+
method,
95+
kind,
96+
durationMs,
97+
errored,
98+
recordId,
99+
arch,
100+
});
101+
} catch (e) {
102+
debug.warn(`[TurboModuleTracker] record failed for ${name}.${method}: ${String(e)}`);
103+
}
104+
}
105+
106+
/**
107+
* Wraps the trailing completion callbacks of `args` in place so the call's
108+
* record is emitted when the callback fires rather than when the method
109+
* returns. Returns `undefined` when the method isn't callback-shaped, which is
110+
* the common case — nothing is allocated on that path.
111+
*
112+
* Never throws, and neither do the returned handle's methods: this runs outside
113+
* the caller's `try` and before the real invocation, so a failure here must
114+
* only drop the attribution data, never block or corrupt the user's call.
115+
*
116+
* React Native's bridge fixes the shape: the last argument is the success
117+
* callback, the second-to-last the failure callback, and a non-function
118+
* argument may never follow a function one (see `genMethod` in RN's
119+
* `Libraries/BatchedBridge/NativeModules.js`). `'promise'`-typed methods never
120+
* receive callbacks and are already covered by the thenable path, so they are
121+
* skipped outright.
122+
*/
123+
export function instrumentTrailingCallbacks(
124+
args: unknown[],
125+
originalFn: (...a: unknown[]) => unknown,
126+
name: string,
127+
method: string,
128+
startedAtMs: number,
129+
recordId: number | undefined,
130+
arch: TurboModuleArch,
131+
): CallbackCallHandle | undefined {
132+
const state: CallbackCallState = { settled: false, returned: false, pendingId: undefined };
133+
try {
134+
return createCallbackCall(state, args, originalFn, name, method, startedAtMs, recordId, arch);
135+
} catch (e) {
136+
// Some callbacks may already have been swapped into `args` — arity and
137+
// argument types are unchanged, so the user's call is unaffected, but they
138+
// must not emit anything: the caller sees `undefined` and now closes the
139+
// record itself.
140+
state.settled = true;
141+
debug.warn(`[TurboModuleTracker] callback instrumentation failed for ${name}.${method}: ${String(e)}`);
142+
return undefined;
143+
}
144+
}
145+
146+
/** Body of {@link instrumentTrailingCallbacks}; may throw, isolated by its caller. */
147+
function createCallbackCall(
148+
state: CallbackCallState,
149+
args: unknown[],
150+
originalFn: (...a: unknown[]) => unknown,
151+
name: string,
152+
method: string,
153+
startedAtMs: number,
154+
recordId: number | undefined,
155+
arch: TurboModuleArch,
156+
): CallbackCallHandle | undefined {
157+
const methodType = (originalFn as { type?: unknown }).type;
158+
if (methodType === 'promise') {
159+
return undefined;
160+
}
161+
162+
const lastIndex = args.length - 1;
163+
if (lastIndex < 0 || typeof args[lastIndex] !== 'function') {
164+
return undefined;
165+
}
166+
const failureIndex = lastIndex > 0 && typeof args[lastIndex - 1] === 'function' ? lastIndex - 1 : -1;
167+
168+
// Only the Old Architecture bridge guarantees that the second-to-last
169+
// function is the failure callback. New Architecture TurboModules take
170+
// arbitrary callbacks with no such convention, so guessing there would
171+
// corrupt `errorCount` — close the record without flagging an error instead.
172+
const failureIsError = failureIndex >= 0 && arch === 'legacy' && typeof methodType === 'string';
173+
174+
const settle = (errored: boolean, durationMs: number): void => {
175+
if (state.settled) {
176+
return;
177+
}
178+
state.settled = true;
179+
forgetPendingCall(state);
180+
safeRecordTurboModuleCall(
181+
name,
182+
method,
183+
// A callback that already fired before the method returned means the work
184+
// was synchronous (RN's `'sync'` method type invokes callbacks inline).
185+
state.returned ? 'async' : 'sync',
186+
durationMs,
187+
errored,
188+
recordId,
189+
arch,
190+
);
191+
};
192+
193+
const emit = (errored: boolean): void => {
194+
const durationMs = Date.now() - startedAtMs;
195+
// A callback firing this late is not a completion callback (e.g. a
196+
// long-lived subscription handler), so its "duration" is meaningless.
197+
// Still record the call itself — dropping it would hide the method from
198+
// the aggregate entirely, which is worse than the pre-fix ~0ms.
199+
settle(errored, state.returned && durationMs > CALLBACK_MAX_AGE_MS ? 0 : durationMs);
200+
};
201+
202+
args[lastIndex] = instrumentCallback(args[lastIndex] as (...a: unknown[]) => unknown, false, emit);
203+
if (failureIndex >= 0) {
204+
args[failureIndex] = instrumentCallback(args[failureIndex] as (...a: unknown[]) => unknown, failureIsError, emit);
205+
}
206+
207+
return {
208+
markReturned: (): void => {
209+
// Set before the guarded part: a later callback must be attributed as
210+
// 'async' even if registering the pending entry fails.
211+
state.returned = true;
212+
if (state.settled) {
213+
return;
214+
}
215+
try {
216+
evictStalePendingCallbackCalls(startedAtMs);
217+
state.pendingId = nextPendingCallbackId++;
218+
pendingCallbackCalls.set(state.pendingId, {
219+
startedAtMs,
220+
// Closed out before the callback fired: keep the call in the
221+
// aggregate, but with no duration we can stand behind.
222+
expire: (): void => {
223+
state.pendingId = undefined;
224+
settle(false, 0);
225+
},
226+
});
227+
} catch (e) {
228+
// Only the bound on this one call is lost; the callback can still
229+
// close the record when it fires.
230+
state.pendingId = undefined;
231+
debug.warn(`[TurboModuleTracker] pending registration failed for ${name}.${method}: ${String(e)}`);
232+
}
233+
},
234+
abandon: (): boolean => {
235+
// Throw-free: only local state and a `Map.delete`.
236+
const alreadyRecorded = state.settled;
237+
state.settled = true;
238+
forgetPendingCall(state);
239+
return alreadyRecorded;
240+
},
241+
};
242+
}
243+
244+
/** Drops the pending entry, if any, without emitting a record. */
245+
function forgetPendingCall(state: CallbackCallState): void {
246+
if (state.pendingId !== undefined) {
247+
pendingCallbackCalls.delete(state.pendingId);
248+
state.pendingId = undefined;
249+
}
250+
}
251+
252+
/**
253+
* Returns a stand-in for `callback` that closes the pending record before
254+
* handing control to the original. The bookkeeping runs first so the callback's
255+
* own body isn't counted as native time, and is isolated so a tracker failure
256+
* can never break the user's callback.
257+
*/
258+
function instrumentCallback(
259+
callback: (...a: unknown[]) => unknown,
260+
errored: boolean,
261+
emit: (errored: boolean) => void,
262+
): (...a: unknown[]) => unknown {
263+
return function sentryTurboModuleCallback(this: unknown, ...callbackArgs: unknown[]): unknown {
264+
try {
265+
emit(errored);
266+
} catch (e) {
267+
debug.warn(`[TurboModuleTracker] callback record failed: ${String(e)}`);
268+
}
269+
return callback.apply(this, callbackArgs);
270+
};
271+
}
272+
273+
/**
274+
* Closes out pending callback calls that aged out, plus the oldest entry when
275+
* the cap is reached. Bounded per invocation so the sweep stays amortised O(1)
276+
* on the wrap hot path.
277+
*
278+
* `nowMs` is the current call's start timestamp — taken microseconds ago, so it
279+
* saves a `Date.now()` on the hot path at the cost of an imperceptibly
280+
* conservative cutoff.
281+
*/
282+
function evictStalePendingCallbackCalls(nowMs: number): void {
283+
let budget = CALLBACK_SWEEP_BUDGET;
284+
for (const [id, pending] of pendingCallbackCalls) {
285+
if (budget-- <= 0 || nowMs - pending.startedAtMs <= CALLBACK_MAX_AGE_MS) {
286+
break;
287+
}
288+
pendingCallbackCalls.delete(id);
289+
pending.expire();
290+
}
291+
292+
while (pendingCallbackCalls.size >= MAX_PENDING_CALLBACK_CALLS) {
293+
const oldest = pendingCallbackCalls.entries().next();
294+
if (oldest.done) {
295+
break;
296+
}
297+
const [id, pending] = oldest.value;
298+
pendingCallbackCalls.delete(id);
299+
pending.expire();
300+
debug.log(
301+
`[TurboModuleTracker] More than ${MAX_PENDING_CALLBACK_CALLS} callback-style calls awaiting completion — ` +
302+
`closing the oldest one without a duration.`,
303+
);
304+
}
305+
}

0 commit comments

Comments
 (0)