feat: save devtools log (#1665)

.gitignore

@@ -14,6 +14,7 @@ results.html
 last-run-results.html
 
 *.trace.json
+*.devtoolslog.json
 *.screenshots.html
 *.report.html
 *.artifacts.log
@@ -29,4 +30,3 @@ lighthouse-cli/commands/*.js
 
 lighthouse-cli/types/*.js
 lighthouse-cli/types/*.map
-

lighthouse-core/gather/connections/connection.js

@@ -18,6 +18,7 @@
 
 const EventEmitter = require('events').EventEmitter;
 const log = require('../../lib/log.js');
+const MessageLog = require('./message-log');
 
 class Connection {
 
@@ -26,6 +27,7 @@ class Connection {
     /** @type {!Map<number, {resolve: function(*), reject: function(*), method: string}>}*/
     this._callbacks = new Map();
     this._eventEmitter = new EventEmitter();
+    this.log = new MessageLog();
   }
 
   /**
@@ -108,6 +110,8 @@ class Connection {
         return object.result;
       }));
     }
+
+    this.log.record(object);
     log.formatProtocol('<= event',
         {method: object.method, params: object.params}, 'verbose');
     this.emitNotification(object.method, object.params);

lighthouse-core/gather/connections/message-log.js

@@ -0,0 +1,54 @@
+/**
+ * @license
+ * Copyright 2017 Google Inc. All Rights Reserved.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+'use strict';
+
+class MessageLog {
+  constructor() {
+    this._messages = [];
+    this._isRecording = false;
+  }
+
+  /**
+   * @return {!Array<Object>}
+   */
+  get messages() {
+    return this._messages;
+  }
+
+  reset() {
+    this._messages = [];
+  }
+
+  beginRecording() {
+    this._isRecording = true;
+  }
+
+  endRecording() {
+    this._isRecording = false;
+  }
+
+  /**
+   * @param {{method: string, params: Object}} message
+   */
+  record(message) {
+    if (this._isRecording && /^(Page|Network)\./.test(message.method)) {
+      this._messages.push(message);
+    }
+  }
+}
+
+module.exports = MessageLog;

lighthouse-core/gather/driver.js

@@ -62,6 +62,10 @@ class Driver {
     ];
   }
 
+  get devtoolsLog() {
+    return this._connection.log.messages;
+  }
+
   /**
    * @return {!Promise<null>}
    */
@@ -571,6 +575,9 @@ class Driver {
       throw new Error('DOM domain enabled when starting trace');
     }
 
+    this._connection.log.reset();
+    this._connection.log.beginRecording();
+
     // Enable Page domain to wait for Page.loadEventFired
     return this.sendCommand('Page.enable')
       .then(_ => this.sendCommand('Tracing.start', tracingOpts));
