chore: add a deflake utility (#11111)

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;
 }

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"]',
+          },
         ],
       },
     },

test/package.json

@@ -24,6 +24,7 @@
     }
   },
   "dependencies": {
+    "puppeteer-core": "file:../packages/puppeteer-core",
     "puppeteer": "file:../packages/puppeteer"
   }
 }

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 {
+import {getTestState, isHeadless, launch} from './mocha-utils.js';
-  getTestState,
-  isHeadless,
-  itOnlyRegularInstall,
-  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,
         });

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<PuppeteerTestState> = {};
 
-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,

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<ReturnType<typeof launch>>;
 

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();
   });

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, <DescribeBody>)`       | Capture and print debug logs for each test that failed                            |
+| `it.deflake`             | `(repeat, title, <itFunction>)` | Reruns the test N number of times and print the debug logs if for the failed runs |
+| `it.deflakeOnly`         | `(repeat, title, <itFunction>)` | 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
+```

tools/mocha-runner/package.json

@@ -29,5 +29,8 @@
         "build"
       ]
     }
+  },
+  "dependencies": {
+    "puppeteer-core": "file:../../packages/puppeteer-core"
   }
 }

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;