Skip to content

Commit 063394c

Browse files
hoxyqhoxyq
authored
[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.
1 parent d8a15c4 commit 063394c

File tree

2 files changed

+53
-10
lines changed

2 files changed

+53
-10
lines changed

‎packages/react-reconciler/src/ReactFiberCommitWork.js‎

Lines changed: 33 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -130,10 +130,13 @@ import {
130130
popComponentEffectDuration,
131131
pushComponentEffectErrors,
132132
popComponentEffectErrors,
133+
pushComponentEffectDidSpawnUpdate,
134+
popComponentEffectDidSpawnUpdate,
133135
componentEffectStartTime,
134136
componentEffectEndTime,
135137
componentEffectDuration,
136138
componentEffectErrors,
139+
componentEffectSpawnedUpdate,
137140
} from './ReactProfilerTimer';
138141
import {
139142
logComponentRender,
@@ -595,6 +598,7 @@ function commitLayoutEffectOnFiber(
595598
const prevEffectStart = pushComponentEffectStart();
596599
const prevEffectDuration = pushComponentEffectDuration();
597600
const prevEffectErrors = pushComponentEffectErrors();
601+
const prevEffectDidSpawnUpdate = pushComponentEffectDidSpawnUpdate();
598602
// When updating this function, also update reappearLayoutEffects, which does
599603
// most of the same things when an offscreen tree goes from hidden -> visible.
600604
const flags = finishedWork.flags;
@@ -876,7 +880,7 @@ function commitLayoutEffectOnFiber(
876880
componentEffectStartTime >= 0 &&
877881
componentEffectEndTime >= 0
878882
) {
879-
if (componentEffectDuration > 0.05) {
883+
if (componentEffectSpawnedUpdate || componentEffectDuration > 0.05) {
880884
logComponentEffect(
881885
finishedWork,
882886
componentEffectStartTime,
@@ -909,6 +913,7 @@ function commitLayoutEffectOnFiber(
909913
popComponentEffectStart(prevEffectStart);
910914
popComponentEffectDuration(prevEffectDuration);
911915
popComponentEffectErrors(prevEffectErrors);
916+
popComponentEffectDidSpawnUpdate(prevEffectDidSpawnUpdate);
912917
}
913918

914919
function abortRootTransitions(
@@ -1430,6 +1435,7 @@ function commitDeletionEffectsOnFiber(
14301435
const prevEffectStart = pushComponentEffectStart();
14311436
const prevEffectDuration = pushComponentEffectDuration();
14321437
const prevEffectErrors = pushComponentEffectErrors();
1438+
const prevEffectDidSpawnUpdate = pushComponentEffectDidSpawnUpdate();
14331439

14341440
// The cases in this outer switch modify the stack before they traverse
14351441
// into their subtree. There are simpler cases in the inner switch
@@ -1750,7 +1756,7 @@ function commitDeletionEffectsOnFiber(
17501756
(deletedFiber.mode & ProfileMode) !== NoMode &&
17511757
componentEffectStartTime >= 0 &&
17521758
componentEffectEndTime >= 0 &&
1753-
componentEffectDuration > 0.05
1759+
(componentEffectSpawnedUpdate || componentEffectDuration > 0.05)
17541760
) {
17551761
logComponentEffect(
17561762
deletedFiber,
@@ -1764,6 +1770,7 @@ function commitDeletionEffectsOnFiber(
17641770
popComponentEffectStart(prevEffectStart);
17651771
popComponentEffectDuration(prevEffectDuration);
17661772
popComponentEffectErrors(prevEffectErrors);
1773+
popComponentEffectDidSpawnUpdate(prevEffectDidSpawnUpdate);
17671774
}
17681775

17691776
function commitSuspenseCallback(finishedWork: Fiber) {
@@ -1987,6 +1994,7 @@ function commitMutationEffectsOnFiber(
19871994
const prevEffectStart = pushComponentEffectStart();
19881995
const prevEffectDuration = pushComponentEffectDuration();
19891996
const prevEffectErrors = pushComponentEffectErrors();
1997+
const prevEffectDidSpawnUpdate = pushComponentEffectDidSpawnUpdate();
19901998
const current = finishedWork.alternate;
19911999
const flags = finishedWork.flags;
19922000

@@ -2611,7 +2619,7 @@ function commitMutationEffectsOnFiber(
26112619
componentEffectStartTime >= 0 &&
26122620
componentEffectEndTime >= 0
26132621
) {
2614-
if (componentEffectDuration > 0.05) {
2622+
if (componentEffectSpawnedUpdate || componentEffectDuration > 0.05) {
26152623
logComponentEffect(
26162624
finishedWork,
26172625
componentEffectStartTime,
@@ -2644,6 +2652,7 @@ function commitMutationEffectsOnFiber(
26442652
popComponentEffectStart(prevEffectStart);
26452653
popComponentEffectDuration(prevEffectDuration);
26462654
popComponentEffectErrors(prevEffectErrors);
2655+
popComponentEffectDidSpawnUpdate(prevEffectDidSpawnUpdate);
26472656
}
26482657

26492658
function commitReconciliationEffects(
@@ -2900,6 +2909,7 @@ export function disappearLayoutEffects(finishedWork: Fiber) {
29002909
const prevEffectStart = pushComponentEffectStart();
29012910
const prevEffectDuration = pushComponentEffectDuration();
29022911
const prevEffectErrors = pushComponentEffectErrors();
2912+
const prevEffectDidSpawnUpdate = pushComponentEffectDidSpawnUpdate();
29032913
switch (finishedWork.tag) {
29042914
case FunctionComponent:
29052915
case ForwardRef:
@@ -2990,7 +3000,7 @@ export function disappearLayoutEffects(finishedWork: Fiber) {
29903000
(finishedWork.mode & ProfileMode) !== NoMode &&
29913001
componentEffectStartTime >= 0 &&
29923002
componentEffectEndTime >= 0 &&
2993-
componentEffectDuration > 0.05
3003+
(componentEffectSpawnedUpdate || componentEffectDuration > 0.05)
29943004
) {
29953005
logComponentEffect(
29963006
finishedWork,
@@ -3004,6 +3014,7 @@ export function disappearLayoutEffects(finishedWork: Fiber) {
30043014
popComponentEffectStart(prevEffectStart);
30053015
popComponentEffectDuration(prevEffectDuration);
30063016
popComponentEffectErrors(prevEffectErrors);
3017+
popComponentEffectDidSpawnUpdate(prevEffectDidSpawnUpdate);
30073018
}
30083019

30093020
function recursivelyTraverseDisappearLayoutEffects(parentFiber: Fiber) {
@@ -3027,6 +3038,7 @@ export function reappearLayoutEffects(
30273038
const prevEffectStart = pushComponentEffectStart();
30283039
const prevEffectDuration = pushComponentEffectDuration();
30293040
const prevEffectErrors = pushComponentEffectErrors();
3041+
const prevEffectDidSpawnUpdate = pushComponentEffectDidSpawnUpdate();
30303042
// Turn on layout effects in a tree that previously disappeared.
30313043
const flags = finishedWork.flags;
30323044
switch (finishedWork.tag) {
@@ -3224,7 +3236,7 @@ export function reappearLayoutEffects(
32243236
(finishedWork.mode & ProfileMode) !== NoMode &&
32253237
componentEffectStartTime >= 0 &&
32263238
componentEffectEndTime >= 0 &&
3227-
componentEffectDuration > 0.05
3239+
(componentEffectSpawnedUpdate || componentEffectDuration > 0.05)
32283240
) {
32293241
logComponentEffect(
32303242
finishedWork,
@@ -3238,6 +3250,7 @@ export function reappearLayoutEffects(
32383250
popComponentEffectStart(prevEffectStart);
32393251
popComponentEffectDuration(prevEffectDuration);
32403252
popComponentEffectErrors(prevEffectErrors);
3253+
popComponentEffectDidSpawnUpdate(prevEffectDidSpawnUpdate);
32413254
}
32423255

32433256
function recursivelyTraverseReappearLayoutEffects(
@@ -3489,6 +3502,7 @@ function commitPassiveMountOnFiber(
34893502
const prevEffectStart = pushComponentEffectStart();
34903503
const prevEffectDuration = pushComponentEffectDuration();
34913504
const prevEffectErrors = pushComponentEffectErrors();
3505+
const prevEffectDidSpawnUpdate = pushComponentEffectDidSpawnUpdate();
34923506
const prevDeepEquality = pushDeepEquality();
34933507

34943508
const isViewTransitionEligible = enableViewTransition
@@ -4060,7 +4074,7 @@ function commitPassiveMountOnFiber(
40604074
}
40614075
}
40624076
if (componentEffectStartTime >= 0 && componentEffectEndTime >= 0) {
4063-
if (componentEffectDuration > 0.05) {
4077+
if (componentEffectSpawnedUpdate || componentEffectDuration > 0.05) {
40644078
logComponentEffect(
40654079
finishedWork,
40664080
componentEffectStartTime,
@@ -4082,6 +4096,7 @@ function commitPassiveMountOnFiber(
40824096
popComponentEffectStart(prevEffectStart);
40834097
popComponentEffectDuration(prevEffectDuration);
40844098
popComponentEffectErrors(prevEffectErrors);
4099+
popComponentEffectDidSpawnUpdate(prevEffectDidSpawnUpdate);
40854100
popDeepEquality(prevDeepEquality);
40864101
}
40874102

@@ -4144,6 +4159,7 @@ export function reconnectPassiveEffects(
41444159
const prevEffectStart = pushComponentEffectStart();
41454160
const prevEffectDuration = pushComponentEffectDuration();
41464161
const prevEffectErrors = pushComponentEffectErrors();
4162+
const prevEffectDidSpawnUpdate = pushComponentEffectDidSpawnUpdate();
41474163
const prevDeepEquality = pushDeepEquality();
41484164

41494165
// If this component rendered in Profiling mode (DEV or in Profiler component) then log its
@@ -4334,7 +4350,7 @@ export function reconnectPassiveEffects(
43344350
(finishedWork.mode & ProfileMode) !== NoMode &&
43354351
componentEffectStartTime >= 0 &&
43364352
componentEffectEndTime >= 0 &&
4337-
componentEffectDuration > 0.05
4353+
(componentEffectSpawnedUpdate || componentEffectDuration > 0.05)
43384354
) {
43394355
logComponentEffect(
43404356
finishedWork,
@@ -4348,6 +4364,7 @@ export function reconnectPassiveEffects(
43484364
popComponentEffectStart(prevEffectStart);
43494365
popComponentEffectDuration(prevEffectDuration);
43504366
popComponentEffectErrors(prevEffectErrors);
4367+
popComponentEffectDidSpawnUpdate(prevEffectDidSpawnUpdate);
43514368
popDeepEquality(prevDeepEquality);
43524369
}
43534370

@@ -4737,6 +4754,7 @@ function commitPassiveUnmountOnFiber(finishedWork: Fiber): void {
47374754
const prevEffectStart = pushComponentEffectStart();
47384755
const prevEffectDuration = pushComponentEffectDuration();
47394756
const prevEffectErrors = pushComponentEffectErrors();
4757+
const prevEffectDidSpawnUpdate = pushComponentEffectDidSpawnUpdate();
47404758
switch (finishedWork.tag) {
47414759
case FunctionComponent:
47424760
case ForwardRef:
@@ -4833,7 +4851,7 @@ function commitPassiveUnmountOnFiber(finishedWork: Fiber): void {
48334851
(finishedWork.mode & ProfileMode) !== NoMode &&
48344852
componentEffectStartTime >= 0 &&
48354853
componentEffectEndTime >= 0 &&
4836-
componentEffectDuration > 0.05
4854+
(componentEffectSpawnedUpdate || componentEffectDuration > 0.05)
48374855
) {
48384856
logComponentEffect(
48394857
finishedWork,
@@ -4846,6 +4864,7 @@ function commitPassiveUnmountOnFiber(finishedWork: Fiber): void {
48464864

48474865
popComponentEffectStart(prevEffectStart);
48484866
popComponentEffectDuration(prevEffectDuration);
4867+
popComponentEffectDidSpawnUpdate(prevEffectDidSpawnUpdate);
48494868
popComponentEffectErrors(prevEffectErrors);
48504869
}
48514870

@@ -4903,6 +4922,7 @@ export function disconnectPassiveEffect(finishedWork: Fiber): void {
49034922
const prevEffectStart = pushComponentEffectStart();
49044923
const prevEffectDuration = pushComponentEffectDuration();
49054924
const prevEffectErrors = pushComponentEffectErrors();
4925+
const prevEffectDidSpawnUpdate = pushComponentEffectDidSpawnUpdate();
49064926

49074927
switch (finishedWork.tag) {
49084928
case FunctionComponent:
@@ -4942,7 +4962,7 @@ export function disconnectPassiveEffect(finishedWork: Fiber): void {
49424962
(finishedWork.mode & ProfileMode) !== NoMode &&
49434963
componentEffectStartTime >= 0 &&
49444964
componentEffectEndTime >= 0 &&
4945-
componentEffectDuration > 0.05
4965+
(componentEffectSpawnedUpdate || componentEffectDuration > 0.05)
49464966
) {
49474967
logComponentEffect(
49484968
finishedWork,
@@ -4955,6 +4975,7 @@ export function disconnectPassiveEffect(finishedWork: Fiber): void {
49554975

49564976
popComponentEffectStart(prevEffectStart);
49574977
popComponentEffectDuration(prevEffectDuration);
4978+
popComponentEffectDidSpawnUpdate(prevEffectDidSpawnUpdate);
49584979
popComponentEffectErrors(prevEffectErrors);
49594980
}
49604981

@@ -5016,6 +5037,7 @@ function commitPassiveUnmountInsideDeletedTreeOnFiber(
50165037
const prevEffectStart = pushComponentEffectStart();
50175038
const prevEffectDuration = pushComponentEffectDuration();
50185039
const prevEffectErrors = pushComponentEffectErrors();
5040+
const prevEffectDidSpawnUpdate = pushComponentEffectDidSpawnUpdate();
50195041
switch (current.tag) {
50205042
case FunctionComponent:
50215043
case ForwardRef:
@@ -5135,7 +5157,7 @@ function commitPassiveUnmountInsideDeletedTreeOnFiber(
51355157
(current.mode & ProfileMode) !== NoMode &&
51365158
componentEffectStartTime >= 0 &&
51375159
componentEffectEndTime >= 0 &&
5138-
componentEffectDuration > 0.05
5160+
(componentEffectSpawnedUpdate || componentEffectDuration > 0.05)
51395161
) {
51405162
logComponentEffect(
51415163
current,
@@ -5148,6 +5170,7 @@ function commitPassiveUnmountInsideDeletedTreeOnFiber(
51485170

51495171
popComponentEffectStart(prevEffectStart);
51505172
popComponentEffectDuration(prevEffectDuration);
5173+
popComponentEffectDidSpawnUpdate(prevEffectDidSpawnUpdate);
51515174
popComponentEffectErrors(prevEffectErrors);
51525175
}
51535176

‎packages/react-reconciler/src/ReactProfilerTimer.js‎

Lines changed: 20 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -64,6 +64,7 @@ export let componentEffectDuration: number = -0;
6464
export let componentEffectStartTime: number = -1.1;
6565
export let componentEffectEndTime: number = -1.1;
6666
export let componentEffectErrors: null | Array<CapturedValue<mixed>> = null;
67+
export let componentEffectSpawnedUpdate: boolean = false;
6768

6869
export let blockingClampTime: number = -0;
6970
export let blockingUpdateTime: number = -1.1; // First sync setState scheduled.
@@ -153,6 +154,7 @@ export function startUpdateTimerByLane(
153154
blockingUpdateComponentName = getComponentNameFromFiber(fiber);
154155
}
155156
if (isAlreadyRendering()) {
157+
componentEffectSpawnedUpdate = true;
156158
blockingUpdateType = SPAWNED_UPDATE;
157159
}
158160
const newEventTime = resolveEventTimeStamp();
@@ -495,6 +497,24 @@ export function popComponentEffectErrors(
495497
componentEffectErrors = prevErrors;
496498
}
497499

500+
export function pushComponentEffectDidSpawnUpdate(): boolean {
501+
if (!enableProfilerTimer || !enableProfilerCommitHooks) {
502+
return false;
503+
}
504+
505+
const prev = componentEffectSpawnedUpdate;
506+
componentEffectSpawnedUpdate = false; // Reset.
507+
return prev;
508+
}
509+
510+
export function popComponentEffectDidSpawnUpdate(previousValue: boolean): void {
511+
if (!enableProfilerTimer || !enableProfilerCommitHooks) {
512+
return;
513+
}
514+
515+
componentEffectSpawnedUpdate = previousValue;
516+
}
517+
498518
/**
499519
* Tracks whether the current update was a nested/cascading update (scheduled from a layout effect).
500520
*

0 commit comments

Comments
 (0)