feat(profiling): js self profiling

packages/browser/src/index.ts

@@ -32,3 +32,8 @@ export { Replay } from '@sentry/replay';
 // __ROLLUP_EXCLUDE_OFFLINE_FROM_BUNDLES_BEGIN__
 export { makeBrowserOfflineTransport } from './transports/offline';
 // __ROLLUP_EXCLUDE_OFFLINE_FROM_BUNDLES_END__
+
+// __ROLLUP_EXCLUDE_BROWSER_PROFILING_FROM_BUNDLES_BEGIN__
+export { onProfilingStartRouteTransaction } from './profiling/hubextensions';
+export { BrowserProfilingIntegration } from './profiling/integration';
+// __ROLLUP_EXCLUDE_BROWSER_PROFILING_FROM_BUNDLES_END__

packages/browser/src/profiling/cache.ts

@@ -0,0 +1,72 @@
+import type { Event } from '@sentry/types';
+
+/**
+ * Creates a cache that evicts keys in fifo order
+ * @param size {Number}
+ */
+export function makeProfilingCache<Key extends string, Value extends Event>(
+ size: number,
+): {
+ get: (key: Key) => Value | undefined;
+ add: (key: Key, value: Value) => void;
+ delete: (key: Key) => boolean;
+ clear: () => void;
+ size: () => number;
+} {
+ // Maintain a fifo queue of keys, we cannot rely on Object.keys as the browser may not support it.
+ let evictionOrder: Key[] = [];
+ let cache: Record<string, Value> = {};
+
+ return {
+ add(key: Key, value: Value) {
+ while (evictionOrder.length >= size) {
+ // shift is O(n) but this is small size and only happens if we are
+ // exceeding the cache size so it should be fine.
+ const evictCandidate = evictionOrder.shift();
+
+ if (evictCandidate !== undefined) {
+ // eslint-disable-next-line @typescript-eslint/no-dynamic-delete
+ delete cache[evictCandidate];
+ }
+ }
+
+ // in case we have a collision, delete the old key.
+ if (cache[key]) {
+ this.delete(key);
+ }
+
+ evictionOrder.push(key);
+ cache[key] = value;
+ },
+ clear() {
+ cache = {};
+ evictionOrder = [];
+ },
+ get(key: Key): Value | undefined {
+ return cache[key];
+ },
+ size() {
+ return evictionOrder.length;
+ },
+ // Delete cache key and return true if it existed, false otherwise.
+ delete(key: Key): boolean {
+ if (!cache[key]) {
+ return false;
+ }
+
+ // eslint-disable-next-line @typescript-eslint/no-dynamic-delete
+ delete cache[key];
+
+ for (let i = 0; i < evictionOrder.length; i++) {
+ if (evictionOrder[i] === key) {
+ evictionOrder.splice(i, 1);
+ break;
+ }
+ }
+
+ return true;
+ },
+ };
+}
+
+export const PROFILING_EVENT_CACHE = makeProfilingCache<string, Event>(20);

packages/browser/src/profiling/hubextensions.ts

