From 8425c9cb452c08e2698d0ebd3e457264b49353ae Mon Sep 17 00:00:00 2001 From: Sebastian Markbage Date: Tue, 25 Mar 2025 00:36:06 -0400 Subject: [PATCH 1/4] Define console.timeStamp and console.createTask extensions --- scripts/flow/environment.js | 40 +++++++++++++++++++++++++++++++++++++ 1 file changed, 40 insertions(+) diff --git a/scripts/flow/environment.js b/scripts/flow/environment.js index 96784a8353383..c3fe40eeef302 100644 --- a/scripts/flow/environment.js +++ b/scripts/flow/environment.js @@ -33,6 +33,46 @@ declare interface ConsoleTask { run(f: () => T): T; } +declare var console: { + assert(condition: mixed, ...data: Array): void, + clear(): void, + count(label?: string): void, + countReset(label?: string): void, + debug(...data: Array): void, + dir(...data: Array): void, + dirxml(...data: Array): void, + error(...data: Array): void, + _exception(...data: Array): void, + group(...data: Array): void, + groupCollapsed(...data: Array): void, + groupEnd(): void, + info(...data: Array): void, + log(...data: Array): void, + profile(name?: string): void, + profileEnd(name?: string): void, + table( + tabularData: + | {[key: string]: any, ...} + | Array<{[key: string]: any, ...}> + | Array>, + ): void, + time(label?: string): void, + timeEnd(label: string): void, + timeStamp( + label?: string, + start?: string | number, + end?: string | number, + trackName?: string, + trackGroup?: string, + color?: string, + ): void, + timeLog(label?: string, ...data?: Array): void, + trace(...data: Array): void, + warn(...data: Array): void, + createTask(label: string): ConsoleTask, + ... +}; + type ScrollTimelineOptions = { source: Element, axis?: 'block' | 'inline' | 'x' | 'y', From 5836a8095714344a6cfd94ba2c6c5aa0708969f6 Mon Sep 17 00:00:00 2001 From: Sebastian Markbage Date: Tue, 25 Mar 2025 00:36:37 -0400 Subject: [PATCH 2/4] Use console.timeStamp instead of performance.measure Except for errors in DEV where we use the properties extension. --- .../src/ReactFlightPerformanceTrack.js | 95 ++-- .../src/ReactFiberPerformanceTrack.js | 462 +++++++++++------- 2 files changed, 330 insertions(+), 227 deletions(-) diff --git a/packages/react-client/src/ReactFlightPerformanceTrack.js b/packages/react-client/src/ReactFlightPerformanceTrack.js index 123878526d3eb..338b836e9223e 100644 --- a/packages/react-client/src/ReactFlightPerformanceTrack.js +++ b/packages/react-client/src/ReactFlightPerformanceTrack.js @@ -7,6 +7,8 @@ * @flow */ +/* eslint-disable react-internal/no-production-logging */ + import type {ReactComponentInfo} from 'shared/ReactTypes'; import {enableProfilerTimer} from 'shared/ReactFeatureFlags'; @@ -15,7 +17,9 @@ const supportsUserTiming = enableProfilerTimer && typeof performance !== 'undefined' && // $FlowFixMe[method-unbinding] - typeof performance.measure === 'function'; + typeof performance.mark === 'function' && + typeof console !== 'undefined' && + typeof console.timeStamp === 'function'; const COMPONENTS_TRACK = 'Server Components ⚛'; @@ -39,20 +43,6 @@ export function markAllTracksInOrder() { } } -// Reused to avoid thrashing the GC. -const reusableComponentDevToolDetails = { - color: 'primary', - track: '', - trackGroup: COMPONENTS_TRACK, -}; -const reusableComponentOptions = { - start: -0, - end: -0, - detail: { - devtools: reusableComponentDevToolDetails, - }, -}; - const trackNames = [ 'Primary', 'Parallel', @@ -79,7 +69,7 @@ export function logComponentRender( const name = componentInfo.name; const isPrimaryEnv = env === rootEnv; const selfTime = endTime - startTime; - reusableComponentDevToolDetails.color = + const color = selfTime < 0.5 ? isPrimaryEnv ? 'primary-light' @@ -93,12 +83,16 @@ export function logComponentRender( ? 'primary-dark' : 'secondary-dark' : 'error'; - reusableComponentDevToolDetails.track = trackNames[trackIdx]; - reusableComponentOptions.start = startTime < 0 ? 0 : startTime; - reusableComponentOptions.end = childrenEndTime; const entryName = isPrimaryEnv || env === undefined ? name : name + ' [' + env + ']'; - performance.measure(entryName, reusableComponentOptions); + console.timeStamp( + entryName, + startTime < 0 ? 0 : startTime, + childrenEndTime, + trackNames[trackIdx], + COMPONENTS_TRACK, + color, + ); } } @@ -112,7 +106,11 @@ export function logComponentErrored( error: mixed, ): void { if (supportsUserTiming) { - const properties = []; + const env = componentInfo.env; + const name = componentInfo.name; + const isPrimaryEnv = env === rootEnv; + const entryName = + isPrimaryEnv || env === undefined ? name : name + ' [' + env + ']'; if (__DEV__) { const message = typeof error === 'object' && @@ -122,26 +120,30 @@ export function logComponentErrored( String(error.message) : // eslint-disable-next-line react-internal/safe-string-coercion String(error); - properties.push(['Error', message]); - } - const env = componentInfo.env; - const name = componentInfo.name; - const isPrimaryEnv = env === rootEnv; - const entryName = - isPrimaryEnv || env === undefined ? name : name + ' [' + env + ']'; - performance.measure(entryName, { - start: startTime < 0 ? 0 : startTime, - end: childrenEndTime, - detail: { - devtools: { - color: 'error', - track: trackNames[trackIdx], - trackGroup: COMPONENTS_TRACK, - tooltipText: entryName + ' Errored', - properties, + const properties = [['Error', message]]; + performance.measure(entryName, { + start: startTime < 0 ? 0 : startTime, + end: childrenEndTime, + detail: { + devtools: { + color: 'error', + track: trackNames[trackIdx], + trackGroup: COMPONENTS_TRACK, + tooltipText: entryName + ' Errored', + properties, + }, }, - }, - }); + }); + } else { + console.timeStamp( + entryName, + startTime < 0 ? 0 : startTime, + childrenEndTime, + trackNames[trackIdx], + COMPONENTS_TRACK, + 'error', + ); + } } } @@ -153,11 +155,14 @@ export function logDedupedComponentRender( ): void { if (supportsUserTiming && endTime >= 0 && trackIdx < 10) { const name = componentInfo.name; - reusableComponentDevToolDetails.color = 'tertiary-light'; - reusableComponentDevToolDetails.track = trackNames[trackIdx]; - reusableComponentOptions.start = startTime < 0 ? 0 : startTime; - reusableComponentOptions.end = endTime; const entryName = name + ' [deduped]'; - performance.measure(entryName, reusableComponentOptions); + console.timeStamp( + entryName, + startTime < 0 ? 0 : startTime, + endTime, + trackNames[trackIdx], + COMPONENTS_TRACK, + 'tertiary-light', + ); } } diff --git a/packages/react-reconciler/src/ReactFiberPerformanceTrack.js b/packages/react-reconciler/src/ReactFiberPerformanceTrack.js index 042c3fd927eff..f3a4343d9296f 100644 --- a/packages/react-reconciler/src/ReactFiberPerformanceTrack.js +++ b/packages/react-reconciler/src/ReactFiberPerformanceTrack.js @@ -7,6 +7,8 @@ * @flow */ +/* eslint-disable react-internal/no-production-logging */ + import type {Fiber} from './ReactInternalTypes'; import type {Lanes} from './ReactFiberLane'; @@ -30,25 +32,15 @@ const supportsUserTiming = enableProfilerTimer && typeof performance !== 'undefined' && // $FlowFixMe[method-unbinding] - typeof performance.measure === 'function'; + typeof performance.mark === 'function' && + typeof console !== 'undefined' && + typeof console.timeStamp === 'function'; const COMPONENTS_TRACK = 'Components ⚛'; - -// Reused to avoid thrashing the GC. -const reusableComponentDevToolDetails = { - color: 'primary', - track: COMPONENTS_TRACK, -}; -const reusableComponentOptions = { - start: -0, - end: -0, - detail: { - devtools: reusableComponentDevToolDetails, - }, -}; - const LANES_TRACK_GROUP = 'Scheduler ⚛'; +let currentTrack: string = 'Blocking'; // Lane + const reusableLaneDevToolDetails = { color: 'primary', track: 'Blocking', // Lane @@ -63,7 +55,7 @@ const reusableLaneOptions = { }; export function setCurrentTrackFromLanes(lanes: Lanes): void { - reusableLaneDevToolDetails.track = getGroupNameOfHighestPriorityLane(lanes); + currentTrack = getGroupNameOfHighestPriorityLane(lanes); } const blockingLaneMarker = { @@ -130,10 +122,14 @@ function logComponentTrigger( trigger: string, ) { if (supportsUserTiming) { - reusableComponentDevToolDetails.color = 'warning'; - reusableComponentOptions.start = startTime; - reusableComponentOptions.end = endTime; - performance.measure(trigger, reusableComponentOptions); + console.timeStamp( + trigger, + startTime, + endTime, + COMPONENTS_TRACK, + undefined, + 'warning', + ); } } @@ -187,7 +183,7 @@ export function logComponentRender( selfTime -= (child.actualDuration: any); } } - reusableComponentDevToolDetails.color = + const color = selfTime < 0.5 ? wasHydrated ? 'tertiary-light' @@ -201,9 +197,14 @@ export function logComponentRender( ? 'tertiary-dark' : 'primary-dark' : 'error'; - reusableComponentOptions.start = startTime; - reusableComponentOptions.end = endTime; - performance.measure(name, reusableComponentOptions); + console.timeStamp( + name, + startTime, + endTime, + COMPONENTS_TRACK, + undefined, + color, + ); } } @@ -219,8 +220,8 @@ export function logComponentErrored( // Skip return; } - const properties = []; if (__DEV__) { + const properties = []; for (let i = 0; i < errors.length; i++) { const capturedValue = errors[i]; const error = capturedValue.value; @@ -234,22 +235,31 @@ export function logComponentErrored( String(error); properties.push(['Error', message]); } - } - performance.measure(name, { - start: startTime, - end: endTime, - detail: { - devtools: { - color: 'error', - track: COMPONENTS_TRACK, - tooltipText: - fiber.tag === SuspenseComponent - ? 'Hydration failed' - : 'Error boundary caught an error', - properties, + performance.measure(name, { + start: startTime, + end: endTime, + detail: { + devtools: { + color: 'error', + track: COMPONENTS_TRACK, + tooltipText: + fiber.tag === SuspenseComponent + ? 'Hydration failed' + : 'Error boundary caught an error', + properties, + }, }, - }, - }); + }); + } else { + console.timeStamp( + name, + startTime, + endTime, + COMPONENTS_TRACK, + undefined, + 'error', + ); + } } } @@ -265,8 +275,8 @@ function logComponentEffectErrored( // Skip return; } - const properties = []; if (__DEV__) { + const properties = []; for (let i = 0; i < errors.length; i++) { const capturedValue = errors[i]; const error = capturedValue.value; @@ -280,19 +290,28 @@ function logComponentEffectErrored( String(error); properties.push(['Error', message]); } - } - performance.measure(name, { - start: startTime, - end: endTime, - detail: { - devtools: { - color: 'error', - track: COMPONENTS_TRACK, - tooltipText: 'A lifecycle or effect errored', - properties, + performance.measure(name, { + start: startTime, + end: endTime, + detail: { + devtools: { + color: 'error', + track: COMPONENTS_TRACK, + tooltipText: 'A lifecycle or effect errored', + properties, + }, }, - }, - }); + }); + } else { + console.timeStamp( + name, + startTime, + endTime, + COMPONENTS_TRACK, + undefined, + 'error', + ); + } } } @@ -313,7 +332,7 @@ export function logComponentEffect( return; } if (supportsUserTiming) { - reusableComponentDevToolDetails.color = + const color = selfTime < 1 ? 'secondary-light' : selfTime < 100 @@ -321,9 +340,14 @@ export function logComponentEffect( : selfTime < 500 ? 'secondary-dark' : 'error'; - reusableComponentOptions.start = startTime; - reusableComponentOptions.end = endTime; - performance.measure(name, reusableComponentOptions); + console.timeStamp( + name, + startTime, + endTime, + COMPONENTS_TRACK, + undefined, + color, + ); } } @@ -335,7 +359,7 @@ export function logYieldTime(startTime: number, endTime: number): void { return; } // Being blocked on CPU is potentially bad so we color it by how long it took. - reusableComponentDevToolDetails.color = + const color = yieldDuration < 5 ? 'primary-light' : yieldDuration < 10 @@ -343,13 +367,18 @@ export function logYieldTime(startTime: number, endTime: number): void { : yieldDuration < 100 ? 'primary-dark' : 'error'; - reusableComponentOptions.start = startTime; - reusableComponentOptions.end = endTime; // This get logged in the components track if we don't commit which leaves them // hanging by themselves without context. It's a useful indicator for why something // might be starving this render though. // TODO: Considering adding these to a queue and only logging them if we commit. - performance.measure('Blocked', reusableComponentOptions); + console.timeStamp( + 'Blocked', + startTime, + endTime, + COMPONENTS_TRACK, + undefined, + color, + ); } } @@ -359,10 +388,14 @@ export function logSuspendedYieldTime( suspendedFiber: Fiber, ): void { if (supportsUserTiming) { - reusableComponentDevToolDetails.color = 'primary-light'; - reusableComponentOptions.start = startTime; - reusableComponentOptions.end = endTime; - performance.measure('Suspended', reusableComponentOptions); + console.timeStamp( + 'Suspended', + startTime, + endTime, + COMPONENTS_TRACK, + undefined, + 'primary-light', + ); } } @@ -372,10 +405,14 @@ export function logActionYieldTime( suspendedFiber: Fiber, ): void { if (supportsUserTiming) { - reusableComponentDevToolDetails.color = 'primary-light'; - reusableComponentOptions.start = startTime; - reusableComponentOptions.end = endTime; - performance.measure('Action', reusableComponentOptions); + console.timeStamp( + 'Action', + startTime, + endTime, + COMPONENTS_TRACK, + undefined, + 'primary-light', + ); } } @@ -389,38 +426,40 @@ export function logBlockingStart( lanes: Lanes, ): void { if (supportsUserTiming) { - reusableLaneDevToolDetails.track = 'Blocking'; + currentTrack = 'Blocking'; // If a blocking update was spawned within render or an effect, that's considered a cascading render. // If you have a second blocking update within the same event, that suggests multiple flushSync or // setState in a microtask which is also considered a cascade. if (eventTime > 0 && eventType !== null) { // Log the time from the event timeStamp until we called setState. - reusableLaneDevToolDetails.color = eventIsRepeat - ? 'secondary-light' - : 'warning'; - reusableLaneOptions.start = eventTime; - reusableLaneOptions.end = updateTime > 0 ? updateTime : renderStartTime; - performance.measure( + const color = eventIsRepeat ? 'secondary-light' : 'warning'; + console.timeStamp( eventIsRepeat ? '' : 'Event: ' + eventType, - reusableLaneOptions, + eventTime, + updateTime > 0 ? updateTime : renderStartTime, + currentTrack, + LANES_TRACK_GROUP, + color, ); } if (updateTime > 0) { // Log the time from when we called setState until we started rendering. - reusableLaneDevToolDetails.color = isSpawnedUpdate + const color = isSpawnedUpdate ? 'error' : includesOnlyHydrationOrOffscreenLanes(lanes) ? 'tertiary-light' : 'primary-light'; - reusableLaneOptions.start = updateTime; - reusableLaneOptions.end = renderStartTime; - performance.measure( + console.timeStamp( isSpawnedUpdate ? 'Cascading Update' : renderStartTime - updateTime > 5 ? 'Update Blocked' : 'Update', - reusableLaneOptions, + updateTime, + renderStartTime, + currentTrack, + LANES_TRACK_GROUP, + color, ); } } @@ -435,39 +474,45 @@ export function logTransitionStart( renderStartTime: number, ): void { if (supportsUserTiming) { - reusableLaneDevToolDetails.track = 'Transition'; + currentTrack = 'Transition'; if (eventTime > 0 && eventType !== null) { // Log the time from the event timeStamp until we started a transition. - reusableLaneDevToolDetails.color = eventIsRepeat - ? 'secondary-light' - : 'warning'; - reusableLaneOptions.start = eventTime; - reusableLaneOptions.end = + const color = eventIsRepeat ? 'secondary-light' : 'warning'; + const endTime = startTime > 0 ? startTime : updateTime > 0 ? updateTime : renderStartTime; - performance.measure( + console.timeStamp( eventIsRepeat ? '' : 'Event: ' + eventType, - reusableLaneOptions, + eventTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + color, ); } if (startTime > 0) { // Log the time from when we started an async transition until we called setState or started rendering. - reusableLaneDevToolDetails.color = 'primary-dark'; - reusableLaneOptions.start = startTime; - reusableLaneOptions.end = updateTime > 0 ? updateTime : renderStartTime; - performance.measure('Action', reusableLaneOptions); + console.timeStamp( + 'Action', + startTime, + updateTime > 0 ? updateTime : renderStartTime, + currentTrack, + LANES_TRACK_GROUP, + 'primary-dark', + ); } if (updateTime > 0) { // Log the time from when we called setState until we started rendering. - reusableLaneDevToolDetails.color = 'primary-light'; - reusableLaneOptions.start = updateTime; - reusableLaneOptions.end = renderStartTime; - performance.measure( + console.timeStamp( renderStartTime - updateTime > 5 ? 'Update Blocked' : 'Update', - reusableLaneOptions, + updateTime, + renderStartTime, + currentTrack, + LANES_TRACK_GROUP, + 'primary-light', ); } } @@ -479,20 +524,20 @@ export function logRenderPhase( lanes: Lanes, ): void { if (supportsUserTiming) { - reusableLaneDevToolDetails.color = includesOnlyHydrationOrOffscreenLanes( - lanes, - ) + const color = includesOnlyHydrationOrOffscreenLanes(lanes) ? 'tertiary-dark' : 'primary-dark'; - reusableLaneOptions.start = startTime; - reusableLaneOptions.end = endTime; - performance.measure( + console.timeStamp( includesOnlyOffscreenLanes(lanes) ? 'Prepared' : includesOnlyHydrationLanes(lanes) ? 'Hydrated' : 'Render', - reusableLaneOptions, + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + color, ); } } @@ -503,20 +548,20 @@ export function logInterruptedRenderPhase( lanes: Lanes, ): void { if (supportsUserTiming) { - reusableLaneDevToolDetails.color = includesOnlyHydrationOrOffscreenLanes( - lanes, - ) + const color = includesOnlyHydrationOrOffscreenLanes(lanes) ? 'tertiary-dark' : 'primary-dark'; - reusableLaneOptions.start = startTime; - reusableLaneOptions.end = endTime; - performance.measure( + console.timeStamp( includesOnlyOffscreenLanes(lanes) ? 'Prewarm' : includesOnlyHydrationLanes(lanes) ? 'Interrupted Hydration' : 'Interrupted Render', - reusableLaneOptions, + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + color, ); } } @@ -527,14 +572,17 @@ export function logSuspendedRenderPhase( lanes: Lanes, ): void { if (supportsUserTiming) { - reusableLaneDevToolDetails.color = includesOnlyHydrationOrOffscreenLanes( - lanes, - ) + const color = includesOnlyHydrationOrOffscreenLanes(lanes) ? 'tertiary-dark' : 'primary-dark'; - reusableLaneOptions.start = startTime; - reusableLaneOptions.end = endTime; - performance.measure('Prewarm', reusableLaneOptions); + console.timeStamp( + 'Prewarm', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + color, + ); } } @@ -545,14 +593,17 @@ export function logSuspendedWithDelayPhase( ): void { // This means the render was suspended and cannot commit until it gets unblocked. if (supportsUserTiming) { - reusableLaneDevToolDetails.color = includesOnlyHydrationOrOffscreenLanes( - lanes, - ) + const color = includesOnlyHydrationOrOffscreenLanes(lanes) ? 'tertiary-dark' : 'primary-dark'; - reusableLaneOptions.start = startTime; - reusableLaneOptions.end = endTime; - performance.measure('Suspended', reusableLaneOptions); + console.timeStamp( + 'Suspended', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + color, + ); } } @@ -564,8 +615,8 @@ export function logRecoveredRenderPhase( hydrationFailed: boolean, ): void { if (supportsUserTiming) { - const properties = []; if (__DEV__) { + const properties = []; for (let i = 0; i < recoverableErrors.length; i++) { const capturedValue = recoverableErrors[i]; const error = capturedValue.value; @@ -579,22 +630,31 @@ export function logRecoveredRenderPhase( String(error); properties.push(['Recoverable Error', message]); } - } - performance.measure('Recovered', { - start: startTime, - end: endTime, - detail: { - devtools: { - color: 'primary-dark', - track: reusableLaneDevToolDetails.track, - trackGroup: LANES_TRACK_GROUP, - tooltipText: hydrationFailed - ? 'Hydration Failed' - : 'Recovered after Error', - properties, + performance.measure('Recovered', { + start: startTime, + end: endTime, + detail: { + devtools: { + color: 'primary-dark', + track: currentTrack, + trackGroup: LANES_TRACK_GROUP, + tooltipText: hydrationFailed + ? 'Hydration Failed' + : 'Recovered after Error', + properties, + }, }, - }, - }); + }); + } else { + console.timeStamp( + 'Recovered', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'error', + ); + } } } @@ -604,10 +664,14 @@ export function logErroredRenderPhase( lanes: Lanes, ): void { if (supportsUserTiming) { - reusableLaneDevToolDetails.color = 'error'; - reusableLaneOptions.start = startTime; - reusableLaneOptions.end = endTime; - performance.measure('Errored', reusableLaneOptions); + console.timeStamp( + 'Errored', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'error', + ); } } @@ -616,10 +680,14 @@ export function logInconsistentRender( endTime: number, ): void { if (supportsUserTiming) { - reusableLaneDevToolDetails.color = 'error'; - reusableLaneOptions.start = startTime; - reusableLaneOptions.end = endTime; - performance.measure('Teared Render', reusableLaneOptions); + console.timeStamp( + 'Teared Render', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'error', + ); } } @@ -629,10 +697,14 @@ export function logSuspenseThrottlePhase( ): void { // This was inside a throttled Suspense boundary commit. if (supportsUserTiming) { - reusableLaneDevToolDetails.color = 'secondary-light'; - reusableLaneOptions.start = startTime; - reusableLaneOptions.end = endTime; - performance.measure('Throttled', reusableLaneOptions); + console.timeStamp( + 'Throttled', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'secondary-light', + ); } } @@ -642,12 +714,16 @@ export function logSuspendedCommitPhase( ): void { // This means the commit was suspended on CSS or images. if (supportsUserTiming) { - reusableLaneDevToolDetails.color = 'secondary-light'; - reusableLaneOptions.start = startTime; - reusableLaneOptions.end = endTime; // TODO: Include the exact reason and URLs of what resources suspended. // TODO: This might also be Suspended while waiting on a View Transition. - performance.measure('Suspended on CSS or Images', reusableLaneOptions); + console.timeStamp( + 'Suspended on CSS or Images', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'secondary-light', + ); } } @@ -658,8 +734,8 @@ export function logCommitErrored( passive: boolean, ): void { if (supportsUserTiming) { - const properties = []; if (__DEV__) { + const properties = []; for (let i = 0; i < errors.length; i++) { const capturedValue = errors[i]; const error = capturedValue.value; @@ -673,20 +749,31 @@ export function logCommitErrored( String(error); properties.push(['Error', message]); } - } - performance.measure('Errored', { - start: startTime, - end: endTime, - detail: { - devtools: { - color: 'error', - track: reusableLaneDevToolDetails.track, - trackGroup: LANES_TRACK_GROUP, - tooltipText: passive ? 'Remaining Effects Errored' : 'Commit Errored', - properties, + performance.measure('Errored', { + start: startTime, + end: endTime, + detail: { + devtools: { + color: 'error', + track: currentTrack, + trackGroup: LANES_TRACK_GROUP, + tooltipText: passive + ? 'Remaining Effects Errored' + : 'Commit Errored', + properties, + }, }, - }, - }); + }); + } else { + console.timeStamp( + 'Errored', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'error', + ); + } } } @@ -700,10 +787,16 @@ export function logCommitPhase( return; } if (supportsUserTiming) { - reusableLaneDevToolDetails.color = 'secondary-dark'; reusableLaneOptions.start = startTime; reusableLaneOptions.end = endTime; - performance.measure('Commit', reusableLaneOptions); + console.timeStamp( + 'Commit', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'secondary-dark', + ); } } @@ -713,12 +806,13 @@ export function logPaintYieldPhase( delayedUntilPaint: boolean, ): void { if (supportsUserTiming) { - reusableLaneDevToolDetails.color = 'secondary-light'; - reusableLaneOptions.start = startTime; - reusableLaneOptions.end = endTime; - performance.measure( + console.timeStamp( delayedUntilPaint ? 'Waiting for Paint' : '', - reusableLaneOptions, + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'secondary-light', ); } } @@ -733,9 +827,13 @@ export function logPassiveCommitPhase( return; } if (supportsUserTiming) { - reusableLaneDevToolDetails.color = 'secondary-dark'; - reusableLaneOptions.start = startTime; - reusableLaneOptions.end = endTime; - performance.measure('Remaining Effects', reusableLaneOptions); + console.timeStamp( + 'Remaining Effects', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'secondary-dark', + ); } } From e25b2a74ae0d36f5b77c6a3102523734f19c71f4 Mon Sep 17 00:00:00 2001 From: Sebastian Markbage Date: Tue, 25 Mar 2025 01:07:41 -0400 Subject: [PATCH 3/4] Use console.timeStamp instead of performance.mark If we use the same start/end time we get the same effect. --- .../src/ReactFlightPerformanceTrack.js | 23 ++--- .../src/ReactFiberPerformanceTrack.js | 83 +++++++------------ 2 files changed, 40 insertions(+), 66 deletions(-) diff --git a/packages/react-client/src/ReactFlightPerformanceTrack.js b/packages/react-client/src/ReactFlightPerformanceTrack.js index 338b836e9223e..58011d19f97ea 100644 --- a/packages/react-client/src/ReactFlightPerformanceTrack.js +++ b/packages/react-client/src/ReactFlightPerformanceTrack.js @@ -15,31 +15,24 @@ import {enableProfilerTimer} from 'shared/ReactFeatureFlags'; const supportsUserTiming = enableProfilerTimer && - typeof performance !== 'undefined' && - // $FlowFixMe[method-unbinding] - typeof performance.mark === 'function' && typeof console !== 'undefined' && typeof console.timeStamp === 'function'; const COMPONENTS_TRACK = 'Server Components ⚛'; -const componentsTrackMarker = { - startTime: 0.001, - detail: { - devtools: { - color: 'primary-light', - track: 'Primary', - trackGroup: COMPONENTS_TRACK, - }, - }, -}; - export function markAllTracksInOrder() { if (supportsUserTiming) { // Ensure we create the Server Component track groups earlier than the Client Scheduler // and Client Components. We can always add the 0 time slot even if it's in the past. // That's still considered for ordering. - performance.mark('Server Components Track', componentsTrackMarker); + console.timeStamp( + 'Server Components Track', + 0.001, + 0.001, + 'Primary', + COMPONENTS_TRACK, + 'primary-light', + ); } } diff --git a/packages/react-reconciler/src/ReactFiberPerformanceTrack.js b/packages/react-reconciler/src/ReactFiberPerformanceTrack.js index f3a4343d9296f..8bc1c1c9b4e91 100644 --- a/packages/react-reconciler/src/ReactFiberPerformanceTrack.js +++ b/packages/react-reconciler/src/ReactFiberPerformanceTrack.js @@ -30,9 +30,6 @@ import {enableProfilerTimer} from 'shared/ReactFeatureFlags'; const supportsUserTiming = enableProfilerTimer && - typeof performance !== 'undefined' && - // $FlowFixMe[method-unbinding] - typeof performance.mark === 'function' && typeof console !== 'undefined' && typeof console.timeStamp === 'function'; @@ -58,60 +55,44 @@ export function setCurrentTrackFromLanes(lanes: Lanes): void { currentTrack = getGroupNameOfHighestPriorityLane(lanes); } -const blockingLaneMarker = { - startTime: 0.003, - detail: { - devtools: { - color: 'primary-light', - track: 'Blocking', - trackGroup: LANES_TRACK_GROUP, - }, - }, -}; - -const transitionLaneMarker = { - startTime: 0.003, - detail: { - devtools: { - color: 'primary-light', - track: 'Transition', - trackGroup: LANES_TRACK_GROUP, - }, - }, -}; - -const suspenseLaneMarker = { - startTime: 0.003, - detail: { - devtools: { - color: 'primary-light', - track: 'Suspense', - trackGroup: LANES_TRACK_GROUP, - }, - }, -}; - -const idleLaneMarker = { - startTime: 0.003, - detail: { - devtools: { - color: 'primary-light', - track: 'Idle', - trackGroup: LANES_TRACK_GROUP, - }, - }, -}; - export function markAllLanesInOrder() { if (supportsUserTiming) { // Ensure we create all tracks in priority order. Currently performance.mark() are in // first insertion order but performance.measure() are in the reverse order. We can // always add the 0 time slot even if it's in the past. That's still considered for // ordering. - performance.mark('Blocking Track', blockingLaneMarker); - performance.mark('Transition Track', transitionLaneMarker); - performance.mark('Suspense Track', suspenseLaneMarker); - performance.mark('Idle Track', idleLaneMarker); + console.timeStamp( + 'Blocking Track', + 0.003, + 0.003, + 'Blocking', + LANES_TRACK_GROUP, + 'primary-light', + ); + console.timeStamp( + 'Transition Track', + 0.003, + 0.003, + 'Transition', + LANES_TRACK_GROUP, + 'primary-light', + ); + console.timeStamp( + 'Suspense Track', + 0.003, + 0.003, + 'Suspense', + LANES_TRACK_GROUP, + 'primary-light', + ); + console.timeStamp( + 'Idle Track', + 0.003, + 0.003, + 'Idle', + LANES_TRACK_GROUP, + 'primary-light', + ); } } From 3bc3e8a08abf53bdc39820d2ddea220ea46a086f Mon Sep 17 00:00:00 2001 From: Sebastian Markbage Date: Tue, 25 Mar 2025 01:10:11 -0400 Subject: [PATCH 4/4] Gate performance.measure usage on DEV and existence of the API --- .../src/ReactFlightPerformanceTrack.js | 7 ++++- .../src/ReactFiberPerformanceTrack.js | 28 ++++++++++++++++--- 2 files changed, 30 insertions(+), 5 deletions(-) diff --git a/packages/react-client/src/ReactFlightPerformanceTrack.js b/packages/react-client/src/ReactFlightPerformanceTrack.js index 58011d19f97ea..8af61d7c5ca58 100644 --- a/packages/react-client/src/ReactFlightPerformanceTrack.js +++ b/packages/react-client/src/ReactFlightPerformanceTrack.js @@ -104,7 +104,12 @@ export function logComponentErrored( const isPrimaryEnv = env === rootEnv; const entryName = isPrimaryEnv || env === undefined ? name : name + ' [' + env + ']'; - if (__DEV__) { + if ( + __DEV__ && + typeof performance !== 'undefined' && + // $FlowFixMe[method-unbinding] + typeof performance.measure === 'function' + ) { const message = typeof error === 'object' && error !== null && diff --git a/packages/react-reconciler/src/ReactFiberPerformanceTrack.js b/packages/react-reconciler/src/ReactFiberPerformanceTrack.js index 8bc1c1c9b4e91..8f52fa708b3c9 100644 --- a/packages/react-reconciler/src/ReactFiberPerformanceTrack.js +++ b/packages/react-reconciler/src/ReactFiberPerformanceTrack.js @@ -201,7 +201,12 @@ export function logComponentErrored( // Skip return; } - if (__DEV__) { + if ( + __DEV__ && + typeof performance !== 'undefined' && + // $FlowFixMe[method-unbinding] + typeof performance.measure === 'function' + ) { const properties = []; for (let i = 0; i < errors.length; i++) { const capturedValue = errors[i]; @@ -256,7 +261,12 @@ function logComponentEffectErrored( // Skip return; } - if (__DEV__) { + if ( + __DEV__ && + typeof performance !== 'undefined' && + // $FlowFixMe[method-unbinding] + typeof performance.measure === 'function' + ) { const properties = []; for (let i = 0; i < errors.length; i++) { const capturedValue = errors[i]; @@ -596,7 +606,12 @@ export function logRecoveredRenderPhase( hydrationFailed: boolean, ): void { if (supportsUserTiming) { - if (__DEV__) { + if ( + __DEV__ && + typeof performance !== 'undefined' && + // $FlowFixMe[method-unbinding] + typeof performance.measure === 'function' + ) { const properties = []; for (let i = 0; i < recoverableErrors.length; i++) { const capturedValue = recoverableErrors[i]; @@ -715,7 +730,12 @@ export function logCommitErrored( passive: boolean, ): void { if (supportsUserTiming) { - if (__DEV__) { + if ( + __DEV__ && + typeof performance !== 'undefined' && + // $FlowFixMe[method-unbinding] + typeof performance.measure === 'function' + ) { const properties = []; for (let i = 0; i < errors.length; i++) { const capturedValue = errors[i];