[DevTools] Add initial APIs for logging instrumentation events under …

…feature flag (#22276)
facebook · Sep 14, 2021 · 50263d3 · 50263d3
1 parent 263cfa6
commit 50263d3
Show file tree

Hide file tree

Showing 13 changed files with 234 additions and 110 deletions.
diff --git a/packages/react-devtools-extensions/src/main.js b/packages/react-devtools-extensions/src/main.js
@@ -18,6 +18,7 @@ import {
   localStorageRemoveItem,
   localStorageSetItem,
 } from 'react-devtools-shared/src/storage';
+import {registerEventLogger} from 'react-devtools-shared/src/Logger';
 import DevTools from 'react-devtools-shared/src/devtools/views/DevTools';
 import {__DEBUG__} from 'react-devtools-shared/src/constants';
 
@@ -87,6 +88,10 @@ function createPanelIfReactLoaded() {
 
       const tabId = chrome.devtools.inspectedWindow.tabId;
 
+      registerEventLogger((event: LogEvent) => {
+        // TODO: hook up event logging
+      });
+
       function initBridgeAndStore() {
         const port = chrome.runtime.connect({
           name: '' + tabId,

diff --git a/packages/react-devtools-shared/src/Logger.js b/packages/react-devtools-shared/src/Logger.js
@@ -0,0 +1,47 @@
+/**
+ * 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 strict-local
+ */
+
+import {enableLogger} from 'react-devtools-feature-flags';
+
+type LoadHookNamesEvent = {|
+  +name: 'loadHookNames',
+  +displayName: string | null,
+  +numberOfHooks: number | null,
+  +durationMs: number,
+  +resolution: 'success' | 'error' | 'timeout' | 'unknown',
+|};
+
+// prettier-ignore
+export type LogEvent =
+  | LoadHookNamesEvent;
+
+export type LogFunction = LogEvent => void;
+
+let loggers: Array<LogFunction> = [];
+export const logEvent: LogFunction =
+  enableLogger === true
+    ? function logEvent(event: LogEvent): void {
+        loggers.forEach(log => {
+          log(event);
+        });
+      }
+    : function logEvent() {};
+
+export const registerEventLogger =
+  enableLogger === true
+    ? function registerEventLogger(eventLogger: LogFunction): () => void {
+        if (enableLogger) {
+          loggers.push(eventLogger);
+          return function unregisterEventLogger() {
+            loggers = loggers.filter(logger => logger !== eventLogger);
+          };
+        }
+        return () => {};
+      }
+    : function registerEventLogger() {};
diff --git a/...t-devtools-shared/src/PerformanceMarks.js → ...ols-shared/src/PerformanceLoggingUtils.js b/...t-devtools-shared/src/PerformanceMarks.js → ...ols-shared/src/PerformanceLoggingUtils.js
@@ -14,6 +14,9 @@ const supportsUserTiming =
   typeof performance.mark === 'function' &&
   typeof performance.clearMarks === 'function';
 
+const supportsPerformanceNow =
+  typeof performance !== 'undefined' && typeof performance.now === 'function';
+
 function mark(markName: string): void {
   if (supportsUserTiming) {
     performance.mark(markName + '-start');
@@ -27,42 +30,78 @@ function measure(markName: string): void {
   }
 }
 
-export async function withAsyncPerformanceMark<TReturn>(
+function now(): number {
+  if (supportsPerformanceNow) {
+    return performance.now();
+  }
+  return Date.now();
+}
+
+export async function withAsyncPerfMeasurements<TReturn>(
   markName: string,
   callback: () => Promise<TReturn>,
+  onComplete?: number => void,
 ): Promise<TReturn> {
+  const start = now();
   if (__PERFORMANCE_PROFILE__) {
     mark(markName);
-    const result = await callback();
+  }
+  const result = await callback();
+
+  if (__PERFORMANCE_PROFILE__) {
     measure(markName);
-    return result;
   }
-  return callback();
+
+  if (onComplete != null) {
+    const duration = now() - start;
+    onComplete(duration);
+  }
+
+  return result;
 }
 
-export function withSyncPerformanceMark<TReturn>(
+export function withSyncPerfMeasurements<TReturn>(
   markName: string,
   callback: () => TReturn,
+  onComplete?: number => void,
 ): TReturn {
+  const start = now();
   if (__PERFORMANCE_PROFILE__) {
     mark(markName);
-    const result = callback();
+  }
+  const result = callback();
+
+  if (__PERFORMANCE_PROFILE__) {
     measure(markName);
-    return result;
   }
-  return callback();
+
+  if (onComplete != null) {
+    const duration = now() - start;
+    onComplete(duration);
+  }
+
+  return result;
 }
 
-export function withCallbackPerformanceMark<TReturn>(
+export function withCallbackPerfMeasurements<TReturn>(
   markName: string,
   callback: (done: () => void) => TReturn,
+  onComplete?: number => void,
 ): TReturn {
+  const start = now();
   if (__PERFORMANCE_PROFILE__) {
     mark(markName);
-    const done = () => {
-      measure(markName);
-    };
-    return callback(done);
   }
-  return callback(() => {});
+
+  const done = () => {
+    if (__PERFORMANCE_PROFILE__) {
+      measure(markName);
+    }
+
+    if (onComplete != null) {
+      const duration = now() - start;
+      onComplete(duration);
+    }
+  };
+  return callback(done);
 }
diff --git a/packages/react-devtools-shared/src/config/DevToolsFeatureFlags.core-fb.js b/packages/react-devtools-shared/src/config/DevToolsFeatureFlags.core-fb.js
@@ -16,6 +16,7 @@
 export const enableProfilerChangedHookIndices = true;
 export const isInternalFacebookBuild = true;
 export const enableNamedHooksFeature = false;
+export const enableLogger = false;
 export const consoleManagedByDevToolsDuringStrictMode = false;
 
 /************************************************************************

diff --git a/packages/react-devtools-shared/src/config/DevToolsFeatureFlags.core-oss.js b/packages/react-devtools-shared/src/config/DevToolsFeatureFlags.core-oss.js
@@ -16,6 +16,7 @@
 export const enableProfilerChangedHookIndices = false;
 export const isInternalFacebookBuild = false;
 export const enableNamedHooksFeature = false;
+export const enableLogger = false;
 export const consoleManagedByDevToolsDuringStrictMode = false;
 
 /************************************************************************

diff --git a/packages/react-devtools-shared/src/config/DevToolsFeatureFlags.default.js b/packages/react-devtools-shared/src/config/DevToolsFeatureFlags.default.js
@@ -16,4 +16,5 @@
 export const enableProfilerChangedHookIndices = false;
 export const isInternalFacebookBuild = false;
 export const enableNamedHooksFeature = true;
+export const enableLogger = false;
 export const consoleManagedByDevToolsDuringStrictMode = true;
diff --git a/packages/react-devtools-shared/src/config/DevToolsFeatureFlags.extension-fb.js b/packages/react-devtools-shared/src/config/DevToolsFeatureFlags.extension-fb.js
@@ -16,6 +16,7 @@
 export const enableProfilerChangedHookIndices = true;
 export const isInternalFacebookBuild = true;
 export const enableNamedHooksFeature = true;
+export const enableLogger = false;
 export const consoleManagedByDevToolsDuringStrictMode = true;
 
 /************************************************************************

diff --git a/packages/react-devtools-shared/src/config/DevToolsFeatureFlags.extension-oss.js b/packages/react-devtools-shared/src/config/DevToolsFeatureFlags.extension-oss.js
@@ -16,6 +16,7 @@
 export const enableProfilerChangedHookIndices = true;
 export const isInternalFacebookBuild = false;
 export const enableNamedHooksFeature = true;
+export const enableLogger = false;
 export const consoleManagedByDevToolsDuringStrictMode = true;
 
 /************************************************************************

diff --git a/packages/react-devtools-shared/src/hookNamesCache.js b/packages/react-devtools-shared/src/hookNamesCache.js
@@ -18,6 +18,8 @@ import type {
 } from 'react-devtools-shared/src/types';
 import type {HookSource} from 'react-debug-tools/src/ReactDebugHooks';
 import type {FetchFileWithCaching} from 'react-devtools-shared/src/devtools/views/Components/FetchFileWithCachingContext';
+import {withCallbackPerfMeasurements} from './PerformanceLoggingUtils';
+import {logEvent} from './Logger';
 
 const TIMEOUT = 30000;
 
@@ -92,6 +94,11 @@ export function loadHookNames(
       },
     };
 
+    let timeoutID;
+    let didTimeout = false;
+    let resolution = 'unknown';
+    let resolvedHookNames: HookNames | null = null;
+
     const wake = () => {
       if (timeoutID) {
         clearTimeout(timeoutID);
@@ -103,71 +110,92 @@ export function loadHookNames(
       callbacks.clear();
     };
 
+    const handleLoadComplete = (durationMs: number): void => {
+      // Log duration for parsing hook names
+      logEvent({
+        name: 'loadHookNames',
+        displayName: element.displayName,
+        numberOfHooks: resolvedHookNames?.size ?? null,
+        durationMs,
+        resolution,
+      });
+    };
+
     const newRecord: Record<HookNames> = (record = {
       status: Pending,
       value: wakeable,
     });
 
-    let didTimeout = false;
-
-    loadHookNamesFunction(hooksTree, fetchFileWithCaching).then(
-      function onSuccess(hookNames) {
-        if (didTimeout) {
-          return;
-        }
-
-        if (__DEBUG__) {
-          console.log('[hookNamesCache] onSuccess() hookNames:', hookNames);
-        }
-
-        if (hookNames) {
-          const resolvedRecord = ((newRecord: any): ResolvedRecord<HookNames>);
-          resolvedRecord.status = Resolved;
-          resolvedRecord.value = hookNames;
-        } else {
-          const notFoundRecord = ((newRecord: any): RejectedRecord);
-          notFoundRecord.status = Rejected;
-          notFoundRecord.value = null;
-        }
-
-        wake();
-      },
-      function onError(error) {
-        if (didTimeout) {
-          return;
-        }
-
-        if (__DEBUG__) {
-          console.log('[hookNamesCache] onError()');
-        }
-
-        console.error(error);
-
-        const thrownRecord = ((newRecord: any): RejectedRecord);
-        thrownRecord.status = Rejected;
-        thrownRecord.value = null;
-
-        wake();
+    withCallbackPerfMeasurements(
+      'loadHookNames',
+      done => {
+        loadHookNamesFunction(hooksTree, fetchFileWithCaching).then(
+          function onSuccess(hookNames) {
+            if (didTimeout) {
+              return;
+            }
+
+            if (__DEBUG__) {
+              console.log('[hookNamesCache] onSuccess() hookNames:', hookNames);
+            }
+
+            if (hookNames) {
+              const resolvedRecord = ((newRecord: any): ResolvedRecord<HookNames>);
+              resolvedRecord.status = Resolved;
+              resolvedRecord.value = hookNames;
+            } else {
+              const notFoundRecord = ((newRecord: any): RejectedRecord);
+              notFoundRecord.status = Rejected;
+              notFoundRecord.value = null;
+            }
+
+            resolution = 'success';
+            resolvedHookNames = hookNames;
+            done();
+            wake();
+          },
+          function onError(error) {
+            if (didTimeout) {
+              return;
+            }
+
+            if (__DEBUG__) {
+              console.log('[hookNamesCache] onError()');
+            }
+
+            console.error(error);
+
+            const thrownRecord = ((newRecord: any): RejectedRecord);
+            thrownRecord.status = Rejected;
+            thrownRecord.value = null;
+
+            resolution = 'error';
+            done();
+            wake();
+          },
+        );
+
+        // Eventually timeout and stop trying to load names.
+        timeoutID = setTimeout(function onTimeout() {
+          if (__DEBUG__) {
+            console.log('[hookNamesCache] onTimeout()');
+          }
+
+          timeoutID = null;
+
+          didTimeout = true;
+
+          const timedoutRecord = ((newRecord: any): RejectedRecord);
+          timedoutRecord.status = Rejected;
+          timedoutRecord.value = null;
+
+          resolution = 'timeout';
+          done();
+          wake();
+        }, TIMEOUT);
       },
+      handleLoadComplete,
     );
-
-    // Eventually timeout and stop trying to load names.
-    let timeoutID = setTimeout(function onTimeout() {
-      if (__DEBUG__) {
-        console.log('[hookNamesCache] onTimeout()');
-      }
-
-      timeoutID = null;
-
-      didTimeout = true;
-
-      const timedoutRecord = ((newRecord: any): RejectedRecord);
-      timedoutRecord.status = Rejected;
-      timedoutRecord.value = null;
-
-      wake();
-    }, TIMEOUT);
-
     map.set(element, record);
   }