From 4a2237d8463e7b8a4109fc900326036af8099ec7 Mon Sep 17 00:00:00 2001 From: Krystof Woldrich Date: Tue, 4 Jun 2024 14:54:54 +0200 Subject: [PATCH 1/4] feat(tracing): Add native application start spans --- CHANGELOG.md | 3 ++ .../io/sentry/react/RNSentryModuleImpl.java | 21 +++------- ios/RNSentry.mm | 20 ++++------ src/js/NativeRNSentry.ts | 11 ++++-- src/js/tracing/reactnativetracing.ts | 39 ++++++++++++++----- test/tracing/reactnavigation.ttid.test.tsx | 7 ++-- 6 files changed, 58 insertions(+), 43 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index f3d9bce7a9..bc97abad8e 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -35,6 +35,9 @@ Note that the `Sentry.BrowserIntegrations`, `Sentry.Integration` and the Class style integrations will be removed in the next major version of the SDK. +- 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 + ### Fixes - Remove unused `rnpm` config ([#3811](https://github.com/getsentry/sentry-react-native/pull/3811)) diff --git a/android/src/main/java/io/sentry/react/RNSentryModuleImpl.java b/android/src/main/java/io/sentry/react/RNSentryModuleImpl.java index 4c69337e2b..f894239a35 100644 --- a/android/src/main/java/io/sentry/react/RNSentryModuleImpl.java +++ b/android/src/main/java/io/sentry/react/RNSentryModuleImpl.java @@ -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", didFetchAppStart); - 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; + + promise.resolve(mutableMeasurement); } /** diff --git a/ios/RNSentry.mm b/ios/RNSentry.mm index 0e122e1e66..12da349791 100644 --- a/ios/RNSentry.mm +++ b/ios/RNSentry.mm @@ -379,24 +379,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:didFetchAppStart] 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; + + 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 397cc1ee50..301b3e6c3d 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; } /** @@ -422,7 +423,7 @@ export class ReactNativeTracing implements Integration { const appStart = await NATIVE.fetchNativeAppStart(); - if (!appStart || appStart.didFetchAppStart) { + if (!appStart || appStart.has_fetched) { return; } @@ -448,7 +449,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('App start was never finished.'); return; @@ -461,7 +468,7 @@ export class ReactNativeTracing implements Integration { return; } - const appStartTimeSeconds = appStart.appStartTime / 1000; + const appStartTimeSeconds = appStartTimestampMs / 1000; transaction.startTimestamp = appStartTimeSeconds; @@ -477,18 +484,32 @@ 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({ + 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/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(); From 90efeb96c4eb35a3a62f4f9ab9cdb77ff593ef1f Mon Sep 17 00:00:00 2001 From: Krystof Woldrich Date: Tue, 4 Jun 2024 15:22:28 +0200 Subject: [PATCH 2/4] fix tests --- test/tracing/reactnativetracing.test.ts | 21 ++++++++++++--------- 1 file changed, 12 insertions(+), 9 deletions(-) diff --git a/test/tracing/reactnativetracing.test.ts b/test/tracing/reactnativetracing.test.ts index ff1dfd9b6a..fffce7fc02 100644 --- a/test/tracing/reactnativetracing.test.ts +++ b/test/tracing/reactnativetracing.test.ts @@ -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); @@ -918,9 +920,10 @@ function mockAppStartResponse({ cold, didFetchAppStart }: { cold: boolean; didFe 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: didFetchAppStart ?? false, + spans: [], }; mockFunction(getTimeOriginMilliseconds).mockReturnValue(timeOriginMilliseconds); From 8209a16ddb13b212fbc1f699af0fccfe40f074f4 Mon Sep 17 00:00:00 2001 From: Krystof Woldrich Date: Tue, 4 Jun 2024 17:31:54 +0200 Subject: [PATCH 3/4] add tests --- src/js/tracing/reactnativetracing.ts | 1 + test/tracing/reactnativetracing.test.ts | 62 +++++++++++++++++++++++-- 2 files changed, 60 insertions(+), 3 deletions(-) diff --git a/src/js/tracing/reactnativetracing.ts b/src/js/tracing/reactnativetracing.ts index 301b3e6c3d..465f5dbd62 100644 --- a/src/js/tracing/reactnativetracing.ts +++ b/src/js/tracing/reactnativetracing.ts @@ -503,6 +503,7 @@ export class ReactNativeTracing implements Integration { 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, diff --git a/test/tracing/reactnativetracing.test.ts b/test/tracing/reactnativetracing.test.ts index fffce7fc02..cccb4e12f2 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'; @@ -330,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', () => { @@ -916,14 +956,30 @@ describe('ReactNativeTracing', () => { }); }); -function mockAppStartResponse({ cold, didFetchAppStart }: { cold: boolean; didFetchAppStart?: boolean }) { +function mockAppStartResponse({ + cold, + didFetchAppStart, + enableNativeSpans, +}: { + cold: boolean; + didFetchAppStart?: boolean; + enableNativeSpans?: boolean; +}) { const timeOriginMilliseconds = Date.now(); const appStartTimeMilliseconds = timeOriginMilliseconds - 100; const mockAppStartResponse: NativeAppStartResponse = { type: cold ? 'cold' : 'warm', app_start_timestamp_ms: appStartTimeMilliseconds, has_fetched: didFetchAppStart ?? false, - spans: [], + spans: enableNativeSpans + ? [ + { + description: 'test native app start span', + start_timestamp_ms: timeOriginMilliseconds - 100, + end_timestamp_ms: timeOriginMilliseconds - 50, + }, + ] + : [], }; mockFunction(getTimeOriginMilliseconds).mockReturnValue(timeOriginMilliseconds); From d0cfae52c52bbfa3afc8678d46052cd554e760a8 Mon Sep 17 00:00:00 2001 From: Krystof Woldrich Date: Fri, 7 Jun 2024 11:03:32 +0200 Subject: [PATCH 4/4] review fixes --- CHANGELOG.md | 8 +++++--- .../java/io/sentry/react/RNSentryModuleImpl.java | 6 +++--- ios/RNSentry.mm | 6 +++--- test/tracing/reactnativetracing.test.ts | 14 +++++++------- 4 files changed, 18 insertions(+), 16 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 6967fda4f0..ca70c6e856 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 + ### Fix - Add missing logs to dropped App Start spans ([#3861](https://github.com/getsentry/sentry-react-native/pull/3861)) @@ -50,9 +55,6 @@ Note that the `Sentry.BrowserIntegrations`, `Sentry.Integration` and the Class style integrations will be removed in the next major version of the SDK. -- 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 - ### Fixes - Remove unused `rnpm` config ([#3811](https://github.com/getsentry/sentry-react-native/pull/3811)) diff --git a/android/src/main/java/io/sentry/react/RNSentryModuleImpl.java b/android/src/main/java/io/sentry/react/RNSentryModuleImpl.java index f894239a35..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; @@ -337,12 +337,12 @@ public void fetchNativeAppStart(Promise promise) { final Map measurement = InternalSentrySdk.getAppStartMeasurement(); WritableMap mutableMeasurement = (WritableMap) RNSentryMapConverter.convertToWritable(measurement); - mutableMeasurement.putBoolean("has_fetched", didFetchAppStart); + mutableMeasurement.putBoolean("has_fetched", hasFetchedAppStart); // 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 d7216d8c33..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"; @@ -387,11 +387,11 @@ - (NSDictionary*) fetchNativeStackFramesBy: (NSArray*)instructionsAdd } NSMutableDictionary *mutableMeasurements = [[NSMutableDictionary alloc] initWithDictionary:measurements]; - [mutableMeasurements setValue:[NSNumber numberWithBool:didFetchAppStart] forKey:@"has_fetched"]; + [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 diff --git a/test/tracing/reactnativetracing.test.ts b/test/tracing/reactnativetracing.test.ts index cccb4e12f2..d786cfdd1d 100644 --- a/test/tracing/reactnativetracing.test.ts +++ b/test/tracing/reactnativetracing.test.ts @@ -317,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); @@ -480,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 @@ -958,11 +958,11 @@ describe('ReactNativeTracing', () => { function mockAppStartResponse({ cold, - didFetchAppStart, + has_fetched, enableNativeSpans, }: { cold: boolean; - didFetchAppStart?: boolean; + has_fetched?: boolean; enableNativeSpans?: boolean; }) { const timeOriginMilliseconds = Date.now(); @@ -970,7 +970,7 @@ function mockAppStartResponse({ const mockAppStartResponse: NativeAppStartResponse = { type: cold ? 'cold' : 'warm', app_start_timestamp_ms: appStartTimeMilliseconds, - has_fetched: didFetchAppStart ?? false, + has_fetched: has_fetched ?? false, spans: enableNativeSpans ? [ {