diff --git a/docs/migration/continuous-profiling.md b/docs/migration/continuous-profiling.md new file mode 100644 index 000000000000..59f7a0824b08 --- /dev/null +++ b/docs/migration/continuous-profiling.md @@ -0,0 +1,28 @@ +# Continuous Profiling API Changes + +The continuous profiling API has been redesigned to give developers more explicit control over profiling sessions while maintaining ease of use. This guide outlines the key changes. + +## New Profiling Modes + +### profileLifecycle Option + +We've introduced a new `profileLifecycle` option that allows you to explicitly set how profiling sessions are managed: + +- `manual` (default) - You control profiling sessions using the API methods +- `trace` - Profiling sessions are automatically tied to traces + +Previously, the profiling mode was implicitly determined by initialization options. Now you can clearly specify your intended behavior. + +## New Sampling Controls + +### profileSessionSampleRate + +We've introduced `profileSessionSampleRate` to control what percentage of SDK instances will collect profiles. This is evaluated once during SDK initialization. This is particularly useful for: + +- Controlling profiling costs across distributed services +- Managing profiling in serverless environments where you may only want to profile a subset of instances + +### Deprecations + +The `profilesSampleRate` option has been deprecated in favor of the new sampling controls. +The `profilesSampler` option hsa been deprecated in favor of manual profiler control. diff --git a/packages/core/src/types-hoist/profiling.ts b/packages/core/src/types-hoist/profiling.ts index 7f4f316a9d0b..2c0c439450bb 100644 --- a/packages/core/src/types-hoist/profiling.ts +++ b/packages/core/src/types-hoist/profiling.ts @@ -14,7 +14,14 @@ export interface ProfilingIntegration extends Integration { } export interface Profiler { + /** + * Starts the profiler. + */ startProfiler(): void; + + /** + * Stops the profiler. + */ stopProfiler(): void; } diff --git a/packages/node/src/types.ts b/packages/node/src/types.ts index bf4913688470..9223619522e6 100644 --- a/packages/node/src/types.ts +++ b/packages/node/src/types.ts @@ -26,6 +26,8 @@ export interface BaseNodeOptions { /** * Sets profiling sample rate when @sentry/profiling-node is installed + * + * @deprecated */ profilesSampleRate?: number; @@ -39,9 +41,27 @@ export interface BaseNodeOptions { * * @returns A sample rate between 0 and 1 (0 drops the profile, 1 guarantees it will be sent). Returning `true` is * equivalent to returning 1 and returning `false` is equivalent to returning 0. + * + * @deprecated */ profilesSampler?: (samplingContext: SamplingContext) => number | boolean; + /** + * Sets profiling session sample rate - only evaluated once per SDK initialization. + * @default 0 + */ + profileSessionSampleRate?: number; + + /** + * Set the lifecycle of the profiler. + * + * - `manual`: The profiler will be manually started and stopped. + * - `trace`: The profiler will be automatically started when when a span is sampled and stopped when there are no more sampled spans. + * + * @default 'manual' + */ + profileLifecycle?: 'manual' | 'trace'; + /** Sets an optional server name (device name) */ serverName?: string; diff --git a/packages/profiling-node/src/integration.ts b/packages/profiling-node/src/integration.ts index e134a272b929..35243f6da396 100644 --- a/packages/profiling-node/src/integration.ts +++ b/packages/profiling-node/src/integration.ts @@ -13,7 +13,7 @@ import { spanToJSON, uuid4, } from '@sentry/core'; -import type { NodeClient } from '@sentry/node'; +import type { NodeClient, NodeOptions } from '@sentry/node'; import { DEBUG_BUILD } from './debug-build'; import { NODE_MAJOR, NODE_VERSION } from './nodeVersion'; import { MAX_PROFILE_DURATION_MS, maybeProfileSpan, stopSpanProfile } from './spanProfileUtils'; @@ -41,120 +41,6 @@ function takeFromProfileQueue(profile_id: string): RawThreadCpuProfile | undefin return profile; } -/** - * Instruments the client to automatically invoke the profiler on span start and stop events. - * @param client - */ -function setupAutomatedSpanProfiling(client: NodeClient): void { - const spanToProfileIdMap = new WeakMap(); - - client.on('spanStart', span => { - if (span !== getRootSpan(span)) { - return; - } - - const profile_id = maybeProfileSpan(client, span); - - if (profile_id) { - const options = client.getOptions(); - // Not intended for external use, hence missing types, but we want to profile a couple of things at Sentry that - // currently exceed the default timeout set by the SDKs. - const maxProfileDurationMs = options._experiments?.maxProfileDurationMs || MAX_PROFILE_DURATION_MS; - - if (PROFILE_TIMEOUTS[profile_id]) { - global.clearTimeout(PROFILE_TIMEOUTS[profile_id]); - // eslint-disable-next-line @typescript-eslint/no-dynamic-delete - delete PROFILE_TIMEOUTS[profile_id]; - } - - // Enqueue a timeout to prevent profiles from running over max duration. - const timeout = global.setTimeout(() => { - DEBUG_BUILD && - logger.log('[Profiling] max profile duration elapsed, stopping profiling for:', spanToJSON(span).description); - - const profile = stopSpanProfile(span, profile_id); - if (profile) { - addToProfileQueue(profile_id, profile); - } - }, maxProfileDurationMs); - - // Unref timeout so it doesn't keep the process alive. - timeout.unref(); - - getIsolationScope().setContext('profile', { profile_id }); - spanToProfileIdMap.set(span, profile_id); - } - }); - - client.on('spanEnd', span => { - const profile_id = spanToProfileIdMap.get(span); - - if (profile_id) { - if (PROFILE_TIMEOUTS[profile_id]) { - global.clearTimeout(PROFILE_TIMEOUTS[profile_id]); - // eslint-disable-next-line @typescript-eslint/no-dynamic-delete - delete PROFILE_TIMEOUTS[profile_id]; - } - const profile = stopSpanProfile(span, profile_id); - - if (profile) { - addToProfileQueue(profile_id, profile); - } - } - }); - - client.on('beforeEnvelope', (envelope): void => { - // if not profiles are in queue, there is nothing to add to the envelope. - if (!PROFILE_MAP.size) { - return; - } - - const profiledTransactionEvents = findProfiledTransactionsFromEnvelope(envelope); - if (!profiledTransactionEvents.length) { - return; - } - - const profilesToAddToEnvelope: Profile[] = []; - - for (const profiledTransaction of profiledTransactionEvents) { - const profileContext = profiledTransaction.contexts?.profile; - const profile_id = profileContext?.profile_id; - - if (!profile_id) { - throw new TypeError('[Profiling] cannot find profile for a transaction without a profile context'); - } - - // Remove the profile from the transaction context before sending, relay will take care of the rest. - if (profileContext) { - delete profiledTransaction.contexts?.profile; - } - - const cpuProfile = takeFromProfileQueue(profile_id); - if (!cpuProfile) { - DEBUG_BUILD && logger.log(`[Profiling] Could not retrieve profile for transaction: ${profile_id}`); - continue; - } - - const profile = createProfilingEvent(client, cpuProfile, profiledTransaction); - if (!profile) return; - - profilesToAddToEnvelope.push(profile); - - // @ts-expect-error profile does not inherit from Event - client.emit('preprocessEvent', profile, { - event_id: profiledTransaction.event_id, - }); - - // @ts-expect-error profile does not inherit from Event - client.emit('postprocessEvent', profile, { - event_id: profiledTransaction.event_id, - }); - } - - addProfilesToEnvelope(envelope, profilesToAddToEnvelope); - }); -} - interface ChunkData { id: string; timer: NodeJS.Timeout | undefined; @@ -165,7 +51,11 @@ class ContinuousProfiler { private _profilerId: string | undefined; private _client: NodeClient | undefined = undefined; private _chunkData: ChunkData | undefined = undefined; - + private _mode: 'legacy' | 'current' | undefined = undefined; + private _legacyProfilerMode: 'span' | 'continuous' | undefined = undefined; + private _profileLifecycle: 'manual' | 'trace' | undefined = undefined; + private _sampled: boolean | undefined = undefined; + private _sessionSamplingRate: number | undefined = undefined; /** * Called when the profiler is attached to the client (continuous mode is enabled). If of the profiler * methods called before the profiler is initialized will result in a noop action with debug logs. @@ -173,6 +63,67 @@ class ContinuousProfiler { */ public initialize(client: NodeClient): void { this._client = client; + const options = client.getOptions(); + + this._mode = getProfilingMode(options); + this._sessionSamplingRate = Math.random(); + this._sampled = this._sessionSamplingRate < (options.profileSessionSampleRate ?? 0); + this._profileLifecycle = options.profileLifecycle ?? 'manual'; + + switch (this._mode) { + case 'legacy': { + this._legacyProfilerMode = + 'profilesSampleRate' in options || 'profilesSampler' in options ? 'span' : 'continuous'; + + DEBUG_BUILD && logger.log(`[Profiling] Profiling mode is ${this._legacyProfilerMode}.`); + + switch (this._legacyProfilerMode) { + case 'span': { + this._setupAutomaticSpanProfiling(); + break; + } + case 'continuous': { + // Continous mode requires manual calls to profiler.start() and profiler.stop() + break; + } + default: { + DEBUG_BUILD && + logger.warn( + `[Profiling] Unknown profiler mode: ${this._legacyProfilerMode}, profiler was not initialized`, + ); + break; + } + } + break; + } + + case 'current': { + this._setupSpanChunkInstrumentation(); + + DEBUG_BUILD && logger.log(`[Profiling] Profiling mode is ${this._profileLifecycle}.`); + + switch (this._profileLifecycle) { + case 'trace': { + this._startTraceLifecycleProfiling(); + break; + } + case 'manual': { + // Manual mode requires manual calls to profiler.startProfiler() and profiler.stopProfiler() + break; + } + default: { + DEBUG_BUILD && + logger.warn(`[Profiling] Unknown profiler mode: ${this._profileLifecycle}, profiler was not initialized`); + break; + } + } + break; + } + default: { + DEBUG_BUILD && logger.warn(`[Profiling] Unknown profiler mode: ${this._mode}, profiler was not initialized`); + break; + } + } // Attaches a listener to beforeSend which will add the threadId data to the event being sent. // This adds a constant overhead to all events being sent which could be improved to only attach @@ -185,17 +136,33 @@ class ContinuousProfiler { * @returns void */ public start(): void { + if (this._mode === 'current') { + this._startProfiler(); + return; + } + if (!this._client) { DEBUG_BUILD && logger.log('[Profiling] Failed to start, sentry client was never attached to the profiler.'); return; } + if (this._mode !== 'legacy') { + DEBUG_BUILD && logger.log('[Profiling] Continuous profiling is not supported in the current mode.'); + return; + } + + if (this._legacyProfilerMode === 'span') { + DEBUG_BUILD && logger.log('[Profiling] Calls to profiler.start() are not supported in span profiling mode.'); + return; + } + // Flush any existing chunks before starting a new one. - this._chunkStop(); + + this._stopChunkProfiling(); // Restart the profiler session this._setupSpanChunkInstrumentation(); - this._chunkStart(); + this._restartChunkProfiling(); } /** @@ -203,18 +170,238 @@ class ContinuousProfiler { * @returns void */ public stop(): void { + if (this._mode === 'current') { + this._stopProfiler(); + return; + } + if (!this._client) { DEBUG_BUILD && logger.log('[Profiling] Failed to stop, sentry client was never attached to the profiler.'); return; } - this._chunkStop(); + + if (this._mode !== 'legacy') { + DEBUG_BUILD && logger.log('[Profiling] Continuous profiling is not supported in the current mode.'); + return; + } + + if (this._legacyProfilerMode === 'span') { + DEBUG_BUILD && logger.log('[Profiling] Calls to profiler.stop() are not supported in span profiling mode.'); + return; + } + + this._stopChunkProfiling(); this._teardownSpanChunkInstrumentation(); } + private _startProfiler(): void { + if (this._mode !== 'current') { + DEBUG_BUILD && logger.log('[Profiling] Continuous profiling is not supported in the current mode.'); + return; + } + + if (this._chunkData !== undefined) { + DEBUG_BUILD && logger.log('[Profiling] Profile session already running, no-op.'); + return; + } + + if (this._mode === 'current') { + if (!this._sampled) { + DEBUG_BUILD && logger.log('[Profiling] Profile session not sampled, no-op.'); + return; + } + } + + if (this._profileLifecycle === 'trace') { + DEBUG_BUILD && + logger.log( + '[Profiling] You are using the trace profile lifecycle, manual calls to profiler.startProfiler() and profiler.stopProfiler() will be ignored.', + ); + return; + } + + this._startChunkProfiling(); + } + + private _stopProfiler(): void { + if (this._mode !== 'current') { + DEBUG_BUILD && logger.log('[Profiling] Continuous profiling is not supported in the current mode.'); + return; + } + + if (this._profileLifecycle === 'trace') { + DEBUG_BUILD && + logger.log( + '[Profiling] You are using the trace profile lifecycle, manual calls to profiler.startProfiler() and profiler.stopProfiler() will be ignored.', + ); + return; + } + + if (!this._chunkData) { + DEBUG_BUILD && logger.log('[Profiling] No profile session running, no-op.'); + return; + } + + this._stopChunkProfiling(); + } + + /** + * Starts trace lifecycle profiling. Profiling will remain active as long as there is an active span. + */ + private _startTraceLifecycleProfiling(): void { + if (!this._client) { + DEBUG_BUILD && + logger.log( + '[Profiling] Failed to start trace lifecycle profiling, sentry client was never attached to the profiler.', + ); + return; + } + + let activeSpanCounter = 0; + this._client.on('spanStart', _span => { + if (activeSpanCounter === 0) { + this._startChunkProfiling(); + } + activeSpanCounter++; + }); + + this._client.on('spanEnd', _span => { + if (activeSpanCounter === 1) { + this._stopChunkProfiling(); + } + activeSpanCounter--; + }); + } + + private _setupAutomaticSpanProfiling(): void { + if (!this._client) { + DEBUG_BUILD && + logger.log( + '[Profiling] Failed to setup automatic span profiling, sentry client was never attached to the profiler.', + ); + return; + } + + const spanToProfileIdMap = new WeakMap(); + + this._client.on('spanStart', span => { + if (span !== getRootSpan(span)) { + return; + } + + const profile_id = maybeProfileSpan(this._client, span); + + if (profile_id) { + // eslint-disable-next-line @typescript-eslint/no-non-null-assertion + const options = this._client!.getOptions(); + // Not intended for external use, hence missing types, but we want to profile a couple of things at Sentry that + // currently exceed the default timeout set by the SDKs. + const maxProfileDurationMs = options._experiments?.maxProfileDurationMs || MAX_PROFILE_DURATION_MS; + + if (PROFILE_TIMEOUTS[profile_id]) { + global.clearTimeout(PROFILE_TIMEOUTS[profile_id]); + // eslint-disable-next-line @typescript-eslint/no-dynamic-delete + delete PROFILE_TIMEOUTS[profile_id]; + } + + // Enqueue a timeout to prevent profiles from running over max duration. + const timeout = global.setTimeout(() => { + DEBUG_BUILD && + logger.log( + '[Profiling] max profile duration elapsed, stopping profiling for:', + spanToJSON(span).description, + ); + + const profile = stopSpanProfile(span, profile_id); + if (profile) { + addToProfileQueue(profile_id, profile); + } + }, maxProfileDurationMs); + + // Unref timeout so it doesn't keep the process alive. + timeout.unref(); + + getIsolationScope().setContext('profile', { profile_id }); + spanToProfileIdMap.set(span, profile_id); + } + }); + + this._client.on('spanEnd', span => { + const profile_id = spanToProfileIdMap.get(span); + + if (profile_id) { + if (PROFILE_TIMEOUTS[profile_id]) { + global.clearTimeout(PROFILE_TIMEOUTS[profile_id]); + // eslint-disable-next-line @typescript-eslint/no-dynamic-delete + delete PROFILE_TIMEOUTS[profile_id]; + } + const profile = stopSpanProfile(span, profile_id); + + if (profile) { + addToProfileQueue(profile_id, profile); + } + } + }); + + this._client.on('beforeEnvelope', (envelope): void => { + // if not profiles are in queue, there is nothing to add to the envelope. + if (!PROFILE_MAP.size) { + return; + } + + const profiledTransactionEvents = findProfiledTransactionsFromEnvelope(envelope); + if (!profiledTransactionEvents.length) { + return; + } + + const profilesToAddToEnvelope: Profile[] = []; + + for (const profiledTransaction of profiledTransactionEvents) { + const profileContext = profiledTransaction.contexts?.profile; + const profile_id = profileContext?.profile_id; + + if (!profile_id) { + throw new TypeError('[Profiling] cannot find profile for a transaction without a profile context'); + } + + // Remove the profile from the transaction context before sending, relay will take care of the rest. + if (profileContext) { + delete profiledTransaction.contexts?.profile; + } + + const cpuProfile = takeFromProfileQueue(profile_id); + if (!cpuProfile) { + DEBUG_BUILD && logger.log(`[Profiling] Could not retrieve profile for transaction: ${profile_id}`); + continue; + } + + // eslint-disable-next-line @typescript-eslint/no-non-null-assertion + const profile = createProfilingEvent(this._client!, cpuProfile, profiledTransaction); + if (!profile) return; + + profilesToAddToEnvelope.push(profile); + + // @ts-expect-error profile does not inherit from Event + // eslint-disable-next-line @typescript-eslint/no-non-null-assertion + this._client!.emit('preprocessEvent', profile, { + event_id: profiledTransaction.event_id, + }); + + // @ts-expect-error profile does not inherit from Event + // eslint-disable-next-line @typescript-eslint/no-non-null-assertion + this._client!.emit('postprocessEvent', profile, { + event_id: profiledTransaction.event_id, + }); + } + + addProfilesToEnvelope(envelope, profilesToAddToEnvelope); + }); + } + /** * Stop profiler and initializes profiling of the next chunk */ - private _chunkStart(): void { + private _restartChunkProfiling(): void { if (!this._client) { // The client is not attached to the profiler if the user has not enabled continuous profiling. // In this case, calling start() and stop() is a noop action.The reason this exists is because @@ -222,12 +409,13 @@ class ContinuousProfiler { DEBUG_BUILD && logger.log('[Profiling] Profiler was never attached to the client.'); return; } + if (this._chunkData) { DEBUG_BUILD && logger.log( `[Profiling] Chunk with chunk_id ${this._chunkData.id} is still running, current chunk will be stopped a new chunk will be started.`, ); - this._chunkStop(); + this._stopChunkProfiling(); } this._startChunkProfiling(); @@ -236,32 +424,44 @@ class ContinuousProfiler { /** * Stops profiling of the current chunks and flushes the profile to Sentry */ - private _chunkStop(): void { + private _stopChunkProfiling(): void { + if (!this._chunkData) { + DEBUG_BUILD && logger.log('[Profiling] No chunk data found, no-op.'); + return; + } + if (this._chunkData?.timer) { global.clearTimeout(this._chunkData.timer); this._chunkData.timer = undefined; DEBUG_BUILD && logger.log(`[Profiling] Stopping profiling chunk: ${this._chunkData.id}`); } + if (!this._client) { DEBUG_BUILD && logger.log('[Profiling] Failed to collect profile, sentry client was never attached to the profiler.'); + this._resetChunkData(); return; } + if (!this._chunkData?.id) { DEBUG_BUILD && logger.log(`[Profiling] Failed to collect profile for: ${this._chunkData?.id}, the chunk_id is missing.`); + this._resetChunkData(); return; } const profile = CpuProfilerBindings.stopProfiling(this._chunkData.id, ProfileFormat.CHUNK); if (!profile) { - DEBUG_BUILD && logger.log(`[Profiling] _chunkiledStartTraceID to collect profile for: ${this._chunkData.id}`); + DEBUG_BUILD && logger.log(`[Profiling] Failed to collect profile for: ${this._chunkData.id}`); + this._resetChunkData(); return; } + if (!this._profilerId) { DEBUG_BUILD && logger.log('[Profiling] Profile chunk does not contain a valid profiler_id, this is a bug in the SDK'); + this._resetChunkData(); return; } if (profile) { @@ -327,6 +527,11 @@ class ContinuousProfiler { * @param chunk */ private _startChunkProfiling(): void { + if (this._chunkData) { + DEBUG_BUILD && logger.log('[Profiling] Chunk is already running, no-op.'); + return; + } + const traceId = getCurrentScope().getPropagationContext().traceId || getIsolationScope().getPropagationContext().traceId; const chunk = this._initializeChunk(traceId); @@ -336,9 +541,9 @@ class ContinuousProfiler { chunk.timer = global.setTimeout(() => { DEBUG_BUILD && logger.log(`[Profiling] Stopping profiling chunk: ${chunk.id}`); - this._chunkStop(); + this._stopChunkProfiling(); DEBUG_BUILD && logger.log('[Profiling] Starting new profiling chunk.'); - setImmediate(this._chunkStart.bind(this)); + setImmediate(this._restartChunkProfiling.bind(this)); }, CHUNK_INTERVAL_MS); // Unref timeout so it doesn't keep the process alive. @@ -444,36 +649,31 @@ export const _nodeProfilingIntegration = ((): ProfilingIntegration = _profiler: new ContinuousProfiler(), setup(client: NodeClient) { DEBUG_BUILD && logger.log('[Profiling] Profiling integration setup.'); - const options = client.getOptions(); - - const mode = - (options.profilesSampleRate === undefined || - options.profilesSampleRate === null || - options.profilesSampleRate === 0) && - !options.profilesSampler - ? 'continuous' - : 'span'; - switch (mode) { - case 'continuous': { - DEBUG_BUILD && logger.log('[Profiling] Continuous profiler mode enabled.'); - this._profiler.initialize(client); - break; - } - // Default to span profiling when no mode profiler mode is set - case 'span': - case undefined: { - DEBUG_BUILD && logger.log('[Profiling] Span profiler mode enabled.'); - setupAutomatedSpanProfiling(client); - break; - } - default: { - DEBUG_BUILD && logger.warn(`[Profiling] Unknown profiler mode: ${mode}, profiler was not initialized`); - } - } + this._profiler.initialize(client); + return; }, }; }) satisfies IntegrationFn; +/** + * Determines the profiling mode based on the options. + * @param options + * @returns 'legacy' if the options are using the legacy profiling API, 'current' if the options are using the current profiling API + */ +function getProfilingMode(options: NodeOptions): 'legacy' | 'current' { + // Legacy mode takes precedence over current mode + if ('profilesSampleRate' in options || 'profilesSampler' in options) { + return 'legacy'; + } + + if ('profileSessionSampleRate' in options || 'profileLifecycle' in options) { + return 'current'; + } + + // If neither are set, we are in the legacy continuous profiling mode + return 'legacy'; +} + /** * We need this integration in order to send data to Sentry. We hook into the event processor * and inspect each event to see if it is a transaction event and if that transaction event diff --git a/packages/profiling-node/src/spanProfileUtils.ts b/packages/profiling-node/src/spanProfileUtils.ts index 9ff20816895c..4bd28f8e9531 100644 --- a/packages/profiling-node/src/spanProfileUtils.ts +++ b/packages/profiling-node/src/spanProfileUtils.ts @@ -1,3 +1,4 @@ +/* eslint-disable deprecation/deprecation */ import { CpuProfilerBindings, type RawThreadCpuProfile } from '@sentry-internal/node-cpu-profiler'; import type { CustomSamplingContext, Span } from '@sentry/core'; import { logger, spanIsSampled, spanToJSON, uuid4 } from '@sentry/core'; diff --git a/packages/profiling-node/test/integration.test.ts b/packages/profiling-node/test/integration.test.ts index 392e02ed7704..99142651312e 100644 --- a/packages/profiling-node/test/integration.test.ts +++ b/packages/profiling-node/test/integration.test.ts @@ -1,76 +1,1068 @@ -import { EventEmitter } from 'events'; +import * as Sentry from '@sentry/node'; +import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest'; -import type { Transport } from '@sentry/core'; - -import type { NodeClient } from '@sentry/node'; -import { afterEach, describe, expect, it, vi } from 'vitest'; +import { CpuProfilerBindings } from '@sentry-internal/node-cpu-profiler'; +import { getMainCarrier } from '@sentry/core'; +import { GLOBAL_OBJ, createEnvelope, logger } from '@sentry/core'; +import type { ProfilingIntegration } from '@sentry/core'; +import type { ProfileChunk, Transport } from '@sentry/core'; +import type { NodeClientOptions } from '@sentry/node/build/types/types'; import { _nodeProfilingIntegration } from '../src/integration'; -describe('ProfilingIntegration', () => { - afterEach(() => { - vi.clearAllMocks(); +function makeLegacySpanProfilingClient(): [Sentry.NodeClient, Transport] { + const integration = _nodeProfilingIntegration(); + const client = new Sentry.NodeClient({ + stackParser: Sentry.defaultStackParser, + tracesSampleRate: 1, + profilesSampleRate: 1, + debug: true, + environment: 'test-environment', + dsn: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302', + integrations: [integration], + transport: _opts => + Sentry.makeNodeTransport({ + url: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302', + recordDroppedEvent: () => { + return undefined; + }, + }), }); - it('has a name', () => { - expect(_nodeProfilingIntegration().name).toBe('ProfilingIntegration'); + + return [client, client.getTransport() as Transport]; +} + +function makeLegacyContinuousProfilingClient(): [Sentry.NodeClient, Transport] { + const integration = _nodeProfilingIntegration(); + const client = new Sentry.NodeClient({ + stackParser: Sentry.defaultStackParser, + tracesSampleRate: 1, + debug: true, + environment: 'test-environment', + dsn: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302', + integrations: [integration], + transport: _opts => + Sentry.makeNodeTransport({ + url: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302', + recordDroppedEvent: () => { + return undefined; + }, + }), }); - it('does not call transporter if null profile is received', () => { - const transport: Transport = { - send: vi.fn().mockImplementation(() => Promise.resolve()), - flush: vi.fn().mockImplementation(() => Promise.resolve()), - }; - const integration = _nodeProfilingIntegration(); - const emitter = new EventEmitter(); + return [client, client.getTransport() as Transport]; +} + +function makeCurrentSpanProfilingClient(options: Partial = {}): [Sentry.NodeClient, Transport] { + const integration = _nodeProfilingIntegration(); + const client = new Sentry.NodeClient({ + stackParser: Sentry.defaultStackParser, + tracesSampleRate: 1, + debug: true, + environment: 'test-environment', + dsn: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302', + integrations: [integration], + transport: _opts => + Sentry.makeNodeTransport({ + url: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302', + recordDroppedEvent: () => { + return undefined; + }, + }), + ...options, + }); + + return [client, client.getTransport() as Transport]; +} + +function getProfilerId(): string { + return ( + Sentry.getClient()?.getIntegrationByName>('ProfilingIntegration') as any + )?._profiler?._profilerId; +} + +function makeClientOptions( + options: Omit, +): NodeClientOptions { + return { + stackParser: Sentry.defaultStackParser, + integrations: [_nodeProfilingIntegration()], + debug: true, + transport: _opts => + Sentry.makeNodeTransport({ + url: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302', + recordDroppedEvent: () => { + return undefined; + }, + }), + ...options, + }; +} + +const wait = (ms: number) => new Promise(resolve => setTimeout(resolve, ms)); + +describe('ProfilingIntegration', () => { + describe('legacy automated span instrumentation', () => { + beforeEach(() => { + vi.useRealTimers(); + // We will mock the carrier as if it has been initialized by the SDK, else everything is short circuited + getMainCarrier().__SENTRY__ = {}; + GLOBAL_OBJ._sentryDebugIds = undefined as any; + }); + afterEach(() => { + vi.clearAllMocks(); + vi.restoreAllMocks(); + delete getMainCarrier().__SENTRY__; + }); + + it('pulls environment from sdk init', async () => { + const [client, transport] = makeLegacySpanProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); - const client = { - on: emitter.on.bind(emitter), - emit: emitter.emit.bind(emitter), - getOptions: () => { + const transportSpy = vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); + + const transaction = Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); + await wait(500); + transaction.end(); + + await Sentry.flush(1000); + expect(transportSpy.mock.calls?.[0]?.[0]?.[1]?.[0]?.[1]).toMatchObject({ environment: 'test-environment' }); + }); + + it('logger warns user if there are insufficient samples and discards the profile', async () => { + const logSpy = vi.spyOn(logger, 'log'); + + const [client, transport] = makeLegacySpanProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + // @ts-expect-error we just mock the return type and ignore the signature + vi.spyOn(CpuProfilerBindings, 'stopProfiling').mockImplementation(() => { return { - _metadata: {}, + samples: [ + { + stack_id: 0, + thread_id: '0', + elapsed_since_start_ns: '10', + }, + ], + measurements: {}, + stacks: [[0]], + frames: [], + resources: [], + profiler_logging_mode: 'lazy', }; - }, - getDsn: () => { - return {}; - }, - getTransport: () => transport, - } as unknown as NodeClient; + }); + + vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); + + const transaction = Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); + transaction.end(); + + await Sentry.flush(1000); + + expect(logSpy).toHaveBeenCalledWith('[Profiling] Discarding profile because it contains less than 2 samples'); + + expect((transport.send as any).mock.calls[0][0][1][0][0]?.type).toBe('transaction'); + // eslint-disable-next-line @typescript-eslint/unbound-method + expect(transport.send).toHaveBeenCalledTimes(1); + }); + + it('logger warns user if traceId is invalid', async () => { + const logSpy = vi.spyOn(logger, 'log'); + + const [client, transport] = makeLegacySpanProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + // @ts-expect-error we just mock the return type and ignore the signature + vi.spyOn(CpuProfilerBindings, 'stopProfiling').mockImplementation(() => { + return { + samples: [ + { + stack_id: 0, + thread_id: '0', + elapsed_since_start_ns: '10', + }, + { + stack_id: 0, + thread_id: '0', + elapsed_since_start_ns: '10', + }, + ], + measurements: {}, + resources: [], + stacks: [[0]], + frames: [], + profiler_logging_mode: 'lazy', + }; + }); + + vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); + + Sentry.getCurrentScope().getPropagationContext().traceId = 'boop'; + const transaction = Sentry.startInactiveSpan({ + forceTransaction: true, + name: 'profile_hub', + }); + await wait(500); + transaction.end(); + + await Sentry.flush(1000); + + expect(logSpy).toHaveBeenCalledWith('[Profiling] Invalid traceId: ' + 'boop' + ' on profiled event'); + }); + + it('calls profiler when transaction is started/stopped', async () => { + const [client, transport] = makeLegacySpanProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); + + vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); + + const transaction = Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); + await wait(500); + transaction.end(); + + await Sentry.flush(1000); + + expect(startProfilingSpy).toHaveBeenCalledTimes(1); + expect((stopProfilingSpy.mock.calls[stopProfilingSpy.mock.calls.length - 1]?.[0] as string).length).toBe(32); + }); + + it('sends profile in the same envelope as transaction', async () => { + const [client, transport] = makeLegacySpanProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + const transportSpy = vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); + + const transaction = Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); + await wait(500); + transaction.end(); + + await Sentry.flush(1000); + + // One for profile, the other for transaction + expect(transportSpy).toHaveBeenCalledTimes(1); + expect(transportSpy.mock.calls?.[0]?.[0]?.[1]?.[1]?.[0]).toMatchObject({ type: 'profile' }); + }); + + it('does not crash if transaction has no profile context or it is invalid', async () => { + const [client] = makeLegacySpanProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + // @ts-expect-error transaction is partial + client.emit('beforeEnvelope', createEnvelope({ type: 'transaction' }, { type: 'transaction' })); + // @ts-expect-error transaction is partial + client.emit('beforeEnvelope', createEnvelope({ type: 'transaction' }, { type: 'transaction', contexts: {} })); + client.emit( + 'beforeEnvelope', + // @ts-expect-error transaction is partial + createEnvelope({ type: 'transaction' }, { type: 'transaction', contexts: { profile: {} } }), + ); + client.emit( + 'beforeEnvelope', + // @ts-expect-error transaction is partial + createEnvelope({ type: 'transaction' }, { type: 'transaction', contexts: { profile: { profile_id: null } } }), + ); + + // Emit is sync, so we can just assert that we got here + expect(true).toBe(true); + }); + + it('if transaction was profiled, but profiler returned null', async () => { + const [client, transport] = makeLegacySpanProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + vi.spyOn(CpuProfilerBindings, 'stopProfiling').mockReturnValue(null); + // Emit is sync, so we can just assert that we got here + const transportSpy = vi.spyOn(transport, 'send').mockImplementation(() => { + // Do nothing so we don't send events to Sentry + return Promise.resolve({}); + }); + + const transaction = Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); + await wait(500); + transaction.end(); + + await Sentry.flush(1000); + + // Only transaction is sent + expect(transportSpy.mock.calls?.[0]?.[0]?.[1]?.[0]?.[0]).toMatchObject({ type: 'transaction' }); + expect(transportSpy.mock.calls?.[0]?.[0]?.[1][1]).toBeUndefined(); + }); + + it('emits preprocessEvent for profile', async () => { + const [client] = makeLegacySpanProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + const onPreprocessEvent = vi.fn(); - integration?.setup?.(client); + client.on('preprocessEvent', onPreprocessEvent); - // eslint-disable-next-line @typescript-eslint/unbound-method - expect(transport.send).not.toHaveBeenCalled(); + const transaction = Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); + await wait(500); + transaction.end(); + + await Sentry.flush(1000); + + expect(onPreprocessEvent.mock.calls[1]?.[0]).toMatchObject({ + profile: { + samples: expect.arrayContaining([expect.anything()]), + stacks: expect.arrayContaining([expect.anything()]), + }, + }); + }); + + it('automated span instrumentation does not support continuous profiling', () => { + const [client] = makeLegacySpanProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + const integration = client.getIntegrationByName>('ProfilingIntegration'); + if (!integration) { + throw new Error('Profiling integration not found'); + } + + Sentry.profiler.startProfiler(); + expect(startProfilingSpy).not.toHaveBeenCalled(); + }); + }); + + it('does not crash if stop is called multiple times', async () => { + const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); + + const [client] = makeLegacySpanProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + const transaction = Sentry.startInactiveSpan({ forceTransaction: true, name: 'txn' }); + transaction.end(); + transaction.end(); + expect(stopProfilingSpy).toHaveBeenCalledTimes(1); }); - it('binds to spanStart, spanEnd and beforeEnvelope', () => { - const transport: Transport = { - send: vi.fn().mockImplementation(() => Promise.resolve()), - flush: vi.fn().mockImplementation(() => Promise.resolve()), + it('enriches profile with debug_id', async () => { + GLOBAL_OBJ._sentryDebugIds = { + 'Error\n at filename.js (filename.js:36:15)': 'aaaaaaaa-aaaa-4aaa-aaaa-aaaaaaaaaa', + 'Error\n at filename2.js (filename2.js:36:15)': 'bbbbbbbb-bbbb-4bbb-bbbb-bbbbbbbbbb', + 'Error\n at filename3.js (filename3.js:36:15)': 'bbbbbbbb-bbbb-4bbb-bbbb-bbbbbbbbbb', }; - const integration = _nodeProfilingIntegration(); - const client = { - on: vi.fn(), - emit: vi.fn(), - getOptions: () => { + // @ts-expect-error we just mock the return type and ignore the signature + vi.spyOn(CpuProfilerBindings, 'stopProfiling').mockImplementation(() => { + return { + samples: [ + { + stack_id: 0, + thread_id: '0', + elapsed_since_start_ns: '10', + }, + { + stack_id: 0, + thread_id: '0', + elapsed_since_start_ns: '10', + }, + ], + measurements: {}, + resources: ['filename.js', 'filename2.js'], + stacks: [[0]], + frames: [], + profiler_logging_mode: 'lazy', + }; + }); + + const [client, transport] = makeLegacySpanProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + const transportSpy = vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); + + const transaction = Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); + await wait(500); + transaction.end(); + + await Sentry.flush(1000); + + expect(transportSpy.mock.calls?.[0]?.[0]?.[1]?.[1]?.[1]).toMatchObject({ + debug_meta: { + images: [ + { + type: 'sourcemap', + debug_id: 'aaaaaaaa-aaaa-4aaa-aaaa-aaaaaaaaaa', + code_file: 'filename.js', + }, + { + type: 'sourcemap', + debug_id: 'bbbbbbbb-bbbb-4bbb-bbbb-bbbbbbbbbb', + code_file: 'filename2.js', + }, + ], + }, + }); + }); + + describe('legacy continuous profiling', () => { + beforeEach(() => { + vi.useFakeTimers(); + // We will mock the carrier as if it has been initialized by the SDK, else everything is short circuited + getMainCarrier().__SENTRY__ = {}; + GLOBAL_OBJ._sentryDebugIds = undefined as any; + }); + afterEach(() => { + const client = Sentry.getClient(); + const integration = client?.getIntegrationByName>('ProfilingIntegration'); + + if (integration) { + Sentry.profiler.stopProfiler(); + } + + vi.clearAllMocks(); + vi.restoreAllMocks(); + vi.runAllTimers(); + delete getMainCarrier().__SENTRY__; + }); + + it('attaches sdk metadata to chunks', () => { + // @ts-expect-error we just mock the return type and ignore the signature + vi.spyOn(CpuProfilerBindings, 'stopProfiling').mockImplementation(() => { return { - _metadata: {}, - profilesSampleRate: 1, + samples: [ + { + stack_id: 0, + thread_id: '0', + elapsed_since_start_ns: '10', + }, + { + stack_id: 0, + thread_id: '0', + elapsed_since_start_ns: '10', + }, + ], + measurements: {}, + stacks: [[0]], + frames: [], + resources: [], + profiler_logging_mode: 'lazy', }; - }, - getDsn: () => { - return {}; - }, - getTransport: () => transport, - } as unknown as NodeClient; + }); + + const [client, transport] = makeLegacyContinuousProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + const transportSpy = vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); + Sentry.profiler.startProfiler(); + vi.advanceTimersByTime(1000); + Sentry.profiler.stopProfiler(); + vi.advanceTimersByTime(1000); + + const profile = transportSpy.mock.calls?.[0]?.[0]?.[1]?.[0]?.[1] as ProfileChunk; + expect(profile.client_sdk.name).toBe('sentry.javascript.node'); + expect(profile.client_sdk.version).toEqual(expect.stringMatching(/\d+\.\d+\.\d+/)); + }); + + it('initializes the continuous profiler', () => { + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + + const [client] = makeLegacyContinuousProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + expect(startProfilingSpy).not.toHaveBeenCalledTimes(1); + Sentry.profiler.startProfiler(); + + const integration = client.getIntegrationByName>('ProfilingIntegration'); + expect(integration?._profiler).toBeDefined(); + }); + + it('starts a continuous profile', () => { + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + + const [client] = makeLegacyContinuousProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + expect(startProfilingSpy).not.toHaveBeenCalledTimes(1); + Sentry.profiler.startProfiler(); + expect(startProfilingSpy).toHaveBeenCalledTimes(1); + }); + + it('multiple calls to start abort previous profile', () => { + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); + + const [client] = makeLegacyContinuousProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + expect(startProfilingSpy).not.toHaveBeenCalledTimes(1); + Sentry.profiler.startProfiler(); + Sentry.profiler.startProfiler(); + + expect(startProfilingSpy).toHaveBeenCalledTimes(2); + expect(stopProfilingSpy).toHaveBeenCalledTimes(1); + }); + + it('restarts a new chunk after previous', async () => { + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); + + const [client] = makeLegacyContinuousProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + expect(startProfilingSpy).not.toHaveBeenCalledTimes(1); + Sentry.profiler.startProfiler(); + + vi.advanceTimersByTime(60_001); + expect(stopProfilingSpy).toHaveBeenCalledTimes(1); + expect(startProfilingSpy).toHaveBeenCalledTimes(2); + }); + + it('chunks share the same profilerId', async () => { + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); + + const [client] = makeLegacyContinuousProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + expect(startProfilingSpy).not.toHaveBeenCalledTimes(1); + Sentry.profiler.startProfiler(); + const profilerId = getProfilerId(); + + vi.advanceTimersByTime(60_001); + expect(stopProfilingSpy).toHaveBeenCalledTimes(1); + expect(startProfilingSpy).toHaveBeenCalledTimes(2); + expect(getProfilerId()).toBe(profilerId); + }); + + it('explicit calls to stop clear profilerId', async () => { + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + + const [client] = makeLegacyContinuousProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + expect(startProfilingSpy).not.toHaveBeenCalledTimes(1); + Sentry.profiler.startProfiler(); + const profilerId = getProfilerId(); + Sentry.profiler.stopProfiler(); + Sentry.profiler.startProfiler(); + + expect(getProfilerId()).toEqual(expect.any(String)); + expect(getProfilerId()).not.toBe(profilerId); + }); + + it('stops a continuous profile after interval', async () => { + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); + + const [client] = makeLegacyContinuousProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + expect(startProfilingSpy).not.toHaveBeenCalledTimes(1); + Sentry.profiler.startProfiler(); + + vi.advanceTimersByTime(60_001); + expect(stopProfilingSpy).toHaveBeenCalledTimes(1); + }); + + it('manually stopping a chunk doesnt restart the profiler', async () => { + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); + + const [client] = makeLegacyContinuousProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + expect(startProfilingSpy).not.toHaveBeenCalledTimes(1); + Sentry.profiler.startProfiler(); + + vi.advanceTimersByTime(1000); + + Sentry.profiler.stopProfiler(); + expect(stopProfilingSpy).toHaveBeenCalledTimes(1); + + vi.advanceTimersByTime(1000); + expect(startProfilingSpy).toHaveBeenCalledTimes(1); + }); + + it('continuous mode does not instrument spans', () => { + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + + const [client] = makeLegacyContinuousProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); + expect(startProfilingSpy).not.toHaveBeenCalled(); + }); + + it('sends as profile_chunk envelope type', async () => { + // @ts-expect-error we just mock the return type and ignore the signature + vi.spyOn(CpuProfilerBindings, 'stopProfiling').mockImplementation(() => { + return { + samples: [ + { + stack_id: 0, + thread_id: '0', + elapsed_since_start_ns: '10', + }, + { + stack_id: 0, + thread_id: '0', + elapsed_since_start_ns: '10', + }, + ], + measurements: {}, + stacks: [[0]], + frames: [], + resources: [], + profiler_logging_mode: 'lazy', + }; + }); + + const [client, transport] = makeLegacyContinuousProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + const transportSpy = vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); + Sentry.profiler.startProfiler(); + vi.advanceTimersByTime(1000); + Sentry.profiler.stopProfiler(); + vi.advanceTimersByTime(1000); + + expect(transportSpy.mock.calls?.[0]?.[0]?.[1]?.[0]?.[0]?.type).toBe('profile_chunk'); + }); + + it('sets global profile context', async () => { + const [client, transport] = makeLegacyContinuousProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + const transportSpy = vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); + + const nonProfiledTransaction = Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); + nonProfiledTransaction.end(); + + expect(transportSpy.mock.calls?.[0]?.[0]?.[1]?.[0]?.[1]).not.toMatchObject({ + contexts: { + profile: {}, + }, + }); + + const integration = client.getIntegrationByName>('ProfilingIntegration'); + if (!integration) { + throw new Error('Profiling integration not found'); + } + + integration._profiler.start(); + const profiledTransaction = Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); + profiledTransaction.end(); + Sentry.profiler.stopProfiler(); + + expect(transportSpy.mock.calls?.[1]?.[0]?.[1]?.[0]?.[1]).toMatchObject({ + contexts: { + trace: { + data: expect.objectContaining({ + ['thread.id']: expect.any(String), + ['thread.name']: expect.any(String), + }), + }, + profile: { + profiler_id: expect.any(String), + }, + }, + }); + }); + + it.each([['no option is set', makeClientOptions({})]])('%s', async (_label, options) => { + const client = new Sentry.NodeClient({ + ...options, + dsn: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302', + tracesSampleRate: 1, + transport: _opts => + Sentry.makeNodeTransport({ + url: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302', + recordDroppedEvent: () => { + return undefined; + }, + }), + integrations: [_nodeProfilingIntegration()], + }); + + Sentry.setCurrentClient(client); + client.init(); + + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + const transport = client.getTransport(); + + if (!transport) { + throw new Error('Transport not found'); + } + + vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); + Sentry.profiler.startProfiler(); + const callCount = startProfilingSpy.mock.calls.length; + expect(startProfilingSpy).toHaveBeenCalled(); + + Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); + expect(startProfilingSpy).toHaveBeenCalledTimes(callCount); + }); + }); + + describe('current manual continuous profiling', () => { + it('start and stops a profile session', () => { + const [client] = makeCurrentSpanProfilingClient({ + profileLifecycle: 'manual', + profileSessionSampleRate: 1, + }); + Sentry.setCurrentClient(client); + client.init(); + + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); + + Sentry.profiler.startProfiler(); + Sentry.profiler.stopProfiler(); + + expect(startProfilingSpy).toHaveBeenCalled(); + expect(stopProfilingSpy).toHaveBeenCalled(); + }); + + it('calling start and stop while profile session is running does nothing', () => { + const [client] = makeCurrentSpanProfilingClient({ + profileLifecycle: 'manual', + profileSessionSampleRate: 1, + }); + Sentry.setCurrentClient(client); + client.init(); + + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); + + Sentry.profiler.startProfiler(); + Sentry.profiler.startProfiler(); + + expect(startProfilingSpy).toHaveBeenCalledTimes(1); + + Sentry.profiler.stopProfiler(); + Sentry.profiler.stopProfiler(); + + expect(stopProfilingSpy).toHaveBeenCalledTimes(1); + }); + + it('profileSessionSamplingRate is required', () => { + const [client] = makeCurrentSpanProfilingClient({ + profileLifecycle: 'manual', + }); + Sentry.setCurrentClient(client); + client.init(); + + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); + + Sentry.profiler.startProfiler(); + Sentry.profiler.stopProfiler(); + + expect(startProfilingSpy).not.toHaveBeenCalled(); + expect(stopProfilingSpy).not.toHaveBeenCalled(); + }); + + it('profileSessionSamplingRate is respected', () => { + const [client] = makeCurrentSpanProfilingClient({ + profileSessionSampleRate: 0, + profileLifecycle: 'manual', + }); + Sentry.setCurrentClient(client); + client.init(); + + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); + + Sentry.profiler.startProfiler(); + Sentry.profiler.stopProfiler(); + + expect(startProfilingSpy).not.toHaveBeenCalled(); + expect(stopProfilingSpy).not.toHaveBeenCalled(); + }); + + describe('envelope', () => { + beforeEach(() => { + vi.useRealTimers(); + }); + + it('sends a profile_chunk envelope type', async () => { + const [client, transport] = makeCurrentSpanProfilingClient({ + profileLifecycle: 'manual', + profileSessionSampleRate: 1, + }); + + Sentry.setCurrentClient(client); + client.init(); + + const transportSpy = vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); + + Sentry.profiler.startProfiler(); + await wait(1000); + Sentry.profiler.stopProfiler(); + + await Sentry.flush(1000); + + expect(transportSpy.mock.calls?.[0]?.[0]?.[1]?.[0]?.[0]).toMatchObject({ + type: 'profile_chunk', + }); + + expect(transportSpy.mock.calls?.[0]?.[0]?.[1]?.[0]?.[1]).toMatchObject({ + profiler_id: expect.any(String), + chunk_id: expect.any(String), + profile: expect.objectContaining({ + stacks: expect.any(Array), + }), + }); + }); + }); + }); + + describe('trace profile lifecycle', () => { + it('trace profile lifecycle ignores manual calls to start and stop', () => { + const [client] = makeCurrentSpanProfilingClient({ + profileLifecycle: 'trace', + }); + + Sentry.setCurrentClient(client); + client.init(); + + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); + + Sentry.profiler.startProfiler(); + Sentry.profiler.stopProfiler(); + + expect(startProfilingSpy).not.toHaveBeenCalled(); + expect(stopProfilingSpy).not.toHaveBeenCalled(); + }); + + it('starts profiler when first span is created', () => { + const [client] = makeCurrentSpanProfilingClient({ + profileLifecycle: 'trace', + }); + + Sentry.setCurrentClient(client); + client.init(); + + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); + + const span = Sentry.startInactiveSpan({ forceTransaction: true, name: 'test' }); + + expect(startProfilingSpy).toHaveBeenCalled(); + expect(stopProfilingSpy).not.toHaveBeenCalled(); + + span.end(); + expect(stopProfilingSpy).toHaveBeenCalled(); + }); + + it('waits for the tail span to end before stopping the profiler', () => { + const [client] = makeCurrentSpanProfilingClient({ + profileLifecycle: 'trace', + }); + + Sentry.setCurrentClient(client); + client.init(); + + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); + + const first = Sentry.startInactiveSpan({ forceTransaction: true, name: 'test' }); + const second = Sentry.startInactiveSpan({ forceTransaction: true, name: 'child' }); + + expect(startProfilingSpy).toHaveBeenCalled(); + expect(stopProfilingSpy).not.toHaveBeenCalled(); + + first.end(); + expect(stopProfilingSpy).not.toHaveBeenCalled(); + + second.end(); + expect(stopProfilingSpy).toHaveBeenCalled(); + }); + + it('ending last span does not stop the profiler if first span is not ended', () => { + const [client] = makeCurrentSpanProfilingClient({ + profileLifecycle: 'trace', + }); + + Sentry.setCurrentClient(client); + client.init(); + + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); + + const first = Sentry.startInactiveSpan({ forceTransaction: true, name: 'test' }); + const second = Sentry.startInactiveSpan({ forceTransaction: true, name: 'child' }); + + expect(startProfilingSpy).toHaveBeenCalled(); + + second.end(); + expect(stopProfilingSpy).not.toHaveBeenCalled(); + + first.end(); + expect(stopProfilingSpy).toHaveBeenCalled(); + }); + it('multiple calls to span.end do not restart the profiler', () => { + const [client] = makeCurrentSpanProfilingClient({ + profileLifecycle: 'trace', + }); + + Sentry.setCurrentClient(client); + client.init(); + + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); + + const first = Sentry.startInactiveSpan({ forceTransaction: true, name: 'test' }); + const second = Sentry.startInactiveSpan({ forceTransaction: true, name: 'child' }); + + expect(startProfilingSpy).toHaveBeenCalled(); + + first.end(); + first.end(); + expect(stopProfilingSpy).not.toHaveBeenCalled(); + + second.end(); + expect(stopProfilingSpy).toHaveBeenCalled(); + }); + + describe('envelope', () => { + beforeEach(() => { + vi.useRealTimers(); + }); + + it('sends a profile_chunk envelope type', async () => { + const [client, transport] = makeCurrentSpanProfilingClient({ + profileLifecycle: 'trace', + profileSessionSampleRate: 1, + }); + + Sentry.setCurrentClient(client); + client.init(); + + const transportSpy = vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); + + const span = Sentry.startInactiveSpan({ forceTransaction: true, name: 'test' }); + await wait(1000); + span.end(); + + await Sentry.flush(1000); + + expect(transportSpy.mock.calls?.[1]?.[0]?.[1]?.[0]?.[0]).toMatchObject({ + type: 'transaction', + }); + expect(transportSpy.mock.calls?.[0]?.[0]?.[1]?.[0]?.[0]).toMatchObject({ + type: 'profile_chunk', + }); + + expect(transportSpy.mock.calls?.[0]?.[0]?.[1]?.[0]?.[1]).toMatchObject({ + profiler_id: expect.any(String), + chunk_id: expect.any(String), + profile: expect.objectContaining({ + stacks: expect.any(Array), + }), + }); + }); + }); + }); +}); + +describe('Legacy vs Current API compat', () => { + describe('legacy', () => { + describe('span profiling', () => { + it('profiler.start, profiler.stop, profiler.startProfiler, profiler.stopProfiler void in automated span profiling mode', () => { + const [client] = makeLegacySpanProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); + + // Profiler calls void + Sentry.profiler.startProfiler(); + Sentry.profiler.stopProfiler(); + + expect(startProfilingSpy).not.toHaveBeenCalled(); + expect(stopProfilingSpy).not.toHaveBeenCalled(); + + // Only starting and stopping the profiler is supported in legacy mode + const span = Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); + span.end(); + + expect(startProfilingSpy).toHaveBeenCalled(); + expect(stopProfilingSpy).toHaveBeenCalled(); + }); + }); + + describe('continuous profiling', () => { + it('profiler.start and profiler.stop start and stop the profiler, calls to profiler.startProfiler and profiler.stopProfiler are ignored', () => { + const [client] = makeLegacyContinuousProfilingClient(); + Sentry.setCurrentClient(client); + client.init(); + + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); + + // Creating a span will not invoke the profiler + const span = Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); + span.end(); + + expect(startProfilingSpy).not.toHaveBeenCalled(); + expect(stopProfilingSpy).not.toHaveBeenCalled(); + + Sentry.profiler.startProfiler(); + Sentry.profiler.stopProfiler(); + + expect(startProfilingSpy).toHaveBeenCalled(); + expect(stopProfilingSpy).toHaveBeenCalled(); + }); + }); + }); + + describe('current', () => { + describe('span profiling', () => { + it('profiler.start, profiler.stop, profiler.startProfiler, profiler.stopProfiler void in automated span profiling mode', () => { + const [client] = makeCurrentSpanProfilingClient({ + profileLifecycle: 'trace', + }); + Sentry.setCurrentClient(client); + client.init(); + + const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); + const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); + + // Legacy mode is not supported under the new API + Sentry.profiler.startProfiler(); + Sentry.profiler.stopProfiler(); - const spy = vi.spyOn(client, 'on'); + expect(startProfilingSpy).not.toHaveBeenCalled(); + expect(stopProfilingSpy).not.toHaveBeenCalled(); - integration?.setup?.(client); + // This API is not supported in trace mode + Sentry.profiler.startProfiler(); + Sentry.profiler.stopProfiler(); - expect(spy).toHaveBeenCalledTimes(3); - expect(spy).toHaveBeenCalledWith('spanStart', expect.any(Function)); - expect(spy).toHaveBeenCalledWith('spanEnd', expect.any(Function)); - expect(spy).toHaveBeenCalledWith('beforeEnvelope', expect.any(Function)); + expect(startProfilingSpy).not.toHaveBeenCalled(); + expect(stopProfilingSpy).not.toHaveBeenCalled(); + }); + }); }); }); diff --git a/packages/profiling-node/test/spanProfileUtils.worker.test.ts b/packages/profiling-node/test/integration.worker.test.ts similarity index 98% rename from packages/profiling-node/test/spanProfileUtils.worker.test.ts rename to packages/profiling-node/test/integration.worker.test.ts index 95b1a7bfad3f..6ce62f018c01 100644 --- a/packages/profiling-node/test/spanProfileUtils.worker.test.ts +++ b/packages/profiling-node/test/integration.worker.test.ts @@ -18,7 +18,6 @@ function makeContinuousProfilingClient(): [Sentry.NodeClient, Transport] { const client = new Sentry.NodeClient({ stackParser: Sentry.defaultStackParser, tracesSampleRate: 1, - profilesSampleRate: undefined, debug: true, environment: 'test-environment', dsn: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302', diff --git a/packages/profiling-node/test/spanProfileUtils.test.ts b/packages/profiling-node/test/spanProfileUtils.test.ts deleted file mode 100644 index 5aae42783c86..000000000000 --- a/packages/profiling-node/test/spanProfileUtils.test.ts +++ /dev/null @@ -1,790 +0,0 @@ -import * as Sentry from '@sentry/node'; -import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest'; - -import { CpuProfilerBindings } from '@sentry-internal/node-cpu-profiler'; -import { getMainCarrier } from '@sentry/core'; -import { GLOBAL_OBJ, createEnvelope, logger } from '@sentry/core'; -import type { ProfilingIntegration } from '@sentry/core'; -import type { ProfileChunk, Transport } from '@sentry/core'; -import type { NodeClientOptions } from '@sentry/node/build/types/types'; -import { _nodeProfilingIntegration } from '../src/integration'; - -function makeClientWithHooks(): [Sentry.NodeClient, Transport] { - const integration = _nodeProfilingIntegration(); - const client = new Sentry.NodeClient({ - stackParser: Sentry.defaultStackParser, - tracesSampleRate: 1, - profilesSampleRate: 1, - debug: true, - environment: 'test-environment', - dsn: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302', - integrations: [integration], - transport: _opts => - Sentry.makeNodeTransport({ - url: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302', - recordDroppedEvent: () => { - return undefined; - }, - }), - }); - - return [client, client.getTransport() as Transport]; -} - -function makeContinuousProfilingClient(): [Sentry.NodeClient, Transport] { - const integration = _nodeProfilingIntegration(); - const client = new Sentry.NodeClient({ - stackParser: Sentry.defaultStackParser, - tracesSampleRate: 1, - profilesSampleRate: undefined, - debug: true, - environment: 'test-environment', - dsn: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302', - integrations: [integration], - transport: _opts => - Sentry.makeNodeTransport({ - url: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302', - recordDroppedEvent: () => { - return undefined; - }, - }), - }); - - return [client, client.getTransport() as Transport]; -} - -function getProfilerId(): string { - return ( - Sentry.getClient()?.getIntegrationByName>('ProfilingIntegration') as any - )?._profiler?._profilerId; -} - -function makeClientOptions( - options: Omit, -): NodeClientOptions { - return { - stackParser: Sentry.defaultStackParser, - integrations: [_nodeProfilingIntegration()], - debug: true, - transport: _opts => - Sentry.makeNodeTransport({ - url: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302', - recordDroppedEvent: () => { - return undefined; - }, - }), - ...options, - }; -} - -const wait = (ms: number) => new Promise(resolve => setTimeout(resolve, ms)); - -describe('automated span instrumentation', () => { - beforeEach(() => { - vi.useRealTimers(); - // We will mock the carrier as if it has been initialized by the SDK, else everything is short circuited - getMainCarrier().__SENTRY__ = {}; - GLOBAL_OBJ._sentryDebugIds = undefined as any; - }); - afterEach(() => { - vi.clearAllMocks(); - vi.restoreAllMocks(); - delete getMainCarrier().__SENTRY__; - }); - - it('pulls environment from sdk init', async () => { - const [client, transport] = makeClientWithHooks(); - Sentry.setCurrentClient(client); - client.init(); - - const transportSpy = vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); - - const transaction = Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); - await wait(500); - transaction.end(); - - await Sentry.flush(1000); - expect(transportSpy.mock.calls?.[0]?.[0]?.[1]?.[0]?.[1]).toMatchObject({ environment: 'test-environment' }); - }); - - it('logger warns user if there are insufficient samples and discards the profile', async () => { - const logSpy = vi.spyOn(logger, 'log'); - - const [client, transport] = makeClientWithHooks(); - Sentry.setCurrentClient(client); - client.init(); - - // @ts-expect-error we just mock the return type and ignore the signature - vi.spyOn(CpuProfilerBindings, 'stopProfiling').mockImplementation(() => { - return { - samples: [ - { - stack_id: 0, - thread_id: '0', - elapsed_since_start_ns: '10', - }, - ], - measurements: {}, - stacks: [[0]], - frames: [], - resources: [], - profiler_logging_mode: 'lazy', - }; - }); - - vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); - - const transaction = Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); - transaction.end(); - - await Sentry.flush(1000); - - expect(logSpy).toHaveBeenCalledWith('[Profiling] Discarding profile because it contains less than 2 samples'); - - expect((transport.send as any).mock.calls[0][0][1][0][0]?.type).toBe('transaction'); - // eslint-disable-next-line @typescript-eslint/unbound-method - expect(transport.send).toHaveBeenCalledTimes(1); - }); - - it('logger warns user if traceId is invalid', async () => { - const logSpy = vi.spyOn(logger, 'log'); - - const [client, transport] = makeClientWithHooks(); - Sentry.setCurrentClient(client); - client.init(); - - // @ts-expect-error we just mock the return type and ignore the signature - vi.spyOn(CpuProfilerBindings, 'stopProfiling').mockImplementation(() => { - return { - samples: [ - { - stack_id: 0, - thread_id: '0', - elapsed_since_start_ns: '10', - }, - { - stack_id: 0, - thread_id: '0', - elapsed_since_start_ns: '10', - }, - ], - measurements: {}, - resources: [], - stacks: [[0]], - frames: [], - profiler_logging_mode: 'lazy', - }; - }); - - vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); - - Sentry.getCurrentScope().getPropagationContext().traceId = 'boop'; - const transaction = Sentry.startInactiveSpan({ - forceTransaction: true, - name: 'profile_hub', - }); - await wait(500); - transaction.end(); - - await Sentry.flush(1000); - - expect(logSpy).toHaveBeenCalledWith('[Profiling] Invalid traceId: ' + 'boop' + ' on profiled event'); - }); - - describe('with hooks', () => { - it('calls profiler when transaction is started/stopped', async () => { - const [client, transport] = makeClientWithHooks(); - Sentry.setCurrentClient(client); - client.init(); - - const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); - const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); - - vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); - - const transaction = Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); - await wait(500); - transaction.end(); - - await Sentry.flush(1000); - - expect(startProfilingSpy).toHaveBeenCalledTimes(1); - expect((stopProfilingSpy.mock.calls[stopProfilingSpy.mock.calls.length - 1]?.[0] as string).length).toBe(32); - }); - - it('sends profile in the same envelope as transaction', async () => { - const [client, transport] = makeClientWithHooks(); - Sentry.setCurrentClient(client); - client.init(); - - const transportSpy = vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); - - const transaction = Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); - await wait(500); - transaction.end(); - - await Sentry.flush(1000); - - // One for profile, the other for transaction - expect(transportSpy).toHaveBeenCalledTimes(1); - expect(transportSpy.mock.calls?.[0]?.[0]?.[1]?.[1]?.[0]).toMatchObject({ type: 'profile' }); - }); - - it('does not crash if transaction has no profile context or it is invalid', async () => { - const [client] = makeClientWithHooks(); - Sentry.setCurrentClient(client); - client.init(); - - // @ts-expect-error transaction is partial - client.emit('beforeEnvelope', createEnvelope({ type: 'transaction' }, { type: 'transaction' })); - // @ts-expect-error transaction is partial - client.emit('beforeEnvelope', createEnvelope({ type: 'transaction' }, { type: 'transaction', contexts: {} })); - client.emit( - 'beforeEnvelope', - // @ts-expect-error transaction is partial - createEnvelope({ type: 'transaction' }, { type: 'transaction', contexts: { profile: {} } }), - ); - client.emit( - 'beforeEnvelope', - // @ts-expect-error transaction is partial - createEnvelope({ type: 'transaction' }, { type: 'transaction', contexts: { profile: { profile_id: null } } }), - ); - - // Emit is sync, so we can just assert that we got here - expect(true).toBe(true); - }); - - it('if transaction was profiled, but profiler returned null', async () => { - const [client, transport] = makeClientWithHooks(); - Sentry.setCurrentClient(client); - client.init(); - - vi.spyOn(CpuProfilerBindings, 'stopProfiling').mockReturnValue(null); - // Emit is sync, so we can just assert that we got here - const transportSpy = vi.spyOn(transport, 'send').mockImplementation(() => { - // Do nothing so we don't send events to Sentry - return Promise.resolve({}); - }); - - const transaction = Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); - await wait(500); - transaction.end(); - - await Sentry.flush(1000); - - // Only transaction is sent - expect(transportSpy.mock.calls?.[0]?.[0]?.[1]?.[0]?.[0]).toMatchObject({ type: 'transaction' }); - expect(transportSpy.mock.calls?.[0]?.[0]?.[1][1]).toBeUndefined(); - }); - - it('emits preprocessEvent for profile', async () => { - const [client] = makeClientWithHooks(); - Sentry.setCurrentClient(client); - client.init(); - - const onPreprocessEvent = vi.fn(); - - client.on('preprocessEvent', onPreprocessEvent); - - const transaction = Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); - await wait(500); - transaction.end(); - - await Sentry.flush(1000); - - expect(onPreprocessEvent.mock.calls[1]?.[0]).toMatchObject({ - profile: { - samples: expect.arrayContaining([expect.anything()]), - stacks: expect.arrayContaining([expect.anything()]), - }, - }); - }); - - it('automated span instrumentation does not support continuous profiling', () => { - const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); - - const [client] = makeClientWithHooks(); - Sentry.setCurrentClient(client); - client.init(); - - const integration = client.getIntegrationByName>('ProfilingIntegration'); - if (!integration) { - throw new Error('Profiling integration not found'); - } - integration._profiler.start(); - expect(startProfilingSpy).not.toHaveBeenCalled(); - }); - }); - - it('does not crash if stop is called multiple times', async () => { - const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); - - const [client] = makeClientWithHooks(); - Sentry.setCurrentClient(client); - client.init(); - - const transaction = Sentry.startInactiveSpan({ forceTransaction: true, name: 'txn' }); - transaction.end(); - transaction.end(); - expect(stopProfilingSpy).toHaveBeenCalledTimes(1); - }); - it('enriches profile with debug_id', async () => { - GLOBAL_OBJ._sentryDebugIds = { - 'Error\n at filename.js (filename.js:36:15)': 'aaaaaaaa-aaaa-4aaa-aaaa-aaaaaaaaaa', - 'Error\n at filename2.js (filename2.js:36:15)': 'bbbbbbbb-bbbb-4bbb-bbbb-bbbbbbbbbb', - 'Error\n at filename3.js (filename3.js:36:15)': 'bbbbbbbb-bbbb-4bbb-bbbb-bbbbbbbbbb', - }; - - // @ts-expect-error we just mock the return type and ignore the signature - vi.spyOn(CpuProfilerBindings, 'stopProfiling').mockImplementation(() => { - return { - samples: [ - { - stack_id: 0, - thread_id: '0', - elapsed_since_start_ns: '10', - }, - { - stack_id: 0, - thread_id: '0', - elapsed_since_start_ns: '10', - }, - ], - measurements: {}, - resources: ['filename.js', 'filename2.js'], - stacks: [[0]], - frames: [], - profiler_logging_mode: 'lazy', - }; - }); - - const [client, transport] = makeClientWithHooks(); - Sentry.setCurrentClient(client); - client.init(); - - const transportSpy = vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); - - const transaction = Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); - await wait(500); - transaction.end(); - - await Sentry.flush(1000); - - expect(transportSpy.mock.calls?.[0]?.[0]?.[1]?.[1]?.[1]).toMatchObject({ - debug_meta: { - images: [ - { - type: 'sourcemap', - debug_id: 'aaaaaaaa-aaaa-4aaa-aaaa-aaaaaaaaaa', - code_file: 'filename.js', - }, - { - type: 'sourcemap', - debug_id: 'bbbbbbbb-bbbb-4bbb-bbbb-bbbbbbbbbb', - code_file: 'filename2.js', - }, - ], - }, - }); - }); -}); - -describe('continuous profiling', () => { - beforeEach(() => { - vi.useFakeTimers(); - // We will mock the carrier as if it has been initialized by the SDK, else everything is short circuited - getMainCarrier().__SENTRY__ = {}; - GLOBAL_OBJ._sentryDebugIds = undefined as any; - }); - afterEach(() => { - const client = Sentry.getClient(); - const integration = client?.getIntegrationByName>('ProfilingIntegration'); - - if (integration) { - Sentry.profiler.stopProfiler(); - } - - vi.clearAllMocks(); - vi.restoreAllMocks(); - vi.runAllTimers(); - delete getMainCarrier().__SENTRY__; - }); - - it('attaches sdk metadata to chunks', () => { - // @ts-expect-error we just mock the return type and ignore the signature - vi.spyOn(CpuProfilerBindings, 'stopProfiling').mockImplementation(() => { - return { - samples: [ - { - stack_id: 0, - thread_id: '0', - elapsed_since_start_ns: '10', - }, - { - stack_id: 0, - thread_id: '0', - elapsed_since_start_ns: '10', - }, - ], - measurements: {}, - stacks: [[0]], - frames: [], - resources: [], - profiler_logging_mode: 'lazy', - }; - }); - - const [client, transport] = makeContinuousProfilingClient(); - Sentry.setCurrentClient(client); - client.init(); - - const transportSpy = vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); - Sentry.profiler.startProfiler(); - vi.advanceTimersByTime(1000); - Sentry.profiler.stopProfiler(); - vi.advanceTimersByTime(1000); - - const profile = transportSpy.mock.calls?.[0]?.[0]?.[1]?.[0]?.[1] as ProfileChunk; - expect(profile.client_sdk.name).toBe('sentry.javascript.node'); - expect(profile.client_sdk.version).toEqual(expect.stringMatching(/\d+\.\d+\.\d+/)); - }); - - it('initializes the continuous profiler', () => { - const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); - - const [client] = makeContinuousProfilingClient(); - Sentry.setCurrentClient(client); - client.init(); - - expect(startProfilingSpy).not.toHaveBeenCalledTimes(1); - Sentry.profiler.startProfiler(); - - const integration = client.getIntegrationByName>('ProfilingIntegration'); - expect(integration?._profiler).toBeDefined(); - }); - - it('starts a continuous profile', () => { - const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); - - const [client] = makeContinuousProfilingClient(); - Sentry.setCurrentClient(client); - client.init(); - - expect(startProfilingSpy).not.toHaveBeenCalledTimes(1); - Sentry.profiler.startProfiler(); - expect(startProfilingSpy).toHaveBeenCalledTimes(1); - }); - - it('multiple calls to start abort previous profile', () => { - const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); - const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); - - const [client] = makeContinuousProfilingClient(); - Sentry.setCurrentClient(client); - client.init(); - - expect(startProfilingSpy).not.toHaveBeenCalledTimes(1); - Sentry.profiler.startProfiler(); - Sentry.profiler.startProfiler(); - - expect(startProfilingSpy).toHaveBeenCalledTimes(2); - expect(stopProfilingSpy).toHaveBeenCalledTimes(1); - }); - - it('restarts a new chunk after previous', async () => { - const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); - const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); - - const [client] = makeContinuousProfilingClient(); - Sentry.setCurrentClient(client); - client.init(); - - expect(startProfilingSpy).not.toHaveBeenCalledTimes(1); - Sentry.profiler.startProfiler(); - - vi.advanceTimersByTime(60_001); - expect(stopProfilingSpy).toHaveBeenCalledTimes(1); - expect(startProfilingSpy).toHaveBeenCalledTimes(2); - }); - - it('chunks share the same profilerId', async () => { - const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); - const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); - - const [client] = makeContinuousProfilingClient(); - Sentry.setCurrentClient(client); - client.init(); - - expect(startProfilingSpy).not.toHaveBeenCalledTimes(1); - Sentry.profiler.startProfiler(); - const profilerId = getProfilerId(); - - vi.advanceTimersByTime(60_001); - expect(stopProfilingSpy).toHaveBeenCalledTimes(1); - expect(startProfilingSpy).toHaveBeenCalledTimes(2); - expect(getProfilerId()).toBe(profilerId); - }); - - it('explicit calls to stop clear profilerId', async () => { - const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); - - const [client] = makeContinuousProfilingClient(); - Sentry.setCurrentClient(client); - client.init(); - - expect(startProfilingSpy).not.toHaveBeenCalledTimes(1); - Sentry.profiler.startProfiler(); - const profilerId = getProfilerId(); - Sentry.profiler.stopProfiler(); - Sentry.profiler.startProfiler(); - - expect(getProfilerId()).toEqual(expect.any(String)); - expect(getProfilerId()).not.toBe(profilerId); - }); - - it('stops a continuous profile after interval', async () => { - const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); - const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); - - const [client] = makeContinuousProfilingClient(); - Sentry.setCurrentClient(client); - client.init(); - - expect(startProfilingSpy).not.toHaveBeenCalledTimes(1); - Sentry.profiler.startProfiler(); - - vi.advanceTimersByTime(60_001); - expect(stopProfilingSpy).toHaveBeenCalledTimes(1); - }); - - it('manually stopping a chunk doesnt restart the profiler', async () => { - const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); - const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); - - const [client] = makeContinuousProfilingClient(); - Sentry.setCurrentClient(client); - client.init(); - - expect(startProfilingSpy).not.toHaveBeenCalledTimes(1); - Sentry.profiler.startProfiler(); - - vi.advanceTimersByTime(1000); - - Sentry.profiler.stopProfiler(); - expect(stopProfilingSpy).toHaveBeenCalledTimes(1); - - vi.advanceTimersByTime(1000); - expect(startProfilingSpy).toHaveBeenCalledTimes(1); - }); - - it('continuous mode does not instrument spans', () => { - const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); - - const [client] = makeContinuousProfilingClient(); - Sentry.setCurrentClient(client); - client.init(); - - Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); - expect(startProfilingSpy).not.toHaveBeenCalled(); - }); - - it('sends as profile_chunk envelope type', async () => { - // @ts-expect-error we just mock the return type and ignore the signature - vi.spyOn(CpuProfilerBindings, 'stopProfiling').mockImplementation(() => { - return { - samples: [ - { - stack_id: 0, - thread_id: '0', - elapsed_since_start_ns: '10', - }, - { - stack_id: 0, - thread_id: '0', - elapsed_since_start_ns: '10', - }, - ], - measurements: {}, - stacks: [[0]], - frames: [], - resources: [], - profiler_logging_mode: 'lazy', - }; - }); - - const [client, transport] = makeContinuousProfilingClient(); - Sentry.setCurrentClient(client); - client.init(); - - const transportSpy = vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); - Sentry.profiler.startProfiler(); - vi.advanceTimersByTime(1000); - Sentry.profiler.stopProfiler(); - vi.advanceTimersByTime(1000); - - expect(transportSpy.mock.calls?.[0]?.[0]?.[1]?.[0]?.[0]?.type).toBe('profile_chunk'); - }); - - it('sets global profile context', async () => { - const [client, transport] = makeContinuousProfilingClient(); - Sentry.setCurrentClient(client); - client.init(); - - const transportSpy = vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); - - const nonProfiledTransaction = Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); - nonProfiledTransaction.end(); - - expect(transportSpy.mock.calls?.[0]?.[0]?.[1]?.[0]?.[1]).not.toMatchObject({ - contexts: { - profile: {}, - }, - }); - - const integration = client.getIntegrationByName>('ProfilingIntegration'); - if (!integration) { - throw new Error('Profiling integration not found'); - } - - integration._profiler.start(); - const profiledTransaction = Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); - profiledTransaction.end(); - Sentry.profiler.stopProfiler(); - - expect(transportSpy.mock.calls?.[1]?.[0]?.[1]?.[0]?.[1]).toMatchObject({ - contexts: { - trace: { - data: expect.objectContaining({ - ['thread.id']: expect.any(String), - ['thread.name']: expect.any(String), - }), - }, - profile: { - profiler_id: expect.any(String), - }, - }, - }); - }); -}); - -describe('continuous profiling does not start in span profiling mode', () => { - it.each([ - ['profilesSampleRate=1', makeClientOptions({ profilesSampleRate: 1 })], - ['profilesSampler is defined', makeClientOptions({ profilesSampler: () => 1 })], - ])('%s', async (_label, options) => { - const logSpy = vi.spyOn(logger, 'log'); - const client = new Sentry.NodeClient({ - ...options, - dsn: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302', - tracesSampleRate: 1, - transport: _opts => - Sentry.makeNodeTransport({ - url: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302', - recordDroppedEvent: () => { - return undefined; - }, - }), - integrations: [_nodeProfilingIntegration()], - }); - - Sentry.setCurrentClient(client); - client.init(); - - const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); - const transport = client.getTransport(); - - if (!transport) { - throw new Error('Transport not found'); - } - - vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); - Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); - - expect(startProfilingSpy).toHaveBeenCalled(); - const integration = client.getIntegrationByName>('ProfilingIntegration'); - - if (!integration) { - throw new Error('Profiling integration not found'); - } - - integration._profiler.start(); - expect(logSpy).toHaveBeenLastCalledWith( - '[Profiling] Failed to start, sentry client was never attached to the profiler.', - ); - }); -}); -describe('continuous profiling mode', () => { - beforeEach(() => { - vi.clearAllMocks(); - }); - - it.each([ - ['profilesSampleRate=0', makeClientOptions({ profilesSampleRate: 0 })], - ['profilesSampleRate=undefined', makeClientOptions({ profilesSampleRate: undefined })], - // @ts-expect-error test invalid value - ['profilesSampleRate=null', makeClientOptions({ profilesSampleRate: null })], - [ - 'profilesSampler is not defined and profilesSampleRate is not set', - makeClientOptions({ profilesSampler: undefined, profilesSampleRate: 0 }), - ], - ])('%s', async (_label, options) => { - const client = new Sentry.NodeClient({ - ...options, - dsn: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302', - tracesSampleRate: 1, - transport: _opts => - Sentry.makeNodeTransport({ - url: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302', - recordDroppedEvent: () => { - return undefined; - }, - }), - integrations: [_nodeProfilingIntegration()], - }); - - Sentry.setCurrentClient(client); - client.init(); - - const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); - const transport = client.getTransport(); - - if (!transport) { - throw new Error('Transport not found'); - } - - vi.spyOn(transport, 'send').mockReturnValue(Promise.resolve({})); - Sentry.profiler.startProfiler(); - const callCount = startProfilingSpy.mock.calls.length; - expect(startProfilingSpy).toHaveBeenCalled(); - - Sentry.startInactiveSpan({ forceTransaction: true, name: 'profile_hub' }); - expect(startProfilingSpy).toHaveBeenCalledTimes(callCount); - }); - - it('top level methods proxy to integration', () => { - const client = new Sentry.NodeClient({ - ...makeClientOptions({ profilesSampleRate: undefined }), - dsn: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302', - tracesSampleRate: 1, - transport: _opts => - Sentry.makeNodeTransport({ - url: 'https://7fa19397baaf433f919fbe02228d5470@o1137848.ingest.sentry.io/6625302', - recordDroppedEvent: () => { - return undefined; - }, - }), - integrations: [_nodeProfilingIntegration()], - }); - - Sentry.setCurrentClient(client); - client.init(); - - const startProfilingSpy = vi.spyOn(CpuProfilerBindings, 'startProfiling'); - const stopProfilingSpy = vi.spyOn(CpuProfilerBindings, 'stopProfiling'); - - Sentry.profiler.startProfiler(); - expect(startProfilingSpy).toHaveBeenCalledTimes(1); - Sentry.profiler.stopProfiler(); - expect(stopProfilingSpy).toHaveBeenCalledTimes(1); - }); -});