[No QA] Performance tracking with flipper-plugin-performance

babel.config.js

@@ -1,3 +1,5 @@
+require('dotenv').config();
+
 const defaultPresets = ['@babel/preset-react', '@babel/preset-env', '@babel/preset-flow'];
 const defaultPlugins = [
     // Adding the commonjs: true option to react-native-web plugin can cause styling conflicts
@@ -34,6 +36,24 @@ const metro = {
     ],
 };
 
+/* When CAPTURE_METRICS is set we add these aliases to also capture
+ * React.Profiler metrics for release builds */
+if (process.env.CAPTURE_METRICS) {
+    const path = require('path');
+    const profilingRenderer = path.resolve(
+        __dirname,
+        './node_modules/react-native/Libraries/Renderer/implementations/ReactNativeRenderer-profiling',
+    );
+
+    metro.plugins.push(['module-resolver', {
+        root: ['./'],
+        alias: {
+            'ReactNativeRenderer-prod': profilingRenderer,
+            'scheduler/tracing': 'scheduler/tracing-profiling',
+        },
+    }]);
+}
+
 module.exports = ({caller}) => {
     // For `react-native` (iOS/Android) caller will be "metro"
     // For `webpack` (Web) caller will be "@babel-loader"

ios/Podfile.lock

@@ -105,6 +105,8 @@ PODS:
     - OpenSSL-Universal (= 1.1.180)
   - Flipper-Glog (0.3.6)
   - Flipper-PeerTalk (0.0.4)
+  - flipper-plugin-react-native-performance (0.6.0):
+    - React
   - Flipper-RSocket (1.3.1):
     - Flipper-Folly (~> 2.5)
   - FlipperKit (0.75.1):
@@ -412,7 +414,7 @@ PODS:
     - React-Core
   - react-native-document-picker (5.1.0):
     - React-Core
-  - react-native-flipper (0.100.0):
+  - react-native-flipper (0.103.0):
     - React-Core
   - react-native-image-picker (4.0.3):
     - React-Core
@@ -598,6 +600,7 @@ DEPENDENCIES:
   - Flipper-Folly (~> 2.5.3)
   - Flipper-Glog (= 0.3.6)
   - Flipper-PeerTalk (~> 0.0.4)
+  - flipper-plugin-react-native-performance (from `../node_modules/flipper-plugin-react-native-performance/ios`)
   - Flipper-RSocket (~> 1.3)
   - FlipperKit (~> 0.75.1)
   - FlipperKit/Core (~> 0.75.1)
@@ -731,6 +734,8 @@ EXTERNAL SOURCES:
     :path: "../node_modules/react-native/Libraries/FBLazyVector"
   FBReactNativeSpec:
     :path: "../node_modules/react-native/React/FBReactNativeSpec"
+  flipper-plugin-react-native-performance:
+    :path: "../node_modules/flipper-plugin-react-native-performance/ios"
   glog:
     :podspec: "../node_modules/react-native/third-party-podspecs/glog.podspec"
   onfido-react-native-sdk:
@@ -877,7 +882,7 @@ SPEC CHECKSUMS:
   DoubleConversion: cf9b38bf0b2d048436d9a82ad2abe1404f11e7de
   EXHaptics: 337c160c148baa6f0e7166249f368965906e346b
   FBLazyVector: 7b423f9e248eae65987838148c36eec1dbfe0b53
-  FBReactNativeSpec: 884d4cc2b011759361797a4035c47e10099393b5
+  FBReactNativeSpec: d2bbf7ed8374a5ef7e82afdce19c4e50731f1f0e
   Firebase: 54cdc8bc9c9b3de54f43dab86e62f5a76b47034f
   FirebaseABTesting: 4cb61aeeb50f60680af1c01fff781dfaf9293916
   FirebaseAnalytics: 4751d6a49598a2b58da678cc07df696bcd809ab9
@@ -892,6 +897,7 @@ SPEC CHECKSUMS:
   Flipper-Folly: 755929a4f851b2fb2c347d533a23f191b008554c
   Flipper-Glog: 1dfd6abf1e922806c52ceb8701a3599a79a200a6
   Flipper-PeerTalk: 116d8f857dc6ef55c7a5a75ea3ceaafe878aadc9
+  flipper-plugin-react-native-performance: c639bbaf0e0444bab8eeb86dad93651c2e13291e
   Flipper-RSocket: 127954abe8b162fcaf68d2134d34dc2bd7076154
   FlipperKit: 8a20b5c5fcf9436cac58551dc049867247f64b00
   glog: 73c2498ac6884b13ede40eda8228cb1eee9d9d62
@@ -923,7 +929,7 @@ SPEC CHECKSUMS:
   React-jsinspector: 500a59626037be5b3b3d89c5151bc3baa9abf1a9
   react-native-config: d8b45133fd13d4f23bd2064b72f6e2c08b2763ed
   react-native-document-picker: 0e3602a4064da040321bafad6848d8b0edcb1d55
-  react-native-flipper: 1943b82f2e494c77b741eb1ed257b6734a334b83
+  react-native-flipper: 169e8ba429b73ad637ce007337ce4b415e783799
   react-native-image-picker: 4089335b89b625d4e34d53fb249c48a7a791b3ea
   react-native-netinfo: 52cf0ee8342548a485e28f4b09e56b477567244d
   react-native-pdf: 4b5a9e4465a6a3b399e91dc4838eb44ddf716d1f

package.json

@@ -84,7 +84,7 @@
     "react-native-image-picker": "^4.0.3",
     "react-native-keyboard-spacer": "^0.4.1",
     "react-native-modal": "^11.10.0",
-    "react-native-onyx": "git+https://github.com/Expensify/react-native-onyx.git#f3b24dd2c947bb4b9b60dc3718dc170f93f751f0",
+    "react-native-onyx": "git+https://github.com/kidroca/react-native-onyx.git#4c17f3d305b26792a252b14b959d112b8d524081",
     "react-native-pdf": "^6.2.2",
     "react-native-performance": "^2.0.0",
     "react-native-permissions": "^3.0.1",
@@ -150,6 +150,7 @@
     "eslint-plugin-detox": "^1.0.0",
     "eslint-plugin-jest": "^24.1.0",
     "flipper-plugin-bridgespy-client": "^0.1.9",
+    "flipper-plugin-react-native-performance": "^0.6.0",
     "html-webpack-plugin": "^4.3.0",
     "jest": "^26.5.2",
     "jest-circus": "^26.5.2",
@@ -159,7 +160,8 @@
     "portfinder": "^1.0.28",
     "pusher-js-mock": "^0.3.3",
     "react-hot-loader": "^4.12.21",
-    "react-native-flipper": "^0.100.0",
+    "react-native-flipper": "^0.103.0",
+    "react-native-performance-flipper-reporter": "^2.0.0",
     "react-native-svg-transformer": "^0.14.3",
     "react-test-renderer": "16.13.1",
     "rn-async-storage-flipper": "0.0.10",

src/components/OnyxProvider.js

@@ -7,11 +7,13 @@ import ComposeProviders from './ComposeProviders';
 import CONST from '../CONST';
 import Log from '../libs/Log';
 import listenToStorageEvents from '../libs/listenToStorageEvents';
+import canCapturePerformanceMetrics from '../libs/canCapturePerformanceMetrics';
 
 // Initialize the store when the app loads for the first time
 Onyx.init({
     keys: ONYXKEYS,
     safeEvictionKeys: [ONYXKEYS.COLLECTION.REPORT_ACTIONS],
+    captureMetrics: canCapturePerformanceMetrics(),
     initialKeyStates: {
 
         // Clear any loading and error messages so they do not appear on app startup

src/libs/Performance.js

@@ -1,6 +1,14 @@
 import _ from 'underscore';
 import lodashTransform from 'lodash/transform';
+import React, {Profiler, forwardRef} from 'react';
+import {Alert} from 'react-native';
+
 import canCapturePerformanceMetrics from './canCapturePerformanceMetrics';
+import getComponentDisplayName from './getComponentDisplayName';
+import CONST from '../CONST';
+
+/** @type {import('react-native-performance').Performance} */
+let performance;
 
 /**
  * Deep diff between two objects. Useful for figuring out what changed about an object from one render to the next so
@@ -25,43 +33,157 @@ function diffObject(object, base) {
     return changes(object, base);
 }
 
-/**
- * Sets up an observer to capture events recorded in the native layer before the app fully initializes.
- */
-function setupPerformanceObserver() {
-    if (!canCapturePerformanceMetrics()) {
-        return;
-    }
+// When performance monitoring is disabled the implementations are blank
+/* eslint-disable import/no-mutable-exports */
+let setupPerformanceObserver = () => {};
+let printPerformanceMetrics = () => {};
+let markStart = () => {};
+let markEnd = () => {};
+let traceRender = () => {};
+let withRenderTrace = () => Component => Component;
+/* eslint-enable import/no-mutable-exports */
 
-    const performance = require('react-native-performance').default;
-    const PerformanceObserver = require('react-native-performance').PerformanceObserver;
-    new PerformanceObserver((list) => {
-        if (list.getEntries().find(entry => entry.name === 'nativeLaunchEnd')) {
-            performance.measure('nativeLaunch', 'nativeLaunchStart', 'nativeLaunchEnd');
-
-            // eslint-disable-next-line no-undef
-            if (__DEV__) {
-                performance.measure('jsBundleDownload', 'downloadStart', 'downloadEnd');
-            } else {
-                performance.measure('runJsBundle', 'runJsBundleStart', 'runJsBundleEnd');
-            }
-        }
-    }).observe({type: 'react-native-mark', buffered: true});
-}
+if (canCapturePerformanceMetrics()) {
+    /**
+     * Sets up an observer to capture events recorded in the native layer before the app fully initializes.
+     */
+    setupPerformanceObserver = () => {
+        const performanceReported = require('react-native-performance-flipper-reporter');
+        performanceReported.setupDefaultFlipperReporter();
 
-/**
- * Outputs performance stats. We alert these so that they are easy to access in release builds.
- */
-function printPerformanceMetrics() {
-    const performance = require('react-native-performance').default;
-    const entries = _.map(performance.getEntriesByType('measure'), entry => ({
-        name: entry.name, duration: Math.floor(entry.duration),
-    }));
-    alert(JSON.stringify(entries, null, 4));
+        const perfModule = require('react-native-performance');
+        perfModule.setResourceLoggingEnabled(true);
+        performance = perfModule.default;
+
+        // Monitor some native marks that we want to put on the timeline
+        new perfModule.PerformanceObserver((list, observer) => {
+            list.getEntries()
+                .forEach((entry) => {
+                    if (entry.name === 'nativeLaunchEnd') {
+                        performance.measure('nativeLaunch', 'nativeLaunchStart', 'nativeLaunchEnd');
+                    }
+                    if (entry.name === 'downloadEnd') {
+                        performance.measure('jsBundleDownload', 'downloadStart', 'downloadEnd');
+                    }
+                    if (entry.name === 'runJsBundleEnd') {
+                        performance.measure('runJsBundle', 'runJsBundleStart', 'runJsBundleEnd');
+                    }
+
+                    // We don't need to keep the observer past this point
+                    if (entry.name === 'runJsBundleEnd' || entry.name === 'downloadEnd') {
+                        observer.disconnect();
+                    }
+                });
+        }).observe({type: 'react-native-mark', buffered: true});
+
+        // Monitor for "_end" marks and capture "_start" to "_end" measures
+        new perfModule.PerformanceObserver((list) => {
+            list.getEntriesByType('mark')
+                .forEach((mark) => {
+                    if (mark.name.endsWith('_end')) {
+                        const end = mark.name;
+                        const name = end.replace(/_end$/, '');
+                        const start = `${name}_start`;
+                        performance.measure(name, start, end);
+                    }
+
+                    // Capture any custom measures or metrics below
+                    if (mark.name === `${CONST.TIMING.SIDEBAR_LOADED}_end`) {
+                        performance.measure('TTI', 'nativeLaunchStart', mark.name);
+                        printPerformanceMetrics();
+                    }
+                });
+        }).observe({type: 'mark', buffered: true});
+    };
+
+    /**
+     * Outputs performance stats. We alert these so that they are easy to access in release builds.
+     */
+    printPerformanceMetrics = () => {
+        const stats = [
+            ...performance.getEntriesByName('nativeLaunch'),
+            ...performance.getEntriesByName('runJsBundle'),
+            ...performance.getEntriesByName('jsBundleDownload'),
+            ...performance.getEntriesByName('TTI'),
+        ]
+            .filter(entry => entry.duration > 0)
+            .map(entry => `\u2022 ${entry.name}: ${entry.duration.toFixed(1)}ms`);
+
+        Alert.alert('Performance', stats.join('\n'));
+    };
+
+    /**
+     * Add a start mark to the performance entries
+     * @param {string} name
+     * @param {Object} [detail]
+     * @returns {PerformanceMark}
+     */
+    markStart = (name, detail) => performance.mark(`${name}_start`, {detail});
+
+    /**
+     * Add an end mark to the performance entries
+     * A measure between start and end is captured automatically
+     * @param {string} name
+     * @param {Object} [detail]
+     * @returns {PerformanceMark}
+     */
+    markEnd = (name, detail) => performance.mark(`${name}_end`, {detail});
+
+    /**
+     * Put data emitted by Profiler components on the timeline
+     * @param {string} id the "id" prop of the Profiler tree that has just committed
+     * @param {'mount'|'update'} phase either "mount" (if the tree just mounted) or "update" (if it re-rendered)
+     * @param {number} actualDuration time spent rendering the committed update
+     * @param {number} baseDuration estimated time to render the entire subtree without memoization
+     * @param {number} startTime when React began rendering this update
+     * @param {number} commitTime when React committed this update
+     * @param {Set} interactions the Set of interactions belonging to this update
+     * @returns {PerformanceMeasure}
+     */
+    traceRender = (
+        id,
+        phase,
+        actualDuration,
+        baseDuration,
+        startTime,
+        commitTime,
+        interactions,
+    ) => performance.measure(id, {
+        start: startTime,
+        duration: actualDuration,
+        detail: {
+            phase,
+            baseDuration,
+            commitTime,
+            interactions,
+        },
+    });
+
+    /**
+     * A HOC that captures render timings of the Wrapped component
+     * @param {object} config
+     * @param {string} config.id
+     * @returns {function(React.Component): React.FunctionComponent}
+     */
+    withRenderTrace = ({id}) => (WrappedComponent) => {
+        const WithRenderTrace = forwardRef((props, ref) => (
+            <Profiler id={id} onRender={traceRender}>
+                {/* eslint-disable-next-line react/jsx-props-no-spreading */}
+                <WrappedComponent {...props} ref={ref} />
+            </Profiler>
+        ));
+
+        WithRenderTrace.displayName = `withRenderTrace(${getComponentDisplayName(WrappedComponent)})`;
+        return WithRenderTrace;
+    };
 }
 
 export {
     diffObject,
     printPerformanceMetrics,
     setupPerformanceObserver,
+    markStart,
+    markEnd,
+    traceRender,
+    withRenderTrace,
 };