From 4a2a37b825798893c34277ef67164e6b8fa6049e Mon Sep 17 00:00:00 2001 From: Nikolay Vitkov <34244704+Lightning00Blade@users.noreply.github.com> Date: Wed, 11 Oct 2023 19:21:50 +0200 Subject: [PATCH] chore: add a deflake utility (#11111) --- .../puppeteer-core/src/bidi/BidiOverCdp.ts | 9 +- test/.eslintrc.js | 5 ++ test/package.json | 1 + test/src/launcher.spec.ts | 11 +-- test/src/mocha-utils.ts | 85 ++++++++----------- test/src/oopif.spec.ts | 4 +- test/src/target.spec.ts | 4 +- tools/mocha-runner/README.md | 30 +++++++ tools/mocha-runner/package.json | 3 + tools/mocha-runner/src/interface.ts | 79 ++++++++++++++++- 10 files changed, 167 insertions(+), 64 deletions(-) diff --git a/packages/puppeteer-core/src/bidi/BidiOverCdp.ts b/packages/puppeteer-core/src/bidi/BidiOverCdp.ts index f6f262b658e..57367c4141a 100644 --- a/packages/puppeteer-core/src/bidi/BidiOverCdp.ts +++ b/packages/puppeteer-core/src/bidi/BidiOverCdp.ts @@ -20,11 +20,16 @@ import type {ProtocolMapping} from 'devtools-protocol/types/protocol-mapping.js' import type {CDPEvents, CDPSession} from '../api/CDPSession.js'; import type {Connection as CdpConnection} from '../cdp/Connection.js'; +import {debug} from '../common/Debug.js'; import {TargetCloseError} from '../common/Errors.js'; import type {Handler} from '../common/EventEmitter.js'; import {BidiConnection} from './Connection.js'; +const bidiServerLogger = (prefix: string, ...args: unknown[]): void => { + debug(`bidi:${prefix}`)(args); +}; + /** * @internal */ @@ -54,7 +59,9 @@ export async function connectBidiOverCdp( const bidiServer = await BidiMapper.BidiServer.createAndStart( transportBiDi, cdpConnectionAdapter, - '' + '', + undefined, + bidiServerLogger ); return pptrBiDiConnection; } diff --git a/test/.eslintrc.js b/test/.eslintrc.js index 7d4ccdfbae7..489868b6ed3 100644 --- a/test/.eslintrc.js +++ b/test/.eslintrc.js @@ -26,6 +26,11 @@ module.exports = { selector: 'MemberExpression[object.name="puppeteer"][property.name="launch"]', }, + { + message: 'Unexpected debugging mocha test.', + selector: + 'CallExpression[callee.object.name="it"] > MemberExpression > Identifier[name="deflake"], CallExpression[callee.object.name="it"] > MemberExpression > Identifier[name="deflakeOnly"]', + }, ], }, }, diff --git a/test/package.json b/test/package.json index 74a5af0afbc..16053d03067 100644 --- a/test/package.json +++ b/test/package.json @@ -24,6 +24,7 @@ } }, "dependencies": { + "puppeteer-core": "file:../packages/puppeteer-core", "puppeteer": "file:../packages/puppeteer" } } diff --git a/test/src/launcher.spec.ts b/test/src/launcher.spec.ts index 0c0a5b9349e..a84d4c53727 100644 --- a/test/src/launcher.spec.ts +++ b/test/src/launcher.spec.ts @@ -26,12 +26,7 @@ import type {Page} from 'puppeteer-core/internal/api/Page.js'; import {rmSync} from 'puppeteer-core/internal/node/util/fs.js'; import sinon from 'sinon'; -import { - getTestState, - isHeadless, - itOnlyRegularInstall, - launch, -} from './mocha-utils.js'; +import {getTestState, isHeadless, launch} from './mocha-utils.js'; import {dumpFrames, waitEvent} from './utils.js'; const TMP_FOLDER = path.join(os.tmpdir(), 'pptr_tmp_folder-'); @@ -601,7 +596,7 @@ describe('Launcher specs', function () { }); describe('Puppeteer.launch', function () { - itOnlyRegularInstall('should be able to launch Chrome', async () => { + it('should be able to launch Chrome', async () => { const {browser, close} = await launch({product: 'chrome'}); try { const userAgent = await browser.userAgent(); @@ -875,7 +870,7 @@ describe('Launcher specs', function () { }); }); describe('Puppeteer.executablePath', function () { - itOnlyRegularInstall('should work', async () => { + it('should work', async () => { const {puppeteer} = await getTestState({ skipLaunch: true, }); diff --git a/test/src/mocha-utils.ts b/test/src/mocha-utils.ts index 166a3db32c1..474fa3669b2 100644 --- a/test/src/mocha-utils.ts +++ b/test/src/mocha-utils.ts @@ -20,15 +20,11 @@ import path from 'path'; import {TestServer} from '@pptr/testserver'; import type {Protocol} from 'devtools-protocol'; import expect from 'expect'; -import type * as Mocha from 'mocha'; +import type * as MochaBase from 'mocha'; import puppeteer from 'puppeteer/lib/cjs/puppeteer/puppeteer.js'; import type {Browser} from 'puppeteer-core/internal/api/Browser.js'; import type {BrowserContext} from 'puppeteer-core/internal/api/BrowserContext.js'; import type {Page} from 'puppeteer-core/internal/api/Page.js'; -import { - setLogCapture, - getCapturedLogs, -} from 'puppeteer-core/internal/common/Debug.js'; import type { PuppeteerLaunchOptions, PuppeteerNode, @@ -40,11 +36,45 @@ import sinon from 'sinon'; import {extendExpectWithToBeGolden} from './utils.js'; +declare global { + // eslint-disable-next-line @typescript-eslint/no-namespace + namespace Mocha { + export interface SuiteFunction { + /** + * Use it if you want to capture debug logs for a specitic test suite in CI. + * This describe function enables capturing of debug logs and would print them + * only if a test fails to reduce the amount of output. + */ + withDebugLogs: ( + description: string, + body: (this: MochaBase.Suite) => void + ) => void; + } + export interface TestFunction { + /* + * Use to rerun the test and capture logs for the failed attempts + * that way we don't push all the logs making it easier to read. + */ + deflake: ( + repeats: number, + title: string, + fn: MochaBase.AsyncFunc + ) => void; + /* + * Use to rerun a single test and capture logs for the failed attempts + */ + deflakeOnly: ( + repeats: number, + title: string, + fn: MochaBase.AsyncFunc + ) => void; + } + } +} + const product = process.env['PRODUCT'] || process.env['PUPPETEER_PRODUCT'] || 'chrome'; -const alternativeInstall = process.env['PUPPETEER_ALT_INSTALL'] || false; - const headless = (process.env['HEADLESS'] || 'true').trim().toLowerCase() as | 'true' | 'false' @@ -95,7 +125,6 @@ if (defaultBrowserOptions.executablePath) { const processVariables: { product: string; - alternativeInstall: string | boolean; headless: 'true' | 'false' | 'new'; isHeadless: boolean; isFirefox: boolean; @@ -104,7 +133,6 @@ const processVariables: { defaultBrowserOptions: PuppeteerLaunchOptions; } = { product, - alternativeInstall, headless, isHeadless, isFirefox, @@ -217,17 +245,6 @@ export interface PuppeteerTestState { } const state: Partial = {}; -export const itOnlyRegularInstall = ( - description: string, - body: Mocha.AsyncFunc -): Mocha.Test => { - if (processVariables.alternativeInstall || process.env['BINARY']) { - return it.skip(description, body); - } else { - return it(description, body); - } -}; - if ( process.env['MOCHA_WORKER_ID'] === undefined || process.env['MOCHA_WORKER_ID'] === '0' @@ -376,34 +393,6 @@ export const expectCookieEquals = async ( } }; -/** - * Use it if you want to capture debug logs for a specitic test suite in CI. - * This describe function enables capturing of debug logs and would print them - * only if a test fails to reduce the amount of output. - */ -export const describeWithDebugLogs = ( - description: string, - body: (this: Mocha.Suite) => void -): Mocha.Suite | void => { - describe(description + '-debug', () => { - beforeEach(() => { - setLogCapture(true); - }); - - afterEach(function () { - if (this.currentTest?.state === 'failed') { - console.log( - `\n"${this.currentTest.fullTitle()}" failed. Here is a debug log:` - ); - console.log(getCapturedLogs().join('\n') + '\n'); - } - setLogCapture(false); - }); - - describe(description, body); - }); -}; - export const shortWaitForArrayToHaveAtLeastNElements = async ( data: unknown[], minLength: number, diff --git a/test/src/oopif.spec.ts b/test/src/oopif.spec.ts index d3c606ae6b0..5d65b89d19c 100644 --- a/test/src/oopif.spec.ts +++ b/test/src/oopif.spec.ts @@ -18,10 +18,10 @@ import expect from 'expect'; import type {BrowserContext} from 'puppeteer-core/internal/api/BrowserContext.js'; import type {CdpTarget} from 'puppeteer-core/internal/cdp/Target.js'; -import {describeWithDebugLogs, getTestState, launch} from './mocha-utils.js'; +import {getTestState, launch} from './mocha-utils.js'; import {attachFrame, detachFrame, navigateFrame} from './utils.js'; -describeWithDebugLogs('OOPIF', function () { +describe('OOPIF', function () { /* We use a special browser for this test as we need the --site-per-process flag */ let state: Awaited>; diff --git a/test/src/target.spec.ts b/test/src/target.spec.ts index 0f01c6cb67d..a8824de2185 100644 --- a/test/src/target.spec.ts +++ b/test/src/target.spec.ts @@ -246,6 +246,7 @@ describe('Target', function () { expect(targetChanged).toBe(false); context.off('targetchanged', listener); }); + it('should not crash while redirecting if original request was missed', async () => { const {page, server, context} = await getTestState(); @@ -268,11 +269,12 @@ describe('Target', function () { {timeout: 3000} ); const newPage = (await target.page())!; + const loadEvent = waitEvent(newPage, 'load'); // Issue a redirect. serverResponse.writeHead(302, {location: '/injectedstyle.css'}); serverResponse.end(); // Wait for the new page to load. - await waitEvent(newPage, 'load'); + await loadEvent; // Cleanup. await newPage.close(); }); diff --git a/tools/mocha-runner/README.md b/tools/mocha-runner/README.md index adb5c2e610a..0bdd9f253bb 100644 --- a/tools/mocha-runner/README.md +++ b/tools/mocha-runner/README.md @@ -71,3 +71,33 @@ Examples: Currently, expectations are updated manually. The test runner outputs the suggested changes to the expectation file if the test run does not match expectations. + +## Debugging flaky test + +### Utility functions: + +| Utility | Params | Description | +| ------------------------ | ------------------------------- | --------------------------------------------------------------------------------- | +| `describe.withDebugLogs` | `(title, )` | Capture and print debug logs for each test that failed | +| `it.deflake` | `(repeat, title, )` | Reruns the test N number of times and print the debug logs if for the failed runs | +| `it.deflakeOnly` | `(repeat, title, )` | Same as `it.deflake` but runs only this specific test | + +### With Environment variable + +Run the test with the following environment variable to wrap it around `describe.withDebugLogs`. Example: + +```bash +PUPPETEER_DEFLAKE_TESTS="[navigation.spec] navigation Page.goto should navigate to empty page with networkidle0" npm run test:chrome:headless +``` + +It also works with [patterns](#1--this-is-my-header) just like `TestExpectations.json` + +```bash +PUPPETEER_DEFLAKE_TESTS="[navigation.spec] *" npm run test:chrome:headless +``` + +By default the test is rerun 100 times, but you can control this as well: + +```bash +PUPPETEER_DEFLAKE_RETRIES=1000 PUPPETEER_DEFLAKE_TESTS="[navigation.spec] *" npm run test:chrome:headless +``` diff --git a/tools/mocha-runner/package.json b/tools/mocha-runner/package.json index 59b9ef3c7f6..11a532daf21 100644 --- a/tools/mocha-runner/package.json +++ b/tools/mocha-runner/package.json @@ -29,5 +29,8 @@ "build" ] } + }, + "dependencies": { + "puppeteer-core": "file:../../packages/puppeteer-core" } } diff --git a/tools/mocha-runner/src/interface.ts b/tools/mocha-runner/src/interface.ts index 418ce68c120..35eedab4220 100644 --- a/tools/mocha-runner/src/interface.ts +++ b/tools/mocha-runner/src/interface.ts @@ -16,6 +16,10 @@ import Mocha from 'mocha'; import commonInterface from 'mocha/lib/interfaces/common'; +import { + setLogCapture, + getCapturedLogs, +} from 'puppeteer-core/internal/common/Debug.js'; import {testIdMatchesExpectationPattern} from './utils.js'; @@ -28,6 +32,10 @@ const skippedTests: Array<{testIdPattern: string; skip: true}> = process.env[ ? JSON.parse(process.env['PUPPETEER_SKIPPED_TEST_CONFIG']) : []; +const deflakeRetries = Number(process.env['PUPPETEER_DEFLAKE_RETRIES'] ?? 100); +const deflakeTestPattern: string | undefined = + process.env['PUPPETEER_DEFLAKE_TESTS']; + function shouldSkipTest(test: Mocha.Test): boolean { // TODO: more efficient lookup. const definition = skippedTests.find(skippedTest => { @@ -39,8 +47,26 @@ function shouldSkipTest(test: Mocha.Test): boolean { return false; } +function shouldDeflakeTest(test: Mocha.Test): boolean { + if (deflakeTestPattern) { + // TODO: cache if we have seen it already + return testIdMatchesExpectationPattern(test, deflakeTestPattern); + } + return false; +} + +function dumpLogsIfFail(this: Mocha.Context) { + if (this.currentTest?.state === 'failed') { + console.log( + `\n"${this.currentTest.fullTitle()}" failed. Here is a debug log:` + ); + console.log(getCapturedLogs().join('\n') + '\n'); + } + setLogCapture(false); +} + function customBDDInterface(suite: Mocha.Suite) { - const suites = [suite]; + const suites: [Mocha.Suite] = [suite]; suite.on( Mocha.Suite.constants.EVENT_FILE_PRE_REQUIRE, @@ -78,12 +104,25 @@ function customBDDInterface(suite: Mocha.Suite) { }); }; + describe.withDebugLogs = function ( + description: string, + body: (this: Mocha.Suite) => void + ): void { + context['describe']('with Debug Logs', () => { + context['beforeEach'](() => { + setLogCapture(true); + }); + context['afterEach'](dumpLogsIfFail); + context['describe'](description, body); + }); + }; + // eslint-disable-next-line @typescript-eslint/ban-ts-comment // @ts-expect-error context['describe'] = describe; function it(title: string, fn: Mocha.TestFunction, itOnly = false) { - const suite = suites[0]!; + const suite = suites[0]! as Mocha.Suite; const test = new Mocha.Test(title, suite.isPending() ? undefined : fn); test.file = file; test.parent = suite; @@ -95,8 +134,22 @@ function customBDDInterface(suite: Mocha.Suite) { return child === suite; }) ); + if (shouldDeflakeTest(test)) { + const deflakeSuit = Mocha.Suite.create(suite, 'with Debug Logs'); + test.parent = deflakeSuit; + deflakeSuit.file = file; + deflakeSuit.parent = suite; - if (shouldSkipTest(test) && !(itOnly || describeOnly)) { + deflakeSuit.beforeEach(function () { + setLogCapture(true); + }); + deflakeSuit.afterEach(dumpLogsIfFail); + for (let i = 0; i < deflakeRetries; i++) { + deflakeSuit.addTest(test.clone()); + } + + return test; + } else if (!(itOnly || describeOnly) && shouldSkipTest(test)) { const test = new Mocha.Test(title); test.file = file; suite.addTest(test); @@ -110,7 +163,7 @@ function customBDDInterface(suite: Mocha.Suite) { it.only = function (title: string, fn: Mocha.TestFunction) { return common.test.only( mocha, - (context['it'] as typeof it)(title, fn, true) + (context['it'] as unknown as typeof it)(title, fn, true) ); }; @@ -118,6 +171,24 @@ function customBDDInterface(suite: Mocha.Suite) { return context['it'](title); }; + function wrapDeflake( + func: Function + ): (repeats: number, title: string, fn: Mocha.AsyncFunc) => void { + return (repeats: number, title: string, fn: Mocha.AsyncFunc): void => { + (context['describe'] as unknown as typeof describe).withDebugLogs( + 'with Debug Logs', + () => { + for (let i = 1; i <= repeats; i++) { + func(`${i}/${title}`, fn); + } + } + ); + }; + } + + it.deflake = wrapDeflake(it); + it.deflakeOnly = wrapDeflake(it.only); + // eslint-disable-next-line @typescript-eslint/ban-ts-comment // @ts-expect-error context.it = it;