cli: use logger to print status messages (#530)

When cli is run with the output directed to stdout, it may become quite
inconvenient for the progress status messages to pop up on the stdout
as they are being mixed with the audit formatted results.

This change makes both `status` and `statusEnd` events be emitted on
`log.events`, and replaces `console.time` and `console.timeEnd` with
outputting the timers using lighthouse logger, so that all timer
messages go to the same place, usually stderr.

In any event, this change makes it easier to control and redirect
status messages in the same way all other logging is done.

lighthouse-cli/index.js

@@ -22,6 +22,7 @@ const yargs = require('yargs');
 const semver = require('semver');
 const Printer = require('./printer');
 const lighthouse = require('../lighthouse-core');
+const log = require('../lighthouse-core/lib/log');
 
 // node 5.x required due to use of ES2015 features, like spread operator
 if (semver.lt(process.version, '5.0.0')) {
@@ -146,6 +147,25 @@ if (!flags.auditWhitelist || flags.auditWhitelist === 'all') {
   flags.auditWhitelist = new Set(flags.auditWhitelist.split(',').map(a => a.toLowerCase()));
 }
 
+// Listen on progress events, record their start timestamps
+// and print result using the logger.
+let timers = {};
+log.events.on('status', function(event) {
+  let msg = event[1];
+  if (!msg) {
+    return;
+  }
+  timers[msg] = Date.now();
+});
+log.events.on('statusEnd', function(event) {
+  let msg = event[1];
+  if (!msg) {
+    return;
+  }
+  let t = Date.now() - timers[msg];
+  log.log('Timer', `${msg} ${t}ms`);
+});
+
 // kick off a lighthouse run
 lighthouse(url, flags, config)
   .then(results => Printer.write(results, outputMode, outputPath))

lighthouse-core/lib/log.js

@@ -44,13 +44,9 @@ const events = new Emitter();
 module.exports = {
   setLevel,
   events,
-  log(title, msg) {
-    if (title === 'status') {
-      console.time(msg);
-      events.emit('status', arguments);
-    }
-    if (title === 'statusEnd') {
-      console.timeEnd(msg);
+  log(title) {
+    if (title === 'status' || title === 'statusEnd') {
+      events.emit(title, arguments);
     }
     return _log(title, arguments);
   },