Profiler: Include ref callbacks in onCommit duration (#20060)

Brian Vaughn · web-flow · commit d1bb4d851f49 · 2020-10-20T14:35:57.000-04:00
diff --git a/packages/react-reconciler/src/ReactFiberCommitWork.new.js b/packages/react-reconciler/src/ReactFiberCommitWork.new.js
@@ -194,14 +194,38 @@ function safelyDetachRef(current: Fiber, nearestMountedAncestor: Fiber) {
   if (ref !== null) {
     if (typeof ref === 'function') {
       if (__DEV__) {
-        invokeGuardedCallback(null, ref, null, null);
+        if (
+          enableProfilerTimer &&
+          enableProfilerCommitHooks &&
+          current.mode & ProfileMode
+        ) {
+          startLayoutEffectTimer();
+          invokeGuardedCallback(null, ref, null, null);
+          recordLayoutEffectDuration(current);
+        } else {
+          invokeGuardedCallback(null, ref, null, null);
+        }
+
         if (hasCaughtError()) {
           const refError = clearCaughtError();
           captureCommitPhaseError(current, nearestMountedAncestor, refError);
         }
       } else {
         try {
-          ref(null);
+          if (
+            enableProfilerTimer &&
+            enableProfilerCommitHooks &&
+            current.mode & ProfileMode
+          ) {
+            try {
+              startLayoutEffectTimer();
+              ref(null);
+            } finally {
+              recordLayoutEffectDuration(current);
+            }
+          } else {
+            ref(null);
+          }
         } catch (refError) {
           captureCommitPhaseError(current, nearestMountedAncestor, refError);
         }
@@ -965,7 +989,20 @@ function commitAttachRef(finishedWork: Fiber) {
       instanceToUse = instance;
     }
     if (typeof ref === 'function') {
-      ref(instanceToUse);
+      if (
+        enableProfilerTimer &&
+        enableProfilerCommitHooks &&
+        finishedWork.mode & ProfileMode
+      ) {
+        try {
+          startLayoutEffectTimer();
+          ref(instanceToUse);
+        } finally {
+          recordLayoutEffectDuration(finishedWork);
+        }
+      } else {
+        ref(instanceToUse);
+      }
     } else {
       if (__DEV__) {
         if (!ref.hasOwnProperty('current')) {
@@ -986,7 +1023,20 @@ function commitDetachRef(current: Fiber) {
   const currentRef = current.ref;
   if (currentRef !== null) {
     if (typeof currentRef === 'function') {
-      currentRef(null);
+      if (
+        enableProfilerTimer &&
+        enableProfilerCommitHooks &&
+        current.mode & ProfileMode
+      ) {
+        try {
+          startLayoutEffectTimer();
+          currentRef(null);
+        } finally {
+          recordLayoutEffectDuration(current);
+        }
+      } else {
+        currentRef(null);
+      }
     } else {
       currentRef.current = null;
     }
diff --git a/packages/react-reconciler/src/ReactFiberCommitWork.old.js b/packages/react-reconciler/src/ReactFiberCommitWork.old.js
@@ -180,14 +180,38 @@ function safelyDetachRef(current: Fiber) {
   if (ref !== null) {
     if (typeof ref === 'function') {
       if (__DEV__) {
-        invokeGuardedCallback(null, ref, null, null);
+        if (
+          enableProfilerTimer &&
+          enableProfilerCommitHooks &&
+          current.mode & ProfileMode
+        ) {
+          startLayoutEffectTimer();
+          invokeGuardedCallback(null, ref, null, null);
+          recordLayoutEffectDuration(current);
+        } else {
+          invokeGuardedCallback(null, ref, null, null);
+        }
+
         if (hasCaughtError()) {
           const refError = clearCaughtError();
           captureCommitPhaseError(current, refError);
         }
       } else {
         try {
-          ref(null);
+          if (
+            enableProfilerTimer &&
+            enableProfilerCommitHooks &&
+            current.mode & ProfileMode
+          ) {
+            try {
+              startLayoutEffectTimer();
+              ref(null);
+            } finally {
+              recordLayoutEffectDuration(current);
+            }
+          } else {
+            ref(null);
+          }
         } catch (refError) {
           captureCommitPhaseError(current, refError);
         }
@@ -832,7 +856,20 @@ function commitAttachRef(finishedWork: Fiber) {
       instanceToUse = instance;
     }
     if (typeof ref === 'function') {
-      ref(instanceToUse);
+      if (
+        enableProfilerTimer &&
+        enableProfilerCommitHooks &&
+        finishedWork.mode & ProfileMode
+      ) {
+        try {
+          startLayoutEffectTimer();
+          ref(instanceToUse);
+        } finally {
+          recordLayoutEffectDuration(finishedWork);
+        }
+      } else {
+        ref(instanceToUse);
+      }
     } else {
       if (__DEV__) {
         if (!ref.hasOwnProperty('current')) {
@@ -853,7 +890,20 @@ function commitDetachRef(current: Fiber) {
   const currentRef = current.ref;
   if (currentRef !== null) {
     if (typeof currentRef === 'function') {
-      currentRef(null);
+      if (
+        enableProfilerTimer &&
+        enableProfilerCommitHooks &&
+        current.mode & ProfileMode
+      ) {
+        try {
+          startLayoutEffectTimer();
+          currentRef(null);
+        } finally {
+          recordLayoutEffectDuration(current);
+        }
+      } else {
+        currentRef(null);
+      }
     } else {
       currentRef.current = null;
     }
diff --git a/packages/react/src/__tests__/ReactProfiler-test.internal.js b/packages/react/src/__tests__/ReactProfiler-test.internal.js
@@ -1491,6 +1491,61 @@ describe('Profiler', () => {
         expect(call[4]).toEqual(enableSchedulerTracing ? new Set() : undefined); // interaction events
       });
 
+      it('should include time spent in ref callbacks', () => {
+        const callback = jest.fn();
+
+        const refSetter = ref => {
+          if (ref !== null) {
+            Scheduler.unstable_advanceTime(10);
+          } else {
+            Scheduler.unstable_advanceTime(100);
+          }
+        };
+
+        class ClassComponent extends React.Component {
+          render() {
+            return null;
+          }
+        }
+
+        const Component = () => {
+          Scheduler.unstable_advanceTime(1000);
+          return <ClassComponent ref={refSetter} />;
+        };
+
+        Scheduler.unstable_advanceTime(1);
+
+        const renderer = ReactTestRenderer.create(
+          <React.Profiler id="root" onCommit={callback}>
+            <Component />
+          </React.Profiler>,
+        );
+
+        expect(callback).toHaveBeenCalledTimes(1);
+
+        let call = callback.mock.calls[0];
+
+        expect(call).toHaveLength(enableSchedulerTracing ? 5 : 4);
+        expect(call[0]).toBe('root');
+        expect(call[1]).toBe('mount');
+        expect(call[2]).toBe(10); // durations
+        expect(call[3]).toBe(1001); // commit start time (before mutations or effects)
+
+        callback.mockClear();
+
+        renderer.update(<React.Profiler id="root" onCommit={callback} />);
+
+        expect(callback).toHaveBeenCalledTimes(1);
+
+        call = callback.mock.calls[0];
+
+        expect(call).toHaveLength(enableSchedulerTracing ? 5 : 4);
+        expect(call[0]).toBe('root');
+        expect(call[1]).toBe('update');
+        expect(call[2]).toBe(100); // durations
+        expect(call[3]).toBe(1011); // commit start time (before mutations or effects)
+      });
+
       it('should bubble time spent in layout effects to higher profilers', () => {
         const callback = jest.fn();
 
