diff --git a/packages/react-reconciler/src/ReactDebugFiberPerf.js b/packages/react-reconciler/src/ReactDebugFiberPerf.js index b4717fc8a9bb..e068baf946a1 100644 --- a/packages/react-reconciler/src/ReactDebugFiberPerf.js +++ b/packages/react-reconciler/src/ReactDebugFiberPerf.js @@ -58,6 +58,7 @@ let hasScheduledUpdateInCurrentCommit: boolean = false; let hasScheduledUpdateInCurrentPhase: boolean = false; let commitCountInCurrentWorkLoop: number = 0; let effectCountInCurrentCommit: number = 0; +let isWaitingForCallback: boolean = false; // During commits, we only show a measurement once per method name // to avoid stretch the commit phase with measurement overhead. const labelsInCurrentCommit: Set = new Set(); @@ -231,6 +232,29 @@ export function recordScheduleUpdate(): void { } } +export function startRequestCallbackTimer(): void { + if (enableUserTimingAPI) { + if (supportsUserTiming && !isWaitingForCallback) { + isWaitingForCallback = true; + beginMark('(Waiting for async callback...)'); + } + } +} + +export function stopRequestCallbackTimer(didExpire: boolean): void { + if (enableUserTimingAPI) { + if (supportsUserTiming) { + isWaitingForCallback = false; + const warning = didExpire ? 'React was blocked by main thread' : null; + endMark( + '(Waiting for async callback...)', + '(Waiting for async callback...)', + warning, + ); + } + } +} + export function startWorkTimer(fiber: Fiber): void { if (enableUserTimingAPI) { if (!supportsUserTiming || shouldIgnoreFiber(fiber)) { diff --git a/packages/react-reconciler/src/ReactFiberScheduler.js b/packages/react-reconciler/src/ReactFiberScheduler.js index 95cf4c276c09..57e6fe63b71e 100644 --- a/packages/react-reconciler/src/ReactFiberScheduler.js +++ b/packages/react-reconciler/src/ReactFiberScheduler.js @@ -33,6 +33,7 @@ import { HostPortal, ClassComponent, } from 'shared/ReactTypeOfWork'; +import {enableUserTimingAPI} from 'shared/ReactFeatureFlags'; import getComponentName from 'shared/getComponentName'; import invariant from 'fbjs/lib/invariant'; import warning from 'fbjs/lib/warning'; @@ -47,6 +48,8 @@ import ReactDebugCurrentFiber from './ReactDebugCurrentFiber'; import { recordEffect, recordScheduleUpdate, + startRequestCallbackTimer, + stopRequestCallbackTimer, startWorkTimer, stopWorkTimer, stopFailedWorkTimer, @@ -1337,6 +1340,7 @@ export default function( performWork(Sync, null); } else if (!isCallbackScheduled) { isCallbackScheduled = true; + startRequestCallbackTimer(); scheduleDeferredCallback(performAsyncWork); } } @@ -1425,8 +1429,14 @@ export default function( deadline = dl; // Keep working on roots until there's no more work, or until the we reach - // the deadlne. + // the deadline. findHighestPriorityRoot(); + + if (enableUserTimingAPI && deadline !== null) { + const didExpire = nextFlushedExpirationTime < recalculateCurrentTime(); + stopRequestCallbackTimer(didExpire); + } + while ( nextFlushedRoot !== null && nextFlushedExpirationTime !== NoWork && @@ -1449,6 +1459,7 @@ export default function( // If there's work left over, schedule a new callback. if (nextFlushedRoot !== null && !isCallbackScheduled) { isCallbackScheduled = true; + startRequestCallbackTimer(); scheduleDeferredCallback(performAsyncWork); } diff --git a/packages/react-reconciler/src/__tests__/ReactIncrementalPerf-test.js b/packages/react-reconciler/src/__tests__/ReactIncrementalPerf-test.js index 0ea69b10ad23..672c3d8f62ae 100644 --- a/packages/react-reconciler/src/__tests__/ReactIncrementalPerf-test.js +++ b/packages/react-reconciler/src/__tests__/ReactIncrementalPerf-test.js @@ -20,6 +20,7 @@ describe('ReactDebugFiberPerf', () => { let activeMeasure; let knownMarks; let knownMeasures; + let comments; function resetFlamechart() { root = { @@ -35,12 +36,11 @@ describe('ReactDebugFiberPerf', () => { activeMeasure = root; knownMarks = new Set(); knownMeasures = new Set(); + comments = []; } function addComment(comment) { - activeMeasure.children.push( - `${' '.repeat(activeMeasure.indent + 1)}// ${comment}`, - ); + comments.push(comment); } function getFlameChart() { @@ -67,9 +67,11 @@ describe('ReactDebugFiberPerf', () => { // Will be assigned on measure() call: label: null, parent: activeMeasure, + comments, toString() { return ( [ + ...this.comments.map(c => ' '.repeat(this.indent) + '// ' + c), ' '.repeat(this.indent) + this.label, ...this.children.map(c => c.toString()), ].join('\n') + @@ -78,6 +80,7 @@ describe('ReactDebugFiberPerf', () => { ); }, }; + comments = []; // Step one level deeper activeMeasure.children.push(measure); activeMeasure = measure; @@ -546,4 +549,15 @@ describe('ReactDebugFiberPerf', () => { ReactNoop.flush(); expect(getFlameChart()).toMatchSnapshot(); }); + + it('warns if async work expires (starvation)', () => { + function Foo() { + return ; + } + + ReactNoop.render(); + ReactNoop.expire(5000); + ReactNoop.flush(); + expect(getFlameChart()).toMatchSnapshot(); + }); }); diff --git a/packages/react-reconciler/src/__tests__/__snapshots__/ReactIncrementalPerf-test.js.snap b/packages/react-reconciler/src/__tests__/__snapshots__/ReactIncrementalPerf-test.js.snap index 0bd35bd70129..1d588f3e7fef 100644 --- a/packages/react-reconciler/src/__tests__/__snapshots__/ReactIncrementalPerf-test.js.snap +++ b/packages/react-reconciler/src/__tests__/__snapshots__/ReactIncrementalPerf-test.js.snap @@ -1,7 +1,9 @@ // Jest Snapshot v1, https://goo.gl/fbAQLP exports[`ReactDebugFiberPerf captures all lifecycles 1`] = ` -"// Mount +"⚛ (Waiting for async callback...) + +// Mount ⚛ (React Tree Reconciliation) ⚛ AllLifecycles [mount] ⚛ AllLifecycles.componentWillMount @@ -12,6 +14,8 @@ exports[`ReactDebugFiberPerf captures all lifecycles 1`] = ` ⚛ (Calling Lifecycle Methods: 1 Total) ⚛ AllLifecycles.componentDidMount +⚛ (Waiting for async callback...) + // Update ⚛ (React Tree Reconciliation) ⚛ AllLifecycles [update] @@ -25,6 +29,8 @@ exports[`ReactDebugFiberPerf captures all lifecycles 1`] = ` ⚛ (Calling Lifecycle Methods: 2 Total) ⚛ AllLifecycles.componentDidUpdate +⚛ (Waiting for async callback...) + // Unmount ⚛ (React Tree Reconciliation) @@ -36,7 +42,9 @@ exports[`ReactDebugFiberPerf captures all lifecycles 1`] = ` `; exports[`ReactDebugFiberPerf deduplicates lifecycle names during commit to reduce overhead 1`] = ` -"// The commit phase should mention A and B just once +"⚛ (Waiting for async callback...) + +// The commit phase should mention A and B just once ⚛ (React Tree Reconciliation) ⚛ Parent [update] ⚛ A [update] @@ -50,6 +58,8 @@ exports[`ReactDebugFiberPerf deduplicates lifecycle names during commit to reduc ⚛ A.componentDidUpdate ⚛ B.componentDidUpdate +⚛ (Waiting for async callback...) + // Because of deduplication, we don't know B was cascading, // but we should still see the warning for the commit phase. ⚛ (React Tree Reconciliation) @@ -94,7 +104,9 @@ exports[`ReactDebugFiberPerf does not schedule an extra callback if setState is `; exports[`ReactDebugFiberPerf does not treat setState from cWM or cWRP as cascading 1`] = ` -"// Should not print a warning +"⚛ (Waiting for async callback...) + +// Should not print a warning ⚛ (React Tree Reconciliation) ⚛ Parent [mount] ⚛ NotCascading [mount] @@ -104,6 +116,8 @@ exports[`ReactDebugFiberPerf does not treat setState from cWM or cWRP as cascadi ⚛ (Committing Host Effects: 1 Total) ⚛ (Calling Lifecycle Methods: 0 Total) +⚛ (Waiting for async callback...) + // Should not print a warning ⚛ (React Tree Reconciliation) ⚛ Parent [update] @@ -117,7 +131,9 @@ exports[`ReactDebugFiberPerf does not treat setState from cWM or cWRP as cascadi `; exports[`ReactDebugFiberPerf measures a simple reconciliation 1`] = ` -"// Mount +"⚛ (Waiting for async callback...) + +// Mount ⚛ (React Tree Reconciliation) ⚛ Parent [mount] ⚛ Child [mount] @@ -126,6 +142,8 @@ exports[`ReactDebugFiberPerf measures a simple reconciliation 1`] = ` ⚛ (Committing Host Effects: 1 Total) ⚛ (Calling Lifecycle Methods: 0 Total) +⚛ (Waiting for async callback...) + // Update ⚛ (React Tree Reconciliation) ⚛ Parent [update] @@ -135,6 +153,8 @@ exports[`ReactDebugFiberPerf measures a simple reconciliation 1`] = ` ⚛ (Committing Host Effects: 2 Total) ⚛ (Calling Lifecycle Methods: 2 Total) +⚛ (Waiting for async callback...) + // Unmount ⚛ (React Tree Reconciliation) @@ -145,17 +165,23 @@ exports[`ReactDebugFiberPerf measures a simple reconciliation 1`] = ` `; exports[`ReactDebugFiberPerf measures deferred work in chunks 1`] = ` -"// Start mounting Parent and A +"⚛ (Waiting for async callback...) + +// Start mounting Parent and A ⚛ (React Tree Reconciliation) ⚛ Parent [mount] ⚛ A [mount] ⚛ Child [mount] +⚛ (Waiting for async callback...) + // Mount B just a little (but not enough to memoize) ⚛ (React Tree Reconciliation) ⚛ Parent [mount] ⚛ B [mount] +⚛ (Waiting for async callback...) + // Complete B and Parent ⚛ (React Tree Reconciliation) ⚛ Parent [mount] @@ -177,6 +203,8 @@ exports[`ReactDebugFiberPerf measures deprioritized work 1`] = ` ⚛ (Committing Host Effects: 1 Total) ⚛ (Calling Lifecycle Methods: 0 Total) +⚛ (Waiting for async callback...) + // Flush the child ⚛ (React Tree Reconciliation) ⚛ Child [mount] @@ -188,7 +216,9 @@ exports[`ReactDebugFiberPerf measures deprioritized work 1`] = ` `; exports[`ReactDebugFiberPerf recovers from caught errors 1`] = ` -"// Stop on Baddie and restart from Boundary +"⚛ (Waiting for async callback...) + +// Stop on Baddie and restart from Boundary ⚛ (React Tree Reconciliation) ⚛ Parent [mount] ⛔ Boundary [mount] Warning: An error was thrown inside this error boundary @@ -211,7 +241,9 @@ exports[`ReactDebugFiberPerf recovers from caught errors 1`] = ` `; exports[`ReactDebugFiberPerf recovers from fatal errors 1`] = ` -"// Will fatal +"⚛ (Waiting for async callback...) + +// Will fatal ⚛ (React Tree Reconciliation) ⚛ Parent [mount] ⚛ Baddie [mount] @@ -220,6 +252,8 @@ exports[`ReactDebugFiberPerf recovers from fatal errors 1`] = ` ⚛ (Committing Host Effects: 1 Total) ⚛ (Calling Lifecycle Methods: 1 Total) +⚛ (Waiting for async callback...) + // Will reconcile from a clean state ⚛ (React Tree Reconciliation) ⚛ Parent [mount] @@ -232,7 +266,9 @@ exports[`ReactDebugFiberPerf recovers from fatal errors 1`] = ` `; exports[`ReactDebugFiberPerf skips parents during setState 1`] = ` -"// Should include just A and B, no Parents +"⚛ (Waiting for async callback...) + +// Should include just A and B, no Parents ⚛ (React Tree Reconciliation) ⚛ A [update] ⚛ B [update] @@ -244,7 +280,9 @@ exports[`ReactDebugFiberPerf skips parents during setState 1`] = ` `; exports[`ReactDebugFiberPerf supports portals 1`] = ` -"⚛ (React Tree Reconciliation) +"⚛ (Waiting for async callback...) + +⚛ (React Tree Reconciliation) ⚛ Parent [mount] ⚛ Child [mount] @@ -255,7 +293,9 @@ exports[`ReactDebugFiberPerf supports portals 1`] = ` `; exports[`ReactDebugFiberPerf supports returns 1`] = ` -"⚛ (React Tree Reconciliation) +"⚛ (Waiting for async callback...) + +⚛ (React Tree Reconciliation) ⚛ App [mount] ⚛ CoParent [mount] ⚛ HandleReturns [mount] @@ -272,26 +312,42 @@ exports[`ReactDebugFiberPerf supports returns 1`] = ` `; exports[`ReactDebugFiberPerf warns if an in-progress update is interrupted 1`] = ` -"⚛ (React Tree Reconciliation) - ⚛ Foo [mount] +"⚛ (Waiting for async callback...) -⛔ (React Tree Reconciliation) Warning: A top-level update interrupted the previous render +⚛ (React Tree Reconciliation) ⚛ Foo [mount] +⚛ (Waiting for async callback...) + ⛔ (React Tree Reconciliation) Warning: A top-level update interrupted the previous render + ⚛ Foo [mount] + ⚛ (Committing Changes) + ⚛ (Committing Host Effects: 1 Total) + ⚛ (Calling Lifecycle Methods: 0 Total) + +⚛ (React Tree Reconciliation) + ⚛ (Committing Changes) ⚛ (Committing Host Effects: 1 Total) - ⚛ (Calling Lifecycle Methods: 0 Total) + ⚛ (Calling Lifecycle Methods: 1 Total) +" +`; + +exports[`ReactDebugFiberPerf warns if async work expires (starvation) 1`] = ` +"⛔ (Waiting for async callback...) Warning: React was blocked by main thread ⚛ (React Tree Reconciliation) + ⚛ Foo [mount] ⚛ (Committing Changes) ⚛ (Committing Host Effects: 1 Total) - ⚛ (Calling Lifecycle Methods: 1 Total) + ⚛ (Calling Lifecycle Methods: 0 Total) " `; exports[`ReactDebugFiberPerf warns on cascading renders from setState 1`] = ` -"// Should print a warning +"⚛ (Waiting for async callback...) + +// Should print a warning ⚛ (React Tree Reconciliation) ⚛ Parent [mount] ⚛ Cascading [mount] @@ -311,7 +367,9 @@ exports[`ReactDebugFiberPerf warns on cascading renders from setState 1`] = ` `; exports[`ReactDebugFiberPerf warns on cascading renders from top-level render 1`] = ` -"// Rendering the first root +"⚛ (Waiting for async callback...) + +// Rendering the first root ⚛ (React Tree Reconciliation) ⚛ Cascading [mount] @@ -319,8 +377,8 @@ exports[`ReactDebugFiberPerf warns on cascading renders from top-level render 1` ⚛ (Committing Host Effects: 1 Total) ⚛ (Calling Lifecycle Methods: 1 Total) ⛔ Cascading.componentDidMount Warning: Scheduled a cascading update - // Scheduling another root from componentDidMount +// Scheduling another root from componentDidMount ⚛ (React Tree Reconciliation) ⚛ Child [mount]