tests: pass logger to smokehouse runners to get log even on timeout (#16175)

This commit is contained in:
Connor Clark 2024-09-04 16:50:02 -07:00 коммит произвёл GitHub
Родитель 21e444418a
Коммит ba1a46c881
Не найден ключ, соответствующий данной подписи
Идентификатор ключа GPG: B5690EEEBB952194
5 изменённых файлов: 51 добавлений и 47 удалений

Просмотреть файл

@ -21,6 +21,7 @@ import * as ChromeLauncher from 'chrome-launcher';
import {LH_ROOT} from '../../../../shared/root.js';
import {loadArtifacts, saveArtifacts} from '../../../../core/lib/asset-saver.js';
import {LocalConsole} from '../lib/local-console.js';
// This runs only in the worker. The rest runs on the main thread.
if (!isMainThread && parentPort) {
@ -105,12 +106,13 @@ async function runBundledLighthouse(url, config, testRunnerOptions) {
* Launch Chrome and do a full Lighthouse run via the Lighthouse DevTools bundle.
* @param {string} url
* @param {LH.Config=} config
* @param {LocalConsole=} logger
* @param {Smokehouse.SmokehouseOptions['testRunnerOptions']=} testRunnerOptions
* @return {Promise<{lhr: LH.Result, artifacts: LH.Artifacts, log: string}>}
* @return {Promise<{lhr: LH.Result, artifacts: LH.Artifacts}>}
*/
async function runLighthouse(url, config, testRunnerOptions = {}) {
/** @type {string[]} */
const logs = [];
async function runLighthouse(url, config, logger, testRunnerOptions = {}) {
logger = logger || new LocalConsole();
const worker = new Worker(new URL(import.meta.url), {
stdout: true,
stderr: true,
@ -119,16 +121,16 @@ async function runLighthouse(url, config, testRunnerOptions = {}) {
worker.stdout.setEncoding('utf8');
worker.stderr.setEncoding('utf8');
worker.stdout.addListener('data', (data) => {
logs.push(`[STDOUT] ${data}`);
logger.log(`[STDOUT] ${data}`);
});
worker.stderr.addListener('data', (data) => {
logs.push(`[STDERR] ${data}`);
logger.log(`[STDERR] ${data}`);
});
const [workerResponse] = await once(worker, 'message');
const log = logs.join('') + '\n';
if (workerResponse.type === 'error') {
throw new Error(`Worker returned an error: ${workerResponse.value}\nLog:\n${log}`);
const log = logger.getLog();
throw new Error(`Worker returned an error: ${workerResponse.value}\nLog:\n${log}\n`);
}
const result = workerResponse.value;
@ -142,7 +144,6 @@ async function runLighthouse(url, config, testRunnerOptions = {}) {
return {
lhr: result.lhr,
artifacts,
log,
};
}

Просмотреть файл

@ -12,8 +12,7 @@
*/
import {promises as fs} from 'fs';
import {promisify} from 'util';
import {execFile} from 'child_process';
import {spawn} from 'child_process';
import log from 'lighthouse-logger';
@ -22,21 +21,20 @@ import {LocalConsole} from '../lib/local-console.js';
import {ChildProcessError} from '../lib/child-process-error.js';
import {LH_ROOT} from '../../../../shared/root.js';
const execFileAsync = promisify(execFile);
/**
* Launch Chrome and do a full Lighthouse run via the Lighthouse CLI.
* @param {string} url
* @param {LH.Config=} config
* @param {LocalConsole=} logger
* @param {Smokehouse.SmokehouseOptions['testRunnerOptions']=} testRunnerOptions
* @return {Promise<{lhr: LH.Result, artifacts: LH.Artifacts, log: string}>}
* @return {Promise<{lhr: LH.Result, artifacts: LH.Artifacts}>}
*/
async function runLighthouse(url, config, testRunnerOptions = {}) {
async function runLighthouse(url, config, logger, testRunnerOptions = {}) {
const {isDebug} = testRunnerOptions;
const tmpDir = `${LH_ROOT}/.tmp/smokehouse`;
await fs.mkdir(tmpDir, {recursive: true});
const tmpPath = await fs.mkdtemp(`${tmpDir}/smokehouse-`);
return internalRun(url, tmpPath, config, testRunnerOptions)
return internalRun(url, tmpPath, config, logger, testRunnerOptions)
// Wait for internalRun() before removing scratch directory.
.finally(() => !isDebug && fs.rm(tmpPath, {recursive: true, force: true}));
}
@ -46,12 +44,13 @@ async function runLighthouse(url, config, testRunnerOptions = {}) {
* @param {string} url
* @param {string} tmpPath
* @param {LH.Config=} config
* @param {LocalConsole=} logger
* @param {Smokehouse.SmokehouseOptions['testRunnerOptions']=} options
* @return {Promise<{lhr: LH.Result, artifacts: LH.Artifacts, log: string}>}
* @return {Promise<{lhr: LH.Result, artifacts: LH.Artifacts}>}
*/
async function internalRun(url, tmpPath, config, options) {
async function internalRun(url, tmpPath, config, logger, options) {
const {isDebug, headless} = options || {};
const localConsole = new LocalConsole();
logger = logger || new LocalConsole();
const outputPath = `${tmpPath}/smokehouse.report.json`;
const artifactsDirectory = `${tmpPath}/artifacts/`;
@ -78,29 +77,25 @@ async function internalRun(url, tmpPath, config, options) {
const command = 'node';
const env = {...process.env, NODE_ENV: 'test'};
localConsole.log(`${log.dim}$ ${command} ${args.join(' ')} ${log.reset}`);
logger.log(`${log.dim}$ ${command} ${args.join(' ')} ${log.reset}`);
/** @type {{stdout: string, stderr: string, code?: number}} */
let execResult;
try {
execResult = await execFileAsync(command, args, {env});
} catch (e) {
// exec-thrown errors have stdout, stderr, and exit code from child process.
execResult = e;
}
const exitCode = execResult.code || 0;
if (isDebug) {
localConsole.log(`exit code ${exitCode}`);
localConsole.log(`STDOUT: ${execResult.stdout}`);
localConsole.log(`STDERR: ${execResult.stderr}`);
const cp = spawn(command, args, {env});
cp.stdout.on('data', data => logger.log(`[STDOUT] ${data.toString().trim()}`));
cp.stderr.on('data', data => logger.log(`[STDERR] ${data.toString().trim()}`));
/** @type {Promise<number|null>} */
const cpPromise = new Promise((resolve, reject) => {
cp.addListener('exit', resolve);
cp.addListener('error', reject);
});
const exitCode = await cpPromise;
if (exitCode) {
logger.log(`exit code ${exitCode}`);
}
try {
await fs.access(outputPath);
} catch (e) {
throw new ChildProcessError(`Lighthouse run failed to produce a report and exited with ${exitCode}.`, // eslint-disable-line max-len
localConsole.getLog());
throw new ChildProcessError(`Lighthouse run failed to produce a report.`, logger.getLog());
}
/** @type {LH.Result} */
@ -109,21 +104,20 @@ async function internalRun(url, tmpPath, config, options) {
// Output has been established as existing, so can log for debug.
if (isDebug) {
localConsole.log(`LHR output available at: ${outputPath}`);
localConsole.log(`Artifacts avaiable in: ${artifactsDirectory}`);
logger.log(`LHR output available at: ${outputPath}`);
logger.log(`Artifacts avaiable in: ${artifactsDirectory}`);
}
// There should either be both an error exitCode and a lhr.runtimeError or neither.
if (Boolean(exitCode) !== Boolean(lhr.runtimeError)) {
const runtimeErrorCode = lhr.runtimeError?.code;
throw new ChildProcessError(`Lighthouse did not exit with an error correctly, exiting with ${exitCode} but with runtimeError '${runtimeErrorCode}'`, // eslint-disable-line max-len
localConsole.getLog());
logger.getLog());
}
return {
lhr,
artifacts,
log: localConsole.getLog(),
};
}

Просмотреть файл

@ -40,21 +40,24 @@ async function setup() {
* CHROME_PATH determines which Chrome is usedotherwise the default is puppeteer's chrome binary.
* @param {string} url
* @param {LH.Config=} config
* @param {import('../lib/local-console.js').LocalConsole=} logger
* @param {Smokehouse.SmokehouseOptions['testRunnerOptions']=} testRunnerOptions
* @return {Promise<{lhr: LH.Result, artifacts: LH.Artifacts, log: string}>}
* @return {Promise<{lhr: LH.Result, artifacts: LH.Artifacts}>}
*/
async function runLighthouse(url, config, testRunnerOptions) {
async function runLighthouse(url, config, logger, testRunnerOptions) {
const chromeFlags = [
testRunnerOptions?.headless ? '--headless=new' : '',
`--custom-devtools-frontend=file://${devtoolsDir}/out/LighthouseIntegration/gen/front_end`,
];
// TODO: `testUrlFromDevtools` should accept a logger, so we get some output even for time outs.
const {lhr, artifacts, logs} = await testUrlFromDevtools(url, {
config,
chromeFlags,
});
const log = logs.join('') + '\n';
return {lhr, artifacts, log};
if (logger) {
logger.log(logs.join('') + '\n');
}
return {lhr, artifacts};
}
export {

Просмотреть файл

@ -161,6 +161,8 @@ async function runSmokeTest(smokeTestDefn, testOptions) {
bufferedConsole.log(` Retrying run (${i} out of ${retries} retries)…`);
}
const logger = new LocalConsole();
// Run Lighthouse.
try {
// Each individual runner has internal timeouts, but we've had bugs where
@ -170,12 +172,13 @@ async function runSmokeTest(smokeTestDefn, testOptions) {
reject(new Error('Timed out waiting for provided lighthouseRunner')), 1000 * 120);
});
const timedResult = await Promise.race([
lighthouseRunner(requestedUrl, config, testRunnerOptions),
lighthouseRunner(requestedUrl, config, logger, testRunnerOptions),
timeoutPromise,
]);
result = {
...timedResult,
networkRequests: takeNetworkRequestUrls ? takeNetworkRequestUrls() : undefined,
log: logger.getLog(),
};
if (!result.lhr?.audits || !result.artifacts) {
@ -188,6 +191,8 @@ async function runSmokeTest(smokeTestDefn, testOptions) {
if (takeNetworkRequestUrls) takeNetworkRequestUrls();
logChildProcessError(bufferedConsole, e);
bufferedConsole.log('Timed out. log from lighthouseRunner:');
bufferedConsole.log(logger.getLog());
continue; // Retry, if possible.
}

3
types/internal/smokehouse.d.ts поставляемый
Просмотреть файл

@ -7,6 +7,7 @@
import {Artifacts} from '../artifacts.js';
import Config from '../config.js';
import LHResult from '../lhr/lhr.js';
import {LocalConsole} from '../../cli/test/smokehouse/lib/local-console.js';
declare global {
module Smokehouse {
@ -53,7 +54,7 @@ declare global {
{expectations: Smokehouse.ExpectedRunnerResult | Array<Smokehouse.ExpectedRunnerResult>}
export type LighthouseRunner =
{runnerName?: string} & ((url: string, config?: Config, runnerOptions?: {isDebug?: boolean}) => Promise<{lhr: LHResult, artifacts: Artifacts, log: string}>);
{runnerName?: string} & ((url: string, config?: Config, logger?: LocalConsole, runnerOptions?: {isDebug?: boolean}) => Promise<{lhr: LHResult, artifacts: Artifacts}>);
export interface SmokehouseOptions {
/** Options to pass to the specific Lighthouse runner. */