Merge pull request #2593 from GoogleChrome/streamingjson

paulirish · web-flow · commit 2d7aca87fcd0 · 2017-06-28T17:10:42.000-07:00
Add streaming JSON parser and file writer
diff --git a/lighthouse-core/gather/driver.js b/lighthouse-core/gather/driver.js
@@ -10,6 +10,7 @@ const emulation = require('../lib/emulation');
 const Element = require('../lib/element');
 const EventEmitter = require('events').EventEmitter;
 const URL = require('../lib/url-shim');
+const TraceParser = require('../lib/traces/trace-parser');
 
 const log = require('lighthouse-logger');
 const DevtoolsLog = require('./devtools-log');
@@ -801,7 +802,7 @@ class Driver {
   _readTraceFromStream(streamHandle) {
     return new Promise((resolve, reject) => {
       let isEOF = false;
-      let result = '';
+      const parser = new TraceParser();
 
       const readArguments = {
         handle: streamHandle.stream
@@ -812,11 +813,11 @@ class Driver {
           return;
         }
 
-        result += response.data;
+        parser.parseChunk(response.data);
 
         if (response.eof) {
           isEOF = true;
-          return resolve(JSON.parse(result));
+          return resolve(parser.getTrace());
         }
 
         return this.sendCommand('IO.read', readArguments).then(onChunkRead);
diff --git a/lighthouse-core/lib/asset-saver.js b/lighthouse-core/lib/asset-saver.js
@@ -7,6 +7,7 @@
 
 const fs = require('fs');
 const log = require('lighthouse-logger');
+const stream = require('stream');
 const stringifySafe = require('json-stringify-safe');
 const Metrics = require('./traces/pwmetrics-events');
 
@@ -102,6 +103,68 @@ function prepareAssets(artifacts, audits) {
     .then(_ => assets);
 }
 
+/**
+ * Generates a JSON representation of traceData line-by-line to avoid OOM due to
+ * very large traces.
+ * @param {{traceEvents: !Array}} traceData
+ * @return {!Iterator<string>}
+ */
+function* traceJsonGenerator(traceData) {
+  const keys = Object.keys(traceData);
+
+  yield '{\n';
+
+  // Stringify and emit trace events separately to avoid a giant string in memory.
+  yield '"traceEvents": [\n';
+  if (traceData.traceEvents.length > 0) {
+    const eventsIterator = traceData.traceEvents[Symbol.iterator]();
+    // Emit first item manually to avoid a trailing comma.
+    const firstEvent = eventsIterator.next().value;
+    yield `  ${JSON.stringify(firstEvent)}`;
+    for (const event of eventsIterator) {
+      yield `,\n  ${JSON.stringify(event)}`;
+    }
+  }
+  yield '\n]';
+
+  // Emit the rest of the object (usually just `metadata`)
+  if (keys.length > 1) {
+    for (const key of keys) {
+      if (key === 'traceEvents') continue;
+
+      yield `,\n"${key}": ${JSON.stringify(traceData[key], null, 2)}`;
+    }
+  }
+
+  yield '}\n';
+}
+
+/**
+ * Save a trace as JSON by streaming to disk at traceFilename.
+ * @param {{traceEvents: !Array}} traceData
+ * @param {string} traceFilename
+ * @return {!Promise<undefined>}
+ */
+function saveTrace(traceData, traceFilename) {
+  return new Promise((resolve, reject) => {
+    const traceIter = traceJsonGenerator(traceData);
+    // A stream that pulls in the next traceJsonGenerator chunk as writeStream
+    // reads from it. Closes stream with null when iteration is complete.
+    const traceStream = new stream.Readable({
+      read() {
+        const next = traceIter.next();
+        this.push(next.done ? null : next.value);
+      }
+    });
+
+    const writeStream = fs.createWriteStream(traceFilename);
+    writeStream.on('finish', resolve);
+    writeStream.on('error', reject);
+
+    traceStream.pipe(writeStream);
+  });
+}
+
 /**
  * Writes trace(s) and associated screenshot(s) to disk.
  * @param {!Artifacts} artifacts
@@ -111,28 +174,31 @@ function prepareAssets(artifacts, audits) {
  */
 function saveAssets(artifacts, audits, pathWithBasename) {
   return prepareAssets(artifacts, audits).then(assets => {
-    assets.forEach((data, index) => {
-      const traceFilename = `${pathWithBasename}-${index}.trace.json`;
-      fs.writeFileSync(traceFilename, JSON.stringify(data.traceData, null, 2));
-      log.log('trace file saved to disk', traceFilename);
-
+    return Promise.all(assets.map((data, index) => {
       const devtoolsLogFilename = `${pathWithBasename}-${index}.devtoolslog.json`;
       fs.writeFileSync(devtoolsLogFilename, JSON.stringify(data.devtoolsLog, null, 2));
-      log.log('devtools log saved to disk', devtoolsLogFilename);
+      log.log('saveAssets', 'devtools log saved to disk: ' + devtoolsLogFilename);
 
       const screenshotsHTMLFilename = `${pathWithBasename}-${index}.screenshots.html`;
       fs.writeFileSync(screenshotsHTMLFilename, data.screenshotsHTML);
-      log.log('screenshots saved to disk', screenshotsHTMLFilename);
+      log.log('saveAssets', 'screenshots saved to disk: ' + screenshotsHTMLFilename);
 
       const screenshotsJSONFilename = `${pathWithBasename}-${index}.screenshots.json`;
       fs.writeFileSync(screenshotsJSONFilename, JSON.stringify(data.screenshots, null, 2));
-      log.log('screenshots saved to disk', screenshotsJSONFilename);
-    });
+      log.log('saveAssets', 'screenshots saved to disk: ' + screenshotsJSONFilename);
+
+      const streamTraceFilename = `${pathWithBasename}-${index}.trace.json`;
+      log.log('saveAssets', 'streaming trace file to disk: ' + streamTraceFilename);
+      return saveTrace(data.traceData, streamTraceFilename).then(_ => {
+        log.log('saveAssets', 'trace file streamed to disk: ' + streamTraceFilename);
+      });
+    }));
   });
 }
 
 module.exports = {
   saveArtifacts,
   saveAssets,
-  prepareAssets
+  prepareAssets,
+  saveTrace
 };
diff --git a/lighthouse-core/lib/traces/trace-parser.js b/lighthouse-core/lib/traces/trace-parser.js
@@ -0,0 +1,70 @@
+/**
+ * @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';
+
+const WebInspector = require('../web-inspector');
+
+/**
+ * Traces > 256MB hit limits in V8, so TraceParser will parse the trace events stream as it's
+ * received. We use DevTools' TimelineLoader for the heavy lifting, as it has a fast trace-specific
+ * streaming JSON parser.
+ * The resulting trace doesn't include the "metadata" property, as it's excluded via DevTools'
+ * implementation.
+ */
+class TraceParser {
+  constructor() {
+    this.traceEvents = [];
+
+    this.tracingModel = {
+      reset: _ => this._reset(),
+      addEvents: evts => this._addEvents(evts),
+    };
+
+    const delegateMock = {
+      loadingProgress: _ => {},
+      loadingStarted: _ => {},
+      loadingComplete: success => {
+        if (!success) throw new Error('Parsing problem');
+      }
+    };
+    this.loader = new WebInspector.TimelineLoader(this.tracingModel, delegateMock);
+  }
+
+  /**
+   * Reset the trace events array
+   */
+  _reset() {
+    this.traceEvents = [];
+  }
+
+  /**
+   * Adds parsed trace events to array
+   * @param {!Array<!TraceEvent>} evts
+   */
+  _addEvents(evts) {
+    this.traceEvents.push(...evts);
+  }
+
+  /**
+   * Receive chunk of streamed trace
+   * @param {string} data
+   */
+  parseChunk(data) {
+    this.loader.write(data);
+  }
+
+  /**
+   * Returns entire trace
+   * @return {{traceEvents: !Array<!TraceEvent>}}
+   */
+  getTrace() {
+    return {
+      traceEvents: this.traceEvents
+    };
+  }
+}
+
+module.exports = TraceParser;
diff --git a/lighthouse-core/lib/web-inspector.js b/lighthouse-core/lib/web-inspector.js
@@ -176,6 +176,11 @@ module.exports = (function() {
   require('chrome-devtools-frontend/front_end/timeline_model/TimelineModel.js');
   require('chrome-devtools-frontend/front_end/ui_lazy/SortableDataGrid.js');
   require('chrome-devtools-frontend/front_end/timeline/TimelineTreeView.js');
+
+  // used for streaming json parsing
+  require('chrome-devtools-frontend/front_end/common/TextUtils.js');
+  require('chrome-devtools-frontend/front_end/timeline/TimelineLoader.js');
+
   require('chrome-devtools-frontend/front_end/timeline_model/TimelineProfileTree.js');
   require('chrome-devtools-frontend/front_end/components_lazy/FilmStripModel.js');
   require('chrome-devtools-frontend/front_end/timeline_model/TimelineIRModel.js');
diff --git a/lighthouse-core/test/lib/asset-saver-test.js b/lighthouse-core/test/lib/asset-saver-test.js
@@ -15,6 +15,7 @@ const traceEvents = require('../fixtures/traces/progressive-app.json');
 const dbwTrace = require('../fixtures/traces/dbw_tester.json');
 const dbwResults = require('../fixtures/dbw_tester-perf-results.json');
 const Audit = require('../../audits/audit.js');
+const fullTraceObj = require('../fixtures/traces/progressive-app-m60.json');
 
 /* eslint-env mocha */
 describe('asset-saver helper', () => {
@@ -34,24 +35,26 @@ describe('asset-saver helper', () => {
   });
 
   describe('saves files', function() {
-    const artifacts = {
-      devtoolsLogs: {
-        [Audit.DEFAULT_PASS]: [{message: 'first'}, {message: 'second'}]
-      },
-      traces: {
-        [Audit.DEFAULT_PASS]: {
-          traceEvents
-        }
-      },
-      requestScreenshots: () => Promise.resolve(screenshotFilmstrip)
-    };
+    before(() => {
+      const artifacts = {
+        devtoolsLogs: {
+          [Audit.DEFAULT_PASS]: [{message: 'first'}, {message: 'second'}]
+        },
+        traces: {
+          [Audit.DEFAULT_PASS]: {
+            traceEvents
+          }
+        },
+        requestScreenshots: () => Promise.resolve(screenshotFilmstrip)
+      };
 
-    assetSaver.saveAssets(artifacts, dbwResults.audits, process.cwd() + '/the_file');
+      return assetSaver.saveAssets(artifacts, dbwResults.audits, process.cwd() + '/the_file');
+    });
 
-    it('trace file saved to disk with data', () => {
+    it('trace file saved to disk with only trace events', () => {
       const traceFilename = 'the_file-0.trace.json';
       const traceFileContents = fs.readFileSync(traceFilename, 'utf8');
-      assert.ok(traceFileContents.length > 3000000);
+      assert.deepStrictEqual(JSON.parse(traceFileContents), {traceEvents});
       fs.unlinkSync(traceFilename);
     });
 
@@ -97,4 +100,81 @@ describe('asset-saver helper', () => {
       });
     });
   });
+
+  describe('saveTrace', () => {
+    const traceFilename = 'test-trace-0.json';
+
+    afterEach(() => {
+      fs.unlinkSync(traceFilename);
+    });
+
+    it('correctly saves a trace with metadata to disk', () => {
+      return assetSaver.saveTrace(fullTraceObj, traceFilename)
+        .then(_ => {
+          const traceFileContents = fs.readFileSync(traceFilename, 'utf8');
+          assert.deepStrictEqual(JSON.parse(traceFileContents), fullTraceObj);
+        });
+    });
+
+    it('correctly saves a trace with no trace events to disk', () => {
+      const trace = {
+        traceEvents: [],
+        metadata: {
+          'clock-domain': 'MAC_MACH_ABSOLUTE_TIME',
+          'cpu-family': 6,
+          'cpu-model': 70,
+          'cpu-stepping': 1,
+          'field-trials': [],
+        }
+      };
+
+      return assetSaver.saveTrace(trace, traceFilename)
+        .then(_ => {
+          const traceFileContents = fs.readFileSync(traceFilename, 'utf8');
+          assert.deepStrictEqual(JSON.parse(traceFileContents), trace);
+        });
+    });
+
+    it('correctly saves a trace with multiple extra properties to disk', () => {
+      const trace = {
+        traceEvents,
+        metadata: fullTraceObj.metadata,
+        someProp: 555,
+        anotherProp: {
+          unlikely: {
+            nested: [
+              'value'
+            ]
+          }
+        },
+      };
+
+      return assetSaver.saveTrace(trace, traceFilename)
+        .then(_ => {
+          const traceFileContents = fs.readFileSync(traceFilename, 'utf8');
+          assert.deepStrictEqual(JSON.parse(traceFileContents), trace);
+        });
+    });
+
+    it('can save traces over 256MB (slow)', () => {
+      // Create a trace that wil be longer than 256MB when stringified, the hard
+      // limit of a string in v8.
+      // https://mobile.twitter.com/bmeurer/status/879276976523157505
+      const baseEventsLength = JSON.stringify(traceEvents).length;
+      const countNeeded = Math.ceil(Math.pow(2, 28) / baseEventsLength);
+      let longTraceEvents = [];
+      for (let i = 0; i < countNeeded; i++) {
+        longTraceEvents = longTraceEvents.concat(traceEvents);
+      }
+      const trace = {
+        traceEvents: longTraceEvents
+      };
+
+      return assetSaver.saveTrace(trace, traceFilename)
+        .then(_ => {
+          const fileStats = fs.lstatSync(traceFilename);
+          assert.ok(fileStats.size > Math.pow(2, 28));
+        });
+    });
+  });
 });
diff --git a/lighthouse-core/test/lib/traces/trace-parser-test.js b/lighthouse-core/test/lib/traces/trace-parser-test.js
