Gatherer for critical request chains

scripts/netdep_graph_json.py

@@ -46,6 +46,7 @@ def main():
   with open('clovis-trace.log') as f:
     graph = get_network_dependency_graph(json.load(f))
 
+
   output_file = "dependency-graph.json"
   with open(output_file, 'w') as f:
     json.dump(graph.deps_graph.ToJsonDict(), f)

scripts/process_artifacts.py

@@ -35,18 +35,25 @@ def create_tracing_track(trace_events):
             or event['cat'] == '__metadata']}
 
 def create_page_track(frame_load_events):
-  events = [{'frame_id': e['frameId'], 'method': e['method']}
-            for e in frame_load_events]
+  events = []
+  for event in frame_load_events:
+    clovis_event = {
+      'frame_id': event['frameId'],
+      'method': event['method'],
+      'parent_frame_id': event.get('parentFrameId', None)
+    }
+    events.append(clovis_event)
   return {'events': events}
 
 def create_request_track(raw_network_events):
   request_track = RequestTrack(None)
   for event in raw_network_events:
-    request_track.Handle(event['method'], event)
+    if event['method'] in RequestTrack._METHOD_TO_HANDLER:  # pylint: disable=protected-access
+      request_track.Handle(event['method'], event)
   return request_track.ToJsonDict()
 
 def main():
-  with open('artifacts.log', 'r') as f:
+  with open('clovisData.json', 'r') as f:
     artifacts = json.load(f)
 
   clovis_trace = {}

src/gatherers/critical-network-chains.js

