diff --git a/packages/browser/src/profiling/hubextensions.ts b/packages/browser/src/profiling/hubextensions.ts index aadcb541dbb0..027b25e223f9 100644 --- a/packages/browser/src/profiling/hubextensions.ts +++ b/packages/browser/src/profiling/hubextensions.ts @@ -1,24 +1,15 @@ /* eslint-disable complexity */ -import { getCurrentHub } from '@sentry/core'; import type { Transaction } from '@sentry/types'; import { logger, uuid4 } from '@sentry/utils'; import { WINDOW } from '../helpers'; -import type { JSSelfProfile, JSSelfProfiler, JSSelfProfilerConstructor } from './jsSelfProfiling'; -import { addProfileToMap, isValidSampleRate } from './utils'; - -export const MAX_PROFILE_DURATION_MS = 30_000; -// Keep a flag value to avoid re-initializing the profiler constructor. If it fails -// once, it will always fail and this allows us to early return. -let PROFILING_CONSTRUCTOR_FAILED = false; - -/** - * Check if profiler constructor is available. - * @param maybeProfiler - */ -function isJSProfilerSupported(maybeProfiler: unknown): maybeProfiler is typeof JSSelfProfilerConstructor { - return typeof maybeProfiler === 'function'; -} +import type { JSSelfProfile } from './jsSelfProfiling'; +import { + addProfileToGlobalCache, + MAX_PROFILE_DURATION_MS, + shouldProfileTransaction, + startJSSelfProfile, +} from './utils'; /** * Safety wrapper for startTransaction for the unlikely case that transaction starts before tracing is imported - @@ -35,98 +26,24 @@ export function onProfilingStartRouteTransaction(transaction: Transaction | unde return transaction; } - return wrapTransactionWithProfiling(transaction); + if (shouldProfileTransaction(transaction)) { + return startProfileForTransaction(transaction); + } + + return transaction; } /** * Wraps startTransaction and stopTransaction with profiling related logic. - * startProfiling is called after the call to startTransaction in order to avoid our own code from + * startProfileForTransaction is called after the call to startTransaction in order to avoid our own code from * being profiled. Because of that same reason, stopProfiling is called before the call to stopTransaction. */ -export function wrapTransactionWithProfiling(transaction: Transaction): Transaction { - // Feature support check first - const JSProfilerConstructor = WINDOW.Profiler; - - if (!isJSProfilerSupported(JSProfilerConstructor)) { - if (__DEBUG_BUILD__) { - logger.log( - '[Profiling] Profiling is not supported by this browser, Profiler interface missing on window object.', - ); - } - return transaction; - } - - // If constructor failed once, it will always fail, so we can early return. - if (PROFILING_CONSTRUCTOR_FAILED) { - if (__DEBUG_BUILD__) { - logger.log('[Profiling] Profiling has been disabled for the duration of the current user session.'); - } - return transaction; - } - - const client = getCurrentHub().getClient(); - const options = client && client.getOptions(); - if (!options) { - __DEBUG_BUILD__ && logger.log('[Profiling] Profiling disabled, no options found.'); - return transaction; - } +export function startProfileForTransaction(transaction: Transaction): Transaction { + // Start the profiler and get the profiler instance. + const profiler = startJSSelfProfile(); - // @ts-expect-error profilesSampleRate is not part of the browser options yet - const profilesSampleRate: number | boolean | undefined = options.profilesSampleRate; - - // Since this is coming from the user (or from a function provided by the user), who knows what we might get. (The - // only valid values are booleans or numbers between 0 and 1.) - if (!isValidSampleRate(profilesSampleRate)) { - __DEBUG_BUILD__ && logger.warn('[Profiling] Discarding profile because of invalid sample rate.'); - return transaction; - } - - // if the function returned 0 (or false), or if `profileSampleRate` is 0, it's a sign the profile should be dropped - if (!profilesSampleRate) { - __DEBUG_BUILD__ && - logger.log( - '[Profiling] Discarding profile because a negative sampling decision was inherited or profileSampleRate is set to 0', - ); - return transaction; - } - - // Now we roll the dice. Math.random is inclusive of 0, but not of 1, so strict < is safe here. In case sampleRate is - // a boolean, the < comparison will cause it to be automatically cast to 1 if it's true and 0 if it's false. - const sampled = profilesSampleRate === true ? true : Math.random() < profilesSampleRate; - // Check if we should sample this profile - if (!sampled) { - __DEBUG_BUILD__ && - logger.log( - `[Profiling] Discarding profile because it's not included in the random sample (sampling rate = ${Number( - profilesSampleRate, - )})`, - ); - return transaction; - } - - // From initial testing, it seems that the minimum value for sampleInterval is 10ms. - const samplingIntervalMS = 10; - // Start the profiler - const maxSamples = Math.floor(MAX_PROFILE_DURATION_MS / samplingIntervalMS); - let profiler: JSSelfProfiler | undefined; - - // Attempt to initialize the profiler constructor, if it fails, we disable profiling for the current user session. - // This is likely due to a missing 'Document-Policy': 'js-profiling' header. We do not want to throw an error if this happens - // as we risk breaking the user's application, so just disable profiling and log an error. - try { - profiler = new JSProfilerConstructor({ sampleInterval: samplingIntervalMS, maxBufferSize: maxSamples }); - } catch (e) { - if (__DEBUG_BUILD__) { - logger.log( - "[Profiling] Failed to initialize the Profiling constructor, this is likely due to a missing 'Document-Policy': 'js-profiling' header.", - ); - logger.log('[Profiling] Disabling profiling for current user session.'); - } - PROFILING_CONSTRUCTOR_FAILED = true; - } - - // We failed to construct the profiler, fallback to original transaction - there is no need to log - // anything as we already did that in the try/catch block. + // We failed to construct the profiler, fallback to original transaction. + // No need to log anything as this has already been logged in startProfile. if (!profiler) { return transaction; } @@ -172,19 +89,9 @@ export function wrapTransactionWithProfiling(transaction: Transaction): Transact return null; } - // This is temporary - we will use the collected span data to evaluate - // if deferring txn.finish until profiler resolves is a viable approach. - const stopProfilerSpan = transaction.startChild({ - description: 'profiler.stop', - op: 'profiler', - origin: 'auto.profiler.browser', - }); - return profiler .stop() - .then((p: JSSelfProfile): null => { - stopProfilerSpan.finish(); - + .then((profile: JSSelfProfile): null => { if (maxDurationTimeoutID) { WINDOW.clearTimeout(maxDurationTimeoutID); maxDurationTimeoutID = undefined; @@ -195,7 +102,7 @@ export function wrapTransactionWithProfiling(transaction: Transaction): Transact } // In case of an overlapping transaction, stopProfiling may return null and silently ignore the overlapping profile. - if (!p) { + if (!profile) { if (__DEBUG_BUILD__) { logger.log( `[Profiling] profiler returned null profile for: ${transaction.name || transaction.description}`, @@ -205,11 +112,10 @@ export function wrapTransactionWithProfiling(transaction: Transaction): Transact return null; } - addProfileToMap(profileId, p); + addProfileToGlobalCache(profileId, profile); return null; }) .catch(error => { - stopProfilerSpan.finish(); if (__DEBUG_BUILD__) { logger.log('[Profiling] error while stopping profiler:', error); } diff --git a/packages/browser/src/profiling/integration.ts b/packages/browser/src/profiling/integration.ts index dc7cb4d15120..1792b1190c1e 100644 --- a/packages/browser/src/profiling/integration.ts +++ b/packages/browser/src/profiling/integration.ts @@ -2,14 +2,16 @@ import type { EventProcessor, Hub, Integration, Transaction } from '@sentry/type import type { Profile } from '@sentry/types/src/profiling'; import { logger } from '@sentry/utils'; -import type { BrowserClient } from './../client'; -import { wrapTransactionWithProfiling } from './hubextensions'; +import { startProfileForTransaction } from './hubextensions'; import type { ProfiledEvent } from './utils'; import { addProfilesToEnvelope, createProfilingEvent, findProfiledTransactionsFromEnvelope, - PROFILE_MAP, + getActiveProfilesCount, + isAutomatedPageLoadTransaction, + shouldProfileTransaction, + takeProfileFromGlobalCache, } from './utils'; /** @@ -37,16 +39,29 @@ export class BrowserProfilingIntegration implements Integration { */ public setupOnce(_addGlobalEventProcessor: (callback: EventProcessor) => void, getCurrentHub: () => Hub): void { this.getCurrentHub = getCurrentHub; - const client = this.getCurrentHub().getClient() as BrowserClient; + + const hub = this.getCurrentHub(); + const client = hub.getClient(); + const scope = hub.getScope(); + + const transaction = scope.getTransaction(); + + if (transaction && isAutomatedPageLoadTransaction(transaction)) { + if (shouldProfileTransaction(transaction)) { + startProfileForTransaction(transaction); + } + } if (client && typeof client.on === 'function') { client.on('startTransaction', (transaction: Transaction) => { - wrapTransactionWithProfiling(transaction); + if (shouldProfileTransaction(transaction)) { + startProfileForTransaction(transaction); + } }); client.on('beforeEnvelope', (envelope): void => { // if not profiles are in queue, there is nothing to add to the envelope. - if (!PROFILE_MAP['size']) { + if (!getActiveProfilesCount()) { return; } @@ -59,7 +74,13 @@ export class BrowserProfilingIntegration implements Integration { for (const profiledTransaction of profiledTransactionEvents) { const context = profiledTransaction && profiledTransaction.contexts; - const profile_id = context && context['profile'] && (context['profile']['profile_id'] as string); + const profile_id = context && context['profile'] && context['profile']['profile_id']; + + if (typeof profile_id !== 'string') { + __DEBUG_BUILD__ && + logger.log('[Profiling] cannot find profile for a transaction without a profile context'); + continue; + } if (!profile_id) { __DEBUG_BUILD__ && @@ -72,15 +93,13 @@ export class BrowserProfilingIntegration implements Integration { delete context.profile; } - const profile = PROFILE_MAP.get(profile_id); + const profile = takeProfileFromGlobalCache(profile_id); if (!profile) { __DEBUG_BUILD__ && logger.log(`[Profiling] Could not retrieve profile for transaction: ${profile_id}`); continue; } - PROFILE_MAP.delete(profile_id); const profileEvent = createProfilingEvent(profile_id, profile, profiledTransaction as ProfiledEvent); - if (profileEvent) { profilesToAddToEnvelope.push(profileEvent); } diff --git a/packages/browser/src/profiling/jsSelfProfiling.ts b/packages/browser/src/profiling/jsSelfProfiling.ts index 8dc981d3d5d3..a0030f7cc39c 100644 --- a/packages/browser/src/profiling/jsSelfProfiling.ts +++ b/packages/browser/src/profiling/jsSelfProfiling.ts @@ -26,14 +26,12 @@ export type JSSelfProfile = { samples: JSSelfProfileSample[]; }; -type BufferFullCallback = (trace: JSSelfProfile) => void; - export interface JSSelfProfiler { sampleInterval: number; stopped: boolean; stop: () => Promise; - addEventListener(event: 'samplebufferfull', callback: BufferFullCallback): void; + addEventListener(event: 'samplebufferfull', callback: (trace: JSSelfProfile) => void): void; } export declare const JSSelfProfilerConstructor: { diff --git a/packages/browser/src/profiling/utils.ts b/packages/browser/src/profiling/utils.ts index 40944fc260fe..5c713980f690 100644 --- a/packages/browser/src/profiling/utils.ts +++ b/packages/browser/src/profiling/utils.ts @@ -1,12 +1,12 @@ /* eslint-disable max-lines */ import { DEFAULT_ENVIRONMENT, getCurrentHub } from '@sentry/core'; -import type { DebugImage, Envelope, Event, StackFrame, StackParser } from '@sentry/types'; +import type { DebugImage, Envelope, Event, StackFrame, StackParser, Transaction } from '@sentry/types'; import type { Profile, ThreadCpuProfile } from '@sentry/types/src/profiling'; import { browserPerformanceTimeOrigin, forEachEnvelopeItem, GLOBAL_OBJ, logger, uuid4 } from '@sentry/utils'; import { WINDOW } from '../helpers'; -import type { JSSelfProfile, JSSelfProfileStack } from './jsSelfProfiling'; +import type { JSSelfProfile, JSSelfProfiler, JSSelfProfilerConstructor, JSSelfProfileStack } from './jsSelfProfiling'; const MS_TO_NS = 1e6; // Use 0 as main thread id which is identical to threadId in node:worker_threads @@ -189,6 +189,16 @@ export function isProfiledTransactionEvent(event: Event): event is ProfiledEvent return !!(event.sdkProcessingMetadata && event.sdkProcessingMetadata['profile']); } +/* + See packages/tracing-internal/src/browser/router.ts +*/ +/** + * + */ +export function isAutomatedPageLoadTransaction(transaction: Transaction): boolean { + return transaction.op === 'pageload'; +} + /** * Converts a JSSelfProfile to a our sampled format. * Does not currently perform stack indexing. @@ -446,6 +456,120 @@ function isValidProfile(profile: JSSelfProfile): profile is JSSelfProfile & { pr return true; } +// Keep a flag value to avoid re-initializing the profiler constructor. If it fails +// once, it will always fail and this allows us to early return. +let PROFILING_CONSTRUCTOR_FAILED: boolean = false; +export const MAX_PROFILE_DURATION_MS = 30_000; + +/** + * Check if profiler constructor is available. + * @param maybeProfiler + */ +function isJSProfilerSupported(maybeProfiler: unknown): maybeProfiler is typeof JSSelfProfilerConstructor { + return typeof maybeProfiler === 'function'; +} + +/** + * Starts the profiler and returns the profiler instance. + */ +export function startJSSelfProfile(): JSSelfProfiler | undefined { + // Feature support check first + const JSProfilerConstructor = WINDOW.Profiler; + + if (!isJSProfilerSupported(JSProfilerConstructor)) { + if (__DEBUG_BUILD__) { + logger.log( + '[Profiling] Profiling is not supported by this browser, Profiler interface missing on window object.', + ); + } + return; + } + + // From initial testing, it seems that the minimum value for sampleInterval is 10ms. + const samplingIntervalMS = 10; + // Start the profiler + const maxSamples = Math.floor(MAX_PROFILE_DURATION_MS / samplingIntervalMS); + + // Attempt to initialize the profiler constructor, if it fails, we disable profiling for the current user session. + // This is likely due to a missing 'Document-Policy': 'js-profiling' header. We do not want to throw an error if this happens + // as we risk breaking the user's application, so just disable profiling and log an error. + try { + return new JSProfilerConstructor({ sampleInterval: samplingIntervalMS, maxBufferSize: maxSamples }); + } catch (e) { + if (__DEBUG_BUILD__) { + logger.log( + "[Profiling] Failed to initialize the Profiling constructor, this is likely due to a missing 'Document-Policy': 'js-profiling' header.", + ); + logger.log('[Profiling] Disabling profiling for current user session.'); + } + PROFILING_CONSTRUCTOR_FAILED = true; + } + + return; +} + +/** + * Determine if a profile should be profiled. + */ +export function shouldProfileTransaction(transaction: Transaction): boolean { + // If constructor failed once, it will always fail, so we can early return. + if (PROFILING_CONSTRUCTOR_FAILED) { + if (__DEBUG_BUILD__) { + logger.log('[Profiling] Profiling has been disabled for the duration of the current user session.'); + } + return false; + } + + if (!transaction.sampled) { + if (__DEBUG_BUILD__) { + logger.log('[Profiling] Discarding profile because transaction was not sampled.'); + } + return false; + } + + const client = getCurrentHub().getClient(); + const options = client && client.getOptions(); + if (!options) { + __DEBUG_BUILD__ && logger.log('[Profiling] Profiling disabled, no options found.'); + return false; + } + + // @ts-expect-error profilesSampleRate is not part of the browser options yet + const profilesSampleRate: number | boolean | undefined = options.profilesSampleRate; + + // Since this is coming from the user (or from a function provided by the user), who knows what we might get. (The + // only valid values are booleans or numbers between 0 and 1.) + if (!isValidSampleRate(profilesSampleRate)) { + __DEBUG_BUILD__ && logger.warn('[Profiling] Discarding profile because of invalid sample rate.'); + return false; + } + + // if the function returned 0 (or false), or if `profileSampleRate` is 0, it's a sign the profile should be dropped + if (!profilesSampleRate) { + __DEBUG_BUILD__ && + logger.log( + '[Profiling] Discarding profile because a negative sampling decision was inherited or profileSampleRate is set to 0', + ); + return false; + } + + // Now we roll the dice. Math.random is inclusive of 0, but not of 1, so strict < is safe here. In case sampleRate is + // a boolean, the < comparison will cause it to be automatically cast to 1 if it's true and 0 if it's false. + const sampled = profilesSampleRate === true ? true : Math.random() < profilesSampleRate; + // Check if we should sample this profile + if (!sampled) { + __DEBUG_BUILD__ && + logger.log( + `[Profiling] Discarding profile because it's not included in the random sample (sampling rate = ${Number( + profilesSampleRate, + )})`, + ); + return false; + } + + return true; +} + /** * Creates a profiling envelope item, if the profile does not pass validation, returns null. * @param event @@ -459,11 +583,28 @@ export function createProfilingEvent(profile_id: string, profile: JSSelfProfile, return createProfilePayload(event, profile, profile_id); } -export const PROFILE_MAP: Map = new Map(); +const PROFILE_MAP: Map = new Map(); /** * */ -export function addProfileToMap(profile_id: string, profile: JSSelfProfile): void { +export function getActiveProfilesCount(): number { + return PROFILE_MAP.size; +} + +/** + * Retrieves profile from global cache and removes it. + */ +export function takeProfileFromGlobalCache(profile_id: string): JSSelfProfile | undefined { + const profile = PROFILE_MAP.get(profile_id); + if (profile) { + PROFILE_MAP.delete(profile_id); + } + return profile; +} +/** + * Adds profile to global cache and evicts the oldest profile if the cache is full. + */ +export function addProfileToGlobalCache(profile_id: string, profile: JSSelfProfile): void { PROFILE_MAP.set(profile_id, profile); if (PROFILE_MAP.size > 30) { diff --git a/packages/browser/test/unit/profiling/integration.test.ts b/packages/browser/test/unit/profiling/integration.test.ts new file mode 100644 index 000000000000..d95c3f21ebf5 --- /dev/null +++ b/packages/browser/test/unit/profiling/integration.test.ts @@ -0,0 +1,68 @@ +import type { BrowserClient } from '@sentry/browser'; +import * as Sentry from '@sentry/browser'; + +import { BrowserProfilingIntegration } from '../../../src/profiling/integration'; +import type { JSSelfProfile } from '../../../src/profiling/jsSelfProfiling'; + +describe('BrowserProfilingIntegration', () => { + beforeEach(() => { + jest.clearAllMocks(); + jest.useRealTimers(); + // We will mock the carrier as if it has been initialized by the SDK, else everything is short circuited + }); + it('pageload profiles follow regular transaction code path', async () => { + const stopProfile = jest.fn().mockImplementation((): Promise => { + return Promise.resolve({ + frames: [{ name: 'pageload_fn', line: 1, column: 1 }], + stacks: [{ frameId: 0, parentId: undefined }], + samples: [ + { stackId: 0, timestamp: 0 }, + { stackId: 0, timestamp: 100 }, + { stackId: 0, timestamp: 200 }, + ], + resources: [], + }); + }); + + class MockProfiler { + stopped: boolean = false; + constructor(_opts: { sampleInterval: number; maxBufferSize: number }) {} + stop() { + this.stopped = true; + return stopProfile(); + } + } + + // @ts-expect-error this is a mock constructor + window.Profiler = MockProfiler; + + const flush = jest.fn().mockImplementation(() => Promise.resolve(true)); + const send = jest.fn().mockImplementation(() => Promise.resolve()); + Sentry.init({ + tracesSampleRate: 1, + profilesSampleRate: 1, + debug: true, + environment: 'test-environment', + dsn: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302', + transport: _opts => { + return { + flush, + send, + }; + }, + integrations: [new Sentry.BrowserTracing(), new BrowserProfilingIntegration()], + }); + + const client = Sentry.getCurrentHub().getClient() as BrowserClient; + + const currentTransaction = Sentry.getCurrentHub().getScope().getTransaction(); + expect(currentTransaction?.op).toBe('pageload'); + currentTransaction?.finish(); + await client.flush(1000); + + expect(send).toHaveBeenCalledTimes(1); + + const profile = send.mock.calls?.[0]?.[0]?.[1]?.[1]?.[1]; + expect(profile.profile.frames[0]).toMatchObject({ function: 'pageload_fn', lineno: 1, colno: 1 }); + }); +});