From 8f43f4c98f7dca06091384c1c75a0588f7e0adab Mon Sep 17 00:00:00 2001 From: Dmitry Gozman Date: Thu, 18 Nov 2021 14:36:55 -0800 Subject: [PATCH] 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 | 21 ++++++++------- packages/playwright-test/src/util.ts | 17 ++++++++++++ packages/playwright-test/src/workerRunner.ts | 11 ++++---- tests/playwright-test/hooks.spec.ts | 23 +++++++++++++++++ tests/playwright-test/playwright.spec.ts | 27 ++++++++++++++++++++ 5 files changed, 85 insertions(+), 14 deletions(-) diff --git a/packages/playwright-test/src/index.ts b/packages/playwright-test/src/index.ts index 13b421be7a..da2e15c609 100644 --- a/packages/playwright-test/src/index.ts +++ b/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({ 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(); 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({ 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({ } })); - 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) => { diff --git a/packages/playwright-test/src/util.ts b/packages/playwright-test/src/util.ts index b1a8ae43fb..0d5274eb8a 100644 --- a/packages/playwright-test/src/util.ts +++ b/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; +} diff --git a/packages/playwright-test/src/workerRunner.ts b/packages/playwright-test/src/workerRunner.ts index 61bd146971..bfa2ac00de 100644 --- a/packages/playwright-test/src/workerRunner.ts +++ b/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) { diff --git a/tests/playwright-test/hooks.spec.ts b/tests/playwright-test/hooks.spec.ts index 8e1c6e82bb..720bc581d6 100644 --- a/tests/playwright-test/hooks.spec.ts +++ b/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!'); +}); diff --git a/tests/playwright-test/playwright.spec.ts b/tests/playwright-test/playwright.spec.ts index 119662a161..14d3fc9f01 100644 --- a/tests/playwright-test/playwright.spec.ts +++ b/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('
Click me
'); + 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': `