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.

Sign up for GitHub

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(driver): handle promise rejections from sendCommand #6739

Merged
merged 8 commits into from
Dec 13, 2018
Merged

core(driver): handle promise rejections from sendCommand #6739

Changes from 7 commits
Commits
Show all changes
8 commits
Select commit Hold shift + click to select a range
55165e8
Handle promise rejections from SendCommand.
exterkamp Dec 6, 2018
c5ae03e
Moved checkForQuiet catch to outside function. Thx Patrick!
exterkamp Dec 6, 2018
3d64d5d
Use Promise.resolve() instead of resolve().
exterkamp Dec 6, 2018
773e4f7
Brendan's async refactor suggestion!
exterkamp Dec 11, 2018
ab932b4
Removed old comments.
exterkamp Dec 11, 2018
85bda02
I got overzealous in my changes.
exterkamp Dec 11, 2018
76a4046
Awaited Page.navigate and cleaned up if-else.
exterkamp Dec 11, 2018
b1fd5b6
Comment nits.
exterkamp Dec 13, 2018
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
50 changes: 23 additions & 27 deletions lighthouse-core/gather/driver.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -628,33 +628,31 @@ class Driver {
/**
* @param {Driver} driver
* @param {() => void} resolve
* @return {Promise<void>}
*/
function checkForQuiet(driver, resolve) {
async function checkForQuiet(driver, resolve) {
if (cancelled) return;
const timeSinceLongTask = await driver.evaluateAsync(checkForQuietExpression);
if (cancelled) return;

return driver.evaluateAsync(checkForQuietExpression)
.then(timeSinceLongTask => {
if (cancelled) return;

if (typeof timeSinceLongTask === 'number') {
if (timeSinceLongTask >= waitForCPUQuiet) {
log.verbose('Driver', `CPU has been idle for ${timeSinceLongTask} ms`);
resolve();
} else {
log.verbose('Driver', `CPU has been idle for ${timeSinceLongTask} ms`);
const timeToWait = waitForCPUQuiet - timeSinceLongTask;
lastTimeout = setTimeout(() => checkForQuiet(driver, resolve), timeToWait);
}
}
});
if (typeof timeSinceLongTask === 'number') {
if (timeSinceLongTask >= waitForCPUQuiet) {
log.verbose('Driver', `CPU has been idle for ${timeSinceLongTask} ms`);
resolve();
} else {
log.verbose('Driver', `CPU has been idle for ${timeSinceLongTask} ms`);
const timeToWait = waitForCPUQuiet - timeSinceLongTask;
lastTimeout = setTimeout(() => checkForQuiet(driver, resolve), timeToWait);
}
}
}

/** @type {(() => void)} */
let cancel = () => {
throw new Error('_waitForCPUIdle.cancel() called before it was defined');
};
const promise = new Promise((resolve, reject) => {
checkForQuiet(this, resolve);
const promise = new Promise(async (resolve, reject) => {
checkForQuiet(this, resolve).catch(reject);
cancel = () => {
cancelled = true;
if (lastTimeout) clearTimeout(lastTimeout);
Expand Down Expand Up @@ -890,19 +888,14 @@ class Driver {
await this._beginNetworkStatusMonitoring(url);
await this._clearIsolatedContextId();

// These can 'race' and that's OK.
// We don't want to wait for Page.navigate's resolution, as it can now
// happen _after_ onload: https://crbug.com/768961
this.sendCommand('Page.enable');
this.sendCommand('Emulation.setScriptExecutionDisabled', {value: disableJS});
await this.sendCommand('Page.enable');
Copy link
Member Author

Choose a reason for hiding this comment

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

Is it okay to await these? The comments above them talk about racing like this might be purposefully not-awaited.

Copy link
Collaborator

Choose a reason for hiding this comment

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

Bug is marked as fixed now. If it truly is, can you also remove the comments?

Copy link
Collaborator

Choose a reason for hiding this comment

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

the big bug was definitely about not awaiting Page.navigate, but why are we needing to await these? is it just about unhandled rejections?

Copy link
Collaborator

Choose a reason for hiding this comment

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

could still timeout on any protocol command. what happens in the underlying connection dies? we should avoid any possible unhandled rejection.

But await each command isn't the only way to avoid unhandled rejections here. wdyt of just tacking a catch on Page.enable, or combining the two commands like this:

await Promise.all([
this.sendCommand('Page.enable'),
this.sendCommand('Emulation.setScriptExecutionDisabled', {value: disableJS}),
])

so that it's one less event loop iteration ?

Copy link
Collaborator

Choose a reason for hiding this comment

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

right I'm onboard with that, but I'm asking because there are then other things we might try instead of serialling awaiting like this._sendAndSilentlyIgnoreErrors or something :)

It looks like we used to be just fine waiting on these in sequence though, and the Page.navigate change just moved all of 'em to be together, so we don't need to go crazy avoiding the await #3413

I'm a tad spooked by this given that it was a real nasty bug to hunt down, but I think this makes sense if the bug really is fixed. +1 to removing the comments if we're making this change

Copy link
Collaborator

@connorjclark connorjclark Dec 6, 2018 •
edited
Loading

Choose a reason for hiding this comment

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

_innerSendCommand is specifically for when you don't want to timeout.

I'm not sure if _innerSendCommand can ever reject. You could try setting a breakpoint just before, then kill Chrome, then hit play, and see what happens ... But if I read the code correctly for how the connection works, it won't ever result in a rejected promise - just a stalled one.

Copy link
Collaborator

@patrickhulce patrickhulce Dec 6, 2018 •
edited
Loading

Choose a reason for hiding this comment

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

Or I guess sendCommand is never the real problem it's always the PROTOCOL_TIMEOUT that's the real problem?

You guys beat me to the punch you're already on it 👍 😄

Copy link
Member

Choose a reason for hiding this comment

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

maybe I'm not following the conversation correctly here, but _innerSendCommand can reject via connection:

lighthouse/lighthouse-core/gather/connections/connection.js

Lines 120 to 124 in 9ebf069

return callback.resolve(Promise.resolve().then(_ => {
if (object.error) {
log.formatProtocol('method <= browser ERR', {method: callback.method}, 'error');
throw LHError.fromProtocolMessage(callback.method, object.error);
}

(throwing inside Promise.resolve().then(_ => {/* throw */}) rejects it, then callback.resolve() with a rejected promise rejects as well. We could probably make that a lot more understandable with an explicit callback.resolve or callback.reject, as well as using an async function for the inner part)

Copy link
Member

Choose a reason for hiding this comment

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

so do we want to add an empty catch to the this._innerSendCommand('Page.navigate', {url}); line? Or are we assuming it's so rare that it's ok that a unhandledRejection listener can catch it?

Copy link
Member Author

Choose a reason for hiding this comment

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

Since it seems like this never happens, should we just let sleeping dragons lie?

await this.sendCommand('Emulation.setScriptExecutionDisabled', {value: disableJS});
// No timeout needed for Page.navigate. See #6413.
this._innerSendCommand('Page.navigate', {url});
const waitforPageNavigateCmd = this._innerSendCommand('Page.navigate', {url});

if (waitForNavigated) {
await this._waitForFrameNavigated();
}

if (waitForLoad) {
} else if (waitForLoad) {
Copy link
Member

Choose a reason for hiding this comment

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

👍

const passConfig = /** @type {Partial<LH.Config.Pass>} */ (passContext.passConfig || {});
let {pauseAfterLoadMs, networkQuietThresholdMs, cpuQuietThresholdMs} = passConfig;
let maxWaitMs = passContext.settings && passContext.settings.maxWaitForLoad;
Expand All @@ -918,6 +911,9 @@ class Driver {
maxWaitMs);
}

// Awaiting so that errors can be properly processed.
Copy link
Collaborator

Choose a reason for hiding this comment

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

nit: while this comment makes total sense in the context of this PR, I can definitely see myself coming back in a year and being like "what?" maybe a link to this PR or a tad more explanation?

Copy link
Member

Choose a reason for hiding this comment

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

good call. Maybe even just something like // Bring any 'Page.navigate' errors back into the promise chain. and a link back here.

The comment above the Page.navigate command isn't terribly helpful either, but I don't have a great suggestion :)

await waitforPageNavigateCmd;
Copy link
Collaborator

Choose a reason for hiding this comment

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

there's nothing in _endNetworkStatusMonitoring we need, right?

Copy link
Member

Choose a reason for hiding this comment

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

there's nothing in _endNetworkStatusMonitoring we need, right?

it returns the finalUrl after redirects, which is used for updating passContext (and eventually the artifact).

A little too convoluted but somewhat difficult to fix since networkRecords don't entirely exist by that point.


return this._endNetworkStatusMonitoring();
}

Expand Down