Skip to content

Commit

Permalink
core(long-tasks): add startTime property (GoogleChrome#10942)
Browse files Browse the repository at this point in the history
  • Loading branch information
@patrickhulce
patrickhulce authored and George Martin committed Jul 6, 2020
1 parent d80c59c commit ac79a28
Show file tree
Hide file tree
Showing 5 changed files with 102 additions and 50 deletions.
1 change: 1 addition & 0 deletions lighthouse-cli/test/smokehouse/test-definitions/perf/expectations.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -192,6 +192,7 @@ module.exports = [
0: {
url: 'http://localhost:10200/perf/delayed-element.js',
duration: '>500',
startTime: '5000 +/- 5000', // make sure it's on the right time scale, but nothing more
},
},
},
Expand Down
37 changes: 33 additions & 4 deletions lighthouse-core/audits/long-tasks.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,11 @@ const NetworkRecords = require('../computed/network-records.js');
const i18n = require('../lib/i18n/i18n.js');
const MainThreadTasks = require('../computed/main-thread-tasks.js');
const BootupTime = require('./bootup-time.js');
const PageDependencyGraph = require('../computed/page-dependency-graph.js');
const LoadSimulator = require('../computed/load-simulator.js');

/** We don't always have timing data for short tasks, if we're missing timing data. Treat it as though it were 0ms. */
const DEFAULT_TIMING = {startTime: 0, endTime: 0, duration: 0};

