[Perf Tracks]: Always log effect that spawned blocking update (#34648)

We've observed some scenarios, where cascading update happens in an
effect that was shorter than 0.05ms. In this case, this effect won't be
displayed on a timeline, because of the threshold that we are using, but
it would be shown in entry properties or in a stack trace.

To avoid confusion, we should always log such effects.

Validated via manually changing the threshold to 100ms+ and observing
that only effects that triggered an update are visible on a timeline.
This commit is contained in:
Ruslan Lesiutin 2025-09-30 20:05:44 +01:00 committed by GitHub
parent d8a15c49a4
commit 063394cf82
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
2 changed files with 53 additions and 10 deletions

View File

@ -130,10 +130,13 @@ import {
popComponentEffectDuration, popComponentEffectDuration,
pushComponentEffectErrors, pushComponentEffectErrors,
popComponentEffectErrors, popComponentEffectErrors,
pushComponentEffectDidSpawnUpdate,
popComponentEffectDidSpawnUpdate,
componentEffectStartTime, componentEffectStartTime,
componentEffectEndTime, componentEffectEndTime,
componentEffectDuration, componentEffectDuration,
componentEffectErrors, componentEffectErrors,
componentEffectSpawnedUpdate,
} from './ReactProfilerTimer'; } from './ReactProfilerTimer';
import { import {
logComponentRender, logComponentRender,
@ -595,6 +598,7 @@ function commitLayoutEffectOnFiber(
const prevEffectStart = pushComponentEffectStart(); const prevEffectStart = pushComponentEffectStart();
const prevEffectDuration = pushComponentEffectDuration(); const prevEffectDuration = pushComponentEffectDuration();
const prevEffectErrors = pushComponentEffectErrors(); const prevEffectErrors = pushComponentEffectErrors();
const prevEffectDidSpawnUpdate = pushComponentEffectDidSpawnUpdate();
// When updating this function, also update reappearLayoutEffects, which does // When updating this function, also update reappearLayoutEffects, which does
// most of the same things when an offscreen tree goes from hidden -> visible. // most of the same things when an offscreen tree goes from hidden -> visible.
const flags = finishedWork.flags; const flags = finishedWork.flags;
@ -876,7 +880,7 @@ function commitLayoutEffectOnFiber(
componentEffectStartTime >= 0 && componentEffectStartTime >= 0 &&
componentEffectEndTime >= 0 componentEffectEndTime >= 0
) { ) {
if (componentEffectDuration > 0.05) { if (componentEffectSpawnedUpdate || componentEffectDuration > 0.05) {
logComponentEffect( logComponentEffect(
finishedWork, finishedWork,
componentEffectStartTime, componentEffectStartTime,
@ -909,6 +913,7 @@ function commitLayoutEffectOnFiber(
popComponentEffectStart(prevEffectStart); popComponentEffectStart(prevEffectStart);
popComponentEffectDuration(prevEffectDuration); popComponentEffectDuration(prevEffectDuration);
popComponentEffectErrors(prevEffectErrors); popComponentEffectErrors(prevEffectErrors);
popComponentEffectDidSpawnUpdate(prevEffectDidSpawnUpdate);
} }
function abortRootTransitions( function abortRootTransitions(
@ -1430,6 +1435,7 @@ function commitDeletionEffectsOnFiber(
const prevEffectStart = pushComponentEffectStart(); const prevEffectStart = pushComponentEffectStart();
const prevEffectDuration = pushComponentEffectDuration(); const prevEffectDuration = pushComponentEffectDuration();
const prevEffectErrors = pushComponentEffectErrors(); const prevEffectErrors = pushComponentEffectErrors();
const prevEffectDidSpawnUpdate = pushComponentEffectDidSpawnUpdate();
// The cases in this outer switch modify the stack before they traverse // The cases in this outer switch modify the stack before they traverse
// into their subtree. There are simpler cases in the inner switch // into their subtree. There are simpler cases in the inner switch
@ -1750,7 +1756,7 @@ function commitDeletionEffectsOnFiber(
(deletedFiber.mode & ProfileMode) !== NoMode && (deletedFiber.mode & ProfileMode) !== NoMode &&
componentEffectStartTime >= 0 && componentEffectStartTime >= 0 &&
componentEffectEndTime >= 0 && componentEffectEndTime >= 0 &&
componentEffectDuration > 0.05 (componentEffectSpawnedUpdate || componentEffectDuration > 0.05)
) { ) {
logComponentEffect( logComponentEffect(
deletedFiber, deletedFiber,
@ -1764,6 +1770,7 @@ function commitDeletionEffectsOnFiber(
popComponentEffectStart(prevEffectStart); popComponentEffectStart(prevEffectStart);
popComponentEffectDuration(prevEffectDuration); popComponentEffectDuration(prevEffectDuration);
popComponentEffectErrors(prevEffectErrors); popComponentEffectErrors(prevEffectErrors);
popComponentEffectDidSpawnUpdate(prevEffectDidSpawnUpdate);
} }
function commitSuspenseCallback(finishedWork: Fiber) { function commitSuspenseCallback(finishedWork: Fiber) {
@ -1987,6 +1994,7 @@ function commitMutationEffectsOnFiber(
const prevEffectStart = pushComponentEffectStart(); const prevEffectStart = pushComponentEffectStart();
const prevEffectDuration = pushComponentEffectDuration(); const prevEffectDuration = pushComponentEffectDuration();
const prevEffectErrors = pushComponentEffectErrors(); const prevEffectErrors = pushComponentEffectErrors();
const prevEffectDidSpawnUpdate = pushComponentEffectDidSpawnUpdate();
const current = finishedWork.alternate; const current = finishedWork.alternate;
const flags = finishedWork.flags; const flags = finishedWork.flags;
@ -2611,7 +2619,7 @@ function commitMutationEffectsOnFiber(
componentEffectStartTime >= 0 && componentEffectStartTime >= 0 &&
componentEffectEndTime >= 0 componentEffectEndTime >= 0
) { ) {
if (componentEffectDuration > 0.05) { if (componentEffectSpawnedUpdate || componentEffectDuration > 0.05) {
logComponentEffect( logComponentEffect(
finishedWork, finishedWork,
componentEffectStartTime, componentEffectStartTime,
@ -2644,6 +2652,7 @@ function commitMutationEffectsOnFiber(
popComponentEffectStart(prevEffectStart); popComponentEffectStart(prevEffectStart);
popComponentEffectDuration(prevEffectDuration); popComponentEffectDuration(prevEffectDuration);
popComponentEffectErrors(prevEffectErrors); popComponentEffectErrors(prevEffectErrors);
popComponentEffectDidSpawnUpdate(prevEffectDidSpawnUpdate);
} }
function commitReconciliationEffects( function commitReconciliationEffects(
@ -2900,6 +2909,7 @@ export function disappearLayoutEffects(finishedWork: Fiber) {
const prevEffectStart = pushComponentEffectStart(); const prevEffectStart = pushComponentEffectStart();
const prevEffectDuration = pushComponentEffectDuration(); const prevEffectDuration = pushComponentEffectDuration();
const prevEffectErrors = pushComponentEffectErrors(); const prevEffectErrors = pushComponentEffectErrors();
const prevEffectDidSpawnUpdate = pushComponentEffectDidSpawnUpdate();
switch (finishedWork.tag) { switch (finishedWork.tag) {
case FunctionComponent: case FunctionComponent:
case ForwardRef: case ForwardRef:
@ -2990,7 +3000,7 @@ export function disappearLayoutEffects(finishedWork: Fiber) {
(finishedWork.mode & ProfileMode) !== NoMode && (finishedWork.mode & ProfileMode) !== NoMode &&
componentEffectStartTime >= 0 && componentEffectStartTime >= 0 &&
componentEffectEndTime >= 0 && componentEffectEndTime >= 0 &&
componentEffectDuration > 0.05 (componentEffectSpawnedUpdate || componentEffectDuration > 0.05)
) { ) {
logComponentEffect( logComponentEffect(
finishedWork, finishedWork,
@ -3004,6 +3014,7 @@ export function disappearLayoutEffects(finishedWork: Fiber) {
popComponentEffectStart(prevEffectStart); popComponentEffectStart(prevEffectStart);
popComponentEffectDuration(prevEffectDuration); popComponentEffectDuration(prevEffectDuration);
popComponentEffectErrors(prevEffectErrors); popComponentEffectErrors(prevEffectErrors);
popComponentEffectDidSpawnUpdate(prevEffectDidSpawnUpdate);
} }
function recursivelyTraverseDisappearLayoutEffects(parentFiber: Fiber) { function recursivelyTraverseDisappearLayoutEffects(parentFiber: Fiber) {
@ -3027,6 +3038,7 @@ export function reappearLayoutEffects(
const prevEffectStart = pushComponentEffectStart(); const prevEffectStart = pushComponentEffectStart();
const prevEffectDuration = pushComponentEffectDuration(); const prevEffectDuration = pushComponentEffectDuration();
const prevEffectErrors = pushComponentEffectErrors(); const prevEffectErrors = pushComponentEffectErrors();
const prevEffectDidSpawnUpdate = pushComponentEffectDidSpawnUpdate();
// Turn on layout effects in a tree that previously disappeared. // Turn on layout effects in a tree that previously disappeared.
const flags = finishedWork.flags; const flags = finishedWork.flags;
switch (finishedWork.tag) { switch (finishedWork.tag) {
@ -3224,7 +3236,7 @@ export function reappearLayoutEffects(
(finishedWork.mode & ProfileMode) !== NoMode && (finishedWork.mode & ProfileMode) !== NoMode &&
componentEffectStartTime >= 0 && componentEffectStartTime >= 0 &&
componentEffectEndTime >= 0 && componentEffectEndTime >= 0 &&
componentEffectDuration > 0.05 (componentEffectSpawnedUpdate || componentEffectDuration > 0.05)
) { ) {
logComponentEffect( logComponentEffect(
finishedWork, finishedWork,
@ -3238,6 +3250,7 @@ export function reappearLayoutEffects(
popComponentEffectStart(prevEffectStart); popComponentEffectStart(prevEffectStart);
popComponentEffectDuration(prevEffectDuration); popComponentEffectDuration(prevEffectDuration);
popComponentEffectErrors(prevEffectErrors); popComponentEffectErrors(prevEffectErrors);
popComponentEffectDidSpawnUpdate(prevEffectDidSpawnUpdate);
} }
function recursivelyTraverseReappearLayoutEffects( function recursivelyTraverseReappearLayoutEffects(
@ -3489,6 +3502,7 @@ function commitPassiveMountOnFiber(
const prevEffectStart = pushComponentEffectStart(); const prevEffectStart = pushComponentEffectStart();
const prevEffectDuration = pushComponentEffectDuration(); const prevEffectDuration = pushComponentEffectDuration();
const prevEffectErrors = pushComponentEffectErrors(); const prevEffectErrors = pushComponentEffectErrors();
const prevEffectDidSpawnUpdate = pushComponentEffectDidSpawnUpdate();
const prevDeepEquality = pushDeepEquality(); const prevDeepEquality = pushDeepEquality();
const isViewTransitionEligible = enableViewTransition const isViewTransitionEligible = enableViewTransition
@ -4060,7 +4074,7 @@ function commitPassiveMountOnFiber(
} }
} }
if (componentEffectStartTime >= 0 && componentEffectEndTime >= 0) { if (componentEffectStartTime >= 0 && componentEffectEndTime >= 0) {
if (componentEffectDuration > 0.05) { if (componentEffectSpawnedUpdate || componentEffectDuration > 0.05) {
logComponentEffect( logComponentEffect(
finishedWork, finishedWork,
componentEffectStartTime, componentEffectStartTime,
@ -4082,6 +4096,7 @@ function commitPassiveMountOnFiber(
popComponentEffectStart(prevEffectStart); popComponentEffectStart(prevEffectStart);
popComponentEffectDuration(prevEffectDuration); popComponentEffectDuration(prevEffectDuration);
popComponentEffectErrors(prevEffectErrors); popComponentEffectErrors(prevEffectErrors);
popComponentEffectDidSpawnUpdate(prevEffectDidSpawnUpdate);
popDeepEquality(prevDeepEquality); popDeepEquality(prevDeepEquality);
} }
@ -4144,6 +4159,7 @@ export function reconnectPassiveEffects(
const prevEffectStart = pushComponentEffectStart(); const prevEffectStart = pushComponentEffectStart();
const prevEffectDuration = pushComponentEffectDuration(); const prevEffectDuration = pushComponentEffectDuration();
const prevEffectErrors = pushComponentEffectErrors(); const prevEffectErrors = pushComponentEffectErrors();
const prevEffectDidSpawnUpdate = pushComponentEffectDidSpawnUpdate();
const prevDeepEquality = pushDeepEquality(); const prevDeepEquality = pushDeepEquality();
// If this component rendered in Profiling mode (DEV or in Profiler component) then log its // If this component rendered in Profiling mode (DEV or in Profiler component) then log its
@ -4334,7 +4350,7 @@ export function reconnectPassiveEffects(
(finishedWork.mode & ProfileMode) !== NoMode && (finishedWork.mode & ProfileMode) !== NoMode &&
componentEffectStartTime >= 0 && componentEffectStartTime >= 0 &&
componentEffectEndTime >= 0 && componentEffectEndTime >= 0 &&
componentEffectDuration > 0.05 (componentEffectSpawnedUpdate || componentEffectDuration > 0.05)
) { ) {
logComponentEffect( logComponentEffect(
finishedWork, finishedWork,
@ -4348,6 +4364,7 @@ export function reconnectPassiveEffects(
popComponentEffectStart(prevEffectStart); popComponentEffectStart(prevEffectStart);
popComponentEffectDuration(prevEffectDuration); popComponentEffectDuration(prevEffectDuration);
popComponentEffectErrors(prevEffectErrors); popComponentEffectErrors(prevEffectErrors);
popComponentEffectDidSpawnUpdate(prevEffectDidSpawnUpdate);
popDeepEquality(prevDeepEquality); popDeepEquality(prevDeepEquality);
} }
@ -4737,6 +4754,7 @@ function commitPassiveUnmountOnFiber(finishedWork: Fiber): void {
const prevEffectStart = pushComponentEffectStart(); const prevEffectStart = pushComponentEffectStart();
const prevEffectDuration = pushComponentEffectDuration(); const prevEffectDuration = pushComponentEffectDuration();
const prevEffectErrors = pushComponentEffectErrors(); const prevEffectErrors = pushComponentEffectErrors();
const prevEffectDidSpawnUpdate = pushComponentEffectDidSpawnUpdate();
switch (finishedWork.tag) { switch (finishedWork.tag) {
case FunctionComponent: case FunctionComponent:
case ForwardRef: case ForwardRef:
@ -4833,7 +4851,7 @@ function commitPassiveUnmountOnFiber(finishedWork: Fiber): void {
(finishedWork.mode & ProfileMode) !== NoMode && (finishedWork.mode & ProfileMode) !== NoMode &&
componentEffectStartTime >= 0 && componentEffectStartTime >= 0 &&
componentEffectEndTime >= 0 && componentEffectEndTime >= 0 &&
componentEffectDuration > 0.05 (componentEffectSpawnedUpdate || componentEffectDuration > 0.05)
) { ) {
logComponentEffect( logComponentEffect(
finishedWork, finishedWork,
@ -4846,6 +4864,7 @@ function commitPassiveUnmountOnFiber(finishedWork: Fiber): void {
popComponentEffectStart(prevEffectStart); popComponentEffectStart(prevEffectStart);
popComponentEffectDuration(prevEffectDuration); popComponentEffectDuration(prevEffectDuration);
popComponentEffectDidSpawnUpdate(prevEffectDidSpawnUpdate);
popComponentEffectErrors(prevEffectErrors); popComponentEffectErrors(prevEffectErrors);
} }
@ -4903,6 +4922,7 @@ export function disconnectPassiveEffect(finishedWork: Fiber): void {
const prevEffectStart = pushComponentEffectStart(); const prevEffectStart = pushComponentEffectStart();
const prevEffectDuration = pushComponentEffectDuration(); const prevEffectDuration = pushComponentEffectDuration();
const prevEffectErrors = pushComponentEffectErrors(); const prevEffectErrors = pushComponentEffectErrors();
const prevEffectDidSpawnUpdate = pushComponentEffectDidSpawnUpdate();
switch (finishedWork.tag) { switch (finishedWork.tag) {
case FunctionComponent: case FunctionComponent:
@ -4942,7 +4962,7 @@ export function disconnectPassiveEffect(finishedWork: Fiber): void {
(finishedWork.mode & ProfileMode) !== NoMode && (finishedWork.mode & ProfileMode) !== NoMode &&
componentEffectStartTime >= 0 && componentEffectStartTime >= 0 &&
componentEffectEndTime >= 0 && componentEffectEndTime >= 0 &&
componentEffectDuration > 0.05 (componentEffectSpawnedUpdate || componentEffectDuration > 0.05)
) { ) {
logComponentEffect( logComponentEffect(
finishedWork, finishedWork,
@ -4955,6 +4975,7 @@ export function disconnectPassiveEffect(finishedWork: Fiber): void {
popComponentEffectStart(prevEffectStart); popComponentEffectStart(prevEffectStart);
popComponentEffectDuration(prevEffectDuration); popComponentEffectDuration(prevEffectDuration);
popComponentEffectDidSpawnUpdate(prevEffectDidSpawnUpdate);
popComponentEffectErrors(prevEffectErrors); popComponentEffectErrors(prevEffectErrors);
} }
@ -5016,6 +5037,7 @@ function commitPassiveUnmountInsideDeletedTreeOnFiber(
const prevEffectStart = pushComponentEffectStart(); const prevEffectStart = pushComponentEffectStart();
const prevEffectDuration = pushComponentEffectDuration(); const prevEffectDuration = pushComponentEffectDuration();
const prevEffectErrors = pushComponentEffectErrors(); const prevEffectErrors = pushComponentEffectErrors();
const prevEffectDidSpawnUpdate = pushComponentEffectDidSpawnUpdate();
switch (current.tag) { switch (current.tag) {
case FunctionComponent: case FunctionComponent:
case ForwardRef: case ForwardRef:
@ -5135,7 +5157,7 @@ function commitPassiveUnmountInsideDeletedTreeOnFiber(
(current.mode & ProfileMode) !== NoMode && (current.mode & ProfileMode) !== NoMode &&
componentEffectStartTime >= 0 && componentEffectStartTime >= 0 &&
componentEffectEndTime >= 0 && componentEffectEndTime >= 0 &&
componentEffectDuration > 0.05 (componentEffectSpawnedUpdate || componentEffectDuration > 0.05)
) { ) {
logComponentEffect( logComponentEffect(
current, current,
@ -5148,6 +5170,7 @@ function commitPassiveUnmountInsideDeletedTreeOnFiber(
popComponentEffectStart(prevEffectStart); popComponentEffectStart(prevEffectStart);
popComponentEffectDuration(prevEffectDuration); popComponentEffectDuration(prevEffectDuration);
popComponentEffectDidSpawnUpdate(prevEffectDidSpawnUpdate);
popComponentEffectErrors(prevEffectErrors); popComponentEffectErrors(prevEffectErrors);
} }

View File

@ -64,6 +64,7 @@ export let componentEffectDuration: number = -0;
export let componentEffectStartTime: number = -1.1; export let componentEffectStartTime: number = -1.1;
export let componentEffectEndTime: number = -1.1; export let componentEffectEndTime: number = -1.1;
export let componentEffectErrors: null | Array<CapturedValue<mixed>> = null; export let componentEffectErrors: null | Array<CapturedValue<mixed>> = null;
export let componentEffectSpawnedUpdate: boolean = false;
export let blockingClampTime: number = -0; export let blockingClampTime: number = -0;
export let blockingUpdateTime: number = -1.1; // First sync setState scheduled. export let blockingUpdateTime: number = -1.1; // First sync setState scheduled.
@ -153,6 +154,7 @@ export function startUpdateTimerByLane(
blockingUpdateComponentName = getComponentNameFromFiber(fiber); blockingUpdateComponentName = getComponentNameFromFiber(fiber);
} }
if (isAlreadyRendering()) { if (isAlreadyRendering()) {
componentEffectSpawnedUpdate = true;
blockingUpdateType = SPAWNED_UPDATE; blockingUpdateType = SPAWNED_UPDATE;
} }
const newEventTime = resolveEventTimeStamp(); const newEventTime = resolveEventTimeStamp();
@ -495,6 +497,24 @@ export function popComponentEffectErrors(
componentEffectErrors = prevErrors; componentEffectErrors = prevErrors;
} }
export function pushComponentEffectDidSpawnUpdate(): boolean {
if (!enableProfilerTimer || !enableProfilerCommitHooks) {
return false;
}
const prev = componentEffectSpawnedUpdate;
componentEffectSpawnedUpdate = false; // Reset.
return prev;
}
export function popComponentEffectDidSpawnUpdate(previousValue: boolean): void {
if (!enableProfilerTimer || !enableProfilerCommitHooks) {
return;
}
componentEffectSpawnedUpdate = previousValue;
}
/** /**
* Tracks whether the current update was a nested/cascading update (scheduled from a layout effect). * Tracks whether the current update was a nested/cascading update (scheduled from a layout effect).
* *