diff --git a/CHANGELOG.md b/CHANGELOG.md index 5ec3591fa7..e678e59b78 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,6 +6,12 @@ > make sure you follow our [migration guide](https://docs.sentry.io/platforms/react-native/migration/) first. +## Unreleased + +### Features + +- Add experimental `extendAppStart`/`finishExtendedAppStart`/`getExtendedAppStartSpan` to extend the standalone app start window and instrument post-init work ([#6392](https://github.com/getsentry/sentry-react-native/pull/6392)) + ## 8.17.0 ### Features diff --git a/packages/core/etc/sentry-react-native.api.md b/packages/core/etc/sentry-react-native.api.md index 4fa2d8c95f..2d9066c23e 100644 --- a/packages/core/etc/sentry-react-native.api.md +++ b/packages/core/etc/sentry-react-native.api.md @@ -305,6 +305,9 @@ export const expoRouterIntegration: (options?: ExpoRouterIntegrationOptions) => // @public export const expoUpdatesListenerIntegration: () => Integration; +// @public +export function extendAppStart(): void; + export { extraErrorDataIntegration } export { FeatureFlagsIntegration } @@ -353,6 +356,9 @@ export const feedbackIntegration: (initOptions?: Partial & { enableShakeToReport?: boolean; }) => FeedbackIntegration; +// @public +export function finishExtendedAppStart(): Promise; + // @public export function flush(): Promise; @@ -384,6 +390,9 @@ export function getDataFromUri(uri: string): Promise; // @public export function getDefaultIdleNavigationSpanOptions(): StartSpanOptions; +// @public +export function getExtendedAppStartSpan(): Span; + export { getGlobalScope } export { getIsolationScope } diff --git a/packages/core/src/js/index.ts b/packages/core/src/js/index.ts index 3b609bde18..094e724bab 100644 --- a/packages/core/src/js/index.ts +++ b/packages/core/src/js/index.ts @@ -109,6 +109,9 @@ export { withScope, crashedLastRun, appLoaded, + extendAppStart, + getExtendedAppStartSpan, + finishExtendedAppStart, pauseAppHangTracking, resumeAppHangTracking, } from './sdk'; diff --git a/packages/core/src/js/sdk.tsx b/packages/core/src/js/sdk.tsx index 2ddc9121e2..d5f8bc87d6 100644 --- a/packages/core/src/js/sdk.tsx +++ b/packages/core/src/js/sdk.tsx @@ -1,5 +1,5 @@ /* oxlint-disable eslint(complexity) */ -import type { Breadcrumb, BreadcrumbHint, Integration, Scope } from '@sentry/core'; +import type { Breadcrumb, BreadcrumbHint, Integration, Scope, Span } from '@sentry/core'; import { debug, @@ -25,7 +25,12 @@ import { shouldEnableNativeNagger } from './options'; import { enableSyncToNative } from './scopeSync'; import { TouchEventBoundary } from './touchevents'; import { ReactNativeProfiler } from './tracing'; -import { _appLoaded } from './tracing/integrations/appStart'; +import { + _appLoaded, + _extendAppStart, + _finishExtendedAppStart, + _getExtendedAppStartSpan, +} from './tracing/integrations/appStart'; import { useEncodePolyfill } from './transports/encodePolyfill'; import { DEFAULT_BUFFER_SIZE, makeNativeTransportFactory } from './transports/native'; import { getDefaultEnvironment, isExpoGo, isRunningInMetroDevServer, isWeb } from './utils/environment'; @@ -250,6 +255,64 @@ export function appLoaded(): void { _appLoaded(); } +/** + * Extends the app start window so work done after initialization (remote config, session restore, + * splash screen dismissal, etc.) is included in the app start measurement. Call + * {@link finishExtendedAppStart} when the app is ready, or attach child spans via + * {@link getExtendedAppStartSpan} to break the extended work down. + * + * Requires standalone app start tracing (`_experiments.enableStandaloneAppStartTracing`). No-ops if + * the app start transaction was already created, if extend was already called, or if called before + * `Sentry.init()`. + * + * @experimental This API is subject to change in future versions. + * + * @example + * ```ts + * Sentry.extendAppStart(); + * await initializeRemoteConfig(); + * Sentry.finishExtendedAppStart(); + * ``` + */ +export function extendAppStart(): void { + _extendAppStart(); +} + +/** + * Returns the extended app start span for attaching child spans, or a no-op span when there is no + * active extension. Only meaningful between {@link extendAppStart} and {@link finishExtendedAppStart}. + * + * @experimental This API is subject to change in future versions. + * + * @example + * ```ts + * Sentry.extendAppStart(); + * const parentSpan = Sentry.getExtendedAppStartSpan(); + * const child = Sentry.startInactiveSpan({ parentSpan, op: 'app.init', name: 'fetch remote config' }); + * await loadRemoteConfig(); + * child.end(); + * Sentry.finishExtendedAppStart(); + * ``` + */ +export function getExtendedAppStartSpan(): Span { + return _getExtendedAppStartSpan(); +} + +/** + * Finishes the app start extension started with {@link extendAppStart}, finalizing the app start + * transaction (its duration is trimmed to the last child span). No-ops if there is no active + * extension. + * + * Returns a promise that resolves once the app start transaction has been captured. `await` it + * before {@link flush} (e.g. before a code-push/expo update) to make sure the app start data is + * queued. + * + * @experimental This API is subject to change in future versions. + */ +export function finishExtendedAppStart(): Promise { + return _finishExtendedAppStart(); +} + /** * Flushes all pending events in the queue to disk. * Use this before applying any realtime updates such as code-push or expo updates. diff --git a/packages/core/src/js/tracing/integrations/appStart.ts b/packages/core/src/js/tracing/integrations/appStart.ts index 79c2c0f79b..fa360ce366 100644 --- a/packages/core/src/js/tracing/integrations/appStart.ts +++ b/packages/core/src/js/tracing/integrations/appStart.ts @@ -6,9 +6,12 @@ import { getCapturedScopesOnSpan, getClient, getCurrentScope, + getSpanDescendants, SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN, SentryNonRecordingSpan, + SPAN_STATUS_ERROR, spanIsSampled, + spanToJSON, startInactiveSpan, timestampInSeconds, } from '@sentry/core'; @@ -27,6 +30,7 @@ import { getRootSpanDiscardReason, getTransactionEventDiscardReason } from '../o import { APP_START as APP_START_OP, APP_START_COLD as APP_START_COLD_OP, + APP_START_EXTENDED as APP_START_EXTENDED_OP, APP_START_WARM as APP_START_WARM_OP, UI_LOAD as UI_LOAD_OP, } from '../ops'; @@ -39,7 +43,12 @@ import { SEMANTIC_ATTRIBUTE_SENTRY_OP, } from '../semanticAttributes'; import { setMainThreadInfo } from '../span'; -import { createChildSpanJSON, createSpanJSON, getBundleStartTimestampMs } from '../utils'; +import { + createChildSpanJSON, + createSpanJSON, + getBundleStartTimestampMs, + getLatestChildSpanEndTimestamp, +} from '../utils'; const INTEGRATION_NAME = 'AppStart'; @@ -47,6 +56,9 @@ export type AppStartIntegration = Integration & { captureStandaloneAppStart: () => Promise; cancelDeferredStandaloneCapture: () => void; scheduleDeferredStandaloneCapture: () => void; + extendAppStart: () => void; + getExtendedAppStartSpan: () => Span; + finishExtendedAppStart: () => Promise; }; /** @@ -62,6 +74,16 @@ const MAX_APP_START_AGE_MS = 60_000; /** App Start transaction name */ const APP_START_TX_NAME = 'App Start'; +/** Extended app start span name */ +const EXTENDED_APP_START_SPAN_NAME = 'Extended App Start'; + +/** + * If `finishExtendedAppStart()` is never called, the extended app start auto-finishes after this + * deadline. The transaction is still captured, but its `app.vitals.start` measurement is suppressed + * so we never emit a ~30s app start. + */ +const EXTEND_APP_START_DEADLINE_MS = 30_000; + interface AppStartEndData { timestampMs: number; endFrames: NativeFramesResponse | null; @@ -176,6 +198,38 @@ export async function _captureAppStart({ isManual }: { isManual: boolean }): Pro } } +/** + * Extends the app start window. Called internally by `extendAppStart()` from the public SDK API. + * + * @private + */ +export function _extendAppStart(): void { + getClient()?.getIntegrationByName(INTEGRATION_NAME)?.extendAppStart(); +} + +/** + * Returns the extended app start span (a no-op span when there's no active extension). + * Called internally by `getExtendedAppStartSpan()` from the public SDK API. + * + * @private + */ +export function _getExtendedAppStartSpan(): Span { + return ( + getClient()?.getIntegrationByName(INTEGRATION_NAME)?.getExtendedAppStartSpan() ?? + new SentryNonRecordingSpan() + ); +} + +/** + * Finishes the extended app start. Called internally by `finishExtendedAppStart()` from the public + * SDK API. + * + * @private + */ +export async function _finishExtendedAppStart(): Promise { + await getClient()?.getIntegrationByName(INTEGRATION_NAME)?.finishExtendedAppStart(); +} + /** * Fetches native frames data and attaches it to the current app start end data. */ @@ -305,6 +359,17 @@ export const appStartIntegration = ({ // — a late `appLoaded()`, or one racing the in-flight deferred auto-capture — observes it and // bails. Reset on `runApplication` so the next app run captures again. let standaloneAppStartCaptured = false; + // Extend-app-start state (standalone mode). `extendAppStart()` keeps the standalone transaction + // open and hosts an `app.start.extended` span for user-instrumented work; `finishExtendedAppStart()` + // or the deadline finalizes it. `openStandaloneAppStartSpan` is the held-open root transaction. + let extendedAppStartSpan: Span | undefined = undefined; + let openStandaloneAppStartSpan: Span | undefined = undefined; + let extendDeadlineTimeout: ReturnType | undefined = undefined; + let extendedAppStartFinalized = false; + // Incremented on every `runApplication` reset. Captured at the start of an app start attach so a + // finalize suspended at the native-data await can detect that a new app run began and bail instead + // of corrupting the new run's state. + let appStartRunGeneration = 0; const setup = (client: Client): void => { _client = client; @@ -334,16 +399,27 @@ export const appStartIntegration = ({ // reduces to the original `appStartDataFlushed` check. if (appStartDataFlushed || standaloneAppStartCaptured) { debug.log('[AppStartIntegration] Resetting app start state based on runApplication call.'); + // Mark a new app run. Any standalone attach still suspended at the native-data await (e.g. an + // in-flight `finishExtendedAppStart()` from the previous run) detects the generation change + // when it resumes and bails without mutating the new run's state. + appStartRunGeneration += 1; appStartDataFlushed = false; firstStartedActiveRootSpanId = undefined; firstStartedActiveRootSpan = undefined; isAppLoadedManuallyInvoked = false; cachedNativeAppStart = undefined; standaloneAppStartCaptured = false; + extendedAppStartSpan = undefined; + openStandaloneAppStartSpan = undefined; + extendedAppStartFinalized = false; if (deferredStandaloneTimeout !== undefined) { clearTimeout(deferredStandaloneTimeout); deferredStandaloneTimeout = undefined; } + if (extendDeadlineTimeout !== undefined) { + clearTimeout(extendDeadlineTimeout); + extendDeadlineTimeout = undefined; + } } else { debug.log( '[AppStartIntegration] Waiting for initial app start was flush, before updating based on runApplication call.', @@ -478,11 +554,11 @@ export const appStartIntegration = ({ return; } - await attachAppStartToTransactionEvent(event); - // App start data is carried as Span V2 attributes on the root transaction, so the standalone - // transaction is meaningful even without breakdown child spans. If attachment was skipped - // (e.g. already flushed, or native data unavailable) the vitals attribute is absent — skip send. - if (event.contexts?.trace?.data?.[SEMANTIC_ATTRIBUTE_APP_VITALS_START_VALUE] === undefined) { + // If attachment was skipped (e.g. already flushed, or native data unavailable) there's nothing + // to send. App start data is carried as Span V2 attributes on the root transaction, so the + // standalone transaction is meaningful even without breakdown child spans. + const attached = await attachAppStartToTransactionEvent(event); + if (!attached) { debug.log('[AppStart] No app start data attached to the standalone transaction. Skipping send.'); return; } @@ -491,11 +567,21 @@ export const appStartIntegration = ({ scope.captureEvent(event); } - async function attachAppStartToTransactionEvent(event: TransactionEvent): Promise { + async function attachAppStartToTransactionEvent( + event: TransactionEvent, + { + suppressMeasurement = false, + extendedEndTimestampMs, + }: { suppressMeasurement?: boolean; extendedEndTimestampMs?: number } = {}, + ): Promise { + // Snapshot the current app run. If a `runApplication` reset happens while we're awaiting native + // data below, the resumed call belongs to a stale run and must not touch the new run's state. + const generationAtStart = appStartRunGeneration; + if (appStartDataFlushed) { // App start data is only relevant for the first transaction of the app run debug.log('[AppStart] App start data already flushed. Skipping.'); - return; + return false; } // Don't attach (and don't flip the flushed flag) for transactions the @@ -505,12 +591,12 @@ export const appStartIntegration = ({ // start data because `appStartDataFlushed` would already be `true`. if (getTransactionEventDiscardReason(event)) { debug.log('[AppStart] Skipping app start attach for transaction marked for discard.'); - return; + return false; } if (!event.contexts?.trace) { debug.warn('[AppStart] Transaction event is missing trace context. Can not attach app start.'); - return; + return false; } // When standalone is true, we create our own transaction and don't need to verify @@ -519,14 +605,14 @@ export const appStartIntegration = ({ if (!standalone) { if (!firstStartedActiveRootSpanId) { debug.warn('[AppStart] No first started active root span id recorded. Can not attach app start.'); - return; + return false; } if (firstStartedActiveRootSpanId !== event.contexts.trace.span_id) { debug.warn( '[AppStart] First started active root span id does not match the transaction event span id. Can not attached app start.', ); - return; + return false; } } @@ -539,11 +625,18 @@ export const appStartIntegration = ({ // NATIVE.fetchNativeAppStart() call would incorrectly bail out. const isCached = cachedNativeAppStart !== undefined; const appStart = isCached ? cachedNativeAppStart : await NATIVE.fetchNativeAppStart(); + if (generationAtStart !== appStartRunGeneration) { + // A `runApplication` reset began a new app run while we awaited native data. Bail without + // mutating shared state (`cachedNativeAppStart`, `appStartDataFlushed`) so the new run can + // still capture its own app start. + debug.log('[AppStart] App run changed during app start attach. Discarding stale attach.'); + return false; + } cachedNativeAppStart = appStart; if (!appStart) { debug.warn('[AppStart] Failed to retrieve the app start metrics from the native layer.'); appStartDataFlushed = true; - return; + return false; } // Skip the has_fetched check when using a cached response — the native layer // sets has_fetched = true after the first fetch, but we intentionally re-use @@ -551,24 +644,29 @@ export const appStartIntegration = ({ if (!isCached && appStart.has_fetched) { debug.warn('[AppStart] Measured app start metrics were already reported from the native layer.'); appStartDataFlushed = true; - return; + return false; } const appStartTimestampMs = appStart.app_start_timestamp_ms; if (!appStartTimestampMs) { debug.warn('[AppStart] App start timestamp could not be loaded from the native layer.'); appStartDataFlushed = true; - return; + return false; } - const appStartEndTimestampMs = appStartEndData?.timestampMs || getBundleStartTimestampMs(); - if (!appStartEndTimestampMs) { + const originalAppStartEndTimestampMs = appStartEndData?.timestampMs || getBundleStartTimestampMs(); + if (!originalAppStartEndTimestampMs) { debug.warn( '[AppStart] Javascript failed to record app start end. `_setAppStartEndData` was not called nor could the bundle start be found.', ); appStartDataFlushed = true; - return; + return false; } + // When finalizing an *extended* app start the end is pushed past the native app start end. The + // extended end drives the measurement value and transaction timestamp; the 60s sanity cap below + // still applies to the original (native) window, so a legitimately extended start is never + // silently dropped just for being long. + const appStartEndTimestampMs = extendedEndTimestampMs || originalAppStartEndTimestampMs; // The age check guards against attaching a stale app start to a much-later navigation // transaction. It is meaningless for standalone, where the transaction *is* the app start @@ -581,17 +679,17 @@ export const appStartIntegration = ({ if (!standalone && !__DEV__ && !isAppStartWithinBounds) { debug.warn('[AppStart] App start timestamp is too far in the past to be used for app start span.'); appStartDataFlushed = true; - return; + return false; } - const appStartDurationMs = appStartEndTimestampMs - appStartTimestampMs; - if (!__DEV__ && appStartDurationMs >= MAX_APP_START_DURATION_MS) { + if (!__DEV__ && originalAppStartEndTimestampMs - appStartTimestampMs >= MAX_APP_START_DURATION_MS) { // Dev builds can have long app start waiting over minute for the first bundle to be produced debug.warn('[AppStart] App start duration is over a minute long, not adding app start span.'); appStartDataFlushed = true; - return; + return false; } + const appStartDurationMs = appStartEndTimestampMs - appStartTimestampMs; if (appStartDurationMs < 0) { // This can happen when MainActivity on Android is recreated, // and the app start end timestamp is not updated, for example @@ -601,7 +699,7 @@ export const appStartIntegration = ({ 'This is usually caused by missing `Sentry.wrap(RootComponent)` call.', ); appStartDataFlushed = true; - return; + return false; } appStartDataFlushed = true; @@ -658,16 +756,21 @@ export const appStartIntegration = ({ if (standalone) { // Bound the standalone transaction exactly to the app start window. event.timestamp = appStartEndTimestampSeconds; - event.contexts.trace.data[SEMANTIC_ATTRIBUTE_APP_VITALS_START_VALUE] = appStartDurationMs; - event.contexts.trace.data[SEMANTIC_ATTRIBUTE_APP_VITALS_START_TYPE] = appStart.type; - - // Screen shown when app start completes. Unlike the non-standalone `ui.load` transaction - // (whose name is the screen, which Relay backfills from), the standalone transaction is named - // `App Start`, so we set the screen explicitly. Sourced from the current route tracked by the - // tracing integration; omitted when no route has been registered yet at capture time. - const screen = getCurrentReactNativeTracingIntegration()?.state.currentRoute; - if (screen) { - event.contexts.trace.data[SEMANTIC_ATTRIBUTE_APP_VITALS_START_SCREEN] = screen; + + // The measurement is suppressed on the extended-app-start deadline path so we never emit a + // bogus ~30s app start; the transaction itself is still captured. + if (!suppressMeasurement) { + event.contexts.trace.data[SEMANTIC_ATTRIBUTE_APP_VITALS_START_VALUE] = appStartDurationMs; + event.contexts.trace.data[SEMANTIC_ATTRIBUTE_APP_VITALS_START_TYPE] = appStart.type; + + // Screen shown when app start completes. Unlike the non-standalone `ui.load` transaction + // (whose name is the screen, which Relay backfills from), the standalone transaction is named + // `App Start`, so we set the screen explicitly. Sourced from the current route tracked by the + // tracing integration; omitted when no route has been registered yet at capture time. + const screen = getCurrentReactNativeTracingIntegration()?.state.currentRoute; + if (screen) { + event.contexts.trace.data[SEMANTIC_ATTRIBUTE_APP_VITALS_START_SCREEN] = screen; + } } // Minimal parent referencing the root transaction span, so the breakdown spans attach @@ -723,7 +826,7 @@ export const appStartIntegration = ({ children.push(...appStartSpans); debug.log('[AppStart] Added app start spans to transaction event.', JSON.stringify(appStartSpans, undefined, 2)); - if (!standalone) { + if (!standalone && !suppressMeasurement) { const measurementKey = appStart.type === 'cold' ? APP_START_COLD_MEASUREMENT : APP_START_WARM_MEASUREMENT; const measurementValue = { value: appStartDurationMs, @@ -736,8 +839,185 @@ export const appStartIntegration = ({ JSON.stringify(measurementValue, undefined, 2), ); } + + // Re-check after the frames-delay await above (up to ~2s): if a new app run started in the + // meantime, report failure so the caller doesn't send a stale standalone transaction. + if (generationAtStart !== appStartRunGeneration) { + debug.log('[AppStart] App run changed during app start attach. Discarding stale attach.'); + return false; + } + + return true; + } + + /** + * Ends any still-open descendant spans of the extended app start span with the given status. + * Used when finalizing: open children are `cancelled` on an explicit finish, `deadline_exceeded` + * when the deadline fires. + */ + const finishOpenExtendedChildren = (statusMessage: 'cancelled' | 'deadline_exceeded'): void => { + if (!extendedAppStartSpan) { + return; + } + for (const child of getSpanDescendants(extendedAppStartSpan)) { + if (child === extendedAppStartSpan || spanToJSON(child).timestamp !== undefined) { + continue; // the extended span itself, or an already-finished child + } + child.setStatus({ code: SPAN_STATUS_ERROR, message: statusMessage }); + child.end(); + } + }; + + /** + * Finalizes a held-open standalone `app.start` transaction (used by the extend flow): sets its + * end to the already-computed `trimmedEndMs`, enriches it with app start data, and sends it. When + * `suppressMeasurement` is set (deadline path) the `app.vitals.start` attributes are removed so we + * never emit a bogus ~30s app start, while the transaction itself is still captured. + */ + async function finalizeStandaloneAppStart( + span: Span, + { suppressMeasurement = false, trimmedEndMs = 0 }: { suppressMeasurement?: boolean; trimmedEndMs?: number } = {}, + ): Promise { + if (!_client) { + return; + } + + setEndTimeValue(span, (trimmedEndMs || timestampInSeconds() * 1000) / 1000); + _client.emit('spanEnd', span); + + const event = convertSpanToTransaction(span); + if (!event) { + debug.warn('[AppStart] Failed to convert extended App Start span to transaction.'); + return; + } + + const attached = await attachAppStartToTransactionEvent(event, { + suppressMeasurement, + extendedEndTimestampMs: trimmedEndMs || undefined, + }); + if (!attached) { + debug.log('[AppStart] No app start data attached to the extended standalone transaction. Skipping send.'); + return; + } + + const scope = getCapturedScopesOnSpan(span).scope || getCurrentScope(); + scope.captureEvent(event); } + const finalizeExtendedAppStart = async ({ + deadlineExceeded = false, + }: { deadlineExceeded?: boolean } = {}): Promise => { + if (!extendedAppStartSpan || !openStandaloneAppStartSpan || extendedAppStartFinalized) { + return; + } + extendedAppStartFinalized = true; + + if (extendDeadlineTimeout !== undefined) { + clearTimeout(extendDeadlineTimeout); + extendDeadlineTimeout = undefined; + } + + finishOpenExtendedChildren(deadlineExceeded ? 'deadline_exceeded' : 'cancelled'); + + let extendedEndSeconds: number | undefined; + if (deadlineExceeded) { + // Deadline: keep the full window up to the deadline (diagnostic — the measurement is + // suppressed) by ending the wrapper span at the current time. + extendedAppStartSpan.setStatus({ code: SPAN_STATUS_ERROR, message: 'deadline_exceeded' }); + extendedAppStartSpan.end(); + extendedEndSeconds = spanToJSON(extendedAppStartSpan).timestamp; + } else { + // Explicit finish: trim the end to the latest finished child of the extended span (the user's + // instrumented work), floored at the default app start end so extending never shortens a + // normal app start, and at the wrapper's own start so its duration stays non-negative. The + // wrapper span itself is excluded — it is computed before ending the wrapper, so its + // finalization-time end doesn't pin the measurement to the `finishExtendedAppStart()` call. + const defaultEndMs = appStartEndData?.timestampMs || getBundleStartTimestampMs() || 0; + const extendedStartMs = (spanToJSON(extendedAppStartSpan).start_timestamp || 0) * 1000; + const latestChildEndSeconds = getLatestChildSpanEndTimestamp(extendedAppStartSpan); + const trimmedEndMs = Math.max( + latestChildEndSeconds ? latestChildEndSeconds * 1000 : 0, + defaultEndMs, + extendedStartMs, + ); + extendedEndSeconds = trimmedEndMs ? trimmedEndMs / 1000 : timestampInSeconds(); + extendedAppStartSpan.end(extendedEndSeconds); + } + + const spanToFinalize = openStandaloneAppStartSpan; + extendedAppStartSpan = undefined; + openStandaloneAppStartSpan = undefined; + + await finalizeStandaloneAppStart(spanToFinalize, { + suppressMeasurement: deadlineExceeded, + trimmedEndMs: extendedEndSeconds ? extendedEndSeconds * 1000 : 0, + }); + }; + + const extendAppStart = (): void => { + if (!_client) { + // oxlint-disable-next-line eslint(no-console) + console.warn('[AppStart] Could not extend App Start, missing client, call `Sentry.init` first.'); + return; + } + if (!standalone) { + debug.warn('[AppStart] extendAppStart() requires standalone app start tracing. Ignoring.'); + return; + } + if (extendedAppStartSpan) { + debug.log('[AppStart] extendAppStart() already called for this app run. Ignoring.'); + return; + } + if (standaloneAppStartCaptured) { + debug.warn('[AppStart] extendAppStart() called after the app start transaction was created. Ignoring.'); + return; + } + + const rootSpan = startInactiveSpan({ + forceTransaction: true, + name: APP_START_TX_NAME, + op: APP_START_OP, + }); + if (rootSpan instanceof SentryNonRecordingSpan) { + // Tracing is disabled or this app start was sampled out. Don't claim the run and leave the + // deferred auto-capture in place as a fallback — extending is a no-op here. + debug.log('[AppStart] extendAppStart(): standalone app start transaction is not recording.'); + return; + } + + // Take over the send: cancel the deferred auto-capture and claim the run so the normal capture + // path does not also finalize/send. Only after we have a recording span, so a non-recording + // (sampled-out) run still falls back to the normal capture path. + cancelDeferredStandaloneCapture(); + standaloneAppStartCaptured = true; + + openStandaloneAppStartSpan = rootSpan; + extendedAppStartSpan = startInactiveSpan({ + parentSpan: rootSpan, + op: APP_START_EXTENDED_OP, + name: EXTENDED_APP_START_SPAN_NAME, + }); + + extendDeadlineTimeout = setTimeout(() => { + extendDeadlineTimeout = undefined; + debug.warn('[AppStart] Extended app start deadline reached. Finalizing without a measurement.'); + // oxlint-disable-next-line typescript-eslint(no-floating-promises) + finalizeExtendedAppStart({ deadlineExceeded: true }); + }, EXTEND_APP_START_DEADLINE_MS); + }; + + const getExtendedAppStartSpan = (): Span => { + return extendedAppStartSpan || new SentryNonRecordingSpan(); + }; + + const finishExtendedAppStart = async (): Promise => { + if (!extendedAppStartSpan || extendedAppStartFinalized) { + debug.log('[AppStart] finishExtendedAppStart(): no extended app start in progress. Ignoring.'); + return; + } + await finalizeExtendedAppStart({ deadlineExceeded: false }); + }; + const cancelDeferredStandaloneCapture = (): void => { if (deferredStandaloneTimeout !== undefined) { clearTimeout(deferredStandaloneTimeout); @@ -765,6 +1045,9 @@ export const appStartIntegration = ({ captureStandaloneAppStart, cancelDeferredStandaloneCapture, scheduleDeferredStandaloneCapture, + extendAppStart, + getExtendedAppStartSpan, + finishExtendedAppStart, setFirstStartedActiveRootSpanId, } as AppStartIntegration; }; diff --git a/packages/core/src/js/tracing/ops.ts b/packages/core/src/js/tracing/ops.ts index 0d392bc3fa..6abe26262c 100644 --- a/packages/core/src/js/tracing/ops.ts +++ b/packages/core/src/js/tracing/ops.ts @@ -11,5 +11,8 @@ export const APP_START_WARM = 'app.start.warm'; /** Standalone app start transaction op (Span V2 / EAP). */ export const APP_START = 'app.start'; +/** Extended app start span op — parent of user-instrumented app start work. */ +export const APP_START_EXTENDED = 'app.start.extended'; + export const UI_LOAD_INITIAL_DISPLAY = 'ui.load.initial_display'; export const UI_LOAD_FULL_DISPLAY = 'ui.load.full_display'; diff --git a/packages/core/test/tracing/integrations/appStart.test.ts b/packages/core/test/tracing/integrations/appStart.test.ts index 9f3f7661ef..7d35e217b2 100644 --- a/packages/core/test/tracing/integrations/appStart.test.ts +++ b/packages/core/test/tracing/integrations/appStart.test.ts @@ -9,6 +9,7 @@ import { SEMANTIC_ATTRIBUTE_SENTRY_ORIGIN, SentryNonRecordingSpan, setCurrentClient, + spanToJSON, startInactiveSpan, timestampInSeconds, } from '@sentry/core'; @@ -22,6 +23,7 @@ import { import { APP_START as APP_START_OP, APP_START_COLD as APP_START_COLD_OP, + APP_START_EXTENDED as APP_START_EXTENDED_OP, APP_START_WARM as APP_START_WARM_OP, UI_LOAD, } from '../../../src/js/tracing'; @@ -1186,6 +1188,361 @@ describe('App Start Integration', () => { }); }); +describe('Extended App Start', () => { + beforeEach(() => { + jest.clearAllMocks(); + mockReactNativeBundleExecutionStartTimestamp(); + getCurrentScope().clear(); + getIsolationScope().clear(); + getGlobalScope().clear(); + _clearAppStartEndData(); + _clearRootComponentCreationTimestampMs(); + }); + + afterEach(() => { + clearReactNativeBundleExecutionStartTimestamp(); + _clearAppStartEndData(); + _clearRootComponentCreationTimestampMs(); + }); + + const setupStandaloneIntegration = ( + standalone = true, + ): { integration: AppStartIntegrationTest; client: TestClient } => { + const integration = appStartIntegration({ standalone }) as AppStartIntegrationTest; + const client = new TestClient({ + ...getDefaultTestClientOptions(), + enableAppStartTracking: true, + tracesSampleRate: 1.0, + }); + setCurrentClient(client); + integration.setup(client); + return { integration, client }; + }; + + it('creates an extended app start span and finalizes it with a measurement on finish', async () => { + mockAppStart({ cold: true }); + const { integration, client } = setupStandaloneIntegration(); + + integration.extendAppStart(); + const extendedSpan = integration.getExtendedAppStartSpan(); + expect(spanToJSON(extendedSpan).op).toBe(APP_START_EXTENDED_OP); + + const child = startInactiveSpan({ parentSpan: extendedSpan, op: 'app.init', name: 'load config' }); + child.end(); + + await integration.finishExtendedAppStart(); + + const event = client.event as TransactionEvent; + expect(event?.contexts?.trace?.op).toBe(APP_START_OP); + expect(event?.contexts?.trace?.data?.[SEMANTIC_ATTRIBUTE_APP_VITALS_START_VALUE]).toBeDefined(); + + const extended = event?.spans?.find(s => s.op === APP_START_EXTENDED_OP); + expect(extended).toBeDefined(); + const childSpan = event?.spans?.find(s => s.description === 'load config'); + expect(childSpan).toBeDefined(); + expect(childSpan?.parent_span_id).toBe(extended?.span_id); + }); + + it('trims the transaction end to the last child span', async () => { + const [timeOriginMilliseconds] = mockAppStart({ cold: true }); + const { integration, client } = setupStandaloneIntegration(); + + integration.extendAppStart(); + const childEndSeconds = timeOriginMilliseconds / 1000 + 2; // 2s after the default app start end + const child = startInactiveSpan({ + parentSpan: integration.getExtendedAppStartSpan(), + op: 'app.init', + name: 'late', + }); + child.end(childEndSeconds); + + await integration.finishExtendedAppStart(); + + const event = client.event as TransactionEvent; + expect(event?.timestamp).toBeCloseTo(childEndSeconds, 1); + }); + + it('trims the end to the last child, not the finishExtendedAppStart() call time', async () => { + mockAppStart({ cold: true }); + const { integration, client } = setupStandaloneIntegration(); + + integration.extendAppStart(); + const child = startInactiveSpan({ + parentSpan: integration.getExtendedAppStartSpan(), + op: 'app.init', + name: 'work', + }); + child.end(); + const childEndSeconds = spanToJSON(child).timestamp as number; + + // A gap between the last child finishing and the app declaring itself ready. + await new Promise(resolve => setTimeout(resolve, 100)); + await integration.finishExtendedAppStart(); + + const event = client.event as TransactionEvent; + // The transaction (and the wrapper span) end at the last child, not ~100ms later at finish(). + expect(event?.timestamp).toBeCloseTo(childEndSeconds, 2); + const wrapper = event?.spans?.find(s => s.op === APP_START_EXTENDED_OP); + expect(wrapper?.timestamp).toBeCloseTo(childEndSeconds, 2); + }); + + it('getExtendedAppStartSpan returns a no-op span when not extending', () => { + mockAppStart({ cold: true }); + const { integration } = setupStandaloneIntegration(); + expect(integration.getExtendedAppStartSpan().isRecording()).toBe(false); + }); + + it('extendAppStart is a no-op when standalone tracing is disabled', () => { + mockAppStart({ cold: true }); + const { integration } = setupStandaloneIntegration(false); + integration.extendAppStart(); + expect(integration.getExtendedAppStartSpan().isRecording()).toBe(false); + }); + + it('extendAppStart is first-wins on repeat calls', () => { + mockAppStart({ cold: true }); + const { integration } = setupStandaloneIntegration(); + integration.extendAppStart(); + const first = integration.getExtendedAppStartSpan(); + integration.extendAppStart(); + expect(integration.getExtendedAppStartSpan()).toBe(first); + }); + + it('finishExtendedAppStart is a no-op when there is no extension', async () => { + mockAppStart({ cold: true }); + const { integration, client } = setupStandaloneIntegration(); + await integration.finishExtendedAppStart(); + expect(client.event).toBeUndefined(); + }); + + it('finishExtendedAppStart only finalizes once', async () => { + mockAppStart({ cold: true }); + const { integration, client } = setupStandaloneIntegration(); + integration.extendAppStart(); + + await integration.finishExtendedAppStart(); + expect(client.eventQueue.length).toBe(1); + + await integration.finishExtendedAppStart(); + expect(client.eventQueue.length).toBe(1); + }); + + it('finalizes without a measurement when the deadline is reached', async () => { + jest.useFakeTimers(); + mockAppStart({ cold: true }); + const { integration, client } = setupStandaloneIntegration(); + + integration.extendAppStart(); + // Deadline fires (finishExtendedAppStart never called). + jest.advanceTimersByTime(30_000); + jest.useRealTimers(); + await new Promise(resolve => setTimeout(resolve, 50)); + + expect(client.eventQueue.length).toBe(1); + const event = client.eventQueue[0] as TransactionEvent; + expect(event?.contexts?.trace?.op).toBe(APP_START_OP); + expect(event?.contexts?.trace?.data?.[SEMANTIC_ATTRIBUTE_APP_VITALS_START_VALUE]).toBeUndefined(); + }); + + it('does not claim the run when the standalone transaction is not recording (falls back to normal capture)', async () => { + const [timeOriginMilliseconds] = mockAppStart({ cold: true }); + mockFunction(timestampInSeconds).mockReturnValue(timeOriginMilliseconds / 1000); + + const integration = appStartIntegration({ standalone: true }) as AppStartIntegrationTest; + const noTracingClient = new TestClient({ + ...getDefaultTestClientOptions(), + enableAppStartTracking: true, + tracesSampleRate: undefined, // tracing disabled => startInactiveSpan returns SentryNonRecordingSpan + }); + setCurrentClient(noTracingClient); + integration.setup(noTracingClient); + noTracingClient.addIntegration(integration); + + // Tracing disabled: extend cannot open a recording transaction, so it must not claim the run. + integration.extendAppStart(); + expect(integration.getExtendedAppStartSpan().isRecording()).toBe(false); + + // The normal capture path is not blocked by a claimed-run guard: it proceeds past the per-run + // dedup check (logs "tracking standalone root span") rather than bailing "already captured". + const logSpy = jest.spyOn(debug, 'log'); + await integration.captureStandaloneAppStart(); + expect(logSpy).not.toHaveBeenCalledWith(expect.stringContaining('already captured for this app run')); + expect(logSpy).toHaveBeenCalledWith(expect.stringContaining('tracking standalone root span')); + }); + + it('drops an in-progress extension on runApplication remount and lets the new run capture', async () => { + const { mockedOnRunApplication } = mockAppRegistryIntegration(); + mockAppStart({ cold: true }); + const { integration, client } = setupStandaloneIntegration(); + integration.afterAllSetup(client); // registers the onRunApplication callback + + integration.extendAppStart(); + expect(integration.getExtendedAppStartSpan().isRecording()).toBe(true); + + // Remount before finishExtendedAppStart()/deadline: the interrupted extension is dropped + // (never sent) and state is reset — no orphan, no send. + const runApplicationCallback = mockedOnRunApplication.mock.calls[0][0]; + runApplicationCallback(); + expect(integration.getExtendedAppStartSpan().isRecording()).toBe(false); + expect(client.eventQueue.length).toBe(0); + + // The new run can still capture its own app start. + _clearAppStartEndData(); + mockAppStart({ cold: true }); + await integration.captureStandaloneAppStart(); + expect(client.eventQueue.length).toBe(1); + expect(client.eventQueue[0]?.contexts?.trace?.op).toBe(APP_START_OP); + }); + + it('discards a finish still in flight when a new run starts, without blocking the new run', async () => { + const { mockedOnRunApplication } = mockAppRegistryIntegration(); + const [timeOriginMilliseconds, appStartTimeMilliseconds] = mockAppStart({ cold: true }); + mockFunction(timestampInSeconds).mockReturnValue(timeOriginMilliseconds / 1000); + + // Gate the native fetch so finishExtendedAppStart()'s finalize suspends inside attach. + let releaseFetch: () => void = () => {}; + const gate = new Promise(resolve => { + releaseFetch = resolve; + }); + const gatedResponse: NativeAppStartResponse = { + type: 'cold', + app_start_timestamp_ms: appStartTimeMilliseconds, + has_fetched: false, + spans: [], + }; + mockFunction(NATIVE.fetchNativeAppStart).mockReturnValue(gate.then(() => gatedResponse)); + + const { integration, client } = setupStandaloneIntegration(); + integration.afterAllSetup(client); + + integration.extendAppStart(); + const finishPromise = integration.finishExtendedAppStart(); // suspends at the gated native fetch + + // A new app run starts while the finalize is suspended awaiting native data. + const runApplicationCallback = mockedOnRunApplication.mock.calls[0][0]; + runApplicationCallback(); + + // Releasing the fetch: the stale finalize must bail without sending or corrupting shared state. + releaseFetch(); + await finishPromise; + await new Promise(resolve => setTimeout(resolve, 50)); + expect(client.eventQueue.length).toBe(0); + + // The new run captures its own app start — appStartDataFlushed was not left stuck at true. + _clearAppStartEndData(); + const [newTimeOriginMs, newAppStartMs] = mockAppStart({ cold: true }); + mockFunction(timestampInSeconds).mockReturnValue(newTimeOriginMs / 1000); + mockFunction(NATIVE.fetchNativeAppStart).mockResolvedValue({ + type: 'cold', + app_start_timestamp_ms: newAppStartMs, + has_fetched: false, + spans: [], + }); + await integration.captureStandaloneAppStart(); + expect(client.eventQueue.length).toBe(1); + }); + + it('does not send a stale transaction when a new run starts during the frames-delay await', async () => { + const { mockedOnRunApplication } = mockAppRegistryIntegration(); + const [timeOriginMilliseconds, appStartTimeMilliseconds] = mockAppStart({ cold: true }); + mockFunction(timestampInSeconds).mockReturnValue(timeOriginMilliseconds / 1000); + // endFrames present so attach reaches the second await (fetchNativeFramesDelay). + _setAppStartEndData({ + timestampMs: timeOriginMilliseconds, + endFrames: { totalFrames: 100, slowFrames: 1, frozenFrames: 0 }, + }); + + // Gate the native fetch (first await) and the frames-delay fetch (second await) independently. + let releaseNative: () => void = () => {}; + const nativeGate = new Promise(resolve => { + releaseNative = resolve; + }); + mockFunction(NATIVE.fetchNativeAppStart).mockReturnValue( + nativeGate.then(() => ({ + type: 'cold', + app_start_timestamp_ms: appStartTimeMilliseconds, + has_fetched: false, + spans: [], + })), + ); + let releaseDelay: () => void = () => {}; + const delayGate = new Promise(resolve => { + releaseDelay = resolve; + }); + mockFunction(NATIVE.fetchNativeFramesDelay).mockReturnValue(delayGate.then(() => 0.25)); + + const { integration, client } = setupStandaloneIntegration(); + integration.afterAllSetup(client); + + integration.extendAppStart(); + const child = startInactiveSpan({ parentSpan: integration.getExtendedAppStartSpan(), op: 'app.init', name: 'x' }); + child.end(); + const finishPromise = integration.finishExtendedAppStart(); + + // Let the first await pass the generation guard, then suspend at the frames-delay await. + releaseNative(); + await new Promise(resolve => setTimeout(resolve, 10)); + + // A new app run starts during the frames-delay await (after the first guard already passed). + const runApplicationCallback = mockedOnRunApplication.mock.calls[0][0]; + runApplicationCallback(); + + releaseDelay(); + await finishPromise; + await new Promise(resolve => setTimeout(resolve, 50)); + expect(client.eventQueue.length).toBe(0); + }); + + it('does not drop an extended app start whose extended duration exceeds the 60s cap', async () => { + // The 60s sanity cap applies to the native app start window, not the (deadline-bounded) + // extension — a short native start extended past a minute must still be sent. + set__DEV__(false); + const [timeOriginMilliseconds] = mockAppStart({ cold: true }); + const { integration, client } = setupStandaloneIntegration(); + + integration.extendAppStart(); + const childEndSeconds = timeOriginMilliseconds / 1000 + 61; // extended total > 60s + const child = startInactiveSpan({ + parentSpan: integration.getExtendedAppStartSpan(), + op: 'app.init', + name: 'very-late', + }); + child.end(childEndSeconds); + + await integration.finishExtendedAppStart(); + set__DEV__(true); + + expect(client.eventQueue.length).toBe(1); + const event = client.eventQueue[0] as TransactionEvent; + expect(event?.contexts?.trace?.data?.[SEMANTIC_ATTRIBUTE_APP_VITALS_START_VALUE]).toBeDefined(); + expect(event?.timestamp).toBeCloseTo(childEndSeconds, 1); + }); + + it('uses the extended end even when app start end data was never recorded (no wrap()/appLoaded())', async () => { + const [timeOriginMilliseconds] = mockAppStart({ cold: true }); + const { integration, client } = setupStandaloneIntegration(); + // Simulate no wrap()/appLoaded(): no recorded app start end, only the bundle start remains. + _clearAppStartEndData(); + + integration.extendAppStart(); + const childEndSeconds = timeOriginMilliseconds / 1000 + 3; + const child = startInactiveSpan({ + parentSpan: integration.getExtendedAppStartSpan(), + op: 'app.init', + name: 'late', + }); + child.end(childEndSeconds); + + await integration.finishExtendedAppStart(); + + // The transaction end reflects the extension, not the bundle-start fallback. + expect(client.eventQueue.length).toBe(1); + const event = client.eventQueue[0] as TransactionEvent; + expect(event?.timestamp).toBeCloseTo(childEndSeconds, 1); + expect(event?.contexts?.trace?.data?.[SEMANTIC_ATTRIBUTE_APP_VITALS_START_VALUE]).toBeDefined(); + }); +}); + describe('appLoaded() API', () => { let client: TestClient;