diff --git a/dev-packages/browser-integration-tests/suites/profiling/manualMode/subject.js b/dev-packages/browser-integration-tests/suites/profiling/manualMode/subject.js new file mode 100644 index 000000000000..35855580cc3a --- /dev/null +++ b/dev-packages/browser-integration-tests/suites/profiling/manualMode/subject.js @@ -0,0 +1,80 @@ +import * as Sentry from '@sentry/browser'; +import { browserProfilingIntegration } from '@sentry/browser'; + +window.Sentry = Sentry; + +Sentry.init({ + dsn: 'https://public@dsn.ingest.sentry.io/1337', + integrations: [browserProfilingIntegration()], + tracesSampleRate: 1, + profileSessionSampleRate: 1, + profileLifecycle: 'manual', +}); + +function largeSum(amount = 1000000) { + let sum = 0; + for (let i = 0; i < amount; i++) { + sum += Math.sqrt(i) * Math.sin(i); + } +} + +function fibonacci(n) { + if (n <= 1) { + return n; + } + return fibonacci(n - 1) + fibonacci(n - 2); +} + +function fibonacci1(n) { + if (n <= 1) { + return n; + } + return fibonacci1(n - 1) + fibonacci1(n - 2); +} + +function fibonacci2(n) { + if (n <= 1) { + return n; + } + return fibonacci1(n - 1) + fibonacci1(n - 2); +} + +function notProfiledFib(n) { + if (n <= 1) { + return n; + } + return fibonacci1(n - 1) + fibonacci1(n - 2); +} + +// Adding setTimeout to ensure we cross the sampling interval to avoid flakes + +// --- + +Sentry.profiler.startProfiler(); + +fibonacci(40); +await new Promise(resolve => setTimeout(resolve, 25)); + +largeSum(); +await new Promise(resolve => setTimeout(resolve, 25)); + +Sentry.profiler.stopProfiler(); + +// --- + +notProfiledFib(40); +await new Promise(resolve => setTimeout(resolve, 25)); + +// --- + +Sentry.profiler.startProfiler(); + +fibonacci2(40); +await new Promise(resolve => setTimeout(resolve, 25)); + +Sentry.profiler.stopProfiler(); + +// --- + +const client = Sentry.getClient(); +await client?.flush(8000); diff --git a/dev-packages/browser-integration-tests/suites/profiling/manualMode/test.ts b/dev-packages/browser-integration-tests/suites/profiling/manualMode/test.ts new file mode 100644 index 000000000000..79093089e57e --- /dev/null +++ b/dev-packages/browser-integration-tests/suites/profiling/manualMode/test.ts @@ -0,0 +1,89 @@ +import { expect } from '@playwright/test'; +import type { ProfileChunkEnvelope } from '@sentry/core'; +import { sentryTest } from '../../../utils/fixtures'; +import { + countEnvelopes, + getMultipleSentryEnvelopeRequests, + properFullEnvelopeRequestParser, + shouldSkipTracingTest, +} from '../../../utils/helpers'; +import { validateProfile, validateProfilePayloadMetadata } from '../test-utils'; + +sentryTest( + 'does not send profile envelope when document-policy is not set', + async ({ page, getLocalTestUrl, browserName }) => { + if (shouldSkipTracingTest() || browserName !== 'chromium') { + // Profiling only works when tracing is enabled + sentryTest.skip(); + } + + const url = await getLocalTestUrl({ testDir: __dirname }); + + // Assert that no profile_chunk envelope is sent without policy header + const chunkCount = await countEnvelopes(page, { url, envelopeType: 'profile_chunk', timeout: 1500 }); + expect(chunkCount).toBe(0); + }, +); + +sentryTest('sends profile_chunk envelopes in manual mode', async ({ page, getLocalTestUrl, browserName }) => { + if (shouldSkipTracingTest() || browserName !== 'chromium') { + // Profiling only works when tracing is enabled + sentryTest.skip(); + } + + const url = await getLocalTestUrl({ testDir: __dirname, responseHeaders: { 'Document-Policy': 'js-profiling' } }); + + // In manual mode we start and stop once -> expect exactly one chunk + const profileChunkEnvelopes = await getMultipleSentryEnvelopeRequests( + page, + 2, + { url, envelopeType: 'profile_chunk', timeout: 8000 }, + properFullEnvelopeRequestParser, + ); + + expect(profileChunkEnvelopes.length).toBe(2); + + // Validate the first chunk thoroughly + const profileChunkEnvelopeItem = profileChunkEnvelopes[0][1][0]; + const envelopeItemHeader = profileChunkEnvelopeItem[0]; + const envelopeItemPayload1 = profileChunkEnvelopeItem[1]; + + expect(envelopeItemHeader).toHaveProperty('type', 'profile_chunk'); + expect(envelopeItemPayload1.profile).toBeDefined(); + + validateProfilePayloadMetadata(envelopeItemPayload1); + + validateProfile(envelopeItemPayload1.profile, { + expectedFunctionNames: ['startJSSelfProfile', 'fibonacci', 'largeSum'], + minSampleDurationMs: 20, + isChunkFormat: true, + }); + + // only contains fibonacci + const functionNames1 = envelopeItemPayload1.profile.frames.map(frame => frame.function).filter(name => name !== ''); + expect(functionNames1).toEqual(expect.not.arrayContaining(['fibonacci1', 'fibonacci2', 'fibonacci3'])); + + // === PROFILE CHUNK 2 === + + const profileChunkEnvelopeItem2 = profileChunkEnvelopes[1][1][0]; + const envelopeItemHeader2 = profileChunkEnvelopeItem2[0]; + const envelopeItemPayload2 = profileChunkEnvelopeItem2[1]; + + expect(envelopeItemHeader2).toHaveProperty('type', 'profile_chunk'); + expect(envelopeItemPayload2.profile).toBeDefined(); + + validateProfilePayloadMetadata(envelopeItemPayload2); + + validateProfile(envelopeItemPayload2.profile, { + expectedFunctionNames: [ + 'startJSSelfProfile', + 'fibonacci1', // called by fibonacci2 + 'fibonacci2', + ], + isChunkFormat: true, + }); + + // does not contain fibonacci3 (called during unprofiled part) + const functionNames2 = envelopeItemPayload1.profile.frames.map(frame => frame.function).filter(name => name !== ''); + expect(functionNames2).toEqual(expect.not.arrayContaining(['fibonacci3'])); +}); diff --git a/dev-packages/browser-integration-tests/suites/profiling/test-utils.ts b/dev-packages/browser-integration-tests/suites/profiling/test-utils.ts index e150be2d56bc..39e6d2ca20b7 100644 --- a/dev-packages/browser-integration-tests/suites/profiling/test-utils.ts +++ b/dev-packages/browser-integration-tests/suites/profiling/test-utils.ts @@ -90,7 +90,7 @@ export function validateProfile( } } - // Frames + // FRAMES expect(profile.frames.length).toBeGreaterThan(0); for (const frame of profile.frames) { expect(frame).toHaveProperty('function'); diff --git a/packages/browser/src/profiling/UIProfiler.ts b/packages/browser/src/profiling/UIProfiler.ts index fb7cd022ac7f..35cb0dbe7585 100644 --- a/packages/browser/src/profiling/UIProfiler.ts +++ b/packages/browser/src/profiling/UIProfiler.ts @@ -15,13 +15,13 @@ import { createProfileChunkPayload, startJSSelfProfile, validateProfileChunk } f const CHUNK_INTERVAL_MS = 60_000; // 1 minute // Maximum length for trace lifecycle profiling per root span (e.g. if spanEnd never fires) -const MAX_ROOT_SPAN_PROFILE_MS = 300_000; // 5 minutes +const MAX_ROOT_SPAN_PROFILE_MS = 300_000; // 5 minutes max per root span in trace mode /** - * Browser trace-lifecycle profiler (UI Profiling / Profiling V2): - * - Starts when the first sampled root span starts - * - Stops when the last sampled root span ends - * - While running, periodically stops and restarts the JS self-profiling API to collect chunks + * UIProfiler (Profiling V2): + * Supports two lifecycle modes: + * - 'manual': controlled explicitly via start()/stop() + * - 'trace': automatically runs while there are active sampled root spans * * Profiles are emitted as standalone `profile_chunk` envelopes either when: * - there are no more sampled root spans, or @@ -31,114 +31,87 @@ export class UIProfiler { private _client: Client | undefined; private _profiler: JSSelfProfiler | undefined; private _chunkTimer: ReturnType | undefined; - // For keeping track of active root spans + + // Manual + Trace + private _profilerId: string | undefined; // one per Profiler session + private _isRunning: boolean; // current profiler instance active flag + private _sessionSampled: boolean; // sampling decision for entire session + private _lifecycleMode: 'manual' | 'trace' | undefined; + + // Trace-only private _activeRootSpanIds: Set; private _rootSpanTimeouts: Map>; - // ID for Profiler session - private _profilerId: string | undefined; - private _isRunning: boolean; - private _sessionSampled: boolean; public constructor() { this._client = undefined; this._profiler = undefined; this._chunkTimer = undefined; - this._activeRootSpanIds = new Set(); - this._rootSpanTimeouts = new Map>(); + this._profilerId = undefined; this._isRunning = false; this._sessionSampled = false; + this._lifecycleMode = undefined; + + this._activeRootSpanIds = new Set(); + this._rootSpanTimeouts = new Map(); } - /** - * Initialize the profiler with client and session sampling decision computed by the integration. - */ - public initialize(client: Client, sessionSampled: boolean): void { + /** Initialize the profiler with client, session sampling and lifecycle mode. */ + public initialize(client: Client, sessionSampled: boolean, lifecycleMode: 'manual' | 'trace'): void { // One Profiler ID per profiling session (user session) this._profilerId = uuid4(); - DEBUG_BUILD && debug.log("[Profiling] Initializing profiler (lifecycle='trace')."); + DEBUG_BUILD && debug.log(`[Profiling] Initializing profiler (lifecycle='${lifecycleMode}').`); this._client = client; this._sessionSampled = sessionSampled; + this._lifecycleMode = lifecycleMode; - client.on('spanStart', span => { - if (!this._sessionSampled) { - DEBUG_BUILD && debug.log('[Profiling] Session not sampled because of negative sampling decision.'); - return; - } - if (span !== getRootSpan(span)) { - return; - } - // Only count sampled root spans - if (!span.isRecording()) { - DEBUG_BUILD && debug.log('[Profiling] Discarding profile because root span was not sampled.'); - return; - } - - // Matching root spans with profiles - getGlobalScope().setContext('profile', { - profiler_id: this._profilerId, - }); - - const spanId = span.spanContext().spanId; - if (!spanId) { - return; - } - if (this._activeRootSpanIds.has(spanId)) { - return; - } - - this._activeRootSpanIds.add(spanId); - const rootSpanCount = this._activeRootSpanIds.size; - - const timeout = setTimeout(() => { - this._onRootSpanTimeout(spanId); - }, MAX_ROOT_SPAN_PROFILE_MS); - this._rootSpanTimeouts.set(spanId, timeout); - - if (rootSpanCount === 1) { - DEBUG_BUILD && - debug.log( - `[Profiling] Root span with ID ${spanId} started. Will continue profiling for as long as there are active root spans (currently: ${rootSpanCount}).`, - ); + if (lifecycleMode === 'trace') { + this._setupTraceLifecycleListeners(client); + } + } - this.start(); - } - }); + /** Start profiling manually (only effective in 'manual' mode and when sampled). */ + public start(): void { + if (this._lifecycleMode === 'trace') { + DEBUG_BUILD && + debug.log('[Profiling] `profileLifecycle` is set to "trace"; manual start() calls are ignored in trace mode.'); + return; + } - client.on('spanEnd', span => { - if (!this._sessionSampled) { - return; - } + if (this._isRunning) { + DEBUG_BUILD && debug.log('[Profiling] Profile session already running, no-op.'); + return; + } - const spanId = span.spanContext().spanId; - if (!spanId || !this._activeRootSpanIds.has(spanId)) { - return; - } + if (!this._sessionSampled) { + DEBUG_BUILD && debug.log('[Profiling] Session not sampled, start() is a no-op.'); + return; + } - this._activeRootSpanIds.delete(spanId); - const rootSpanCount = this._activeRootSpanIds.size; + this._beginProfiling(); + } + /** Stop profiling manually (only effective in 'manual' mode). */ + public stop(): void { + if (this._lifecycleMode === 'trace') { DEBUG_BUILD && - debug.log( - `[Profiling] Root span with ID ${spanId} ended. Will continue profiling for as long as there are active root spans (currently: ${rootSpanCount}).`, - ); - if (rootSpanCount === 0) { - this._collectCurrentChunk().catch(e => { - DEBUG_BUILD && debug.error('[Profiling] Failed to collect current profile chunk on `spanEnd`:', e); - }); + debug.log('[Profiling] `profileLifecycle` is set to "trace"; manual stop() calls are ignored in trace mode.'); + return; + } - this.stop(); - } - }); + if (!this._isRunning) { + DEBUG_BUILD && debug.log('[Profiling] No profile session running, stop() is a no-op.'); + return; + } + + this._endProfiling(); } - /** - * Handle an already-active root span at integration setup time. - */ + /** Handle an already-active root span at integration setup time (used only in trace mode). */ public notifyRootSpanActive(rootSpan: Span): void { - if (!this._sessionSampled) { + if (this._lifecycleMode !== 'trace' || !this._sessionSampled) { return; } @@ -155,25 +128,26 @@ export class UIProfiler { DEBUG_BUILD && debug.log('[Profiling] Detected already active root span during setup. Active root spans now:', rootSpanCount); - this.start(); + this._beginProfiling(); } } - /** - * Start profiling if not already running. - */ - public start(): void { + /** Begin profiling if not already running. */ + private _beginProfiling(): void { if (this._isRunning) { return; } this._isRunning = true; - DEBUG_BUILD && debug.log('[Profiling] Started profiling with profile ID:', this._profilerId); + DEBUG_BUILD && debug.log('[Profiling] Started profiling with profiler ID:', this._profilerId); + + // Expose profiler_id to match root spans with profiles + getGlobalScope().setContext('profile', { profiler_id: this._profilerId }); this._startProfilerInstance(); if (!this._profiler) { - DEBUG_BUILD && debug.log('[Profiling] Stopping trace lifecycle profiling.'); + DEBUG_BUILD && debug.log('[Profiling] Failed to start JS Profiler; stopping.'); this._resetProfilerInfo(); return; } @@ -181,15 +155,13 @@ export class UIProfiler { this._startPeriodicChunking(); } - /** - * Stop profiling; final chunk will be collected and sent. - */ - public stop(): void { + /** End profiling session; final chunk will be collected and sent. */ + private _endProfiling(): void { if (!this._isRunning) { return; } - this._isRunning = false; + if (this._chunkTimer) { clearTimeout(this._chunkTimer); this._chunkTimer = undefined; @@ -201,34 +173,102 @@ export class UIProfiler { this._collectCurrentChunk().catch(e => { DEBUG_BUILD && debug.error('[Profiling] Failed to collect current profile chunk on `stop()`:', e); }); + + // Clear context so subsequent events aren't marked as profiled in manual mode. + // todo: test in manual mode + if (this._lifecycleMode === 'manual') { + getGlobalScope().setContext('profile', {}); + } } - /** - * Resets profiling information from scope and resets running state - */ + /** Trace-mode: attach spanStart/spanEnd listeners. */ + private _setupTraceLifecycleListeners(client: Client): void { + client.on('spanStart', span => { + if (!this._sessionSampled) { + DEBUG_BUILD && debug.log('[Profiling] Session not sampled because of negative sampling decision.'); + return; + } + if (span !== getRootSpan(span)) { + return; // only care about root spans + } + // Only count sampled root spans + if (!span.isRecording()) { + DEBUG_BUILD && debug.log('[Profiling] Discarding profile because root span was not sampled.'); + return; + } + + // Match emitted chunks with events: set profiler_id on global scope + // todo: do I need this? + // getGlobalScope().setContext('profile', { profiler_id: this._profilerId }); + + const spanId = span.spanContext().spanId; + if (!spanId || this._activeRootSpanIds.has(spanId)) { + return; + } + + this._registerTraceRootSpan(spanId); + + const rootSpanCount = this._activeRootSpanIds.size; + if (rootSpanCount === 1) { + DEBUG_BUILD && + debug.log( + `[Profiling] Root span ${spanId} started. Profiling active while there are active root spans (count=${rootSpanCount}).`, + ); + this._beginProfiling(); + } + }); + + client.on('spanEnd', span => { + if (!this._sessionSampled) { + return; + } + const spanId = span.spanContext().spanId; + if (!spanId || !this._activeRootSpanIds.has(spanId)) { + return; + } + this._activeRootSpanIds.delete(spanId); + const rootSpanCount = this._activeRootSpanIds.size; + + DEBUG_BUILD && + debug.log( + `[Profiling] Root span with ID ${spanId} ended. Will continue profiling for as long as there are active root spans (currently: ${rootSpanCount}).`, + ); + if (rootSpanCount === 0) { + this._collectCurrentChunk().catch(e => { + DEBUG_BUILD && debug.error('[Profiling] Failed to collect current profile chunk on last `spanEnd`:', e); + }); + this._endProfiling(); + } + }); + } + + /** Reset running state and profiling context (used on failure). */ private _resetProfilerInfo(): void { this._isRunning = false; getGlobalScope().setContext('profile', {}); } - /** - * Clear and reset all per-root-span timeouts. - */ + /** Clear and reset all per-root-span timeouts. */ private _clearAllRootSpanTimeouts(): void { this._rootSpanTimeouts.forEach(timeout => clearTimeout(timeout)); this._rootSpanTimeouts.clear(); } - /** - * Start a profiler instance if needed. - */ + /** Register root span and schedule safeguard timeout (trace mode). */ + private _registerTraceRootSpan(spanId: string): void { + this._activeRootSpanIds.add(spanId); + const timeout = setTimeout(() => this._onRootSpanTimeout(spanId), MAX_ROOT_SPAN_PROFILE_MS); + this._rootSpanTimeouts.set(spanId, timeout); + } + + /** Start a profiler instance if needed. */ private _startProfilerInstance(): void { if (this._profiler?.stopped === false) { - return; + return; // already running } const profiler = startJSSelfProfile(); if (!profiler) { - DEBUG_BUILD && debug.log('[Profiling] Failed to start JS Profiler in trace lifecycle.'); + DEBUG_BUILD && debug.log('[Profiling] Failed to start JS Profiler.'); return; } this._profiler = profiler; @@ -285,15 +325,12 @@ export class UIProfiler { this._activeRootSpanIds.delete(rootSpanId); - const rootSpanCount = this._activeRootSpanIds.size; - if (rootSpanCount === 0) { - this.stop(); + if (this._activeRootSpanIds.size === 0) { + this._endProfiling(); } } - /** - * Stop the current profiler, convert and send a profile chunk. - */ + /** Stop current profiler instance, convert profile to chunk & send. */ private async _collectCurrentChunk(): Promise { const prevProfiler = this._profiler; this._profiler = undefined; @@ -327,9 +364,7 @@ export class UIProfiler { } } - /** - * Send a profile chunk as a standalone envelope. - */ + /** Send a profile chunk as a standalone envelope. */ private _sendProfileChunk(chunk: ProfileChunk): void { // eslint-disable-next-line @typescript-eslint/no-non-null-assertion const client = this._client!; diff --git a/packages/browser/src/profiling/integration.ts b/packages/browser/src/profiling/integration.ts index 7cd1886e636d..db870ad7be55 100644 --- a/packages/browser/src/profiling/integration.ts +++ b/packages/browser/src/profiling/integration.ts @@ -66,7 +66,7 @@ const _browserProfilingIntegration = (() => { } const traceLifecycleProfiler = new UIProfiler(); - traceLifecycleProfiler.initialize(client, sessionSampled); + traceLifecycleProfiler.initialize(client, sessionSampled, lifecycleMode); // If there is an active, sampled root span already, notify the profiler if (rootSpan) {