From 3da0519528d37b7dc5fb3fa44a8a1df930c4344a Mon Sep 17 00:00:00 2001 From: Sebastian Markbage Date: Fri, 15 Nov 2024 12:38:24 -0500 Subject: [PATCH 1/2] Unify renderEndTime --- .../src/ReactFiberWorkLoop.js | 27 +++++++++++-------- 1 file changed, 16 insertions(+), 11 deletions(-) diff --git a/packages/react-reconciler/src/ReactFiberWorkLoop.js b/packages/react-reconciler/src/ReactFiberWorkLoop.js index 7a5409a73559a..91bc681e18b6e 100644 --- a/packages/react-reconciler/src/ReactFiberWorkLoop.js +++ b/packages/react-reconciler/src/ReactFiberWorkLoop.js @@ -948,6 +948,11 @@ export function performWorkOnRoot( } break; } else { + let renderEndTime = 0; + if (enableProfilerTimer && enableComponentPerformanceTrack) { + renderEndTime = now(); + } + // The render completed. // Check if this render may have yielded to a concurrent event, and if so, @@ -962,7 +967,6 @@ export function performWorkOnRoot( ) { if (enableProfilerTimer && enableComponentPerformanceTrack) { setCurrentTrackFromLanes(lanes); - const renderEndTime = now(); logInconsistentRender(renderStartTime, renderEndTime); finalizeRender(lanes, renderEndTime); markUpdateAsRepeat(lanes); @@ -990,7 +994,6 @@ export function performWorkOnRoot( if (errorRetryLanes !== NoLanes) { if (enableProfilerTimer && enableComponentPerformanceTrack) { setCurrentTrackFromLanes(lanes); - const renderEndTime = now(); logErroredRenderPhase(renderStartTime, renderEndTime); finalizeRender(lanes, renderEndTime); markUpdateAsRepeat(lanes); @@ -1014,13 +1017,15 @@ export function performWorkOnRoot( continue; } else { // The root errored yet again. Proceed to commit the tree. + if (enableProfilerTimer && enableComponentPerformanceTrack) { + renderEndTime = now(); + } } } } if (exitStatus === RootFatalErrored) { if (enableProfilerTimer && enableComponentPerformanceTrack) { setCurrentTrackFromLanes(lanes); - const renderEndTime = now(); logErroredRenderPhase(renderStartTime, renderEndTime); finalizeRender(lanes, renderEndTime); } @@ -1034,7 +1039,13 @@ export function performWorkOnRoot( // We now have a consistent tree. The next step is either to commit it, // or, if something suspended, wait to commit it after a timeout. - finishConcurrentRender(root, exitStatus, finishedWork, lanes); + finishConcurrentRender( + root, + exitStatus, + finishedWork, + lanes, + renderEndTime, + ); } break; } while (true); @@ -1133,14 +1144,8 @@ function finishConcurrentRender( exitStatus: RootExitStatus, finishedWork: Fiber, lanes: Lanes, + renderEndTime: number // Profiling-only ) { - let renderEndTime = 0; - if (enableProfilerTimer && enableComponentPerformanceTrack) { - // Track when we finished the last unit of work, before we actually commit it. - // The commit can be suspended/blocked until we commit it. - renderEndTime = now(); - } - // TODO: The fact that most of these branches are identical suggests that some // of the exit statuses are not best modeled as exit statuses and should be // tracked orthogonally. From 490a279ccf77d410a9817af9740f07ce245aac28 Mon Sep 17 00:00:00 2001 From: Sebastian Markbage Date: Fri, 15 Nov 2024 12:57:38 -0500 Subject: [PATCH 2/2] Track suspended time when the render doesn't commit because it suspended This stops whenever the same lane group starts rendering again. Clamped by the preceeding start time/event time/update time. --- .../src/ReactFiberPerformanceTrack.js | 13 +++++ .../src/ReactFiberWorkLoop.js | 55 ++++++++++++++++--- .../src/ReactProfilerTimer.js | 15 +++++ 3 files changed, 75 insertions(+), 8 deletions(-) diff --git a/packages/react-reconciler/src/ReactFiberPerformanceTrack.js b/packages/react-reconciler/src/ReactFiberPerformanceTrack.js index f43d296a8ad61..7d074d545664a 100644 --- a/packages/react-reconciler/src/ReactFiberPerformanceTrack.js +++ b/packages/react-reconciler/src/ReactFiberPerformanceTrack.js @@ -222,6 +222,19 @@ export function logSuspendedRenderPhase( } } +export function logSuspendedWithDelayPhase( + startTime: number, + endTime: number, +): void { + // This means the render was suspended and cannot commit until it gets unblocked. + if (supportsUserTiming) { + reusableLaneDevToolDetails.color = 'primary-dark'; + reusableLaneOptions.start = startTime; + reusableLaneOptions.end = endTime; + performance.measure('Suspended', reusableLaneOptions); + } +} + export function logErroredRenderPhase( startTime: number, endTime: number, diff --git a/packages/react-reconciler/src/ReactFiberWorkLoop.js b/packages/react-reconciler/src/ReactFiberWorkLoop.js index 91bc681e18b6e..6c7644909b022 100644 --- a/packages/react-reconciler/src/ReactFiberWorkLoop.js +++ b/packages/react-reconciler/src/ReactFiberWorkLoop.js @@ -73,6 +73,7 @@ import { logSuspendedRenderPhase, logErroredRenderPhase, logInconsistentRender, + logSuspendedWithDelayPhase, logSuspenseThrottlePhase, logSuspendedCommitPhase, logCommitPhase, @@ -239,12 +240,14 @@ import { blockingEventTime, blockingEventType, blockingEventIsRepeat, + blockingSuspendedTime, transitionClampTime, transitionStartTime, transitionUpdateTime, transitionEventTime, transitionEventType, transitionEventIsRepeat, + transitionSuspendedTime, clearBlockingTimers, clearTransitionTimers, clampBlockingTimers, @@ -260,6 +263,7 @@ import { stopProfilerTimerIfRunningAndRecordDuration, stopProfilerTimerIfRunningAndRecordIncompleteDuration, markUpdateAsRepeat, + trackSuspendedTime, } from './ReactProfilerTimer'; import {setCurrentTrackFromLanes} from './ReactFiberPerformanceTrack'; @@ -1144,7 +1148,7 @@ function finishConcurrentRender( exitStatus: RootExitStatus, finishedWork: Fiber, lanes: Lanes, - renderEndTime: number // Profiling-only + renderEndTime: number, // Profiling-only ) { // TODO: The fact that most of these branches are identical suggests that some // of the exit statuses are not best modeled as exit statuses and should be @@ -1169,6 +1173,7 @@ function finishConcurrentRender( setCurrentTrackFromLanes(lanes); logSuspendedRenderPhase(renderStartTime, renderEndTime); finalizeRender(lanes, renderEndTime); + trackSuspendedTime(lanes, renderEndTime); } const didAttemptEntireTree = !workInProgressRootDidSkipSuspendedSiblings; markRootSuspended( @@ -1704,13 +1709,29 @@ function prepareFreshStack(root: FiberRoot, lanes: Lanes): Fiber { } if (includesSyncLane(lanes) || includesBlockingLane(lanes)) { - logBlockingStart( + const clampedUpdateTime = blockingUpdateTime >= 0 && blockingUpdateTime < blockingClampTime ? blockingClampTime - : blockingUpdateTime, + : blockingUpdateTime; + const clampedEventTime = blockingEventTime >= 0 && blockingEventTime < blockingClampTime ? blockingClampTime - : blockingEventTime, + : blockingEventTime; + if (blockingSuspendedTime >= 0) { + setCurrentTrackFromLanes(lanes); + logSuspendedWithDelayPhase( + blockingSuspendedTime, + // Clamp the suspended time to the first event/update. + clampedEventTime >= 0 + ? clampedEventTime + : clampedUpdateTime >= 0 + ? clampedUpdateTime + : renderStartTime, + ); + } + logBlockingStart( + clampedUpdateTime, + clampedEventTime, blockingEventType, blockingEventIsRepeat, renderStartTime, @@ -1718,16 +1739,34 @@ function prepareFreshStack(root: FiberRoot, lanes: Lanes): Fiber { clearBlockingTimers(); } if (includesTransitionLane(lanes)) { - logTransitionStart( + const clampedStartTime = transitionStartTime >= 0 && transitionStartTime < transitionClampTime ? transitionClampTime - : transitionStartTime, + : transitionStartTime; + const clampedUpdateTime = transitionUpdateTime >= 0 && transitionUpdateTime < transitionClampTime ? transitionClampTime - : transitionUpdateTime, + : transitionUpdateTime; + const clampedEventTime = transitionEventTime >= 0 && transitionEventTime < transitionClampTime ? transitionClampTime - : transitionEventTime, + : transitionEventTime; + if (transitionSuspendedTime >= 0) { + setCurrentTrackFromLanes(lanes); + logSuspendedWithDelayPhase( + transitionSuspendedTime, + // Clamp the suspended time to the first event/update. + clampedEventTime >= 0 + ? clampedEventTime + : clampedUpdateTime >= 0 + ? clampedUpdateTime + : renderStartTime, + ); + } + logTransitionStart( + clampedStartTime, + clampedUpdateTime, + clampedEventTime, transitionEventType, transitionEventIsRepeat, renderStartTime, diff --git a/packages/react-reconciler/src/ReactProfilerTimer.js b/packages/react-reconciler/src/ReactProfilerTimer.js index 87d7c0324bcb5..da4e1f7bf356b 100644 --- a/packages/react-reconciler/src/ReactProfilerTimer.js +++ b/packages/react-reconciler/src/ReactProfilerTimer.js @@ -48,6 +48,7 @@ export let blockingUpdateTime: number = -1.1; // First sync setState scheduled. export let blockingEventTime: number = -1.1; // Event timeStamp of the first setState. export let blockingEventType: null | string = null; // Event type of the first setState. export let blockingEventIsRepeat: boolean = false; +export let blockingSuspendedTime: number = -1.1; // TODO: This should really be one per Transition lane. export let transitionClampTime: number = -0; export let transitionStartTime: number = -1.1; // First startTransition call before setState. @@ -55,6 +56,7 @@ export let transitionUpdateTime: number = -1.1; // First transition setState sch export let transitionEventTime: number = -1.1; // Event timeStamp of the first transition. export let transitionEventType: null | string = null; // Event type of the first transition. export let transitionEventIsRepeat: boolean = false; +export let transitionSuspendedTime: number = -1.1; export function startUpdateTimerByLane(lane: Lane): void { if (!enableProfilerTimer || !enableComponentPerformanceTrack) { @@ -100,8 +102,20 @@ export function markUpdateAsRepeat(lanes: Lanes): void { } } +export function trackSuspendedTime(lanes: Lanes, renderEndTime: number) { + if (!enableProfilerTimer || !enableComponentPerformanceTrack) { + return; + } + if (includesSyncLane(lanes) || includesBlockingLane(lanes)) { + blockingSuspendedTime = renderEndTime; + } else if (includesTransitionLane(lanes)) { + transitionSuspendedTime = renderEndTime; + } +} + export function clearBlockingTimers(): void { blockingUpdateTime = -1.1; + blockingSuspendedTime = -1.1; } export function startAsyncTransitionTimer(): void { @@ -145,6 +159,7 @@ export function clearAsyncTransitionTimer(): void { export function clearTransitionTimers(): void { transitionStartTime = -1.1; transitionUpdateTime = -1.1; + transitionSuspendedTime = -1.1; } export function clampBlockingTimers(finalTime: number): void {