diff --git a/CHANGELOG.md b/CHANGELOG.md index 7626f3625..a9c1fba55 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,10 @@ ## Unreleased +### Changes + +- Native Frames uses `spanId` to attach frames replacing `traceId` ([#4030](https://github.com/getsentry/sentry-react-native/pull/4030)) + ### Dependencies - Bump JavaScript SDK from v8.11.0 to v8.26.0 ([#3851](https://github.com/getsentry/sentry-react-native/pull/3851)) diff --git a/src/js/integrations/default.ts b/src/js/integrations/default.ts index 130dd2766..3565534bb 100644 --- a/src/js/integrations/default.ts +++ b/src/js/integrations/default.ts @@ -12,6 +12,8 @@ import { browserGlobalHandlersIntegration, browserLinkedErrorsIntegration, browserReplayIntegration, + createNativeFramesIntegrations, + createReactNativeRewriteFrames, debugSymbolicatorIntegration, dedupeIntegration, deviceContextIntegration, @@ -24,7 +26,6 @@ import { inboundFiltersIntegration, mobileReplayIntegration, modulesLoaderIntegration, - nativeFramesIntegration, nativeLinkedErrorsIntegration, nativeReleaseIntegration, reactNativeErrorHandlersIntegration, @@ -36,7 +37,6 @@ import { userInteractionIntegration, viewHierarchyIntegration, } from './exports'; -import { createReactNativeRewriteFrames } from './rewriteframes'; /** * Returns the default ReactNative integrations based on the current environment. @@ -104,8 +104,11 @@ export function getDefaultIntegrations(options: ReactNativeClientOptions): Integ if (hasTracingEnabled && options.enableAppStartTracking) { integrations.push(appStartIntegration()); } - if (hasTracingEnabled && options.enableNativeFramesTracking) { - integrations.push(nativeFramesIntegration()); + const nativeFramesIntegrationInstance = createNativeFramesIntegrations( + hasTracingEnabled && options.enableNativeFramesTracking, + ); + if (nativeFramesIntegrationInstance) { + integrations.push(nativeFramesIntegrationInstance); } if (hasTracingEnabled && options.enableStallTracking) { integrations.push(stallTrackingIntegration()); diff --git a/src/js/integrations/exports.ts b/src/js/integrations/exports.ts index 345be885a..07cc3289a 100644 --- a/src/js/integrations/exports.ts +++ b/src/js/integrations/exports.ts @@ -14,9 +14,10 @@ export { expoContextIntegration } from './expocontext'; export { spotlightIntegration } from './spotlight'; export { mobileReplayIntegration } from '../replay/mobilereplay'; export { appStartIntegration } from '../tracing/integrations/appStart'; -export { nativeFramesIntegration } from '../tracing/integrations/nativeFrames'; +export { nativeFramesIntegration, createNativeFramesIntegrations } from '../tracing/integrations/nativeFrames'; export { stallTrackingIntegration } from '../tracing/integrations/stalltracking'; export { userInteractionIntegration } from '../tracing/integrations/userInteraction'; +export { createReactNativeRewriteFrames } from './rewriteframes'; export { breadcrumbsIntegration, diff --git a/src/js/tracing/integrations/nativeFrames.ts b/src/js/tracing/integrations/nativeFrames.ts index 012e2d534..cab525685 100644 --- a/src/js/tracing/integrations/nativeFrames.ts +++ b/src/js/tracing/integrations/nativeFrames.ts @@ -1,18 +1,37 @@ -import { spanToJSON } from '@sentry/core'; import type { Client, Event, Integration, Measurements, MeasurementUnit, Span } from '@sentry/types'; import { logger, timestampInSeconds } from '@sentry/utils'; import type { NativeFramesResponse } from '../../NativeRNSentry'; -import type { ReactNativeClientOptions } from '../../options'; +import { AsyncExpiringMap } from '../../utils/AsyncExpiringMap'; import { isRootSpan } from '../../utils/span'; import { NATIVE } from '../../wrapper'; /** - * Timeout from the final native frames fetch to processing the associated transaction. - * If the transaction is not processed by this time, the native frames will be dropped - * and not added to the event. + * Timeout from the start of a span to fetching the associated native frames. */ -const FINAL_FRAMES_TIMEOUT_MS = 2000; +const FETCH_FRAMES_TIMEOUT_MS = 2_000; + +/** + * This is the time end frames data from the native layer will be + * kept in memory and waiting for the event processing. This ensures that spans + * which are never processed are not leaking memory. + */ +const END_FRAMES_TIMEOUT_MS = 2_000; + +/** + * This is the time start frames data from the native layer will be + * kept in memory and waiting for span end. This ensures that spans + * which never end or are not processed are not leaking memory. + */ +const START_FRAMES_TIMEOUT_MS = 60_000; + +/** + * A margin of error of 50ms is allowed for the async native bridge call. + * Anything larger would reduce the accuracy of our frames measurements. + */ +const MARGIN_OF_ERROR_SECONDS = 0.05; + +const INTEGRATION_NAME = 'NativeFrames'; export interface FramesMeasurements extends Measurements { frames_total: { value: number; unit: MeasurementUnit }; @@ -20,220 +39,163 @@ export interface FramesMeasurements extends Measurements { frames_frozen: { value: number; unit: MeasurementUnit }; } -/** The listeners for each native frames response, keyed by traceId. This must be global to avoid closure issues and reading outdated values. */ -const _framesListeners: Map void> = new Map(); +interface NativeFramesResponseWithTimestamp { + timestamp: number; + nativeFrames: NativeFramesResponse; +} -/** The native frames at the transaction finish time, keyed by traceId. This must be global to avoid closure issues and reading outdated values. */ -const _finishFrames: Map = new Map(); +export const createNativeFramesIntegrations = (enable: boolean | undefined): Integration | undefined => { + if (!enable && NATIVE.enableNative) { + // On Android this will free up resource when JS reloaded (native modules stay) and thus JS side of the SDK reinitialized. + NATIVE.disableNativeFramesTracking(); + return undefined; + } -/** - * A margin of error of 50ms is allowed for the async native bridge call. - * Anything larger would reduce the accuracy of our frames measurements. - */ -const MARGIN_OF_ERROR_SECONDS = 0.05; + return nativeFramesIntegration(); +}; /** * Instrumentation to add native slow/frozen frames measurements onto transactions. */ export const nativeFramesIntegration = (): Integration => { - const name: string = 'NativeFrames'; - /** The native frames at the finish time of the most recent span. */ - let _lastSpanFinishFrames: - | { - timestamp: number; - nativeFrames: NativeFramesResponse; - } - | undefined = undefined; - const _spanToNativeFramesAtStartMap: Map = new Map(); + let _lastChildSpanEndFrames: NativeFramesResponseWithTimestamp | null = null; + const _spanToNativeFramesAtStartMap: AsyncExpiringMap = new AsyncExpiringMap({ + ttl: START_FRAMES_TIMEOUT_MS, + }); + const _spanToNativeFramesAtEndMap: AsyncExpiringMap = + new AsyncExpiringMap({ ttl: END_FRAMES_TIMEOUT_MS }); /** * Hooks into the client start and end span events. */ const setup = (client: Client): void => { - const { enableNativeFramesTracking } = client.getOptions() as ReactNativeClientOptions; - - if (enableNativeFramesTracking && !NATIVE.enableNative) { - // Do not enable native frames tracking if native is not available. + if (!NATIVE.enableNative) { logger.warn( - '[ReactNativeTracing] NativeFramesTracking is not available on the Web, Expo Go and other platforms without native modules.', + `[${INTEGRATION_NAME}] This is not available on the Web, Expo Go and other platforms without native modules.`, ); - return; - } - - if (!enableNativeFramesTracking && NATIVE.enableNative) { - // Disable native frames tracking when native available and option is false. - NATIVE.disableNativeFramesTracking(); - return; - } - - if (!enableNativeFramesTracking) { - return; + return undefined; } NATIVE.enableNativeFramesTracking(); - - client.on('spanStart', _onSpanStart); - client.on('spanEnd', _onSpanFinish); - logger.log('[ReactNativeTracing] Native frames instrumentation initialized.'); - }; - - /** - * Adds frames measurements to an event. Called from a valid event processor. - * Awaits for finish frames if needed. - */ - const processEvent = (event: Event): Promise => { - return _processEvent(event); + client.on('spanStart', fetchStartFramesForSpan); + client.on('spanEnd', fetchEndFramesForSpan); }; - /** - * Fetches the native frames in background if the given span is a root span. - * - * @param {Span} rootSpan - The span that has started. - */ - const _onSpanStart = (rootSpan: Span): void => { + const fetchStartFramesForSpan = (rootSpan: Span): void => { if (!isRootSpan(rootSpan)) { return; } - logger.debug(`[NativeFrames] Fetching frames for root span start (${rootSpan.spanContext().spanId}).`); - - NATIVE.fetchNativeFrames() - .then(frames => { - if (!frames) { - logger.warn( - `[NativeFrames] Fetched frames for root span start (${ - rootSpan.spanContext().spanId - }), but no frames were returned.`, - ); - return; - } - - _spanToNativeFramesAtStartMap.set(rootSpan.spanContext().traceId, frames); - }) - .then(undefined, error => { - logger.error( - `[NativeFrames] Error while fetching frames for root span start (${rootSpan.spanContext().spanId})`, - error, - ); - }); + const spanId = rootSpan.spanContext().spanId; + logger.debug(`[${INTEGRATION_NAME}] Fetching frames for root span start (${spanId}).`); + _spanToNativeFramesAtStartMap.set( + spanId, + new Promise(resolve => { + fetchNativeFrames() + .then(frames => resolve(frames)) + .then(undefined, error => { + logger.debug(`[${INTEGRATION_NAME}] Error while fetching native frames.`, error); + resolve(null); + }); + }), + ); }; - /** - * Called on a span finish to fetch native frames to support transactions with trimEnd. - * Only to be called when a span does not have an end timestamp. - */ - const _onSpanFinish = (span: Span): void => { - if (isRootSpan(span)) { - return _onTransactionFinish(span); - } - + const fetchEndFramesForSpan = (span: Span): void => { const timestamp = timestampInSeconds(); + const spanId = span.spanContext().spanId; - void NATIVE.fetchNativeFrames() - .then(frames => { - if (!frames) { - return; - } - - _lastSpanFinishFrames = { - timestamp, - nativeFrames: frames, - }; - }) - .then(undefined, error => { - logger.error(`[NativeFrames] Error while fetching frames for child span end.`, error); - }); - }; + if (isRootSpan(span)) { + const hasStartFrames = _spanToNativeFramesAtStartMap.has(spanId); + if (!hasStartFrames) { + // We don't have start frames, won't be able to calculate the difference. + return; + } - /** - * To be called when a transaction is finished - */ - const _onTransactionFinish = (span: Span): void => { - _fetchFramesForTransaction(span).then(undefined, (reason: unknown) => { - logger.error( - `[NativeFrames] Error while fetching frames for root span start (${span.spanContext().spanId})`, - reason, + logger.debug(`[${INTEGRATION_NAME}] Fetch frames for root span end (${spanId}).`); + _spanToNativeFramesAtEndMap.set( + spanId, + new Promise(resolve => { + fetchNativeFrames() + .then(frames => { + resolve({ + timestamp, + nativeFrames: frames, + }); + }) + .then(undefined, error => { + logger.debug(`[${INTEGRATION_NAME}] Error while fetching native frames.`, error); + resolve(null); + }); + }), ); - }); + return undefined; + } else { + logger.debug(`[${INTEGRATION_NAME}] Fetch frames for child span end (${spanId}).`); + fetchNativeFrames() + .then(frames => { + _lastChildSpanEndFrames = { + timestamp, + nativeFrames: frames, + }; + }) + .catch(error => logger.debug(`[${INTEGRATION_NAME}] Error while fetching native frames.`, error)); + } }; - /** - * Returns the computed frames measurements and awaits for them if they are not ready yet. - */ - const _getFramesMeasurements = ( - traceId: string, - finalEndTimestamp: number, - startFrames: NativeFramesResponse, - ): Promise => { - if (_finishFrames.has(traceId)) { - logger.debug(`[NativeFrames] Native end frames already fetched for trace id (${traceId}).`); - return Promise.resolve(_prepareMeasurements(traceId, finalEndTimestamp, startFrames)); + const processEvent = async (event: Event): Promise => { + if ( + event.type !== 'transaction' || + !event.transaction || + !event.contexts || + !event.contexts.trace || + !event.timestamp || + !event.contexts.trace.span_id + ) { + return event; } - return new Promise(resolve => { - const timeout = setTimeout(() => { - logger.debug(`[NativeFrames] Native end frames listener removed by timeout for trace id (${traceId}).`); - _framesListeners.delete(traceId); - - resolve(null); - }, 2000); - - _framesListeners.set(traceId, () => { - logger.debug(`[NativeFrames] Native end frames listener called for trace id (${traceId}).`); - resolve(_prepareMeasurements(traceId, finalEndTimestamp, startFrames)); - - clearTimeout(timeout); - _framesListeners.delete(traceId); - }); - }); - }; + const traceOp = event.contexts.trace.op; + const spanId = event.contexts.trace.span_id; + const startFrames = await _spanToNativeFramesAtStartMap.pop(spanId); + if (!startFrames) { + logger.warn( + `[${INTEGRATION_NAME}] Start frames of transaction ${event.transaction} (eventId, ${event.event_id}) are missing, but the transaction already ended.`, + ); + return event; + } - /** - * Returns the computed frames measurements given ready data - */ - const _prepareMeasurements = ( - traceId: string, - finalEndTimestamp: number, // The actual transaction finish time. - startFrames: NativeFramesResponse, - ): FramesMeasurements | null => { - let finalFinishFrames: NativeFramesResponse | undefined; + const endFrames = await _spanToNativeFramesAtEndMap.pop(spanId); + let finalEndFrames: NativeFramesResponse | undefined; - const finish = _finishFrames.get(traceId); - if ( - finish && - finish.nativeFrames && + if (endFrames && isClose(endFrames.timestamp, event.timestamp)) { // Must be in the margin of error of the actual transaction finish time (finalEndTimestamp) - Math.abs(finish.timestamp - finalEndTimestamp) < MARGIN_OF_ERROR_SECONDS - ) { - logger.debug(`[NativeFrames] Using frames from root span end (traceId, ${traceId}).`); - finalFinishFrames = finish.nativeFrames; - } else if ( - _lastSpanFinishFrames && - Math.abs(_lastSpanFinishFrames.timestamp - finalEndTimestamp) < MARGIN_OF_ERROR_SECONDS - ) { + logger.debug(`[${INTEGRATION_NAME}] Using frames from root span end (spanId, ${spanId}).`); + finalEndFrames = endFrames.nativeFrames; + } else if (_lastChildSpanEndFrames && isClose(_lastChildSpanEndFrames.timestamp, event.timestamp)) { // Fallback to the last span finish if it is within the margin of error of the actual finish timestamp. // This should be the case for trimEnd. - logger.debug(`[NativeFrames] Using native frames from last span end (traceId, ${traceId}).`); - finalFinishFrames = _lastSpanFinishFrames.nativeFrames; + logger.debug(`[${INTEGRATION_NAME}] Using native frames from last child span end (spanId, ${spanId}).`); + finalEndFrames = _lastChildSpanEndFrames.nativeFrames; } else { logger.warn( - `[NativeFrames] Frames were collected within larger than margin of error delay for traceId (${traceId}). Dropping the inaccurate values.`, + `[${INTEGRATION_NAME}] Frames were collected within larger than margin of error delay for spanId (${spanId}). Dropping the inaccurate values.`, ); - return null; + return event; } const measurements = { frames_total: { - value: finalFinishFrames.totalFrames - startFrames.totalFrames, + value: finalEndFrames.totalFrames - startFrames.totalFrames, unit: 'none', }, frames_frozen: { - value: finalFinishFrames.frozenFrames - startFrames.frozenFrames, + value: finalEndFrames.frozenFrames - startFrames.frozenFrames, unit: 'none', }, frames_slow: { - value: finalFinishFrames.slowFrames - startFrames.slowFrames, + value: finalEndFrames.slowFrames - startFrames.slowFrames, unit: 'none', }, }; @@ -244,118 +206,52 @@ export const nativeFramesIntegration = (): Integration => { measurements.frames_total.value <= 0 ) { logger.warn( - `[NativeFrames] Detected zero slow or frozen frames. Not adding measurements to traceId (${traceId}).`, - ); - return null; - } - - return measurements; - }; - - /** - * Fetch finish frames for a transaction at the current time. Calls any awaiting listeners. - */ - const _fetchFramesForTransaction = async (span: Span): Promise => { - const traceId = spanToJSON(span).trace_id; - if (!traceId) { - return; - } - - const startFrames = _spanToNativeFramesAtStartMap.get(span.spanContext().traceId); - - // This timestamp marks when the finish frames were retrieved. It should be pretty close to the transaction finish. - const timestamp = timestampInSeconds(); - let finishFrames: NativeFramesResponse | null = null; - if (startFrames) { - finishFrames = await NATIVE.fetchNativeFrames(); - } - - _finishFrames.set(traceId, { - nativeFrames: finishFrames, - timestamp, - }); - - _framesListeners.get(traceId)?.(); - - setTimeout(() => _cancelEndFrames(span), FINAL_FRAMES_TIMEOUT_MS); - }; - - /** - * On a finish frames failure, we cancel the await. - */ - const _cancelEndFrames = (span: Span): void => { - const spanJSON = spanToJSON(span); - const traceId = spanJSON.trace_id; - if (!traceId) { - return; - } - - if (_finishFrames.has(traceId)) { - _finishFrames.delete(traceId); - - logger.log( - `[NativeFrames] Native frames timed out for ${spanJSON.op} transaction ${spanJSON.description}. Not adding native frames measurements.`, - ); - } - }; - - /** - * Adds frames measurements to an event. Called from a valid event processor. - * Awaits for finish frames if needed. - */ - const _processEvent = async (event: Event): Promise => { - if ( - event.type !== 'transaction' || - !event.transaction || - !event.contexts || - !event.contexts.trace || - !event.timestamp || - !event.contexts.trace.trace_id - ) { - return event; - } - - const traceOp = event.contexts.trace.op; - const traceId = event.contexts.trace.trace_id; - const startFrames = _spanToNativeFramesAtStartMap.get(traceId); - _spanToNativeFramesAtStartMap.delete(traceId); - if (!startFrames) { - logger.warn( - `[NativeFrames] Start frames of transaction ${event.transaction} (eventId, ${event.event_id}) are missing, but it already ended.`, - ); - return event; - } - - const measurements = await _getFramesMeasurements(traceId, event.timestamp, startFrames); - - if (!measurements) { - logger.log( - `[NativeFrames] Could not fetch native frames for ${traceOp} transaction ${event.transaction}. Not adding native frames measurements.`, + `[${INTEGRATION_NAME}] Detected zero slow or frozen frames. Not adding measurements to spanId (${spanId}).`, ); return event; } logger.log( - `[Measurements] Adding measurements to ${traceOp} transaction ${event.transaction}: ${JSON.stringify( + `[${INTEGRATION_NAME}] Adding measurements to ${traceOp} transaction ${event.transaction}: ${JSON.stringify( measurements, undefined, 2, )}`, ); - event.measurements = { ...(event.measurements ?? {}), ...measurements, }; - - _finishFrames.delete(traceId); - return event; }; return { - name, + name: INTEGRATION_NAME, setup, processEvent, }; }; + +function fetchNativeFrames(): Promise { + return new Promise((resolve, reject) => { + NATIVE.fetchNativeFrames() + .then(value => { + if (!value) { + reject('Native frames response is null.'); + return; + } + resolve(value); + }) + .then(undefined, error => { + reject(error); + }); + + setTimeout(() => { + reject('Fetching native frames took too long. Dropping frames.'); + }, FETCH_FRAMES_TIMEOUT_MS); + }); +} + +function isClose(t1: number, t2: number): boolean { + return Math.abs(t1 - t2) < MARGIN_OF_ERROR_SECONDS; +} diff --git a/src/js/utils/AsyncExpiringMap.ts b/src/js/utils/AsyncExpiringMap.ts new file mode 100644 index 000000000..3f3906c9c --- /dev/null +++ b/src/js/utils/AsyncExpiringMap.ts @@ -0,0 +1,163 @@ +/** + * A Map that automatically removes entries after their TTL has expired. + * + * The map is Promise-aware, meaning it will start TTL countdown only after the promise has resolved. + */ +export class AsyncExpiringMap { + private _ttl: number; + private _cleanupIntervalMs: number; + private _map: Map | null }>; + private _cleanupInterval: ReturnType; + + public constructor({ + cleanupInterval = 5_000, + ttl = 2_000, + }: { + cleanupInterval?: number; + ttl?: number; + } = {}) { + this._ttl = ttl; + this._map = new Map(); + this._cleanupIntervalMs = cleanupInterval; + this.startCleanup(); + } + + /** + * Set a key-value pair. + */ + public set(key: K, promise: PromiseLike | V): void { + if (!this._cleanupInterval) { + this.startCleanup(); + } + + if (typeof promise !== 'object' || !('then' in promise)) { + this._map.set(key, { value: promise, expiresAt: Date.now() + this._ttl, promise: null }); + return; + } + + const entry: { value: V | undefined; expiresAt: number | null; promise: PromiseLike | null } = { + value: undefined, + expiresAt: null, + promise, + }; + this._map.set(key, entry); + + promise.then( + value => { + entry.value = value; + entry.expiresAt = Date.now() + this._ttl; + entry.promise = null; + }, + () => { + entry.expiresAt = Date.now() + this._ttl; + entry.promise = null; + }, + ); + } + + /** + * Pops a key-value pair. + */ + public pop(key: K): PromiseLike | V | undefined { + const entry = this.get(key); + this._map.delete(key); + return entry; + } + + /** + * Get a value by key. + * + * If the values is expired it will be returned and removed from the map. + */ + public get(key: K): PromiseLike | V | undefined { + const entry = this._map.get(key); + + if (!entry) { + return undefined; + } + + if (entry.promise) { + return entry.promise; + } + + if (entry.expiresAt && entry.expiresAt <= Date.now()) { + this._map.delete(key); + } + + return entry.value; + } + + /** + * Check if a key exists in the map. + * + * If the key is expired it's not present in the map. + */ + public has(key: K): boolean { + const entry = this._map.get(key); + + if (!entry) { + return false; + } + + if (entry.promise) { + return true; + } + + if (entry.expiresAt && entry.expiresAt <= Date.now()) { + this._map.delete(key); + return false; + } + + return true; + } + + /** + * Get the remaining time to live of a key. + */ + public ttl(key: K): number | undefined { + const entry = this._map.get(key); + if (entry && entry.expiresAt) { + const remainingTime = entry.expiresAt - Date.now(); + return remainingTime > 0 ? remainingTime : 0; + } + return undefined; + } + + /** + * Remove expired entries. + */ + public cleanup(): void { + const now = Date.now(); + for (const [key, entry] of this._map.entries()) { + if (entry.expiresAt && entry.expiresAt <= now) { + this._map.delete(key); + } + } + const size = this._map.size; + if (!size) { + this.stopCleanup(); + } + } + + /** + * Clear all entries. + */ + public clear(): void { + clearInterval(this._cleanupInterval); + this._map.clear(); + } + + /** + * Stop the cleanup interval. + */ + public stopCleanup(): void { + clearInterval(this._cleanupInterval); + } + + /** + * Start the cleanup interval. + */ + public startCleanup(): void { + this._cleanupInterval = setInterval(() => this.cleanup(), this._cleanupIntervalMs); + } +} diff --git a/test/profiling/integration.test.ts b/test/profiling/integration.test.ts index 1488c7d4f..6d6cb3ba0 100644 --- a/test/profiling/integration.test.ts +++ b/test/profiling/integration.test.ts @@ -340,6 +340,7 @@ function initTestClient( const options: Sentry.ReactNativeOptions = { dsn: MOCK_DSN, enableTracing: true, + enableNativeFramesTracking: false, _experiments: { profilesSampleRate: 1, }, diff --git a/test/tracing/integrations/nativeframes.test.ts b/test/tracing/integrations/nativeframes.test.ts index 7c483b0b0..c5453dcc8 100644 --- a/test/tracing/integrations/nativeframes.test.ts +++ b/test/tracing/integrations/nativeframes.test.ts @@ -19,10 +19,16 @@ jest.mock('../../../src/js/wrapper', () => { jest.useFakeTimers({ advanceTimers: true }); +const mockDate = new Date(2024, 7, 14); // Set your desired mock date here +const originalDateNow = Date.now; // Store the original Date.now function + describe('NativeFramesInstrumentation', () => { let client: TestClient; + let asyncProcessorBeforeNativeFrames: (event: Event) => Promise = async (event: Event) => event; beforeEach(() => { + global.Date.now = jest.fn(() => mockDate.getTime()); + getCurrentScope().clear(); getIsolationScope().clear(); getGlobalScope().clear(); @@ -30,7 +36,13 @@ describe('NativeFramesInstrumentation', () => { const options = getDefaultTestClientOptions({ tracesSampleRate: 1.0, enableNativeFramesTracking: true, - integrations: [nativeFramesIntegration()], + integrations: [ + { + name: 'MockAsyncIntegration', + processEvent: e => asyncProcessorBeforeNativeFrames(e), + }, + nativeFramesIntegration(), + ], }); client = new TestClient(options); setCurrentClient(client); @@ -39,6 +51,7 @@ describe('NativeFramesInstrumentation', () => { afterEach(() => { jest.clearAllMocks(); + global.Date.now = originalDateNow; }); it('sets native frames measurements on a transaction event', async () => { @@ -216,6 +229,17 @@ describe('NativeFramesInstrumentation', () => { }); it('does not set measurements on a transaction event for which finishFrames times out.', async () => { + asyncProcessorBeforeNativeFrames = async (event: Event) => { + await Promise.resolve(); + await Promise.resolve(); + await Promise.resolve(); + + global.Date.now = jest.fn(() => mockDate.getTime() + 2100); // hardcoded final frames timeout 2000ms + await jest.runOnlyPendingTimersAsync(); + await jest.advanceTimersByTimeAsync(2100); // hardcoded final frames timeout 2000ms + return event; + }; + const startFrames = { totalFrames: 100, slowFrames: 20, @@ -232,8 +256,6 @@ describe('NativeFramesInstrumentation', () => { await Promise.resolve(); // native frames fetch is async call this will flush the start frames fetch promise }); - await jest.runOnlyPendingTimersAsync(); - await jest.advanceTimersByTimeAsync(2100); // hardcoded final frames timeout 2000ms await client.flush(); expect(client.event!).toBeOneOf([ diff --git a/test/utils/AsyncExpiringMap.test.ts b/test/utils/AsyncExpiringMap.test.ts new file mode 100644 index 000000000..f8953d7e3 --- /dev/null +++ b/test/utils/AsyncExpiringMap.test.ts @@ -0,0 +1,213 @@ +import { AsyncExpiringMap } from '../../src/js/utils/AsyncExpiringMap'; + +describe('AsyncExpiringMap', () => { + let now = 0; + + beforeEach(() => { + jest.useFakeTimers(); + + now = 0; + jest.spyOn(global.performance, 'now').mockImplementation(() => now); + jest.spyOn(global.Date, 'now').mockImplementation(() => now); + }); + + afterEach(() => { + jest.runOnlyPendingTimers(); + jest.useRealTimers(); + jest.restoreAllMocks(); + }); + + it('retrieves a pending promise correctly', () => { + const map = new AsyncExpiringMap>(); + const promise = new Promise(resolve => setTimeout(() => resolve('value'), 1000)); + map.set('key1', promise); + + const retrievedValue = map.get('key1'); + expect(retrievedValue).toBe(promise); + }); + + it('retrieves a resolved promise value correctly', async () => { + const map = new AsyncExpiringMap>(); + const promise = Promise.resolve('value'); + map.set('key1', promise); + + await promise; + + const retrievedValue = map.get('key1'); + expect(retrievedValue).toEqual('value'); + }); + + it('removes a resolved promise after TTL', async () => { + const ttl = 2000; + const cleanupInterval = ttl / 2; + const map = new AsyncExpiringMap({ ttl, cleanupInterval }); + + let resolvePromise: (value: string) => void; + const promise = new Promise(resolve => { + resolvePromise = resolve; + }); + map.set('key2', promise); + + now += ttl; + jest.advanceTimersByTime(ttl); + expect(map.get('key2')).toBe(promise); + + resolvePromise('value'); + await promise; + + now += ttl; + jest.advanceTimersByTime(ttl); + + const retrievedValue = map.get('key2'); + expect(retrievedValue).toBeUndefined(); + }); + + it('handles rejected promises without crashing', async () => { + const cleanupInterval = 1000; + const ttl = 2000; + const map = new AsyncExpiringMap({ ttl, cleanupInterval }); + const rejectedPromise = Promise.reject('error'); + + map.set('key9', rejectedPromise); + await rejectedPromise.catch(() => {}); + + now += ttl; + jest.advanceTimersByTime(ttl); + + const retrievedValue = map.get('key9'); + expect(retrievedValue).toBeUndefined(); + }); + + it('returns expired value if not cleaned up yet', () => { + const ttl = 2000; + const cleanupInterval = 2 * ttl; + const map = new AsyncExpiringMap({ ttl, cleanupInterval }); + + map.set('key1', 'value1'); + now += ttl; + jest.advanceTimersByTime(ttl); + + const retrievedValue = map.get('key1'); + expect(retrievedValue).toBe('value1'); + }); + + it('has function cleans expired value if not cleaned up yet', () => { + const ttl = 2000; + const cleanupInterval = 2 * ttl; + const map = new AsyncExpiringMap({ ttl, cleanupInterval }); + + map.set('key1', 'value1'); + now += ttl; + jest.advanceTimersByTime(ttl); + + const hasKey = map.has('key1'); + expect(hasKey).toBeFalse(); + + const retrievedValue = map.get('key1'); + expect(retrievedValue).toBeUndefined(); + }); + + it('pop removes a key-value pair', () => { + const map = new AsyncExpiringMap(); + + map.set('key1', 'value'); + const retrievedValue = map.pop('key1'); + expect(retrievedValue).toBe('value'); + + const hasKeyAfterPop = map.has('key1'); + expect(hasKeyAfterPop).toBeFalse(); + }); + + it('does not delete unexpired keys during cleanup', () => { + const ttl = 5000; + const map = new AsyncExpiringMap({ ttl }); + + map.set('key3', 'value3'); + + now += 2000; + jest.advanceTimersByTime(2000); + map.cleanup(); + + const retrievedValue = map.get('key3'); + expect(retrievedValue).toBe('value3'); + }); + + it('clears all entries when clear is called', () => { + const map = new AsyncExpiringMap(); + + map.set('key4', 'value4'); + map.clear(); + + const retrievedValue = map.get('key4'); + expect(retrievedValue).toBeUndefined(); + }); + + it('stops cleanup when stopCleanup is called', () => { + const map = new AsyncExpiringMap(); + + map.set('key5', 'value5'); + map.stopCleanup(); + + now += 10000; + jest.advanceTimersByTime(10000); + expect(map.get('key5')).toBe('value5'); + }); + + it('restarts cleanup when startCleanup is called', () => { + const ttl = 2000; + const cleanupInterval = ttl / 2; + const map = new AsyncExpiringMap({ ttl, cleanupInterval }); + + map.set('key6', 'value6'); + map.stopCleanup(); + + now += ttl; + jest.advanceTimersByTime(ttl); + expect(map.get('key6')).toBe('value6'); + + map.startCleanup(); + now += ttl; + jest.advanceTimersByTime(ttl); + + const retrievedValue = map.get('key6'); + expect(retrievedValue).toBeUndefined(); + }); + + it('correctly reports the TTL of an existing entry', () => { + const ttl = 5000; + const map = new AsyncExpiringMap({ ttl }); + + map.set('key7', 'value7'); + now += 2000; + jest.advanceTimersByTime(2000); + + const remainingTTL = map.ttl('key7'); + expect(remainingTTL).toBeGreaterThan(0); + expect(remainingTTL).toBeLessThanOrEqual(ttl - 2000); + }); + + it('handles setting non-promise values correctly', () => { + const map = new AsyncExpiringMap(); + + map.set('key8', 'value8'); + const retrievedValue = map.get('key8'); + + expect(retrievedValue).toBe('value8'); + }); + + it('handles multiple entries with different TTLs correctly', () => { + const cleanupInterval = 1000; + const ttl = 2000; + const map = new AsyncExpiringMap({ ttl, cleanupInterval }); + + map.set('key10', 'value10'); + map.set('key11', 'value11'); + now += ttl; + jest.advanceTimersByTime(ttl); + map.set('key12', 'value12'); + + expect(map.get('key10')).toBeUndefined(); // Expired + expect(map.get('key11')).toBeUndefined(); // Expired + expect(map.get('key12')).toBe('value12'); // Not yet expired + }); +});