@@ -0,0 +1,259 @@
+import { getCurrentHub, getMainCarrier } from '@sentry/core';
+import type { CustomSamplingContext, Hub, Transaction, TransactionContext } from '@sentry/types';
+import { logger, uuid4 } from '@sentry/utils';
+
+import { WINDOW } from '../helpers';
+import type { JSSelfProfile, JSSelfProfiler, ProcessedJSSelfProfile } from './jsSelfProfiling';
+import { sendProfile } from './sendProfile';
+
+// Max profile duration.
+const MAX_PROFILE_DURATION_MS = 30_000;
+
+// While we experiment, per transaction sampling interval will be more flexible to work with.
+type StartTransaction = (
+ this: Hub,
+ transactionContext: TransactionContext,
+ customSamplingContext?: CustomSamplingContext,
+) => Transaction | undefined;
+
+/**
+ * Check if profiler constructor is available.
+ * @param maybeProfiler
+ */
+function isJSProfilerSupported(maybeProfiler: unknown): maybeProfiler is typeof JSSelfProfiler {
+ return typeof maybeProfiler === 'function';
+}
+
+/**
+ * Safety wrapper for startTransaction for the unlikely case that transaction starts before tracing is imported -
+ * if that happens we want to avoid throwing an error from profiling code.
+ * see https://github.com/getsentry/sentry-javascript/issues/4731.
+ *
+ * @experimental
+ */
+export function onProfilingStartRouteTransaction(transaction: Transaction | undefined): Transaction | undefined {
+ if (!transaction) {
+ if (__DEBUG_BUILD__) {
+ logger.log('[Profiling] Transaction is undefined, skipping profiling');
+ }
+ return transaction;
+ }
+
+ return wrapTransactionWithProfiling(transaction);
+}
+
+/**
+ * Wraps startTransaction and stopTransaction with profiling related logic.
+ * startProfiling is called after the call to startTransaction in order to avoid our own code from
+ * being profiled. Because of that same reason, stopProfiling is called before the call to stopTransaction.
+ */
+function wrapTransactionWithProfiling(transaction: Transaction): Transaction {
+ // Feature support check first
+ const JSProfiler = WINDOW.Profiler;
+ if (!isJSProfilerSupported(JSProfiler)) {
+ if (__DEBUG_BUILD__) {
+ logger.log(
+ '[Profiling] Profiling is not supported by this browser, Profiler interface missing on window object.',
+ );
+ }
+ return transaction;
+ }
+
+ // profilesSampleRate is multiplied with tracesSampleRate to get the final sampling rate.
+ if (!transaction.sampled) {
+ if (__DEBUG_BUILD__) {
+ logger.log('[Profiling] Transaction is not sampled, skipping profiling');
+ }
+ return transaction;
+ }
+
+ const client = getCurrentHub().getClient();
+ const options = client && client.getOptions();
+
+ // @ts-ignore not part of the browser options yet
+ const profilesSampleRate = (options && options.profilesSampleRate) || 0;
+ if (profilesSampleRate === undefined) {
+ if (__DEBUG_BUILD__) {
+ logger.log('[Profiling] Profiling disabled, enable it by setting `profilesSampleRate` option to SDK init call.');
+ }
+ return transaction;
+ }
+
+ // Check if we should sample this profile
+ if (Math.random() > profilesSampleRate) {
+ if (__DEBUG_BUILD__) {
+ logger.log('[Profiling] Skip profiling transaction due to sampling.');
+ }
+ return transaction;
+ }
+
+ // From initial testing, it seems that the minimum value for sampleInterval is 10ms.
+ const samplingIntervalMS = 10;
+ // Start the profiler
+ const maxSamples = Math.floor(MAX_PROFILE_DURATION_MS / samplingIntervalMS);
+ const profiler = new JSProfiler({ sampleInterval: samplingIntervalMS, maxBufferSize: maxSamples });
+ if (__DEBUG_BUILD__) {
+ logger.log(`[Profiling] started profiling transaction: ${transaction.name || transaction.description}`);
+ }
+
+ // We create "unique" transaction names to avoid concurrent transactions with same names
+ // from being ignored by the profiler. From here on, only this transaction name should be used when
+ // calling the profiler methods. Note: we log the original name to the user to avoid confusion.
+ const profileId = uuid4();
+
+ // A couple of important things to note here:
+ // `CpuProfilerBindings.stopProfiling` will be scheduled to run in 30seconds in order to exceed max profile duration.
+ // Whichever of the two (transaction.finish/timeout) is first to run, the profiling will be stopped and the gathered profile
+ // will be processed when the original transaction is finished. Since onProfileHandler can be invoked multiple times in the
+ // event of an error or user mistake (calling transaction.finish multiple times), it is important that the behavior of onProfileHandler
+ // is idempotent as we do not want any timings or profiles to be overriden by the last call to onProfileHandler.
+ // After the original finish method is called, the event will be reported through the integration and delegated to transport.
+ let processedProfile: ProcessedJSSelfProfile | null = null;
+
+ /**
+ * Idempotent handler for profile stop
+ */
+ function onProfileHandler(): void {
+ // Check if the profile exists and return it the behavior has to be idempotent as users may call transaction.finish multiple times.
+ if (!transaction) {
+ return;
+ }
+ if (processedProfile) {
+ if (__DEBUG_BUILD__) {
+ logger.log(
+ '[Profiling] profile for:',
+ transaction.name || transaction.description,
+ 'already exists, returning early',
+ );
+ }
+ return;
+ }
+
+ profiler
+ .stop()
+ .then((p: JSSelfProfile): void => {
+ if (maxDurationTimeoutID) {
+ WINDOW.clearTimeout(maxDurationTimeoutID);
+ maxDurationTimeoutID = undefined;
+ }
+
+ if (__DEBUG_BUILD__) {
+ logger.log(`[Profiling] stopped profiling of transaction: ${transaction.name || transaction.description}`);
+ }
+
+ // In case of an overlapping transaction, stopProfiling may return null and silently ignore the overlapping profile.
+ if (!p) {
+ if (__DEBUG_BUILD__) {
+ logger.log(
+ `[Profiling] profiler returned null profile for: ${transaction.name || transaction.description}`,
+ 'this may indicate an overlapping transaction or a call to stopProfiling with a profile title that was never started',
+ );
+ }
+ return;
+ }
+
+ // If a profile has less than 2 samples, it is not useful and should be discarded.
+ if (p.samples.length < 2) {
+ return;
+ }
+
+ processedProfile = { ...p, profile_id: profileId };
+ sendProfile(profileId, processedProfile);
+ })
+ .catch(error => {
+ if (__DEBUG_BUILD__) {
+ logger.log('[Profiling] error while stopping profiler:', error);
+ }
+ return null;
+ });
+ }
+
+ // Enqueue a timeout to prevent profiles from running over max duration.
+ let maxDurationTimeoutID: number | undefined = WINDOW.setTimeout(() => {
+ if (__DEBUG_BUILD__) {
+ logger.log(
+ '[Profiling] max profile duration elapsed, stopping profiling for:',
+ transaction.name || transaction.description,
+ );
+ }
+ void onProfileHandler();
+ }, MAX_PROFILE_DURATION_MS);
+
+ // We need to reference the original finish call to avoid creating an infinite loop
+ const originalFinish = transaction.finish.bind(transaction);
+
+ /**
+ * Wraps startTransaction and stopTransaction with profiling related logic.
+ * startProfiling is called after the call to startTransaction in order to avoid our own code from
+ * being profiled. Because of that same reason, stopProfiling is called before the call to stopTransaction.
+ */
+ function profilingWrappedTransactionFinish(): Promise<Transaction> {
+ if (!transaction) {
+ return originalFinish();
+ }
+ // onProfileHandler should always return the same profile even if this is called multiple times.
+ // Always call onProfileHandler to ensure stopProfiling is called and the timeout is cleared.
+ onProfileHandler();
+
+ // Set profile context
+ transaction.setContext('profile', { profile_id: profileId });
+
+ return originalFinish();
+ }
+
+ transaction.finish = profilingWrappedTransactionFinish;
+ return transaction;
+}
+
+/**
+ * Wraps startTransaction with profiling logic. This is done automatically by the profiling integration.
+ */
+function __PRIVATE__wrapStartTransactionWithProfiling(startTransaction: StartTransaction): StartTransaction {
+ return function wrappedStartTransaction(
+ this: Hub,
+ transactionContext: TransactionContext,
+ customSamplingContext?: CustomSamplingContext,
+ ): Transaction | undefined {
+ const transaction: Transaction | undefined = startTransaction.call(this, transactionContext, customSamplingContext);
+ if (transaction === undefined) {
+ if (__DEBUG_BUILD__) {
+ logger.log('[Profiling] Transaction is undefined, skipping profiling');
+ }
+ return transaction;
+ }
+
+ return wrapTransactionWithProfiling(transaction);
+ };
+}
+
+/**
+ * Patches startTransaction and stopTransaction with profiling logic.
+ */
+export function addProfilingExtensionMethods(): void {
+ const carrier = getMainCarrier();
+ if (!carrier.__SENTRY__) {
+ if (__DEBUG_BUILD__) {
+ logger.log("[Profiling] Can't find main carrier, profiling won't work.");
+ }
+ return;
+ }
+ carrier.__SENTRY__.extensions = carrier.__SENTRY__.extensions || {};
+
+ if (!carrier.__SENTRY__.extensions['startTransaction']) {
+ if (__DEBUG_BUILD__) {
+ logger.log(
+ '[Profiling] startTransaction does not exists, profiling will not work. Make sure you import @sentry/tracing package before @sentry/profiling-node as import order matters.',
+ );
+ }
+ return;
+ }
+
+ if (__DEBUG_BUILD__) {
+ logger.log('[Profiling] startTransaction exists, patching it with profiling functionality...');
+ }
+
+ carrier.__SENTRY__.extensions['startTransaction'] = __PRIVATE__wrapStartTransactionWithProfiling(
+ // This is already patched by sentry/tracing, we are going to re-patch it...
+ carrier.__SENTRY__.extensions['startTransaction'] as StartTransaction,
+ );
+}

