feat(serial): better errors from beforeAll (#10419)

When beforeAll hook times out or fails with an exception, we now
close the context and show a nice error.

packages/playwright-test/src/index.ts

@@ -22,6 +22,7 @@ import { rootTestType } from './testType';
 import { createGuid, removeFolders } from 'playwright-core/lib/utils/utils';
 import { GridClient } from 'playwright-core/lib/grid/gridClient';
 import { Browser } from 'playwright-core';
+import { prependToTestError } from './util';
 export { expect } from './expect';
 export const _baseTest: TestType<{}, {}> = rootTestType.test;
 
@@ -185,8 +186,10 @@ export const test = _baseTest.extend<TestFixtures, WorkerAndFileFixtures>({
     const captureTrace = (traceMode === 'on' || traceMode === 'retain-on-failure' || (traceMode === 'on-first-retry' && testInfo.retry === 1));
     const temporaryTraceFiles: string[] = [];
     const temporaryScreenshots: string[] = [];
+    const createdContexts = new Set<BrowserContext>();
 
     const onDidCreateContext = async (context: BrowserContext) => {
+      createdContexts.add(context);
       context.setDefaultTimeout(actionTimeout || 0);
       context.setDefaultNavigationTimeout(navigationTimeout || actionTimeout || 0);
       if (captureTrace) {
@@ -313,6 +316,14 @@ export const test = _baseTest.extend<TestFixtures, WorkerAndFileFixtures>({
       else
         await fs.promises.unlink(file).catch(() => {});
     }));
+
+    // 7. Cleanup created contexts when we know it's safe - this will produce nice error message.
+    if (hookType(testInfo) === 'beforeAll' && testInfo.status === 'timedOut') {
+      const anyContext = leftoverContexts[0];
+      const pendingCalls = anyContext ? formatPendingCalls((anyContext as any)._connection.pendingProtocolCalls()) : '';
+      await Promise.all(leftoverContexts.filter(c => createdContexts.has(c)).map(c => c.close()));
+      testInfo.error = prependToTestError(testInfo.error, pendingCalls);
+    }
   }, { auto: true }],
 
   _contextFactory: async ({ browser, video, _artifactsDir }, use, testInfo) => {
@@ -364,15 +375,7 @@ export const test = _baseTest.extend<TestFixtures, WorkerAndFileFixtures>({
       }
     }));
 
-    if (prependToError) {
-      if (!testInfo.error) {
-        testInfo.error = { value: prependToError };
-      } else if (testInfo.error.message) {
-        testInfo.error.message = prependToError + testInfo.error.message;
-        if (testInfo.error.stack)
-          testInfo.error.stack = prependToError + testInfo.error.stack;
-      }
-    }
+    testInfo.error = prependToTestError(testInfo.error, prependToError);
   },
 
   context: async ({ _contextFactory }, use) => {

packages/playwright-test/src/util.ts

@@ -162,3 +162,20 @@ export function getContainedPath(parentPath: string, subPath: string = ''): stri
 }
 
 export const debugTest = debug('pw:test');
+
+export function prependToTestError(testError: TestError | undefined, message: string | undefined) {
+  if (!message)
+    return testError;
+  if (!testError)
+    return { value: message };
+  if (testError.message) {
+    const stack = testError.stack ? message + testError.stack : testError.stack;
+    message = message + testError.message;
+    return {
+      value: testError.value,
+      message,
+      stack,
+    };
+  }
+  return testError;
+}

packages/playwright-test/src/workerRunner.ts

@@ -20,7 +20,7 @@ import rimraf from 'rimraf';
 import util from 'util';
 import colors from 'colors/safe';
 import { EventEmitter } from 'events';
