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: add timeout to all protocol commands #6347

Merged
merged 5 commits into from
Oct 24, 2018
Merged
Show file tree
Hide file tree
Changes from 1 commit
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
145 changes: 72 additions & 73 deletions lighthouse-core/gather/driver.js
Original file line number Diff line number Diff line change
Expand Up @@ -29,6 +29,8 @@ const DEFAULT_PAUSE_AFTER_LOAD = 0;
const DEFAULT_NETWORK_QUIET_THRESHOLD = 5000;
// Controls how long to wait between longtasks before determining the CPU is idle, off by default
const DEFAULT_CPU_QUIET_THRESHOLD = 0;
// Controls how long to wait for a response after sending a DevTools protocol command.
const DEFAULT_PROTOCOL_TIMEOUT = 5000;

/**
* @typedef {LH.Protocol.StrictEventEmitter<LH.CrdpEvents>} CrdpEventEmitter
Expand Down Expand Up @@ -85,6 +87,12 @@ class Driver {
* @private
*/
this._lastSecurityState = null;

/**
* @type {number}
* @private
*/
this._protocolTimeout = DEFAULT_PROTOCOL_TIMEOUT;
}

static get traceCategories() {
Expand Down Expand Up @@ -142,6 +150,13 @@ class Driver {
return this.evaluateAsync(`(${pageFunctions.ultradumbBenchmarkString})()`);
}

/**
* @param {number} timeout
*/
setProtocolTimeout(timeout) {
this._protocolTimeout = timeout;
Copy link
Collaborator

Choose a reason for hiding this comment

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

I afraid we'll need to make timeout a setting on sendCommand with a global default :/

Copy link
Collaborator Author

@connorjclark connorjclark Oct 19, 2018

Choose a reason for hiding this comment

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

We can move to that if it's really needed. It could complicate usage quite a bit, that + the unique typing on the method, I think the best option would be this:

/**
 * Call protocol methods.
 * @template {keyof LH.CrdpCommands} C
 * @param {C|{method: C, timeout: number}} methodOrOpts
 * @param {LH.CrdpCommands[C]['paramsType']} params,
 * @return {Promise<LH.CrdpCommands[C]['returnType']>}
 */
sendCommand(methodOrOpts, ...params) {
  const {method, timeout} = typeof methodOrOpts === 'object' ? methodOrOpts : {
    method: methodOrOpts,
    timeout: DEFAULT_PROTOCOL_TIMEOUT
  }
}

That way, the calling code for most use cases can remain the same.

}

/**
* @return {Promise<void>}
*/
Expand Down Expand Up @@ -255,8 +270,20 @@ class Driver {
return Promise.resolve();
}
}

return this._connection.sendCommand(method, ...params);
return new Promise((resolve, reject) => {
const asyncTimeout = setTimeout((_ => {
const err = new LHError(LHError.errors.PROTOCOL_TIMEOUT);
err.message += ` Method: ${method}`;
reject(err);
}), this._protocolTimeout);
this._connection.sendCommand(method, ...params).then(result => {
clearTimeout(asyncTimeout);
resolve(result);
}).catch(err => {
clearTimeout(asyncTimeout);
reject(err);
});
});
Copy link
Member

Choose a reason for hiding this comment

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

maybe drop keep the promise just to the thing that has to be a promise? e.g.

return new Promise(async (resolve, reject) => {
  const asyncTimeout = setTimeout((_ => {
    const err = new LHError(LHError.errors.PROTOCOL_TIMEOUT);
    err.message += ` Method: ${method}`;
    reject(err);
  }), this._protocolTimeout);

  try {
    const result = await this._connection.sendCommand(method, ...params);
    clearTimeout(asyncTimeout);
    resolve(result);
  } catch (err) {
    clearTimeout(asyncTimeout);
    reject(err);
  }
});

}

