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?

Author: Brian Vaughn

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(<App />, 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(<App />);
+    });
+    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(<App />));
+    utils.act(() => root.render(<App shouldCascade={true} />));
+    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);
+    }
+  });
+});

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,

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,

packages/react-devtools-shared/src/backend/types.js

@@ -326,6 +326,7 @@ export type RendererInterface = {
   getPathForElement: (id: number) => Array<PathFrame> | null,
   handleCommitFiberRoot: (fiber: Object, commitPriority?: number) => void,
   handleCommitFiberUnmount: (fiber: Object) => void,
+  handlePostCommitFiberRoot: (fiber: Object) => void,
   inspectElement: (
     requestID: number,
     id: number,

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.

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(

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 (