diff --git a/packages/react-reconciler/src/ReactFiberBeginWork.js b/packages/react-reconciler/src/ReactFiberBeginWork.js index 33b9e79edfaf..7a3bb4ef814c 100644 --- a/packages/react-reconciler/src/ReactFiberBeginWork.js +++ b/packages/react-reconciler/src/ReactFiberBeginWork.js @@ -158,6 +158,7 @@ import { DefaultHydrationLane, SomeRetryLane, includesSomeLane, + includesOnlyRetries, laneToLanes, removeLanes, mergeLanes, @@ -269,6 +270,7 @@ import { scheduleUpdateOnFiber, renderDidSuspendDelayIfPossible, markSkippedUpdateLanes, + markRenderDerivedCause, getWorkInProgressRoot, peekDeferredLane, } from './ReactFiberWorkLoop'; @@ -946,6 +948,13 @@ function updateDehydratedActivityComponent( // but after we've already committed once. warnIfHydrating(); + if (includesSomeLane(renderLanes, (OffscreenLane: Lane))) { + // If we're rendering Offscreen and we're entering the activity then it's possible + // that the only reason we rendered was because this boundary left work. Provide + // it as a cause if another one doesn't already exist. + markRenderDerivedCause(workInProgress); + } + if ( // TODO: Factoring is a little weird, since we check this right below, too. !didReceiveUpdate @@ -1132,6 +1141,16 @@ function updateActivityComponent( children: nextChildren, }; + if ( + includesSomeLane(renderLanes, (OffscreenLane: Lane)) && + includesSomeLane(renderLanes, current.lanes) + ) { + // If we're rendering Offscreen and we're entering the activity then it's possible + // that the only reason we rendered was because this boundary left work. Provide + // it as a cause if another one doesn't already exist. + markRenderDerivedCause(workInProgress); + } + const primaryChildFragment = updateWorkInProgressOffscreenFiber( currentChild, offscreenChildProps, @@ -2515,6 +2534,17 @@ function updateSuspenseComponent( workInProgress.memoizedState = SUSPENDED_MARKER; return fallbackChildFragment; } else { + if ( + prevState !== null && + includesOnlyRetries(renderLanes) && + includesSomeLane(renderLanes, current.lanes) + ) { + // If we're rendering Retry lanes and we're entering the primary content then it's possible + // that the only reason we rendered was because we left this boundary to be warmed up but + // nothing else scheduled an update. If so, use it as the cause of the render. + markRenderDerivedCause(workInProgress); + } + pushPrimaryTreeSuspenseHandler(workInProgress); const nextPrimaryChildren = nextProps.children; @@ -2873,6 +2903,13 @@ function updateDehydratedSuspenseComponent( // but after we've already committed once. warnIfHydrating(); + if (includesSomeLane(renderLanes, (OffscreenLane: Lane))) { + // If we're rendering Offscreen and we're entering the activity then it's possible + // that the only reason we rendered was because this boundary left work. Provide + // it as a cause if another one doesn't already exist. + markRenderDerivedCause(workInProgress); + } + if (isSuspenseInstanceFallback(suspenseInstance)) { // This boundary is in a permanent fallback state. In this case, we'll never // get an update and we'll never be able to hydrate the final content. Let's just try the diff --git a/packages/react-reconciler/src/ReactFiberHooks.js b/packages/react-reconciler/src/ReactFiberHooks.js index 63332124e2f0..940dff5e69a0 100644 --- a/packages/react-reconciler/src/ReactFiberHooks.js +++ b/packages/react-reconciler/src/ReactFiberHooks.js @@ -122,7 +122,10 @@ import { markStateUpdateScheduled, setIsStrictModeForDevtools, } from './ReactFiberDevToolsHook'; -import {startUpdateTimerByLane} from './ReactProfilerTimer'; +import { + startUpdateTimerByLane, + startHostActionTimer, +} from './ReactProfilerTimer'; import {createCache} from './ReactFiberCacheComponent'; import { createUpdate as createLegacyQueueUpdate, @@ -3239,6 +3242,8 @@ export function startHostTransition( BasicStateAction | TransitionStatus>, > = stateHook.queue; + startHostActionTimer(formFiber); + startTransition( formFiber, queue, diff --git a/packages/react-reconciler/src/ReactFiberPerformanceTrack.js b/packages/react-reconciler/src/ReactFiberPerformanceTrack.js index 4f70a589cb08..f7415dbf46dc 100644 --- a/packages/react-reconciler/src/ReactFiberPerformanceTrack.js +++ b/packages/react-reconciler/src/ReactFiberPerformanceTrack.js @@ -609,6 +609,7 @@ export function logBlockingStart( eventType: null | string, eventIsRepeat: boolean, isSpawnedUpdate: boolean, + isPingedUpdate: boolean, renderStartTime: number, lanes: Lanes, debugTask: null | ConsoleTask, // DEV-only @@ -658,11 +659,13 @@ export function logBlockingStart( // $FlowFixMe[method-unbinding] console.timeStamp.bind( console, - isSpawnedUpdate - ? 'Cascading Update' - : renderStartTime - updateTime > 5 - ? 'Update Blocked' - : 'Update', + isPingedUpdate + ? 'Promise Resolved' + : isSpawnedUpdate + ? 'Cascading Update' + : renderStartTime - updateTime > 5 + ? 'Update Blocked' + : 'Update', updateTime, renderStartTime, currentTrack, @@ -672,11 +675,13 @@ export function logBlockingStart( ); } else { console.timeStamp( - isSpawnedUpdate - ? 'Cascading Update' - : renderStartTime - updateTime > 5 - ? 'Update Blocked' - : 'Update', + isPingedUpdate + ? 'Promise Resolved' + : isSpawnedUpdate + ? 'Cascading Update' + : renderStartTime - updateTime > 5 + ? 'Update Blocked' + : 'Update', updateTime, renderStartTime, currentTrack, @@ -694,6 +699,7 @@ export function logTransitionStart( eventTime: number, eventType: null | string, eventIsRepeat: boolean, + isPingedUpdate: boolean, renderStartTime: number, debugTask: null | ConsoleTask, // DEV-only ): void { @@ -763,7 +769,11 @@ export function logTransitionStart( // $FlowFixMe[method-unbinding] console.timeStamp.bind( console, - renderStartTime - updateTime > 5 ? 'Update Blocked' : 'Update', + isPingedUpdate + ? 'Promise Resolved' + : renderStartTime - updateTime > 5 + ? 'Update Blocked' + : 'Update', updateTime, renderStartTime, currentTrack, @@ -773,7 +783,11 @@ export function logTransitionStart( ); } else { console.timeStamp( - renderStartTime - updateTime > 5 ? 'Update Blocked' : 'Update', + isPingedUpdate + ? 'Promise Resolved' + : renderStartTime - updateTime > 5 + ? 'Update Blocked' + : 'Update', updateTime, renderStartTime, currentTrack, @@ -789,23 +803,43 @@ export function logRenderPhase( startTime: number, endTime: number, lanes: Lanes, + debugTask: null | ConsoleTask, ): void { if (supportsUserTiming) { + if (endTime <= startTime) { + return; + } const color = includesOnlyHydrationOrOffscreenLanes(lanes) ? 'tertiary-dark' : 'primary-dark'; - console.timeStamp( - includesOnlyOffscreenLanes(lanes) - ? 'Prepared' - : includesOnlyHydrationLanes(lanes) - ? 'Hydrated' - : 'Render', - startTime, - endTime, - currentTrack, - LANES_TRACK_GROUP, - color, - ); + const label = includesOnlyOffscreenLanes(lanes) + ? 'Prepared' + : includesOnlyHydrationLanes(lanes) + ? 'Hydrated' + : 'Render'; + if (__DEV__ && debugTask) { + debugTask.run( + // $FlowFixMe[method-unbinding] + console.timeStamp.bind( + console, + label, + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + color, + ), + ); + } else { + console.timeStamp( + label, + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + color, + ); + } } } @@ -813,23 +847,43 @@ export function logInterruptedRenderPhase( startTime: number, endTime: number, lanes: Lanes, + debugTask: null | ConsoleTask, ): void { if (supportsUserTiming) { + if (endTime <= startTime) { + return; + } const color = includesOnlyHydrationOrOffscreenLanes(lanes) ? 'tertiary-dark' : 'primary-dark'; - console.timeStamp( - includesOnlyOffscreenLanes(lanes) - ? 'Prewarm' - : includesOnlyHydrationLanes(lanes) - ? 'Interrupted Hydration' - : 'Interrupted Render', - startTime, - endTime, - currentTrack, - LANES_TRACK_GROUP, - color, - ); + const label = includesOnlyOffscreenLanes(lanes) + ? 'Prewarm' + : includesOnlyHydrationLanes(lanes) + ? 'Interrupted Hydration' + : 'Interrupted Render'; + if (__DEV__ && debugTask) { + debugTask.run( + // $FlowFixMe[method-unbinding] + console.timeStamp.bind( + console, + label, + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + color, + ), + ); + } else { + console.timeStamp( + label, + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + color, + ); + } } } @@ -837,19 +891,38 @@ export function logSuspendedRenderPhase( startTime: number, endTime: number, lanes: Lanes, + debugTask: null | ConsoleTask, ): void { if (supportsUserTiming) { + if (endTime <= startTime) { + return; + } const color = includesOnlyHydrationOrOffscreenLanes(lanes) ? 'tertiary-dark' : 'primary-dark'; - console.timeStamp( - 'Prewarm', - startTime, - endTime, - currentTrack, - LANES_TRACK_GROUP, - color, - ); + if (__DEV__ && debugTask) { + debugTask.run( + // $FlowFixMe[method-unbinding] + console.timeStamp.bind( + console, + 'Prewarm', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + color, + ), + ); + } else { + console.timeStamp( + 'Prewarm', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + color, + ); + } } } @@ -857,20 +930,39 @@ export function logSuspendedWithDelayPhase( startTime: number, endTime: number, lanes: Lanes, + debugTask: null | ConsoleTask, ): void { // This means the render was suspended and cannot commit until it gets unblocked. if (supportsUserTiming) { + if (endTime <= startTime) { + return; + } const color = includesOnlyHydrationOrOffscreenLanes(lanes) ? 'tertiary-dark' : 'primary-dark'; - console.timeStamp( - 'Suspended', - startTime, - endTime, - currentTrack, - LANES_TRACK_GROUP, - color, - ); + if (__DEV__ && debugTask) { + debugTask.run( + // $FlowFixMe[method-unbinding] + console.timeStamp.bind( + console, + 'Suspended', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + color, + ), + ); + } else { + console.timeStamp( + 'Suspended', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + color, + ); + } } } @@ -880,8 +972,12 @@ export function logRecoveredRenderPhase( lanes: Lanes, recoverableErrors: Array>, hydrationFailed: boolean, + debugTask: null | ConsoleTask, ): void { if (supportsUserTiming) { + if (endTime <= startTime) { + return; + } if (__DEV__) { const properties: Array<[string, string]> = []; for (let i = 0; i < recoverableErrors.length; i++) { @@ -897,7 +993,7 @@ export function logRecoveredRenderPhase( String(error); properties.push(['Recoverable Error', message]); } - performance.measure('Recovered', { + const options = { start: startTime, end: endTime, detail: { @@ -911,7 +1007,15 @@ export function logRecoveredRenderPhase( properties, }, }, - }); + }; + if (debugTask) { + debugTask.run( + // $FlowFixMe[method-unbinding] + performance.measure.bind(performance, 'Recovered', options), + ); + } else { + performance.measure('Recovered', options); + } } else { console.timeStamp( 'Recovered', @@ -929,68 +1033,144 @@ export function logErroredRenderPhase( startTime: number, endTime: number, lanes: Lanes, + debugTask: null | ConsoleTask, ): void { if (supportsUserTiming) { - console.timeStamp( - 'Errored', - startTime, - endTime, - currentTrack, - LANES_TRACK_GROUP, - 'error', - ); + if (endTime <= startTime) { + return; + } + if (__DEV__ && debugTask) { + debugTask.run( + // $FlowFixMe[method-unbinding] + console.timeStamp.bind( + console, + 'Errored', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'error', + ), + ); + } else { + console.timeStamp( + 'Errored', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'error', + ); + } } } export function logInconsistentRender( startTime: number, endTime: number, + debugTask: null | ConsoleTask, ): void { if (supportsUserTiming) { - console.timeStamp( - 'Teared Render', - startTime, - endTime, - currentTrack, - LANES_TRACK_GROUP, - 'error', - ); + if (endTime <= startTime) { + return; + } + if (__DEV__ && debugTask) { + debugTask.run( + // $FlowFixMe[method-unbinding] + console.timeStamp.bind( + console, + 'Teared Render', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'error', + ), + ); + } else { + console.timeStamp( + 'Teared Render', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'error', + ); + } } } export function logSuspenseThrottlePhase( startTime: number, endTime: number, + debugTask: null | ConsoleTask, ): void { // This was inside a throttled Suspense boundary commit. if (supportsUserTiming) { - console.timeStamp( - 'Throttled', - startTime, - endTime, - currentTrack, - LANES_TRACK_GROUP, - 'secondary-light', - ); + if (endTime <= startTime) { + return; + } + if (__DEV__ && debugTask) { + debugTask.run( + // $FlowFixMe[method-unbinding] + console.timeStamp.bind( + console, + 'Throttled', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'secondary-light', + ), + ); + } else { + console.timeStamp( + 'Throttled', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'secondary-light', + ); + } } } export function logSuspendedCommitPhase( startTime: number, endTime: number, + debugTask: null | ConsoleTask, ): void { // This means the commit was suspended on CSS or images. if (supportsUserTiming) { + if (endTime <= startTime) { + return; + } // TODO: Include the exact reason and URLs of what resources suspended. // TODO: This might also be Suspended while waiting on a View Transition. - console.timeStamp( - 'Suspended on CSS or Images', - startTime, - endTime, - currentTrack, - LANES_TRACK_GROUP, - 'secondary-light', - ); + if (__DEV__ && debugTask) { + debugTask.run( + // $FlowFixMe[method-unbinding] + console.timeStamp.bind( + console, + 'Suspended on CSS or Images', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'secondary-light', + ), + ); + } else { + console.timeStamp( + 'Suspended on CSS or Images', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'secondary-light', + ); + } } } @@ -999,8 +1179,12 @@ export function logCommitErrored( endTime: number, errors: Array>, passive: boolean, + debugTask: null | ConsoleTask, ): void { if (supportsUserTiming) { + if (endTime <= startTime) { + return; + } if (__DEV__) { const properties: Array<[string, string]> = []; for (let i = 0; i < errors.length; i++) { @@ -1016,7 +1200,7 @@ export function logCommitErrored( String(error); properties.push(['Error', message]); } - performance.measure('Errored', { + const options = { start: startTime, end: endTime, detail: { @@ -1030,7 +1214,15 @@ export function logCommitErrored( properties, }, }, - }); + }; + if (debugTask) { + debugTask.run( + // $FlowFixMe[method-unbinding] + performance.measure.bind(performance, 'Errored', options), + ); + } else { + performance.measure('Errored', options); + } } else { console.timeStamp( 'Errored', @@ -1048,20 +1240,39 @@ export function logCommitPhase( startTime: number, endTime: number, errors: null | Array>, + debugTask: null | ConsoleTask, ): void { if (errors !== null) { - logCommitErrored(startTime, endTime, errors, false); + logCommitErrored(startTime, endTime, errors, false, debugTask); return; } if (supportsUserTiming) { - console.timeStamp( - 'Commit', - startTime, - endTime, - currentTrack, - LANES_TRACK_GROUP, - 'secondary-dark', - ); + if (endTime <= startTime) { + return; + } + if (__DEV__ && debugTask) { + debugTask.run( + // $FlowFixMe[method-unbinding] + console.timeStamp.bind( + console, + 'Commit', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'secondary-dark', + ), + ); + } else { + console.timeStamp( + 'Commit', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'secondary-dark', + ); + } } } @@ -1069,16 +1280,35 @@ export function logPaintYieldPhase( startTime: number, endTime: number, delayedUntilPaint: boolean, + debugTask: null | ConsoleTask, ): void { if (supportsUserTiming) { - console.timeStamp( - delayedUntilPaint ? 'Waiting for Paint' : '', - startTime, - endTime, - currentTrack, - LANES_TRACK_GROUP, - 'secondary-light', - ); + if (endTime <= startTime) { + return; + } + if (__DEV__ && debugTask) { + debugTask.run( + // $FlowFixMe[method-unbinding] + console.timeStamp.bind( + console, + delayedUntilPaint ? 'Waiting for Paint' : '', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'secondary-light', + ), + ); + } else { + console.timeStamp( + delayedUntilPaint ? 'Waiting for Paint' : '', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'secondary-light', + ); + } } } @@ -1086,19 +1316,38 @@ export function logPassiveCommitPhase( startTime: number, endTime: number, errors: null | Array>, + debugTask: null | ConsoleTask, ): void { if (errors !== null) { - logCommitErrored(startTime, endTime, errors, true); + logCommitErrored(startTime, endTime, errors, true, debugTask); return; } if (supportsUserTiming) { - console.timeStamp( - 'Remaining Effects', - startTime, - endTime, - currentTrack, - LANES_TRACK_GROUP, - 'secondary-dark', - ); + if (endTime <= startTime) { + return; + } + if (__DEV__ && debugTask) { + debugTask.run( + // $FlowFixMe[method-unbinding] + console.timeStamp.bind( + console, + 'Remaining Effects', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'secondary-dark', + ), + ); + } else { + console.timeStamp( + 'Remaining Effects', + startTime, + endTime, + currentTrack, + LANES_TRACK_GROUP, + 'secondary-dark', + ); + } } } diff --git a/packages/react-reconciler/src/ReactFiberReconciler.js b/packages/react-reconciler/src/ReactFiberReconciler.js index 778518116ff2..8d0f71d16b39 100644 --- a/packages/react-reconciler/src/ReactFiberReconciler.js +++ b/packages/react-reconciler/src/ReactFiberReconciler.js @@ -346,6 +346,7 @@ export function createHydrationContainer( update.callback = callback !== undefined && callback !== null ? callback : null; enqueueUpdate(current, update, lane); + startUpdateTimerByLane(lane, 'hydrateRoot()'); scheduleInitialHydrationOnRoot(root, lane); return root; diff --git a/packages/react-reconciler/src/ReactFiberWorkLoop.js b/packages/react-reconciler/src/ReactFiberWorkLoop.js index 1107c5bd4624..e76083eb0a9f 100644 --- a/packages/react-reconciler/src/ReactFiberWorkLoop.js +++ b/packages/react-reconciler/src/ReactFiberWorkLoop.js @@ -266,15 +266,16 @@ import { blockingClampTime, blockingUpdateTime, blockingUpdateTask, + blockingUpdateType, blockingEventTime, blockingEventType, blockingEventIsRepeat, - blockingSpawnedUpdate, blockingSuspendedTime, transitionClampTime, transitionStartTime, transitionUpdateTime, transitionUpdateTask, + transitionUpdateType, transitionEventTime, transitionEventType, transitionEventIsRepeat, @@ -301,6 +302,8 @@ import { startPingTimerByLanes, recordEffectError, resetCommitErrors, + PINGED_UPDATE, + SPAWNED_UPDATE, } from './ReactProfilerTimer'; // DEV stuff @@ -482,6 +485,9 @@ export function getWorkInProgressTransitions(): null | Array { return workInProgressTransitions; } +// The first setState call that eventually caused the current render. +let workInProgressUpdateTask: null | ConsoleTask = null; + let currentPendingTransitionCallbacks: PendingTransitionCallbacks | null = null; let currentEndTime: number | null = null; @@ -1104,7 +1110,11 @@ export function performWorkOnRoot( ) { if (enableProfilerTimer && enableComponentPerformanceTrack) { setCurrentTrackFromLanes(lanes); - logInconsistentRender(renderStartTime, renderEndTime); + logInconsistentRender( + renderStartTime, + renderEndTime, + workInProgressUpdateTask, + ); finalizeRender(lanes, renderEndTime); } // A store was mutated in an interleaved event. Render again, @@ -1130,7 +1140,12 @@ export function performWorkOnRoot( if (errorRetryLanes !== NoLanes) { if (enableProfilerTimer && enableComponentPerformanceTrack) { setCurrentTrackFromLanes(lanes); - logErroredRenderPhase(renderStartTime, renderEndTime, lanes); + logErroredRenderPhase( + renderStartTime, + renderEndTime, + lanes, + workInProgressUpdateTask, + ); finalizeRender(lanes, renderEndTime); } lanes = errorRetryLanes; @@ -1161,7 +1176,12 @@ export function performWorkOnRoot( if (exitStatus === RootFatalErrored) { if (enableProfilerTimer && enableComponentPerformanceTrack) { setCurrentTrackFromLanes(lanes); - logErroredRenderPhase(renderStartTime, renderEndTime, lanes); + logErroredRenderPhase( + renderStartTime, + renderEndTime, + lanes, + workInProgressUpdateTask, + ); finalizeRender(lanes, renderEndTime); } prepareFreshStack(root, NoLanes); @@ -1302,7 +1322,12 @@ function finishConcurrentRender( // until we receive more data. if (enableProfilerTimer && enableComponentPerformanceTrack) { setCurrentTrackFromLanes(lanes); - logSuspendedRenderPhase(renderStartTime, renderEndTime, lanes); + logSuspendedRenderPhase( + renderStartTime, + renderEndTime, + lanes, + workInProgressUpdateTask, + ); finalizeRender(lanes, renderEndTime); trackSuspendedTime(lanes, renderEndTime); } @@ -1867,18 +1892,22 @@ function prepareFreshStack(root: FiberRoot, lanes: Lanes): Fiber { previousRenderStartTime, renderStartTime, lanes, + workInProgressUpdateTask, ); } else { logInterruptedRenderPhase( previousRenderStartTime, renderStartTime, lanes, + workInProgressUpdateTask, ); } finalizeRender(workInProgressRootRenderLanes, renderStartTime); } + workInProgressUpdateTask = null; if (includesSyncLane(lanes) || includesBlockingLane(lanes)) { + workInProgressUpdateTask = blockingUpdateTask; const clampedUpdateTime = blockingUpdateTime >= 0 && blockingUpdateTime < blockingClampTime ? blockingClampTime @@ -1898,6 +1927,7 @@ function prepareFreshStack(root: FiberRoot, lanes: Lanes): Fiber { ? clampedUpdateTime : renderStartTime, lanes, + workInProgressUpdateTask, ); } logBlockingStart( @@ -1905,7 +1935,8 @@ function prepareFreshStack(root: FiberRoot, lanes: Lanes): Fiber { clampedEventTime, blockingEventType, blockingEventIsRepeat, - blockingSpawnedUpdate, + blockingUpdateType === SPAWNED_UPDATE, + blockingUpdateType === PINGED_UPDATE, renderStartTime, lanes, blockingUpdateTask, @@ -1913,6 +1944,7 @@ function prepareFreshStack(root: FiberRoot, lanes: Lanes): Fiber { clearBlockingTimers(); } if (includesTransitionLane(lanes)) { + workInProgressUpdateTask = transitionUpdateTask; const clampedStartTime = transitionStartTime >= 0 && transitionStartTime < transitionClampTime ? transitionClampTime @@ -1936,6 +1968,7 @@ function prepareFreshStack(root: FiberRoot, lanes: Lanes): Fiber { ? clampedUpdateTime : renderStartTime, lanes, + workInProgressUpdateTask, ); } logTransitionStart( @@ -1944,6 +1977,7 @@ function prepareFreshStack(root: FiberRoot, lanes: Lanes): Fiber { clampedEventTime, transitionEventType, transitionEventIsRepeat, + transitionUpdateType === PINGED_UPDATE, renderStartTime, transitionUpdateTask, ); @@ -2227,6 +2261,21 @@ function popAsyncDispatcher(prevAsyncDispatcher: any) { ReactSharedInternals.A = prevAsyncDispatcher; } +export function markRenderDerivedCause(fiber: Fiber): void { + if (enableProfilerTimer && enableComponentPerformanceTrack) { + if (__DEV__) { + if (workInProgressUpdateTask === null) { + // If we don't have a cause associated with this render, it's likely because some + // other render left work behind on this Fiber. The real cause is this Fiber itself. + // We use its debugTask as the cause for this render. This might not be the only + // one when multiple siblings are rendered but they ideally shouldn't be. + workInProgressUpdateTask = + fiber._debugTask == null ? null : fiber._debugTask; + } + } + } +} + export function markCommitTimeOfFallback() { globalMostRecentFallbackTime = now(); } @@ -3239,6 +3288,7 @@ function commitRoot( completedRenderStartTime, completedRenderEndTime, lanes, + workInProgressUpdateTask, ); } else if (recoverableErrors !== null) { const hydrationFailed = @@ -3252,9 +3302,15 @@ function commitRoot( lanes, recoverableErrors, hydrationFailed, + workInProgressUpdateTask, ); } else { - logRenderPhase(completedRenderStartTime, completedRenderEndTime, lanes); + logRenderPhase( + completedRenderStartTime, + completedRenderEndTime, + lanes, + workInProgressUpdateTask, + ); } } @@ -3425,9 +3481,17 @@ function commitRoot( recordCommitTime(); if (enableComponentPerformanceTrack) { if (suspendedCommitReason === SUSPENDED_COMMIT) { - logSuspendedCommitPhase(completedRenderEndTime, commitStartTime); + logSuspendedCommitPhase( + completedRenderEndTime, + commitStartTime, + workInProgressUpdateTask, + ); } else if (suspendedCommitReason === THROTTLED_COMMIT) { - logSuspenseThrottlePhase(completedRenderEndTime, commitStartTime); + logSuspenseThrottlePhase( + completedRenderEndTime, + commitStartTime, + workInProgressUpdateTask, + ); } } } @@ -3672,6 +3736,7 @@ function flushSpawnedWork(): void { : commitStartTime, commitEndTime, commitErrors, + workInProgressUpdateTask, ); } @@ -4147,6 +4212,7 @@ function flushPassiveEffectsImpl(wasDelayedCommit: void | boolean) { commitEndTime, passiveEffectStartTime, !!wasDelayedCommit, + workInProgressUpdateTask, ); } @@ -4182,6 +4248,7 @@ function flushPassiveEffectsImpl(wasDelayedCommit: void | boolean) { passiveEffectStartTime, passiveEffectsEndTime, commitErrors, + workInProgressUpdateTask, ); finalizeRender(lanes, passiveEffectsEndTime); } diff --git a/packages/react-reconciler/src/ReactProfilerTimer.js b/packages/react-reconciler/src/ReactProfilerTimer.js index b46209a6e6ff..4768ffffb563 100644 --- a/packages/react-reconciler/src/ReactProfilerTimer.js +++ b/packages/react-reconciler/src/ReactProfilerTimer.js @@ -48,6 +48,11 @@ const createTask = console.createTask : (name: string) => null; +export const REGULAR_UPDATE: UpdateType = 0; +export const SPAWNED_UPDATE: UpdateType = 1; +export const PINGED_UPDATE: UpdateType = 2; +export opaque type UpdateType = 0 | 1 | 2; + export let renderStartTime: number = -0; export let commitStartTime: number = -0; export let commitEndTime: number = -0; @@ -62,15 +67,16 @@ export let componentEffectErrors: null | Array> = null; export let blockingClampTime: number = -0; export let blockingUpdateTime: number = -1.1; // First sync setState scheduled. export let blockingUpdateTask: null | ConsoleTask = null; // First sync setState's stack trace. +export let blockingUpdateType: UpdateType = 0; export let blockingEventTime: number = -1.1; // Event timeStamp of the first setState. export let blockingEventType: null | string = null; // Event type of the first setState. export let blockingEventIsRepeat: boolean = false; -export let blockingSpawnedUpdate: boolean = false; export let blockingSuspendedTime: number = -1.1; // TODO: This should really be one per Transition lane. export let transitionClampTime: number = -0; export let transitionStartTime: number = -1.1; // First startTransition call before setState. export let transitionUpdateTime: number = -1.1; // First transition setState scheduled. +export let transitionUpdateType: UpdateType = 0; export let transitionUpdateTask: null | ConsoleTask = null; // First transition setState's stack trace. export let transitionEventTime: number = -1.1; // Event timeStamp of the first transition. export let transitionEventType: null | string = null; // Event type of the first transition. @@ -97,7 +103,7 @@ export function startUpdateTimerByLane(lane: Lane, method: string): void { blockingUpdateTime = now(); blockingUpdateTask = createTask(method); if (isAlreadyRendering()) { - blockingSpawnedUpdate = true; + blockingUpdateType = SPAWNED_UPDATE; } const newEventTime = resolveEventTimeStamp(); const newEventType = resolveEventType(); @@ -110,7 +116,7 @@ export function startUpdateTimerByLane(lane: Lane, method: string): void { // If this is a second update in the same event, we treat it as a spawned update. // This might be a microtask spawned from useEffect, multiple flushSync or // a setState in a microtask spawned after the first setState. Regardless it's bad. - blockingSpawnedUpdate = true; + blockingUpdateType = SPAWNED_UPDATE; } blockingEventTime = newEventTime; blockingEventType = newEventType; @@ -135,6 +141,54 @@ export function startUpdateTimerByLane(lane: Lane, method: string): void { } } +export function startHostActionTimer(fiber: Fiber): void { + if (!enableProfilerTimer || !enableComponentPerformanceTrack) { + return; + } + // This schedules an update on both the blocking lane for the pending state and on the + // transition lane for the action update. Using the debug task from the host fiber. + if (blockingUpdateTime < 0) { + blockingUpdateTime = now(); + blockingUpdateTask = + __DEV__ && fiber._debugTask != null ? fiber._debugTask : null; + if (isAlreadyRendering()) { + blockingUpdateType = SPAWNED_UPDATE; + } + const newEventTime = resolveEventTimeStamp(); + const newEventType = resolveEventType(); + if ( + newEventTime !== blockingEventTime || + newEventType !== blockingEventType + ) { + blockingEventIsRepeat = false; + } else if (newEventType !== null) { + // If this is a second update in the same event, we treat it as a spawned update. + // This might be a microtask spawned from useEffect, multiple flushSync or + // a setState in a microtask spawned after the first setState. Regardless it's bad. + blockingUpdateType = SPAWNED_UPDATE; + } + blockingEventTime = newEventTime; + blockingEventType = newEventType; + } + if (transitionUpdateTime < 0) { + transitionUpdateTime = now(); + transitionUpdateTask = + __DEV__ && fiber._debugTask != null ? fiber._debugTask : null; + if (transitionStartTime < 0) { + const newEventTime = resolveEventTimeStamp(); + const newEventType = resolveEventType(); + if ( + newEventTime !== transitionEventTime || + newEventType !== transitionEventType + ) { + transitionEventIsRepeat = false; + } + transitionEventTime = newEventTime; + transitionEventType = newEventType; + } + } +} + export function startPingTimerByLanes(lanes: Lanes): void { if (!enableProfilerTimer || !enableComponentPerformanceTrack) { return; @@ -145,10 +199,14 @@ export function startPingTimerByLanes(lanes: Lanes): void { if (includesSyncLane(lanes) || includesBlockingLane(lanes)) { if (blockingUpdateTime < 0) { blockingClampTime = blockingUpdateTime = now(); + blockingUpdateTask = createTask('Promise Resolved'); + blockingUpdateType = PINGED_UPDATE; } } else if (includesTransitionLane(lanes)) { if (transitionUpdateTime < 0) { transitionClampTime = transitionUpdateTime = now(); + transitionUpdateTask = createTask('Promise Resolved'); + transitionUpdateType = PINGED_UPDATE; } } } @@ -166,10 +224,9 @@ export function trackSuspendedTime(lanes: Lanes, renderEndTime: number) { export function clearBlockingTimers(): void { blockingUpdateTime = -1.1; - blockingUpdateTask = null; + blockingUpdateType = 0; blockingSuspendedTime = -1.1; blockingEventIsRepeat = true; - blockingSpawnedUpdate = false; } export function startAsyncTransitionTimer(): void { @@ -196,20 +253,6 @@ export function hasScheduledTransitionWork(): boolean { return transitionUpdateTime > -1; } -// We use this marker to indicate that we have scheduled a render to be performed -// but it's not an explicit state update. -const ACTION_STATE_MARKER = -0.5; - -export function startActionStateUpdate(): void { - if (!enableProfilerTimer || !enableComponentPerformanceTrack) { - return; - } - if (transitionUpdateTime < 0) { - transitionUpdateTime = ACTION_STATE_MARKER; - transitionUpdateTask = null; - } -} - export function clearAsyncTransitionTimer(): void { transitionStartTime = -1.1; } @@ -217,7 +260,7 @@ export function clearAsyncTransitionTimer(): void { export function clearTransitionTimers(): void { transitionStartTime = -1.1; transitionUpdateTime = -1.1; - transitionUpdateTask = null; + transitionUpdateType = 0; transitionSuspendedTime = -1.1; transitionEventIsRepeat = true; }