From 6e90985c4fad7f2a5dcb6ada6ff7c35ca2c386c0 Mon Sep 17 00:00:00 2001 From: Patrick Hulce Date: Sun, 20 Aug 2017 17:36:10 -0700 Subject: [PATCH] feat(predictive-perf): add CPU estimation --- lighthouse-core/audits/predictive-perf.js | 46 +++- .../computed/dependency-graph/cpu-node.js | 71 ++++++ .../dependency-graph/estimator/estimator.js | 194 ++++++++++++----- .../computed/dependency-graph/network-node.js | 15 ++ .../gather/computed/dependency-graph/node.js | 23 +- .../gather/computed/page-dependency-graph.js | 203 ++++++++++++++++-- .../lib/traces/tracing-processor.js | 2 + .../test/audits/predictive-perf-test.js | 15 +- .../estimator/estimator-test.js | 96 +++++++-- .../computed/page-dependency-graph-test.js | 139 +++++++++++- 10 files changed, 688 insertions(+), 116 deletions(-) create mode 100644 lighthouse-core/gather/computed/dependency-graph/cpu-node.js diff --git a/lighthouse-core/audits/predictive-perf.js b/lighthouse-core/audits/predictive-perf.js index f19b50a880b9..707a1a7e1b17 100644 --- a/lighthouse-core/audits/predictive-perf.js +++ b/lighthouse-core/audits/predictive-perf.js @@ -15,6 +15,9 @@ const Node = require('../gather/computed/dependency-graph/node.js'); const SCORING_POINT_OF_DIMINISHING_RETURNS = 1700; const SCORING_MEDIAN = 10000; +// Any CPU task of 20 ms or more will end up being a critical long task on mobile +const CRITICAL_LONG_TASK_THRESHOLD = 20000; + class PredictivePerf extends Audit { /** * @return {!AuditMeta} @@ -38,8 +41,7 @@ class PredictivePerf extends Audit { const fmp = traceOfTab.timestamps.firstMeaningfulPaint; return graph.cloneWithRelationships(node => { if (node.endTime > fmp) return false; - if (node.type !== Node.TYPES.NETWORK) return true; - return node.record.priority() === 'VeryHigh'; // proxy for render-blocking + return node.isRenderBlocking(); }); } @@ -51,7 +53,11 @@ class PredictivePerf extends Audit { static getPessimisticFMPGraph(graph, traceOfTab) { const fmp = traceOfTab.timestamps.firstMeaningfulPaint; return graph.cloneWithRelationships(node => { - return node.endTime <= fmp; + if (node.endTime > fmp) return false; + // Include CPU tasks that performed a layout + if (node.type === Node.TYPES.CPU) return node.didPerformLayout(); + // Include every request before FMP that wasn't an image + return node.resourceType !== 'image'; }); } @@ -61,7 +67,10 @@ class PredictivePerf extends Audit { */ static getOptimisticTTCIGraph(graph) { return graph.cloneWithRelationships(node => { - return node.record._resourceType && node.record._resourceType._name === 'script' || + // Include everything that might be a long task + if (node.type === Node.TYPES.CPU) return node.event.dur > CRITICAL_LONG_TASK_THRESHOLD; + // Include all scripts and high priority requests + return node.resourceType === 'script' || node.record.priority() === 'High' || node.record.priority() === 'VeryHigh'; }); @@ -75,6 +84,18 @@ class PredictivePerf extends Audit { return graph; } + /** + * @param {!Map} nodeAuxData + * @return {number} + */ + static getLastLongTaskEndTime(nodeAuxData) { + return Array.from(nodeAuxData.entries()) + .filter(([node, auxData]) => node.type === Node.TYPES.CPU && + auxData.endTime - auxData.startTime > 50) + .map(([_, auxData]) => auxData.endTime) + .reduce((max, x) => Math.max(max, x), 0); + } + /** * @param {!Artifacts} artifacts * @return {!AuditResult} @@ -96,7 +117,22 @@ class PredictivePerf extends Audit { let sum = 0; const values = {}; Object.keys(graphs).forEach(key => { - values[key] = PageDependencyGraph.computeGraphDuration(graphs[key]); + const estimate = PageDependencyGraph.estimateGraph(graphs[key]); + const lastLongTaskEnd = PredictivePerf.getLastLongTaskEndTime(estimate.nodeAuxiliaryData); + + switch (key) { + case 'optimisticFMP': + case 'pessimisticFMP': + values[key] = estimate.timeInMs; + break; + case 'optimisticTTCI': + values[key] = Math.max(values.optimisticFMP, lastLongTaskEnd); + break; + case 'pessimisticTTCI': + values[key] = Math.max(values.pessimisticFMP, lastLongTaskEnd); + break; + } + sum += values[key]; }); diff --git a/lighthouse-core/gather/computed/dependency-graph/cpu-node.js b/lighthouse-core/gather/computed/dependency-graph/cpu-node.js new file mode 100644 index 000000000000..b7fc846f4401 --- /dev/null +++ b/lighthouse-core/gather/computed/dependency-graph/cpu-node.js @@ -0,0 +1,71 @@ +/** + * @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 Node = require('./node'); + +class CPUNode extends Node { + /** + * @param {!TraceEvent} parentEvent + * @param {!Array=} children + */ + constructor(parentEvent, children = []) { + super(`${parentEvent.tid}.${parentEvent.ts}`); + this._event = parentEvent; + this._children = children; + } + + /** + * @return {string} + */ + get type() { + return Node.TYPES.CPU; + } + + /** + * @return {number} + */ + get startTime() { + return this._event.ts; + } + + /** + * @return {number} + */ + get endTime() { + return this._event.ts + this._event.dur; + } + + /** + * @return {!TraceEvent} + */ + get event() { + return this._event; + } + + /** + * @return {!TraceEvent} + */ + get children() { + return this._children; + } + + /** + * @return {boolean} + */ + didPerformLayout() { + return this._children.some(evt => evt.name === 'Layout'); + } + + /** + * @return {!CPUNode} + */ + cloneWithoutRelationships() { + return new CPUNode(this._event, this._children); + } +} + +module.exports = CPUNode; diff --git a/lighthouse-core/gather/computed/dependency-graph/estimator/estimator.js b/lighthouse-core/gather/computed/dependency-graph/estimator/estimator.js index 6a52b92113a3..e5c96d33121c 100644 --- a/lighthouse-core/gather/computed/dependency-graph/estimator/estimator.js +++ b/lighthouse-core/gather/computed/dependency-graph/estimator/estimator.js @@ -13,6 +13,7 @@ const DEFAULT_MAXIMUM_CONCURRENT_REQUESTS = 10; const DEFAULT_RESPONSE_TIME = 30; const DEFAULT_RTT = 150; const DEFAULT_THROUGHPUT = 1600 * 1024; // 1.6 Mbps +const DEFAULT_CPU_MULTIPLIER = 5; function groupBy(items, keyFunc) { const grouped = new Map(); @@ -40,6 +41,7 @@ class Estimator { throughput: DEFAULT_THROUGHPUT, defaultResponseTime: DEFAULT_RESPONSE_TIME, maximumConcurrentRequests: DEFAULT_MAXIMUM_CONCURRENT_REQUESTS, + cpuMultiplier: DEFAULT_CPU_MULTIPLIER, }, options ); @@ -51,6 +53,7 @@ class Estimator { TcpConnection.maximumSaturatedConnections(this._rtt, this._throughput), this._options.maximumConcurrentRequests ); + this._cpuMultiplier = this._options.cpuMultiplier; } /** @@ -77,10 +80,7 @@ class Estimator { _initializeNetworkConnections() { const connections = new Map(); - const recordsByConnection = groupBy( - this._networkRecords, - record => record.connectionId - ); + const recordsByConnection = groupBy(this._networkRecords, record => record.connectionId); for (const [connectionId, records] of recordsByConnection.entries()) { const isSsl = records[0].parsedURL.scheme === 'https'; @@ -93,12 +93,7 @@ class Estimator { responseTime = this._defaultResponseTime; } - const connection = new TcpConnection( - this._rtt, - this._throughput, - responseTime, - isSsl - ); + const connection = new TcpConnection(this._rtt, this._throughput, responseTime, isSsl); connections.set(connectionId, connection); } @@ -109,22 +104,74 @@ class Estimator { _initializeAuxiliaryData() { this._nodeAuxiliaryData = new Map(); + this._nodesUnprocessed = new Set(); this._nodesCompleted = new Set(); this._nodesInProcess = new Set(); this._nodesInQueue = new Set(); // TODO: replace this with priority queue this._connectionsInUse = new Set(); + this._numberInProcessByType = new Map(); + } + + /** + * @param {string} type + * @return {number} + */ + _numberInProcess(type) { + return this._numberInProcessByType.get(type) || 0; } /** * @param {!Node} node + * @param {!Object} values */ - _enqueueNodeIfPossible(node) { - const dependencies = node.getDependencies(); - if ( - !this._nodesCompleted.has(node) && - dependencies.every(dependency => this._nodesCompleted.has(dependency)) - ) { - this._nodesInQueue.add(node); + _setAuxData(node, values) { + const auxData = this._nodeAuxiliaryData.get(node) || {}; + Object.assign(auxData, values); + this._nodeAuxiliaryData.set(node, auxData); + } + + /** + * @param {!Node} node + * @param {number} queuedTime + */ + _markNodeAsInQueue(node, queuedTime) { + this._nodesInQueue.add(node); + this._nodesUnprocessed.delete(node); + this._setAuxData(node, {queuedTime}); + } + + /** + * @param {!Node} node + * @param {number} startTime + */ + _markNodeAsInProcess(node, startTime) { + this._nodesInQueue.delete(node); + this._nodesInProcess.add(node); + this._numberInProcessByType.set(node.type, this._numberInProcess(node.type) + 1); + this._setAuxData(node, {startTime}); + } + + /** + * @param {!Node} node + * @param {number} endTime + */ + _markNodeAsComplete(node, endTime) { + this._nodesCompleted.add(node); + this._nodesInProcess.delete(node); + this._numberInProcessByType.set(node.type, this._numberInProcess(node.type) - 1); + this._setAuxData(node, {endTime}); + + // Try to add all its dependents to the queue + for (const dependent of node.getDependents()) { + // Skip this node if it's already been completed + if (this._nodesCompleted.has(dependent)) continue; + + // Skip this node if one of its dependencies hasn't finished yet + const dependencies = dependent.getDependencies(); + if (dependencies.some(dependency => !this._nodesCompleted.has(dependency))) continue; + + // Otherwise add it to the queue + this._markNodeAsInQueue(dependent, endTime); } } @@ -133,21 +180,31 @@ class Estimator { * @param {number} totalElapsedTime */ _startNodeIfPossible(node, totalElapsedTime) { - if (node.type !== Node.TYPES.NETWORK) return; + if (node.type === Node.TYPES.CPU) { + // Start a CPU task if there's no other CPU task in process + if (this._numberInProcess(node.type) === 0) { + this._markNodeAsInProcess(node, totalElapsedTime); + this._setAuxData(node, {timeElapsed: 0}); + } + + return; + } + + if (node.type !== Node.TYPES.NETWORK) throw new Error('Unsupported'); const connection = this._connections.get(node.record.connectionId); + const numberOfActiveRequests = this._numberInProcess(node.type); + // Start a network request if the connection isn't in use and we're not at max requests if ( - this._nodesInProcess.size >= this._maximumConcurrentRequests || + numberOfActiveRequests >= this._maximumConcurrentRequests || this._connectionsInUse.has(connection) ) { return; } - this._nodesInQueue.delete(node); - this._nodesInProcess.add(node); - this._nodeAuxiliaryData.set(node, { - startTime: totalElapsedTime, + this._markNodeAsInProcess(node, totalElapsedTime); + this._setAuxData(node, { timeElapsed: 0, timeElapsedOvershoot: 0, bytesDownloaded: 0, @@ -167,18 +224,26 @@ class Estimator { * @return {number} */ _estimateTimeRemaining(node) { + if (node.type === Node.TYPES.CPU) { + const auxData = this._nodeAuxiliaryData.get(node); + const totalDuration = Math.round(node.event.dur / 1000 * this._cpuMultiplier); + const estimatedTimeElapsed = totalDuration - auxData.timeElapsed; + this._setAuxData(node, {estimatedTimeElapsed}); + return estimatedTimeElapsed; + } + if (node.type !== Node.TYPES.NETWORK) throw new Error('Unsupported'); - const auxiliaryData = this._nodeAuxiliaryData.get(node); + const auxData = this._nodeAuxiliaryData.get(node); const connection = this._connections.get(node.record.connectionId); const calculation = connection.calculateTimeToDownload( - node.record.transferSize - auxiliaryData.bytesDownloaded, - auxiliaryData.timeElapsed + node.record.transferSize - auxData.bytesDownloaded, + auxData.timeElapsed ); - const estimate = calculation.timeElapsed + auxiliaryData.timeElapsedOvershoot; - auxiliaryData.estimatedTimeElapsed = estimate; - return estimate; + const estimatedTimeElapsed = calculation.timeElapsed + auxData.timeElapsedOvershoot; + this._setAuxData(node, {estimatedTimeElapsed}); + return estimatedTimeElapsed; } /** @@ -199,55 +264,60 @@ class Estimator { * @param {number} totalElapsedTime */ _updateProgressMadeInTimePeriod(node, timePeriodLength, totalElapsedTime) { + const auxData = this._nodeAuxiliaryData.get(node); + const isFinished = auxData.estimatedTimeElapsed === timePeriodLength; + + if (node.type === Node.TYPES.CPU) { + return isFinished + ? this._markNodeAsComplete(node, totalElapsedTime) + : (auxData.timeElapsed += timePeriodLength); + } + if (node.type !== Node.TYPES.NETWORK) throw new Error('Unsupported'); - const auxiliaryData = this._nodeAuxiliaryData.get(node); const connection = this._connections.get(node.record.connectionId); const calculation = connection.calculateTimeToDownload( - node.record.transferSize - auxiliaryData.bytesDownloaded, - auxiliaryData.timeElapsed, - timePeriodLength - auxiliaryData.timeElapsedOvershoot + node.record.transferSize - auxData.bytesDownloaded, + auxData.timeElapsed, + timePeriodLength - auxData.timeElapsedOvershoot ); connection.setCongestionWindow(calculation.congestionWindow); - if (auxiliaryData.estimatedTimeElapsed === timePeriodLength) { - auxiliaryData.endTime = totalElapsedTime; - + if (isFinished) { connection.setWarmed(true); this._connectionsInUse.delete(connection); - - this._nodesCompleted.add(node); - this._nodesInProcess.delete(node); - - for (const dependent of node.getDependents()) { - this._enqueueNodeIfPossible(dependent); - } + this._markNodeAsComplete(node, totalElapsedTime); } else { - auxiliaryData.timeElapsed += calculation.timeElapsed; - auxiliaryData.timeElapsedOvershoot += - calculation.timeElapsed - timePeriodLength; - auxiliaryData.bytesDownloaded += calculation.bytesDownloaded; + auxData.timeElapsed += calculation.timeElapsed; + auxData.timeElapsedOvershoot += calculation.timeElapsed - timePeriodLength; + auxData.bytesDownloaded += calculation.bytesDownloaded; } } /** - * @return {number} + * @return {{timeInMs: number, nodeAuxiliaryData: !Map}} */ - estimate() { + estimateWithDetails() { // initialize all the necessary data containers this._initializeNetworkRecords(); this._initializeNetworkConnections(); this._initializeAuxiliaryData(); + const nodesUnprocessed = this._nodesUnprocessed; const nodesInQueue = this._nodesInQueue; const nodesInProcess = this._nodesInProcess; - // add root node to queue - nodesInQueue.add(this._graph.getRootNode()); + const rootNode = this._graph.getRootNode(); + rootNode.traverse(node => nodesUnprocessed.add(node)); let depth = 0; let totalElapsedTime = 0; + + // add root node to queue + this._markNodeAsInQueue(rootNode, totalElapsedTime); + + // loop as long as we have nodes in the queue or currently in process while (nodesInQueue.size || nodesInProcess.size) { depth++; @@ -265,11 +335,7 @@ class Estimator { // update how far each node will progress until that point for (const node of nodesInProcess) { - this._updateProgressMadeInTimePeriod( - node, - minimumTime, - totalElapsedTime - ); + this._updateProgressMadeInTimePeriod(node, minimumTime, totalElapsedTime); } if (depth > 10000) { @@ -277,7 +343,21 @@ class Estimator { } } - return totalElapsedTime; + if (nodesUnprocessed.size !== 0) { + throw new Error(`Cycle detected: ${nodesUnprocessed.size} unused nodes`); + } + + return { + timeInMs: totalElapsedTime, + nodeAuxiliaryData: this._nodeAuxiliaryData, + }; + } + + /** + * @return {number} + */ + estimate() { + return this.estimateWithDetails().timeInMs; } } diff --git a/lighthouse-core/gather/computed/dependency-graph/network-node.js b/lighthouse-core/gather/computed/dependency-graph/network-node.js index d5fc2ccf67ae..42b914ee4485 100644 --- a/lighthouse-core/gather/computed/dependency-graph/network-node.js +++ b/lighthouse-core/gather/computed/dependency-graph/network-node.js @@ -44,6 +44,21 @@ class NetworkNode extends Node { return this._record; } + /** + * @return {string} + */ + get resourceType() { + return this._record._resourceType && this._record._resourceType._name; + } + + /** + * @return {boolean} + */ + isRenderBlocking() { + const priority = this._record.priority(); + return priority === 'VeryHigh' || (priority === 'High' && this.resourceType === 'script'); + } + /** * @return {!NetworkNode} */ diff --git a/lighthouse-core/gather/computed/dependency-graph/node.js b/lighthouse-core/gather/computed/dependency-graph/node.js index 9d4497f26f73..d36f6f2b176d 100644 --- a/lighthouse-core/gather/computed/dependency-graph/node.js +++ b/lighthouse-core/gather/computed/dependency-graph/node.js @@ -43,6 +43,13 @@ class Node { throw new Error('Unimplemented'); } + /** + * @return {boolean} + */ + isRenderBlocking() { + return false; + } + /** * @return {!Array} */ @@ -50,7 +57,6 @@ class Node { return this._dependents.slice(); } - /** * @return {!Array} */ @@ -58,6 +64,12 @@ class Node { return this._dependencies.slice(); } + /** + * @return {number} + */ + getNumberOfDependencies() { + return this._dependencies.length; + } /** * @return {!Node} @@ -96,6 +108,14 @@ class Node { this._dependencies.push(node); } + /** + * @param {!Node} + * @return {boolean} + */ + hasDependency(node) { + return this._dependencies.includes(node); + } + /** * Clones the node's information without adding any dependencies/dependents. * @return {!Node} @@ -199,6 +219,7 @@ class Node { Node.TYPES = { UNKNOWN: 'unknown', NETWORK: 'network', + CPU: 'cpu', }; module.exports = Node; diff --git a/lighthouse-core/gather/computed/page-dependency-graph.js b/lighthouse-core/gather/computed/page-dependency-graph.js index 4398614c19d4..ddd153f4dfa7 100644 --- a/lighthouse-core/gather/computed/page-dependency-graph.js +++ b/lighthouse-core/gather/computed/page-dependency-graph.js @@ -7,7 +7,11 @@ const ComputedArtifact = require('./computed-artifact'); const NetworkNode = require('./dependency-graph/network-node'); +const CPUNode = require('./dependency-graph/cpu-node'); const GraphEstimator = require('./dependency-graph/estimator/estimator'); +const TracingProcessor = require('../../lib/traces/tracing-processor'); + +const MINIMUM_TASK_DURATION = 10 * 1000; class PageDependencyGraphArtifact extends ComputedArtifact { get name() { @@ -34,52 +38,202 @@ class PageDependencyGraphArtifact extends ComputedArtifact { } /** - * @param {!TraceOfTabArtifact} traceOfTab * @param {!Array} networkRecords - * @return {!Node} + * @return {!NetworkNodeOutput} */ - static createGraph(traceOfTab, networkRecords) { + static getNetworkNodes(networkRecords) { + const nodes = []; const idToNodeMap = new Map(); const urlToNodeMap = new Map(); networkRecords.forEach(record => { const node = new NetworkNode(record); + nodes.push(node); idToNodeMap.set(record.requestId, node); if (urlToNodeMap.has(record.url)) { - // If duplicate requests have been made to this URL we can't be certain which node is being - // referenced, so act like we don't know the URL at all. - urlToNodeMap.set(record.url, undefined); + const list = urlToNodeMap.get(record.url); + list.push(node); } else { - urlToNodeMap.set(record.url, node); + urlToNodeMap.set(record.url, [node]); } }); - const rootRequest = networkRecords - .reduce((min, next) => min.startTime < next.startTime ? min : next); - const rootNode = idToNodeMap.get(rootRequest.requestId); - networkRecords.forEach(record => { - const initiators = PageDependencyGraphArtifact.getNetworkInitiators(record); - const node = idToNodeMap.get(record.requestId); + return {nodes, idToNodeMap, urlToNodeMap}; + } + + /** + * @param {!TraceOfTabArtifact} traceOfTab + * @return {!Array} + */ + static getCPUNodes(traceOfTab) { + const nodes = []; + let i = 0; + while (i < traceOfTab.mainThreadEvents.length) { + const evt = traceOfTab.mainThreadEvents[i]; + + // Skip all trace events that aren't schedulable tasks with sizable duration + if ( + evt.name !== TracingProcessor.SCHEDULABLE_TASK_TITLE || + !evt.dur || + evt.dur < MINIMUM_TASK_DURATION + ) { + i++; + continue; + } + + // Capture all events that occurred within the task + const children = []; + i++; // Start examining events after this one + for ( + const endTime = evt.ts + evt.dur; + i < traceOfTab.mainThreadEvents.length && traceOfTab.mainThreadEvents[i].ts < endTime; + i++ + ) { + children.push(traceOfTab.mainThreadEvents[i]); + } + + nodes.push(new CPUNode(evt, children)); + } + + return nodes; + } + + /** + * @param {!Node} rootNode + * @param {!NetworkNodeOutput} networkNodeOutput + */ + static linkNetworkNodes(rootNode, networkNodeOutput) { + networkNodeOutput.nodes.forEach(node => { + const initiators = PageDependencyGraphArtifact.getNetworkInitiators(node.record); if (initiators.length) { initiators.forEach(initiator => { - const parent = urlToNodeMap.get(initiator) || rootNode; + const parentCandidates = networkNodeOutput.urlToNodeMap.get(initiator) || [rootNode]; + // Only add the initiator relationship if the initiator is unambiguous + const parent = parentCandidates.length === 1 ? parentCandidates[0] : rootNode; parent.addDependent(node); }); - } else if (record !== rootRequest) { + } else if (node !== rootNode) { rootNode.addDependent(node); } }); + } + + /** + * @param {!Node} rootNode + * @param {!NetworkNodeOutput} networkNodeOutput + * @param {!Array} cpuNodes + * @param {!TraceOfTabArtifact} traceOfTab + */ + static linkCPUNodes(rootNode, networkNodeOutput, cpuNodes) { + function addDependentNetworkRequest(cpuNode, reqId) { + const networkNode = networkNodeOutput.idToNodeMap.get(reqId); + if (!networkNode || networkNode.resourceType !== 'xhr') return; + networkNode.addDependency(cpuNode); + } + + function addDependencyOnUrl(cpuNode, url) { + const candidates = networkNodeOutput.urlToNodeMap.get(url) || []; + + let minCandidate = null; + let minDistance = Infinity; + // Find the closest request that finished before this CPU task started + candidates.forEach(candidate => { + const distance = cpuNode.startTime - candidate.endTime; + if (distance > 0 && distance < minDistance) { + minCandidate = candidate; + minDistance = distance; + } + }); + + if (!minCandidate) return; + cpuNode.addDependency(minCandidate); + } + + const timers = new Map(); + for (const node of cpuNodes) { + for (const evt of node.children) { + if (!evt.args.data) continue; + + const url = evt.args.data.url; + const stackTraceUrls = (evt.args.data.stackTrace || []).map(l => l.url).filter(Boolean); + + switch (evt.name) { + case 'TimerInstall': + timers.set(evt.args.data.timerId, node); + stackTraceUrls.forEach(url => addDependencyOnUrl(node, url)); + break; + case 'TimerFire': { + const installer = timers.get(evt.args.data.timerId); + if (!installer) break; + installer.addDependent(node); + break; + } + + case 'InvalidateLayout': + case 'ScheduleStyleRecalculation': + stackTraceUrls.forEach(url => addDependencyOnUrl(node, url)); + break; + + case 'EvaluateScript': + addDependencyOnUrl(node, url); + stackTraceUrls.forEach(url => addDependencyOnUrl(node, url)); + break; + + case 'XHRReadyStateChange': + // Only create the dependency if the request was completed + if (evt.args.data.readyState !== 4) break; + + addDependencyOnUrl(node, url); + stackTraceUrls.forEach(url => addDependencyOnUrl(node, url)); + break; + + case 'FunctionCall': + case 'v8.compile': + addDependencyOnUrl(node, url); + break; + + case 'ParseAuthorStyleSheet': + addDependencyOnUrl(node, evt.args.data.styleSheetUrl); + break; + + case 'ResourceSendRequest': + addDependentNetworkRequest(node, evt.args.data.requestId, evt); + stackTraceUrls.forEach(url => addDependencyOnUrl(node, url)); + break; + } + } + + if (node.getNumberOfDependencies() === 0) { + node.addDependency(rootNode); + } + } + } + + /** + * @param {!TraceOfTabArtifact} traceOfTab + * @param {!Array} networkRecords + * @return {!Node} + */ + static createGraph(traceOfTab, networkRecords) { + const networkNodeOutput = this.getNetworkNodes(networkRecords); + const cpuNodes = this.getCPUNodes(traceOfTab); + + const rootRequest = networkRecords.reduce((min, r) => (min.startTime < r.startTime ? min : r)); + const rootNode = networkNodeOutput.idToNodeMap.get(rootRequest.requestId); + + this.linkNetworkNodes(rootNode, networkNodeOutput, networkRecords); + this.linkCPUNodes(rootNode, networkNodeOutput, cpuNodes, traceOfTab); return rootNode; } /** * @param {!Node} rootNode - * @return {number} + * @return {} */ - static computeGraphDuration(rootNode) { - return new GraphEstimator(rootNode).estimate(); + static estimateGraph(rootNode) { + return new GraphEstimator(rootNode).estimateWithDetails(); } /** @@ -107,8 +261,10 @@ class PageDependencyGraphArtifact extends ComputedArtifact { const offset = Math.round((node.startTime - min) / timePerCharacter); const length = Math.ceil((node.endTime - node.startTime) / timePerCharacter); const bar = padRight('', offset) + padRight('', length, '='); + + const displayName = node.record ? node.record._url : node.type; // eslint-disable-next-line - console.log(padRight(bar, widthInCharacters), `| ${node.record._url.slice(0, 30)}`); + console.log(padRight(bar, widthInCharacters), `| ${displayName.slice(0, 30)}`); }); } @@ -131,3 +287,12 @@ class PageDependencyGraphArtifact extends ComputedArtifact { } module.exports = PageDependencyGraphArtifact; + +/** + * @typedef {{ + * nodes: !Array, + * idToNodeMap: !Map, + * urlToNodeMap: !Map + * }} + */ +PageDependencyGraphArtifact.NetworkNodeOutput; // eslint-disable-line no-unused-expressions diff --git a/lighthouse-core/lib/traces/tracing-processor.js b/lighthouse-core/lib/traces/tracing-processor.js index c945f8b387ad..78ca0f84cf81 100644 --- a/lighthouse-core/lib/traces/tracing-processor.js +++ b/lighthouse-core/lib/traces/tracing-processor.js @@ -168,4 +168,6 @@ class TraceProcessor { } } +TraceProcessor.SCHEDULABLE_TASK_TITLE = SCHEDULABLE_TASK_TITLE; + module.exports = TraceProcessor; diff --git a/lighthouse-core/test/audits/predictive-perf-test.js b/lighthouse-core/test/audits/predictive-perf-test.js index 2a4abac6ca0a..7c88058d70a6 100644 --- a/lighthouse-core/test/audits/predictive-perf-test.js +++ b/lighthouse-core/test/audits/predictive-perf-test.js @@ -12,7 +12,6 @@ const assert = require('assert'); const acceptableTrace = require('../fixtures/traces/progressive-app-m60.json'); const acceptableDevToolsLog = require('../fixtures/traces/progressive-app-m60.devtools.log.json'); - /* eslint-env mocha */ describe('Performance: predictive performance audit', () => { it('should compute the predicted values', () => { @@ -26,15 +25,15 @@ describe('Performance: predictive performance audit', () => { }, Runner.instantiateComputedArtifacts()); return PredictivePerf.audit(artifacts).then(output => { - assert.equal(output.score, 66); - assert.equal(Math.round(output.rawValue), 7226); - assert.equal(output.displayValue, '7,230\xa0ms'); + assert.equal(output.score, 95); + assert.equal(Math.round(output.rawValue), 2638); + assert.equal(output.displayValue, '2,640\xa0ms'); const valueOf = name => Math.round(output.extendedInfo.value[name]); - assert.equal(valueOf('optimisticFMP'), 1058); - assert.equal(valueOf('pessimisticFMP'), 4704); - assert.equal(valueOf('optimisticTTCI'), 4207); - assert.equal(valueOf('pessimisticTTCI'), 18935); + assert.equal(valueOf('optimisticFMP'), 1362); + assert.equal(valueOf('pessimisticFMP'), 2070); + assert.equal(valueOf('optimisticTTCI'), 3470); + assert.equal(valueOf('pessimisticTTCI'), 3649); }); }); }); diff --git a/lighthouse-core/test/gather/computed/dependency-graph/estimator/estimator-test.js b/lighthouse-core/test/gather/computed/dependency-graph/estimator/estimator-test.js index e68d30d99ffe..bab442d7403b 100644 --- a/lighthouse-core/test/gather/computed/dependency-graph/estimator/estimator-test.js +++ b/lighthouse-core/test/gather/computed/dependency-graph/estimator/estimator-test.js @@ -5,11 +5,13 @@ */ 'use strict'; -const Node = require('../../../../../gather/computed/dependency-graph/network-node'); +const NetworkNode = require('../../../../../gather/computed/dependency-graph/network-node'); +const CpuNode = require('../../../../../gather/computed/dependency-graph/cpu-node'); const Estimator = require('../../../../../gather/computed/dependency-graph/estimator/estimator'); const assert = require('assert'); let nextRequestId = 1; +let nextTid = 1; function request({requestId, connectionId, transferSize, scheme, timing}) { requestId = requestId || nextRequestId++; @@ -26,22 +28,40 @@ function request({requestId, connectionId, transferSize, scheme, timing}) { }; } +function cpuTask({tid, ts, duration}) { + tid = tid || nextTid++; + ts = ts || 0; + const dur = (duration || 0) * 1000 / 5; + return {tid, ts, dur}; +} + /* eslint-env mocha */ describe('DependencyGraph/Estimator', () => { describe('.estimate', () => { - it('should estimate basic graphs', () => { - const rootNode = new Node(request({})); + it('should estimate basic network graphs', () => { + const rootNode = new NetworkNode(request({})); const estimator = new Estimator(rootNode, {defaultResponseTime: 500}); const result = estimator.estimate(); // should be 2 RTTs and 500ms for the server response time assert.equal(result, 300 + 500); }); - it('should estimate basic waterfall graphs', () => { - const nodeA = new Node(request({connectionId: 1})); - const nodeB = new Node(request({connectionId: 2})); - const nodeC = new Node(request({connectionId: 3})); - const nodeD = new Node(request({connectionId: 4})); + it('should estimate basic mixed graphs', () => { + const rootNode = new NetworkNode(request({})); + const cpuNode = new CpuNode(cpuTask({duration: 200})); + cpuNode.addDependency(rootNode); + + const estimator = new Estimator(rootNode, {defaultResponseTime: 500}); + const result = estimator.estimate(); + // should be 2 RTTs and 500ms for the server response time + 200 CPU + assert.equal(result, 300 + 500 + 200); + }); + + it('should estimate basic network waterfall graphs', () => { + const nodeA = new NetworkNode(request({connectionId: 1})); + const nodeB = new NetworkNode(request({connectionId: 2})); + const nodeC = new NetworkNode(request({connectionId: 3})); + const nodeD = new NetworkNode(request({connectionId: 4})); nodeA.addDependent(nodeB); nodeB.addDependent(nodeC); @@ -53,11 +73,47 @@ describe('DependencyGraph/Estimator', () => { assert.equal(result, 3200); }); + it('should estimate basic CPU queue graphs', () => { + const nodeA = new NetworkNode(request({connectionId: 1})); + const nodeB = new CpuNode(cpuTask({duration: 100})); + const nodeC = new CpuNode(cpuTask({duration: 600})); + const nodeD = new CpuNode(cpuTask({duration: 300})); + + nodeA.addDependent(nodeB); + nodeA.addDependent(nodeC); + nodeA.addDependent(nodeD); + + const estimator = new Estimator(nodeA, {defaultResponseTime: 500}); + const result = estimator.estimate(); + // should be 800ms A, then 1000 ms total for B, C, D in serial + assert.equal(result, 1800); + }); + + it('should estimate basic network waterfall graphs with CPU', () => { + const nodeA = new NetworkNode(request({connectionId: 1})); + const nodeB = new NetworkNode(request({connectionId: 2})); + const nodeC = new NetworkNode(request({connectionId: 3})); + const nodeD = new NetworkNode(request({connectionId: 4})); + const nodeE = new CpuNode(cpuTask({duration: 1000})); + const nodeF = new CpuNode(cpuTask({duration: 1000})); + + nodeA.addDependent(nodeB); + nodeB.addDependent(nodeC); + nodeB.addDependent(nodeE); // finishes 200 ms after C + nodeC.addDependent(nodeD); + nodeC.addDependent(nodeF); // finishes 400 ms after D + + const estimator = new Estimator(nodeA, {defaultResponseTime: 500}); + const result = estimator.estimate(); + // should be 800ms each for A, B, C, D, with F finishing 400 ms after D + assert.equal(result, 3600); + }); + it('should estimate basic parallel requests', () => { - const nodeA = new Node(request({connectionId: 1})); - const nodeB = new Node(request({connectionId: 2})); - const nodeC = new Node(request({connectionId: 3, transferSize: 15000})); - const nodeD = new Node(request({connectionId: 4})); + const nodeA = new NetworkNode(request({connectionId: 1})); + const nodeB = new NetworkNode(request({connectionId: 2})); + const nodeC = new NetworkNode(request({connectionId: 3, transferSize: 15000})); + const nodeD = new NetworkNode(request({connectionId: 4})); nodeA.addDependent(nodeB); nodeA.addDependent(nodeC); @@ -70,10 +126,10 @@ describe('DependencyGraph/Estimator', () => { }); it('should not reuse connections', () => { - const nodeA = new Node(request({connectionId: 1})); - const nodeB = new Node(request({connectionId: 1})); - const nodeC = new Node(request({connectionId: 1})); - const nodeD = new Node(request({connectionId: 1})); + const nodeA = new NetworkNode(request({connectionId: 1})); + const nodeB = new NetworkNode(request({connectionId: 1})); + const nodeC = new NetworkNode(request({connectionId: 1})); + const nodeD = new NetworkNode(request({connectionId: 1})); nodeA.addDependent(nodeB); nodeA.addDependent(nodeC); @@ -86,10 +142,10 @@ describe('DependencyGraph/Estimator', () => { }); it('should adjust throughput based on number of requests', () => { - const nodeA = new Node(request({connectionId: 1})); - const nodeB = new Node(request({connectionId: 2})); - const nodeC = new Node(request({connectionId: 3, transferSize: 15000})); - const nodeD = new Node(request({connectionId: 4})); + const nodeA = new NetworkNode(request({connectionId: 1})); + const nodeB = new NetworkNode(request({connectionId: 2})); + const nodeC = new NetworkNode(request({connectionId: 3, transferSize: 15000})); + const nodeD = new NetworkNode(request({connectionId: 4})); nodeA.addDependent(nodeB); nodeA.addDependent(nodeC); diff --git a/lighthouse-core/test/gather/computed/page-dependency-graph-test.js b/lighthouse-core/test/gather/computed/page-dependency-graph-test.js index eca31b54290b..b4efd086794f 100644 --- a/lighthouse-core/test/gather/computed/page-dependency-graph-test.js +++ b/lighthouse-core/test/gather/computed/page-dependency-graph-test.js @@ -14,16 +14,42 @@ const sampleDevtoolsLog = require('../../fixtures/traces/progressive-app-m60.dev const assert = require('assert'); -function createRequest(requestId, url, startTime, _initiator) { - return {requestId, url, startTime, _initiator}; +function createRequest(requestId, url, startTime = 0, _initiator = null, resourceType = '') { + startTime = startTime / 1000; + const endTime = startTime + .1; + return {requestId, url, startTime, endTime, _initiator, _resourceType: {_name: resourceType}}; } /* eslint-env mocha */ describe('PageDependencyGraph computed artifact:', () => { let computedArtifacts; + let traceOfTab; + + function addTaskEvents(startTs, duration, evts) { + const mainEvent = { + name: 'TaskQueueManager::ProcessTaskFromWorkQueue', + tid: 1, + ts: startTs * 1000, + dur: duration * 1000, + args: {}, + }; + + traceOfTab.mainThreadEvents.push(mainEvent); + + let i = 0; + for (const evt of evts) { + i++; + traceOfTab.mainThreadEvents.push({ + name: evt.name, + ts: (evt.ts * 1000) || (startTs * 1000 + i), + args: {data: evt.data}, + }); + } + } beforeEach(() => { computedArtifacts = Runner.instantiateComputedArtifacts(); + traceOfTab = {mainThreadEvents: []}; }); describe('#compute_', () => { @@ -41,15 +67,82 @@ describe('PageDependencyGraph computed artifact:', () => { }); }); + describe('#getNetworkNodes', () => { + const request1 = createRequest(1, 'urlA'); + const request2 = createRequest(2, 'urlB'); + const request3 = createRequest(3, 'urlB'); + const networkRecords = [request1, request2, request3]; + + it('should create network nodes', () => { + const networkNodeOutput = PageDependencyGraph.getNetworkNodes(networkRecords); + for (let i = 0; i < networkRecords.length; i++) { + const node = networkNodeOutput.nodes[i]; + assert.ok(node, `did not create node at index ${i}`); + assert.equal(node.id, i + 1); + assert.equal(node.type, 'network'); + assert.equal(node.record, networkRecords[i]); + } + }); + + it('should index nodes by ID', () => { + const networkNodeOutput = PageDependencyGraph.getNetworkNodes(networkRecords); + const indexedById = networkNodeOutput.idToNodeMap; + for (const record of networkRecords) { + assert.equal(indexedById.get(record.requestId).record, record); + } + }); + + it('should index nodes by URL', () => { + const networkNodeOutput = PageDependencyGraph.getNetworkNodes(networkRecords); + const nodes = networkNodeOutput.nodes; + const indexedByUrl = networkNodeOutput.urlToNodeMap; + assert.deepEqual(indexedByUrl.get('urlA'), [nodes[0]]); + assert.deepEqual(indexedByUrl.get('urlB'), [nodes[1], nodes[2]]); + }); + }); + + describe('#getCPUNodes', () => { + it('should create CPU nodes', () => { + addTaskEvents(0, 100, [ + {name: 'MyCustomEvent'}, + {name: 'OtherEvent'}, + {name: 'OutsideTheWindow', ts: 200}, + {name: 'OrphanedEvent'}, // should be ignored since we stopped at OutsideTheWindow + ]); + + addTaskEvents(250, 50, [ + {name: 'LaterEvent'}, + ]); + + assert.equal(traceOfTab.mainThreadEvents.length, 7); + const nodes = PageDependencyGraph.getCPUNodes(traceOfTab); + assert.equal(nodes.length, 2); + + const node1 = nodes[0]; + assert.equal(node1.id, '1.0'); + assert.equal(node1.type, 'cpu'); + assert.equal(node1.event, traceOfTab.mainThreadEvents[0]); + assert.equal(node1.children.length, 2); + assert.equal(node1.children[1].name, 'OtherEvent'); + + const node2 = nodes[1]; + assert.equal(node2.id, '1.250000'); + assert.equal(node2.type, 'cpu'); + assert.equal(node2.event, traceOfTab.mainThreadEvents[5]); + assert.equal(node2.children.length, 1); + assert.equal(node2.children[0].name, 'LaterEvent'); + }); + }); + describe('#createGraph', () => { - it('should compute a simple graph', () => { + it('should compute a simple network graph', () => { const request1 = createRequest(1, '1', 0); const request2 = createRequest(2, '2', 5); const request3 = createRequest(3, '3', 5); const request4 = createRequest(4, '4', 10, {url: '2'}); const networkRecords = [request1, request2, request3, request4]; - const graph = PageDependencyGraph.createGraph({}, networkRecords); + const graph = PageDependencyGraph.createGraph(traceOfTab, networkRecords); const nodes = []; graph.traverse(node => nodes.push(node)); @@ -61,14 +154,48 @@ describe('PageDependencyGraph computed artifact:', () => { assert.deepEqual(nodes[3].getDependencies(), [nodes[1]]); }); - it('should compute a graph with duplicate URLs', () => { + it('should compute a simple network and CPU graph', () => { + const request1 = createRequest(1, '1', 0); + const request2 = createRequest(2, '2', 50); + const request3 = createRequest(3, '3', 50); + const request4 = createRequest(4, '4', 300, null, 'xhr'); + const networkRecords = [request1, request2, request3, request4]; + + addTaskEvents(200, 200, [ + {name: 'EvaluateScript', data: {url: '2'}}, + {name: 'ResourceSendRequest', data: {requestId: 4}}, + ]); + + addTaskEvents(700, 50, [ + {name: 'InvalidateLayout', data: {stackTrace: [{url: '3'}]}}, + {name: 'XHRReadyStateChange', data: {readyState: 4, url: '4'}}, + ]); + + const graph = PageDependencyGraph.createGraph(traceOfTab, networkRecords); + const nodes = []; + graph.traverse(node => nodes.push(node)); + + const getIds = nodes => nodes.map(node => node.id); + const getDependencyIds = node => getIds(node.getDependencies()); + + assert.equal(nodes.length, 6); + assert.deepEqual(getIds(nodes), [1, 2, 3, 4, '1.200000', '1.700000']); + assert.deepEqual(getDependencyIds(nodes[0]), []); + assert.deepEqual(getDependencyIds(nodes[1]), [1]); + assert.deepEqual(getDependencyIds(nodes[2]), [1]); + assert.deepEqual(getDependencyIds(nodes[3]), [1, '1.200000']); + assert.deepEqual(getDependencyIds(nodes[4]), [2]); + assert.deepEqual(getDependencyIds(nodes[5]), [3, 4]); + }); + + it('should compute a network graph with duplicate URLs', () => { const request1 = createRequest(1, '1', 0); const request2 = createRequest(2, '2', 5); const request3 = createRequest(3, '2', 5); // duplicate URL const request4 = createRequest(4, '4', 10, {url: '2'}); const networkRecords = [request1, request2, request3, request4]; - const graph = PageDependencyGraph.createGraph({}, networkRecords); + const graph = PageDependencyGraph.createGraph(traceOfTab, networkRecords); const nodes = []; graph.traverse(node => nodes.push(node));