Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

core(fr): colocate PerformanceObserver installation with wait logic #12365

Merged
merged 3 commits into from
Apr 14, 2021
Merged
Show file tree
Hide file tree
Changes from 2 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
9 changes: 0 additions & 9 deletions lighthouse-core/gather/driver.js
Original file line number Diff line number Diff line change
Expand Up @@ -899,15 +899,6 @@ class Driver {
`);
}

/**
* Install a performance observer that watches longtask timestamps for waitForCPUIdle.
* @return {Promise<void>}
*/
async registerPerformanceObserver() {
const scriptStr = `(${pageFunctions.registerPerformanceObserverInPageString})()`;
await this.evaluateScriptOnNewDocument(scriptStr);
}

/**
* Use a RequestIdleCallback shim for tests run with simulated throttling, so that the deadline can be used without
* a penalty
Expand Down
74 changes: 70 additions & 4 deletions lighthouse-core/gather/driver/wait-for-condition.js
Original file line number Diff line number Diff line change
Expand Up @@ -5,10 +5,11 @@
*/
'use strict';

/* global window */

const log = require('lighthouse-logger');
const LHError = require('../../lib/lh-error.js');
const ExecutionContext = require('./execution-context.js');
const pageFunctions = require('../../lib/page-functions.js');

/** @typedef {import('./network-monitor.js')} NetworkMonitor */
/** @typedef {import('./network-monitor.js').NetworkMonitorEvent} NetworkMonitorEvent */
Expand Down Expand Up @@ -221,7 +222,7 @@ function waitForCPUIdle(session, waitForCPUQuiet) {
async function checkForQuiet(executionContext, resolve) {
if (canceled) return;
const timeSinceLongTask =
await executionContext.evaluate(pageFunctions.checkTimeSinceLastLongTask, {args: []});
await executionContext.evaluate(checkTimeSinceLastLongTaskInPage, {args: []});
if (canceled) return;

if (typeof timeSinceLongTask === 'number') {
Expand All @@ -241,9 +242,12 @@ function waitForCPUIdle(session, waitForCPUQuiet) {
throw new Error('waitForCPUIdle.cancel() called before it was defined');
};

const executionContext = new ExecutionContext(session);
/** @type {Promise<void>} */
const promise = new Promise((resolve, reject) => {
checkForQuiet(new ExecutionContext(session), resolve).catch(reject);
executionContext.evaluate(registerPerformanceObserverInPage, {args: []})
.then(() => checkForQuiet(executionContext, resolve))
.catch(reject);
cancel = () => {
if (canceled) return;
canceled = true;
Expand All @@ -258,6 +262,69 @@ function waitForCPUIdle(session, waitForCPUQuiet) {
};
}

/* c8 ignore start */

/**
* This function is executed in the page itself when the document is first loaded.
*
* Used by _waitForCPUIdle and executed in the context of the page, updates the ____lastLongTask
* property on window to the end time of the last long task.
*/
function registerPerformanceObserverInPage() {
// Do not re-register if we've already run this script.
Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this is new

if (window.____lastLongTask === undefined) return;
patrickhulce marked this conversation as resolved.
Show resolved Hide resolved

window.____lastLongTask = window.__perfNow();
const observer = new window.PerformanceObserver(entryList => {
const entries = entryList.getEntries();
for (const entry of entries) {
if (entry.entryType === 'longtask') {
const taskEnd = entry.startTime + entry.duration;
window.____lastLongTask = Math.max(window.____lastLongTask || 0, taskEnd);
}
}
});

observer.observe({entryTypes: ['longtask'], buffered: true});
Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

as is the buffered flag which didn't exist when we originally wrote this when PerfObservers were brand new hotness :)

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this seems like a big fix?

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

not really that big. we previously installed it before even the document is available and we always assume that a longtask just happened so the likelihood of this catching anything new is very small.

now that we're registering slightly later in the page's lifecycle it makes more semantic sense, but again because of our assumption a longtask just happened on installation it doesn't make much of a difference in practice

}

/**
* This function is executed in the page itself.
*
* Used by _waitForCPUIdle and executed in the context of the page, returns time since last long task.
* @return {Promise<number>}
*/
function checkTimeSinceLastLongTaskInPage() {
// This function attempts to return the time since the last long task occurred.
// `PerformanceObserver`s don't always immediately fire though, so we check twice with some time in
// between to make sure nothing has happened very recently.

// Chrome 88 introduced heavy throttling of timers which means our `setTimeout` will be executed
// at some point farish (several hundred ms) into the future and the time at which it executes isn't
// a reliable indicator of long task existence, instead we check if any information has changed.
// See https://developer.chrome.com/blog/timer-throttling-in-chrome-88/
return new window.__nativePromise(resolve => {
const firstAttemptTs = window.__perfNow();
const firstAttemptLastLongTaskTs = window.____lastLongTask || 0;

setTimeout(() => {
// We can't be sure a long task hasn't occurred since our first attempt, but if the `____lastLongTask`
// value is the same (i.e. the perf observer didn't have any new information), we can be pretty
// confident that the long task info was accurate *at the time of our first attempt*.
const secondAttemptLastLongTaskTs = window.____lastLongTask || 0;
const timeSinceLongTask =
firstAttemptLastLongTaskTs === secondAttemptLastLongTaskTs
? // The time of the last long task hasn't changed, the information from our first attempt is accurate.
firstAttemptTs - firstAttemptLastLongTaskTs
: // The time of the last long task *did* change, we can't really trust the information we have.
0;
resolve(timeSinceLongTask);
}, 150);
});
}

/* c8 ignore stop */

/**
* Return a promise that resolves `pauseAfterLoadMs` after the load event
* fires and a method to cancel internal listeners and timeout.
Expand Down Expand Up @@ -294,7 +361,6 @@ function waitForLoadEvent(session, pauseAfterLoadMs) {
};
}


/**
* Returns whether the page appears to be hung.
* @param {LH.Gatherer.FRProtocolSession} session
Expand Down
1 change: 0 additions & 1 deletion lighthouse-core/gather/gather-runner.js
Original file line number Diff line number Diff line change
Expand Up @@ -133,7 +133,6 @@ class GatherRunner {
await driver.enableRuntimeEvents();
await driver.enableAsyncStacks();
await driver.cacheNatives();
await driver.registerPerformanceObserver();
await driver.dismissJavaScriptDialogs();
await driver.registerRequestIdleCallbackWrap(options.settings);
if (resetStorage) {
Expand Down
53 changes: 0 additions & 53 deletions lighthouse-core/lib/page-functions.js
Original file line number Diff line number Diff line change
Expand Up @@ -47,57 +47,6 @@ function wrapRuntimeEvalErrorInBrowser(err) {
};
}

/**
* Used by _waitForCPUIdle and executed in the context of the page, updates the ____lastLongTask
* property on window to the end time of the last long task.
*/
function registerPerformanceObserverInPage() {
window.____lastLongTask = window.__perfNow();
const observer = new window.PerformanceObserver(entryList => {
const entries = entryList.getEntries();
for (const entry of entries) {
if (entry.entryType === 'longtask') {
const taskEnd = entry.startTime + entry.duration;
window.____lastLongTask = Math.max(window.____lastLongTask || 0, taskEnd);
}
}
});

observer.observe({entryTypes: ['longtask']});
}

/**
* Used by _waitForCPUIdle and executed in the context of the page, returns time since last long task.
* @return {Promise<number>}
*/
function checkTimeSinceLastLongTask() {
// This function attempts to return the time since the last long task occurred.
// `PerformanceObserver`s don't always immediately fire though, so we check twice with some time in
// between to make sure nothing has happened very recently.

// Chrome 88 introduced heavy throttling of timers which means our `setTimeout` will be executed
// at some point farish (several hundred ms) into the future and the time at which it executes isn't
// a reliable indicator of long task existence, instead we check if any information has changed.
// See https://developer.chrome.com/blog/timer-throttling-in-chrome-88/
return new window.__nativePromise(resolve => {
const firstAttemptTs = window.__perfNow();
const firstAttemptLastLongTaskTs = window.____lastLongTask || 0;

setTimeout(() => {
// We can't be sure a long task hasn't occurred since our first attempt, but if the `____lastLongTask`
// value is the same (i.e. the perf observer didn't have any new information), we can be pretty
// confident that the long task info was accurate *at the time of our first attempt*.
const secondAttemptLastLongTaskTs = window.____lastLongTask || 0;
const timeSinceLongTask = firstAttemptLastLongTaskTs === secondAttemptLastLongTaskTs ?
// The time of the last long task hasn't changed, the information from our first attempt is accurate.
firstAttemptTs - firstAttemptLastLongTaskTs :
// The time of the last long task *did* change, we can't really trust the information we have.
0;
resolve(timeSinceLongTask);
}, 150);
});
}

/**
* @template {string} T
* @param {T} selector Optional simple CSS selector to filter nodes on.
Expand Down Expand Up @@ -577,8 +526,6 @@ const getNodeDetailsString = `function getNodeDetails(element) {
module.exports = {
wrapRuntimeEvalErrorInBrowserString: wrapRuntimeEvalErrorInBrowser.toString(),
wrapRuntimeEvalErrorInBrowser,
registerPerformanceObserverInPageString: registerPerformanceObserverInPage.toString(),
checkTimeSinceLastLongTask,
getElementsInDocument,
getElementsInDocumentString: getElementsInDocument.toString(),
getOuterHTMLSnippetString: getOuterHTMLSnippet.toString(),
Expand Down
3 changes: 0 additions & 3 deletions lighthouse-core/test/gather/fake-driver.js
Original file line number Diff line number Diff line change
Expand Up @@ -84,9 +84,6 @@ function makeFakeDriver({protocolGetVersionResponse}) {
getScrollPosition() {
return Promise.resolve(scrollPosition);
},
registerPerformanceObserver() {
return Promise.resolve();
},
beginTrace() {
return Promise.resolve();
},
Expand Down
1 change: 0 additions & 1 deletion lighthouse-core/test/gather/gather-runner-test.js
Original file line number Diff line number Diff line change
Expand Up @@ -341,7 +341,6 @@ describe('GatherRunner', function() {
enableAsyncStacks: asyncFunc,
cacheNatives: asyncFunc,
gotoURL: asyncFunc,
registerPerformanceObserver: asyncFunc,
registerRequestIdleCallbackWrap: asyncFunc,
cleanBrowserCaches: createCheck('calledCleanBrowserCaches'),
clearDataForOrigin: createCheck('calledClearStorage'),
Expand Down