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

Preserve error stack when timing out a promise #13332

Closed
2 tasks done
BR0kEN- opened this issue Nov 6, 2021 · 0 comments
Closed
2 tasks done

Preserve error stack when timing out a promise #13332

BR0kEN- opened this issue Nov 6, 2021 · 0 comments
Assignees

Comments

@BR0kEN-
Copy link
Contributor

BR0kEN- commented Nov 6, 2021

FAQ

URL

not applicable

What happened?

There is a typical technique to create a timeable promise via Promise.race. The lighthouse-core uses it in several places:

const timeoutMs = this.getNextProtocolTimeout();
this._nextProtocolTimeout = undefined;
/** @type {NodeJS.Timer|undefined} */
let timeout;
const timeoutPromise = new Promise((resolve, reject) => {
if (timeoutMs === Infinity) return;
timeout = setTimeout((() => {
const err = new LHError(LHError.errors.PROTOCOL_TIMEOUT, {protocolMethod: method});
reject(err);
}), timeoutMs);
});
const resultPromise = this._session.send(method, ...params);
const resultWithTimeoutPromise = Promise.race([resultPromise, timeoutPromise]);
return resultWithTimeoutPromise.finally(() => {
if (timeout) clearTimeout(timeout);
});

const timeout = this._nextProtocolTimeout;
this._nextProtocolTimeout = DEFAULT_PROTOCOL_TIMEOUT;
/** @type {NodeJS.Timer|undefined} */
let asyncTimeout;
const timeoutPromise = new Promise((resolve, reject) => {
if (timeout === Infinity) return;
asyncTimeout = setTimeout((() => {
const err = new LHError(
LHError.errors.PROTOCOL_TIMEOUT,
{protocolMethod: method}
);
reject(err);
}), timeout);
});
return Promise.race([
this._innerSendCommand(method, sessionId, ...params),
timeoutPromise,
]).finally(() => {
asyncTimeout && clearTimeout(asyncTimeout);
});

const startTime = Date.now();
/** @type {NodeJS.Timeout} */
let timeoutHandle;
const timeoutPromise = new Promise((_, reject) => {
timeoutHandle = setTimeout(() => {
reject(new Error('Timed out fetching resource'));
}, options.timeout);
});
const responsePromise = this._loadNetworkResource(url);
/** @type {{stream: LH.Crdp.IO.StreamHandle|null, status: number|null}} */
const response = await Promise.race([responsePromise, timeoutPromise])
.finally(() => clearTimeout(timeoutHandle));
const isOk = response.status && response.status >= 200 && response.status <= 299;
if (!response.stream || !isOk) return {status: response.status, content: null};
const timeout = options.timeout - (Date.now() - startTime);
const content = await this._readIOStream(response.stream, {timeout});
return {status: response.status, content};

Each implementation listed above has a flaw, preventing to preserve the stack of the error if it's thrown. Example:

LighthouseError [LHError]: PROTOCOL_TIMEOUT
    at Timeout.<anonymous> (/crawler/node_modules/lighthouse/lighthouse-core/gather/driver.js:343:21)
    at listOnTimeout (node:internal/timers:556:17)
    at processTimers (node:internal/timers:499:7) {
  code: 'PROTOCOL_TIMEOUT',
  friendlyMessage: 'Waiting for DevTools protocol response has exceeded the allotted time. (Method: Page.enable)',
  lhrRuntimeError: true,
  protocolMethod: 'Page.enable'
}

In all cases, the new instance is created within the setTimeout callback and the only available stack for each such error is:

    at Timeout.<anonymous> (/crawler/node_modules/lighthouse/lighthouse-core/gather/driver.js:343:21)
    at listOnTimeout (node:internal/timers:556:17)
    at processTimers (node:internal/timers:499:7) {

What did you expect?

The error object should be constructed outside the setTimeout callback to preserve the call stack.

LighthouseError [LHError]: PROTOCOL_TIMEOUT
    at /crawler/node_modules/lighthouse/lighthouse-core/gather/driver.js:341:50
    at new Promise (<anonymous>)
    at Driver.sendCommandToSession (/crawler/node_modules/lighthouse/lighthouse-core/gather/driver.js:339:28)
    at Driver.sendCommand (/crawler/node_modules/lighthouse/lighthouse-core/gather/driver.js:363:17)
    at ExecutionContext._evaluateInContext (/crawler/node_modules/lighthouse/lighthouse-core/gather/driver/execution-context.js:109:42)
    at ExecutionContext.evaluateAsync (/crawler/node_modules/lighthouse/lighthouse-core/gather/driver/execution-context.js:146:25)
    at ExecutionContext.evaluate (/crawler/node_modules/lighthouse/lighthouse-core/gather/driver/execution-context.js:178:17)
    at getBenchmarkIndex (/crawler/node_modules/lighthouse/lighthouse-core/gather/driver/environment.js:54:43)
    at Function.run (/crawler/node_modules/lighthouse/lighthouse-core/gather/gather-runner.js:469:44)
    at processTicksAndRejections (node:internal/process/task_queues:93:5) {
  code: 'PROTOCOL_TIMEOUT',
  friendlyMessage: 'Waiting for DevTools protocol response has exceeded the allotted time. (Method: Runtime.evaluate)',
  lhrRuntimeError: true,
  protocolMethod: 'Runtime.evaluate'
}

What have you tried?

No response

How were you running Lighthouse?

CLI

Lighthouse Version

8.6.0

Chrome Version

chrome-stable--91.0.4472.114-amd64.deb

Node Version

v15.2.1

OS

Linux 702400aa3abf 4.4.0-177-generic #207-Ubuntu SMP Mon Mar 16 01:16:10 UTC 2020 x86_64 GNU/Linux

Relevant log output

No response

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

4 participants