From 08840767b4a065389465ab6796c9e66b9911203f Mon Sep 17 00:00:00 2001 From: Krystof Woldrich <31292499+krystofwoldrich@users.noreply.github.com> Date: Mon, 10 Jun 2024 14:06:22 +0200 Subject: [PATCH] feat(tracing): Add native application start spans (#3855) --- CHANGELOG.md | 5 ++ .../io/sentry/react/RNSentryModuleImpl.java | 25 ++---- ios/RNSentry.mm | 24 +++-- src/js/NativeRNSentry.ts | 11 ++- src/js/tracing/reactnativetracing.ts | 40 +++++++-- test/tracing/reactnativetracing.test.ts | 89 +++++++++++++++---- test/tracing/reactnavigation.ttid.test.tsx | 7 +- 7 files changed, 139 insertions(+), 62 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 75dadafde4..8dd19d92e7 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,11 @@ ## Unreleased +### Features + +- Add native application start spans ([#3855](https://github.com/getsentry/sentry-react-native/pull/3855)) + - This doesn't change the app start measurement length, but add child spans (more detail) into the existing app start span + ### Dependencies - Bump Cocoa SDK from v8.27.0 to v8.28.0 ([#3866](https://github.com/getsentry/sentry-react-native/pull/3866)) diff --git a/android/src/main/java/io/sentry/react/RNSentryModuleImpl.java b/android/src/main/java/io/sentry/react/RNSentryModuleImpl.java index 4c69337e2b..9b9195d4dd 100644 --- a/android/src/main/java/io/sentry/react/RNSentryModuleImpl.java +++ b/android/src/main/java/io/sentry/react/RNSentryModuleImpl.java @@ -103,7 +103,7 @@ public class RNSentryModuleImpl { private FrameMetricsAggregator frameMetricsAggregator = null; private boolean androidXAvailable; - private static boolean didFetchAppStart; + private static boolean hasFetchedAppStart; // 700ms to constitute frozen frames. private static final int FROZEN_FRAME_THRESHOLD = 700; @@ -334,28 +334,17 @@ public void fetchNativeRelease(Promise promise) { } public void fetchNativeAppStart(Promise promise) { - final AppStartMetrics appStartInstance = AppStartMetrics.getInstance(); - final SentryDate appStartTime = appStartInstance.getAppStartTimeSpan().getStartTimestamp(); - final boolean isColdStart = appStartInstance.getAppStartType() == AppStartMetrics.AppStartType.COLD; + final Map measurement = InternalSentrySdk.getAppStartMeasurement(); - if (appStartTime == null) { - logger.log(SentryLevel.WARNING, "App start won't be sent due to missing appStartTime."); - promise.resolve(null); - } else { - final double appStartTimestampMs = DateUtils.nanosToMillis(appStartTime.nanoTimestamp()); - - WritableMap appStart = Arguments.createMap(); + WritableMap mutableMeasurement = (WritableMap) RNSentryMapConverter.convertToWritable(measurement); + mutableMeasurement.putBoolean("has_fetched", hasFetchedAppStart); - appStart.putDouble("appStartTime", appStartTimestampMs); - appStart.putBoolean("isColdStart", isColdStart); - appStart.putBoolean("didFetchAppStart", didFetchAppStart); - - promise.resolve(appStart); - } // This is always set to true, as we would only allow an app start fetch to only // happen once in the case of a JS bundle reload, we do not want it to be // instrumented again. - didFetchAppStart = true; + hasFetchedAppStart = true; + + promise.resolve(mutableMeasurement); } /** diff --git a/ios/RNSentry.mm b/ios/RNSentry.mm index 6c0b91b60f..1ae62f71e8 100644 --- a/ios/RNSentry.mm +++ b/ios/RNSentry.mm @@ -55,7 +55,7 @@ + (void)storeEnvelope:(SentryEnvelope *)envelope; @end -static bool didFetchAppStart; +static bool hasFetchedAppStart; static NSString* const nativeSdkName = @"sentry.cocoa.react-native"; @@ -380,24 +380,20 @@ - (NSDictionary*) fetchNativeStackFramesBy: (NSArray*)instructionsAdd rejecter:(RCTPromiseRejectBlock)reject) { #if SENTRY_HAS_UIKIT - SentryAppStartMeasurement *appStartMeasurement = PrivateSentrySDKOnly.appStartMeasurement; - - if (appStartMeasurement == nil) { + NSDictionary *measurements = [PrivateSentrySDKOnly appStartMeasurementWithSpans]; + if (measurements == nil) { resolve(nil); - } else { - BOOL isColdStart = appStartMeasurement.type == SentryAppStartTypeCold; - - resolve(@{ - @"isColdStart": [NSNumber numberWithBool:isColdStart], - @"appStartTime": [NSNumber numberWithDouble:(appStartMeasurement.appStartTimestamp.timeIntervalSince1970 * 1000)], - @"didFetchAppStart": [NSNumber numberWithBool:didFetchAppStart], - }); - + return; } + NSMutableDictionary *mutableMeasurements = [[NSMutableDictionary alloc] initWithDictionary:measurements]; + [mutableMeasurements setValue:[NSNumber numberWithBool:hasFetchedAppStart] forKey:@"has_fetched"]; + // This is always set to true, as we would only allow an app start fetch to only happen once // in the case of a JS bundle reload, we do not want it to be instrumented again. - didFetchAppStart = true; + hasFetchedAppStart = true; + + resolve(mutableMeasurements); #else resolve(nil); #endif diff --git a/src/js/NativeRNSentry.ts b/src/js/NativeRNSentry.ts index b76ce28485..3af21faae6 100644 --- a/src/js/NativeRNSentry.ts +++ b/src/js/NativeRNSentry.ts @@ -90,9 +90,14 @@ export type NativeStackFrames = { }; export type NativeAppStartResponse = { - isColdStart: boolean; - appStartTime: number; - didFetchAppStart: boolean; + type: 'cold' | 'warm' | 'unknown'; + has_fetched: boolean; + app_start_timestamp_ms?: number; + spans: { + description: string; + start_timestamp_ms: number; + end_timestamp_ms: number; + }[]; }; export type NativeFramesResponse = { diff --git a/src/js/tracing/reactnativetracing.ts b/src/js/tracing/reactnativetracing.ts index a85f26cd3a..a242ab3492 100644 --- a/src/js/tracing/reactnativetracing.ts +++ b/src/js/tracing/reactnativetracing.ts @@ -7,6 +7,7 @@ import type { Event, EventProcessor, Integration, + Span, Transaction as TransactionType, TransactionContext, } from '@sentry/types'; @@ -404,11 +405,11 @@ export class ReactNativeTracing implements Integration { * Returns the App Start Duration in Milliseconds. Also returns undefined if not able do * define the duration. */ - private _getAppStartDurationMilliseconds(appStart: NativeAppStartResponse): number | undefined { + private _getAppStartDurationMilliseconds(appStartTimestampMs: number): number | undefined { if (!this._appStartFinishTimestamp) { return undefined; } - return this._appStartFinishTimestamp * 1000 - appStart.appStartTime; + return this._appStartFinishTimestamp * 1000 - appStartTimestampMs; } /** @@ -427,7 +428,7 @@ export class ReactNativeTracing implements Integration { return; } - if (appStart.didFetchAppStart) { + if (appStart.has_fetched) { logger.warn('[ReactNativeTracing] Not instrumenting App Start because this start was already reported.'); return; } @@ -455,7 +456,13 @@ export class ReactNativeTracing implements Integration { * Adds app start measurements and starts a child span on a transaction. */ private _addAppStartData(transaction: IdleTransaction, appStart: NativeAppStartResponse): void { - const appStartDurationMilliseconds = this._getAppStartDurationMilliseconds(appStart); + const appStartTimestampMs = appStart.app_start_timestamp_ms; + if (!appStartTimestampMs) { + logger.warn('App start timestamp could not be loaded from the native layer.'); + return; + } + + const appStartDurationMilliseconds = this._getAppStartDurationMilliseconds(appStartTimestampMs); if (!appStartDurationMilliseconds) { logger.warn('[ReactNativeTracing] App start end has not been recorded, not adding app start span.'); return; @@ -469,7 +476,7 @@ export class ReactNativeTracing implements Integration { return; } - const appStartTimeSeconds = appStart.appStartTime / 1000; + const appStartTimeSeconds = appStartTimestampMs / 1000; transaction.startTimestamp = appStartTimeSeconds; @@ -485,18 +492,33 @@ export class ReactNativeTracing implements Integration { setSpanDurationAsMeasurement('time_to_full_display', maybeTtfdSpan); } - const op = appStart.isColdStart ? APP_START_COLD_OP : APP_START_WARM_OP; - transaction.startChild({ - description: appStart.isColdStart ? 'Cold App Start' : 'Warm App Start', + const op = appStart.type === 'cold' ? APP_START_COLD_OP : APP_START_WARM_OP; + const appStartSpan = transaction.startChild({ + description: appStart.type === 'cold' ? 'Cold App Start' : 'Warm App Start', op, startTimestamp: appStartTimeSeconds, endTimestamp: this._appStartFinishTimestamp, }); + this._addNativeSpansTo(appStartSpan, appStart.spans); - const measurement = appStart.isColdStart ? APP_START_COLD : APP_START_WARM; + const measurement = appStart.type === 'cold' ? APP_START_COLD : APP_START_WARM; transaction.setMeasurement(measurement, appStartDurationMilliseconds, 'millisecond'); } + /** + * Adds native spans to the app start span. + */ + private _addNativeSpansTo(appStartSpan: Span, nativeSpans: NativeAppStartResponse['spans']): void { + nativeSpans.forEach(span => { + appStartSpan.startChild({ + op: appStartSpan.op, + description: span.description, + startTimestamp: span.start_timestamp_ms / 1000, + endTimestamp: span.end_timestamp_ms / 1000, + }); + }); + } + /** To be called when the route changes, but BEFORE the components of the new route mount. */ private _onRouteWillChange(context: TransactionContext): TransactionType | undefined { return this._createRouteTransaction(context); diff --git a/test/tracing/reactnativetracing.test.ts b/test/tracing/reactnativetracing.test.ts index ff1dfd9b6a..d786cfdd1d 100644 --- a/test/tracing/reactnativetracing.test.ts +++ b/test/tracing/reactnativetracing.test.ts @@ -1,6 +1,6 @@ /* eslint-disable @typescript-eslint/no-explicit-any */ import * as SentryBrowser from '@sentry/browser'; -import type { Event } from '@sentry/types'; +import type { Event, SpanJSON } from '@sentry/types'; import type { NativeAppStartResponse } from '../../src/js/NativeRNSentry'; import { RoutingInstrumentation } from '../../src/js/tracing/routingInstrumentation'; @@ -269,9 +269,10 @@ describe('ReactNativeTracing', () => { const timeOriginMilliseconds = Date.now(); const appStartTimeMilliseconds = timeOriginMilliseconds - 65000; const mockAppStartResponse: NativeAppStartResponse = { - isColdStart: false, - appStartTime: appStartTimeMilliseconds, - didFetchAppStart: false, + type: 'warm', + app_start_timestamp_ms: appStartTimeMilliseconds, + has_fetched: false, + spans: [], }; mockFunction(getTimeOriginMilliseconds).mockReturnValue(timeOriginMilliseconds); @@ -295,9 +296,10 @@ describe('ReactNativeTracing', () => { const timeOriginMilliseconds = Date.now(); const appStartTimeMilliseconds = timeOriginMilliseconds - 65000; const mockAppStartResponse: NativeAppStartResponse = { - isColdStart: false, - appStartTime: appStartTimeMilliseconds, - didFetchAppStart: false, + type: 'warm', + app_start_timestamp_ms: appStartTimeMilliseconds, + has_fetched: false, + spans: [], }; mockFunction(getTimeOriginMilliseconds).mockReturnValue(timeOriginMilliseconds); @@ -315,10 +317,10 @@ describe('ReactNativeTracing', () => { expect(transaction?.start_timestamp).toBeGreaterThanOrEqual(timeOriginMilliseconds / 1000); }); - it('Does not create app start transaction if didFetchAppStart == true', async () => { + it('Does not create app start transaction if has_fetched == true', async () => { const integration = new ReactNativeTracing(); - mockAppStartResponse({ cold: false, didFetchAppStart: true }); + mockAppStartResponse({ cold: false, has_fetched: true }); setup(integration); @@ -328,6 +330,46 @@ describe('ReactNativeTracing', () => { const transaction = client.event; expect(transaction).toBeUndefined(); }); + + it('adds native spans as a child of the main app start span', async () => { + const integration = new ReactNativeTracing(); + + const [timeOriginMilliseconds] = mockAppStartResponse({ + cold: true, + enableNativeSpans: true, + }); + + setup(integration); + + await jest.advanceTimersByTimeAsync(500); + await jest.runOnlyPendingTimersAsync(); + + const transaction = client.event; + + const appStartRootSpan = transaction!.spans!.find(({ description }) => description === 'Cold App Start'); + const nativeSpan = transaction!.spans!.find(({ description }) => description === 'test native app start span'); + const nativeSpanJSON = spanToJSON(nativeSpan!); + const appStartRootSpanJSON = spanToJSON(appStartRootSpan!); + + expect(appStartRootSpan).toBeDefined(); + expect(nativeSpan).toBeDefined(); + expect(appStartRootSpanJSON).toEqual( + expect.objectContaining({ + description: 'Cold App Start', + span_id: expect.any(String), + op: APP_START_COLD_OP, + }), + ); + expect(nativeSpanJSON).toEqual( + expect.objectContaining({ + description: 'test native app start span', + start_timestamp: (timeOriginMilliseconds - 100) / 1000, + timestamp: (timeOriginMilliseconds - 50) / 1000, + parent_span_id: spanToJSON(appStartRootSpan!).span_id, // parent is the root app start span + op: spanToJSON(appStartRootSpan!).op, // op is the same as the root app start span + }), + ); + }); }); describe('With routing instrumentation', () => { @@ -438,14 +480,14 @@ describe('ReactNativeTracing', () => { expect(span!.timestamp).toBe(timeOriginMilliseconds / 1000); }); - it('Does not update route transaction if didFetchAppStart == true', async () => { + it('Does not update route transaction if has_fetched == true', async () => { const routingInstrumentation = new RoutingInstrumentation(); const integration = new ReactNativeTracing({ enableStallTracking: false, routingInstrumentation, }); - const [, appStartTimeMilliseconds] = mockAppStartResponse({ cold: false, didFetchAppStart: true }); + const [, appStartTimeMilliseconds] = mockAppStartResponse({ cold: false, has_fetched: true }); setup(integration); // wait for internal promises to resolve, fetch app start data from mocked native @@ -914,13 +956,30 @@ describe('ReactNativeTracing', () => { }); }); -function mockAppStartResponse({ cold, didFetchAppStart }: { cold: boolean; didFetchAppStart?: boolean }) { +function mockAppStartResponse({ + cold, + has_fetched, + enableNativeSpans, +}: { + cold: boolean; + has_fetched?: boolean; + enableNativeSpans?: boolean; +}) { const timeOriginMilliseconds = Date.now(); const appStartTimeMilliseconds = timeOriginMilliseconds - 100; const mockAppStartResponse: NativeAppStartResponse = { - isColdStart: cold, - appStartTime: appStartTimeMilliseconds, - didFetchAppStart: didFetchAppStart ?? false, + type: cold ? 'cold' : 'warm', + app_start_timestamp_ms: appStartTimeMilliseconds, + has_fetched: has_fetched ?? false, + spans: enableNativeSpans + ? [ + { + description: 'test native app start span', + start_timestamp_ms: timeOriginMilliseconds - 100, + end_timestamp_ms: timeOriginMilliseconds - 50, + }, + ] + : [], }; mockFunction(getTimeOriginMilliseconds).mockReturnValue(timeOriginMilliseconds); diff --git a/test/tracing/reactnavigation.ttid.test.tsx b/test/tracing/reactnavigation.ttid.test.tsx index 200257957f..df840a3e13 100644 --- a/test/tracing/reactnavigation.ttid.test.tsx +++ b/test/tracing/reactnavigation.ttid.test.tsx @@ -36,9 +36,10 @@ describe('React Navigation - TTID', () => { (isHermesEnabled as jest.Mock).mockReturnValue(true); mockWrapper.NATIVE.fetchNativeAppStart.mockResolvedValue({ - appStartTime: mockedAppStartTimeSeconds * 1000, - didFetchAppStart: false, - isColdStart: true, + app_start_timestamp_ms: mockedAppStartTimeSeconds * 1000, + has_fetched: false, + type: 'cold', + spans: [], }); mockedEventEmitter = mockedSentryEventEmitter.createMockedSentryEventEmitter();