Skip to content

Commit

Permalink
[Fiber] Log the Render/Commit phases and the gaps in between (#31016)
Browse files Browse the repository at this point in the history
A slight behavior change here too is that I now mark the start of the
commit phase before the BeforeMutationEffect phase. This affects
`<Profiler>` too.

The named sequences are as follows:

Render -> Suspended or Throttled -> Commit -> Waiting for Paint ->
Remaining Effects

The Suspended phase is only logged if we delay the Commit due to CSS /
images.

The Throttled phase is only logged if we delay the commit due to the
Suspense throttling timer.

<img width="1246" alt="Screenshot 2024-09-20 at 9 14 23 PM"
src="https://github.com/user-attachments/assets/8d01f444-bb85-472b-9b42-6157d92c81b4">

I don't yet log render phases that don't complete. I think I also need
to special case renders that or don't commit after being suspended.
  • Loading branch information
sebmarkbage authored Sep 23, 2024
1 parent 5d19e1c commit 4e9540e
Show file tree
Hide file tree
Showing 6 changed files with 184 additions and 44 deletions.
22 changes: 11 additions & 11 deletions packages/react-reconciler/src/ReactFiberCommitEffects.js
Original file line number Diff line number Diff line change
Expand Up @@ -899,7 +899,7 @@ function safelyCallDestroy(
function commitProfiler(
finishedWork: Fiber,
current: Fiber | null,
commitTime: number,
commitStartTime: number,
effectDuration: number,
) {
const {id, onCommit, onRender} = finishedWork.memoizedProps;
Expand All @@ -918,7 +918,7 @@ function commitProfiler(
finishedWork.actualDuration,
finishedWork.treeBaseDuration,
finishedWork.actualStartTime,
commitTime,
commitStartTime,
);
}

Expand All @@ -928,7 +928,7 @@ function commitProfiler(
finishedWork.memoizedProps.id,
phase,
effectDuration,
commitTime,
commitStartTime,
);
}
}
Expand All @@ -937,7 +937,7 @@ function commitProfiler(
export function commitProfilerUpdate(
finishedWork: Fiber,
current: Fiber | null,
commitTime: number,
commitStartTime: number,
effectDuration: number,
) {
if (enableProfilerTimer) {
Expand All @@ -948,11 +948,11 @@ export function commitProfilerUpdate(
commitProfiler,
finishedWork,
current,
commitTime,
commitStartTime,
effectDuration,
);
} else {
commitProfiler(finishedWork, current, commitTime, effectDuration);
commitProfiler(finishedWork, current, commitStartTime, effectDuration);
}
} catch (error) {
captureCommitPhaseError(finishedWork, finishedWork.return, error);
Expand All @@ -963,7 +963,7 @@ export function commitProfilerUpdate(
function commitProfilerPostCommitImpl(
finishedWork: Fiber,
current: Fiber | null,
commitTime: number,
commitStartTime: number,
passiveEffectDuration: number,
): void {
const {id, onPostCommit} = finishedWork.memoizedProps;
Expand All @@ -976,14 +976,14 @@ function commitProfilerPostCommitImpl(
}

if (typeof onPostCommit === 'function') {
onPostCommit(id, phase, passiveEffectDuration, commitTime);
onPostCommit(id, phase, passiveEffectDuration, commitStartTime);
}
}

export function commitProfilerPostCommit(
finishedWork: Fiber,
current: Fiber | null,
commitTime: number,
commitStartTime: number,
passiveEffectDuration: number,
) {
try {
Expand All @@ -993,14 +993,14 @@ export function commitProfilerPostCommit(
commitProfilerPostCommitImpl,
finishedWork,
current,
commitTime,
commitStartTime,
passiveEffectDuration,
);
} else {
commitProfilerPostCommitImpl(
finishedWork,
current,
commitTime,
commitStartTime,
passiveEffectDuration,
);
}
Expand Down
12 changes: 6 additions & 6 deletions packages/react-reconciler/src/ReactFiberCommitWork.js
Original file line number Diff line number Diff line change
Expand Up @@ -99,8 +99,7 @@ import {
Cloned,
} from './ReactFiberFlags';
import {
commitTime,
completeTime,
commitStartTime,
pushNestedEffectDurations,
popNestedEffectDurations,
bubbleNestedEffectDurations,
Expand Down Expand Up @@ -505,7 +504,7 @@ function commitLayoutEffectOnFiber(
commitProfilerUpdate(
finishedWork,
current,
commitTime,
commitStartTime,
profilerInstance.effectDuration,
);
} else {
Expand Down Expand Up @@ -2345,7 +2344,7 @@ export function reappearLayoutEffects(
commitProfilerUpdate(
finishedWork,
current,
commitTime,
commitStartTime,
profilerInstance.effectDuration,
);
} else {
Expand Down Expand Up @@ -2568,6 +2567,7 @@ export function commitPassiveMountEffects(
finishedWork: Fiber,
committedLanes: Lanes,
committedTransitions: Array<Transition> | null,
renderEndTime: number, // Profiling-only
): void {
resetComponentEffectTimers();

Expand All @@ -2576,7 +2576,7 @@ export function commitPassiveMountEffects(
finishedWork,
committedLanes,
committedTransitions,
enableProfilerTimer && enableComponentPerformanceTrack ? completeTime : 0,
enableProfilerTimer && enableComponentPerformanceTrack ? renderEndTime : 0,
);
}

Expand Down Expand Up @@ -2763,7 +2763,7 @@ function commitPassiveMountOnFiber(
finishedWork.alternate,
// This value will still reflect the previous commit phase.
// It does not get reset until the start of the next commit phase.
commitTime,
commitStartTime,
profilerInstance.passiveEffectDuration,
);
} else {
Expand Down
65 changes: 65 additions & 0 deletions packages/react-reconciler/src/ReactFiberPerformanceTrack.js
Original file line number Diff line number Diff line change
Expand Up @@ -164,3 +164,68 @@ export function logTransitionStart(
}
}
}

export function logRenderPhase(startTime: number, endTime: number): void {
if (supportsUserTiming) {
reusableComponentDevToolDetails.color = 'primary-dark';
reusableComponentOptions.start = startTime;
reusableComponentOptions.end = endTime;
performance.measure('Render', reusableComponentOptions);
}
}

export function logSuspenseThrottlePhase(
startTime: number,
endTime: number,
): void {
// This was inside a throttled Suspense boundary commit.
if (supportsUserTiming) {
reusableComponentDevToolDetails.color = 'secondary-light';
reusableComponentOptions.start = startTime;
reusableComponentOptions.end = endTime;
performance.measure('Throttled', reusableComponentOptions);
}
}

export function logSuspendedCommitPhase(
startTime: number,
endTime: number,
): void {
// This means the commit was suspended on CSS or images.
if (supportsUserTiming) {
reusableComponentDevToolDetails.color = 'secondary-light';
reusableComponentOptions.start = startTime;
reusableComponentOptions.end = endTime;
performance.measure('Suspended', reusableComponentOptions);
}
}

export function logCommitPhase(startTime: number, endTime: number): void {
if (supportsUserTiming) {
reusableComponentDevToolDetails.color = 'secondary-dark';
reusableComponentOptions.start = startTime;
reusableComponentOptions.end = endTime;
performance.measure('Commit', reusableComponentOptions);
}
}

export function logPaintYieldPhase(startTime: number, endTime: number): void {
if (supportsUserTiming) {
reusableComponentDevToolDetails.color = 'secondary-light';
reusableComponentOptions.start = startTime;
reusableComponentOptions.end = endTime;
performance.measure('Waiting for Paint', reusableComponentOptions);
}
}

export function logPassiveCommitPhase(
startTime: number,
endTime: number,
): void {
if (supportsUserTiming) {
reusableComponentDevToolDetails.color = 'secondary-dark';
reusableComponentOptions.start = startTime;
reusableComponentOptions.end = endTime;
performance.measure('Remaining Effects', reusableComponentOptions);
}
}
Loading

0 comments on commit 4e9540e

Please sign in to comment.