From b2f6e0dbcaa225c5ad4202613641f55515ea5df6 Mon Sep 17 00:00:00 2001 From: Ward Peeters Date: Thu, 5 Oct 2017 22:39:49 +0200 Subject: [PATCH 01/15] feat(page-execution-timings): Audit for page-execution-timings --- .../audits/page-execution-timings.js | 107 ++++++++++++++++++ lighthouse-core/config/default.js | 2 + lighthouse-core/config/test-config.js | 0 3 files changed, 109 insertions(+) create mode 100644 lighthouse-core/audits/page-execution-timings.js create mode 100644 lighthouse-core/config/test-config.js diff --git a/lighthouse-core/audits/page-execution-timings.js b/lighthouse-core/audits/page-execution-timings.js new file mode 100644 index 000000000000..69a9a8386901 --- /dev/null +++ b/lighthouse-core/audits/page-execution-timings.js @@ -0,0 +1,107 @@ +/** + * @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. + */ + +/** + * @fileoverview Audit a page to see if it does not use that block first paint. + */ + +'use strict'; + +const Audit = require('./audit'); +const Util = require('../report/v2/renderer/util'); +const DevtoolsTimelineModel = require('../lib/traces/devtools-timeline-model'); + +const timelineCategories = [ + 'Compile Script', + 'Evaluate Script', + 'Minor GC', + 'Major GC', + 'XHR Ready State Change', + 'Layout', + 'Paint', + 'Composite Layers', + 'Recalculate Style', + 'Parse HTML', + 'Parse Stylesheet', + 'DOM GC', + 'Image Decode', +]; + +class PageExecutionTimings extends Audit { + + /** + * @return {!AuditMeta} + */ + static get meta() { + return { + category: 'Performance', + name: 'boot-up-time', + description: 'Boot-up time is high', + informative: true, + helpText: 'Consider reducing the time spent parsing, compiling and executing JS.' + + 'You may find delivering smaller JS payloads helps with this.', + requiredArtifacts: ['traces'], + }; + } + + /** + * @param {!Array=} trace + * @param {!WebInspector.TimelineProfileTree.Node} A grouped and sorted tree + */ + static getTimingsByCategory(trace) { + const timelineModel = new DevtoolsTimelineModel(trace); + + return timelineModel.bottomUpGroupBy('EventName'); + } + + /** + * @param {!Array=} trace + * @return {!Map} + */ + static getExecutionTimingsByCategory(trace) { + const bottomUpByName = PageExecutionTimings.getTimingsByCategory(trace); + + const result = new Map(); + bottomUpByName.children.forEach((value, key) => + result.set(key, value.selfTime.toFixed(1))); + + return result; + } + + /** + * @param {!Artifacts} artifacts + * @return {!AuditResult} + */ + static audit(artifacts) { + const trace = artifacts.traces[PageExecutionTimings.DEFAULT_PASS].traceEvents; + const executionTimings = PageExecutionTimings.getExecutionTimingsByCategory(trace); + let totalExecutionTime = 0; + + const results = timelineCategories.map(category => { + const timing = Number(executionTimings.get(category) || 0); + totalExecutionTime += timing; + + return { + category, + duration: Util.formatMilliseconds(timing, 1), + } + }); + + const headings = [ + {key: 'category', itemType: 'text', text: 'Category'}, + {key: 'duration', itemType: 'text', text: 'Time spent'}, + ]; + const tableDetails = PageExecutionTimings.makeTableDetails(headings, results); + + return { + rawValue: totalExecutionTime, + displayValue: Util.formatMilliseconds(totalExecutionTime), + details: tableDetails, + }; + } +} + +module.exports = PageExecutionTimings; diff --git a/lighthouse-core/config/default.js b/lighthouse-core/config/default.js index 5a6e994d0334..686269f0c3de 100644 --- a/lighthouse-core/config/default.js +++ b/lighthouse-core/config/default.js @@ -86,6 +86,7 @@ module.exports = { 'content-width', 'image-aspect-ratio', 'deprecations', + 'page-execution-timings', 'manual/pwa-cross-browser', 'manual/pwa-page-transitions', 'manual/pwa-each-page-has-url', @@ -243,6 +244,7 @@ module.exports = { {id: 'critical-request-chains', weight: 0, group: 'perf-info'}, {id: 'user-timings', weight: 0, group: 'perf-info'}, {id: 'screenshot-thumbnails', weight: 0}, + {id: 'page-execution-timings', weight: 0, group: 'perf-info'}, ], }, 'accessibility': { diff --git a/lighthouse-core/config/test-config.js b/lighthouse-core/config/test-config.js new file mode 100644 index 000000000000..e69de29bb2d1 From 8fbe712e4278986ea73562fcc598f02c28aad1d1 Mon Sep 17 00:00:00 2001 From: Ward Peeters Date: Tue, 10 Oct 2017 17:42:52 +0200 Subject: [PATCH 02/15] Add category group --- .../audits/page-execution-timings.js | 76 ++++++++++++++----- 1 file changed, 59 insertions(+), 17 deletions(-) diff --git a/lighthouse-core/audits/page-execution-timings.js b/lighthouse-core/audits/page-execution-timings.js index 69a9a8386901..5e3ed42acd36 100644 --- a/lighthouse-core/audits/page-execution-timings.js +++ b/lighthouse-core/audits/page-execution-timings.js @@ -15,19 +15,58 @@ const Util = require('../report/v2/renderer/util'); const DevtoolsTimelineModel = require('../lib/traces/devtools-timeline-model'); const timelineCategories = [ - 'Compile Script', - 'Evaluate Script', - 'Minor GC', - 'Major GC', - 'XHR Ready State Change', - 'Layout', - 'Paint', - 'Composite Layers', - 'Recalculate Style', - 'Parse HTML', - 'Parse Stylesheet', - 'DOM GC', - 'Image Decode', + { + name: 'Compile Script', + group: 'JavaScript', + }, + { + name: 'Evaluate Script', + group: 'JavaScript', + }, + { + name: 'Minor GC', + group: 'JavaScript', + }, + { + name: 'Major GC', + group: 'JavaScript', + }, + { + name: 'XHR Ready State Change', + group: 'JavaScript', + }, + { + name: 'Layout', + group: 'Paint/Layout', + }, + { + name: 'Paint', + group: 'Paint/Layout', + }, + { + name: 'Composite Layers', + group: 'Paint/Layout', + }, + { + name: 'Recalculate Style', + group: 'Paint/Layout', + }, + { + name: 'Parse HTML', + group: 'DOM/CSS', + }, + { + name: 'Parse Stylesheet', + group: 'DOM/CSS', + }, + { + name: 'DOM GC', + group: 'DOM/CSS', + }, + { + name: 'Image Decode', + group: 'Images', + }, ]; class PageExecutionTimings extends Audit { @@ -38,8 +77,8 @@ class PageExecutionTimings extends Audit { static get meta() { return { category: 'Performance', - name: 'boot-up-time', - description: 'Boot-up time is high', + name: 'page-execution-timings', + description: 'Page executiontime is high', informative: true, helpText: 'Consider reducing the time spent parsing, compiling and executing JS.' + 'You may find delivering smaller JS payloads helps with this.', @@ -81,22 +120,25 @@ class PageExecutionTimings extends Audit { let totalExecutionTime = 0; const results = timelineCategories.map(category => { - const timing = Number(executionTimings.get(category) || 0); + const timing = Number(executionTimings.get(category.name) || 0); totalExecutionTime += timing; return { - category, + category: category.name, + group: category.group, duration: Util.formatMilliseconds(timing, 1), } }); const headings = [ {key: 'category', itemType: 'text', text: 'Category'}, + {key: 'group', itemType: 'text', text: 'Task Category'}, {key: 'duration', itemType: 'text', text: 'Time spent'}, ]; const tableDetails = PageExecutionTimings.makeTableDetails(headings, results); return { + score: false, rawValue: totalExecutionTime, displayValue: Util.formatMilliseconds(totalExecutionTime), details: tableDetails, From 9ed9d5df681f68bc87041d9ae40ca1d243092b7d Mon Sep 17 00:00:00 2001 From: Ward Peeters Date: Tue, 10 Oct 2017 17:49:28 +0200 Subject: [PATCH 03/15] Add extra timing categories --- lighthouse-core/audits/page-execution-timings.js | 12 ++++++++++++ 1 file changed, 12 insertions(+) diff --git a/lighthouse-core/audits/page-execution-timings.js b/lighthouse-core/audits/page-execution-timings.js index 5e3ed42acd36..8fbdcb312621 100644 --- a/lighthouse-core/audits/page-execution-timings.js +++ b/lighthouse-core/audits/page-execution-timings.js @@ -23,6 +23,10 @@ const timelineCategories = [ name: 'Evaluate Script', group: 'JavaScript', }, + { + name: 'Run Microtasks', + group: 'JavaScript', + }, { name: 'Minor GC', group: 'JavaScript', @@ -35,6 +39,10 @@ const timelineCategories = [ name: 'XHR Ready State Change', group: 'JavaScript', }, + { + name: 'XHR Load', + group: 'JavaScript', + }, { name: 'Layout', group: 'Paint/Layout', @@ -47,6 +55,10 @@ const timelineCategories = [ name: 'Composite Layers', group: 'Paint/Layout', }, + { + name: 'Update Layer Tree', + group: 'Paint/Layout', + }, { name: 'Recalculate Style', group: 'Paint/Layout', From 1bffff7366116a310a5853add11f21761326d485 Mon Sep 17 00:00:00 2001 From: Ward Peeters Date: Tue, 10 Oct 2017 22:28:09 +0200 Subject: [PATCH 04/15] Fix copyright year 2017 --- lighthouse-core/audits/page-execution-timings.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lighthouse-core/audits/page-execution-timings.js b/lighthouse-core/audits/page-execution-timings.js index 8fbdcb312621..1e55a6f1cbbb 100644 --- a/lighthouse-core/audits/page-execution-timings.js +++ b/lighthouse-core/audits/page-execution-timings.js @@ -1,5 +1,5 @@ /** - * @license Copyright 2016 Google Inc. All Rights Reserved. + * @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. */ From 36a68484e32dd9c0a2bf1a8e6e77a144b116f557 Mon Sep 17 00:00:00 2001 From: Ward Peeters Date: Thu, 12 Oct 2017 23:02:20 +0200 Subject: [PATCH 05/15] Review changes --- .../audits/page-execution-timings.js | 181 ++++++++++-------- 1 file changed, 96 insertions(+), 85 deletions(-) diff --git a/lighthouse-core/audits/page-execution-timings.js b/lighthouse-core/audits/page-execution-timings.js index 1e55a6f1cbbb..04b510599625 100644 --- a/lighthouse-core/audits/page-execution-timings.js +++ b/lighthouse-core/audits/page-execution-timings.js @@ -14,72 +14,88 @@ const Audit = require('./audit'); const Util = require('../report/v2/renderer/util'); const DevtoolsTimelineModel = require('../lib/traces/devtools-timeline-model'); -const timelineCategories = [ - { - name: 'Compile Script', - group: 'JavaScript', - }, - { - name: 'Evaluate Script', - group: 'JavaScript', - }, - { - name: 'Run Microtasks', - group: 'JavaScript', - }, - { - name: 'Minor GC', - group: 'JavaScript', - }, - { - name: 'Major GC', - group: 'JavaScript', - }, - { - name: 'XHR Ready State Change', - group: 'JavaScript', - }, - { - name: 'XHR Load', - group: 'JavaScript', - }, - { - name: 'Layout', - group: 'Paint/Layout', - }, - { - name: 'Paint', - group: 'Paint/Layout', - }, - { - name: 'Composite Layers', - group: 'Paint/Layout', - }, - { - name: 'Update Layer Tree', - group: 'Paint/Layout', - }, - { - name: 'Recalculate Style', - group: 'Paint/Layout', - }, - { - name: 'Parse HTML', - group: 'DOM/CSS', - }, - { - name: 'Parse Stylesheet', - group: 'DOM/CSS', - }, - { - name: 'DOM GC', - group: 'DOM/CSS', - }, - { - name: 'Image Decode', - group: 'Images', - }, -]; +const group = { + loading: 'Network request loading', + parseHTML: 'Parsing DOM', + styleLayout: 'Style & Layout', + compositing: 'Compositing', + painting: 'Paint', + gpu: 'GPU', + scripting: 'Script Evaluation', + scriptParseCompile: 'Script Parsing & Compile', + scriptGC: 'Garbage collection', + other: 'Other', + images: 'Images', +}; + +const taskToGroup = { + 'Animation': group.painting, + 'Async Task': group.other, + 'Frame Start': group.painting, + 'Frame Start (main thread)': group.painting, + 'Cancel Animation Frame': group.scripting, + 'Cancel Idle Callback': group.scripting, + 'Compile Script': group.scriptParseCompile, + 'Composite Layers': group.compositing, + 'Console Time': group.scripting, + 'Image Decode': group.images, + 'Draw Frame': group.painting, + 'Embedder Callback': group.scripting, + 'Evaluate Script': group.scripting, + 'Event': group.scripting, + 'Animation Frame Fired': group.scripting, + 'Fire Idle Callback': group.scripting, + 'Function Call': group.scripting, + 'DOM GC': group.scriptGC, + 'GC Event': group.scriptGC, + 'GPU': group.gpu, + 'Hit Test': group.compositing, + 'Invalidate Layout': group.styleLayout, + 'JS Frame': group.scripting, + 'Input Latency': group.scripting, + 'Layout': group.styleLayout, + 'Major GC': group.scriptGC, + 'DOMContentLoaded event': group.scripting, + 'First paint': group.painting, + 'FMP': group.painting, + 'FMP candidate': group.painting, + 'Load event': group.scripting, + 'Minor GC': group.scriptGC, + 'Paint': group.painting, + 'Paint Image': group.images, + 'Paint Setup': group.painting, + 'Parse Stylesheet': group.parseHTML, + 'Parse HTML': group.parseHTML, + 'Parse Script': group.scriptParseCompile, + 'Other': group.other, + 'Rasterize Paint': group.painting, + 'Recalculate Style': group.styleLayout, + 'Request Animation Frame': group.scripting, + 'Request Idle Callback': group.scripting, + 'Request Main Thread Frame': group.painting, + 'Image Resize': group.images, + 'Finish Loading': group.loading, + 'Receive Data': group.loading, + 'Receive Response': group.loading, + 'Send Request': group.loading, + 'Run Microtasks': group.scripting, + 'Schedule Style Recalculation': group.styleLayout, + 'Scroll': group.compositing, + 'Task': group.other, + 'Timer Fired': group.scripting, + 'Install Timer': group.scripting, + 'Remove Timer': group.scripting, + 'Timestamp': group.scripting, + 'Update Layer': group.compositing, + 'Update Layer Tree': group.compositing, + 'User Timing': group.scripting, + 'Create WebSocket': group.scripting, + 'Destroy WebSocket': group.scripting, + 'Receive WebSocket Handshake': group.scripting, + 'Send WebSocket Handshake': group.scripting, + 'XHR Load': group.scripting, + 'XHR Ready State Change': group.scripting, +}; class PageExecutionTimings extends Audit { @@ -98,26 +114,17 @@ class PageExecutionTimings extends Audit { }; } - /** - * @param {!Array=} trace - * @param {!WebInspector.TimelineProfileTree.Node} A grouped and sorted tree - */ - static getTimingsByCategory(trace) { - const timelineModel = new DevtoolsTimelineModel(trace); - - return timelineModel.bottomUpGroupBy('EventName'); - } - /** * @param {!Array=} trace * @return {!Map} */ static getExecutionTimingsByCategory(trace) { - const bottomUpByName = PageExecutionTimings.getTimingsByCategory(trace); + const timelineModel = new DevtoolsTimelineModel(trace); + const bottomUpByName = timelineModel.bottomUpGroupBy('EventName'); const result = new Map(); bottomUpByName.children.forEach((value, key) => - result.set(key, value.selfTime.toFixed(1))); + result.set(key, Number(value.selfTime.toFixed(1)))); return result; } @@ -131,15 +138,16 @@ class PageExecutionTimings extends Audit { const executionTimings = PageExecutionTimings.getExecutionTimingsByCategory(trace); let totalExecutionTime = 0; - const results = timelineCategories.map(category => { - const timing = Number(executionTimings.get(category.name) || 0); - totalExecutionTime += timing; + const extendedInfo = {}; + const results = Array.from(executionTimings).map(([eventName, duration]) => { + totalExecutionTime += duration; + extendedInfo[eventName] = duration; return { - category: category.name, - group: category.group, - duration: Util.formatMilliseconds(timing, 1), - } + category: eventName, + group: taskToGroup[eventName], + duration: Util.formatMilliseconds(duration, 1), + }; }); const headings = [ @@ -154,6 +162,9 @@ class PageExecutionTimings extends Audit { rawValue: totalExecutionTime, displayValue: Util.formatMilliseconds(totalExecutionTime), details: tableDetails, + extendedInfo: { + value: extendedInfo, + }, }; } } From 2e0f83008a2dda62215076a947299bb0f6b25441 Mon Sep 17 00:00:00 2001 From: Ward Peeters Date: Thu, 12 Oct 2017 23:02:26 +0200 Subject: [PATCH 06/15] Add unit test from trace --- .../audits/page-execution-timings-test.js | 56 +++++++++++++++++++ 1 file changed, 56 insertions(+) create mode 100644 lighthouse-core/test/audits/page-execution-timings-test.js diff --git a/lighthouse-core/test/audits/page-execution-timings-test.js b/lighthouse-core/test/audits/page-execution-timings-test.js new file mode 100644 index 000000000000..cc04efe32f2e --- /dev/null +++ b/lighthouse-core/test/audits/page-execution-timings-test.js @@ -0,0 +1,56 @@ +/** + * @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 PageExecutionTimings = require('../../audits/page-execution-timings.js'); +const assert = require('assert'); + +const acceptableTrace = require('../fixtures/traces/progressive-app-m60.json'); +const brokenTrace = require('../fixtures/traces/airhorner_no_fcp.json'); +const trace = require('../fixtures/traces/response.json'); + +/* eslint-env mocha */ +describe('Performance: page execution timings audit', () => { + it('should compute the correct pageExecutionTiming values', () => { + const artifacts = { + traces: { + [PageExecutionTimings.DEFAULT_PASS]: acceptableTrace, + }, + }; + + const output = PageExecutionTimings.audit(artifacts); + assert.equal(output.details.items.length, 12); + assert.equal(output.score, false); + assert.equal(Math.round(output.rawValue), 611); + + const valueOf = name => Math.round(output.extendedInfo.value[name]); + assert.equal(valueOf('Recalculate Style'), 170); + assert.equal(valueOf('Layout'), 138); + assert.equal(valueOf('Evaluate Script'), 131); + assert.equal(valueOf('Paint'), 52); + assert.equal(valueOf('DOM GC'), 33); + assert.equal(valueOf('Update Layer Tree'), 25); + assert.equal(valueOf('Compile Script'), 25); + assert.equal(valueOf('Parse HTML'), 14); + assert.equal(valueOf('Major GC'), 8); + assert.equal(valueOf('Minor GC'), 7); + assert.equal(valueOf('Composite Layers'), 6); + assert.equal(valueOf('Image Decode'), 1); + }); + + it('should get no data when no events are present', () => { + const artifacts = { + traces: { + [PageExecutionTimings.DEFAULT_PASS]: brokenTrace, + }, + }; + + const output = PageExecutionTimings.audit(artifacts); + assert.equal(output.details.items.length, 0); + assert.equal(output.score, false); + assert.equal(Math.round(output.rawValue), 0); + }); +}); From b1d55074828c47b2942b7836041b3dc23aff6a2e Mon Sep 17 00:00:00 2001 From: Ward Peeters Date: Fri, 13 Oct 2017 08:12:36 +0200 Subject: [PATCH 07/15] Review fixes & unit tests --- .../audits/page-execution-timings.js | 2 +- .../audits/page-execution-timings-test.js | 96 +++++++++++-------- 2 files changed, 59 insertions(+), 39 deletions(-) diff --git a/lighthouse-core/audits/page-execution-timings.js b/lighthouse-core/audits/page-execution-timings.js index 04b510599625..92fd27ddb1b0 100644 --- a/lighthouse-core/audits/page-execution-timings.js +++ b/lighthouse-core/audits/page-execution-timings.js @@ -134,7 +134,7 @@ class PageExecutionTimings extends Audit { * @return {!AuditResult} */ static audit(artifacts) { - const trace = artifacts.traces[PageExecutionTimings.DEFAULT_PASS].traceEvents; + const trace = artifacts.traces[PageExecutionTimings.DEFAULT_PASS]; const executionTimings = PageExecutionTimings.getExecutionTimingsByCategory(trace); let totalExecutionTime = 0; diff --git a/lighthouse-core/test/audits/page-execution-timings-test.js b/lighthouse-core/test/audits/page-execution-timings-test.js index cc04efe32f2e..bec182f2823c 100644 --- a/lighthouse-core/test/audits/page-execution-timings-test.js +++ b/lighthouse-core/test/audits/page-execution-timings-test.js @@ -6,51 +6,71 @@ 'use strict'; const PageExecutionTimings = require('../../audits/page-execution-timings.js'); +const fs = require('fs'); const assert = require('assert'); -const acceptableTrace = require('../fixtures/traces/progressive-app-m60.json'); -const brokenTrace = require('../fixtures/traces/airhorner_no_fcp.json'); -const trace = require('../fixtures/traces/response.json'); +// sadly require(file) is not working correctly. +// traceParser parser returns preact trace data the same as JSON.parse +// fails when require is used +const readFile = (file, cb) => { + let output = ''; + const readStream = fs.createReadStream(__dirname + file, { + encoding: 'utf-8', + }); + + readStream.on('data', (chunk) => { + output += chunk.toString(); + }); + readStream.on('end', () => { + cb(JSON.parse(output)); + }); +} /* eslint-env mocha */ describe('Performance: page execution timings audit', () => { - it('should compute the correct pageExecutionTiming values', () => { - const artifacts = { - traces: { - [PageExecutionTimings.DEFAULT_PASS]: acceptableTrace, - }, - }; - - const output = PageExecutionTimings.audit(artifacts); - assert.equal(output.details.items.length, 12); - assert.equal(output.score, false); - assert.equal(Math.round(output.rawValue), 611); - - const valueOf = name => Math.round(output.extendedInfo.value[name]); - assert.equal(valueOf('Recalculate Style'), 170); - assert.equal(valueOf('Layout'), 138); - assert.equal(valueOf('Evaluate Script'), 131); - assert.equal(valueOf('Paint'), 52); - assert.equal(valueOf('DOM GC'), 33); - assert.equal(valueOf('Update Layer Tree'), 25); - assert.equal(valueOf('Compile Script'), 25); - assert.equal(valueOf('Parse HTML'), 14); - assert.equal(valueOf('Major GC'), 8); - assert.equal(valueOf('Minor GC'), 7); - assert.equal(valueOf('Composite Layers'), 6); - assert.equal(valueOf('Image Decode'), 1); + it('should compute the correct pageExecutionTiming values', (done) => { + readFile('/../fixtures/traces/progressive-app-m60.json', fileData => { + const artifacts = { + traces: { + [PageExecutionTimings.DEFAULT_PASS]: fileData, + }, + }; + + const output = PageExecutionTimings.audit(artifacts); + assert.equal(output.details.items.length, 12); + assert.equal(output.score, false); + assert.equal(Math.round(output.rawValue), 611); + + const valueOf = name => Math.round(output.extendedInfo.value[name]); + assert.equal(valueOf('Recalculate Style'), 170); + assert.equal(valueOf('Layout'), 138); + assert.equal(valueOf('Evaluate Script'), 131); + assert.equal(valueOf('Paint'), 52); + assert.equal(valueOf('DOM GC'), 33); + assert.equal(valueOf('Update Layer Tree'), 25); + assert.equal(valueOf('Compile Script'), 25); + assert.equal(valueOf('Parse HTML'), 14); + assert.equal(valueOf('Major GC'), 8); + assert.equal(valueOf('Minor GC'), 7); + assert.equal(valueOf('Composite Layers'), 6); + assert.equal(valueOf('Image Decode'), 1); + + done(); + }); }); it('should get no data when no events are present', () => { - const artifacts = { - traces: { - [PageExecutionTimings.DEFAULT_PASS]: brokenTrace, - }, - }; - - const output = PageExecutionTimings.audit(artifacts); - assert.equal(output.details.items.length, 0); - assert.equal(output.score, false); - assert.equal(Math.round(output.rawValue), 0); + readFile('/../fixtures/traces/airhorner_no_fcp.json', fileData => { + const artifacts = { + traces: { + [PageExecutionTimings.DEFAULT_PASS]: fileData, + }, + }; + + const output = PageExecutionTimings.audit(artifacts); + assert.equal(output.details.items.length, 0); + assert.equal(output.score, false); + assert.equal(Math.round(output.rawValue), 0); + }); }); }); From 475b7f9a799c239fae2428e8a40da37a962d4987 Mon Sep 17 00:00:00 2001 From: Ward Peeters Date: Fri, 13 Oct 2017 17:26:39 +0200 Subject: [PATCH 08/15] Remove test config --- lighthouse-core/config/test-config.js | 0 1 file changed, 0 insertions(+), 0 deletions(-) delete mode 100644 lighthouse-core/config/test-config.js diff --git a/lighthouse-core/config/test-config.js b/lighthouse-core/config/test-config.js deleted file mode 100644 index e69de29bb2d1..000000000000 From aa89302af7b94a2ff2072535bb9447ac9a2bbd5c Mon Sep 17 00:00:00 2001 From: Ward Peeters Date: Sat, 14 Oct 2017 14:11:30 +0200 Subject: [PATCH 09/15] Use readFileSync instead of async --- .../audits/page-execution-timings.js | 1 - .../audits/page-execution-timings-test.js | 89 ++++++++----------- 2 files changed, 39 insertions(+), 51 deletions(-) diff --git a/lighthouse-core/audits/page-execution-timings.js b/lighthouse-core/audits/page-execution-timings.js index 92fd27ddb1b0..5aab43a34c88 100644 --- a/lighthouse-core/audits/page-execution-timings.js +++ b/lighthouse-core/audits/page-execution-timings.js @@ -98,7 +98,6 @@ const taskToGroup = { }; class PageExecutionTimings extends Audit { - /** * @return {!AuditMeta} */ diff --git a/lighthouse-core/test/audits/page-execution-timings-test.js b/lighthouse-core/test/audits/page-execution-timings-test.js index bec182f2823c..878102f5d94c 100644 --- a/lighthouse-core/test/audits/page-execution-timings-test.js +++ b/lighthouse-core/test/audits/page-execution-timings-test.js @@ -5,6 +5,7 @@ */ 'use strict'; +/* eslint-env mocha */ const PageExecutionTimings = require('../../audits/page-execution-timings.js'); const fs = require('fs'); const assert = require('assert'); @@ -12,65 +13,53 @@ const assert = require('assert'); // sadly require(file) is not working correctly. // traceParser parser returns preact trace data the same as JSON.parse // fails when require is used -const readFile = (file, cb) => { - let output = ''; - const readStream = fs.createReadStream(__dirname + file, { - encoding: 'utf-8', - }); - - readStream.on('data', (chunk) => { - output += chunk.toString(); - }); - readStream.on('end', () => { - cb(JSON.parse(output)); - }); -} +const acceptableTrace = JSON.parse( + fs.readFileSync(__dirname + '/../fixtures/traces/progressive-app-m60.json') +); +const errorTrace = JSON.parse( + fs.readFileSync(__dirname + '/../fixtures/traces/airhorner_no_fcp.json') +); -/* eslint-env mocha */ describe('Performance: page execution timings audit', () => { it('should compute the correct pageExecutionTiming values', (done) => { - readFile('/../fixtures/traces/progressive-app-m60.json', fileData => { - const artifacts = { - traces: { - [PageExecutionTimings.DEFAULT_PASS]: fileData, - }, - }; + const artifacts = { + traces: { + [PageExecutionTimings.DEFAULT_PASS]: acceptableTrace, + }, + }; - const output = PageExecutionTimings.audit(artifacts); - assert.equal(output.details.items.length, 12); - assert.equal(output.score, false); - assert.equal(Math.round(output.rawValue), 611); + const output = PageExecutionTimings.audit(artifacts); + assert.equal(output.details.items.length, 12); + assert.equal(output.score, false); + assert.equal(Math.round(output.rawValue), 611); - const valueOf = name => Math.round(output.extendedInfo.value[name]); - assert.equal(valueOf('Recalculate Style'), 170); - assert.equal(valueOf('Layout'), 138); - assert.equal(valueOf('Evaluate Script'), 131); - assert.equal(valueOf('Paint'), 52); - assert.equal(valueOf('DOM GC'), 33); - assert.equal(valueOf('Update Layer Tree'), 25); - assert.equal(valueOf('Compile Script'), 25); - assert.equal(valueOf('Parse HTML'), 14); - assert.equal(valueOf('Major GC'), 8); - assert.equal(valueOf('Minor GC'), 7); - assert.equal(valueOf('Composite Layers'), 6); - assert.equal(valueOf('Image Decode'), 1); + const valueOf = name => Math.round(output.extendedInfo.value[name]); + assert.equal(valueOf('Recalculate Style'), 170); + assert.equal(valueOf('Layout'), 138); + assert.equal(valueOf('Evaluate Script'), 131); + assert.equal(valueOf('Paint'), 52); + assert.equal(valueOf('DOM GC'), 33); + assert.equal(valueOf('Update Layer Tree'), 25); + assert.equal(valueOf('Compile Script'), 25); + assert.equal(valueOf('Parse HTML'), 14); + assert.equal(valueOf('Major GC'), 8); + assert.equal(valueOf('Minor GC'), 7); + assert.equal(valueOf('Composite Layers'), 6); + assert.equal(valueOf('Image Decode'), 1); - done(); - }); + done(); }); it('should get no data when no events are present', () => { - readFile('/../fixtures/traces/airhorner_no_fcp.json', fileData => { - const artifacts = { - traces: { - [PageExecutionTimings.DEFAULT_PASS]: fileData, - }, - }; + const artifacts = { + traces: { + [PageExecutionTimings.DEFAULT_PASS]: errorTrace, + }, + }; - const output = PageExecutionTimings.audit(artifacts); - assert.equal(output.details.items.length, 0); - assert.equal(output.score, false); - assert.equal(Math.round(output.rawValue), 0); - }); + const output = PageExecutionTimings.audit(artifacts); + assert.equal(output.details.items.length, 0); + assert.equal(output.score, false); + assert.equal(Math.round(output.rawValue), 0); }); }); From 5fbff87ef9c8c18d51d05e6a07f5631d6edde8b6 Mon Sep 17 00:00:00 2001 From: Ward Peeters Date: Sat, 14 Oct 2017 16:10:46 +0200 Subject: [PATCH 10/15] Fix spelling mistake --- lighthouse-core/audits/page-execution-timings.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lighthouse-core/audits/page-execution-timings.js b/lighthouse-core/audits/page-execution-timings.js index 5aab43a34c88..8c1bff5b514e 100644 --- a/lighthouse-core/audits/page-execution-timings.js +++ b/lighthouse-core/audits/page-execution-timings.js @@ -105,7 +105,7 @@ class PageExecutionTimings extends Audit { return { category: 'Performance', name: 'page-execution-timings', - description: 'Page executiontime is high', + description: 'Page execution time is high', informative: true, helpText: 'Consider reducing the time spent parsing, compiling and executing JS.' + 'You may find delivering smaller JS payloads helps with this.', From 7fe1b3a27efe927d328fee2b6d2301a8577c27af Mon Sep 17 00:00:00 2001 From: Ward Peeters Date: Thu, 19 Oct 2017 21:47:00 +0200 Subject: [PATCH 11/15] Updated review remarks --- lighthouse-core/audits/page-execution-timings.js | 14 +++++++------- 1 file changed, 7 insertions(+), 7 deletions(-) diff --git a/lighthouse-core/audits/page-execution-timings.js b/lighthouse-core/audits/page-execution-timings.js index 8c1bff5b514e..c324c0571610 100644 --- a/lighthouse-core/audits/page-execution-timings.js +++ b/lighthouse-core/audits/page-execution-timings.js @@ -5,7 +5,7 @@ */ /** - * @fileoverview Audit a page to see if it does not use that block first paint. + * @fileoverview Audit a page to show a breakdown of execution timings on the main thread */ 'use strict'; @@ -104,8 +104,8 @@ class PageExecutionTimings extends Audit { static get meta() { return { category: 'Performance', - name: 'page-execution-timings', - description: 'Page execution time is high', + name: 'mainthread-work-breakdown ', + description: 'Main thread work breakdown', informative: true, helpText: 'Consider reducing the time spent parsing, compiling and executing JS.' + 'You may find delivering smaller JS payloads helps with this.', @@ -114,16 +114,16 @@ class PageExecutionTimings extends Audit { } /** - * @param {!Array=} trace - * @return {!Map} + * @param {!Array} trace + * @return {!Map} */ static getExecutionTimingsByCategory(trace) { const timelineModel = new DevtoolsTimelineModel(trace); const bottomUpByName = timelineModel.bottomUpGroupBy('EventName'); const result = new Map(); - bottomUpByName.children.forEach((value, key) => - result.set(key, Number(value.selfTime.toFixed(1)))); + bottomUpByName.children.forEach((event, eventName) => + result.set(eventName, event.selfTime)); return result; } From ca8a29a196de959a5ce980ae2091ed2927f53dc4 Mon Sep 17 00:00:00 2001 From: Ward Peeters Date: Thu, 19 Oct 2017 22:10:32 +0200 Subject: [PATCH 12/15] renamed audit to mainthread-work-breakdown --- ...page-execution-timings.js => mainthread-work-breakdown.js} | 3 ++- lighthouse-core/config/default.js | 4 ++-- ...tion-timings-test.js => mainthread-work-breakdown-test.js} | 2 +- 3 files changed, 5 insertions(+), 4 deletions(-) rename lighthouse-core/audits/{page-execution-timings.js => mainthread-work-breakdown.js} (97%) rename lighthouse-core/test/audits/{page-execution-timings-test.js => mainthread-work-breakdown-test.js} (96%) diff --git a/lighthouse-core/audits/page-execution-timings.js b/lighthouse-core/audits/mainthread-work-breakdown.js similarity index 97% rename from lighthouse-core/audits/page-execution-timings.js rename to lighthouse-core/audits/mainthread-work-breakdown.js index c324c0571610..0dd563e4918a 100644 --- a/lighthouse-core/audits/page-execution-timings.js +++ b/lighthouse-core/audits/mainthread-work-breakdown.js @@ -14,6 +14,7 @@ const Audit = require('./audit'); const Util = require('../report/v2/renderer/util'); const DevtoolsTimelineModel = require('../lib/traces/devtools-timeline-model'); +// We group all trace events into groups to show a highlevel breakdown of the page const group = { loading: 'Network request loading', parseHTML: 'Parsing DOM', @@ -104,7 +105,7 @@ class PageExecutionTimings extends Audit { static get meta() { return { category: 'Performance', - name: 'mainthread-work-breakdown ', + name: 'mainthread-work-breakdown', description: 'Main thread work breakdown', informative: true, helpText: 'Consider reducing the time spent parsing, compiling and executing JS.' + diff --git a/lighthouse-core/config/default.js b/lighthouse-core/config/default.js index 686269f0c3de..c59531c1bda3 100644 --- a/lighthouse-core/config/default.js +++ b/lighthouse-core/config/default.js @@ -86,7 +86,7 @@ module.exports = { 'content-width', 'image-aspect-ratio', 'deprecations', - 'page-execution-timings', + 'mainthread-work-breakdown', 'manual/pwa-cross-browser', 'manual/pwa-page-transitions', 'manual/pwa-each-page-has-url', @@ -244,7 +244,7 @@ module.exports = { {id: 'critical-request-chains', weight: 0, group: 'perf-info'}, {id: 'user-timings', weight: 0, group: 'perf-info'}, {id: 'screenshot-thumbnails', weight: 0}, - {id: 'page-execution-timings', weight: 0, group: 'perf-info'}, + {id: 'mainthread-work-breakdown', weight: 0, group: 'perf-info'}, ], }, 'accessibility': { diff --git a/lighthouse-core/test/audits/page-execution-timings-test.js b/lighthouse-core/test/audits/mainthread-work-breakdown-test.js similarity index 96% rename from lighthouse-core/test/audits/page-execution-timings-test.js rename to lighthouse-core/test/audits/mainthread-work-breakdown-test.js index 878102f5d94c..7919b9e6b337 100644 --- a/lighthouse-core/test/audits/page-execution-timings-test.js +++ b/lighthouse-core/test/audits/mainthread-work-breakdown-test.js @@ -6,7 +6,7 @@ 'use strict'; /* eslint-env mocha */ -const PageExecutionTimings = require('../../audits/page-execution-timings.js'); +const PageExecutionTimings = require('../../audits/mainthread-work-breakdown.js'); const fs = require('fs'); const assert = require('assert'); From 6c99af6b41288f65649636ef9d79b1e2aeaba0e6 Mon Sep 17 00:00:00 2001 From: Ward Peeters Date: Fri, 20 Oct 2017 22:40:29 +0200 Subject: [PATCH 13/15] Add more traces --- .../audits/mainthread-work-breakdown-test.js | 112 +++++++++++++++--- 1 file changed, 97 insertions(+), 15 deletions(-) diff --git a/lighthouse-core/test/audits/mainthread-work-breakdown-test.js b/lighthouse-core/test/audits/mainthread-work-breakdown-test.js index 7919b9e6b337..2387a39d5dbc 100644 --- a/lighthouse-core/test/audits/mainthread-work-breakdown-test.js +++ b/lighthouse-core/test/audits/mainthread-work-breakdown-test.js @@ -16,36 +16,118 @@ const assert = require('assert'); const acceptableTrace = JSON.parse( fs.readFileSync(__dirname + '/../fixtures/traces/progressive-app-m60.json') ); +const siteWithRedirectTrace = JSON.parse( + fs.readFileSync(__dirname + '/../fixtures/traces/site-with-redirect.json') +); +const loadTrace = JSON.parse( + fs.readFileSync(__dirname + '/../fixtures/traces/load.json') +); const errorTrace = JSON.parse( fs.readFileSync(__dirname + '/../fixtures/traces/airhorner_no_fcp.json') ); +const acceptableTraceExpectations = { + 'Compile Script': 25, + 'Composite Layers': 6, + 'DOM GC': 33, + 'Evaluate Script': 131, + 'Image Decode': 1, + 'Layout': 138, + 'Major GC': 8, + 'Minor GC': 7, + 'Paint': 52, + 'Parse HTML': 14, + 'Recalculate Style': 170, + 'Update Layer Tree': 25, +}; +const siteWithRedirectTraceExpectations = { + 'Compile Script': 38, + 'Composite Layers': 2, + 'DOM GC': 25, + 'Evaluate Script': 122, + 'Image Decode': 0, + 'Layout': 209, + 'Major GC': 10, + 'Minor GC': 11, + 'Paint': 4, + 'Parse HTML': 52, + 'Parse Stylesheet': 51, + 'Recalculate Style': 66, + 'Update Layer Tree': 5, +}; +const loadTraceExpectations = { + 'Animation Frame Fired': 6, + 'Composite Layers': 15, + 'Evaluate Script': 296, + 'Image Decode': 4, + 'Layout': 51, + 'Minor GC': 3, + 'Paint': 9, + 'Parse HTML': 25, + 'Recalculate Style': 80, + 'Update Layer Tree': 16, + 'XHR Load': 19, + 'XHR Ready State Change': 1, +}; + describe('Performance: page execution timings audit', () => { it('should compute the correct pageExecutionTiming values', (done) => { - const artifacts = { + // acceptable trace + let artifacts = { traces: { [PageExecutionTimings.DEFAULT_PASS]: acceptableTrace, }, }; + let output = null; + const valueOf = name => Math.round(output.extendedInfo.value[name]); - const output = PageExecutionTimings.audit(artifacts); + output = PageExecutionTimings.audit(artifacts); assert.equal(output.details.items.length, 12); assert.equal(output.score, false); assert.equal(Math.round(output.rawValue), 611); - const valueOf = name => Math.round(output.extendedInfo.value[name]); - assert.equal(valueOf('Recalculate Style'), 170); - assert.equal(valueOf('Layout'), 138); - assert.equal(valueOf('Evaluate Script'), 131); - assert.equal(valueOf('Paint'), 52); - assert.equal(valueOf('DOM GC'), 33); - assert.equal(valueOf('Update Layer Tree'), 25); - assert.equal(valueOf('Compile Script'), 25); - assert.equal(valueOf('Parse HTML'), 14); - assert.equal(valueOf('Major GC'), 8); - assert.equal(valueOf('Minor GC'), 7); - assert.equal(valueOf('Composite Layers'), 6); - assert.equal(valueOf('Image Decode'), 1); + for (const category in output.extendedInfo.value) { + if (output.extendedInfo.value[category]) { + assert.equal(valueOf(category), acceptableTraceExpectations[category]); + } + } + // end acceptable trace + + // siteWithRedirects trace + artifacts = { + traces: { + [PageExecutionTimings.DEFAULT_PASS]: siteWithRedirectTrace, + }, + }; + output = PageExecutionTimings.audit(artifacts); + assert.equal(output.details.items.length, 13); + assert.equal(output.score, false); + assert.equal(Math.round(output.rawValue), 596); + + for (const category in output.extendedInfo.value) { + if (output.extendedInfo.value[category]) { + assert.equal(valueOf(category), siteWithRedirectTraceExpectations[category]); + } + } + // end siteWithRedirects trace + + // load trace + artifacts = { + traces: { + [PageExecutionTimings.DEFAULT_PASS]: loadTrace, + }, + }; + output = PageExecutionTimings.audit(artifacts); + assert.equal(output.details.items.length, 12); + assert.equal(output.score, false); + assert.equal(Math.round(output.rawValue), 524); + + for (const category in output.extendedInfo.value) { + if (output.extendedInfo.value[category]) { + assert.equal(valueOf(category), loadTraceExpectations[category]); + } + } + // end load trace done(); }); From f8a8fb27fd0bb08e832eec593bf539e13e8aa2b8 Mon Sep 17 00:00:00 2001 From: Ward Peeters Date: Fri, 3 Nov 2017 14:32:59 +0100 Subject: [PATCH 14/15] Apply paul's patch --- lighthouse-core/audits/mainthread-work-breakdown.js | 12 +++++++++--- 1 file changed, 9 insertions(+), 3 deletions(-) diff --git a/lighthouse-core/audits/mainthread-work-breakdown.js b/lighthouse-core/audits/mainthread-work-breakdown.js index 0dd563e4918a..d93afeba6f88 100644 --- a/lighthouse-core/audits/mainthread-work-breakdown.js +++ b/lighthouse-core/audits/mainthread-work-breakdown.js @@ -139,22 +139,28 @@ class PageExecutionTimings extends Audit { let totalExecutionTime = 0; const extendedInfo = {}; + const categoryTotals = {}; const results = Array.from(executionTimings).map(([eventName, duration]) => { totalExecutionTime += duration; extendedInfo[eventName] = duration; + const groupName = taskToGroup[eventName]; + + const categoryTotal = categoryTotals[groupName] || 0; + categoryTotals[groupName] = categoryTotal + duration; return { category: eventName, - group: taskToGroup[eventName], + group: groupName, duration: Util.formatMilliseconds(duration, 1), }; }); const headings = [ - {key: 'category', itemType: 'text', text: 'Category'}, - {key: 'group', itemType: 'text', text: 'Task Category'}, + {key: 'group', itemType: 'text', text: 'Category'}, + {key: 'category', itemType: 'text', text: 'Work'}, {key: 'duration', itemType: 'text', text: 'Time spent'}, ]; + results.stableSort((a, b) => categoryTotals[b.group] - categoryTotals[a.group]); const tableDetails = PageExecutionTimings.makeTableDetails(headings, results); return { From be50e6516820811dc62b190ccb6a7f03c5571421 Mon Sep 17 00:00:00 2001 From: Ward Peeters Date: Fri, 3 Nov 2017 14:43:24 +0100 Subject: [PATCH 15/15] Fix unit tests --- .../audits/mainthread-work-breakdown-test.js | 29 +++++++++---------- 1 file changed, 13 insertions(+), 16 deletions(-) diff --git a/lighthouse-core/test/audits/mainthread-work-breakdown-test.js b/lighthouse-core/test/audits/mainthread-work-breakdown-test.js index 2387a39d5dbc..40341692e2b6 100644 --- a/lighthouse-core/test/audits/mainthread-work-breakdown-test.js +++ b/lighthouse-core/test/audits/mainthread-work-breakdown-test.js @@ -71,17 +71,15 @@ const loadTraceExpectations = { }; describe('Performance: page execution timings audit', () => { - it('should compute the correct pageExecutionTiming values', (done) => { - // acceptable trace - let artifacts = { + it('should compute the correct pageExecutionTiming values for the pwa trace', () => { + const artifacts = { traces: { [PageExecutionTimings.DEFAULT_PASS]: acceptableTrace, }, }; - let output = null; + const output = PageExecutionTimings.audit(artifacts); const valueOf = name => Math.round(output.extendedInfo.value[name]); - output = PageExecutionTimings.audit(artifacts); assert.equal(output.details.items.length, 12); assert.equal(output.score, false); assert.equal(Math.round(output.rawValue), 611); @@ -91,15 +89,16 @@ describe('Performance: page execution timings audit', () => { assert.equal(valueOf(category), acceptableTraceExpectations[category]); } } - // end acceptable trace + }); - // siteWithRedirects trace - artifacts = { + it('should compute the correct pageExecutionTiming values for the redirect trace', () => { + const artifacts = { traces: { [PageExecutionTimings.DEFAULT_PASS]: siteWithRedirectTrace, }, }; - output = PageExecutionTimings.audit(artifacts); + const output = PageExecutionTimings.audit(artifacts); + const valueOf = name => Math.round(output.extendedInfo.value[name]); assert.equal(output.details.items.length, 13); assert.equal(output.score, false); assert.equal(Math.round(output.rawValue), 596); @@ -109,15 +108,16 @@ describe('Performance: page execution timings audit', () => { assert.equal(valueOf(category), siteWithRedirectTraceExpectations[category]); } } - // end siteWithRedirects trace + }); - // load trace - artifacts = { + it('should compute the correct pageExecutionTiming values for the load trace', () => { + const artifacts = { traces: { [PageExecutionTimings.DEFAULT_PASS]: loadTrace, }, }; - output = PageExecutionTimings.audit(artifacts); + const output = PageExecutionTimings.audit(artifacts); + const valueOf = name => Math.round(output.extendedInfo.value[name]); assert.equal(output.details.items.length, 12); assert.equal(output.score, false); assert.equal(Math.round(output.rawValue), 524); @@ -127,9 +127,6 @@ describe('Performance: page execution timings audit', () => { assert.equal(valueOf(category), loadTraceExpectations[category]); } } - // end load trace - - done(); }); it('should get no data when no events are present', () => {