Skip to content

Commit

Permalink
feat(tracing): Add native application start spans (#3855)
Browse files Browse the repository at this point in the history
  • Loading branch information
krystofwoldrich authored Jun 10, 2024
1 parent 8866197 commit 0884076
Show file tree
Hide file tree
Showing 7 changed files with 139 additions and 62 deletions.
5 changes: 5 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -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))
Expand Down
25 changes: 7 additions & 18 deletions android/src/main/java/io/sentry/react/RNSentryModuleImpl.java
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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<String, Object> 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);
}

/**
Expand Down
24 changes: 10 additions & 14 deletions ios/RNSentry.mm
Original file line number Diff line number Diff line change
Expand Up @@ -55,7 +55,7 @@ + (void)storeEnvelope:(SentryEnvelope *)envelope;

@end

static bool didFetchAppStart;
static bool hasFetchedAppStart;

static NSString* const nativeSdkName = @"sentry.cocoa.react-native";

Expand Down Expand Up @@ -380,24 +380,20 @@ - (NSDictionary*) fetchNativeStackFramesBy: (NSArray<NSNumber*>*)instructionsAdd
rejecter:(RCTPromiseRejectBlock)reject)
{
#if SENTRY_HAS_UIKIT
SentryAppStartMeasurement *appStartMeasurement = PrivateSentrySDKOnly.appStartMeasurement;

if (appStartMeasurement == nil) {
NSDictionary<NSString *, id> *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<NSString *, id> *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
Expand Down
11 changes: 8 additions & 3 deletions src/js/NativeRNSentry.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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 = {
Expand Down
40 changes: 31 additions & 9 deletions src/js/tracing/reactnativetracing.ts
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ import type {
Event,
EventProcessor,
Integration,
Span,
Transaction as TransactionType,
TransactionContext,
} from '@sentry/types';
Expand Down Expand Up @@ -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;
}

/**
Expand All @@ -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;
}
Expand Down Expand Up @@ -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;
Expand All @@ -469,7 +476,7 @@ export class ReactNativeTracing implements Integration {
return;
}

const appStartTimeSeconds = appStart.appStartTime / 1000;
const appStartTimeSeconds = appStartTimestampMs / 1000;

transaction.startTimestamp = appStartTimeSeconds;

Expand All @@ -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);
Expand Down
89 changes: 74 additions & 15 deletions test/tracing/reactnativetracing.test.ts
Original file line number Diff line number Diff line change
@@ -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';
Expand Down Expand Up @@ -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);
Expand All @@ -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);
Expand All @@ -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);

Expand All @@ -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(<SpanJSON>{
description: 'Cold App Start',
span_id: expect.any(String),
op: APP_START_COLD_OP,
}),
);
expect(nativeSpanJSON).toEqual(
expect.objectContaining(<SpanJSON>{
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', () => {
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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);
Expand Down
7 changes: 4 additions & 3 deletions test/tracing/reactnavigation.ttid.test.tsx
Original file line number Diff line number Diff line change
Expand Up @@ -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();
Expand Down

0 comments on commit 0884076

Please sign in to comment.