diff --git a/packages/react-reconciler/src/ReactFiberPerformanceTrack.js b/packages/react-reconciler/src/ReactFiberPerformanceTrack.js index 7d074d545664a..04e586314293d 100644 --- a/packages/react-reconciler/src/ReactFiberPerformanceTrack.js +++ b/packages/react-reconciler/src/ReactFiberPerformanceTrack.js @@ -114,6 +114,54 @@ export function logComponentEffect( } } +export function logYieldTime(startTime: number, endTime: number): void { + if (supportsUserTiming) { + const yieldDuration = endTime - startTime; + if (yieldDuration < 1) { + // Skip sub-millisecond yields. This happens all the time and is not interesting. + return; + } + // Being blocked on CPU is potentially bad so we color it by how long it took. + reusableComponentDevToolDetails.color = + yieldDuration < 5 + ? 'primary-light' + : yieldDuration < 10 + ? 'primary' + : yieldDuration < 100 + ? 'primary-dark' + : 'error'; + reusableComponentOptions.start = startTime; + reusableComponentOptions.end = endTime; + performance.measure('Blocked', reusableComponentOptions); + } +} + +export function logSuspendedYieldTime( + startTime: number, + endTime: number, + suspendedFiber: Fiber, +): void { + if (supportsUserTiming) { + reusableComponentDevToolDetails.color = 'primary-light'; + reusableComponentOptions.start = startTime; + reusableComponentOptions.end = endTime; + performance.measure('Suspended', reusableComponentOptions); + } +} + +export function logActionYieldTime( + startTime: number, + endTime: number, + suspendedFiber: Fiber, +): void { + if (supportsUserTiming) { + reusableComponentDevToolDetails.color = 'primary-light'; + reusableComponentOptions.start = startTime; + reusableComponentOptions.end = endTime; + performance.measure('Action', reusableComponentOptions); + } +} + export function logBlockingStart( updateTime: number, eventTime: number, diff --git a/packages/react-reconciler/src/ReactFiberWorkLoop.js b/packages/react-reconciler/src/ReactFiberWorkLoop.js index 1d4f136b64510..8c90c6df2b6dc 100644 --- a/packages/react-reconciler/src/ReactFiberWorkLoop.js +++ b/packages/react-reconciler/src/ReactFiberWorkLoop.js @@ -79,6 +79,9 @@ import { logCommitPhase, logPaintYieldPhase, logPassiveCommitPhase, + logYieldTime, + logActionYieldTime, + logSuspendedYieldTime, } from './ReactFiberPerformanceTrack'; import { @@ -264,6 +267,9 @@ import { stopProfilerTimerIfRunningAndRecordIncompleteDuration, markUpdateAsRepeat, trackSuspendedTime, + startYieldTimer, + yieldStartTime, + yieldReason, } from './ReactProfilerTimer'; import {setCurrentTrackFromLanes} from './ReactFiberPerformanceTrack'; @@ -351,7 +357,7 @@ let workInProgress: Fiber | null = null; // The lanes we're rendering let workInProgressRootRenderLanes: Lanes = NoLanes; -opaque type SuspendedReason = 0 | 1 | 2 | 3 | 4 | 5 | 6 | 7 | 8 | 9; +export opaque type SuspendedReason = 0 | 1 | 2 | 3 | 4 | 5 | 6 | 7 | 8 | 9; const NotSuspended: SuspendedReason = 0; const SuspendedOnError: SuspendedReason = 1; const SuspendedOnData: SuspendedReason = 2; @@ -915,6 +921,24 @@ export function performWorkOnRoot( throw new Error('Should not already be working.'); } + if (enableProfilerTimer && enableComponentPerformanceTrack) { + if (workInProgressRootRenderLanes !== NoLanes && workInProgress !== null) { + const yieldedFiber = workInProgress; + // We've returned from yielding to the event loop. Let's log the time it took. + const yieldEndTime = now(); + switch (yieldReason) { + case SuspendedOnData: + logSuspendedYieldTime(yieldStartTime, yieldEndTime, yieldedFiber); + break; + case SuspendedOnAction: + logActionYieldTime(yieldStartTime, yieldEndTime, yieldedFiber); + break; + default: + logYieldTime(yieldStartTime, yieldEndTime); + } + } + } + // We disable time-slicing in some cases: if the work has been CPU-bound // for too long ("expired" work, to prevent starvation), or we're in // sync-updates-by-default mode. @@ -956,6 +980,12 @@ export function performWorkOnRoot( const didAttemptEntireTree = false; markRootSuspended(root, lanes, NoLane, didAttemptEntireTree); } + if (enableProfilerTimer && enableComponentPerformanceTrack) { + // We're about to yield. Let's keep track of how long we yield to the event loop. + // We also stash the suspended reason at the time we yielded since it might have + // changed when we resume such as when it gets pinged. + startYieldTimer(workInProgressSuspendedReason); + } break; } else { let renderEndTime = 0; diff --git a/packages/react-reconciler/src/ReactProfilerTimer.js b/packages/react-reconciler/src/ReactProfilerTimer.js index da4e1f7bf356b..fdd7b7827b4d7 100644 --- a/packages/react-reconciler/src/ReactProfilerTimer.js +++ b/packages/react-reconciler/src/ReactProfilerTimer.js @@ -9,6 +9,8 @@ import type {Fiber} from './ReactInternalTypes'; +import type {SuspendedReason} from './ReactFiberWorkLoop'; + import type {Lane, Lanes} from './ReactFiberLane'; import { isTransitionLane, @@ -58,6 +60,17 @@ export let transitionEventType: null | string = null; // Event type of the first export let transitionEventIsRepeat: boolean = false; export let transitionSuspendedTime: number = -1.1; +export let yieldReason: SuspendedReason = (0: any); +export let yieldStartTime: number = -1.1; // The time when we yielded to the event loop + +export function startYieldTimer(reason: SuspendedReason) { + if (!enableProfilerTimer || !enableComponentPerformanceTrack) { + return; + } + yieldStartTime = now(); + yieldReason = reason; +} + export function startUpdateTimerByLane(lane: Lane): void { if (!enableProfilerTimer || !enableComponentPerformanceTrack) { return;