Show the test progress (#517)

Extension now reveals the progress, as does CLI

lighthouse-core/driver/index.js

@@ -16,6 +16,8 @@
  */
 'use strict';
 
+const log = require('../lib/log.js');
+
 class Driver {
 
   static loadPage(driver, options) {
@@ -32,6 +34,7 @@ class Driver {
   }
 
   static setupDriver(driver, gatherers, options) {
+    log.log('status', 'Initializing…');
     return new Promise((resolve, reject) => {
       // Enable emulation.
       if (options.flags.mobile) {
@@ -82,10 +85,17 @@ class Driver {
     const driver = options.driver;
     const config = options.config;
     const gatherers = config.gatherers;
+    const gatherernames = gatherers.map(g => g.name).join(', ');
     let pass = Promise.resolve();
 
     if (config.loadPage) {
-      pass = pass.then(_ => this.loadPage(driver, options));
+      pass = pass.then(_ => {
+        const status = 'Loading page & waiting for onload';
+        log.log('status', status, gatherernames);
+        return this.loadPage(driver, options).then(_ => {
+          log.log('statusEnd', status);
+        });
+      });
     }
 
     return gatherers.reduce((chain, gatherer) => {
@@ -101,20 +111,36 @@ class Driver {
     let pass = Promise.resolve();
 
     if (config.trace) {
-      pass = pass.then(_ => driver.endTrace().then(traceContents => {
-        loadData.traceContents = traceContents;
-      }));
+      pass = pass.then(_ => {
+        log.log('status', 'Gathering: trace');
+        driver.endTrace().then(traceContents => {
+          loadData.traceContents = traceContents;
+          log.log('statusEnd', 'Gathering: trace');
+        });
+      });
     }
 
     if (config.network) {
-      pass = pass.then(_ => driver.endNetworkCollect().then(networkRecords => {
-        loadData.networkRecords = networkRecords;
-      }));
+      pass = pass.then(_ => {
+        const status = 'Gathering: network records';
+        log.log('status', status);
+        return driver.endNetworkCollect().then(networkRecords => {
+          loadData.networkRecords = networkRecords;
+          log.log('statusEnd', status);
+        });
+      });
     }
 
     return gatherers
         .reduce((chain, gatherer) => {
-          return chain.then(_ => gatherer.afterPass(options, loadData));
+          return chain.then(_ => {
+            const status = `Gathering: ${gatherer.name}`;
+            log.log('status', status);
+            return Promise.resolve(gatherer.afterPass(options, loadData)).then(ret => {
+              log.log('statusEnd', status);
+              return ret;
+            });
+          });
         }, pass)
         .then(_ => loadData);
   }
@@ -171,7 +197,13 @@ class Driver {
       })
 
       // Reload the page to remove any side-effects of Lighthouse (like disabling JavaScript).
-      .then(_ => this.loadPage(driver, options))
+      .then(_ => {
+        const status = 'Reloading page to reset state';
+        log.log('status', status);
+        return this.loadPage(driver, options).then(_ => {
+          log.log('statusEnd', status);
+        });
+      })
 
        // Finish and teardown.
       .then(_ => driver.disconnect())

lighthouse-core/lib/log.js

@@ -17,6 +17,7 @@
 'use strict';
 
 const debug = require('debug');
+const EventEmitter = require('events').EventEmitter;
 
 function setLevel(level) {
   if (level === 'verbose') {
@@ -37,17 +38,31 @@ function _log(title, logargs) {
   return loggers[title](...args);
 }
 
+class Emitter extends EventEmitter { }
+const events = new Emitter();
+
 module.exports = {
   setLevel,
-  log(title) {
+  events,
+  log(title, msg) {
+    if (title === 'status') {
+      console.time(msg);
+      events.emit('status', arguments);
+    }
+    if (title === 'statusEnd') {
+      console.timeEnd(msg);
+    }
     return _log(title, arguments);
   },
+
   warn(title) {
     return _log(`${title}:warn`, arguments);
   },
+
   error(title) {
     return _log(`${title}:error`, arguments);
   },
+
   verbose(title) {
     return _log(`${title}:verbose`, arguments);
   }

lighthouse-core/runner.js

@@ -19,6 +19,7 @@
 const Driver = require('./driver');
 const Aggregator = require('./aggregator');
 const assetSaver = require('./lib/asset-saver');
+const log = require('./lib/log');
 const fs = require('fs');
 const path = require('path');
 
@@ -64,7 +65,12 @@ class Runner {
 
       // Now run the audits.
       run = run.then(artifacts => Promise.all(config.audits.map(audit => {
-        return audit.audit(artifacts);
+        const status = `Evaluating: ${audit.meta.description}`;
+        log.log('status', status);
+        return Promise.resolve(audit.audit(artifacts)).then(ret => {
+          log.log('statusEnd', status);
+          return ret;
+        });
       })));
     } else if (config.auditResults) {
       // If there are existing audit results, surface those here.

lighthouse-extension/app/popup.html

@@ -43,7 +43,8 @@ <h2 class="header-titles__url">...</h2>
 
   <aside class="status">
     <div class="status__spinner"></div>
-    <div class="status__msg">Auditing page...</div>
+    <div class="status__msg">Starting...</div>
+    <div><small class="status__detailsmsg"></small></div>
   </aside>
 
   <script src="scripts/popup.js"></script>

lighthouse-extension/app/src/lighthouse-background.js

@@ -53,6 +53,10 @@ window.runAudits = function(options) {
       });
 };
 
+window.listenForStatus = function(callback) {
+  log.events.addListener('status', callback);
+};
+
 chrome.runtime.onInstalled.addListener(details => {
   if (details.previousVersion) {
     console.log('previousVersion', details.previousVersion);

lighthouse-extension/app/src/popup.js

@@ -21,6 +21,8 @@ document.addEventListener('DOMContentLoaded', _ => {
   const generateReportEl = document.body.querySelector('.generate-report');
 
   const statusEl = document.body.querySelector('.status');
+  const statusMessageEl = document.body.querySelector('.status__msg');
+  const statusDetailsMessageEl = document.body.querySelector('.status__detailsmsg');
   const spinnerEl = document.body.querySelector('.status__spinner');
   const feedbackEl = document.body.querySelector('.feedback');
   let spinnerAnimation;
@@ -41,6 +43,13 @@ document.addEventListener('DOMContentLoaded', _ => {
     statusEl.classList.remove('status--visible');
   };
 
+  const logstatus = ([, message, details]) => {
+    statusMessageEl.textContent = message;
+    statusDetailsMessageEl.textContent = details;
+  };
+
+  background.listenForStatus(logstatus);
+
   generateReportEl.addEventListener('click', () => {
     startSpinner();
     feedbackEl.textContent = '';
@@ -61,6 +70,7 @@ document.addEventListener('DOMContentLoaded', _ => {
       }
       feedbackEl.textContent = message;
       stopSpinner();
+      background.console.error(err);
     });
   });
 

lighthouse-extension/app/styles/lighthouse.css

@@ -141,6 +141,7 @@ body {
   opacity: 0;
   will-change: opacity;
   transition: opacity 0.150s cubic-bezier(0,0,0.41,1);
+  text-align: center;
 }
 
 .status--visible {

lighthouse-extension/gulpfile.js

@@ -154,7 +154,7 @@ gulp.task('watch', ['lint', 'browserify', 'html', 'copyReportScripts'], () => {
   gulp.watch([
     '*.js',
     'app/src/**/*.js',
-    'node_modules/lighthouse-core/**/*.js'
+    '../lighthouse-core/**/*.js'
   ], ['browserify', 'lint']);
 });