@@ -580,6 +587,7 @@ class Driver {
     return new Promise((resolve, reject) => {
       // When the tracing has ended this will fire with a stream handle.
       this.once('Tracing.tracingComplete', streamHandle => {
+        this._connection.log.endRecording();
         this._readTraceFromStream(streamHandle)
             .then(traceContents => resolve(traceContents), reject);
       });

lighthouse-core/gather/gather-runner.js

@@ -219,6 +219,7 @@ class GatherRunner {
         // an object with a traceEvents property. Normalize to object form.
         passData.trace = Array.isArray(traceContents) ?
             {traceEvents: traceContents} : traceContents;
+        passData.devtoolsLog = driver.devtoolsLog;
         log.verbose('statusEnd', 'Retrieving trace');
       });
     }
@@ -288,6 +289,7 @@ class GatherRunner {
     const driver = options.driver;
     const tracingData = {
       traces: {},
+      devtoolsLogs: {},
       networkRecords: {}
     };
 
@@ -330,7 +332,10 @@ class GatherRunner {
               // If requested by config, merge trace and network data for this
               // pass into tracingData.
               const passName = config.passName || Audit.DEFAULT_PASS;
-              config.recordTrace && (tracingData.traces[passName] = passData.trace);
+              if (config.recordTrace) {
+                tracingData.traces[passName] = passData.trace;
+                tracingData.devtoolsLogs[passName] = passData.devtoolsLog;
+              }
               config.recordNetwork &&
                   (tracingData.networkRecords[passName] = passData.networkRecords);
 

lighthouse-core/lib/asset-saver.js

@@ -114,6 +114,7 @@ function prepareAssets(artifacts, audits) {
 
   return passNames.reduce((chain, passName) => {
     const trace = artifacts.traces[passName];
+    const devtoolsLog = artifacts.devtoolsLogs[passName];
 
     return chain.then(_ => artifacts.requestScreenshots(trace))
       .then(screenshots => {
@@ -126,6 +127,7 @@ function prepareAssets(artifacts, audits) {
         }
         assets.push({
           traceData,
+          devtoolsLog,
           html
         });
       });
@@ -143,11 +145,14 @@ function prepareAssets(artifacts, audits) {
 function saveAssets(artifacts, audits, pathWithBasename) {
   return prepareAssets(artifacts, audits).then(assets => {
     assets.forEach((data, index) => {
-      const traceData = data.traceData;
       const traceFilename = `${pathWithBasename}-${index}.trace.json`;
-      fs.writeFileSync(traceFilename, JSON.stringify(traceData, null, 2));
+      fs.writeFileSync(traceFilename, JSON.stringify(data.traceData, null, 2));
       log.log('trace file saved to disk', traceFilename);
 
+      const devtoolsLogFilename = `${pathWithBasename}-${index}.devtoolslog.json`;
+      fs.writeFileSync(devtoolsLogFilename, JSON.stringify(data.devtoolsLog, null, 2));
+      log.log('devtools log saved to disk', devtoolsLogFilename);
+
       const screenshotsFilename = `${pathWithBasename}-${index}.screenshots.html`;
       fs.writeFileSync(screenshotsFilename, data.html);
       log.log('screenshots saved to disk', screenshotsFilename);

lighthouse-core/test/gather/connections/message-log-test.js

@@ -0,0 +1,67 @@
+/**
+ * Copyright 2017 Google Inc. All rights reserved.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+'use strict';
+
+/* eslint-env mocha */
+
+const assert = require('assert');
+const MessageLog = require('../../../gather/connections/message-log');
+
+describe('MessageLog', () => {
+  let messageLog;
+  const pageMsg = {method: 'Page.frameStartedLoading'};
+  const networkMsg = {method: 'Network.requestWillBeSent'};
+  const otherMsg = {method: 'Storage.cleared'};
+
+  beforeEach(() => messageLog = new MessageLog());
+
+  it('returns an array', () => {
+    assert.deepEqual(messageLog.messages, []);
+  });
+
+  it('records only when requested', () => {
+    messageLog.record(pageMsg); // will not record
+    messageLog.beginRecording();
+    messageLog.record(networkMsg); // will record
+    messageLog.endRecording();
+    messageLog.record(pageMsg); // will not record
+    assert.equal(messageLog.messages.length, 1);
+    assert.equal(messageLog.messages[0].method, networkMsg.method);
+  });
+
+  it('does not record non-Network/Page events', () => {
+    messageLog.beginRecording();
+    messageLog.record(pageMsg); // will record
+    messageLog.record(networkMsg); // will record
+    messageLog.record(otherMsg); // won't record
+    messageLog.endRecording();
+    assert.equal(messageLog.messages.length, 2);
+    assert.equal(messageLog.messages[0].method, pageMsg.method);
+  });
+
+  it('resets properly', () => {
+    messageLog.beginRecording();
+    messageLog.record(pageMsg);
+    messageLog.record(pageMsg);
+    messageLog.endRecording();
+    messageLog.reset();
+
+    messageLog.beginRecording();
+    messageLog.record(pageMsg);
+    messageLog.endRecording();
+    assert.equal(messageLog.messages.length, 1);
+  });
+});

lighthouse-core/test/lib/asset-saver-test.js

@@ -47,6 +47,7 @@ describe('asset-saver helper', () => {
 
   it('generates HTML', () => {
     const artifacts = {
+      devtoolsLogs: {},
       traces: {
         [Audit.DEFAULT_PASS]: {
           traceEvents: []
@@ -61,6 +62,9 @@ describe('asset-saver helper', () => {
 
   describe('saves files', function() {
     const artifacts = {
+      devtoolsLogs: {
+        [Audit.DEFAULT_PASS]: [{message: 'first'}, {message: 'second'}]
+      },
       traces: {
         [Audit.DEFAULT_PASS]: {
           traceEvents
@@ -78,6 +82,13 @@ describe('asset-saver helper', () => {
       fs.unlinkSync(traceFilename);
     });
 
+    it('devtools log file saved to disk with data', () => {
+      const filename = 'the_file-0.devtoolslog.json';
+      const fileContents = fs.readFileSync(filename, 'utf8');
+      assert.ok(fileContents.includes('"message": "first"'));
+      fs.unlinkSync(filename);
+    });
+
     it('screenshots file saved to disk with data', () => {
       const ssFilename = 'the_file-0.screenshots.html';
       const ssFileContents = fs.readFileSync(ssFilename, 'utf8');
@@ -91,6 +102,7 @@ describe('asset-saver helper', () => {
     it('adds fake events to trace', () => {
       const countEvents = trace => trace.traceEvents.length;
       const mockArtifacts = {
+        devtoolsLogs: {},
         traces: {
           defaultPass: dbwTrace
         },