/**
Expand Down Expand Up @@ -306,61 +333,45 @@ class Driver {
* @param {number|undefined} contextId
* @return {Promise<*>}
*/
_evaluateInContext(expression, contextId) {
return new Promise((resolve, reject) => {
// If this gets to 60s and it hasn't been resolved, reject the Promise.
const asyncTimeout = setTimeout(
(_ => reject(new Error('The asynchronous expression exceeded the allotted time of 60s'))),
60000
);

const evaluationParams = {
// We need to explicitly wrap the raw expression for several purposes:
// 1. Ensure that the expression will be a native Promise and not a polyfill/non-Promise.
// 2. Ensure that errors in the expression are captured by the Promise.
// 3. Ensure that errors captured in the Promise are converted into plain-old JS Objects
// so that they can be serialized properly b/c JSON.stringify(new Error('foo')) === '{}'
expression: `(function wrapInNativePromise() {
const __nativePromise = window.__nativePromise || Promise;
const URL = window.__nativeURL || window.URL;
return new __nativePromise(function (resolve) {
return __nativePromise.resolve()
.then(_ => ${expression})
.catch(${pageFunctions.wrapRuntimeEvalErrorInBrowserString})
.then(resolve);
});
}())`,
includeCommandLineAPI: true,
awaitPromise: true,
returnByValue: true,
contextId,
};

this.sendCommand('Runtime.evaluate', evaluationParams).then(response => {
clearTimeout(asyncTimeout);

if (response.exceptionDetails) {
// An error occurred before we could even create a Promise, should be *very* rare
return reject(new Error(`Evaluation exception: ${response.exceptionDetails.text}`));
}

// Protocol should always return a 'result' object, but it is sometimes undefined. See #6026.
if (response.result === undefined) {
return reject(new Error('Runtime.evaluate response did not contain a "result" object'));
}

const value = response.result.value;
async _evaluateInContext(expression, contextId) {
Copy link
Collaborator Author

Choose a reason for hiding this comment

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

VSCode suggested this could be async, so I let it :) Thoughts on changing asynchronous syntax? FWIW, V8 just improved the performance of await to match Promises.

Copy link
Member

Choose a reason for hiding this comment

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

Thoughts on changing asynchronous syntax?

Totally fine. Since we adopted Node 8 as the base requirement we've mostly just followed the rule of only changing from Promises to async/await when we're touching the code for some other reason (see initial discussion in #3742), but to convert (or not) at will if that's the case.

We have some tricky uses of promises (see #6343 :) that need real review, which mass changes make difficult, especially since the indentation level changes and the git diffs end up not always the best, even when ignoring whitespace. We (I?) also end up using git blame a lot, and random changes in unrelated PRs make that annoying :)

It's definitely a fuzzy line, though, and sometimes drive by fixes are great.

Copy link
Member

Choose a reason for hiding this comment

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

(This case is totally different, though, because it's fundamentally changing anyways, so it's a prime candidate for fixing.)

const evaluationParams = {
// We need to explicitly wrap the raw expression for several purposes:
// 1. Ensure that the expression will be a native Promise and not a polyfill/non-Promise.
// 2. Ensure that errors in the expression are captured by the Promise.
// 3. Ensure that errors captured in the Promise are converted into plain-old JS Objects
// so that they can be serialized properly b/c JSON.stringify(new Error('foo')) === '{}'
expression: `(function wrapInNativePromise() {
const __nativePromise = window.__nativePromise || Promise;
const URL = window.__nativeURL || window.URL;
return new __nativePromise(function (resolve) {
return __nativePromise.resolve()
.then(_ => ${expression})
.catch(${pageFunctions.wrapRuntimeEvalErrorInBrowserString})
.then(resolve);
});
}())`,
includeCommandLineAPI: true,
awaitPromise: true,
returnByValue: true,
contextId,
};

if (value && value.__failedInBrowser) {
return reject(Object.assign(new Error(), value));
} else {
resolve(value);
}
}).catch(err => {
clearTimeout(asyncTimeout);
reject(err);
});
});
const response = await this.sendCommand('Runtime.evaluate', evaluationParams);
connorjclark marked this conversation as resolved.
Show resolved Hide resolved
if (response.exceptionDetails) {
// An error occurred before we could even create a Promise, should be *very* rare
return Promise.reject(new Error(`Evaluation exception: ${response.exceptionDetails.text}`));
}
// Protocol should always return a 'result' object, but it is sometimes undefined. See #6026.
if (response.result === undefined) {
return Promise.reject(
new Error('Runtime.evaluate response did not contain a "result" object'));
}
const value = response.result.value;
if (value && value.__failedInBrowser) {
return Promise.reject(Object.assign(new Error(), value));
} else {
return value;
}
}

/**
Expand Down Expand Up @@ -860,27 +871,15 @@ class Driver {
* Return the body of the response with the given ID. Rejects if getting the
* body times out.
* @param {string} requestId
* @param {number} [timeout]
* @return {Promise<string>}
*/
getRequestContent(requestId, timeout = 1000) {
async getRequestContent(requestId) {
requestId = NetworkRequest.getRequestIdForBackend(requestId);

return new Promise((resolve, reject) => {
// If this takes more than 1s, reject the Promise.
// Why? Encoding issues can lead to hanging getResponseBody calls: https://github.com/GoogleChrome/lighthouse/pull/4718
const err = new LHError(LHError.errors.REQUEST_CONTENT_TIMEOUT);
const asyncTimeout = setTimeout((_ => reject(err)), timeout);

this.sendCommand('Network.getResponseBody', {requestId}).then(result => {
clearTimeout(asyncTimeout);
// Ignoring result.base64Encoded, which indicates if body is already encoded
resolve(result.body);
}).catch(e => {
clearTimeout(asyncTimeout);
reject(e);
});
});
// Encoding issues may lead to hanging getResponseBody calls: https://github.com/GoogleChrome/lighthouse/pull/4718
// driver.sendCommand will handle timeout after 5s.
Copy link
Collaborator

Choose a reason for hiding this comment

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

Can we keep this at 1s? expanding to 5 could dramatically slow down the failure case when 3 of these go wrong :/

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

ok, I put it back to 1s

const result = await this.sendCommand('Network.getResponseBody', {requestId});
return result.body;
}

async listenForSecurityStateChanges() {
Expand Down
14 changes: 8 additions & 6 deletions lighthouse-core/lib/lh-error.js
Original file line number Diff line number Diff line change
Expand Up @@ -169,17 +169,19 @@ const ERRORS = {
lhrRuntimeError: true,
},

// Protocol timeout failures
REQUEST_CONTENT_TIMEOUT: {
code: 'REQUEST_CONTENT_TIMEOUT',
message: strings.requestContentTimeout,
},

// URL parsing failures
INVALID_URL: {
code: 'INVALID_URL',
message: strings.urlInvalid,
},

// Protocol timeout failures
PROTOCOL_TIMEOUT: {
code: 'PROTOCOL_TIMEOUT',
message: strings.protocolTimeout,
connorjclark marked this conversation as resolved.
Show resolved Hide resolved
},

// Hey! When adding a new error type, update lighthouse-result.proto too.
Copy link
Collaborator

Choose a reason for hiding this comment

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

❤️

};

/** @type {Record<keyof typeof ERRORS, LighthouseErrorDefinition>} */
Expand Down
1 change: 1 addition & 0 deletions lighthouse-core/lib/strings.js
Original file line number Diff line number Diff line change
Expand Up @@ -15,4 +15,5 @@ module.exports = {
internalChromeError: `An internal Chrome error occurred. Please restart Chrome and try re-running Lighthouse.`,
requestContentTimeout: 'Fetching resource content has exceeded the allotted time',
urlInvalid: `The URL you have provided appears to be invalid.`,
protocolTimeout: `Waiting for DevTools protocol response has exceeded the allotted time.`,
};
6 changes: 4 additions & 2 deletions lighthouse-core/test/gather/driver-test.js
Original file line number Diff line number Diff line change
Expand Up @@ -110,6 +110,8 @@ connection.sendCommand = function(command, params) {
}
};

driverStub.setProtocolTimeout(MAX_WAIT_FOR_PROTOCOL);

/* eslint-env jest */

describe('Browser Driver', () => {
Expand Down Expand Up @@ -162,10 +164,10 @@ describe('Browser Driver', () => {
});

it('throws if getRequestContent takes too long', () => {
return driverStub.getRequestContent('', MAX_WAIT_FOR_PROTOCOL).then(_ => {
return driverStub.getRequestContent('').then(_ => {
assert.ok(false, 'long-running getRequestContent supposed to reject');
}, e => {
assert.equal(e.code, 'REQUEST_CONTENT_TIMEOUT');
assert.equal(e.code, 'PROTOCOL_TIMEOUT');
});
});

Expand Down
4 changes: 4 additions & 0 deletions proto/lighthouse-result.proto
Original file line number Diff line number Diff line change
Expand Up @@ -42,6 +42,10 @@ enum LighthouseError {
PARSING_PROBLEM = 15;
// The trace data failed to stream over the protocol.
READ_FAILED = 16;
// Used when security error prevents page load.
INSECURE_DOCUMENT_REQUEST = 17;
connorjclark marked this conversation as resolved.
Show resolved Hide resolved
// Used when security error prevents page load.
PROTOCOL_TIMEOUT = 18;
Copy link
Collaborator Author

@connorjclark connorjclark Oct 19, 2018

Choose a reason for hiding this comment

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

I removed REQUEST_CONTENT_TIMEOUT ... instead of making a new enum value for PROTOCOL_TIMEOUT, could we just reuse REQUEST_CONTENT_TIMEOUT's enum (rename it)? Would that be OK for proto compat?

Copy link
Member

Choose a reason for hiding this comment

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

nope, can't rename.

But actually looks like we never exposed REQUEST_CONTENT_TIMEOUT in the proto. So I think we're OK. :)

}

// The overarching Lighthouse Response object (LHR)
Expand Down