[Fiber] Log Effect and Render Times in Offscreen Commit Phase (#31788)
In https://github.com/facebook/react/pull/30967 and https://github.com/facebook/react/pull/30983 I added logging of the just rendered components and the effects. However this didn't consider the special Offscreen passes. So this adds the same thing to those passes. Log component effect timings for disconnected/reconnected offscreen subtrees. This includes initial mount of a Suspense boundary. Log component render timings for reconnected and already offscreen offscreen subtrees.
Sebastian Markbåge committed
Dec 17, 2024 at 19:46 UTC
6a4b46cd70d2672bc4be59dcb5b8dede22ed0cef
2 files changed
+183
-16
packages/react-reconciler/src/ReactFiberCommitWork.js
+182
-15
@@ -2209,6 +2209,8 @@ function recursivelyTraverseLayoutEffects(
2209
}
2210
2211
export function disappearLayoutEffects(finishedWork: Fiber) {
2212
+ const prevEffectStart = pushComponentEffectStart();
2213
+
2214
switch (finishedWork.tag) {
2215
case FunctionComponent:
2216
case ForwardRef:
@@ -2266,6 +2268,25 @@ export function disappearLayoutEffects(finishedWork: Fiber) {
2268
break;
2269
}
2270
}
2271
+
2272
+ if (
2273
+ enableProfilerTimer &&
2274
+ enableProfilerCommitHooks &&
2275
+ enableComponentPerformanceTrack &&
2276
+ (finishedWork.mode & ProfileMode) !== NoMode &&
2277
+ componentEffectStartTime >= 0 &&
2278
+ componentEffectEndTime >= 0 &&
2279
+ componentEffectDuration > 0.05
2280
+ ) {
2281
+ logComponentEffect(
2282
+ finishedWork,
2283
+ componentEffectStartTime,
2284
+ componentEffectEndTime,
2285
+ componentEffectDuration,
2286
+ );
2287
+ }
2288
+
2289
+ popComponentEffectStart(prevEffectStart);
2290
}
2291
2292
function recursivelyTraverseDisappearLayoutEffects(parentFiber: Fiber) {
@@ -2286,6 +2307,8 @@ export function reappearLayoutEffects(
2307
// node was reused.
2308
includeWorkInProgressEffects: boolean,
2309
) {
2310
+ const prevEffectStart = pushComponentEffectStart();
2311
+
2312
// Turn on layout effects in a tree that previously disappeared.
2313
const flags = finishedWork.flags;
2314
switch (finishedWork.tag) {
@@ -2421,6 +2444,25 @@ export function reappearLayoutEffects(
2444
break;
2445
}
2446
}
2447
+
2448
+ if (
2449
+ enableProfilerTimer &&
2450
+ enableProfilerCommitHooks &&
2451
+ enableComponentPerformanceTrack &&
2452
+ (finishedWork.mode & ProfileMode) !== NoMode &&
2453
+ componentEffectStartTime >= 0 &&
2454
+ componentEffectEndTime >= 0 &&
2455
+ componentEffectDuration > 0.05
2456
+ ) {
2457
+ logComponentEffect(
2458
+ finishedWork,
2459
+ componentEffectStartTime,
2460
+ componentEffectEndTime,
2461
+ componentEffectDuration,
2462
+ );
2463
+ }
2464
+
2465
+ popComponentEffectStart(prevEffectStart);
2466
}
2467
2468
function recursivelyTraverseReappearLayoutEffects(
@@ -2846,6 +2888,7 @@ function commitPassiveMountOnFiber(
2888
finishedWork,
2889
committedLanes,
2890
committedTransitions,
2891
+ endTime,
2892
);
2893
} else {
2894
// Legacy Mode: Fire the effects even if the tree is hidden.
@@ -2884,6 +2927,7 @@ function commitPassiveMountOnFiber(
2927
committedLanes,
2928
committedTransitions,
2929
includeWorkInProgressEffects,
2930
+ endTime,
2931
);
2932
}
2933
}
@@ -2963,6 +3007,7 @@ function recursivelyTraverseReconnectPassiveEffects(
3007
committedLanes: Lanes,
3008
committedTransitions: Array<Transition> | null,
3009
includeWorkInProgressEffects: boolean,
3010
+ endTime: number,
3011
) {
3012
// This function visits both newly finished work and nodes that were re-used
3013
// from a previously committed tree. We cannot check non-static flags if the
@@ -2974,14 +3019,30 @@ function recursivelyTraverseReconnectPassiveEffects(
3019
// TODO (Offscreen) Check: flags & (RefStatic | LayoutStatic)
3020
let child = parentFiber.child;
3021
while (child !== null) {
2977
- reconnectPassiveEffects(
2978
- finishedRoot,
2979
- child,
2980
- committedLanes,
2981
- committedTransitions,
2982
- childShouldIncludeWorkInProgressEffects,
2983
- );
2984
- child = child.sibling;
3022
+ if (enableProfilerTimer && enableComponentPerformanceTrack) {
3023
+ const nextSibling = child.sibling;
3024
+ reconnectPassiveEffects(
3025
+ finishedRoot,
3026
+ child,
3027
+ committedLanes,
3028
+ committedTransitions,
3029
+ childShouldIncludeWorkInProgressEffects,
3030
+ nextSibling !== null
3031
+ ? ((nextSibling.actualStartTime: any): number)
3032
+ : endTime,
3033
+ );
3034
+ child = nextSibling;
3035
+ } else {
3036
+ reconnectPassiveEffects(
3037
+ finishedRoot,
3038
+ child,
3039
+ committedLanes,
3040
+ committedTransitions,
3041
+ childShouldIncludeWorkInProgressEffects,
3042
+ endTime,
3043
+ );
3044
+ child = child.sibling;
3045
+ }
3046
}
3047
}
3048
@@ -2994,7 +3055,28 @@ export function reconnectPassiveEffects(
3055
// from a previously committed tree. We cannot check non-static flags if the
3056
// node was reused.
3057
includeWorkInProgressEffects: boolean,
3058
+ endTime: number, // Profiling-only. The start time of the next Fiber or root completion.
3059
) {
3060
+ const prevEffectStart = pushComponentEffectStart();
3061
+
3062
+ // If this component rendered in Profiling mode (DEV or in Profiler component) then log its
3063
+ // render time. We do this after the fact in the passive effect to avoid the overhead of this
3064
+ // getting in the way of the render characteristics and avoid the overhead of unwinding
3065
+ // uncommitted renders.
3066
+ if (
3067
+ enableProfilerTimer &&
3068
+ enableComponentPerformanceTrack &&
3069
+ (finishedWork.mode & ProfileMode) !== NoMode &&
3070
+ ((finishedWork.actualStartTime: any): number) > 0 &&
3071
+ (finishedWork.flags & PerformedWork) !== NoFlags
3072
+ ) {
3073
+ logComponentRender(
3074
+ finishedWork,
3075
+ ((finishedWork.actualStartTime: any): number),
3076
+ endTime,
3077
+ );
3078
+ }
3079
+
3080
const flags = finishedWork.flags;
3081
switch (finishedWork.tag) {
3082
case FunctionComponent:
@@ -3006,6 +3088,7 @@ export function reconnectPassiveEffects(
3088
committedLanes,
3089
committedTransitions,
3090
includeWorkInProgressEffects,
3091
+ endTime,
3092
);
3093
// TODO: Check for PassiveStatic flag
3094
commitHookPassiveMountEffects(finishedWork, HookPassive);
@@ -3025,6 +3108,7 @@ export function reconnectPassiveEffects(
3108
committedLanes,
3109
committedTransitions,
3110
includeWorkInProgressEffects,
3111
+ endTime,
3112
);
3113
3114
if (includeWorkInProgressEffects && flags & Passive) {
@@ -3051,6 +3135,7 @@ export function reconnectPassiveEffects(
3135
committedLanes,
3136
committedTransitions,
3137
includeWorkInProgressEffects,
3138
+ endTime,
3139
);
3140
} else {
3141
if (disableLegacyMode || finishedWork.mode & ConcurrentMode) {
@@ -3064,6 +3149,7 @@ export function reconnectPassiveEffects(
3149
finishedWork,
3150
committedLanes,
3151
committedTransitions,
3152
+ endTime,
3153
);
3154
} else {
3155
// Legacy Mode: Fire the effects even if the tree is hidden.
@@ -3074,6 +3160,7 @@ export function reconnectPassiveEffects(
3160
committedLanes,
3161
committedTransitions,
3162
includeWorkInProgressEffects,
3163
+ endTime,
3164
);
3165
}
3166
}
@@ -3093,6 +3180,7 @@ export function reconnectPassiveEffects(
3180
committedLanes,
3181
committedTransitions,
3182
includeWorkInProgressEffects,
3183
+ endTime,
3184
);
3185
}
3186
@@ -3110,6 +3198,7 @@ export function reconnectPassiveEffects(
3198
committedLanes,
3199
committedTransitions,
3200
includeWorkInProgressEffects,
3201
+ endTime,
3202
);
3203
if (includeWorkInProgressEffects && flags & Passive) {
3204
// TODO: Pass `current` as argument to this function
@@ -3126,6 +3215,7 @@ export function reconnectPassiveEffects(
3215
committedLanes,
3216
committedTransitions,
3217
includeWorkInProgressEffects,
3218
+ endTime,
3219
);
3220
if (includeWorkInProgressEffects && flags & Passive) {
3221
commitTracingMarkerPassiveMountEffect(finishedWork);
@@ -3141,10 +3231,30 @@ export function reconnectPassiveEffects(
3231
committedLanes,
3232
committedTransitions,
3233
includeWorkInProgressEffects,
3234
+ endTime,
3235
);
3236
break;
3237
}
3238
}
3239
+
3240
+ if (
3241
+ enableProfilerTimer &&
3242
+ enableProfilerCommitHooks &&
3243
+ enableComponentPerformanceTrack &&
3244
+ (finishedWork.mode & ProfileMode) !== NoMode &&
3245
+ componentEffectStartTime >= 0 &&
3246
+ componentEffectEndTime >= 0 &&
3247
+ componentEffectDuration > 0.05
3248
+ ) {
3249
+ logComponentEffect(
3250
+ finishedWork,
3251
+ componentEffectStartTime,
3252
+ componentEffectEndTime,
3253
+ componentEffectDuration,
3254
+ );
3255
+ }
3256
+
3257
+ popComponentEffectStart(prevEffectStart);
3258
}
3259
3260
function recursivelyTraverseAtomicPassiveEffects(
@@ -3152,6 +3262,7 @@ function recursivelyTraverseAtomicPassiveEffects(
3262
parentFiber: Fiber,
3263
committedLanes: Lanes,
3264
committedTransitions: Array<Transition> | null,
3265
+ endTime: number, // Profiling-only. The start time of the next Fiber or root completion.
3266
) {
3267
// "Atomic" effects are ones that need to fire on every commit, even during
3268
// pre-rendering. We call this function when traversing a hidden tree whose
@@ -3160,13 +3271,28 @@ function recursivelyTraverseAtomicPassiveEffects(
3271
if (parentFiber.subtreeFlags & PassiveMask) {
3272
let child = parentFiber.child;
3273
while (child !== null) {
3163
- commitAtomicPassiveEffects(
3164
- finishedRoot,
3165
- child,
3166
- committedLanes,
3167
- committedTransitions,
3168
- );
3169
- child = child.sibling;
3274
+ if (enableProfilerTimer && enableComponentPerformanceTrack) {
3275
+ const nextSibling = child.sibling;
3276
+ commitAtomicPassiveEffects(
3277
+ finishedRoot,
3278
+ child,
3279
+ committedLanes,
3280
+ committedTransitions,
3281
+ nextSibling !== null
3282
+ ? ((nextSibling.actualStartTime: any): number)
3283
+ : endTime,
3284
+ );
3285
+ child = nextSibling;
3286
+ } else {
3287
+ commitAtomicPassiveEffects(
3288
+ finishedRoot,
3289
+ child,
3290
+ committedLanes,
3291
+ committedTransitions,
3292
+ endTime,
3293
+ );
3294
+ child = child.sibling;
3295
+ }
3296
}
3297
}
3298
}
@@ -3176,7 +3302,24 @@ function commitAtomicPassiveEffects(
3302
finishedWork: Fiber,
3303
committedLanes: Lanes,
3304
committedTransitions: Array<Transition> | null,
3305
+ endTime: number, // Profiling-only. The start time of the next Fiber or root completion.
3306
) {
3307
+ // If this component rendered in Profiling mode (DEV or in Profiler component) then log its
3308
+ // render time. A render can happen even if the subtree is offscreen.
3309
+ if (
3310
+ enableProfilerTimer &&
3311
+ enableComponentPerformanceTrack &&
3312
+ (finishedWork.mode & ProfileMode) !== NoMode &&
3313
+ ((finishedWork.actualStartTime: any): number) > 0 &&
3314
+ (finishedWork.flags & PerformedWork) !== NoFlags
3315
+ ) {
3316
+ logComponentRender(
3317
+ finishedWork,
3318
+ ((finishedWork.actualStartTime: any): number),
3319
+ endTime,
3320
+ );
3321
+ }
3322
+
3323
// "Atomic" effects are ones that need to fire on every commit, even during
3324
// pre-rendering. We call this function when traversing a hidden tree whose
3325
// regular effects are currently disconnected.
@@ -3188,6 +3331,7 @@ function commitAtomicPassiveEffects(
3331
finishedWork,
3332
committedLanes,
3333
committedTransitions,
3334
+ endTime,
3335
);
3336
if (flags & Passive) {
3337
// TODO: Pass `current` as argument to this function
@@ -3203,6 +3347,7 @@ function commitAtomicPassiveEffects(
3347
finishedWork,
3348
committedLanes,
3349
committedTransitions,
3350
+ endTime,
3351
);
3352
if (flags & Passive) {
3353
// TODO: Pass `current` as argument to this function
@@ -3217,6 +3362,7 @@ function commitAtomicPassiveEffects(
3362
finishedWork,
3363
committedLanes,
3364
committedTransitions,
3365
+ endTime,
3366
);
3367
break;
3368
}
@@ -3591,6 +3737,8 @@ function commitPassiveUnmountInsideDeletedTreeOnFiber(
3737
current: Fiber,
3738
nearestMountedAncestor: Fiber | null,
3739
): void {
3740
+ const prevEffectStart = pushComponentEffectStart();
3741
+
3742
switch (current.tag) {
3743
case FunctionComponent:
3744
case ForwardRef:
@@ -3702,6 +3850,25 @@ function commitPassiveUnmountInsideDeletedTreeOnFiber(
3850
break;
3851
}
3852
}
3853
+
3854
+ if (
3855
+ enableProfilerTimer &&
3856
+ enableProfilerCommitHooks &&
3857
+ enableComponentPerformanceTrack &&
3858
+ (current.mode & ProfileMode) !== NoMode &&
3859
+ componentEffectStartTime >= 0 &&
3860
+ componentEffectEndTime >= 0 &&
3861
+ componentEffectDuration > 0.05
3862
+ ) {
3863
+ logComponentEffect(
3864
+ current,
3865
+ componentEffectStartTime,
3866
+ componentEffectEndTime,
3867
+ componentEffectDuration,
3868
+ );
3869
+ }
3870
+
3871
+ popComponentEffectStart(prevEffectStart);
3872
}
3873
3874
export function invokeLayoutEffectMountInDEV(fiber: Fiber): void {
packages/react-reconciler/src/ReactFiberWorkLoop.js
+1
-1
@@ -4139,7 +4139,7 @@ function doubleInvokeEffectsOnFiber(
4139
}
4140
reappearLayoutEffects(root, fiber.alternate, fiber, false);
4141
if (shouldDoubleInvokePassiveEffects) {
4142
- reconnectPassiveEffects(root, fiber, NoLanes, null, false);
4142
+ reconnectPassiveEffects(root, fiber, NoLanes, null, false, 0);
4143
}
4144
} finally {
4145
setIsStrictModeForDevtools(false);