-import { monotonicTime, serializeError, sanitizeForFilePath, getContainedPath, addSuffixToFilePath } from './util';
+import { monotonicTime, serializeError, sanitizeForFilePath, getContainedPath, addSuffixToFilePath, prependToTestError } from './util';
 import { TestBeginPayload, TestEndPayload, RunPayload, TestEntry, DonePayload, WorkerInitParams, StepBeginPayload, StepEndPayload } from './ipc';
 import { setCurrentTestInfo } from './globals';
 import { Loader } from './loader';
@@ -412,11 +412,12 @@ export class WorkerRunner extends EventEmitter {
       if (test._type === 'test') {
         // Delay reporting testEnd result until after teardownScopes is done.
         this._failedTest = testData;
-      } else if (!this._fatalError) {
-        if (testInfo.status === 'timedOut')
-          this._fatalError = { message: colors.red(`Timeout of ${testInfo.timeout}ms exceeded in ${test._type} hook.`) };
-        else
+      } else {
+        if (!this._fatalError)
           this._fatalError = testInfo.error;
+        // Keep any error we have, and add "timeout" message.
+        if (testInfo.status === 'timedOut')
+          this._fatalError = prependToTestError(this._fatalError, colors.red(`Timeout of ${testInfo.timeout}ms exceeded in ${test._type} hook.\n`));
       }
       this.stop();
     } else if (reportEvents) {

tests/playwright-test/hooks.spec.ts

@@ -544,3 +544,26 @@ test('uncaught error in beforeEach should not be masked by another error', async
   expect(stripAscii(result.output)).toContain('Expected: 2');
   expect(stripAscii(result.output)).toContain('Received: 1');
 });
+
+test('should report error from fixture teardown when beforeAll times out', async ({ runInlineTest }) => {
+  const result = await runInlineTest({
+    'a.test.js': `
+      const test = pwt.test.extend({
+        foo: async ({}, use) => {
+          let cb;
+          await use(new Promise((f, r) => cb = r));
+          cb(new Error('Oh my!'));
+        },
+      });
+      test.beforeAll(async ({ foo }, testInfo) => {
+        await foo;
+      });
+      test('passing', () => {
+      });
+    `,
+  }, { timeout: 1000 });
+  expect(result.exitCode).toBe(1);
+  expect(result.failed).toBe(1);
+  expect(stripAscii(result.output)).toContain('Timeout of 1000ms exceeded in beforeAll hook.');
+  expect(stripAscii(result.output)).toContain('Error: Oh my!');
+});

tests/playwright-test/playwright.spec.ts

@@ -296,6 +296,33 @@ test('should report error on timeout with shared page', async ({ runInlineTest }
   expect(stripAscii(result.output)).toContain(`14 |         await page.click('text=Missing');`);
 });
 
+test('should report error and pending operations from beforeAll timeout', async ({ runInlineTest }, testInfo) => {
+  const result = await runInlineTest({
+    'a.test.ts': `
+      const { test } = pwt;
+      test.beforeAll(async ({ browser }) => {
+        const page = await browser.newPage();
+        await page.setContent('<div>Click me</div>');
+        await Promise.all([
+          page.click('text=Missing'),
+          page.textContent('text=More missing'),
+        ]);
+      });
+      test('ignored', () => {});
+    `,
+  }, { workers: 1, timeout: 2000 });
+
+  expect(result.exitCode).toBe(1);
+  expect(result.passed).toBe(0);
+  expect(result.failed).toBe(1);
+  expect(result.output).toContain('Timeout of 2000ms exceeded in beforeAll hook.');
+  expect(result.output).toContain('Pending operations:');
+  expect(result.output).toContain('- page.click at a.test.ts:10:16');
+  expect(result.output).toContain('- page.textContent at a.test.ts:11:16');
+  expect(result.output).toContain('waiting for selector');
+  expect(stripAscii(result.output)).toContain(`11 |           page.textContent('text=More missing'),`);
+});
+
 test('should not report waitForEventInfo as pending', async ({ runInlineTest }, testInfo) => {
   const result = await runInlineTest({
     'a.test.ts': `