packages/browser/src/profiling/integration.ts

@@ -0,0 +1,48 @@
+import type { Event, EventProcessor, Integration } from '@sentry/types';
+import { logger } from '@sentry/utils';
+
+import { PROFILING_EVENT_CACHE } from './cache';
+import { addProfilingExtensionMethods } from './hubextensions';
+
+/**
+ * Browser profiling integration. Stores any event that has contexts["profile"]["profile_id"]
+ * This exists because we do not want to await async profiler.stop calls as transaction.finish is called
+ * in a synchronous context. Instead, we handle sending the profile async from the promise callback and
+ * rely on being able to pull the event from the cache when we need to construct the envelope. This makes the
+ * integration less reliable as we might be dropping profiles when the cache is full.
+ *
+ * @experimental
+ */
+export class BrowserProfilingIntegration implements Integration {
+ public readonly name: string = 'BrowserProfilingIntegration';
+
+ /**
+ * @inheritDoc
+ */
+ public setupOnce(addGlobalEventProcessor: (callback: EventProcessor) => void): void {
+ // Patching the hub to add the extension methods.
+ // Warning: we have an implicit dependency on import order and we will fail patching if the constructor of
+ // BrowserProfilingIntegration is called before @sentry/tracing is imported. This is because we need to patch
+ // the methods of @sentry/tracing which are patched as a side effect of importing @sentry/tracing.
+ addProfilingExtensionMethods();
+
+ // Add our event processor
+ addGlobalEventProcessor(this.handleGlobalEvent.bind(this));
+ }
+
+ /**
+ * @inheritDoc
+ */
+ public handleGlobalEvent(event: Event): Event {
+ const profileId = event.contexts && event.contexts['profile'] && event.contexts['profile']['profile_id'];
+
+ if (profileId && typeof profileId === 'string') {
+ if (__DEBUG_BUILD__) {
+ logger.log('[Profiling] Profiling event found, caching it.');
+ }
+ PROFILING_EVENT_CACHE.add(profileId, event);
+ }
+
+ return event;
+ }
+}