refactor(perf): introduce benchpress2

Major changes:
- make API more reusable
- format output nicely
- only force gc if needed

Regarding forcing gc:
Forcing gc can change script execution time.
We now don't force gc at first and ignore results where gc happens during script execution.
When we ignored too many results, we switch to forcing gc.

Closes #339

modules/benchmarks/test/perf/change_detection_perf.js

@@ -1,26 +1,44 @@
 "use strict";
-var util = require('../../../../tools/perf/util.js');
+var benchpress = require('../../../../tools/benchpress/benchpress.js');
 
 describe('ng2 change detection benchmark', function () {
 
   var URL = 'benchmarks/web/change_detection/change_detection_benchmark.html';
 
-  afterEach(util.verifyNoErrors);
+  afterEach(benchpress.verifyNoBrowserErrors);
 
   it('should log ng stats', function() {
     browser.get(URL);
-    util.runClickBenchmark({
+    runClickTimeBenchmark({
       buttons: ['#ng2DetectChanges'],
-      name: browser.params.lang+'.ng2.changeDetection'
+      logId: 'ng2.changeDetection'
     });
   });
 
   it('should log baseline stats', function() {
     browser.get(URL);
-    util.runClickBenchmark({
+    runClickTimeBenchmark({
       buttons: ['#baselineDetectChanges'],
-      name: browser.params.lang+'.baseline.changeDetection'
+      logId: 'baseline.changeDetection'
     });
   });
 
 });
+
+function runClickTimeBenchmark(config) {
+  var buttons = config.buttons.map(function(selector) {
+    return $(selector);
+  });
+  var timeParams = browser.params.timeBenchmark;
+  benchpress.runTimeBenchmark({
+    sampleSize: timeParams.sampleSize,
+    targetCoefficientOfVariation: timeParams.targetCoefficientOfVariation,
+    timeout: timeParams.timeout,
+    metrics: timeParams.metrics,
+    logId: browser.params.lang+'.'+config.logId
+  }, function() {
+    buttons.forEach(function(button) {
+      button.click();
+    });
+  });
+}

modules/benchmarks/test/perf/compiler_perf.js

@@ -1,26 +1,44 @@
 "use strict";
-var util = require('../../../../tools/perf/util.js');
+var benchpress = require('../../../../tools/benchpress/benchpress.js');
 
 describe('ng2 compiler benchmark', function () {
 
   var URL = 'benchmarks/web/compiler/compiler_benchmark.html';
 
-  afterEach(util.verifyNoErrors);
+  afterEach(benchpress.verifyNoBrowserErrors);
 
   it('should log withBindings stats', function() {
     browser.get(URL);
-    util.runClickBenchmark({
+    runClickTimeBenchmark({
       buttons: ['#compileWithBindings'],
-      name: browser.params.lang+'.ng2.compile.withBindings'
+      logId: 'ng2.compile.withBindings'
     });
   });
 
   it('should log noBindings stats', function() {
     browser.get(URL);
-    util.runClickBenchmark({
+    runClickTimeBenchmark({
       buttons: ['#compileNoBindings'],
-      name: browser.params.lang+'.ng2.compile.noBindings'
+      logId: 'ng2.compile.noBindings'
     });
   });
 
 });
+
+function runClickTimeBenchmark(config) {
+  var buttons = config.buttons.map(function(selector) {
+    return $(selector);
+  });
+  var timeParams = browser.params.timeBenchmark;
+  benchpress.runTimeBenchmark({
+    sampleSize: timeParams.sampleSize,
+    targetCoefficientOfVariation: timeParams.targetCoefficientOfVariation,
+    timeout: timeParams.timeout,
+    metrics: timeParams.metrics,
+    logId: browser.params.lang+'.'+config.logId
+  }, function() {
+    buttons.forEach(function(button) {
+      button.click();
+    });
+  });
+}

modules/benchmarks/test/perf/di_perf.js

@@ -1,42 +1,60 @@
 "use strict";
-var util = require('../../../../tools/perf/util.js');
+var benchpress = require('../../../../tools/benchpress/benchpress.js');
 
 describe('ng2 di benchmark', function () {
 
   var URL = 'benchmarks/web/di/di_benchmark.html';
 
-  afterEach(util.verifyNoErrors);
+  afterEach(benchpress.verifyNoBrowserErrors);
 
   it('should log the stats for getByToken', function() {
     browser.get(URL);
-    util.runClickBenchmark({
+    runClickTimeBenchmark({
       buttons: ['#getByToken'],
-      name: browser.params.lang+'.ng2.di.getByToken'
+      logId: 'ng2.di.getByToken'
     });
   });
 
   it('should log the stats for getByKey', function() {
     browser.get(URL);
-    util.runClickBenchmark({
+    runClickTimeBenchmark({
       buttons: ['#getByKey'],
-      name: browser.params.lang+'.ng2.di.getByKey'
+      logId: 'ng2.di.getByKey'
     });
   });
 
   it('should log the stats for getChild', function() {
     browser.get(URL);
-    util.runClickBenchmark({
+    runClickTimeBenchmark({
       buttons: ['#getChild'],
-      name: browser.params.lang+'.ng2.di.getChild'
+      logId: 'ng2.di.getChild'
     });
   });
 
   it('should log the stats for instantiate', function() {
     browser.get(URL);
-    util.runClickBenchmark({
+    runClickTimeBenchmark({
       buttons: ['#instantiate'],
-      name: browser.params.lang+'.ng2.di.instantiate'
+      logId: 'ng2.di.instantiate'
     });
   });
 
 });
+
+function runClickTimeBenchmark(config) {
+  var buttons = config.buttons.map(function(selector) {
+    return $(selector);
+  });
+  var timeParams = browser.params.timeBenchmark;
+  benchpress.runTimeBenchmark({
+    sampleSize: timeParams.sampleSize,
+    targetCoefficientOfVariation: timeParams.targetCoefficientOfVariation,
+    timeout: timeParams.timeout,
+    metrics: timeParams.metrics,
+    logId: browser.params.lang+'.'+config.logId
+  }, function() {
+    buttons.forEach(function(button) {
+      button.click();
+    });
+  });
+}

modules/benchmarks/test/perf/element_injector_perf.js

@@ -1,26 +1,44 @@
 "use strict";
-var util = require('../../../../tools/perf/util.js');
+var benchpress = require('../../../../tools/benchpress/benchpress.js');
 
 describe('ng2 element injector benchmark', function () {
 
   var URL = 'benchmarks/web/element_injector/element_injector_benchmark.html';
 
-  afterEach(util.verifyNoErrors);
+  afterEach(benchpress.verifyNoBrowserErrors);
 
   it('should log the stats for instantiate', function() {
     browser.get(URL);
-    util.runClickBenchmark({
+    runClickTimeBenchmark({
       buttons: ['#instantiate'],
-      name: browser.params.lang+'.ng2.elementInjector.instantiate'
+      logId: 'ng2.elementInjector.instantiate'
     });
   });
 
   it('should log the stats for instantiateDirectives', function() {
     browser.get(URL);
-    util.runClickBenchmark({
+    runClickTimeBenchmark({
       buttons: ['#instantiateDirectives'],
-      name: browser.params.lang+'.ng2.elementInjector.instantiateDirectives'
+      logId: 'ng2.elementInjector.instantiateDirectives'
     });
   });
 
 });
+
+function runClickTimeBenchmark(config) {
+  var buttons = config.buttons.map(function(selector) {
+    return $(selector);
+  });
+  var timeParams = browser.params.timeBenchmark;
+  benchpress.runTimeBenchmark({
+    sampleSize: timeParams.sampleSize,
+    targetCoefficientOfVariation: timeParams.targetCoefficientOfVariation,
+    timeout: timeParams.timeout,
+    metrics: timeParams.metrics,
+    logId: browser.params.lang+'.'+config.logId
+  }, function() {
+    buttons.forEach(function(button) {
+      button.click();
+    });
+  });
+}

modules/benchmarks/test/perf/tree_perf.js

@@ -1,26 +1,44 @@
 "use strict";
-var util = require('../../../../tools/perf/util.js');
+var benchpress = require('../../../../tools/benchpress/benchpress.js');
 
 describe('ng2 tree benchmark', function () {
 
   var URL = 'benchmarks/web/tree/tree_benchmark.html';
 
-  afterEach(util.verifyNoErrors);
+  afterEach(benchpress.verifyNoBrowserErrors);
 
   it('should log the ng stats', function() {
     browser.get(URL);
-    util.runClickBenchmark({
+    runClickTimeBenchmark({
       buttons: ['#ng2DestroyDom', '#ng2CreateDom'],
-      name: browser.params.lang+'.ng2.tree'
+      logId: 'ng2.tree'
     });
   });
 
   it('should log the baseline stats', function() {
     browser.get(URL);
-    util.runClickBenchmark({
+    runClickTimeBenchmark({
       buttons: ['#baselineDestroyDom', '#baselineCreateDom'],
-      name: browser.params.lang+'.baseline.tree'
+      logId: 'baseline.tree'
     });
   });
 
 });
+
+function runClickTimeBenchmark(config) {
+  var buttons = config.buttons.map(function(selector) {
+    return $(selector);
+  });
+  var timeParams = browser.params.timeBenchmark;
+  benchpress.runTimeBenchmark({
+    sampleSize: timeParams.sampleSize,
+    targetCoefficientOfVariation: timeParams.targetCoefficientOfVariation,
+    timeout: timeParams.timeout,
+    metrics: timeParams.metrics,
+    logId: browser.params.lang+'.'+config.logId
+  }, function() {
+    buttons.forEach(function(button) {
+      button.click();
+    });
+  });
+}

modules/benchmarks_external/test/perf/compiler_perf.js

@@ -1,25 +1,44 @@
 "use strict";
-var util = require('../../../../tools/perf/util.js');
+var benchpress = require('../../../../tools/benchpress/benchpress.js');
 
 describe('ng1.x compiler benchmark', function () {
 
   var URL = 'benchmarks_external/web/compiler/compiler_benchmark.html';
 
-  afterEach(util.verifyNoErrors);
+  afterEach(benchpress.verifyNoBrowserErrors);
 
   it('should log withBinding stats', function() {
     browser.get(URL);
-    util.runClickBenchmark({
+    runClickTimeBenchmark({
       buttons: ['#compileWithBindings'],
-      name: browser.params.lang+'.ng1.compile.withBindings'
+      logId: 'ng1.compile.withBindings'
     });
   });
 
   it('should log noBindings stats', function() {
-    util.runClickBenchmark({
+    browser.get(URL);
+    runClickTimeBenchmark({
       buttons: ['#compileNoBindings'],
-      name: browser.params.lang+'.ng1.compile.noBindings'
+      logId: 'ng1.compile.noBindings'
     });
   });
 
 });
+
+function runClickTimeBenchmark(config) {
+  var buttons = config.buttons.map(function(selector) {
+    return $(selector);
+  });
+  var timeParams = browser.params.timeBenchmark;
+  benchpress.runTimeBenchmark({
+    sampleSize: timeParams.sampleSize,
+    targetCoefficientOfVariation: timeParams.targetCoefficientOfVariation,
+    timeout: timeParams.timeout,
+    metrics: timeParams.metrics,
+    logId: browser.params.lang+'.'+config.logId
+  }, function() {
+    buttons.forEach(function(button) {
+      button.click();
+    });
+  });
+}

modules/benchmarks_external/test/perf/tree_perf.js

@@ -1,18 +1,36 @@
 "use strict";
-var util = require('../../../../tools/perf/util.js');
+var benchpress = require('../../../../tools/benchpress/benchpress.js');
 
 describe('ng1.x tree benchmark', function () {
 
   var URL = 'benchmarks_external/web/tree/tree_benchmark.html';
 
-  afterEach(util.verifyNoErrors);
+  afterEach(benchpress.verifyNoBrowserErrors);
 
   it('should log the stats', function() {
     browser.get(URL);
-    util.runClickBenchmark({
+    runClickTimeBenchmark({
       buttons: ['#destroyDom', '#createDom'],
-      name: browser.params.lang+'.ng1.tree'
+      logId: 'ng1.tree'
     });
   });
 
 });
+
+function runClickTimeBenchmark(config) {
+  var buttons = config.buttons.map(function(selector) {
+    return $(selector);
+  });
+  var timeParams = browser.params.timeBenchmark;
+  benchpress.runTimeBenchmark({
+    sampleSize: timeParams.sampleSize,
+    targetCoefficientOfVariation: timeParams.targetCoefficientOfVariation,
+    timeout: timeParams.timeout,
+    metrics: timeParams.metrics,
+    logId: browser.params.lang+'.'+config.logId
+  }, function() {
+    buttons.forEach(function(button) {
+      button.click();
+    });
+  });
+}

package.json

@@ -43,6 +43,7 @@
     "gulp-webserver": "^0.8.7",
     "angular": "1.3.5",
     "minimatch": "^2.0.1",
-    "lodash": "^2.4.1"
+    "lodash": "^2.4.1",
+    "sprintf-js": "1.0.*"
   }
 }

protractor-perf-shared.js

@@ -3,13 +3,13 @@ var config = exports.config = {
   specs: ['modules/*/test/**/*_perf.js'],
 
   params: {
-    // size of the sample to take
-    sampleSize: 10,
-    // error to be used for early exit
-    exitOnErrorLowerThan: 4,
-    // maxium number times the benchmark gets repeated before we output the stats
-    // of the best sample
-    maxRepeatCount: 30
+    timeBenchmark: {
+      // size of the sample to take
+      sampleSize: 10,
+      targetCoefficientOfVariation: 4,
+      timeout: 20000,
+      metrics: ['script', 'render']
+    }
   },
 
   // Disable waiting for Angular as we don't have an integration layer yet...
@@ -54,4 +54,4 @@ if (process.env.TRAVIS) {
       performance: 'ALL'
     }
   };
-}
+}

tools/benchpress/benchpress.js

@@ -0,0 +1,7 @@
+var timeBenchmark = require('./time_benchmark');
+var tools = require('./tools');
+
+module.exports = {
+  runTimeBenchmark: timeBenchmark.runTimeBenchmark,
+  verifyNoBrowserErrors: tools.verifyNoBrowserErrors
+};

tools/benchpress/commands.js

@@ -0,0 +1,55 @@
+var webdriver = require('protractor/node_modules/selenium-webdriver');
+
+module.exports = {
+  gc: gc,
+  timelineRecords: timelineRecords,
+  timelineTimestamp: timelineTimestamp
+};
+
+function timelineTimestamp(timestampId) {
+  browser.executeScript('console.timeStamp("'+timestampId+'")');
+}
+
+function timelineRecords() {
+  return perfLogs().then(function(logs) {
+    var logs = logs && logs['Timeline.eventRecorded'] || [];
+    return logs.map(function(message) {
+      return message.record;
+    });
+  });
+}
+
+function perfLogs() {
+  return plainLogs('performance').then(function(entries) {
+    var entriesByMethod = {};
+    entries.forEach(function(entry) {
+      var message = JSON.parse(entry.message).message;
+      var entries = entriesByMethod[message.method];
+      if (!entries) {
+        entries = entriesByMethod[message.method] = [];
+      }
+      entries.push(message.params);
+    });
+    return entriesByMethod;
+  });
+}
+
+// Needed as selenium-webdriver does not forward
+// performance logs in the correct way
+function plainLogs(type) {
+  return browser.driver.schedule(
+      new webdriver.Command(webdriver.CommandName.GET_LOG).
+          setParameter('type', type),
+      'WebDriver.manage().logs().get(' + type + ')');
+}
+
+function gc() {
+  // TODO(tbosch): this only works on chrome, and we actually should
+  // extend chromedriver to use the Debugger.CollectGarbage call of the
+  // remote debugger protocol.
+  // See http://src.chromium.org/viewvc/blink/trunk/Source/devtools/protocol.json
+  // For iOS Safari we need an extension to appium that uses
+  // the webkit remote debug protocol. See
+  // https://github.com/WebKit/webkit/blob/master/Source/WebInspectorUI/Versions/Inspector-iOS-8.0.json
+  return browser.executeScript('window.gc()');
+}

tools/benchpress/reporter.js

@@ -0,0 +1,32 @@
+var vsprintf = require("sprintf-js").vsprintf;
+
+var HEADER_SEPARATORS = ['----', '----', '----', '----'];
+var FOOTER_SEPARATORS = ['====', '====', '====', '===='];
+
+module.exports = {
+  printHeading: printHeading,
+  printTableHeader: printTableHeader,
+  printTableFooter: printTableFooter,
+  printRow: printRow
+};
+
+function printHeading(title) {
+  console.log('\n');
+  console.log('## '+title);
+}
+
+function printTableHeader(format, values) {
+  printRow(format, values);
+  // TODO(tbosch): generate separators dynamically based on the format!
+  printRow(format, HEADER_SEPARATORS);
+}
+
+function printTableFooter(format, values) {
+  // TODO(tbosch): generate separators dynamically based on the format!
+  printRow(format, FOOTER_SEPARATORS);
+  printRow(format, values);
+}
+
+function printRow(format, values) {
+  console.log(vsprintf(format, values));
+}

tools/benchpress/stats.js

@@ -0,0 +1,52 @@
+module.exports = {
+  createObjectStatsAggregator: createObjectStatsAggregator,
+  calculateCoefficientOfVariation: calculateCoefficientOfVariation,
+  calculateMean: calculateMean,
+  calculateStandardDeviation: calculateStandardDeviation
+};
+
+function createObjectStatsAggregator(sampleSize) {
+  var propSamples = {};
+  var lastResult;
+  return addData;
+
+  function addData(data) {
+    lastResult = {};
+    for (var prop in data) {
+      var samples = propSamples[prop];
+      if (!samples) {
+        samples = propSamples[prop] = [];
+      }
+      samples.push(data[prop]);
+      samples.splice(0, samples.length - sampleSize);
+      var mean = calculateMean(samples);
+      lastResult[prop] = {
+        mean: mean,
+        coefficientOfVariation: calculateCoefficientOfVariation(samples, mean),
+        count: samples.length
+      };
+    }
+    addData.current = lastResult;
+    return lastResult;
+  }
+}
+
+function calculateCoefficientOfVariation(sample, mean) {
+  return calculateStandardDeviation(sample, mean) / mean * 100;
+}
+
+function calculateMean(sample) {
+  var total = 0;
+  sample.forEach(function(x) { total += x; });
+  return total / sample.length;
+}
+
+function calculateStandardDeviation(sample, mean) {
+  var deviation = 0;
+  sample.forEach(function(x) {
+    deviation += Math.pow(x - mean, 2);
+  });
+  deviation = deviation / (sample.length);
+  deviation = Math.sqrt(deviation);
+  return deviation;
+}

tools/benchpress/time_benchmark.js

@@ -0,0 +1,227 @@
+var stats = require('./stats');
+var reporter = require('./reporter');
+var commands = require('./commands');
+
+var SUPPORTED_METRICS = {
+  script: true,
+  gcTime: true,
+  gcAmount: true,
+  gcTimeDuringScript: true,
+  gcAmountDuringScript: true,
+  gcAmountPerMs: true,
+  render: true
+};
+var DETERMINE_FORCE_GC_MODE_ITERATIONS = 5;
+
+var MODE_FORCE_GC = 'forceGc';
+var MODE_IGNORE_RUNS_WITH_GC = 'ignoreRunsWithGc';
+var MODE_INDETERMINATE = 'indeterminate';
+
+var nextTimestampId = 0;
+
+module.exports = {
+  runTimeBenchmark: runTimeBenchmark,
+  supportedMetrics: SUPPORTED_METRICS
+};
+
+function runTimeBenchmark(config, workCallback) {
+  config.metrics.forEach(function(metric) {
+    if (!(metric in SUPPORTED_METRICS)) {
+      throw new Error('Metric '+metric+' is not suported by benchpress right now');
+    }
+  });
+  var ROW_FORMAT = ['%-40s'].concat(config.metrics.map(function() {
+    return '%12s';
+  })).join(' | ');
+
+  var benchmarkStatsAggregator = stats.createObjectStatsAggregator(config.sampleSize);
+
+  var startTime = Date.now();
+  startLoop().then(endLoop);
+
+  var gcDuringScriptCount = 0;
+
+  function startLoop(gcData) {
+    reporter.printHeading('SCRIPT DATA: sampling size '+config.sampleSize);
+    reporter.printTableHeader(ROW_FORMAT, ['name'].concat(config.metrics));
+    return loop(0, MODE_INDETERMINATE);
+  }
+
+  function endLoop(stats) {
+    reporter.printTableFooter(ROW_FORMAT, [config.logId]
+      .concat(formatObjectStats(stats, config.metrics))
+    );
+    return config.metrics.map(function(metric) {
+      return stats[metric];
+    });
+  }
+
+  function loop(iterationIndex, mode) {
+    // For fast tests that don't create a lot of garbage,
+    // we don't want to force gc before every run as that
+    // can slow down the script execution time (even when we subtract
+    // the gc time)!
+    if (mode === MODE_FORCE_GC) {
+      commands.gc();
+    }
+    return measureTime(workCallback).then(function(benchmarkData) {
+      var hasGcDuringScript = !!benchmarkData.gcTimeDuringScript;
+      var ignoreBenchmarkRun = false;
+      if (hasGcDuringScript) {
+        gcDuringScriptCount ++;
+        ignoreBenchmarkRun = (mode === MODE_INDETERMINATE || mode === MODE_IGNORE_RUNS_WITH_GC);
+      }
+      if (mode === MODE_INDETERMINATE && iterationIndex >= DETERMINE_FORCE_GC_MODE_ITERATIONS) {
+        mode = (gcDuringScriptCount / iterationIndex > 0.5) ? MODE_FORCE_GC : MODE_IGNORE_RUNS_WITH_GC;
+      }
+
+      var rowTitle;
+      if (ignoreBenchmarkRun) {
+        rowTitle = '(ignored: gc in script)';
+      } else {
+        rowTitle = config.logId + '#' + iterationIndex;
+      }
+      reporter.printRow(ROW_FORMAT, [rowTitle]
+        .concat(formatObjectData(benchmarkData, config.metrics))
+      );
+
+      var benchmarkStats;
+      if (!ignoreBenchmarkRun) {
+        benchmarkStats = benchmarkStatsAggregator(benchmarkData);
+      } else {
+        benchmarkStats = benchmarkStatsAggregator.current;
+      }
+
+      if (Date.now() - startTime > config.timeout) {
+        return benchmarkStats;
+      }
+      if (benchmarkStats &&
+        (
+          benchmarkStats.script.count >= config.sampleSize &&
+          benchmarkStats.script.coefficientOfVariation < config.targetCoefficientOfVariation)
+        ) {
+        return benchmarkStats
+      }
+      return loop(iterationIndex+1, mode);
+    });
+  }
+}
+
+
+function formatObjectData(data, props) {
+  return props.map(function(prop) {
+    return data[prop].toFixed(2);
+  });
+}
+
+function formatObjectStats(stats, props) {
+  return props.map(function(prop) {
+    var entry = stats[prop];
+    return entry.mean.toFixed(2) + '\u00B1' + entry.coefficientOfVariation.toFixed(2);
+  });
+}
+
+function measureTime(callback) {
+  var startId = (nextTimestampId++).toString();
+  var endId = (nextTimestampId++).toString();
+  commands.timelineTimestamp(startId);
+  callback();
+  commands.timelineTimestamp(endId);
+  var allRecords = [];
+  return readResult();
+
+  function readResult() {
+    return commands.timelineRecords().then(function(records) {
+      allRecords.push.apply(allRecords, records);
+      var stats = sumTimelineRecords(allRecords, startId, endId);
+      if (stats.timeStamps.indexOf(startId) === -1 ||
+          stats.timeStamps.indexOf(endId) === -1) {
+        // Sometimes the logs have not yet arrived at the webdriver
+        // server from the browser.
+        // And sometimes, just waiting is not enough, so we
+        // execute a dummy js function :-(
+        browser.executeScript('1+1');
+        browser.sleep(100);
+        return readResult();
+      } else {
+        return stats;
+      }
+    });
+  }
+}
+
+function sumTimelineRecords(records, startTimeStampId, endTimeStampId) {
+  var isStarted = false;
+  var recordStats = {
+    script: 0,
+    gcTime: 0,
+    gcAmount: 0,
+    gcTimeDuringScript: 0,
+    gcAmountDuringScript: 0,
+    render: 0,
+    timeStamps: []
+  };
+  records.forEach(function(record) {
+    processRecord(record, recordStats, false);
+  });
+  recordStats.gcAmountPerMs = 0;
+  if (recordStats.gcAmount) {
+    recordStats.gcAmountPerMs = recordStats.gcAmount / recordStats.gcTime;
+  }
+  return recordStats;
+
+  function processRecord(record, recordStats, parentIsFunctionCall) {
+    if (record.type === 'TimeStamp' && record.data.message === startTimeStampId) {
+      isStarted = true;
+    }
+
+    // ignore scripts that were injected by Webdriver (e.g. calculation of element positions, ...)
+    var isFunctionCall = record.type === 'FunctionCall' &&
+      (!record.data || record.data.scriptName !== 'InjectedScript');
+
+    var summedChildrenDuration = 0;
+    if (record.children) {
+      record.children.forEach(function(child) {
+        summedChildrenDuration += processRecord(child, recordStats, isFunctionCall);
+      });
+    }
+    var recordDuration;
+    var recordUsed = false;
+    // we need to substract the time of child records
+    // that have been added to the stats from this record.
+    // E.g. for a script record that triggered a gc or reflow while executing.
+    recordDuration = (record.endTime ? record.endTime - record.startTime : 0)
+      - summedChildrenDuration;
+
+    if (isStarted) {
+      if (isFunctionCall) {
+        recordStats.script += recordDuration;
+        recordUsed = true;
+      } else if (record.type === 'GCEvent') {
+        recordStats.gcTime += recordDuration;
+        recordStats.gcAmount += record.data.usedHeapSizeDelta;
+        if (parentIsFunctionCall) {
+          recordStats.gcTimeDuringScript += recordDuration;
+          recordStats.gcAmountDuringScript += record.data.usedHeapSizeDelta;
+        }
+        recordUsed = true;
+      } else if (record.type === 'RecalculateStyles' ||
+          record.type === 'Layout' ||
+          record.type === 'UpdateLayerTree' ||
+          record.type === 'Paint' ||
+          record.type === 'Rasterize' ||
+          record.type === 'CompositeLayers') {
+        recordStats.render += recordDuration;
+        recordUsed = true;
+      } else if (record.type === 'TimeStamp') {
+        recordStats.timeStamps.push(record.data.message);
+      }
+    }
+
+    if (record.type === 'TimeStamp' && record.data.message === endTimeStampId) {
+      isStarted = false;
+    }
+    return recordUsed ? recordDuration : summedChildrenDuration;
+  }
+}
+

tools/benchpress/tools.js

@@ -0,0 +1,18 @@
+var webdriver = require('protractor/node_modules/selenium-webdriver');
+
+module.exports = {
+  verifyNoBrowserErrors: verifyNoBrowserErrors
+};
+
+function verifyNoBrowserErrors() {
+  browser.manage().logs().get('browser').then(function(browserLog) {
+    var filteredLog = browserLog.filter(function(logEntry) {
+      return logEntry.level.value > webdriver.logging.Level.WARNING.value;
+    });
+    expect(filteredLog.length).toEqual(0);
+    if (filteredLog.length) {
+      console.log('browser console errors: ' + require('util').inspect(filteredLog));
+    }
+  });
+}
+

tools/perf/util.js

@@ -1,232 +0,0 @@
-var webdriver = require('protractor/node_modules/selenium-webdriver');
-
-module.exports = {
-  perfLogs: perfLogs,
-  sumTimelineRecords: sumTimelineRecords,
-  runClickBenchmark: runClickBenchmark,
-  verifyNoErrors: verifyNoErrors,
-  printObjectAsMarkdown: printObjectAsMarkdown
-};
-
-function runClickBenchmark(config) {
-  var buttons = config.buttons.map(function(selector) {
-    return $(selector);
-  });
-  var globalParams = browser.params;
-
-  // empty perflogs queue and gc
-  gc();
-  perfLogs();
-  var sampleQueue = [];
-  var bestSampleStats = null;
-
-  loop(globalParams.maxRepeatCount).then(function(stats) {
-    printObjectAsMarkdown(config.name, stats);
-  });
-
-  function loop(count) {
-    if (!count) {
-      return bestSampleStats;
-    }
-    return webdriver.promise.all(buttons.map(function(button) {
-      // Note: even though we remove the gc time from the script time,
-      // we still get a high standard devication if we don't gc after every click...
-      return button.click().then(gc);
-    })).then(function() {
-      return perfLogs();
-    }).then(function(logs) {
-      var stats = calculateStatsBasedOnLogs(logs);
-      if (stats) {
-        if (stats.script.error < globalParams.exitOnErrorLowerThan) {
-          return stats;
-        }
-        if (!bestSampleStats || stats.script.error < bestSampleStats.script.error) {
-          bestSampleStats = stats;
-        }
-      }
-      return loop(count-1);
-    });
-  }
-
-  function calculateStatsBasedOnLogs(logs) {
-    sampleQueue.push(sumTimelineRecords(logs['Timeline.eventRecorded']));
-    if (sampleQueue.length >= globalParams.sampleSize) {
-      sampleQueue.splice(0, sampleQueue.length - globalParams.sampleSize);
-      // TODO: gc numbers don't have much meaning right now,
-      // as a benchmark run destroys everything.
-      // We need to measure the heap size after gc as well!
-      return calculateObjectSampleStats(sampleQueue, ['script', 'render', 'gcTime', 'gcAmount']);
-    }
-    return null;
-  }
-}
-
-function gc() {
-  // TODO(tbosch): this only works on chrome, and we actually should
-  // extend chromedriver to use the Debugger.CollectGarbage call of the
-  // remote debugger protocol.
-  // See http://src.chromium.org/viewvc/blink/trunk/Source/devtools/protocol.json
-  // For iOS Safari we need an extension to appium that uses
-  // the webkit remote debug protocol. See
-  // https://github.com/WebKit/webkit/blob/master/Source/WebInspectorUI/Versions/Inspector-iOS-8.0.json
-  return browser.executeScript('window.gc()');
-}
-
-function verifyNoErrors() {
-  browser.manage().logs().get('browser').then(function(browserLog) {
-    var filteredLog = browserLog.filter(function(logEntry) {
-      return logEntry.level.value > webdriver.logging.Level.WARNING.value;
-    });
-    expect(filteredLog.length).toEqual(0);
-    if (filteredLog.length) {
-      console.log('browser console errors: ' + require('util').inspect(filteredLog));
-    }
-  });
-}
-
-function perfLogs() {
-  return plainLogs('performance').then(function(entries) {
-    var entriesByMethod = {};
-    entries.forEach(function(entry) {
-      var message = JSON.parse(entry.message).message;
-      var entries = entriesByMethod[message.method];
-      if (!entries) {
-        entries = entriesByMethod[message.method] = [];
-      }
-      entries.push(message.params);
-    });
-    return entriesByMethod;
-  });
-}
-
-// Needed as selenium-webdriver does not forward
-// performance logs in the correct way
-function plainLogs(type) {
-  var webdriver = require('protractor/node_modules/selenium-webdriver');
-  return browser.driver.schedule(
-      new webdriver.Command(webdriver.CommandName.GET_LOG).
-          setParameter('type', type),
-      'WebDriver.manage().logs().get(' + type + ')');
-};
-
-
-function sumTimelineRecords(messages) {
-  var recordStats = {
-    script: 0,
-    gcTime: 0,
-    gcAmount: 0,
-    render: 0
-  };
-  messages.forEach(function(message) {
-    processRecord(message.record, recordStats);
-  });
-  return recordStats;
-
-  function processRecord(record, recordStats) {
-    var summedChildrenDuration = 0;
-    if (record.children) {
-      record.children.forEach(function(child) {
-        summedChildrenDuration += processRecord(child, recordStats);
-      });
-    }
-
-    var recordDuration;
-    var recordUsed = false;
-    if (recordStats) {
-      // we need to substract the time of child records
-      // that have been added to the stats from this record.
-      // E.g. for a script record that triggered a gc or reflow while executing.
-      recordDuration = (record.endTime ? record.endTime - record.startTime : 0)
-        - summedChildrenDuration;
-      if (record.type === 'FunctionCall') {
-        if (!record.data || record.data.scriptName !== 'InjectedScript') {
-          // ignore scripts that were injected by Webdriver (e.g. calculation of element positions, ...)
-          recordStats.script += recordDuration;
-          recordUsed = true;
-        }
-      } else if (record.type === 'GCEvent') {
-        recordStats.gcTime += recordDuration;
-        recordStats.gcAmount += record.data.usedHeapSizeDelta;
-        recordUsed = true;
-      } else if (record.type === 'RecalculateStyles' ||
-          record.type === 'Layout' ||
-          record.type === 'UpdateLayerTree' ||
-          record.type === 'Paint' ||
-          record.type === 'Rasterize' ||
-          record.type === 'CompositeLayers') {
-        recordStats.render += recordDuration;
-        recordUsed = true;
-      }
-    }
-    return recordUsed ? recordDuration : summedChildrenDuration;
-  }
-}
-
-function printObjectAsMarkdown(name, obj) {
-  var props = [['name']];
-  var vals = [name];
-  flattenObj(obj, [], props, vals);
-  // log header
-  var separators = [];
-  var header = props.map(function(propPath) {
-    separators.push('----');
-    return propPath.join('.');
-  }).join(' | ');
-  console.log('\n'+header);
-  console.log(separators.join(' | '));
-  console.log(vals.join(' | '));
-  console.log('\n');
-
-  function flattenObj(obj, propPathPrefix, targetProps, targetVals) {
-    for (var prop in obj) {
-      var val = obj[prop];
-      var currPropPath = propPathPrefix.concat([prop]);
-      if (val && typeof val === 'object') {
-        flattenObj(val, currPropPath, targetProps, targetVals);
-      } else {
-        targetProps.push(currPropPath);
-        var valStr = val;
-        if (typeof val === 'number') {
-          valStr = val.toFixed(2);
-        }
-        targetVals.push(valStr);
-      }
-    }
-  }
-}
-
-function calculateObjectSampleStats(objectSamples, properties) {
-  var result = {};
-  properties.forEach(function(prop) {
-    var samples = objectSamples.map(function(objectSample) {
-      return objectSample[prop];
-    });
-    var mean = calculateMean(samples);
-    var error = calculateCoefficientOfVariation(samples, mean);
-    result[prop] = {
-      mean: mean,
-      error: error
-    };
-  });
-  return result;
-}
-
-function calculateCoefficientOfVariation(sample, mean) {
-  return calculateStandardDeviation(sample, mean) / mean * 100;
-}
-
-function calculateMean(sample) {
-  var total = 0;
-  sample.forEach(function(x) { total += x; });
-  return total / sample.length;
-}
-
-function calculateStandardDeviation(sample, mean) {
-  var deviation = 0;
-  sample.forEach(function(x) {
-    deviation += Math.pow(x - mean, 2);
-  });
-  deviation = deviation / (sample.length -1);
-  deviation = Math.sqrt(deviation);
-  return deviation;
-};