Log some very basic timers in WebUI tests using PolymerTest

chrome/test/data/webui/polymer_browser_test_base.js

 // Copyright 2015 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 /**
  * @fileoverview Framework for running JavaScript tests of Polymer elements.
  */
 
 /**
  * Test fixture for Polymer element testing.
@@ skipping 24 matching lines @@
    * Files that need not be compiled. Should be overridden to use correct
    * relative paths with PolymerTest.getLibraries.
    * @override
    */
   extraLibraries: [
     'ui/webui/resources/js/cr.js',
     'third_party/mocha/mocha.js',
     'chrome/test/data/webui/mocha_adapter.js',
   ],
 
+  /** Time when preLoad starts, i.e. before the browsePreload page is loaded. */
+  preloadTime: 0,
+
+  /** Time when test setup starts. */
+  setupTime: 0,
+
+  /** Time when test run starts. */
+  runTime: 0,
+
+  /** @override */
+  preLoad: function() {
+    this.preloadTime = window.performance.now();
+    testing.Test.prototype.preLoad.call(this);
+  },
+
   /** @override */
   setUp: function() {
+    this.setupTime = window.performance.now();
     testing.Test.prototype.setUp.call(this);
 
     // List of imported URLs for debugging purposes.
     PolymerTest.importUrls_ = [];
 
     // Importing a URL like "chrome://md-settings/foo" redirects to the base
     // ("chrome://md-settings") page, which due to how browsePreload works can
     // result in duplicate imports. Wrap document.registerElement so failures
     // caused by re-registering Polymer elements are caught; otherwise Chrome
     // simply throws "Script error" which is unhelpful.
@@ skipping 26 matching lines @@
       }
       if (typeof TestHelpers != 'object') {
         promises.push(
             PolymerTest.importHtml(
                 'chrome://resources/polymer/v1_0/iron-test-helpers/' +
                 'iron-test-helpers.html'));
       }
       return Promise.all(promises);
     });
   },
+
+  /** @override */
+  runTest: function(testBody) {
+    this.runTime = window.performance.now();
+    testing.Test.prototype.runTest.call(this, testBody);
+  },
+
+  /** @override */
+  tearDown: function() {
+    var endTime = window.performance.now();
+    var delta = this.setupTime - this.preloadTime;
+    console.log('Page load time: ' + delta + " ms");

[michaelpg, 2015/11/24 23:26:19]

Turns out floats are really annoying to read...

Could we round delta? or if we want to keep decimal places for some reason,
Math.round(delta * 100) / 100

+    delta = endTime - this.runTime;
+    console.log('Test run time: ' + delta + " ms");
+    delta = endTime - this.preloadTime;
+    console.log('Total time: ' + delta + " ms");
+    testing.Test.prototype.tearDown.call(this);

[Dan Beam, 2015/11/23 23:10:51]

nit: can we use console.time() + console.timeEnd()?

[stevenjb, 2015/11/23 23:24:41]

I was thinking that later we might want to do something in individual tests that
log something like 'Time to basic page ready', etc.

Also, I prefer to log all of the times at the end. With console.time I would
need to log, e.g. the page load time before running the tests, making that
output harder to find.

+  }
 };
 
 /**
  * Imports the HTML file.
  * @param {string} src The URL to load.
  * @return {Promise} A promise that is resolved/rejected on success/failure.
  */
 PolymerTest.importHtml = function(src) {
   PolymerTest.importUrls_.push(src);
   var link = document.createElement('link');
@@ skipping 19 matching lines @@
  */
 PolymerTest.getLibraries = function(basePath) {
   // Ensure basePath ends in '/'.
   if (basePath.length && basePath[basePath.length - 1] != '/')
     basePath += '/';
 
   return PolymerTest.prototype.extraLibraries.map(function(library) {
     return basePath + library;
   });
 };