From 46cfff24aa01205d1b05b4ee3d38170f42080f2e Mon Sep 17 00:00:00 2001 From: Brian Vaughn Date: Thu, 8 Apr 2021 22:04:51 -0400 Subject: [PATCH] DevTools: Add post-commit hook (#21183) 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 | 13 +- .../src/ReactFiberWorkLoop.old.js | 13 +- 11 files changed, 275 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 c61edb45daa65..09042d0446b29 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__, @@ -369,6 +370,7 @@ export function getInternalReactConstants( LegacyHiddenComponent, MemoComponent, OffscreenComponent, + Profiler, ScopeComponent, SimpleMemoComponent, SuspenseComponent, @@ -442,6 +444,8 @@ export function getInternalReactConstants( return 'Scope'; case SuspenseListComponent: return 'SuspenseList'; + case Profiler: + return 'Profiler'; default: const typeSymbol = getTypeSymbol(type); @@ -2154,25 +2158,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 = { @@ -2187,8 +2172,8 @@ export function attach( ), maxActualDuration: 0, priorityLevel: null, - effectDuration, - passiveEffectDuration, + effectDuration: null, + passiveEffectDuration: null, }; } @@ -2206,6 +2191,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; @@ -2227,23 +2225,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 = { @@ -2259,8 +2240,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, }; } @@ -3856,6 +3840,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 593459d78f646..22f70e32e7d02 100644 --- a/packages/react-devtools-shared/src/backend/utils.js +++ b/packages/react-devtools-shared/src/backend/utils.js @@ -118,6 +118,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 425c46851aaba..3344361075e66 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` @@ -2156,6 +2159,14 @@ function flushPassiveEffectsImpl() { nestedPassiveUpdateCount = rootWithPendingPassiveEffects === null ? 0 : nestedPassiveUpdateCount + 1; + // TODO: Move to commitPassiveMountEffects + 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 b22901ff84ec3..73230f5787772 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` @@ -2156,6 +2159,14 @@ function flushPassiveEffectsImpl() { nestedPassiveUpdateCount = rootWithPendingPassiveEffects === null ? 0 : nestedPassiveUpdateCount + 1; + // TODO: Move to commitPassiveMountEffects + onPostCommitRootDevTools(root); + if (enableProfilerTimer && enableProfilerCommitHooks) { + const stateNode = root.current.stateNode; + stateNode.effectDuration = 0; + stateNode.passiveEffectDuration = 0; + } + return true; }