Merge pull request #9392 from adobe/kai/fix-7459-reentrant-perf-timers

redmunds · redmunds · commit 670fc69aa6e8 · 2014-11-21T15:33:22.000-08:00
Fix #7459 -- allow parallel timers of the same name.
diff --git a/src/language/HTMLSimpleDOM.js b/src/language/HTMLSimpleDOM.js
@@ -280,7 +280,10 @@ define(function (require, exports, module) {
         // Appropriate timer is used, and the other is discarded.
         var timerBuildFull = "HTMLInstr. Build DOM Full";
         var timerBuildPart = "HTMLInstr. Build DOM Partial";
-        PerfUtils.markStart([timerBuildFull, timerBuildPart]);
+        var timers; // timer handles
+        timers = PerfUtils.markStart([timerBuildFull, timerBuildPart]);
+        timerBuildFull = timers[0];
+        timerBuildPart = timers[1];
         
         function closeTag(endIndex, endPos) {
             lastClosedTag = stack[stack.length - 1];
diff --git a/src/utils/PerfUtils.js b/src/utils/PerfUtils.js
@@ -63,22 +63,38 @@ define(function (require, exports, module) {
     var updatableTests = {};
     
     /**
-     * Hash of measurement IDs
+     * @private
+     * Keeps the track of measurements sequence number for re-entrant sequences with
+     * the same name currently running. Entries are created and deleted as needed.
      */
-    var perfMeasurementIds = {};
+    var _reentTests = {};
     
     /**
      * @private
      * A unique key to log performance data
      *
-     * @param {!string} id Unique ID for this measurement name
-     * @param {!name} name A short name for this measurement
+     * @param {(string|undefined)} id Unique ID for this measurement name
+     * @param {!string} name A short name for this measurement
+     * @param {?number} reent Sequence identifier for parallel tests of the same name
      */
-    function PerfMeasurement(id, name) {
-        this.id = id;
+    function PerfMeasurement(id, name, reent) {
         this.name = name;
+        this.reent = reent;
+        if (id) {
+            this.id = id;
+        } else {
+            this.id = (reent) ? "[reent " + this.reent + "] " + name : name;
+        }
     }
     
+    /**
+     * Override toString() to allow using PerfMeasurement as an array key without
+     * explicit conversion.
+     */
+    PerfMeasurement.prototype.toString = function () {
+        return this.name;
+    };
+    
     /**
      * Create a new PerfMeasurement key. Adds itself to the module export.
      * Can be accessed on the module, e.g. PerfUtils.MY_PERF_KEY.
@@ -87,10 +103,6 @@ define(function (require, exports, module) {
      * @param {!name} name A short name for this measurement
      */
     function createPerfMeasurement(id, name) {
-        if (perfMeasurementIds[id]) {
-            console.error("Performance measurement " + id + " is already defined");
-        }
-        
         var pm = new PerfMeasurement(id, name);
         exports[id] = pm;
         
@@ -99,59 +111,68 @@ define(function (require, exports, module) {
     
     /**
      * @private
-     * Convert a PerfMeasurement instance to it's id. Otherwise uses the string name for backwards compatibility.
+     * Generates PerfMeasurements based on the name or array of names.
      */
-    function toMeasurementId(o) {
-        return (o instanceof PerfMeasurement) ? o.id : o;
+    function _generatePerfMeasurements(name) {
+        // always convert it to array so that the rest of the routines could rely on it
+        var id = (!Array.isArray(name)) ? [name] : name;
+        // generate unique identifiers for each name
+        var i;
+        for (i = 0; i < id.length; i++) {
+            if (!(id[i] instanceof PerfMeasurement)) {
+                if (_reentTests[id[i]] === undefined) {
+                    _reentTests[id[i]] = 0;
+                } else {
+                    _reentTests[id[i]]++;
+                }
+                id[i] = new PerfMeasurement(undefined, id[i], _reentTests[id[i]]);
+            }
+        }
+        return id;
     }
     
     /**
      * @private
      * Helper function for markStart()
      *
-     * @param {string} name  Timer name.
+     * @param {Object} id  Timer id.
      * @param {number} time  Timer start time.
      */
-    function _markStart(name, time) {
-        if (activeTests[name]) {
-            console.error("Recursive tests with the same name are not supported. Timer name: " + name);
+    function _markStart(id, time) {
+        if (activeTests[id.id]) {
+            console.error("Recursive tests with the same id are not supported. Timer id: " + id.id);
         }
         
-        activeTests[name] = { startTime: time };
+        activeTests[id.id] = { startTime: time };
     }
     
     /**
      * Start a new named timer. The name should be as descriptive as possible, since
      * this name will appear as an entry in the performance report. 
      * For example: "Open file: /Users/brackets/src/ProjectManager.js"
      *
-     * Multiple timers can be opened simultaneously, but all open timers must have
-     * a unique name.
+     * Multiple timers can be opened simultaneously.
+     * 
+     * Returns an opaque set of timer ids which can be stored and used for calling
+     * addMeasurement(). Since name is often creating via concatenating strings this
+     * return value allows clients to construct the name once.
      *
      * @param {(string|Array.<string>)} name  Single name or an Array of names.
-     * @return {string} timer name. Returned for convenience to store and use
-     *      for calling addMeasure(). Since name is often creating via concatenating
-     *      strings this return value allows clients to construct the name once.
+     * @return {(Object|Array.<Object>)} Opaque timer id or array of timer ids.
      */
     function markStart(name) {
         if (!enabled) {
             return;
         }
 
         var time = brackets.app.getElapsedMilliseconds();
-        name = toMeasurementId(name);
+        var id = _generatePerfMeasurements(name);
+        var i;
 
-        // Array of names can be passed in to have multiple timers with same start time
-        if (Array.isArray(name)) {
-            var i;
-            for (i = 0; i < name.length; i++) {
-                _markStart(name[i], time);
-            }
-        } else {
-            _markStart(name, time);
+        for (i = 0; i < id.length; i++) {
+            _markStart(id[i], time);
         }
-
-        return name;
+        return id.length > 1 ? id : id[0];
     }
     
     /**
@@ -163,35 +184,44 @@ define(function (require, exports, module) {
      * If markStart() was not called for the specified timer, the
      * measured time is relative to app startup.
      *
-     * @param {string} name  Timer name.
+     * @param {Object} id  Timer id.
      */
-    function addMeasurement(name) {
+    function addMeasurement(id) {
         if (!enabled) {
             return;
         }
+        
+        if (!(id instanceof PerfMeasurement)) {
+            id = new PerfMeasurement(id, id);
+        }
 
         var elapsedTime = brackets.app.getElapsedMilliseconds();
-        name = toMeasurementId(name);
         
-        if (activeTests[name]) {
-            elapsedTime -= activeTests[name].startTime;
-            delete activeTests[name];
+        if (activeTests[id.id]) {
+            elapsedTime -= activeTests[id.id].startTime;
+            delete activeTests[id.id];
         }
         
-        if (perfData[name]) {
+        if (perfData[id]) {
             // We have existing data, add to it
-            if (Array.isArray(perfData[name])) {
-                perfData[name].push(elapsedTime);
+            if (Array.isArray(perfData[id])) {
+                perfData[id].push(elapsedTime);
             } else {
                 // Current data is a number, convert to Array
-                perfData[name] = [perfData[name], elapsedTime];
+                perfData[id] = [perfData[id], elapsedTime];
             }
         } else {
-            perfData[name] = elapsedTime;
+            perfData[id] = elapsedTime;
+        }
+        
+        if (id.reent !== undefined) {
+            if (_reentTests[id] === 0) {
+                delete _reentTests[id];
+            } else {
+                _reentTests[id]--;
+            }
         }
 
-        // Real time logging
-        //console.log(name + " " + elapsedTime);
     }
 
     /**
@@ -211,36 +241,34 @@ define(function (require, exports, module) {
      * determine if this is the first or subsequent call, so the measurement is
      * not updatable, and it is handled in addMeasurement().
      *
-     * @param {string} name  Timer name.
+     * @param {Object} id  Timer id.
      */
-    function updateMeasurement(name) {
+    function updateMeasurement(id) {
         var elapsedTime = brackets.app.getElapsedMilliseconds();
 
-        name = toMeasurementId(name);
-
-        if (updatableTests[name]) {
+        if (updatableTests[id.id]) {
             // update existing measurement
-            elapsedTime -= updatableTests[name].startTime;
+            elapsedTime -= updatableTests[id].startTime;
             
             // update
-            if (perfData[name] && Array.isArray(perfData[name])) {
+            if (perfData[id] && Array.isArray(perfData[id])) {
                 // We have existing data and it's an array, so update the last entry
-                perfData[name][perfData[name].length - 1] = elapsedTime;
+                perfData[id][perfData[id].length - 1] = elapsedTime;
             } else {
                 // No current data or a single entry, so set/update it
-                perfData[name] = elapsedTime;
+                perfData[id] = elapsedTime;
             }
             
         } else {
             // not yet in updatable list
 
-            if (activeTests[name]) {
+            if (activeTests[id.id]) {
                 // save startTime in updatable list before addMeasurement() deletes it
-                updatableTests[name] = { startTime: activeTests[name].startTime };
+                updatableTests[id.id] = { startTime: activeTests[id.id].startTime };
             }
             
             // let addMeasurement() handle the initial case
-            addMeasurement(name);
+            addMeasurement(id);
         }
     }
 
@@ -250,18 +278,15 @@ define(function (require, exports, module) {
      * updateMeasurement may not have been called, so timer may be
      * in either or neither list, but should never be in both.
      *
-     * @param {string} name  Timer name.
+     * @param {Object} id  Timer id.
      */
-    function finalizeMeasurement(name) {
-
-        name = toMeasurementId(name);
-
-        if (activeTests[name]) {
-            delete activeTests[name];
+    function finalizeMeasurement(id) {
+        if (activeTests[id.id]) {
+            delete activeTests[id.id];
         }
-
-        if (updatableTests[name]) {
-            delete updatableTests[name];
+        
+        if (updatableTests[id.id]) {
+            delete updatableTests[id.id];
         }
     }
     
@@ -270,17 +295,17 @@ define(function (require, exports, module) {
      * timer has been started with addMark(), but has not been added to perfdata
      * with addMeasurement().
      *
-     * @param {string} name  Timer name.
+     * @param {Object} id  Timer id.
      * @return {boolean} Whether a timer is active or not.
      */
-    function isActive(name) {
-        return (activeTests[name]) ? true : false;
+    function isActive(id) {
+        return (activeTests[id.id]) ? true : false;
     }
 
     /**
-      * Returns the performance data as a tab deliminted string
-      * @return {string}
-      */
+     * Returns the performance data as a tab deliminted string
+     * @return {string}
+     */
     function getDelimitedPerfData() {
         var getValue = function (entry) {
             // return single value, or tab deliminted values for an array
@@ -309,14 +334,14 @@ define(function (require, exports, module) {
     
     /**
      * Returns the measured value for the given measurement name.
-     * @param {string|PerfMeasurement} name The measurement to retreive.
+     * @param {Object} id The measurement to retreive.
      */
-    function getData(name) {
-        if (!name) {
+    function getData(id) {
+        if (!id) {
             return perfData;
         }
         
-        return perfData[toMeasurementId(name)];
+        return perfData[id];
     }
     
     function searchData(regExp) {
@@ -340,6 +365,7 @@ define(function (require, exports, module) {
         perfData = {};
         activeTests = {};
         updatableTests = {};
+        _reentTests = {};
     }
     
     // create performance measurement constants
