|
| 1 | +import { getCurrentHub, getMainCarrier } from '@sentry/core'; |
| 2 | +import type { CustomSamplingContext, Hub, Transaction, TransactionContext } from '@sentry/types'; |
| 3 | +import { logger, uuid4 } from '@sentry/utils'; |
| 4 | + |
| 5 | +import { WINDOW } from '../helpers'; |
| 6 | +import type { JSSelfProfile, JSSelfProfiler, ProcessedJSSelfProfile } from './jsSelfProfiling'; |
| 7 | +import { sendProfile } from './sendProfile'; |
| 8 | + |
| 9 | +// Max profile duration. |
| 10 | +const MAX_PROFILE_DURATION_MS = 30_000; |
| 11 | + |
| 12 | +// While we experiment, per transaction sampling interval will be more flexible to work with. |
| 13 | +type StartTransaction = ( |
| 14 | + this: Hub, |
| 15 | + transactionContext: TransactionContext, |
| 16 | + customSamplingContext?: CustomSamplingContext, |
| 17 | +) => Transaction | undefined; |
| 18 | + |
| 19 | +/** |
| 20 | + * Check if profiler constructor is available. |
| 21 | + * @param maybeProfiler |
| 22 | + */ |
| 23 | +function isJSProfilerSupported(maybeProfiler: unknown): maybeProfiler is typeof JSSelfProfiler { |
| 24 | + return typeof maybeProfiler === 'function'; |
| 25 | +} |
| 26 | + |
| 27 | +/** |
| 28 | + * Safety wrapper for startTransaction for the unlikely case that transaction starts before tracing is imported - |
| 29 | + * if that happens we want to avoid throwing an error from profiling code. |
| 30 | + * see https://github.com/getsentry/sentry-javascript/issues/4731. |
| 31 | + * |
| 32 | + * @experimental |
| 33 | + */ |
| 34 | +export function onProfilingStartRouteTransaction(transaction: Transaction | undefined): Transaction | undefined { |
| 35 | + if (!transaction) { |
| 36 | + if (__DEBUG_BUILD__) { |
| 37 | + logger.log('[Profiling] Transaction is undefined, skipping profiling'); |
| 38 | + } |
| 39 | + return transaction; |
| 40 | + } |
| 41 | + |
| 42 | + return wrapTransactionWithProfiling(transaction); |
| 43 | +} |
| 44 | + |
| 45 | +/** |
| 46 | + * Wraps startTransaction and stopTransaction with profiling related logic. |
| 47 | + * startProfiling is called after the call to startTransaction in order to avoid our own code from |
| 48 | + * being profiled. Because of that same reason, stopProfiling is called before the call to stopTransaction. |
| 49 | + */ |
| 50 | +function wrapTransactionWithProfiling(transaction: Transaction): Transaction { |
| 51 | + // Feature support check first |
| 52 | + const JSProfiler = WINDOW.Profiler; |
| 53 | + if (!isJSProfilerSupported(JSProfiler)) { |
| 54 | + if (__DEBUG_BUILD__) { |
| 55 | + logger.log( |
| 56 | + '[Profiling] Profiling is not supported by this browser, Profiler interface missing on window object.', |
| 57 | + ); |
| 58 | + } |
| 59 | + return transaction; |
| 60 | + } |
| 61 | + |
| 62 | + // profilesSampleRate is multiplied with tracesSampleRate to get the final sampling rate. |
| 63 | + if (!transaction.sampled) { |
| 64 | + if (__DEBUG_BUILD__) { |
| 65 | + logger.log('[Profiling] Transaction is not sampled, skipping profiling'); |
| 66 | + } |
| 67 | + return transaction; |
| 68 | + } |
| 69 | + |
| 70 | + const client = getCurrentHub().getClient(); |
| 71 | + const options = client && client.getOptions(); |
| 72 | + |
| 73 | + // @ts-ignore not part of the browser options yet |
| 74 | + const profilesSampleRate = (options && options.profilesSampleRate) || 0; |
| 75 | + if (profilesSampleRate === undefined) { |
| 76 | + if (__DEBUG_BUILD__) { |
| 77 | + logger.log('[Profiling] Profiling disabled, enable it by setting `profilesSampleRate` option to SDK init call.'); |
| 78 | + } |
| 79 | + return transaction; |
| 80 | + } |
| 81 | + |
| 82 | + // Check if we should sample this profile |
| 83 | + if (Math.random() > profilesSampleRate) { |
| 84 | + if (__DEBUG_BUILD__) { |
| 85 | + logger.log('[Profiling] Skip profiling transaction due to sampling.'); |
| 86 | + } |
| 87 | + return transaction; |
| 88 | + } |
| 89 | + |
| 90 | + // From initial testing, it seems that the minimum value for sampleInterval is 10ms. |
| 91 | + const samplingIntervalMS = 10; |
| 92 | + // Start the profiler |
| 93 | + const maxSamples = Math.floor(MAX_PROFILE_DURATION_MS / samplingIntervalMS); |
| 94 | + const profiler = new JSProfiler({ sampleInterval: samplingIntervalMS, maxBufferSize: maxSamples }); |
| 95 | + if (__DEBUG_BUILD__) { |
| 96 | + logger.log(`[Profiling] started profiling transaction: ${transaction.name || transaction.description}`); |
| 97 | + } |
| 98 | + |
| 99 | + // We create "unique" transaction names to avoid concurrent transactions with same names |
| 100 | + // from being ignored by the profiler. From here on, only this transaction name should be used when |
| 101 | + // calling the profiler methods. Note: we log the original name to the user to avoid confusion. |
| 102 | + const profileId = uuid4(); |
| 103 | + |
| 104 | + // A couple of important things to note here: |
| 105 | + // `CpuProfilerBindings.stopProfiling` will be scheduled to run in 30seconds in order to exceed max profile duration. |
| 106 | + // Whichever of the two (transaction.finish/timeout) is first to run, the profiling will be stopped and the gathered profile |
| 107 | + // will be processed when the original transaction is finished. Since onProfileHandler can be invoked multiple times in the |
| 108 | + // event of an error or user mistake (calling transaction.finish multiple times), it is important that the behavior of onProfileHandler |
| 109 | + // is idempotent as we do not want any timings or profiles to be overriden by the last call to onProfileHandler. |
| 110 | + // After the original finish method is called, the event will be reported through the integration and delegated to transport. |
| 111 | + let processedProfile: ProcessedJSSelfProfile | null = null; |
| 112 | + |
| 113 | + /** |
| 114 | + * Idempotent handler for profile stop |
| 115 | + */ |
| 116 | + function onProfileHandler(): void { |
| 117 | + // Check if the profile exists and return it the behavior has to be idempotent as users may call transaction.finish multiple times. |
| 118 | + if (!transaction) { |
| 119 | + return; |
| 120 | + } |
| 121 | + if (processedProfile) { |
| 122 | + if (__DEBUG_BUILD__) { |
| 123 | + logger.log( |
| 124 | + '[Profiling] profile for:', |
| 125 | + transaction.name || transaction.description, |
| 126 | + 'already exists, returning early', |
| 127 | + ); |
| 128 | + } |
| 129 | + return; |
| 130 | + } |
| 131 | + |
| 132 | + profiler |
| 133 | + .stop() |
| 134 | + .then((p: JSSelfProfile): void => { |
| 135 | + if (maxDurationTimeoutID) { |
| 136 | + WINDOW.clearTimeout(maxDurationTimeoutID); |
| 137 | + maxDurationTimeoutID = undefined; |
| 138 | + } |
| 139 | + |
| 140 | + if (__DEBUG_BUILD__) { |
| 141 | + logger.log(`[Profiling] stopped profiling of transaction: ${transaction.name || transaction.description}`); |
| 142 | + } |
| 143 | + |
| 144 | + // In case of an overlapping transaction, stopProfiling may return null and silently ignore the overlapping profile. |
| 145 | + if (!p) { |
| 146 | + if (__DEBUG_BUILD__) { |
| 147 | + logger.log( |
| 148 | + `[Profiling] profiler returned null profile for: ${transaction.name || transaction.description}`, |
| 149 | + 'this may indicate an overlapping transaction or a call to stopProfiling with a profile title that was never started', |
| 150 | + ); |
| 151 | + } |
| 152 | + return; |
| 153 | + } |
| 154 | + |
| 155 | + // If a profile has less than 2 samples, it is not useful and should be discarded. |
| 156 | + if (p.samples.length < 2) { |
| 157 | + return; |
| 158 | + } |
| 159 | + |
| 160 | + processedProfile = { ...p, profile_id: profileId }; |
| 161 | + sendProfile(profileId, processedProfile); |
| 162 | + }) |
| 163 | + .catch(error => { |
| 164 | + if (__DEBUG_BUILD__) { |
| 165 | + logger.log('[Profiling] error while stopping profiler:', error); |
| 166 | + } |
| 167 | + return null; |
| 168 | + }); |
| 169 | + } |
| 170 | + |
| 171 | + // Enqueue a timeout to prevent profiles from running over max duration. |
| 172 | + let maxDurationTimeoutID: number | undefined = WINDOW.setTimeout(() => { |
| 173 | + if (__DEBUG_BUILD__) { |
| 174 | + logger.log( |
| 175 | + '[Profiling] max profile duration elapsed, stopping profiling for:', |
| 176 | + transaction.name || transaction.description, |
| 177 | + ); |
| 178 | + } |
| 179 | + void onProfileHandler(); |
| 180 | + }, MAX_PROFILE_DURATION_MS); |
| 181 | + |
| 182 | + // We need to reference the original finish call to avoid creating an infinite loop |
| 183 | + const originalFinish = transaction.finish.bind(transaction); |
| 184 | + |
| 185 | + /** |
| 186 | + * Wraps startTransaction and stopTransaction with profiling related logic. |
| 187 | + * startProfiling is called after the call to startTransaction in order to avoid our own code from |
| 188 | + * being profiled. Because of that same reason, stopProfiling is called before the call to stopTransaction. |
| 189 | + */ |
| 190 | + function profilingWrappedTransactionFinish(): Promise<Transaction> { |
| 191 | + if (!transaction) { |
| 192 | + return originalFinish(); |
| 193 | + } |
| 194 | + // onProfileHandler should always return the same profile even if this is called multiple times. |
| 195 | + // Always call onProfileHandler to ensure stopProfiling is called and the timeout is cleared. |
| 196 | + onProfileHandler(); |
| 197 | + |
| 198 | + // Set profile context |
| 199 | + transaction.setContext('profile', { profile_id: profileId }); |
| 200 | + |
| 201 | + return originalFinish(); |
| 202 | + } |
| 203 | + |
| 204 | + transaction.finish = profilingWrappedTransactionFinish; |
| 205 | + return transaction; |
| 206 | +} |
| 207 | + |
| 208 | +/** |
| 209 | + * Wraps startTransaction with profiling logic. This is done automatically by the profiling integration. |
| 210 | + */ |
| 211 | +function __PRIVATE__wrapStartTransactionWithProfiling(startTransaction: StartTransaction): StartTransaction { |
| 212 | + return function wrappedStartTransaction( |
| 213 | + this: Hub, |
| 214 | + transactionContext: TransactionContext, |
| 215 | + customSamplingContext?: CustomSamplingContext, |
| 216 | + ): Transaction | undefined { |
| 217 | + const transaction: Transaction | undefined = startTransaction.call(this, transactionContext, customSamplingContext); |
| 218 | + if (transaction === undefined) { |
| 219 | + if (__DEBUG_BUILD__) { |
| 220 | + logger.log('[Profiling] Transaction is undefined, skipping profiling'); |
| 221 | + } |
| 222 | + return transaction; |
| 223 | + } |
| 224 | + |
| 225 | + return wrapTransactionWithProfiling(transaction); |
| 226 | + }; |
| 227 | +} |
| 228 | + |
| 229 | +/** |
| 230 | + * Patches startTransaction and stopTransaction with profiling logic. |
| 231 | + */ |
| 232 | +export function addProfilingExtensionMethods(): void { |
| 233 | + const carrier = getMainCarrier(); |
| 234 | + if (!carrier.__SENTRY__) { |
| 235 | + if (__DEBUG_BUILD__) { |
| 236 | + logger.log("[Profiling] Can't find main carrier, profiling won't work."); |
| 237 | + } |
| 238 | + return; |
| 239 | + } |
| 240 | + carrier.__SENTRY__.extensions = carrier.__SENTRY__.extensions || {}; |
| 241 | + |
| 242 | + if (!carrier.__SENTRY__.extensions['startTransaction']) { |
| 243 | + if (__DEBUG_BUILD__) { |
| 244 | + logger.log( |
| 245 | + '[Profiling] startTransaction does not exists, profiling will not work. Make sure you import @sentry/tracing package before @sentry/profiling-node as import order matters.', |
| 246 | + ); |
| 247 | + } |
| 248 | + return; |
| 249 | + } |
| 250 | + |
| 251 | + if (__DEBUG_BUILD__) { |
| 252 | + logger.log('[Profiling] startTransaction exists, patching it with profiling functionality...'); |
| 253 | + } |
| 254 | + |
| 255 | + carrier.__SENTRY__.extensions['startTransaction'] = __PRIVATE__wrapStartTransactionWithProfiling( |
| 256 | + // This is already patched by sentry/tracing, we are going to re-patch it... |
| 257 | + carrier.__SENTRY__.extensions['startTransaction'] as StartTransaction, |
| 258 | + ); |
| 259 | +} |
0 commit comments