cli(asset-saver): print one devtoolsLog event per line

lighthouse-cli/test/smokehouse/lighthouse-runners/bundle.js

@@ -14,7 +14,6 @@
 const ChromeLauncher = require('chrome-launcher');
 const ChromeProtocol = require('../../../../lighthouse-core/gather/connections/cri.js');
 
-// @ts-expect-error - `require` isn't on `global` in the node typedefs.
 const originalRequire = global.require;
 if (typeof globalThis === 'undefined') {
   // @ts-expect-error - exposing for loading of dt-bundle.
@@ -25,7 +24,6 @@ if (typeof globalThis === 'undefined') {
 // @ts-ignore - file exists if `yarn build-all` is run, but not used for types anyways.
 require('../../../../dist/lighthouse-dt-bundle.js'); // eslint-disable-line
 
-// @ts-expect-error - `require` isn't on `global` in the node typedefs.
 global.require = originalRequire;
 
 /** @type {import('../../../../lighthouse-core/index.js')} */

lighthouse-core/lib/asset-saver.js

@@ -9,13 +9,15 @@ const fs = require('fs');
 const path = require('path');
 const log = require('lighthouse-logger');
 const stream = require('stream');
+const {promisify} = require('util');
 const Simulator = require('./dependency-graph/simulator/simulator.js');
 const lanternTraceSaver = require('./lantern-trace-saver.js');
 const Metrics = require('./traces/pwmetrics-events.js');
 const rimraf = require('rimraf');
 const NetworkAnalysisComputed = require('../computed/network-analysis.js');
 const LoadSimulatorComputed = require('../computed/load-simulator.js');
 const LHError = require('../lib/lh-error.js');
+const pipeline = promisify(stream.pipeline);
 
 const artifactsFilename = 'artifacts.json';
 const traceSuffix = '.trace.json';
@@ -112,8 +114,7 @@ async function saveArtifacts(artifacts, basePath) {
 
   // save devtools log
   for (const [passName, devtoolsLog] of Object.entries(devtoolsLogs)) {
-    const log = JSON.stringify(devtoolsLog);
-    fs.writeFileSync(`${basePath}/${passName}${devtoolsLogSuffix}`, log, 'utf8');
+    await saveDevtoolsLog(devtoolsLog, `${basePath}/${passName}${devtoolsLogSuffix}`);
   }
 
   // save everything else, using a replacer to serialize LHErrors in the artifacts.
@@ -164,47 +165,55 @@ async function prepareAssets(artifacts, audits) {
 }
 
 /**
- * Generates a JSON representation of traceData line-by-line for a nicer printed
- * version with one trace event per line.
- * @param {LH.Trace} traceData
+ * Generates a JSON representation of an array of objects with the objects
+ * printed one per line for a more readable (but not too verbose) version.
+ * @param {Array<unknown>} arrayOfObjects
  * @return {IterableIterator<string>}
  */
-function* traceJsonGenerator(traceData) {
-  const EVENTS_PER_ITERATION = 500;
-  const keys = Object.keys(traceData);
+function* arrayOfObjectsJsonGenerator(arrayOfObjects) {
+  const ITEMS_PER_ITERATION = 500;
 
-  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]();
+  // Stringify and emit items separately to avoid a giant string in memory.
+  yield '[\n';
+  if (arrayOfObjects.length > 0) {
+    const itemsIterator = arrayOfObjects[Symbol.iterator]();
     // Emit first item manually to avoid a trailing comma.
-    const firstEvent = eventsIterator.next().value;
-    yield `  ${JSON.stringify(firstEvent)}`;
-
-    let eventsRemaining = EVENTS_PER_ITERATION;
-    let eventsJSON = '';
-    for (const event of eventsIterator) {
-      eventsJSON += `,\n  ${JSON.stringify(event)}`;
-      eventsRemaining--;
-      if (eventsRemaining === 0) {
-        yield eventsJSON;
-        eventsRemaining = EVENTS_PER_ITERATION;
-        eventsJSON = '';
+    const firstItem = itemsIterator.next().value;
+    yield `  ${JSON.stringify(firstItem)}`;
+
+    let itemsRemaining = ITEMS_PER_ITERATION;
+    let itemsJSON = '';
+    for (const item of itemsIterator) {
+      itemsJSON += `,\n  ${JSON.stringify(item)}`;
+      itemsRemaining--;
+      if (itemsRemaining === 0) {
+        yield itemsJSON;
+        itemsRemaining = ITEMS_PER_ITERATION;
+        itemsJSON = '';
       }
     }
-    yield eventsJSON;
+    yield itemsJSON;
   }
   yield '\n]';
+}
+
+/**
+ * Generates a JSON representation of traceData line-by-line for a nicer printed
+ * version with one trace event per line.
+ * @param {LH.Trace} traceData
+ * @return {IterableIterator<string>}
+ */
+function* traceJsonGenerator(traceData) {
+  const {traceEvents, ...rest} = traceData;
 
-  // Emit the rest of the object (usually just `metadata`)
-  if (keys.length > 1) {
-    for (const key of keys) {
-      if (key === 'traceEvents') continue;
+  yield '{\n';
 
-      yield `,\n"${key}": ${JSON.stringify(traceData[key], null, 2)}`;
-    }
+  yield '"traceEvents": ';
+  yield* arrayOfObjectsJsonGenerator(traceEvents);
+
+  // Emit the rest of the object (usually just `metadata`, if anything).
+  for (const [key, value] of Object.entries(rest)) {
+    yield `,\n"${key}": ${JSON.stringify(value, null, 2)}`;
   }
 
   yield '}\n';
@@ -216,24 +225,26 @@ function* traceJsonGenerator(traceData) {
  * @param {string} traceFilename
  * @return {Promise<void>}
  */
-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);
-      },
-    });
+async function saveTrace(traceData, traceFilename) {
+  const traceIter = traceJsonGenerator(traceData);
+  const writeStream = fs.createWriteStream(traceFilename);
 
-    const writeStream = fs.createWriteStream(traceFilename);
-    writeStream.on('finish', resolve);
-    writeStream.on('error', reject);
+  // TODO: Can remove Readable.from() in Node 13, promisify(pipeline) in Node 15.
+  // https://nodejs.org/api/stream.html#stream_stream_pipeline_streams_callback
+  return pipeline(stream.Readable.from(traceIter), writeStream);
+}
 
-    traceStream.pipe(writeStream);
-  });
+/**
+ * Save a devtoolsLog as JSON by streaming to disk at devtoolLogFilename.
+ * @param {LH.DevtoolsLog} devtoolsLog
+ * @param {string} devtoolLogFilename
+ * @return {Promise<void>}
+ */
+function saveDevtoolsLog(devtoolsLog, devtoolLogFilename) {
+  const logIter = arrayOfObjectsJsonGenerator(devtoolsLog);
+  const writeStream = fs.createWriteStream(devtoolLogFilename);
+
+  return pipeline(stream.Readable.from(logIter), writeStream);
 }
 
 /**
@@ -298,6 +309,7 @@ module.exports = {
   saveAssets,
   prepareAssets,
   saveTrace,
+  saveDevtoolsLog,
   saveLanternNetworkData,
   stringifyReplacer,
 };

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

@@ -89,14 +89,37 @@ describe('asset-saver helper', () => {
       fs.unlinkSync(traceFilename);
     });
 
+    it('prints traces with an event per line', async () => {
+      const trace = {
+        traceEvents: [
+          {args: {}, cat: 'devtools.timeline', pid: 1, ts: 2},
+          {args: {}, cat: 'v8', pid: 1, ts: 3},
+          {args: {IsMainFrame: true}, cat: 'v8', pid: 1, ts: 5},
+          {args: {data: {encodedDataLength: 20, requestId: '1.22'}}, pid: 1, ts: 6},
+        ],
+      };
+      await assetSaver.saveTrace(trace, traceFilename);
+
+      const traceFileContents = fs.readFileSync(traceFilename, 'utf8');
+      expect(traceFileContents).toEqual(
+`{
+"traceEvents": [
+  {"args":{},"cat":"devtools.timeline","pid":1,"ts":2},
+  {"args":{},"cat":"v8","pid":1,"ts":3},
+  {"args":{"IsMainFrame":true},"cat":"v8","pid":1,"ts":5},
+  {"args":{"data":{"encodedDataLength":20,"requestId":"1.22"}},"pid":1,"ts":6}
+]}
+`);
+    });
+
     it('correctly saves a trace with metadata to disk', () => {
       return assetSaver.saveTrace(fullTraceObj, traceFilename)
         .then(_ => {
           const traceFileContents = fs.readFileSync(traceFilename, 'utf8');
           const traceEventsFromDisk = JSON.parse(traceFileContents).traceEvents;
           assertTraceEventsEqual(traceEventsFromDisk, fullTraceObj.traceEvents);
         });
-    }, 10000);
+    });
 
     it('correctly saves a trace with no trace events to disk', () => {
       const trace = {
@@ -161,6 +184,29 @@ describe('asset-saver helper', () => {
     }, 40 * 1000);
   });
 
+  describe('saveDevtoolsLog', () => {
+    const devtoolsLogFilename = 'test-devtoolslog-0.json';
+
+    afterEach(() => {
+      fs.unlinkSync(devtoolsLogFilename);
+    });
+
+    it('prints devtoolsLogs with an event per line', async () => {
+      const devtoolsLog = [
+        {method: 'Network.requestServedFromCache', params: {requestId: '1.22'}},
+        {method: 'Network.responseReceived', params: {status: 301, headers: {':method': 'POST'}}},
+      ];
+      await assetSaver.saveDevtoolsLog(devtoolsLog, devtoolsLogFilename);
+
+      const devtoolsLogFileContents = fs.readFileSync(devtoolsLogFilename, 'utf8');
+      expect(devtoolsLogFileContents).toEqual(
+`[
+  {"method":"Network.requestServedFromCache","params":{"requestId":"1.22"}},
+  {"method":"Network.responseReceived","params":{"status":301,"headers":{":method":"POST"}}}
+]`);
+    });
+  });
+
   describe('loadArtifacts', () => {
     it('loads artifacts from disk', async () => {
       const artifactsPath = __dirname + '/../fixtures/artifacts/perflog/';

package.json

@@ -119,7 +119,7 @@
     "@wardpeet/brfs": "2.1.0",
     "angular": "^1.7.4",
     "archiver": "^3.0.0",
-    "browserify": "^16.2.3",
+    "browserify": "^17.0.0",
     "browserify-banner": "^1.0.15",
     "bundle-phobia-cli": "^0.14.6",
     "c8": "^7.4.0",