From 33ae43f0f8bffac58f9ba04ff9824b09ef2e7c1a Mon Sep 17 00:00:00 2001 From: Brian Vaughn Date: Mon, 5 Apr 2021 16:52:43 -0400 Subject: [PATCH] DevTools: add post-commit hook I recently added UI for the Profiler's commit and post-commit durations to the DevTools, but I made two pretty silly oversights: 1. I used the commit hook (called after mutation+layout effects) to read both the layout and passive effect durations. This is silly because passive effects may not have flushed yet git at this point. 2. I didn't reset the values on the HostRoot node, so they accumulated with each commit. This commitR addresses both issues: 1. First it adds a new DevTools hook, onPostCommitRoot*, to be called after passive effects get flushed. This gives DevTools the opportunity to read passive effect durations (if the build of React being profiled supports it). 2. Second the work loop resets these durations (on the HostRoot) after calling the post-commit hook so address the accumulation problem. I've also added a unit test to guard against this regressing in the future. * Doing this in flushPassiveEffectsImpl seemed simplest, since there are so many places we flush passive effects. Is there any potential problem with this though? --- .../src/__tests__/profilingHostRoot-test.js | 144 ++++++++++++++++++ .../src/backend/legacy/renderer.js | 4 + .../src/backend/renderer.js | 65 +++----- .../src/backend/types.js | 1 + .../src/backend/utils.js | 20 +++ packages/react-devtools-shared/src/hook.js | 8 + .../src/app/InteractionTracing/index.js | 14 +- .../src/ReactFiberDevToolsHook.new.js | 18 +++ .../src/ReactFiberDevToolsHook.old.js | 18 +++ .../src/ReactFiberWorkLoop.new.js | 12 +- .../src/ReactFiberWorkLoop.old.js | 12 +- 11 files changed, 273 insertions(+), 43 deletions(-) create mode 100644 packages/react-devtools-shared/src/__tests__/profilingHostRoot-test.js diff --git a/packages/react-devtools-shared/src/__tests__/profilingHostRoot-test.js b/packages/react-devtools-shared/src/__tests__/profilingHostRoot-test.js new file mode 100644 index 0000000000000..a37401eb4a06e --- /dev/null +++ b/packages/react-devtools-shared/src/__tests__/profilingHostRoot-test.js @@ -0,0 +1,144 @@ +/** + * 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 + */ + +describe('profiling HostRoot', () => { + let React; + let ReactDOM; + let Scheduler; + let store: Store; + let utils; + let getEffectDurations; + + let effectDurations; + let passiveEffectDurations; + + beforeEach(() => { + utils = require('./utils'); + utils.beforeEachProfiling(); + + getEffectDurations = require('../backend/utils').getEffectDurations; + + store = global.store; + + React = require('react'); + ReactDOM = require('react-dom'); + Scheduler = require('scheduler'); + + effectDurations = []; + passiveEffectDurations = []; + + // This is the DevTools hook installed by the env.beforEach() + // The hook is installed as a read-only property on the window, + // so for our test purposes we can just override the commit hook. + const hook = global.__REACT_DEVTOOLS_GLOBAL_HOOK__; + hook.onPostCommitFiberRoot = function onPostCommitFiberRoot( + rendererID, + root, + ) { + const {effectDuration, passiveEffectDuration} = getEffectDurations(root); + effectDurations.push(effectDuration); + passiveEffectDurations.push(passiveEffectDuration); + }; + }); + + it('should expose passive and layout effect durations for render()', () => { + function App() { + React.useEffect(() => { + Scheduler.unstable_advanceTime(10); + }); + React.useLayoutEffect(() => { + Scheduler.unstable_advanceTime(100); + }); + return null; + } + + utils.act(() => store.profilerStore.startProfiling()); + utils.act(() => { + const container = document.createElement('div'); + ReactDOM.render(, container); + }); + utils.act(() => store.profilerStore.stopProfiling()); + + expect(effectDurations).toHaveLength(1); + const effectDuration = effectDurations[0]; + expect(effectDuration === null || effectDuration === 100).toBe(true); + expect(passiveEffectDurations).toHaveLength(1); + const passiveEffectDuration = passiveEffectDurations[0]; + expect(passiveEffectDuration === null || passiveEffectDuration === 10).toBe( + true, + ); + }); + + it('should expose passive and layout effect durations for createRoot()', () => { + function App() { + React.useEffect(() => { + Scheduler.unstable_advanceTime(10); + }); + React.useLayoutEffect(() => { + Scheduler.unstable_advanceTime(100); + }); + return null; + } + + utils.act(() => store.profilerStore.startProfiling()); + utils.act(() => { + const container = document.createElement('div'); + const root = ReactDOM.unstable_createRoot(container); + root.render(); + }); + utils.act(() => store.profilerStore.stopProfiling()); + + expect(effectDurations).toHaveLength(1); + const effectDuration = effectDurations[0]; + expect(effectDuration === null || effectDuration === 100).toBe(true); + expect(passiveEffectDurations).toHaveLength(1); + const passiveEffectDuration = passiveEffectDurations[0]; + expect(passiveEffectDuration === null || passiveEffectDuration === 10).toBe( + true, + ); + }); + + it('should properly reset passive and layout effect durations between commits', () => { + function App({shouldCascade}) { + const [, setState] = React.useState(false); + React.useEffect(() => { + Scheduler.unstable_advanceTime(10); + }); + React.useLayoutEffect(() => { + Scheduler.unstable_advanceTime(100); + }); + React.useLayoutEffect(() => { + if (shouldCascade) { + setState(true); + } + }, [shouldCascade]); + return null; + } + + const container = document.createElement('div'); + const root = ReactDOM.unstable_createRoot(container); + + utils.act(() => store.profilerStore.startProfiling()); + utils.act(() => root.render()); + utils.act(() => root.render()); + utils.act(() => store.profilerStore.stopProfiling()); + + expect(effectDurations).toHaveLength(3); + expect(passiveEffectDurations).toHaveLength(3); + + for (let i = 0; i < effectDurations.length; i++) { + const effectDuration = effectDurations[i]; + expect(effectDuration === null || effectDuration === 100).toBe(true); + const passiveEffectDuration = passiveEffectDurations[i]; + expect( + passiveEffectDuration === null || passiveEffectDuration === 10, + ).toBe(true); + } + }); +}); diff --git a/packages/react-devtools-shared/src/backend/legacy/renderer.js b/packages/react-devtools-shared/src/backend/legacy/renderer.js index 08cbfe340fb6f..fcc7895356aae 100644 --- a/packages/react-devtools-shared/src/backend/legacy/renderer.js +++ b/packages/react-devtools-shared/src/backend/legacy/renderer.js @@ -1012,6 +1012,9 @@ export function attach( const handleCommitFiberUnmount = () => { throw new Error('handleCommitFiberUnmount not supported by this renderer'); }; + const handlePostCommitFiberRoot = () => { + throw new Error('handlePostCommitFiberRoot not supported by this renderer'); + }; const overrideSuspense = () => { throw new Error('overrideSuspense not supported by this renderer'); }; @@ -1082,6 +1085,7 @@ export function attach( getProfilingData, handleCommitFiberRoot, handleCommitFiberUnmount, + handlePostCommitFiberRoot, inspectElement, logElementToConsole, overrideSuspense, diff --git a/packages/react-devtools-shared/src/backend/renderer.js b/packages/react-devtools-shared/src/backend/renderer.js index 050a4e709ab32..07fe8230b5b23 100644 --- a/packages/react-devtools-shared/src/backend/renderer.js +++ b/packages/react-devtools-shared/src/backend/renderer.js @@ -42,6 +42,7 @@ import { copyWithDelete, copyWithRename, copyWithSet, + getEffectDurations, } from './utils'; import { __DEBUG__, @@ -368,6 +369,7 @@ export function getInternalReactConstants( LegacyHiddenComponent, MemoComponent, OffscreenComponent, + Profiler, ScopeComponent, SimpleMemoComponent, SuspenseComponent, @@ -441,6 +443,8 @@ export function getInternalReactConstants( return 'Scope'; case SuspenseListComponent: return 'SuspenseList'; + case Profiler: + return 'Profiler'; default: const typeSymbol = getTypeSymbol(type); @@ -2153,25 +2157,6 @@ export function attach( // Checking root.memoizedInteractions handles multi-renderer edge-case- // where some v16 renderers support profiling and others don't. if (isProfiling && root.memoizedInteractions != null) { - // Profiling durations are only available for certain builds. - // If available, they'll be stored on the HostRoot. - let effectDuration = null; - let passiveEffectDuration = null; - const hostRoot = root.current; - if (hostRoot != null) { - const stateNode = hostRoot.stateNode; - if (stateNode != null) { - effectDuration = - stateNode.effectDuration != null - ? stateNode.effectDuration - : null; - passiveEffectDuration = - stateNode.passiveEffectDuration != null - ? stateNode.passiveEffectDuration - : null; - } - } - // If profiling is active, store commit time and duration, and the current interactions. // The frontend may request this information after profiling has stopped. currentCommitProfilingMetadata = { @@ -2186,8 +2171,8 @@ export function attach( ), maxActualDuration: 0, priorityLevel: null, - effectDuration, - passiveEffectDuration, + effectDuration: null, + passiveEffectDuration: null, }; } @@ -2205,6 +2190,19 @@ export function attach( recordUnmount(fiber, false); } + function handlePostCommitFiberRoot(root) { + const isProfilingSupported = root.memoizedInteractions != null; + if (isProfiling && isProfilingSupported) { + if (currentCommitProfilingMetadata !== null) { + const {effectDuration, passiveEffectDuration} = getEffectDurations( + root, + ); + currentCommitProfilingMetadata.effectDuration = effectDuration; + currentCommitProfilingMetadata.passiveEffectDuration = passiveEffectDuration; + } + } + } + function handleCommitFiberRoot(root, priorityLevel) { const current = root.current; const alternate = current.alternate; @@ -2226,23 +2224,6 @@ export function attach( const isProfilingSupported = root.memoizedInteractions != null; if (isProfiling && isProfilingSupported) { - // Profiling durations are only available for certain builds. - // If available, they'll be stored on the HostRoot. - let effectDuration = null; - let passiveEffectDuration = null; - const hostRoot = root.current; - if (hostRoot != null) { - const stateNode = hostRoot.stateNode; - if (stateNode != null) { - effectDuration = - stateNode.effectDuration != null ? stateNode.effectDuration : null; - passiveEffectDuration = - stateNode.passiveEffectDuration != null - ? stateNode.passiveEffectDuration - : null; - } - } - // If profiling is active, store commit time and duration, and the current interactions. // The frontend may request this information after profiling has stopped. currentCommitProfilingMetadata = { @@ -2258,8 +2239,11 @@ export function attach( maxActualDuration: 0, priorityLevel: priorityLevel == null ? null : formatPriorityLevel(priorityLevel), - effectDuration, - passiveEffectDuration, + + // Initialize to null; if new enough React version is running, + // these values will be read during separate handlePostCommitFiberRoot() call. + effectDuration: null, + passiveEffectDuration: null, }; } @@ -3855,6 +3839,7 @@ export function attach( getProfilingData, handleCommitFiberRoot, handleCommitFiberUnmount, + handlePostCommitFiberRoot, inspectElement, logElementToConsole, prepareViewAttributeSource, diff --git a/packages/react-devtools-shared/src/backend/types.js b/packages/react-devtools-shared/src/backend/types.js index c0ef91021f073..ea83d77666175 100644 --- a/packages/react-devtools-shared/src/backend/types.js +++ b/packages/react-devtools-shared/src/backend/types.js @@ -326,6 +326,7 @@ export type RendererInterface = { getPathForElement: (id: number) => Array | null, handleCommitFiberRoot: (fiber: Object, commitPriority?: number) => void, handleCommitFiberUnmount: (fiber: Object) => void, + handlePostCommitFiberRoot: (fiber: Object) => void, inspectElement: ( requestID: number, id: number, diff --git a/packages/react-devtools-shared/src/backend/utils.js b/packages/react-devtools-shared/src/backend/utils.js index 7a4ff6295ab99..3735aa8f85c05 100644 --- a/packages/react-devtools-shared/src/backend/utils.js +++ b/packages/react-devtools-shared/src/backend/utils.js @@ -117,6 +117,26 @@ export function copyWithSet( return updated; } +export function getEffectDurations(root: Object) { + // Profiling durations are only available for certain builds. + // If available, they'll be stored on the HostRoot. + let effectDuration = null; + let passiveEffectDuration = null; + const hostRoot = root.current; + if (hostRoot != null) { + const stateNode = hostRoot.stateNode; + if (stateNode != null) { + effectDuration = + stateNode.effectDuration != null ? stateNode.effectDuration : null; + passiveEffectDuration = + stateNode.passiveEffectDuration != null + ? stateNode.passiveEffectDuration + : null; + } + } + return {effectDuration, passiveEffectDuration}; +} + export function serializeToString(data: any): string { const cache = new Set(); // Use a custom replacer function to protect against circular references. diff --git a/packages/react-devtools-shared/src/hook.js b/packages/react-devtools-shared/src/hook.js index e29ad7abe956d..a4724f6f6b92b 100644 --- a/packages/react-devtools-shared/src/hook.js +++ b/packages/react-devtools-shared/src/hook.js @@ -287,6 +287,13 @@ export function installHook(target: any): DevToolsHook | null { } } + function onPostCommitFiberRoot(rendererID, root) { + const rendererInterface = rendererInterfaces.get(rendererID); + if (rendererInterface != null) { + rendererInterface.handlePostCommitFiberRoot(root); + } + } + // TODO: More meaningful names for "rendererInterfaces" and "renderers". const fiberRoots = {}; const rendererInterfaces = new Map(); @@ -315,6 +322,7 @@ export function installHook(target: any): DevToolsHook | null { checkDCE, onCommitFiberUnmount, onCommitFiberRoot, + onPostCommitFiberRoot, }; Object.defineProperty( diff --git a/packages/react-devtools-shell/src/app/InteractionTracing/index.js b/packages/react-devtools-shell/src/app/InteractionTracing/index.js index 544b335d0b36a..aab8e77e90910 100644 --- a/packages/react-devtools-shell/src/app/InteractionTracing/index.js +++ b/packages/react-devtools-shell/src/app/InteractionTracing/index.js @@ -21,6 +21,14 @@ import { unstable_wrap as wrap, } from 'scheduler/tracing'; +function sleep(ms) { + const start = performance.now(); + let now; + do { + now = performance.now(); + } while (now - ms < start); +} + export default function InteractionTracing() { const [count, setCount] = useState(0); const [shouldCascade, setShouldCascade] = useState(false); @@ -75,7 +83,11 @@ export default function InteractionTracing() { }, [count, shouldCascade]); useLayoutEffect(() => { - Math.sqrt(100 * 100 * 100 * 100 * 100); + sleep(150); + }); + + useEffect(() => { + sleep(300); }); return ( diff --git a/packages/react-reconciler/src/ReactFiberDevToolsHook.new.js b/packages/react-reconciler/src/ReactFiberDevToolsHook.new.js index a98e569b095b9..e7bde59e20cba 100644 --- a/packages/react-reconciler/src/ReactFiberDevToolsHook.new.js +++ b/packages/react-reconciler/src/ReactFiberDevToolsHook.new.js @@ -134,6 +134,24 @@ export function onCommitRoot(root: FiberRoot, eventPriority: EventPriority) { } } +export function onPostCommitRoot(root: FiberRoot) { + if ( + injectedHook && + typeof injectedHook.onPostCommitFiberRoot === 'function' + ) { + try { + injectedHook.onPostCommitFiberRoot(rendererID, root); + } catch (err) { + if (__DEV__) { + if (!hasLoggedError) { + hasLoggedError = true; + console.error('React instrumentation encountered an error: %s', err); + } + } + } + } +} + export function onCommitUnmount(fiber: Fiber) { if (injectedHook && typeof injectedHook.onCommitFiberUnmount === 'function') { try { diff --git a/packages/react-reconciler/src/ReactFiberDevToolsHook.old.js b/packages/react-reconciler/src/ReactFiberDevToolsHook.old.js index 43b9f360faa3a..494138685e104 100644 --- a/packages/react-reconciler/src/ReactFiberDevToolsHook.old.js +++ b/packages/react-reconciler/src/ReactFiberDevToolsHook.old.js @@ -134,6 +134,24 @@ export function onCommitRoot(root: FiberRoot, eventPriority: EventPriority) { } } +export function onPostCommitRoot(root: FiberRoot) { + if ( + injectedHook && + typeof injectedHook.onPostCommitFiberRoot === 'function' + ) { + try { + injectedHook.onPostCommitFiberRoot(rendererID, root); + } catch (err) { + if (__DEV__) { + if (!hasLoggedError) { + hasLoggedError = true; + console.error('React instrumentation encountered an error: %s', err); + } + } + } + } +} + export function onCommitUnmount(fiber: Fiber) { if (injectedHook && typeof injectedHook.onCommitFiberUnmount === 'function') { try { diff --git a/packages/react-reconciler/src/ReactFiberWorkLoop.new.js b/packages/react-reconciler/src/ReactFiberWorkLoop.new.js index 455067e47e263..4c8dc6a1ae8e6 100644 --- a/packages/react-reconciler/src/ReactFiberWorkLoop.new.js +++ b/packages/react-reconciler/src/ReactFiberWorkLoop.new.js @@ -229,7 +229,10 @@ import { hasCaughtError, clearCaughtError, } from 'shared/ReactErrorUtils'; -import {onCommitRoot as onCommitRootDevTools} from './ReactFiberDevToolsHook.new'; +import { + onCommitRoot as onCommitRootDevTools, + onPostCommitRoot as onPostCommitRootDevTools, +} from './ReactFiberDevToolsHook.new'; import {onCommitRoot as onCommitRootTestSelector} from './ReactTestSelectors'; // Used by `act` @@ -2158,6 +2161,13 @@ function flushPassiveEffectsImpl() { nestedPassiveUpdateCount = rootWithPendingPassiveEffects === null ? 0 : nestedPassiveUpdateCount + 1; + onPostCommitRootDevTools(root); + if (enableProfilerTimer && enableProfilerCommitHooks) { + const stateNode = root.current.stateNode; + stateNode.effectDuration = 0; + stateNode.passiveEffectDuration = 0; + } + return true; } diff --git a/packages/react-reconciler/src/ReactFiberWorkLoop.old.js b/packages/react-reconciler/src/ReactFiberWorkLoop.old.js index 9d056a46402c3..db759eb5ce43b 100644 --- a/packages/react-reconciler/src/ReactFiberWorkLoop.old.js +++ b/packages/react-reconciler/src/ReactFiberWorkLoop.old.js @@ -229,7 +229,10 @@ import { hasCaughtError, clearCaughtError, } from 'shared/ReactErrorUtils'; -import {onCommitRoot as onCommitRootDevTools} from './ReactFiberDevToolsHook.old'; +import { + onCommitRoot as onCommitRootDevTools, + onPostCommitRoot as onPostCommitRootDevTools, +} from './ReactFiberDevToolsHook.old'; import {onCommitRoot as onCommitRootTestSelector} from './ReactTestSelectors'; // Used by `act` @@ -2158,6 +2161,13 @@ function flushPassiveEffectsImpl() { nestedPassiveUpdateCount = rootWithPendingPassiveEffects === null ? 0 : nestedPassiveUpdateCount + 1; + onPostCommitRootDevTools(root); + if (enableProfilerTimer && enableProfilerCommitHooks) { + const stateNode = root.current.stateNode; + stateNode.effectDuration = 0; + stateNode.passiveEffectDuration = 0; + } + return true; }