Skip to content

Commit

Permalink
[Fiber] Log Component Renders to Custom Performance Track (#30967)
Browse files Browse the repository at this point in the history
Stacked on #30960 and #30966. Behind the enableComponentPerformanceTrack
flag.

This is the first step of performance logging. This logs the start and
end time of a component render in the passive effect phase. We use the
data we're already tracking on components when the Profiler component or
DevTools is active in the Profiling or Dev builds. By backdating this
after committing we avoid adding more overhead in the hot path. By only
logging things that actually committed, we avoid the costly unwinding of
an interrupted render which was hard to maintain in earlier versions.

We already have the start time but we don't have the end time. That's
because `actualStartTime + actualDuration` isn't enough since
`actualDuration` counts the actual CPU time excluding yields and
suspending in the render.

Instead, we infer the end time to be the start time of the next sibling
or the complete time of the whole root if there are no more siblings. We
need to pass this down the passive effect tree. This will mean that any
overhead and yields are attributed to this component's span. In a follow
up, we'll need to start logging these yields to make it clear that this
is not part of the component's self-time.

In follow ups, I'll do the same for commit phases. We'll also need to
log more information about the phases in the top track. We'll also need
to filter out more components from the trees that we don't need to
highlight like the internal Offscreen components. It also needs polish
on colors etc.

Currently, I place the components into separate tracks depending on
which lane currently committed. That way you can see what was blocking
Transitions or Suspense etc. One problem that I've hit with the new
performance.measure extensions is that these tracks show up in the order
they're used which is not the order of priority that we use. Even when
you add fake markers they have to actually be within the performance run
since otherwise the calls are noops so it's not enough to do that once.

However, I think this visualization is actually not good because these
trees end up so large that you can't see any other lanes once you expand
one. Therefore, I think in a follow up I'll actually instead switch to a
model where Components is a single track regardless of lane since we
don't currently have overlap anyway. Then the description about what is
actually rendering can be separate lanes.

<img width="1512" alt="Screenshot 2024-09-15 at 10 55 55 PM"
src="https://github.com/user-attachments/assets/5ca3fa74-97ce-40c7-97f7-80c1dd7d6470">

<img width="1512" alt="Screenshot 2024-09-15 at 10 56 27 PM"
src="https://github.com/user-attachments/assets/557ad65b-4190-465f-843c-0bc6cbb9326d">
  • Loading branch information
sebmarkbage authored Sep 16, 2024
1 parent ee1a403 commit f2df569
Show file tree
Hide file tree
Showing 7 changed files with 285 additions and 49 deletions.
74 changes: 66 additions & 8 deletions packages/react-reconciler/src/ReactFiberCommitWork.js
Original file line number Diff line number Diff line change
Expand Up @@ -53,6 +53,7 @@ import {
enableUseEffectEventHook,
enableLegacyHidden,
disableLegacyMode,
enableComponentPerformanceTrack,
} from 'shared/ReactFeatureFlags';
import {
FunctionComponent,
Expand Down Expand Up @@ -102,7 +103,9 @@ import {
getCommitTime,
recordLayoutEffectDuration,
startLayoutEffectTimer,
getCompleteTime,
} from './ReactProfilerTimer';
import {logComponentRender} from './ReactFiberPerformanceTrack';
import {ConcurrentMode, NoMode, ProfileMode} from './ReactTypeOfMode';
import {deferHiddenCallbacks} from './ReactFiberClassUpdateQueue';
import {
Expand Down Expand Up @@ -2648,6 +2651,9 @@ export function commitPassiveMountEffects(
finishedWork,
committedLanes,
committedTransitions,
enableProfilerTimer && enableComponentPerformanceTrack
? getCompleteTime()
: 0,
);
}

Expand All @@ -2656,17 +2662,41 @@ function recursivelyTraversePassiveMountEffects(
parentFiber: Fiber,
committedLanes: Lanes,
committedTransitions: Array<Transition> | null,
endTime: number, // Profiling-only. The start time of the next Fiber or root completion.
) {
if (parentFiber.subtreeFlags & PassiveMask) {
if (
parentFiber.subtreeFlags & PassiveMask ||
// If this subtree rendered with profiling this commit, we need to visit it to log it.
(enableProfilerTimer &&
enableComponentPerformanceTrack &&
parentFiber.actualDuration !== 0 &&
(parentFiber.alternate === null ||
parentFiber.alternate.child !== parentFiber.child))
) {
let child = parentFiber.child;
while (child !== null) {
commitPassiveMountOnFiber(
root,
child,
committedLanes,
committedTransitions,
);
child = child.sibling;
if (enableProfilerTimer && enableComponentPerformanceTrack) {
const nextSibling = child.sibling;
commitPassiveMountOnFiber(
root,
child,
committedLanes,
committedTransitions,
nextSibling !== null
? ((nextSibling.actualStartTime: any): number)
: endTime,
);
child = nextSibling;
} else {
commitPassiveMountOnFiber(
root,
child,
committedLanes,
committedTransitions,
0,
);
child = child.sibling;
}
}
}
}
Expand All @@ -2676,7 +2706,25 @@ function commitPassiveMountOnFiber(
finishedWork: Fiber,
committedLanes: Lanes,
committedTransitions: Array<Transition> | null,
endTime: number, // Profiling-only. The start time of the next Fiber or root completion.
): void {
// If this component rendered in Profiling mode (DEV or in Profiler component) then log its
// render time. We do this after the fact in the passive effect to avoid the overhead of this
// getting in the way of the render characteristics and avoid the overhead of unwinding
// uncommitted renders.
if (
enableProfilerTimer &&
enableComponentPerformanceTrack &&
(finishedWork.mode & ProfileMode) !== NoMode &&
((finishedWork.actualStartTime: any): number) > 0
) {
logComponentRender(
finishedWork,
((finishedWork.actualStartTime: any): number),
endTime,
);
}

// When updating this function, also update reconnectPassiveEffects, which does
// most of the same things when an offscreen tree goes from hidden -> visible,
// or when toggling effects inside a hidden tree.
Expand All @@ -2690,6 +2738,7 @@ function commitPassiveMountOnFiber(
finishedWork,
committedLanes,
committedTransitions,
endTime,
);
if (flags & Passive) {
commitHookPassiveMountEffects(
Expand All @@ -2705,6 +2754,7 @@ function commitPassiveMountOnFiber(
finishedWork,
committedLanes,
committedTransitions,
endTime,
);
if (flags & Passive) {
if (enableCache) {
Expand Down Expand Up @@ -2762,6 +2812,7 @@ function commitPassiveMountOnFiber(
finishedWork,
committedLanes,
committedTransitions,
endTime,
);

// Only Profilers with work in their subtree will have a Passive effect scheduled.
Expand Down Expand Up @@ -2809,6 +2860,7 @@ function commitPassiveMountOnFiber(
finishedWork,
committedLanes,
committedTransitions,
endTime,
);

if (flags & Passive) {
Expand All @@ -2834,6 +2886,7 @@ function commitPassiveMountOnFiber(
finishedWork,
committedLanes,
committedTransitions,
endTime,
);
} else {
if (disableLegacyMode || finishedWork.mode & ConcurrentMode) {
Expand All @@ -2858,6 +2911,7 @@ function commitPassiveMountOnFiber(
finishedWork,
committedLanes,
committedTransitions,
endTime,
);
}
}
Expand All @@ -2870,6 +2924,7 @@ function commitPassiveMountOnFiber(
finishedWork,
committedLanes,
committedTransitions,
endTime,
);
} else {
// The effects are currently disconnected. Reconnect them, while also
Expand Down Expand Up @@ -2901,6 +2956,7 @@ function commitPassiveMountOnFiber(
finishedWork,
committedLanes,
committedTransitions,
endTime,
);
if (flags & Passive) {
// TODO: Pass `current` as argument to this function
Expand All @@ -2916,6 +2972,7 @@ function commitPassiveMountOnFiber(
finishedWork,
committedLanes,
committedTransitions,
endTime,
);
if (flags & Passive) {
commitTracingMarkerPassiveMountEffect(finishedWork);
Expand All @@ -2930,6 +2987,7 @@ function commitPassiveMountOnFiber(
finishedWork,
committedLanes,
committedTransitions,
endTime,
);
break;
}
Expand Down
32 changes: 32 additions & 0 deletions packages/react-reconciler/src/ReactFiberLane.js
Original file line number Diff line number Diff line change
Expand Up @@ -1143,3 +1143,35 @@ export function clearTransitionsForLanes(root: FiberRoot, lanes: Lane | Lanes) {
lanes &= ~lane;
}
}

// Used to name the Performance Track
export function getGroupNameOfHighestPriorityLane(lanes: Lanes): string {
if (
lanes &
(SyncHydrationLane |
SyncLane |
InputContinuousHydrationLane |
InputContinuousLane |
DefaultHydrationLane |
DefaultLane)
) {
return 'Blocking';
}
if (lanes & (TransitionHydrationLane | TransitionLanes)) {
return 'Transition';
}
if (lanes & RetryLanes) {
return 'Suspense';
}
if (
lanes &
(SelectiveHydrationLane |
IdleHydrationLane |
IdleLane |
OffscreenLane |
DeferredLane)
) {
return 'Idle';
}
return 'Other';
}
61 changes: 61 additions & 0 deletions packages/react-reconciler/src/ReactFiberPerformanceTrack.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,61 @@
/**
* Copyright (c) Meta Platforms, Inc. and affiliates.
*
* This source code is licensed under the MIT license found in the
* LICENSE file in the root directory of this source tree.
*
* @flow
*/

import type {Fiber} from './ReactInternalTypes';

import getComponentNameFromFiber from './getComponentNameFromFiber';

import {getGroupNameOfHighestPriorityLane} from './ReactFiberLane';

import {enableProfilerTimer} from 'shared/ReactFeatureFlags';

const supportsUserTiming =
enableProfilerTimer &&
typeof performance !== 'undefined' &&
// $FlowFixMe[method-unbinding]
typeof performance.measure === 'function';

const TRACK_GROUP = 'Components ⚛';

// Reused to avoid thrashing the GC.
const reusableComponentDevToolDetails = {
dataType: 'track-entry',
color: 'primary',
track: 'Blocking', // Lane
trackGroup: TRACK_GROUP,
};
const reusableComponentOptions = {
start: -0,
end: -0,
detail: {
devtools: reusableComponentDevToolDetails,
},
};

export function setCurrentTrackFromLanes(lanes: number): void {
reusableComponentDevToolDetails.track =
getGroupNameOfHighestPriorityLane(lanes);
}

export function logComponentRender(
fiber: Fiber,
startTime: number,
endTime: number,
): void {
const name = getComponentNameFromFiber(fiber);
if (name === null) {
// Skip
return;
}
if (supportsUserTiming) {
reusableComponentOptions.start = startTime;
reusableComponentOptions.end = endTime;
performance.measure(name, reusableComponentOptions);
}
}
Loading

0 comments on commit f2df569

Please sign in to comment.