const UIStrings = {
/** Title of a diagnostic LH audit that provides details on the longest running tasks that occur when the page loads. */
Expand Down Expand Up @@ -52,13 +57,33 @@ class LongTasks extends Audit {
const tasks = await MainThreadTasks.request(trace, context);
const devtoolsLog = artifacts.devtoolsLogs[LongTasks.DEFAULT_PASS];
const networkRecords = await NetworkRecords.request(devtoolsLog, context);
const multiplier = settings.throttlingMethod === 'simulate' ?
settings.throttling.cpuSlowdownMultiplier : 1;

/** @type {Map<LH.TraceEvent, LH.Gatherer.Simulation.NodeTiming>} */
const taskTimingsByEvent = new Map();

if (settings.throttlingMethod === 'simulate') {
const simulatorOptions = {trace, devtoolsLog, settings: context.settings};
const pageGraph = await PageDependencyGraph.request({trace, devtoolsLog}, context);
const simulator = await LoadSimulator.request(simulatorOptions, context);
const simulation = await simulator.simulate(pageGraph, {label: 'long-tasks-diagnostic'});
for (const [node, timing] of simulation.nodeTimings.entries()) {
if (node.type !== 'cpu') continue;
taskTimingsByEvent.set(node.event, timing);
}
} else {
for (const task of tasks) {
if (task.unbounded || task.parent) continue;
taskTimingsByEvent.set(task.event, task);
}
}

const jsURLs = BootupTime.getJavaScriptURLs(networkRecords);
// Only consider up to 20 long, top-level (no parent) tasks that have an explicit endTime
const longtasks = [...tasks]
.map(t => ({...t, duration: t.duration * multiplier}))
const longtasks = tasks
.map(t => {
const timing = taskTimingsByEvent.get(t.event) || DEFAULT_TIMING;
return {...t, duration: timing.duration, startTime: timing.startTime};
})
.filter(t => t.duration >= 50 && !t.unbounded && !t.parent)
.sort((a, b) => b.duration - a.duration)
.slice(0, 20);
Expand All @@ -67,12 +92,16 @@ class LongTasks extends Audit {
const results = longtasks.map(task => ({
url: BootupTime.getAttributableURLForTask(task, jsURLs),
duration: task.duration,
startTime: task.startTime,
}));

/** @type {LH.Audit.Details.Table['headings']} */
const headings = [
/* eslint-disable max-len */
{key: 'url', itemType: 'url', text: str_(i18n.UIStrings.columnURL)},
{key: 'startTime', itemType: 'ms', granularity: 1, text: str_(i18n.UIStrings.columnStartTime)},
{key: 'duration', itemType: 'ms', granularity: 1, text: str_(i18n.UIStrings.columnDuration)},
/* eslint-enable max-len */
];

const tableDetails = Audit.makeTableDetails(headings, results);
Expand Down
5 changes: 4 additions & 1 deletion lighthouse-core/lib/dependency-graph/simulator/simulator.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -82,6 +82,9 @@ class Simulator {
this._dns = new DNSCache({rtt: this._rtt});
// @ts-ignore
this._connectionPool = /** @type {ConnectionPool} */ (null);

if (!Number.isFinite(this._rtt)) throw new Error(`Invalid rtt ${this._rtt}`);
if (!Number.isFinite(this._throughput)) throw new Error(`Invalid rtt ${this._throughput}`);
}

/** @return {number} */
Expand Down Expand Up @@ -487,7 +490,7 @@ class Simulator {

// While this is no longer strictly necessary, it's always better than LH hanging
if (!Number.isFinite(minimumTime) || iteration > 100000) {
throw new Error('Graph creation failed, depth exceeded');
throw new Error('Simulation failed, depth exceeded');
}

iteration++;
Expand Down
86 changes: 46 additions & 40 deletions lighthouse-core/test/audits/long-tasks-test.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -7,9 +7,10 @@

const LongTasks = require('../../audits/long-tasks.js');
const createTestTrace = require('../create-test-trace.js');
const devtoolsLog = require('../fixtures/traces/progressive-app-m60.devtools.log.json');
const networkRecordsToDevtoolsLog = require('../network-records-to-devtools-log.js');

const TASK_URL = 'https://pwa.rocks/';
const BASE_TS = 12345e3;
const TASK_URL = 'https://pwa.rocks';

/* eslint-env jest */

Expand All @@ -19,8 +20,7 @@ const TASK_URL = 'https://pwa.rocks/';
* @param {Boolean} withChildTasks
*/
function generateTraceWithLongTasks({count, duration = 200, withChildTasks = false}) {
const baseTs = 1000;
const traceTasks = [];
const traceTasks = [{ts: BASE_TS, duration: 0}];
for (let i = 1; i <= count; i++) {
/* Generates a top-level task w/ the following breakdown:
task -> {
Expand All @@ -31,7 +31,7 @@ function generateTraceWithLongTasks({count, duration = 200, withChildTasks = fal
Child tasks should start after the parent task and end before it.
Top-level tasks will take on the attributable URL from it's children.
*/
const ts = baseTs * i;
const ts = BASE_TS + i * 1000;
const task = {ts, duration};
task.children = [];
if (withChildTasks) {
Expand All @@ -50,18 +50,21 @@ function generateTraceWithLongTasks({count, duration = 200, withChildTasks = fal
}
return createTestTrace({
topLevelTasks: traceTasks,
navigationStart: BASE_TS,
});
}

describe('Long tasks audit', () => {
const devtoolsLog = networkRecordsToDevtoolsLog([{url: TASK_URL}]);

it('should pass and be non-applicable if there are no long tasks', async () => {
const artifacts = {
traces: {defaultPass: generateTraceWithLongTasks({count: 0})},
devtoolsLogs: {defaultPass: devtoolsLog},
};
const result = await LongTasks.audit(artifacts, {computedCache: new Map()});
expect(result.score).toBe(1);
expect(result.details.items).toHaveLength(0);
expect(result.score).toBe(1);
expect(result.displayValue).toBeUndefined();
expect(result.notApplicable).toBeTruthy();
});
Expand All @@ -72,67 +75,74 @@ describe('Long tasks audit', () => {
devtoolsLogs: {defaultPass: devtoolsLog},
};
const result = await LongTasks.audit(artifacts, {computedCache: new Map()});
expect(result.details.items).toMatchObject([
{url: 'Unattributable', duration: 200, startTime: 1000},
{url: 'Unattributable', duration: 200, startTime: 2000},
{url: 'Unattributable', duration: 200, startTime: 3000},
{url: 'Unattributable', duration: 200, startTime: 4000},
]);
expect(result.score).toBe(0);
expect(result.details.items).toHaveLength(4);
expect(result.displayValue).toBeDisplayString('4 long tasks found');
expect(result.notApplicable).toBeFalsy();

for (const item of result.details.items) {
expect(Number.isFinite(item.duration)).toBeTruthy();
expect(item.duration).toEqual(200);
expect(item.url).toEqual('Unattributable');
}
});

it('should filter out tasks with duration less than 50 ms', async () => {
const trace = createTestTrace({
navigationStart: BASE_TS,
topLevelTasks: [
{ts: 1000, duration: 30},
{ts: 2000, duration: 100},
{ts: 3000, duration: 25},
{ts: 4000, duration: 50},
{ts: BASE_TS, duration: 1},
{ts: BASE_TS + 1000, duration: 30},
{ts: BASE_TS + 2000, duration: 100},
{ts: BASE_TS + 3000, duration: 25},
{ts: BASE_TS + 4000, duration: 50},
],
});
const artifacts = {
traces: {defaultPass: trace},
devtoolsLogs: {defaultPass: devtoolsLog},
};

const result = await LongTasks.audit(artifacts, {computedCache: new Map()});
expect(result.details.items).toMatchObject([
{url: 'Unattributable', duration: 100, startTime: 2000},
{url: 'Unattributable', duration: 50, startTime: 4000},
]);
expect(result.score).toBe(0);
expect(result.details.items).toHaveLength(2);
expect(result.displayValue).toBeDisplayString('2 long tasks found');

for (const item of result.details.items) {
expect(Number.isFinite(item.duration)).toBeTruthy();
expect(item.duration).toBeGreaterThanOrEqual(50);
expect(item.url).toEqual('Unattributable');
}
});

it('should not filter out tasks with duration >= 50 ms only after throttling', async () => {
const artifacts = {
traces: {defaultPass: generateTraceWithLongTasks({count: 4, duration: 45})},
devtoolsLogs: {defaultPass: devtoolsLog},
traces: {defaultPass: generateTraceWithLongTasks({count: 4, duration: 25})},
devtoolsLogs: {defaultPass: networkRecordsToDevtoolsLog([
{url: TASK_URL, timing: {connectEnd: 50, connectStart: 0.01, sslStart: 25, sslEnd: 40}},
])},
};
const context = {
computedCache: new Map(),
settings: {
precomputedLanternData: {
additionalRttByOrigin: {[TASK_URL]: 0},
serverResponseTimeByOrigin: {[TASK_URL]: 100},
},
throttlingMethod: 'simulate',
throttling: {
cpuSlowdownMultiplier: 2,
rttMs: 100,
throughputKbps: 10000,
cpuSlowdownMultiplier: 4,
},
},
};
const result = await LongTasks.audit(artifacts, context);
expect(result.details.items).toMatchObject([
{duration: 100, startTime: 600},
{duration: 100, startTime: 700},
{duration: 100, startTime: 800},
{duration: 100, startTime: 900},
]);
expect(result.score).toBe(0);
expect(result.details.items).toHaveLength(4);
expect(result.displayValue).toBeDisplayString('4 long tasks found');

for (const item of result.details.items) {
expect(Number.isFinite(item.duration)).toBeTruthy();
expect(item.duration).toEqual(90);
expect(item.url).toEqual('Unattributable');
}
});

it('should populate url when tasks have an attributable url', async () => {
Expand All @@ -142,14 +152,10 @@ describe('Long tasks audit', () => {
devtoolsLogs: {defaultPass: devtoolsLog},
};
const result = await LongTasks.audit(artifacts, {computedCache: new Map()});
expect(result.details.items).toMatchObject([
{url: TASK_URL, duration: 300, startTime: 1000},
]);
expect(result.score).toBe(0);
expect(result.details.items).toHaveLength(1);
expect(result.displayValue).toBeDisplayString('1 long task found');

for (const item of result.details.items) {
expect(Number.isFinite(item.duration)).toBeTruthy();
expect(item.duration).toBeGreaterThanOrEqual(50);
expect(item.url).toEqual(TASK_URL);
}
});
});
23 changes: 18 additions & 5 deletions lighthouse-core/test/results/sample_v2.json
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1811,6 +1811,12 @@
"itemType": "url",
"text": "URL"
},
{
"key": "startTime",
"itemType": "ms",
"granularity": 1,
"text": "Start Time"
},
{
"key": "duration",
"itemType": "ms",
Expand All @@ -1821,19 +1827,23 @@
"items": [
{
"url": "http://localhost:10200/dobetterweb/dbw_tester.js",
"duration": 983.081
"duration": 983.081,
"startTime": 2854.095
},
{
"url": "http://ajax.googleapis.com/ajax/libs/jquery/2.1.1/jquery.min.js",
"duration": 127.282
"duration": 127.282,
"startTime": 4808.602
},
{
"url": "Unattributable",
"duration": 123.752
"duration": 123.752,
"startTime": 3839.839
},
{
"url": "http://localhost:10200/zone.js",
"duration": 96.198
"duration": 96.198,
"startTime": 3996.134
}
]
}
Expand Down Expand Up @@ -6477,9 +6487,12 @@
"path": "audits[long-tasks].displayValue"
}
],
"lighthouse-core/lib/i18n/i18n.js | columnDuration": [
"lighthouse-core/lib/i18n/i18n.js | columnStartTime": [
"audits[long-tasks].details.headings[1].text"
],
"lighthouse-core/lib/i18n/i18n.js | columnDuration": [
"audits[long-tasks].details.headings[2].text"
],
"lighthouse-core/audits/manual/pwa-cross-browser.js | title": [
"audits[pwa-cross-browser].title"
],
Expand Down

0 comments on commit ac79a28

Please sign in to comment.