Skip to content

Commit

Permalink
Track suspended time when the render doesn't commit because it suspen…
Browse files Browse the repository at this point in the history
…ded (#31552)

When we suspend the render with delay, we won't do any more work until
we get some kind of another update/ping. It's because conceptually
something is suspended and then will update later. We need to highlight
this period to show why it's not doing any work. We fill the empty space
with "Suspended". This stops whenever the same lane group starts
rendering again. Clamped by the preceeding start time/event time/update
time.

<img width="902" alt="Screenshot 2024-11-15 at 1 01 29 PM"
src="https://github.com/user-attachments/assets/acf9dc9a-8fc3-4367-a8b0-d19f9c9eac73">

Ideally we would instead start the next render and suspend the work loop
at all places we suspend. In that mode this will instead show up as a
very long "Render" with a "Suspended" period instead highlighted in the
Components track as one component is suspended. We'll soon have that for
`use()` but not all updates so this covers the rest.

One issue with `useActionState` is that it is implemented as suspending
at the point of the `useActionState` which means that the period of the
Action shows up as a suspended render instead of as an Action which
happens for raw actions. This is not really how you conceptually think
about it so we need some special case for `useActionState`. In the
screenshot above, the first "Suspended" is actually awaiting an Action
and the second "Suspended" is awaiting the data from it.
  • Loading branch information
sebmarkbage authored Nov 19, 2024
1 parent 6f0dc29 commit 6177b18
Show file tree
Hide file tree
Showing 3 changed files with 90 additions and 18 deletions.
13 changes: 13 additions & 0 deletions packages/react-reconciler/src/ReactFiberPerformanceTrack.js
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down
80 changes: 62 additions & 18 deletions packages/react-reconciler/src/ReactFiberWorkLoop.js
Original file line number Diff line number Diff line change
Expand Up @@ -73,6 +73,7 @@ import {
logSuspendedRenderPhase,
logErroredRenderPhase,
logInconsistentRender,
logSuspendedWithDelayPhase,
logSuspenseThrottlePhase,
logSuspendedCommitPhase,
logCommitPhase,
Expand Down Expand Up @@ -239,12 +240,14 @@ import {
blockingEventTime,
blockingEventType,
blockingEventIsRepeat,
blockingSuspendedTime,
transitionClampTime,
transitionStartTime,
transitionUpdateTime,
transitionEventTime,
transitionEventType,
transitionEventIsRepeat,
transitionSuspendedTime,
clearBlockingTimers,
clearTransitionTimers,
clampBlockingTimers,
Expand All @@ -260,6 +263,7 @@ import {
stopProfilerTimerIfRunningAndRecordDuration,
stopProfilerTimerIfRunningAndRecordIncompleteDuration,
markUpdateAsRepeat,
trackSuspendedTime,
} from './ReactProfilerTimer';
import {setCurrentTrackFromLanes} from './ReactFiberPerformanceTrack';

Expand Down Expand Up @@ -954,6 +958,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,
Expand All @@ -968,7 +977,6 @@ export function performWorkOnRoot(
) {
if (enableProfilerTimer && enableComponentPerformanceTrack) {
setCurrentTrackFromLanes(lanes);
const renderEndTime = now();
logInconsistentRender(renderStartTime, renderEndTime);
finalizeRender(lanes, renderEndTime);
markUpdateAsRepeat(lanes);
Expand Down Expand Up @@ -996,7 +1004,6 @@ export function performWorkOnRoot(
if (errorRetryLanes !== NoLanes) {
if (enableProfilerTimer && enableComponentPerformanceTrack) {
setCurrentTrackFromLanes(lanes);
const renderEndTime = now();
logErroredRenderPhase(renderStartTime, renderEndTime);
finalizeRender(lanes, renderEndTime);
markUpdateAsRepeat(lanes);
Expand All @@ -1020,13 +1027,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);
}
Expand All @@ -1040,7 +1049,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);
Expand Down Expand Up @@ -1139,14 +1154,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.
Expand All @@ -1170,6 +1179,7 @@ function finishConcurrentRender(
setCurrentTrackFromLanes(lanes);
logSuspendedRenderPhase(renderStartTime, renderEndTime);
finalizeRender(lanes, renderEndTime);
trackSuspendedTime(lanes, renderEndTime);
}
const didAttemptEntireTree = !workInProgressRootDidSkipSuspendedSiblings;
markRootSuspended(
Expand Down Expand Up @@ -1705,30 +1715,64 @@ 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,
);
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,
Expand Down
15 changes: 15 additions & 0 deletions packages/react-reconciler/src/ReactProfilerTimer.js
Original file line number Diff line number Diff line change
Expand Up @@ -48,13 +48,15 @@ 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.
export let transitionUpdateTime: number = -1.1; // First transition setState scheduled.
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) {
Expand Down Expand Up @@ -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 {
Expand Down Expand Up @@ -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 {
Expand Down

0 comments on commit 6177b18

Please sign in to comment.