From 40cddfeeb167d4964d82220142deb00f57fe197d Mon Sep 17 00:00:00 2001 From: E-Liang Tan Date: Wed, 8 Jul 2020 22:36:02 +0800 Subject: [PATCH] Add user timing marks for scheduling profiler tool (#19223) High level breakdown of this commit: * Add a enableSchedulingProfiling feature flag. * Add functions that call User Timing APIs to a new SchedulingProfiler file. The file follows DebugTracing's structure. * Add user timing marks to places where DebugTracing logs. * Add user timing marks to most other places where @bvaughn's original draft DebugTracing branch marks. * Tests added * More context (and discussions with @bvaughn) available at our internal PR MLH-Fellowship#11 and issue MLH-Fellowship#5. Similar to DebugTracing, we've only added scheduling profiling calls to the old reconciler fork. Co-authored-by: Kartik Choudhary Co-authored-by: Kartik Choudhary Co-authored-by: Brian Vaughn --- .../src/ReactFiberClassComponent.old.js | 17 + .../src/ReactFiberHooks.old.js | 6 + .../src/ReactFiberReconciler.old.js | 6 + .../src/ReactFiberThrow.old.js | 10 +- .../src/ReactFiberWorkLoop.old.js | 63 +++ .../src/SchedulingProfiler.js | 187 +++++++ .../SchedulingProfiler-test.internal.js | 468 ++++++++++++++++++ packages/shared/ReactFeatureFlags.js | 4 + .../forks/ReactFeatureFlags.native-fb.js | 1 + .../forks/ReactFeatureFlags.native-oss.js | 1 + .../forks/ReactFeatureFlags.test-renderer.js | 1 + .../ReactFeatureFlags.test-renderer.www.js | 1 + .../shared/forks/ReactFeatureFlags.testing.js | 1 + .../forks/ReactFeatureFlags.testing.www.js | 1 + .../forks/ReactFeatureFlags.www-dynamic.js | 5 +- .../shared/forks/ReactFeatureFlags.www.js | 5 +- 16 files changed, 772 insertions(+), 5 deletions(-) create mode 100644 packages/react-reconciler/src/SchedulingProfiler.js create mode 100644 packages/react-reconciler/src/__tests__/SchedulingProfiler-test.internal.js diff --git a/packages/react-reconciler/src/ReactFiberClassComponent.old.js b/packages/react-reconciler/src/ReactFiberClassComponent.old.js index 175f8fd246..ed544db392 100644 --- a/packages/react-reconciler/src/ReactFiberClassComponent.old.js +++ b/packages/react-reconciler/src/ReactFiberClassComponent.old.js @@ -17,6 +17,7 @@ import { debugRenderPhaseSideEffectsForStrictMode, disableLegacyContext, enableDebugTracing, + enableSchedulingProfiler, warnAboutDeprecatedLifecycles, } from 'shared/ReactFeatureFlags'; import ReactStrictModeWarnings from './ReactStrictModeWarnings.old'; @@ -59,6 +60,10 @@ import {requestCurrentSuspenseConfig} from './ReactFiberSuspenseConfig'; import {logForceUpdateScheduled, logStateUpdateScheduled} from './DebugTracing'; import {disableLogs, reenableLogs} from 'shared/ConsolePatchingDev'; +import { + markForceUpdateScheduled, + markStateUpdateScheduled, +} from './SchedulingProfiler'; const fakeInternalInstance = {}; const isArray = Array.isArray; @@ -214,6 +219,10 @@ const classComponentUpdater = { } } } + + if (enableSchedulingProfiler) { + markStateUpdateScheduled(fiber, lane); + } }, enqueueReplaceState(inst, payload, callback) { const fiber = getInstance(inst); @@ -243,6 +252,10 @@ const classComponentUpdater = { } } } + + if (enableSchedulingProfiler) { + markStateUpdateScheduled(fiber, lane); + } }, enqueueForceUpdate(inst, callback) { const fiber = getInstance(inst); @@ -271,6 +284,10 @@ const classComponentUpdater = { } } } + + if (enableSchedulingProfiler) { + markForceUpdateScheduled(fiber, lane); + } }, }; diff --git a/packages/react-reconciler/src/ReactFiberHooks.old.js b/packages/react-reconciler/src/ReactFiberHooks.old.js index 95f2e4f5c0..c5d5ba25ac 100644 --- a/packages/react-reconciler/src/ReactFiberHooks.old.js +++ b/packages/react-reconciler/src/ReactFiberHooks.old.js @@ -26,6 +26,7 @@ import type {OpaqueIDType} from './ReactFiberHostConfig'; import ReactSharedInternals from 'shared/ReactSharedInternals'; import { enableDebugTracing, + enableSchedulingProfiler, enableNewReconciler, } from 'shared/ReactFeatureFlags'; @@ -92,6 +93,7 @@ import { } from './ReactMutableSource.old'; import {getIsRendering} from './ReactCurrentFiber'; import {logStateUpdateScheduled} from './DebugTracing'; +import {markStateUpdateScheduled} from './SchedulingProfiler'; const {ReactCurrentDispatcher, ReactCurrentBatchConfig} = ReactSharedInternals; @@ -1764,6 +1766,10 @@ function dispatchAction( } } } + + if (enableSchedulingProfiler) { + markStateUpdateScheduled(fiber, lane); + } } export const ContextOnlyDispatcher: Dispatcher = { diff --git a/packages/react-reconciler/src/ReactFiberReconciler.old.js b/packages/react-reconciler/src/ReactFiberReconciler.old.js index da1918bcd2..e7b8662ac6 100644 --- a/packages/react-reconciler/src/ReactFiberReconciler.old.js +++ b/packages/react-reconciler/src/ReactFiberReconciler.old.js @@ -39,6 +39,7 @@ import { } from './ReactWorkTags'; import getComponentName from 'shared/getComponentName'; import invariant from 'shared/invariant'; +import {enableSchedulingProfiler} from 'shared/ReactFeatureFlags'; import ReactSharedInternals from 'shared/ReactSharedInternals'; import {getPublicInstance} from './ReactFiberHostConfig'; import { @@ -95,6 +96,7 @@ import { setRefreshHandler, findHostInstancesForRefresh, } from './ReactFiberHotReloading.old'; +import {markRenderScheduled} from './SchedulingProfiler'; export {registerMutableSourceForHydration} from './ReactMutableSource.new'; export {createPortal} from './ReactPortal'; @@ -273,6 +275,10 @@ export function updateContainer( const suspenseConfig = requestCurrentSuspenseConfig(); const lane = requestUpdateLane(current, suspenseConfig); + if (enableSchedulingProfiler) { + markRenderScheduled(lane); + } + const context = getContextForSubtree(parentComponent); if (container.context === null) { container.context = context; diff --git a/packages/react-reconciler/src/ReactFiberThrow.old.js b/packages/react-reconciler/src/ReactFiberThrow.old.js index 02d40de8c1..a215d363e2 100644 --- a/packages/react-reconciler/src/ReactFiberThrow.old.js +++ b/packages/react-reconciler/src/ReactFiberThrow.old.js @@ -32,7 +32,10 @@ import { } from './ReactSideEffectTags'; import {shouldCaptureSuspense} from './ReactFiberSuspenseComponent.old'; import {NoMode, BlockingMode, DebugTracingMode} from './ReactTypeOfMode'; -import {enableDebugTracing} from 'shared/ReactFeatureFlags'; +import { + enableDebugTracing, + enableSchedulingProfiler, +} from 'shared/ReactFeatureFlags'; import {createCapturedValue} from './ReactCapturedValue'; import { enqueueCapturedUpdate, @@ -56,6 +59,7 @@ import { } from './ReactFiberWorkLoop.old'; import {logCapturedError} from './ReactFiberErrorLogger'; import {logComponentSuspended} from './DebugTracing'; +import {markComponentSuspended} from './SchedulingProfiler'; import { SyncLane, @@ -201,6 +205,10 @@ function throwException( } } + if (enableSchedulingProfiler) { + markComponentSuspended(sourceFiber, wakeable); + } + if ((sourceFiber.mode & BlockingMode) === NoMode) { // Reset the memoizedState to what it was before we attempted // to render it. diff --git a/packages/react-reconciler/src/ReactFiberWorkLoop.old.js b/packages/react-reconciler/src/ReactFiberWorkLoop.old.js index 789da343aa..ebc5063303 100644 --- a/packages/react-reconciler/src/ReactFiberWorkLoop.old.js +++ b/packages/react-reconciler/src/ReactFiberWorkLoop.old.js @@ -28,6 +28,7 @@ import { deferRenderPhaseUpdateToNextBatch, decoupleUpdatePriorityFromScheduler, enableDebugTracing, + enableSchedulingProfiler, } from 'shared/ReactFeatureFlags'; import ReactSharedInternals from 'shared/ReactSharedInternals'; import invariant from 'shared/invariant'; @@ -57,6 +58,17 @@ import { logRenderStarted, logRenderStopped, } from './DebugTracing'; +import { + markCommitStarted, + markCommitStopped, + markLayoutEffectsStarted, + markLayoutEffectsStopped, + markPassiveEffectsStarted, + markPassiveEffectsStopped, + markRenderStarted, + markRenderYielded, + markRenderStopped, +} from './SchedulingProfiler'; // The scheduler is imported here *only* to detect whether it's been mocked import * as Scheduler from 'scheduler'; @@ -1509,6 +1521,10 @@ function renderRootSync(root: FiberRoot, lanes: Lanes) { } } + if (enableSchedulingProfiler) { + markRenderStarted(lanes); + } + do { try { workLoopSync(); @@ -1540,6 +1556,10 @@ function renderRootSync(root: FiberRoot, lanes: Lanes) { } } + if (enableSchedulingProfiler) { + markRenderStopped(); + } + // Set this to null to indicate there's no in-progress render. workInProgressRoot = null; workInProgressRootRenderLanes = NoLanes; @@ -1576,6 +1596,10 @@ function renderRootConcurrent(root: FiberRoot, lanes: Lanes) { } } + if (enableSchedulingProfiler) { + markRenderStarted(lanes); + } + do { try { workLoopConcurrent(); @@ -1601,9 +1625,16 @@ function renderRootConcurrent(root: FiberRoot, lanes: Lanes) { // Check if the tree has completed. if (workInProgress !== null) { // Still work remaining. + if (enableSchedulingProfiler) { + markRenderYielded(); + } return RootIncomplete; } else { // Completed the tree. + if (enableSchedulingProfiler) { + markRenderStopped(); + } + // Set this to null to indicate there's no in-progress render. workInProgressRoot = null; workInProgressRootRenderLanes = NoLanes; @@ -1893,6 +1924,10 @@ function commitRootImpl(root, renderPriorityLevel) { } } + if (enableSchedulingProfiler) { + markCommitStarted(lanes); + } + if (finishedWork === null) { if (__DEV__) { if (enableDebugTracing) { @@ -1900,6 +1935,10 @@ function commitRootImpl(root, renderPriorityLevel) { } } + if (enableSchedulingProfiler) { + markCommitStopped(); + } + return null; } root.finishedWork = null; @@ -2196,6 +2235,10 @@ function commitRootImpl(root, renderPriorityLevel) { } } + if (enableSchedulingProfiler) { + markCommitStopped(); + } + // This is a legacy edge case. We just committed the initial mount of // a ReactDOM.render-ed root inside of batchedUpdates. The commit fired // synchronously, but layout updates should be deferred until the end @@ -2212,6 +2255,10 @@ function commitRootImpl(root, renderPriorityLevel) { } } + if (enableSchedulingProfiler) { + markCommitStopped(); + } + return null; } @@ -2342,6 +2389,10 @@ function commitLayoutEffects(root: FiberRoot, committedLanes: Lanes) { } } + if (enableSchedulingProfiler) { + markLayoutEffectsStarted(committedLanes); + } + // TODO: Should probably move the bulk of this function to commitWork. while (nextEffect !== null) { setCurrentDebugFiberInDEV(nextEffect); @@ -2366,6 +2417,10 @@ function commitLayoutEffects(root: FiberRoot, committedLanes: Lanes) { logLayoutEffectsStopped(); } } + + if (enableSchedulingProfiler) { + markLayoutEffectsStopped(); + } } export function flushPassiveEffects() { @@ -2461,6 +2516,10 @@ function flushPassiveEffectsImpl() { } } + if (enableSchedulingProfiler) { + markPassiveEffectsStarted(lanes); + } + if (__DEV__) { isFlushingPassiveEffects = true; } @@ -2623,6 +2682,10 @@ function flushPassiveEffectsImpl() { } } + if (enableSchedulingProfiler) { + markPassiveEffectsStopped(); + } + executionContext = prevExecutionContext; flushSyncCallbackQueue(); diff --git a/packages/react-reconciler/src/SchedulingProfiler.js b/packages/react-reconciler/src/SchedulingProfiler.js new file mode 100644 index 0000000000..5b7673c628 --- /dev/null +++ b/packages/react-reconciler/src/SchedulingProfiler.js @@ -0,0 +1,187 @@ +/** + * Copyright (c) Facebook, Inc. and its 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 {Lane, Lanes} from './ReactFiberLane'; +import type {Fiber} from './ReactInternalTypes'; +import type {Wakeable} from 'shared/ReactTypes'; + +import {enableSchedulingProfiler} from 'shared/ReactFeatureFlags'; +import getComponentName from 'shared/getComponentName'; +import {getStackByFiberInDevAndProd} from './ReactFiberComponentStack'; + +/** + * If performance exists and supports the subset of the User Timing API that we + * require. + */ +const supportsUserTiming = + typeof performance !== 'undefined' && typeof performance.mark === 'function'; + +function formatLanes(laneOrLanes: Lane | Lanes): string { + return ((laneOrLanes: any): number).toString(); +} + +export function markCommitStarted(lanes: Lanes): void { + if (enableSchedulingProfiler) { + if (supportsUserTiming) { + performance.mark(`--commit-start-${formatLanes(lanes)}`); + } + } +} + +export function markCommitStopped(): void { + if (enableSchedulingProfiler) { + if (supportsUserTiming) { + performance.mark('--commit-stop'); + } + } +} + +const PossiblyWeakMap = typeof WeakMap === 'function' ? WeakMap : Map; + +// $FlowFixMe: Flow cannot handle polymorphic WeakMaps +const wakeableIDs: WeakMap = new PossiblyWeakMap(); +let wakeableID: number = 0; +function getWakeableID(wakeable: Wakeable): number { + if (!wakeableIDs.has(wakeable)) { + wakeableIDs.set(wakeable, wakeableID++); + } + return ((wakeableIDs.get(wakeable): any): number); +} + +// $FlowFixMe: Flow cannot handle polymorphic WeakMaps +const cachedFiberStacks: WeakMap = new PossiblyWeakMap(); +function cacheFirstGetComponentStackByFiber(fiber: Fiber): string { + if (cachedFiberStacks.has(fiber)) { + return ((cachedFiberStacks.get(fiber): any): string); + } else { + const alternate = fiber.alternate; + if (alternate !== null && cachedFiberStacks.has(alternate)) { + return ((cachedFiberStacks.get(alternate): any): string); + } + } + // TODO (brian) Generate and store temporary ID so DevTools can match up a component stack later. + const componentStack = getStackByFiberInDevAndProd(fiber) || ''; + cachedFiberStacks.set(fiber, componentStack); + return componentStack; +} + +export function markComponentSuspended(fiber: Fiber, wakeable: Wakeable): void { + if (enableSchedulingProfiler) { + if (supportsUserTiming) { + const id = getWakeableID(wakeable); + const componentName = getComponentName(fiber.type) || 'Unknown'; + const componentStack = cacheFirstGetComponentStackByFiber(fiber); + performance.mark( + `--suspense-suspend-${id}-${componentName}-${componentStack}`, + ); + wakeable.then( + () => + performance.mark( + `--suspense-resolved-${id}-${componentName}-${componentStack}`, + ), + () => + performance.mark( + `--suspense-rejected-${id}-${componentName}-${componentStack}`, + ), + ); + } + } +} + +export function markLayoutEffectsStarted(lanes: Lanes): void { + if (enableSchedulingProfiler) { + if (supportsUserTiming) { + performance.mark(`--layout-effects-start-${formatLanes(lanes)}`); + } + } +} + +export function markLayoutEffectsStopped(): void { + if (enableSchedulingProfiler) { + if (supportsUserTiming) { + performance.mark('--layout-effects-stop'); + } + } +} + +export function markPassiveEffectsStarted(lanes: Lanes): void { + if (enableSchedulingProfiler) { + if (supportsUserTiming) { + performance.mark(`--passive-effects-start-${formatLanes(lanes)}`); + } + } +} + +export function markPassiveEffectsStopped(): void { + if (enableSchedulingProfiler) { + if (supportsUserTiming) { + performance.mark('--passive-effects-stop'); + } + } +} + +export function markRenderStarted(lanes: Lanes): void { + if (enableSchedulingProfiler) { + if (supportsUserTiming) { + performance.mark(`--render-start-${formatLanes(lanes)}`); + } + } +} + +export function markRenderYielded(): void { + if (enableSchedulingProfiler) { + if (supportsUserTiming) { + performance.mark('--render-yield'); + } + } +} + +export function markRenderStopped(): void { + if (enableSchedulingProfiler) { + if (supportsUserTiming) { + performance.mark('--render-stop'); + } + } +} + +export function markRenderScheduled(lane: Lane): void { + if (enableSchedulingProfiler) { + if (supportsUserTiming) { + performance.mark(`--schedule-render-${formatLanes(lane)}`); + } + } +} + +export function markForceUpdateScheduled(fiber: Fiber, lane: Lane): void { + if (enableSchedulingProfiler) { + if (supportsUserTiming) { + const componentName = getComponentName(fiber.type) || 'Unknown'; + const componentStack = cacheFirstGetComponentStackByFiber(fiber); + performance.mark( + `--schedule-forced-update-${formatLanes( + lane, + )}-${componentName}-${componentStack}`, + ); + } + } +} + +export function markStateUpdateScheduled(fiber: Fiber, lane: Lane): void { + if (enableSchedulingProfiler) { + if (supportsUserTiming) { + const componentName = getComponentName(fiber.type) || 'Unknown'; + const componentStack = cacheFirstGetComponentStackByFiber(fiber); + performance.mark( + `--schedule-state-update-${formatLanes( + lane, + )}-${componentName}-${componentStack}`, + ); + } + } +} diff --git a/packages/react-reconciler/src/__tests__/SchedulingProfiler-test.internal.js b/packages/react-reconciler/src/__tests__/SchedulingProfiler-test.internal.js new file mode 100644 index 0000000000..b6d19a18ba --- /dev/null +++ b/packages/react-reconciler/src/__tests__/SchedulingProfiler-test.internal.js @@ -0,0 +1,468 @@ +/** + * Copyright (c) Facebook, Inc. and its affiliates. + * + * This source code is licensed under the MIT license found in the + * LICENSE file in the root directory of this source tree. + * + * @emails react-core + * @jest-environment node + */ + +'use strict'; + +function normalizeCodeLocInfo(str) { + return ( + str && + str.replace(/\n +(?:at|in) ([\S]+)[^\n]*/g, function(m, name) { + return '\n in ' + name + ' (at **)'; + }) + ); +} + +describe('SchedulingProfiler', () => { + let React; + let ReactTestRenderer; + let ReactNoop; + let Scheduler; + + let marks; + + function createUserTimingPolyfill() { + // This is not a true polyfill, but it gives us enough to capture marks. + // Reference: https://developer.mozilla.org/en-US/docs/Web/API/User_Timing_API + return { + mark(markName) { + marks.push(markName); + }, + }; + } + + beforeEach(() => { + jest.resetModules(); + global.performance = createUserTimingPolyfill(); + + React = require('react'); + + // ReactNoop must be imported after ReactTestRenderer! + ReactTestRenderer = require('react-test-renderer'); + ReactNoop = require('react-noop-renderer'); + + Scheduler = require('scheduler'); + + marks = []; + }); + + afterEach(() => { + delete global.performance; + }); + + // @gate !enableSchedulingProfiler + it('should not mark if enableSchedulingProfiler is false', () => { + ReactTestRenderer.create(
); + expect(marks).toEqual([]); + }); + + // @gate enableSchedulingProfiler + it('should mark sync render without suspends or state updates', () => { + ReactTestRenderer.create(
); + + expect(marks).toEqual([ + '--schedule-render-1', + '--render-start-1', + '--render-stop', + '--commit-start-1', + '--layout-effects-start-1', + '--layout-effects-stop', + '--commit-stop', + ]); + }); + + // @gate enableSchedulingProfiler + it('should mark concurrent render without suspends or state updates', () => { + ReactTestRenderer.create(
, {unstable_isConcurrent: true}); + + expect(marks).toEqual(['--schedule-render-512']); + + marks.splice(0); + + expect(Scheduler).toFlushUntilNextPaint([]); + + expect(marks).toEqual([ + '--render-start-512', + '--render-stop', + '--commit-start-512', + '--layout-effects-start-512', + '--layout-effects-stop', + '--commit-stop', + ]); + }); + + // @gate enableSchedulingProfiler + it('should mark render yields', async () => { + function Bar() { + Scheduler.unstable_yieldValue('Bar'); + return null; + } + + function Foo() { + Scheduler.unstable_yieldValue('Foo'); + return ; + } + + ReactNoop.render(); + // Do one step of work. + expect(ReactNoop.flushNextYield()).toEqual(['Foo']); + + expect(marks).toEqual([ + '--schedule-render-512', + '--render-start-512', + '--render-yield', + ]); + }); + + // @gate enableSchedulingProfiler + it('should mark sync render with suspense that resolves', async () => { + const fakeSuspensePromise = Promise.resolve(true); + function Example() { + throw fakeSuspensePromise; + } + + ReactTestRenderer.create( + + + , + ); + + expect(marks).toEqual([ + '--schedule-render-1', + '--render-start-1', + '--suspense-suspend-0-Example-\n at Example\n at Suspense', + '--render-stop', + '--commit-start-1', + '--layout-effects-start-1', + '--layout-effects-stop', + '--commit-stop', + ]); + + marks.splice(0); + + await fakeSuspensePromise; + expect(marks).toEqual([ + '--suspense-resolved-0-Example-\n at Example\n at Suspense', + ]); + }); + + // @gate enableSchedulingProfiler + it('should mark sync render with suspense that rejects', async () => { + const fakeSuspensePromise = Promise.reject(new Error('error')); + function Example() { + throw fakeSuspensePromise; + } + + ReactTestRenderer.create( + + + , + ); + + expect(marks).toEqual([ + '--schedule-render-1', + '--render-start-1', + '--suspense-suspend-0-Example-\n at Example\n at Suspense', + '--render-stop', + '--commit-start-1', + '--layout-effects-start-1', + '--layout-effects-stop', + '--commit-stop', + ]); + + marks.splice(0); + + await expect(fakeSuspensePromise).rejects.toThrow(); + expect(marks).toEqual([ + '--suspense-rejected-0-Example-\n at Example\n at Suspense', + ]); + }); + + // @gate enableSchedulingProfiler + it('should mark concurrent render with suspense that resolves', async () => { + const fakeSuspensePromise = Promise.resolve(true); + function Example() { + throw fakeSuspensePromise; + } + + ReactTestRenderer.create( + + + , + {unstable_isConcurrent: true}, + ); + + expect(marks).toEqual(['--schedule-render-512']); + + marks.splice(0); + + expect(Scheduler).toFlushUntilNextPaint([]); + + expect(marks).toEqual([ + '--render-start-512', + '--suspense-suspend-0-Example-\n at Example\n at Suspense', + '--render-stop', + '--commit-start-512', + '--layout-effects-start-512', + '--layout-effects-stop', + '--commit-stop', + ]); + + marks.splice(0); + + await fakeSuspensePromise; + expect(marks).toEqual([ + '--suspense-resolved-0-Example-\n at Example\n at Suspense', + ]); + }); + + // @gate enableSchedulingProfiler + it('should mark concurrent render with suspense that rejects', async () => { + const fakeSuspensePromise = Promise.reject(new Error('error')); + function Example() { + throw fakeSuspensePromise; + } + + ReactTestRenderer.create( + + + , + {unstable_isConcurrent: true}, + ); + + expect(marks).toEqual(['--schedule-render-512']); + + marks.splice(0); + + expect(Scheduler).toFlushUntilNextPaint([]); + + expect(marks).toEqual([ + '--render-start-512', + '--suspense-suspend-0-Example-\n at Example\n at Suspense', + '--render-stop', + '--commit-start-512', + '--layout-effects-start-512', + '--layout-effects-stop', + '--commit-stop', + ]); + + marks.splice(0); + + await expect(fakeSuspensePromise).rejects.toThrow(); + expect(marks).toEqual([ + '--suspense-rejected-0-Example-\n at Example\n at Suspense', + ]); + }); + + // @gate enableSchedulingProfiler + it('should mark cascading class component state updates', () => { + class Example extends React.Component { + state = {didMount: false}; + componentDidMount() { + this.setState({didMount: true}); + } + render() { + return null; + } + } + + ReactTestRenderer.create(, {unstable_isConcurrent: true}); + + expect(marks).toEqual(['--schedule-render-512']); + + marks.splice(0); + + expect(Scheduler).toFlushUntilNextPaint([]); + + expect(marks.map(normalizeCodeLocInfo)).toEqual([ + '--render-start-512', + '--render-stop', + '--commit-start-512', + '--layout-effects-start-512', + '--schedule-state-update-1-Example-\n in Example (at **)', + '--layout-effects-stop', + '--render-start-1', + '--render-stop', + '--commit-start-1', + '--commit-stop', + '--commit-stop', + ]); + }); + + // @gate enableSchedulingProfiler + it('should mark cascading class component force updates', () => { + class Example extends React.Component { + componentDidMount() { + this.forceUpdate(); + } + render() { + return null; + } + } + + ReactTestRenderer.create(, {unstable_isConcurrent: true}); + + expect(marks).toEqual(['--schedule-render-512']); + + marks.splice(0); + + expect(Scheduler).toFlushUntilNextPaint([]); + + expect(marks.map(normalizeCodeLocInfo)).toEqual([ + '--render-start-512', + '--render-stop', + '--commit-start-512', + '--layout-effects-start-512', + '--schedule-forced-update-1-Example-\n in Example (at **)', + '--layout-effects-stop', + '--render-start-1', + '--render-stop', + '--commit-start-1', + '--commit-stop', + '--commit-stop', + ]); + }); + + // @gate enableSchedulingProfiler + it('should mark render phase state updates for class component', () => { + class Example extends React.Component { + state = {didRender: false}; + render() { + if (this.state.didRender === false) { + this.setState({didRender: true}); + } + return null; + } + } + + ReactTestRenderer.create(, {unstable_isConcurrent: true}); + + expect(marks).toEqual(['--schedule-render-512']); + + marks.splice(0); + + expect(() => { + expect(Scheduler).toFlushUntilNextPaint([]); + }).toErrorDev('Cannot update during an existing state transition'); + + expect(marks.map(normalizeCodeLocInfo)).toContain( + '--schedule-state-update-1024-Example-\n in Example (at **)', + ); + }); + + // @gate enableSchedulingProfiler + it('should mark render phase force updates for class component', () => { + class Example extends React.Component { + state = {didRender: false}; + render() { + if (this.state.didRender === false) { + this.forceUpdate(() => this.setState({didRender: true})); + } + return null; + } + } + + ReactTestRenderer.create(, {unstable_isConcurrent: true}); + + expect(marks).toEqual(['--schedule-render-512']); + + marks.splice(0); + + expect(() => { + expect(Scheduler).toFlushUntilNextPaint([]); + }).toErrorDev('Cannot update during an existing state transition'); + + expect(marks.map(normalizeCodeLocInfo)).toContain( + '--schedule-forced-update-1024-Example-\n in Example (at **)', + ); + }); + + // @gate enableSchedulingProfiler + it('should mark cascading layout updates', () => { + function Example() { + const [didMount, setDidMount] = React.useState(false); + React.useLayoutEffect(() => { + setDidMount(true); + }, []); + return didMount; + } + + ReactTestRenderer.create(, {unstable_isConcurrent: true}); + + expect(marks).toEqual(['--schedule-render-512']); + + marks.splice(0); + + expect(Scheduler).toFlushUntilNextPaint([]); + + expect(marks.map(normalizeCodeLocInfo)).toEqual([ + '--render-start-512', + '--render-stop', + '--commit-start-512', + '--layout-effects-start-512', + '--schedule-state-update-1-Example-\n in Example (at **)', + '--layout-effects-stop', + '--render-start-1', + '--render-stop', + '--commit-start-1', + '--commit-stop', + '--commit-stop', + ]); + }); + + // @gate enableSchedulingProfiler + it('should mark cascading passive updates', () => { + function Example() { + const [didMount, setDidMount] = React.useState(false); + React.useEffect(() => { + setDidMount(true); + }, []); + return didMount; + } + + ReactTestRenderer.act(() => { + ReactTestRenderer.create(, {unstable_isConcurrent: true}); + }); + expect(marks.map(normalizeCodeLocInfo)).toEqual([ + '--schedule-render-512', + '--render-start-512', + '--render-stop', + '--commit-start-512', + '--layout-effects-start-512', + '--layout-effects-stop', + '--commit-stop', + '--passive-effects-start-512', + '--schedule-state-update-1024-Example-\n in Example (at **)', + '--passive-effects-stop', + '--render-start-1024', + '--render-stop', + '--commit-start-1024', + '--commit-stop', + ]); + }); + + // @gate enableSchedulingProfiler + it('should mark render phase updates', () => { + function Example() { + const [didRender, setDidRender] = React.useState(false); + if (!didRender) { + setDidRender(true); + } + return didRender; + } + + ReactTestRenderer.act(() => { + ReactTestRenderer.create(, {unstable_isConcurrent: true}); + }); + + expect(marks.map(normalizeCodeLocInfo)).toContain( + '--schedule-state-update-1024-Example-\n in Example (at **)', + ); + }); +}); diff --git a/packages/shared/ReactFeatureFlags.js b/packages/shared/ReactFeatureFlags.js index 9e9ec4f75a..0837686bf1 100644 --- a/packages/shared/ReactFeatureFlags.js +++ b/packages/shared/ReactFeatureFlags.js @@ -15,6 +15,10 @@ export const enableFilterEmptyStringAttributesDOM = false; // Intended to enable React core members to more easily debug scheduling issues in DEV builds. export const enableDebugTracing = false; +// Adds user timing marks for e.g. state updates, suspense, and work loop stuff, +// for an experimental scheduling profiler tool. +export const enableSchedulingProfiler = false; + // Helps identify side effects in render-phase lifecycle hooks and setState // reducers by double invoking them in Strict Mode. export const debugRenderPhaseSideEffectsForStrictMode = __DEV__; diff --git a/packages/shared/forks/ReactFeatureFlags.native-fb.js b/packages/shared/forks/ReactFeatureFlags.native-fb.js index cbb47f8cf4..1ac12703a2 100644 --- a/packages/shared/forks/ReactFeatureFlags.native-fb.js +++ b/packages/shared/forks/ReactFeatureFlags.native-fb.js @@ -12,6 +12,7 @@ import typeof * as ExportsType from './ReactFeatureFlags.native-fb'; // The rest of the flags are static for better dead code elimination. export const enableDebugTracing = false; +export const enableSchedulingProfiler = false; export const enableProfilerTimer = __PROFILE__; export const enableProfilerCommitHooks = false; export const enableSchedulerTracing = __PROFILE__; diff --git a/packages/shared/forks/ReactFeatureFlags.native-oss.js b/packages/shared/forks/ReactFeatureFlags.native-oss.js index 779e3379aa..1e41269fc8 100644 --- a/packages/shared/forks/ReactFeatureFlags.native-oss.js +++ b/packages/shared/forks/ReactFeatureFlags.native-oss.js @@ -12,6 +12,7 @@ import typeof * as ExportsType from './ReactFeatureFlags.native-oss'; export const debugRenderPhaseSideEffectsForStrictMode = false; export const enableDebugTracing = false; +export const enableSchedulingProfiler = false; export const replayFailedUnitOfWorkWithInvokeGuardedCallback = __DEV__; export const warnAboutDeprecatedLifecycles = true; export const enableProfilerTimer = __PROFILE__; diff --git a/packages/shared/forks/ReactFeatureFlags.test-renderer.js b/packages/shared/forks/ReactFeatureFlags.test-renderer.js index 2837ff17da..0425f62fc0 100644 --- a/packages/shared/forks/ReactFeatureFlags.test-renderer.js +++ b/packages/shared/forks/ReactFeatureFlags.test-renderer.js @@ -12,6 +12,7 @@ import typeof * as ExportsType from './ReactFeatureFlags.test-renderer'; export const debugRenderPhaseSideEffectsForStrictMode = false; export const enableDebugTracing = false; +export const enableSchedulingProfiler = false; export const warnAboutDeprecatedLifecycles = true; export const replayFailedUnitOfWorkWithInvokeGuardedCallback = false; export const enableProfilerTimer = __PROFILE__; diff --git a/packages/shared/forks/ReactFeatureFlags.test-renderer.www.js b/packages/shared/forks/ReactFeatureFlags.test-renderer.www.js index 5e036a4a17..2e2f0aab0d 100644 --- a/packages/shared/forks/ReactFeatureFlags.test-renderer.www.js +++ b/packages/shared/forks/ReactFeatureFlags.test-renderer.www.js @@ -12,6 +12,7 @@ import typeof * as ExportsType from './ReactFeatureFlags.test-renderer.www'; export const debugRenderPhaseSideEffectsForStrictMode = false; export const enableDebugTracing = false; +export const enableSchedulingProfiler = false; export const warnAboutDeprecatedLifecycles = true; export const replayFailedUnitOfWorkWithInvokeGuardedCallback = false; export const enableProfilerTimer = __PROFILE__; diff --git a/packages/shared/forks/ReactFeatureFlags.testing.js b/packages/shared/forks/ReactFeatureFlags.testing.js index 8f4930fedf..b60f732c38 100644 --- a/packages/shared/forks/ReactFeatureFlags.testing.js +++ b/packages/shared/forks/ReactFeatureFlags.testing.js @@ -12,6 +12,7 @@ import typeof * as ExportsType from './ReactFeatureFlags.testing'; export const debugRenderPhaseSideEffectsForStrictMode = false; export const enableDebugTracing = false; +export const enableSchedulingProfiler = false; export const warnAboutDeprecatedLifecycles = true; export const replayFailedUnitOfWorkWithInvokeGuardedCallback = false; export const enableProfilerTimer = __PROFILE__; diff --git a/packages/shared/forks/ReactFeatureFlags.testing.www.js b/packages/shared/forks/ReactFeatureFlags.testing.www.js index 3f47f5a8f4..72cb1a10e1 100644 --- a/packages/shared/forks/ReactFeatureFlags.testing.www.js +++ b/packages/shared/forks/ReactFeatureFlags.testing.www.js @@ -12,6 +12,7 @@ import typeof * as ExportsType from './ReactFeatureFlags.testing.www'; export const debugRenderPhaseSideEffectsForStrictMode = false; export const enableDebugTracing = false; +export const enableSchedulingProfiler = false; export const warnAboutDeprecatedLifecycles = true; export const replayFailedUnitOfWorkWithInvokeGuardedCallback = false; export const enableProfilerTimer = false; diff --git a/packages/shared/forks/ReactFeatureFlags.www-dynamic.js b/packages/shared/forks/ReactFeatureFlags.www-dynamic.js index 32e1cc1537..84fafd6e14 100644 --- a/packages/shared/forks/ReactFeatureFlags.www-dynamic.js +++ b/packages/shared/forks/ReactFeatureFlags.www-dynamic.js @@ -17,9 +17,12 @@ export const warnAboutSpreadingKeyToJSX = __VARIANT__; export const disableInputAttributeSyncing = __VARIANT__; export const enableFilterEmptyStringAttributesDOM = __VARIANT__; export const enableLegacyFBSupport = __VARIANT__; -export const enableDebugTracing = !__VARIANT__; export const decoupleUpdatePriorityFromScheduler = __VARIANT__; +// TODO: These features do not currently exist in the new reconciler fork. +export const enableDebugTracing = !__VARIANT__; +export const enableSchedulingProfiler = !__VARIANT__ && __PROFILE__; + // This only has an effect in the new reconciler. But also, the new reconciler // is only enabled when __VARIANT__ is true. So this is set to the opposite of // __VARIANT__ so that it's `false` when running against the new reconciler. diff --git a/packages/shared/forks/ReactFeatureFlags.www.js b/packages/shared/forks/ReactFeatureFlags.www.js index 6f98961100..f8d399b9cf 100644 --- a/packages/shared/forks/ReactFeatureFlags.www.js +++ b/packages/shared/forks/ReactFeatureFlags.www.js @@ -25,6 +25,8 @@ export const { enableLegacyFBSupport, deferRenderPhaseUpdateToNextBatch, decoupleUpdatePriorityFromScheduler, + enableDebugTracing, + enableSchedulingProfiler, } = dynamicFeatureFlags; // On WWW, __EXPERIMENTAL__ is used for a new modern build. @@ -77,9 +79,6 @@ export const warnUnstableRenderSubtreeIntoContainer = false; // to the correct value. export const enableNewReconciler = __VARIANT__; -// TODO: This does not currently exist in the new reconciler fork. -export const enableDebugTracing = !__VARIANT__; - // Flow magic to verify the exports of this file match the original version. // eslint-disable-next-line no-unused-vars type Check<_X, Y: _X, X: Y = _X> = null;