@@ -0,0 +1,164 @@
+/**
+ * @license
+ * Copyright 2016 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 Gather = require('./gather');
+const childProcess = require('child_process');
+const fs = require('fs');
+const log = require('../lib/log.js');
+
+const flatten = arr => arr.reduce((a, b) => a.concat(b), []);
+const contains = (arr, elm) => arr.indexOf(elm) > -1;
+
+class Node {
+  get requestId() {
+    return this.request.requestId;
+  }
+  constructor(request, parent) {
+    this.children = [];
+    this.parent = parent;
+    this.request = request;
+  }
+
+  setParent(parentNode) {
+    this.parent = parentNode;
+  }
+
+  addChild(childNode) {
+    this.children.push(childNode);
+  }
+
+}
+
+class CriticalNetworkChains extends Gather {
+
+  get criticalPriorities() {
+    return ['VeryHigh', 'High', 'Medium'];
+  }
+
+  postProfiling(options, tracingData) {
+    const graph = this._getNetworkDependencyGraph(options.url, tracingData);
+    const chains = this.getCriticalChains(tracingData.networkRecords, graph);
+
+    // There logs are here so we can test this gatherer
+    // Will be removed when we have a way to surface them in the report
+    const nonTrivialChains = chains.filter(chain => chain.length > 1);
+
+    // Note: Approximately,
+    // startTime: time when request was dispatched
+    // responseReceivedTime: either time to first byte, or time of receiving
+    //  the end of response headers
+    // endTime: time when response loading finished
+    const debuggingData = nonTrivialChains.map(chain => ({
+      urls: chain.map(request => request._url),
+      totalRequests: chain.length,
+      times: chain.map(request => ({
+        startTime: request.startTime,
+        endTime: request.endTime,
+        responseReceivedTime: request.responseReceivedTime
+      })),
+      totalTimeBetweenBeginAndEnd:
+        (chain[chain.length - 1].endTime - chain[0].startTime),
+      totalLoadingTime: chain.reduce((acc, req) =>
+        acc + (req.endTime - req.responseReceivedTime), 0)
+    }));
+    log.log('info', 'cricitalChains', JSON.stringify(debuggingData));
+    return {CriticalNetworkChains: chains};
+  }
+
+  getCriticalChains(networkRecords, graph) {
+    // TODO: Should we also throw out requests after DOMContentLoaded?
+    const criticalRequests = networkRecords.filter(
+      req => contains(this.criticalPriorities, req._initialPriority));
+
+    // Build a map of requestID -> Node.
+    const requestIdToNodes = new Map();
+    for (let request of criticalRequests) {
+      const requestNode = new Node(request, null);
+      requestIdToNodes.set(requestNode.requestId, requestNode);
+    }
+
+    // Connect the parents and children.
+    for (let edge of graph.edges) {
+      const fromNode = graph.nodes[edge.__from_node_index];
+      const toNode = graph.nodes[edge.__to_node_index];
+      const fromRequestId = fromNode.request.request_id;
+      const toRequestId = toNode.request.request_id;
+
+      if (requestIdToNodes.has(fromRequestId) &&
+          requestIdToNodes.has(toRequestId)) {
+        const fromRequestNode = requestIdToNodes.get(fromRequestId);
+        const toRequestNode = requestIdToNodes.get(toRequestId);
+
+        fromRequestNode.addChild(toRequestNode);
+        toRequestNode.setParent(fromRequestNode);
+      }
+    }
+
+    const nodesList = [...requestIdToNodes.values()];
+    const orphanNodes = nodesList.filter(node => node.parent === null);
+    const nodeChains = flatten(orphanNodes.map(
+      node => this._getChainsDFS(node)));
+    const requestChains = nodeChains.map(chain => chain.map(
+      node => node.request));
+    return requestChains;
+  }
+
+  _getChainsDFS(startNode) {
+    if (startNode.children.length === 0) {
+      return [[startNode]];
+    }
+
+    const childrenChains = flatten(startNode.children.map(child =>
+      this._getChainsDFS(child)));
+    return childrenChains.map(chain => [startNode].concat(chain));
+  }
+
+  _saveClovisData(url, tracingData, filename) {
+    const clovisData = {
+      url: url,
+      traceContents: tracingData.traceContents,
+      frameLoadEvents: tracingData.frameLoadEvents,
+      rawNetworkEvents: tracingData.rawNetworkEvents
+    };
+    fs.writeFileSync(filename, JSON.stringify(clovisData));
+  }
+
+  _getNetworkDependencyGraph(url, tracingData) {
+    const clovisDataFilename = 'clovisData.json';
+    const clovisGraphFilename = 'dependency-graph.json';
+
+    // These will go away once we implement initiator graph ourselves
+    this._saveClovisData(url, tracingData, clovisDataFilename);
+    childProcess.execSync('python scripts/process_artifacts.py');
+    childProcess.execSync('python scripts/netdep_graph_json.py', {stdio: [0, 1, 2]});
+    const depGraphString = fs.readFileSync(clovisGraphFilename);
+
+    try {
+      fs.unlinkSync(clovisDataFilename);
+      fs.unlinkSync(clovisGraphFilename);
+    } catch (e) {
+      console.error(e);
+      // Should not halt lighthouse for a file delete error
+    }
+
+    return JSON.parse(depGraphString).graph;
+  }
+}
+
+module.exports = CriticalNetworkChains;

src/lib/drivers/driver.js

@@ -273,6 +273,7 @@ class DriverBase {
       this.on('Network.dataReceived', this._networkRecorder.onDataReceived);
       this.on('Network.loadingFinished', this._networkRecorder.onLoadingFinished);
       this.on('Network.loadingFailed', this._networkRecorder.onLoadingFailed);
+      this.on('Network.resourceChangedPriority', this._networkRecorder.onResourceChangedPriority);
 
       this.sendCommand('Network.enable').then(_ => {
         resolve();
@@ -288,6 +289,7 @@ class DriverBase {
       this.off('Network.dataReceived', this._networkRecorder.onDataReceived);
       this.off('Network.loadingFinished', this._networkRecorder.onLoadingFinished);
       this.off('Network.loadingFailed', this._networkRecorder.onLoadingFailed);
+      this.off('Network.resourceChangedPriority', this._networkRecorder.onResourceChangedPriority);
 
       resolve({
         networkRecords: this._networkRecords,

src/lib/frame-load-recorder.js

@@ -38,7 +38,10 @@ class FrameLoadRecorder {
   }
 
   onFrameAttached(data) {
-    this._events.push({frameId: data.frameId, method: 'Page.frameAttached'});
+    this._events.push({
+      frameId: data.frameId,
+      method: 'Page.frameAttached',
+      parentFrameId: data.parentFrameId});
   }
 
 }

src/lib/network-recorder.js

@@ -38,6 +38,7 @@ class NetworkRecorder {
     this.onDataReceived = this.onDataReceived.bind(this);
     this.onLoadingFinished = this.onLoadingFinished.bind(this);
     this.onLoadingFailed = this.onLoadingFailed.bind(this);
+    this.onResourceChangedPriority = this.onResourceChangedPriority.bind(this);
   }
 
   // There are a few differences between the debugging protocol naming and
@@ -86,6 +87,10 @@ class NetworkRecorder {
         data.timestamp, data.type, data.errorText, data.canceled,
         data.blockedReason);
   }
+
+  onResourceChangedPriority(data) {
+    this._rawEvents.push({method: 'Network.resourceChangedPriority', params: data});
+  }
 }
 
 module.exports = NetworkRecorder;

src/lighthouse.js

@@ -79,6 +79,11 @@ module.exports = function(driver, opts) {
 
   const gatherers = gathererClasses.map(G => new G());
 
+  if (opts.flags.useNetDepGraph) {
+    const CriticalChainClass = require('./gatherers/critical-network-chains');
+    gatherers.push(new CriticalChainClass());
+  }
+
   return Scheduler
       .run(gatherers, Object.assign({}, opts, {driver}))
       .then(artifacts => Auditor.audit(artifacts, audits))

src/scheduler.js

@@ -17,7 +17,6 @@
 'use strict';
 
 const fs = require('fs');
-
 const log = require('./lib/log.js');
 
 function loadPage(driver, gatherers, options) {
@@ -155,7 +154,7 @@ function run(gatherers, options) {
           {traceContents: tracingData.traceContents},
           {frameLoadEvents: tracingData.frameLoadEvents});
 
-      const artifacts = flattenArtifacts(unflattenedArtifacts);
+      let artifacts = flattenArtifacts(unflattenedArtifacts);
 
       if (options.flags.saveArtifacts) {
         saveArtifacts(artifacts);