From e69babad86fa6628df3a6abedaea58762ea25d0a Mon Sep 17 00:00:00 2001 From: Sebastian Markbage Date: Tue, 16 Sep 2025 20:19:23 -0400 Subject: [PATCH 1/3] Clamp start times to simplify logic Also give a name to anonymous entries to help debugging --- .../src/ReactFiberPerformanceTrack.js | 76 ++++++++++++++----- 1 file changed, 55 insertions(+), 21 deletions(-) diff --git a/packages/react-reconciler/src/ReactFiberPerformanceTrack.js b/packages/react-reconciler/src/ReactFiberPerformanceTrack.js index 86f96d5d079..8fe2f2a8a95 100644 --- a/packages/react-reconciler/src/ReactFiberPerformanceTrack.js +++ b/packages/react-reconciler/src/ReactFiberPerformanceTrack.js @@ -636,11 +636,25 @@ export function logBlockingStart( ): void { if (supportsUserTiming) { currentTrack = 'Blocking'; + // Clamp start times + if (updateTime > 0) { + if (updateTime > renderStartTime) { + updateTime = renderStartTime; + } + } else { + updateTime = renderStartTime; + } + if (eventTime > 0) { + if (eventTime > updateTime) { + eventTime = updateTime; + } + } else { + eventTime = updateTime; + } // 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. - const eventEndTime = updateTime > 0 ? updateTime : renderStartTime; - if (eventTime > 0 && eventType !== null && eventEndTime > eventTime) { + if (eventType !== null && updateTime > eventTime) { // Log the time from the event timeStamp until we called setState. const color = eventIsRepeat ? 'secondary-light' : 'warning'; if (__DEV__ && debugTask) { @@ -648,9 +662,9 @@ export function logBlockingStart( // $FlowFixMe[method-unbinding] console.timeStamp.bind( console, - eventIsRepeat ? '' : 'Event: ' + eventType, + eventIsRepeat ? 'Consecutive' : 'Event: ' + eventType, eventTime, - eventEndTime, + updateTime, currentTrack, LANES_TRACK_GROUP, color, @@ -658,16 +672,16 @@ export function logBlockingStart( ); } else { console.timeStamp( - eventIsRepeat ? '' : 'Event: ' + eventType, + eventIsRepeat ? 'Consecutive' : 'Event: ' + eventType, eventTime, - eventEndTime, + updateTime, currentTrack, LANES_TRACK_GROUP, color, ); } } - if (updateTime > 0 && renderStartTime > updateTime) { + if (renderStartTime > updateTime) { // Log the time from when we called setState until we started rendering. const color = isSpawnedUpdate ? 'error' @@ -739,18 +753,39 @@ export function logTransitionStart( ): void { if (supportsUserTiming) { currentTrack = 'Transition'; - const eventEndTime = - startTime > 0 ? startTime : updateTime > 0 ? updateTime : renderStartTime; - if (eventTime > 0 && eventEndTime > eventTime && eventType !== null) { + // Clamp start times + if (updateTime > 0) { + if (updateTime > renderStartTime) { + updateTime = renderStartTime; + } + } else { + updateTime = renderStartTime; + } + if (startTime > 0) { + if (startTime > updateTime) { + startTime = updateTime; + } + } else { + startTime = updateTime; + } + if (eventTime > 0) { + if (eventTime > startTime) { + eventTime = startTime; + } + } else { + eventTime = startTime; + } + + if (startTime > eventTime && eventType !== null) { // Log the time from the event timeStamp until we started a transition. const color = eventIsRepeat ? 'secondary-light' : 'warning'; if (__DEV__ && debugTask) { debugTask.run( console.timeStamp.bind( console, - eventIsRepeat ? '' : 'Event: ' + eventType, + eventIsRepeat ? 'Consecutive' : 'Event: ' + eventType, eventTime, - eventEndTime, + startTime, currentTrack, LANES_TRACK_GROUP, color, @@ -758,17 +793,16 @@ export function logTransitionStart( ); } else { console.timeStamp( - eventIsRepeat ? '' : 'Event: ' + eventType, + eventIsRepeat ? 'Consecutive' : 'Event: ' + eventType, eventTime, - eventEndTime, + startTime, currentTrack, LANES_TRACK_GROUP, color, ); } } - const startEndTime = updateTime > 0 ? updateTime : renderStartTime; - if (startTime > 0 && startEndTime > startTime) { + if (updateTime > startTime) { // Log the time from when we started an async transition until we called setState or started rendering. // TODO: Ideally this would use the debugTask of the startTransition call perhaps. if (__DEV__ && debugTask) { @@ -778,7 +812,7 @@ export function logTransitionStart( console, 'Action', startTime, - startEndTime, + updateTime, currentTrack, LANES_TRACK_GROUP, 'primary-dark', @@ -788,14 +822,14 @@ export function logTransitionStart( console.timeStamp( 'Action', startTime, - startEndTime, + updateTime, currentTrack, LANES_TRACK_GROUP, 'primary-dark', ); } } - if (updateTime > 0 && renderStartTime > updateTime) { + if (renderStartTime > updateTime) { // Log the time from when we called setState until we started rendering. const label = isPingedUpdate ? 'Promise Resolved' @@ -1337,7 +1371,7 @@ export function logPaintYieldPhase( // $FlowFixMe[method-unbinding] console.timeStamp.bind( console, - delayedUntilPaint ? 'Waiting for Paint' : '', + delayedUntilPaint ? 'Waiting for Paint' : 'Waiting', startTime, endTime, currentTrack, @@ -1347,7 +1381,7 @@ export function logPaintYieldPhase( ); } else { console.timeStamp( - delayedUntilPaint ? 'Waiting for Paint' : '', + delayedUntilPaint ? 'Waiting for Paint' : 'Waiting', startTime, endTime, currentTrack, From 13d7460d74d042490d5d1b73c48521586c1913a0 Mon Sep 17 00:00:00 2001 From: Sebastian Markbage Date: Tue, 16 Sep 2025 21:25:58 -0400 Subject: [PATCH 2/3] Update clamp time when logging the event start time This ensures that we can't log another consecutive event on top of the first event which would overlap. Normally we do this in finalizeRender but it's currently possible to prepare a fresh stack that doesn't lead to a render which doesn't finalize. --- packages/react-reconciler/src/ReactProfilerTimer.js | 2 ++ 1 file changed, 2 insertions(+) diff --git a/packages/react-reconciler/src/ReactProfilerTimer.js b/packages/react-reconciler/src/ReactProfilerTimer.js index a1779235fc0..62b76ee6a40 100644 --- a/packages/react-reconciler/src/ReactProfilerTimer.js +++ b/packages/react-reconciler/src/ReactProfilerTimer.js @@ -246,6 +246,7 @@ export function clearBlockingTimers(): void { blockingUpdateComponentName = null; blockingSuspendedTime = -1.1; blockingEventIsRepeat = true; + blockingClampTime = now(); } export function startAsyncTransitionTimer(): void { @@ -282,6 +283,7 @@ export function clearTransitionTimers(): void { transitionUpdateType = 0; transitionSuspendedTime = -1.1; transitionEventIsRepeat = true; + transitionClampTime = now(); } export function clampBlockingTimers(finalTime: number): void { From 747deef71581b9f1b6dd608204372f57c19f017a Mon Sep 17 00:00:00 2001 From: Sebastian Markbage Date: Tue, 16 Sep 2025 21:39:42 -0400 Subject: [PATCH 3/3] Update test --- packages/react/src/__tests__/ReactProfiler-test.internal.js | 1 + 1 file changed, 1 insertion(+) diff --git a/packages/react/src/__tests__/ReactProfiler-test.internal.js b/packages/react/src/__tests__/ReactProfiler-test.internal.js index a8c00b2b562..ee1ec514e4d 100644 --- a/packages/react/src/__tests__/ReactProfiler-test.internal.js +++ b/packages/react/src/__tests__/ReactProfiler-test.internal.js @@ -179,6 +179,7 @@ describe(`onRender`, () => { 'read current time', 'read current time', 'read current time', + 'read current time', ]); } else { assertLog([