Benchmarking tool for React application performance

ReactAppPerf wraps core methods and logs info from them; there's no real
UI at this point

src/core/React.js

@@ -23,6 +23,7 @@ var ReactCompositeComponent = require('ReactCompositeComponent');
 var ReactComponent = require('ReactComponent');
 var ReactDOM = require('ReactDOM');
 var ReactMount = require('ReactMount');
+var ReactPerf = require('ReactPerf');
 var ReactPropTypes = require('ReactPropTypes');
 var ReactServerRendering = require('ReactServerRendering');
 
@@ -42,7 +43,11 @@ var React = {
   constructAndRenderComponentByID: ReactMount.constructAndRenderComponentByID,
   forEachChildren: ReactChildren.forEach,
   mapChildren: ReactChildren.map,
-  renderComponent: ReactMount.renderComponent,
+  renderComponent: ReactPerf.measure(
+    'React',
+    'renderComponent',
+    ReactMount.renderComponent
+  ),
   renderComponentToString: ReactServerRendering.renderComponentToString,
   unmountAndReleaseReactRootNode: ReactMount.unmountAndReleaseReactRootNode,
   isValidComponent: ReactComponent.isValidComponent

src/core/ReactCompositeComponent.js

@@ -21,6 +21,7 @@
 var ReactComponent = require('ReactComponent');
 var ReactCurrentOwner = require('ReactCurrentOwner');
 var ReactOwner = require('ReactOwner');
+var ReactPerf = require('ReactPerf');
 var ReactPropTransferer = require('ReactPropTransferer');
 var ReactUpdates = require('ReactUpdates');
 
@@ -479,41 +480,45 @@ var ReactCompositeComponentMixin = {
    * @final
    * @internal
    */
-  mountComponent: function(rootID, transaction) {
-    ReactComponent.Mixin.mountComponent.call(this, rootID, transaction);
-    this._compositeLifeCycleState = CompositeLifeCycle.MOUNTING;
+  mountComponent: ReactPerf.measure(
+    'ReactCompositeComponent',
+    'mountComponent',
+    function(rootID, transaction) {
+      ReactComponent.Mixin.mountComponent.call(this, rootID, transaction);
+      this._compositeLifeCycleState = CompositeLifeCycle.MOUNTING;
 
-    this._defaultProps = this.getDefaultProps ? this.getDefaultProps() : null;
-    this._processProps(this.props);
+      this._defaultProps = this.getDefaultProps ? this.getDefaultProps() : null;
+      this._processProps(this.props);
 
-    if (this.__reactAutoBindMap) {
-      this._bindAutoBindMethods();
-    }
-
-    this.state = this.getInitialState ? this.getInitialState() : null;
-    this._pendingState = null;
-    this._pendingForceUpdate = false;
-
-    if (this.componentWillMount) {
-      this.componentWillMount();
-      // When mounting, calls to `setState` by `componentWillMount` will set
-      // `this._pendingState` without triggering a re-render.
-      if (this._pendingState) {
-        this.state = this._pendingState;
-        this._pendingState = null;
+      if (this.__reactAutoBindMap) {
+        this._bindAutoBindMethods();
       }
-    }
 
-    this._renderedComponent = this._renderValidatedComponent();
+      this.state = this.getInitialState ? this.getInitialState() : null;
+      this._pendingState = null;
+      this._pendingForceUpdate = false;
 
-    // Done with mounting, `setState` will now trigger UI changes.
-    this._compositeLifeCycleState = null;
-    var markup = this._renderedComponent.mountComponent(rootID, transaction);
-    if (this.componentDidMount) {
-      transaction.getReactOnDOMReady().enqueue(this, this.componentDidMount);
+      if (this.componentWillMount) {
+        this.componentWillMount();
+        // When mounting, calls to `setState` by `componentWillMount` will set
+        // `this._pendingState` without triggering a re-render.
+        if (this._pendingState) {
+          this.state = this._pendingState;
+          this._pendingState = null;
+        }
+      }
+
+      this._renderedComponent = this._renderValidatedComponent();
+
+      // Done with mounting, `setState` will now trigger UI changes.
+      this._compositeLifeCycleState = null;
+      var markup = this._renderedComponent.mountComponent(rootID, transaction);
+      if (this.componentDidMount) {
+        transaction.getReactOnDOMReady().enqueue(this, this.componentDidMount);
+      }
+      return markup;
     }
-    return markup;
-  },
+  ),
 
   /**
    * Releases any resources allocated by `mountComponent`.
@@ -714,25 +719,29 @@ var ReactCompositeComponentMixin = {
    * @internal
    * @overridable
    */
-  updateComponent: function(transaction, prevProps, prevState) {
-    ReactComponent.Mixin.updateComponent.call(this, transaction, prevProps);
-    var currentComponent = this._renderedComponent;
-    var nextComponent = this._renderValidatedComponent();
-    if (currentComponent.constructor === nextComponent.constructor) {
-      currentComponent.receiveProps(nextComponent.props, transaction);
-    } else {
-      // These two IDs are actually the same! But nothing should rely on that.
-      var thisID = this._rootNodeID;
-      var currentComponentID = currentComponent._rootNodeID;
-      currentComponent.unmountComponent();
-      var nextMarkup = nextComponent.mountComponent(thisID, transaction);
-      ReactComponent.DOMIDOperations.dangerouslyReplaceNodeWithMarkupByID(
-        currentComponentID,
-        nextMarkup
-      );
-      this._renderedComponent = nextComponent;
+  updateComponent: ReactPerf.measure(
+    'ReactCompositeComponent',
+    'updateComponent',
+    function(transaction, prevProps, prevState) {
+      ReactComponent.Mixin.updateComponent.call(this, transaction, prevProps);
+      var currentComponent = this._renderedComponent;
+      var nextComponent = this._renderValidatedComponent();
+      if (currentComponent.constructor === nextComponent.constructor) {
+        currentComponent.receiveProps(nextComponent.props, transaction);
+      } else {
+        // These two IDs are actually the same! But nothing should rely on that.
+        var thisID = this._rootNodeID;
+        var currentComponentID = currentComponent._rootNodeID;
+        currentComponent.unmountComponent();
+        var nextMarkup = nextComponent.mountComponent(thisID, transaction);
+        ReactComponent.DOMIDOperations.dangerouslyReplaceNodeWithMarkupByID(
+          currentComponentID,
+          nextMarkup
+        );
+        this._renderedComponent = nextComponent;
+      }
     }
-  },
+  ),
 
   /**
    * Forces an update. This should only be invoked when it is known with

src/core/ReactDefaultInjection.js

@@ -26,6 +26,7 @@ var ReactDOMSelect = require('ReactDOMSelect');
 var ReactDOMTextarea = require('ReactDOMTextarea');
 var ReactEventEmitter = require('ReactEventEmitter');
 var ReactEventTopLevelCallback = require('ReactEventTopLevelCallback');
+var ReactPerf = require('ReactPerf');
 
 var DefaultDOMPropertyConfig = require('DefaultDOMPropertyConfig');
 var DOMProperty = require('DOMProperty');
@@ -66,6 +67,10 @@ function inject() {
   });
 
   DOMProperty.injection.injectDOMPropertyConfig(DefaultDOMPropertyConfig);
+
+  if (__DEV__) {
+    ReactPerf.injection.injectMeasure(require('ReactDefaultPerf').measure);
+  }
 }
 
 module.exports = {

src/core/ReactNativeComponent.js

@@ -26,6 +26,7 @@ var ReactComponent = require('ReactComponent');
 var ReactEventEmitter = require('ReactEventEmitter');
 var ReactMultiChild = require('ReactMultiChild');
 var ReactMount = require('ReactMount');
+var ReactPerf = require('ReactPerf');
 
 var escapeTextForBrowser = require('escapeTextForBrowser');
 var flattenChildren = require('flattenChildren');
@@ -85,15 +86,19 @@ ReactNativeComponent.Mixin = {
    * @param {ReactReconcileTransaction} transaction
    * @return {string} The computed markup.
    */
-  mountComponent: function(rootID, transaction) {
-    ReactComponent.Mixin.mountComponent.call(this, rootID, transaction);
-    assertValidProps(this.props);
-    return (
-      this._createOpenTagMarkup() +
-      this._createContentMarkup(transaction) +
-      this._tagClose
-    );
-  },
+  mountComponent: ReactPerf.measure(
+    'ReactNativeComponent',
+    'mountComponent',
+    function(rootID, transaction) {
+      ReactComponent.Mixin.mountComponent.call(this, rootID, transaction);
+      assertValidProps(this.props);
+      return (
+        this._createOpenTagMarkup() +
+        this._createContentMarkup(transaction) +
+        this._tagClose
+      );
+    }
+  ),
 
   /**
    * Creates markup for the open tag and all attributes.
@@ -184,11 +189,15 @@ ReactNativeComponent.Mixin = {
    * @internal
    * @overridable
    */
-  updateComponent: function(transaction, prevProps) {
-    ReactComponent.Mixin.updateComponent.call(this, transaction, prevProps);
-    this._updateDOMProperties(prevProps);
-    this._updateDOMChildren(prevProps, transaction);
-  },
+  updateComponent: ReactPerf.measure(
+    'ReactNativeComponent',
+    'updateComponent',
+    function(transaction, prevProps) {
+      ReactComponent.Mixin.updateComponent.call(this, transaction, prevProps);
+      this._updateDOMProperties(prevProps);
+      this._updateDOMChildren(prevProps, transaction);
+    }
+  ),
 
   /**
    * Reconciles the properties by detecting differences in property values and

src/test/ReactDefaultPerf.js

@@ -0,0 +1,416 @@
+/**
+ * Copyright 2013 Facebook, Inc.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ *
+ * @providesModule ReactDefaultPerf
+ * @typechecks static-only
+ */
+
+"use strict";
+
+var ReactDefaultPerf = {};
+
+if (__DEV__) {
+  ReactDefaultPerf = {
+    /**
+     * Gets the stored information for a given object's function.
+     *
+     * @param {string} objName
+     * @param {string} fnName
+     * @return {?object}
+     */
+    getInfo: function(objName, fnName) {
+      if (!this.info[objName] || !this.info[objName][fnName]) {
+        return null;
+      }
+      return this.info[objName][fnName];
+    },
+
+    /**
+     * Gets the logs pertaining to a given object's function.
+     *
+     * @param {string} objName
+     * @param {string} fnName
+     * @return {?array<object>}
+     */
+    getLogs: function(objName, fnName) {
+      if (!this.getInfo(objName, fnName)) {
+        return null;
+      }
+      return this.logs.filter(function(log) {
+        return log.objName === objName && log.fnName === fnName;
+      });
+    },
+
+    /**
+     * Runs through the logs and builds an array of arrays, where each array
+     * walks through the mounting/updating of each component underneath.
+     *
+     * @param {string} rootID The reactID of the root node, e.g. '.r[2cpyq]'
+     * @return {array<array>}
+     */
+    getRawRenderHistory: function(rootID) {
+      var history = [];
+      /**
+       * Since logs are added after the method returns, the logs are in a sense
+       * upside-down: the inner-most elements from mounting/updating are logged
+       * first, and the last addition to the log is the top renderComponent.
+       * Therefore, we flip the logs upside down for ease of processing, and
+       * reverse the history array at the end so the earliest event has index 0.
+       */
+      var logs = this.logs.filter(function(log) {
+        return log.reactID.indexOf(rootID) === 0;
+      }).reverse();
+
+      var subHistory = [];
+      logs.forEach(function(log, i) {
+        if (i && log.reactID === rootID && logs[i - 1].reactID !== rootID) {
+          subHistory.length && history.push(subHistory);
+          subHistory = [];
+        }
+        subHistory.push(log);
+      });
+      if (subHistory.length) {
+        history.push(subHistory);
+      }
+      return history.reverse();
+    },
+
+    /**
+     * Runs through the logs and builds an array of strings, where each string
+     * is a multiline formatted way of walking through the mounting/updating
+     * underneath.
+     *
+     * @param {string} rootID The reactID of the root node, e.g. '.r[2cpyq]'
+     * @return {array<string>}
+     */
+    getRenderHistory: function(rootID) {
+      var history = this.getRawRenderHistory(rootID);
+
+      return history.map(function(subHistory) {
+        var headerString = (
+          'log# Component (execution time) [bloat from logging]\n' +
+          '================================================================\n'
+        );
+        return headerString + subHistory.map(function(log) {
+          // Add two spaces for every layer in the reactID.
+          var indents = '\t' + Array(log.reactID.split('.[').length).join('  ');
+          var delta = _microTime(log.timing.delta);
+          var bloat = _microTime(log.timing.timeToLog);
+
+          return log.index + indents + log.name + ' (' + delta + 'ms)' +
+            ' [' + bloat + 'ms]';
+        }).join('\n');
+      });
+    },
+
+    /**
+     * Print the render history from `getRenderHistory` using console.log.
+     * This is currently the best way to display perf data from
+     * any React component; working on that.
+     *
+     * @param {string} rootID The reactID of the root node, e.g. '.r[2cpyq]'
+     * @param {number} index
+     */
+    printRenderHistory: function(rootID, index) {
+      var history = this.getRenderHistory(rootID);
+      if (!history[index]) {
+        console.warn(
+          'Index', index, 'isn\'t available! ' +
+          'The render history is', history.length, 'long.'
+        );
+        return;
+      }
+      console.log(
+        'Loading render history #' + (index + 1) +
+        ' of ' + history.length + ':\n' + history[index]
+      );
+    },
+
+    /**
+     * Prints the heatmap legend to console, showing how the colors correspond
+     * with render times. This relies on console.log styles.
+     */
+    printHeatmapLegend: function() {
+      if (!this.options.heatmap.enabled) {
+        return;
+      }
+      var max = this.info.React
+        && this.info.React.renderComponent
+        && this.info.React.renderComponent.max;
+      if (max) {
+        var logStr = 'Heatmap: ';
+        for (var ii = 0; ii <= 10 * max; ii += max) {
+          logStr += '%c ' + (Math.round(ii) / 10) + 'ms ';
+        }
+        console.log(
+          logStr,
+          'background-color: hsla(100, 100%, 50%, 0.6);',
+          'background-color: hsla( 90, 100%, 50%, 0.6);',
+          'background-color: hsla( 80, 100%, 50%, 0.6);',
+          'background-color: hsla( 70, 100%, 50%, 0.6);',
+          'background-color: hsla( 60, 100%, 50%, 0.6);',
+          'background-color: hsla( 50, 100%, 50%, 0.6);',
+          'background-color: hsla( 40, 100%, 50%, 0.6);',
+          'background-color: hsla( 30, 100%, 50%, 0.6);',
+          'background-color: hsla( 20, 100%, 50%, 0.6);',
+          'background-color: hsla( 10, 100%, 50%, 0.6);',
+          'background-color: hsla(  0, 100%, 50%, 0.6);'
+        );
+      }
+    },
+
+    /**
+     * Measure a given function with logging information, and calls a callback
+     * if there is one.
+     *
+     * @param {string} objName
+     * @param {string} fnName
+     * @param {function} func
+     * @return {function}
+     */
+    measure: function(objName, fnName, func) {
+      var info = _getNewInfo(objName, fnName);
+
+      var fnArgs = _getFnArguments(func);
+
+      return function() {
+        var timeBeforeFn = now();
+        var fnReturn = func.apply(this, arguments);
+        var timeAfterFn = now();
+
+        /**
+         * Hold onto arguments in a readable way: args[1] -> args.component.
+         * args is also passed to the callback, so if you want to save an
+         * argument in the log, do so in the callback.
+         */
+        var args = {};
+        for (var i = 0; i < arguments.length; i++) {
+          args[fnArgs[i]] = arguments[i];
+        }
+
+        var log = {
+          index: ReactDefaultPerf.logs.length,
+          fnName: fnName,
+          objName: objName,
+          timing: {
+            before: timeBeforeFn,
+            after: timeAfterFn,
+            delta: timeAfterFn - timeBeforeFn
+          }
+        };
+
+        ReactDefaultPerf.logs.push(log);
+
+        /**
+         * The callback gets:
+         * - this (the component)
+         * - the original method's arguments
+         * - what the method returned
+         * - the log object, and
+         * - the wrapped method's info object.
+         */
+        var callback = _getCallback(objName, fnName);
+        callback && callback(this, args, fnReturn, log, info);
+
+        log.timing.timeToLog = now() - timeAfterFn;
+
+        return fnReturn;
+      };
+    },
+
+    /**
+     * Holds information on wrapped objects/methods.
+     * For instance, ReactDefaultPerf.info.React.renderComponent
+     */
+    info: {},
+
+    /**
+     * Holds all of the logs. Filter this to pull desired information.
+     */
+    logs: [],
+
+    /**
+     * Toggle settings for ReactDefaultPerf
+     */
+    options: {
+      /**
+       * The heatmap sets the background color of the React containers
+       * according to how much total time has been spent rendering them.
+       * The most temporally expensive component is set as pure red,
+       * and the others are colored from green to red as a fraction
+       * of that max component time.
+       */
+      heatmap: {
+        enabled: true
+      }
+    }
+  };
+
+  /**
+   * Gets a info area for a given object's function, adding a new one if
+   * necessary.
+   *
+   * @param {string} objName
+   * @param {string} fnName
+   * @return {object}
+   */
+  var _getNewInfo = function(objName, fnName) {
+    var info = ReactDefaultPerf.getInfo(objName, fnName);
+    if (info) {
+      return info;
+    }
+    ReactDefaultPerf.info[objName] = ReactDefaultPerf.info[objName] || {};
+
+    return ReactDefaultPerf.info[objName][fnName] = {
+      getLogs: function() {
+        return ReactDefaultPerf.getLogs(objName, fnName);
+      }
+    };
+  };
+
+  /**
+   * Gets a list of the argument names from a function's definition.
+   * This is useful for storing arguments by their names within wrapFn().
+   *
+   * @param {function} fn
+   * @return {array<string>}
+   */
+  var _getFnArguments = function(fn) {
+    var STRIP_COMMENTS = /((\/\/.*$)|(\/\*[\s\S]*?\*\/))/mg;
+    var fnStr = fn.toString().replace(STRIP_COMMENTS, '');
+    fnStr = fnStr.slice(fnStr.indexOf('(') + 1, fnStr.indexOf(')'));
+    return fnStr.match(/([^\s,]+)/g);
+  };
+
+  /**
+   * Store common callbacks within ReactDefaultPerf.
+   *
+   * @param {string} objName
+   * @param {string} fnName
+   * @return {?function}
+   */
+  var _getCallback = function(objName, fnName) {
+    switch (objName + '.' + fnName) {
+      case 'React.renderComponent':
+        return _renderComponentCallback;
+      case 'ReactNativeComponent.mountComponent':
+      case 'ReactNativeComponent.updateComponent':
+        return _nativeComponentCallback;
+      case 'ReactCompositeComponent.mountComponent':
+      case 'ReactCompositeComponent.updateComponent':
+        return _compositeComponentCallback;
+      default:
+        return null;
+    }
+  };
+
+  /**
+   * Callback function for React.renderComponent
+   *
+   * @param {object} component
+   * @param {object} args
+   * @param {?object} fnReturn
+   * @param {object} log
+   * @param {object} info
+   */
+  var _renderComponentCallback =
+    function(component, args, fnReturn, log, info) {
+    log.name = args.nextComponent.constructor.displayName || '[unknown]';
+    log.reactID = fnReturn._rootNodeID || null;
+
+    if (ReactDefaultPerf.options.heatmap.enabled) {
+      var container = args.container;
+      if (!container.loggedByReactDefaultPerf) {
+        container.loggedByReactDefaultPerf = true;
+        info.components = info.components || [];
+        info.components.push(container);
+      }
+
+      container.count = container.count || 0;
+      container.count += log.timing.delta;
+      info.max = info.max || 0;
+      if (container.count > info.max) {
+        info.max = container.count;
+        info.components.forEach(function(component) {
+          _setHue(component, 100 - 100 * component.count / info.max);
+        });
+      } else {
+        _setHue(container, 100 - 100 * container.count / info.max);
+      }
+    }
+  };
+
+  /**
+   * Callback function for ReactNativeComponent
+   *
+   * @param {object} component
+   * @param {object} args
+   * @param {?object} fnReturn
+   * @param {object} log
+   * @param {object} info
+   */
+  var _nativeComponentCallback =
+    function(component, args, fnReturn, log, info) {
+    log.name = component.tagName || '[unknown]';
+    log.reactID = component._rootNodeID;
+  };
+
+  /**
+   * Callback function for ReactCompositeComponent
+   *
+   * @param {object} component
+   * @param {object} args
+   * @param {?object} fnReturn
+   * @param {object} log
+   * @param {object} info
+   */
+  var _compositeComponentCallback =
+    function(component, args, fnReturn, log, info) {
+    log.name = component.constructor.displayName || '[unknown]';
+    log.reactID = component._rootNodeID;
+  };
+
+  /**
+   * Using the hsl() background-color attribute, colors an element.
+   *
+   * @param {DOMElement} el
+   * @param {number} hue [0 for red, 120 for green, 240 for blue]
+   */
+  var _setHue = function(el, hue) {
+    el.style.backgroundColor = 'hsla(' + hue + ', 100%, 50%, 0.6)';
+  };
+
+  /**
+   * Round to the thousandth place.
+   * @param {number} time
+   * @return {number}
+   */
+  var _microTime = function(time) {
+    return Math.round(time * 1000) / 1000;
+  };
+
+  /**
+   * Shim window.performance.now
+   * We can't assign window.performance.now and then call it, so need to bind.
+   * TODO: Support Firefox < 15 for now
+   */
+  var performance = window && (window.performance || window.webkitPeformance);
+  if (!performance || !performance.now) {
+    performance = Date;
+  }
+  var now = performance.now.bind(performance);
+}
+
+module.exports = ReactDefaultPerf;

src/test/ReactPerf.js

@@ -0,0 +1,90 @@
+/**
+ * Copyright 2013 Facebook, Inc.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ *
+ * @providesModule ReactPerf
+ * @typechecks static-only
+ */
+
+"use strict";
+
+var ReactPerf = {
+  /**
+   * Boolean to enable/disable measurement. Set to false by default to prevent
+   * accidental logging and perf loss.
+   */
+  enableMeasure: false,
+
+  /**
+   * Holds onto the measure function in use. By default, don't measure
+   * anything, but we'll override this if we inject a measure function.
+   */
+  storedMeasure: _noMeasure,
+
+  /**
+   * Use this to wrap methods you want to measure.
+   *
+   * @param {string} objName
+   * @param {string} fnName
+   * @param {function} func
+   * @return {function}
+   */
+  measure: function(objName, fnName, func) {
+    if (__DEV__) {
+      if (this.enableMeasure) {
+        var measuredFunc = null;
+        return function() {
+          if (!measuredFunc) {
+            measuredFunc = ReactPerf.storedMeasure(objName, fnName, func);
+          }
+          return measuredFunc.apply(this, arguments);
+        };
+      }
+    }
+    return func;
+  },
+
+  injection: {
+    /**
+     * @param {function} measure
+     */
+    injectMeasure: function(measure) {
+      ReactPerf.storedMeasure = measure;
+    }
+  }
+};
+
+if (__DEV__) {
+  var ExecutionEnvironment = require('ExecutionEnvironment');
+  var URL = ExecutionEnvironment.global &&
+    ExecutionEnvironment.global.location &&
+    ExecutionEnvironment.global.location.href ||
+    '';
+  ReactPerf.enableMeasure = ReactPerf.enableMeasure ||
+    !!URL.match(/[?&]react_perf\b/);
+}
+
+/**
+ * Simply passes through the measured function, without measuring it.
+ *
+ * @param {string} objName
+ * @param {string} fnName
+ * @param {function} func
+ * @return {function}
+ */
+function _noMeasure(objName, fnName, func) {
+  return func;
+}
+
+module.exports = ReactPerf;