From 24a15ddf25679a20f59655ce5165ea0839fcf690 Mon Sep 17 00:00:00 2001 From: Dmitry Gozman Date: Thu, 22 Feb 2024 16:20:00 -0800 Subject: [PATCH] runWithTimeout inside runAsStage --- .../src/utils/timeoutRunner.ts | 2 +- .../playwright/src/worker/fixtureRunner.ts | 22 +- packages/playwright/src/worker/testInfo.ts | 130 +++++++----- .../playwright/src/worker/timeoutManager.ts | 24 +-- packages/playwright/src/worker/workerMain.ts | 196 +++++++++--------- tests/playwright-test/basic.spec.ts | 2 +- tests/playwright-test/timeout.spec.ts | 24 +++ 7 files changed, 219 insertions(+), 181 deletions(-) diff --git a/packages/playwright-core/src/utils/timeoutRunner.ts b/packages/playwright-core/src/utils/timeoutRunner.ts index fc4db8aed9..dd60551f62 100644 --- a/packages/playwright-core/src/utils/timeoutRunner.ts +++ b/packages/playwright-core/src/utils/timeoutRunner.ts @@ -45,11 +45,11 @@ export class TimeoutRunner { timeoutPromise: new ManualPromise(), }; try { + this._updateTimeout(running, this._timeout); const resultPromise = Promise.race([ cb(), running.timeoutPromise ]); - this._updateTimeout(running, this._timeout); return await resultPromise; } finally { this._updateTimeout(running, 0); diff --git a/packages/playwright/src/worker/fixtureRunner.ts b/packages/playwright/src/worker/fixtureRunner.ts index caea7fde4b..7405a83cab 100644 --- a/packages/playwright/src/worker/fixtureRunner.ts +++ b/packages/playwright/src/worker/fixtureRunner.ts @@ -14,7 +14,7 @@ * limitations under the License. */ -import { formatLocation, debugTest, filterStackFile } from '../util'; +import { formatLocation, filterStackFile } from '../util'; import { ManualPromise } from 'playwright-core/lib/utils'; import type { TestInfoImpl } from './testInfo'; import type { FixtureDescription } from './timeoutManager'; @@ -66,8 +66,10 @@ class Fixture { } await testInfo._runAsStage({ + title: `fixture: ${this.registration.name}`, + canTimeout: true, location: this._isInternalFixture ? this.registration.location : undefined, - stepInfo: this._shouldGenerateStep ? { title: `fixture: ${this.registration.name}`, category: 'fixture' } : undefined, + stepCategory: this._shouldGenerateStep ? 'fixture' : undefined, }, async () => { testInfo._timeoutManager.setCurrentFixture(this._setupDescription); await this._setupInternal(testInfo); @@ -99,7 +101,6 @@ class Fixture { let called = false; const useFuncStarted = new ManualPromise(); - debugTest(`setup ${this.registration.name}`); const useFunc = async (value: any) => { if (called) throw new Error(`Cannot provide fixture value for the second time`); @@ -128,8 +129,10 @@ class Fixture { async teardown(testInfo: TestInfoImpl) { await testInfo._runAsStage({ + title: `fixture: ${this.registration.name}`, + canTimeout: true, location: this._isInternalFixture ? this.registration.location : undefined, - stepInfo: this._shouldGenerateStep ? { title: `fixture: ${this.registration.name}`, category: 'fixture' } : undefined, + stepCategory: this._shouldGenerateStep ? 'fixture' : undefined, }, async () => { testInfo._timeoutManager.setCurrentFixture(this._teardownDescription); if (!this._teardownWithDepsComplete) @@ -149,7 +152,6 @@ class Fixture { this._usages.clear(); } if (this._useFuncFinished) { - debugTest(`teardown ${this.registration.name}`); this._useFuncFinished.resolve(); await this._selfTeardownComplete; } @@ -204,12 +206,12 @@ export class FixtureRunner { const collector = new Set(); for (const fixture of fixtures) fixture._collectFixturesInTeardownOrder(scope, collector); - await testInfo._runAsStage({}, async () => { + await testInfo._runAsStage({ title: `teardown ${scope} scope` }, async () => { for (const fixture of collector) await fixture.teardown(testInfo); - if (scope === 'test') - this.testScopeClean = true; }); + if (scope === 'test') + this.testScopeClean = true; } async resolveParametersForFunction(fn: Function, testInfo: TestInfoImpl, autoFixtures: 'worker' | 'test' | 'all-hooks-only'): Promise { @@ -236,7 +238,7 @@ export class FixtureRunner { this._collectFixturesInSetupOrder(this.pool!.resolve(name)!, collector); // Setup fixtures. - await testInfo._runAsStage({ stopOnChildError: true }, async () => { + await testInfo._runAsStage({ title: 'setup fixtures', stopOnChildError: true }, async () => { for (const registration of collector) await this._setupFixtureForRegistration(registration, testInfo); }); @@ -259,7 +261,7 @@ export class FixtureRunner { // Do not run the function when fixture setup has already failed. return null; } - await testInfo._runAsStage({}, async () => { + await testInfo._runAsStage({ title: 'run function', canTimeout: true }, async () => { await fn(params, testInfo); }); } diff --git a/packages/playwright/src/worker/testInfo.ts b/packages/playwright/src/worker/testInfo.ts index 1124377697..792cb3d096 100644 --- a/packages/playwright/src/worker/testInfo.ts +++ b/packages/playwright/src/worker/testInfo.ts @@ -21,10 +21,10 @@ import type { TestInfoError, TestInfo, TestStatus, FullProject, FullConfig } fro import type { AttachmentPayload, StepBeginPayload, StepEndPayload, WorkerInitParams } from '../common/ipc'; import type { TestCase } from '../common/test'; import { TimeoutManager } from './timeoutManager'; -import type { RunnableType, TimeSlot } from './timeoutManager'; +import type { RunnableDescription, RunnableType, TimeSlot } from './timeoutManager'; import type { Annotation, FullConfigInternal, FullProjectInternal } from '../common/config'; import type { Location } from '../../types/testReporter'; -import { filteredStackTrace, getContainedPath, normalizeAndSaveAttachment, serializeError, trimLongString } from '../util'; +import { debugTest, filteredStackTrace, formatLocation, getContainedPath, normalizeAndSaveAttachment, serializeError, trimLongString } from '../util'; import { TestTracing } from './testTracing'; import type { Attachment } from './testTracing'; import type { StackFrame } from '@protocol/channels'; @@ -49,19 +49,20 @@ export interface TestStepInternal { } export type TestStage = { + title: string; + location?: Location; + stepCategory?: 'hook' | 'fixture'; runnableType?: RunnableType; runnableSlot?: TimeSlot; - stepInfo?: { - title: string; - category: 'hook' | 'fixture'; - }; - location?: Location; - allowAndStopOnSkips?: boolean; + canTimeout?: boolean; + allowSkip?: boolean; stopOnChildError?: boolean; + continueOnChildTimeout?: boolean; step?: TestStepInternal; error?: Error; triggeredSkip?: boolean; + triggeredTimeout?: boolean; }; export class TestInfoImpl implements TestInfo { @@ -234,22 +235,6 @@ export class TestInfoImpl implements TestInfo { } } - async _runWithTimeout(cb: () => Promise): Promise { - const timeoutError = await this._timeoutManager.runWithTimeout(cb); - // When interrupting, we arrive here with a timeoutError, but we should not - // consider it a timeout. - if (!this._wasInterrupted && timeoutError && !this._didTimeout) { - this._didTimeout = true; - const serialized = serializeError(timeoutError); - this.errors.push(serialized); - this._tracing.appendForError(serialized); - // Do not overwrite existing failure upon hook/teardown timeout. - if (this.status === 'passed' || this.status === 'skipped') - this.status = 'timedOut'; - } - this.duration = this._timeoutManager.defaultSlotTimings().elapsed | 0; - } - private _findLastNonFinishedStep(filter: (step: TestStepInternal) => boolean) { let result: TestStepInternal | undefined; const visit = (step: TestStepInternal) => { @@ -367,6 +352,13 @@ export class TestInfoImpl implements TestInfo { this.status = 'interrupted'; } + _unhandledError(error: Error) { + this._failWithError(error, true /* isHardError */, true /* retriable */); + const stage = this._stages[this._stages.length - 1]; + if (stage) + stage.error = stage.error ?? error; + } + _failWithError(error: Error, isHardError: boolean, retriable: boolean) { if (!retriable) this._hasNonRetriableError = true; @@ -378,12 +370,6 @@ export class TestInfoImpl implements TestInfo { return; if (isHardError) this._hasHardError = true; - const stage = this._stages[this._stages.length - 1]; - if (stage) { - // Save the error to the stage here, so that unhandled rejections - // are attributed to the current stage. Among many errors, prefer the first one. - stage.error = stage.error ?? error; - } if (this.status === 'passed' || this.status === 'skipped') this.status = 'failed'; const serialized = serializeError(error); @@ -397,54 +383,88 @@ export class TestInfoImpl implements TestInfo { async _runAsStage(stage: TestStage, cb: () => Promise) { // Inherit some properties from parent. const parent = this._stages[this._stages.length - 1]; - stage.allowAndStopOnSkips = stage.allowAndStopOnSkips ?? parent?.allowAndStopOnSkips ?? false; + stage.allowSkip = stage.allowSkip ?? parent?.allowSkip ?? false; - if (parent?.allowAndStopOnSkips && parent?.triggeredSkip) { + if (parent?.allowSkip && parent?.triggeredSkip) { // Do not run more child steps after "skip" has been triggered. + debugTest(`ignored stage "${stage.title}" after previous skip`); return; } if (parent?.stopOnChildError && parent?.error) { // Do not run more child steps after a previous one failed. + debugTest(`ignored stage "${stage.title}" after previous error`); + return; + } + if (parent?.triggeredTimeout && !parent?.continueOnChildTimeout) { + // Do not run more child steps after a previous one timed out. + debugTest(`ignored stage "${stage.title}" after previous timeout`); return; } - const runnable = stage.runnableType ? { - type: stage.runnableType, - slot: stage.runnableSlot, - location: stage.location, - } : undefined; + if (debugTest.enabled) { + const location = stage.location ? ` at "${formatLocation(stage.location)}"` : ``; + debugTest(`started stage "${stage.title}"${location}`); + } + stage.step = stage.stepCategory ? this._addStep({ title: stage.title, category: stage.stepCategory, location: stage.location, wallTime: Date.now(), isStage: true }) : undefined; + this._stages.push(stage); - return await this._timeoutManager.withRunnable(runnable, async () => { - stage.step = stage.stepInfo ? this._addStep({ ...stage.stepInfo, location: stage.location, wallTime: Date.now(), isStage: true }) : undefined; - this._stages.push(stage); + let runnable: RunnableDescription | undefined; + if (stage.canTimeout) { + // Choose the deepest runnable configuration. + runnable = { type: 'test' }; + for (const s of this._stages) { + if (s.runnableType) { + runnable.type = s.runnableType; + runnable.location = s.location; + } + if (s.runnableSlot) + runnable.slot = s.runnableSlot; + } + } + const timeoutError = await this._timeoutManager.withRunnable(runnable, async () => { try { await cb(); } catch (e) { - if (stage.allowAndStopOnSkips && (e instanceof SkipError)) { + if (stage.allowSkip && (e instanceof SkipError)) { stage.triggeredSkip = true; if (this.status === 'passed') this.status = 'skipped'; } else { + // Prefer the first error. + stage.error = stage.error ?? e; this._failWithError(e, true /* isHardError */, true /* retriable */); } } - - if (parent) { - // Notify parent about child error and skip. - parent.error = parent.error ?? stage.error; - parent.triggeredSkip = parent.triggeredSkip || stage.triggeredSkip; - } - - const index = this._stages.indexOf(stage); - if (index !== -1) - this._stages.splice(index, 1); - stage.step?.complete({ error: stage.error }); }); - } + if (timeoutError) + stage.triggeredTimeout = true; - _resetStages() { - this._stages.splice(0, this._stages.length); + // When interrupting, we arrive here with a timeoutError, but we should not + // consider it a timeout. + if (!this._wasInterrupted && !this._didTimeout && timeoutError) { + stage.error = stage.error ?? timeoutError; + this._didTimeout = true; + const serialized = serializeError(timeoutError); + this.errors.push(serialized); + this._tracing.appendForError(serialized); + // Do not overwrite existing failure upon hook/teardown timeout. + if (this.status === 'passed' || this.status === 'skipped') + this.status = 'timedOut'; + } + + if (parent) { + // Notify parent about child error, skip and timeout. + parent.error = parent.error ?? stage.error; + parent.triggeredSkip = parent.triggeredSkip || stage.triggeredSkip; + parent.triggeredTimeout = parent.triggeredTimeout || stage.triggeredTimeout; + } + + if (this._stages[this._stages.length - 1] !== stage) + throw new Error(`Internal error: inconsistent stages!`); + this._stages.pop(); + stage.step?.complete({ error: stage.error }); + debugTest(`finished stage "${stage.title}"`); } _isFailure() { diff --git a/packages/playwright/src/worker/timeoutManager.ts b/packages/playwright/src/worker/timeoutManager.ts index 8cded8ea46..a4dc7963ca 100644 --- a/packages/playwright/src/worker/timeoutManager.ts +++ b/packages/playwright/src/worker/timeoutManager.ts @@ -56,16 +56,22 @@ export class TimeoutManager { this._timeoutRunner.interrupt(); } - async withRunnable(runnable: RunnableDescription | undefined, cb: () => Promise): Promise { - if (!runnable) - return await cb(); + async withRunnable(runnable: RunnableDescription | undefined, cb: () => Promise): Promise { + if (!runnable) { + await cb(); + return; + } const existingRunnable = this._runnable; const effectiveRunnable = { ...runnable }; if (!effectiveRunnable.slot) effectiveRunnable.slot = this._runnable.slot; this._updateRunnables(effectiveRunnable, undefined); try { - return await cb(); + await this._timeoutRunner.run(cb); + } catch (error) { + if (!(error instanceof TimeoutRunnerError)) + throw error; + return this._createTimeoutError(); } finally { this._updateRunnables(existingRunnable, undefined); } @@ -87,16 +93,6 @@ export class TimeoutManager { this._timeoutRunner.updateTimeout(slot.timeout); } - async runWithTimeout(cb: () => Promise): Promise { - try { - await this._timeoutRunner.run(cb); - } catch (error) { - if (!(error instanceof TimeoutRunnerError)) - throw error; - return this._createTimeoutError(); - } - } - setTimeout(timeout: number) { const slot = this._currentSlot(); if (!slot.timeout) diff --git a/packages/playwright/src/worker/workerMain.ts b/packages/playwright/src/worker/workerMain.ts index 18afaba238..319485cf11 100644 --- a/packages/playwright/src/worker/workerMain.ts +++ b/packages/playwright/src/worker/workerMain.ts @@ -15,7 +15,7 @@ */ import { colors } from 'playwright-core/lib/utilsBundle'; -import { debugTest, formatLocation, relativeFilePath, serializeError } from '../util'; +import { debugTest, relativeFilePath, serializeError } from '../util'; import { type TestBeginPayload, type TestEndPayload, type RunPayload, type DonePayload, type WorkerInitParams, type TeardownErrorsPayload, stdioChunkToParams } from '../common/ipc'; import { setCurrentTestInfo, setIsWorkerProcess } from '../common/globals'; import { deserializeConfig } from '../common/configLoader'; @@ -23,7 +23,7 @@ import type { Suite, TestCase } from '../common/test'; import type { Annotation, FullConfigInternal, FullProjectInternal } from '../common/config'; import { FixtureRunner } from './fixtureRunner'; import { ManualPromise, gracefullyCloseAll, removeFolders } from 'playwright-core/lib/utils'; -import { TestInfoImpl, TestStage } from './testInfo'; +import { TestInfoImpl, type TestStage } from './testInfo'; import { ProcessRunner } from '../common/process'; import { loadTestFile } from '../common/testLoader'; import { applyRepeatEachIndex, bindFileSuiteToProject, filterTestsRemoveEmptySuites } from '../common/suiteUtils'; @@ -146,11 +146,9 @@ export class WorkerMain extends ProcessRunner { private async _teardownScopes() { // TODO: separate timeout for teardown? const fakeTestInfo = new TestInfoImpl(this._config, this._project, this._params, undefined, 0, () => {}, () => {}, () => {}); - await fakeTestInfo._runAsStage({ runnableType: 'teardown' }, async () => { - await fakeTestInfo._runWithTimeout(async () => { - await this._fixtureRunner.teardownScope('test', fakeTestInfo); - await this._fixtureRunner.teardownScope('worker', fakeTestInfo); - }); + await fakeTestInfo._runAsStage({ title: 'teardown scopes', runnableType: 'teardown' }, async () => { + await this._fixtureRunner.teardownScope('test', fakeTestInfo); + await this._fixtureRunner.teardownScope('worker', fakeTestInfo); }); this._fatalErrors.push(...fakeTestInfo.errors); } @@ -168,7 +166,7 @@ export class WorkerMain extends ProcessRunner { // and unhandled errors - both lead to the test failing. This is good for regular tests, // so that you can, e.g. expect() from inside an event handler. The test fails, // and we restart the worker. - this._currentTest._failWithError(error, true /* isHardError */, true /* retriable */); + this._currentTest._unhandledError(error); // For tests marked with test.fail(), this might be a problem when unhandled error // is not coming from the user test code (legit failure), but from fixtures or test runner. @@ -308,76 +306,74 @@ export class WorkerMain extends ProcessRunner { this._lastRunningTests.shift(); let shouldRunAfterEachHooks = false; - await testInfo._runWithTimeout(async () => { - await testInfo._runAsStage({ allowAndStopOnSkips: true, stopOnChildError: true }, async () => { - await testInfo._runAsStage({}, async () => { - // Ideally, "trace" would be an config-level option belonging to the - // test runner instead of a fixture belonging to Playwright. - // However, for backwards compatibility, we have to read it from a fixture today. - // We decided to not introduce the config-level option just yet. - const traceFixtureRegistration = test._pool!.resolve('trace'); - if (!traceFixtureRegistration) - return; - if (typeof traceFixtureRegistration.fn === 'function') - throw new Error(`"trace" option cannot be a function`); - await testInfo._tracing.startIfNeeded(traceFixtureRegistration.fn); - }); - - if (this._isStopped || isSkipped) { - // Two reasons to get here: - // - Last test is skipped, so we should not run the test, but run the cleanup. - // - Worker is requested to stop, but was not able to run full cleanup yet. - // We should skip the test, but run the cleanup. - testInfo.status = 'skipped'; + await testInfo._runAsStage({ title: 'setup and test', runnableType: 'test', allowSkip: true, stopOnChildError: true }, async () => { + await testInfo._runAsStage({ title: 'start tracing', canTimeout: true }, async () => { + // Ideally, "trace" would be an config-level option belonging to the + // test runner instead of a fixture belonging to Playwright. + // However, for backwards compatibility, we have to read it from a fixture today. + // We decided to not introduce the config-level option just yet. + const traceFixtureRegistration = test._pool!.resolve('trace'); + if (!traceFixtureRegistration) return; - } + if (typeof traceFixtureRegistration.fn === 'function') + throw new Error(`"trace" option cannot be a function`); + await testInfo._tracing.startIfNeeded(traceFixtureRegistration.fn); + }); - await removeFolders([testInfo.outputDir]); + if (this._isStopped || isSkipped) { + // Two reasons to get here: + // - Last test is skipped, so we should not run the test, but run the cleanup. + // - Worker is requested to stop, but was not able to run full cleanup yet. + // We should skip the test, but run the cleanup. + testInfo.status = 'skipped'; + return; + } - let testFunctionParams: object | null = null; - const beforeHooksStage: TestStage = { stepInfo: { category: 'hook', title: 'Before Hooks' }, stopOnChildError: true }; - await testInfo._runAsStage(beforeHooksStage, async () => { - // Run "beforeAll" hooks, unless already run during previous tests. - for (const suite of suites) - await this._runBeforeAllHooksForSuite(suite, testInfo); + await removeFolders([testInfo.outputDir]); - // Run "beforeEach" hooks. Once started with "beforeEach", we must run all "afterEach" hooks as well. - shouldRunAfterEachHooks = !beforeHooksStage.error && !beforeHooksStage.triggeredSkip; - await this._runEachHooksForSuites(suites, 'beforeEach', testInfo); + let testFunctionParams: object | null = null; + const beforeHooksStage: TestStage = { title: 'Before Hooks', stepCategory: 'hook', stopOnChildError: true }; + await testInfo._runAsStage(beforeHooksStage, async () => { + // Run "beforeAll" hooks, unless already run during previous tests. + for (const suite of suites) + await this._runBeforeAllHooksForSuite(suite, testInfo); - // Setup fixtures required by the test. - testFunctionParams = await this._fixtureRunner.resolveParametersForFunction(test.fn, testInfo, 'test'); - }); + // Run "beforeEach" hooks. Once started with "beforeEach", we must run all "afterEach" hooks as well. + shouldRunAfterEachHooks = !beforeHooksStage.error && !beforeHooksStage.triggeredSkip && !beforeHooksStage.triggeredTimeout; + await this._runEachHooksForSuites(suites, 'beforeEach', testInfo); - if (testFunctionParams === null) { - // Fixture setup failed or was skipped, we should not run the test now. - return; - } + // Setup fixtures required by the test. + testFunctionParams = await this._fixtureRunner.resolveParametersForFunction(test.fn, testInfo, 'test'); + }); - await testInfo._runAsStage({}, async () => { - // Now run the test itself. - debugTest(`test function started`); - const fn = test.fn; // Extract a variable to get a better stack trace ("myTest" vs "TestCase.myTest [as fn]"). - await fn(testFunctionParams, testInfo); - debugTest(`test function finished`); - }); + if (testFunctionParams === null) { + // Fixture setup failed or was skipped, we should not run the test now. + return; + } + + await testInfo._runAsStage({ title: 'test function', canTimeout: true }, async () => { + // Now run the test itself. + const fn = test.fn; // Extract a variable to get a better stack trace ("myTest" vs "TestCase.myTest [as fn]"). + await fn(testFunctionParams, testInfo); }); }); - // Reset stages after a possible timeout. Note: we can remove this if we race each stage against the timeout. - testInfo._resetStages(); + // Update duration, so it is available in fixture teardown and afterEach hooks. + testInfo.duration = testInfo._timeoutManager.defaultSlotTimings().elapsed | 0; // A timed-out test gets a full additional timeout to run after hooks. const afterHooksSlot = testInfo._didTimeout ? { timeout: this._project.project.timeout, elapsed: 0 } : undefined; - await testInfo._runAsStage({ stepInfo: { category: 'hook', title: 'After Hooks' }, runnableType: 'afterHooks', runnableSlot: afterHooksSlot }, async () => { - await testInfo._runWithTimeout(async () => { - // Note: do not wrap all teardown steps together, because failure in any of them - // does not prevent further teardown steps from running. - + await testInfo._runAsStage({ + title: 'After Hooks', + stepCategory: 'hook', + runnableType: 'afterHooks', + runnableSlot: afterHooksSlot, + continueOnChildTimeout: true, // Make sure the full cleanup still runs after regular cleanup timeout. + }, async () => { + // Wrap cleanup steps in a stage, to stop running after one of them times out. + await testInfo._runAsStage({ title: 'regular cleanup' }, async () => { // Run "immediately upon test function finish" callback. - debugTest(`on-test-function-finish callback started`); - await testInfo._runAsStage({}, async () => testInfo._onDidFinishTestFunction?.()); - debugTest(`on-test-function-finish callback finished`); + await testInfo._runAsStage({ title: 'on-test-function-finish', canTimeout: true }, async () => testInfo._onDidFinishTestFunction?.()); // Run "afterEach" hooks, unless we failed at beforeAll stage. if (shouldRunAfterEachHooks) @@ -385,17 +381,20 @@ export class WorkerMain extends ProcessRunner { // Teardown test-scoped fixtures. Attribute to 'test' so that users understand // they should probably increase the test timeout to fix this issue. - debugTest(`tearing down test scope started`); - await this._fixtureRunner.teardownScope('test', testInfo); - debugTest(`tearing down test scope finished`); + await testInfo._runAsStage({ title: 'teardown test scope', runnableType: 'test' }, async () => { + await this._fixtureRunner.teardownScope('test', testInfo); + }); // Run "afterAll" hooks for suites that are not shared with the next test. // In case of failure the worker will be stopped and we have to make sure that afterAll // hooks run before worker fixtures teardown. - for (const suite of reversedSuites) { - if (!nextSuites.has(suite) || testInfo._isFailure()) - await this._runAfterAllHooksForSuite(suite, testInfo); - } + // Continue running "afterAll" hooks even after some of them timeout. + await testInfo._runAsStage({ title: `after hooks suites`, continueOnChildTimeout: true }, async () => { + for (const suite of reversedSuites) { + if (!nextSuites.has(suite) || testInfo._isFailure()) + await this._runAfterAllHooksForSuite(suite, testInfo); + } + }); }); if (testInfo._isFailure()) @@ -407,32 +406,28 @@ export class WorkerMain extends ProcessRunner { this._didRunFullCleanup = true; // Give it more time for the full cleanup. - await testInfo._runWithTimeout(async () => { - debugTest(`running full cleanup after the failure`); - - const teardownSlot = { timeout: this._project.project.timeout, elapsed: 0 }; - await testInfo._runAsStage({ runnableType: 'teardown', runnableSlot: teardownSlot }, async () => { - // Attribute to 'test' so that users understand they should probably increate the test timeout to fix this issue. - debugTest(`tearing down test scope started`); + const teardownSlot = { timeout: this._project.project.timeout, elapsed: 0 }; + await testInfo._runAsStage({ title: 'full cleanup', runnableType: 'teardown', runnableSlot: teardownSlot }, async () => { + // Attribute to 'test' so that users understand they should probably increate the test timeout to fix this issue. + await testInfo._runAsStage({ title: 'teardown test scope', runnableType: 'test' }, async () => { await this._fixtureRunner.teardownScope('test', testInfo); - debugTest(`tearing down test scope finished`); - - for (const suite of reversedSuites) - await this._runAfterAllHooksForSuite(suite, testInfo); - - // Attribute to 'teardown' because worker fixtures are not perceived as a part of a test. - debugTest(`tearing down worker scope started`); - await this._fixtureRunner.teardownScope('worker', testInfo); - debugTest(`tearing down worker scope finished`); }); + + for (const suite of reversedSuites) + await this._runAfterAllHooksForSuite(suite, testInfo); + + // Attribute to 'teardown' because worker fixtures are not perceived as a part of a test. + await this._fixtureRunner.teardownScope('worker', testInfo); }); } }); - await testInfo._runAsStage({}, async () => { + await testInfo._runAsStage({ title: 'stop tracing' }, async () => { await testInfo._tracing.stopIfNeeded(); }); + testInfo.duration = testInfo._timeoutManager.defaultSlotTimings().elapsed | 0; + this._currentTest = null; setCurrentTestInfo(null); this.dispatchEvent('testEnd', buildTestEndPayload(testInfo)); @@ -469,24 +464,25 @@ export class WorkerMain extends ProcessRunner { private async _runBeforeAllHooksForSuite(suite: Suite, testInfo: TestInfoImpl) { if (this._activeSuites.has(suite)) - return 'success'; + return; const extraAnnotations: Annotation[] = []; this._activeSuites.set(suite, extraAnnotations); - return await this._runAllHooksForSuite(suite, testInfo, 'beforeAll', extraAnnotations); + await this._runAllHooksForSuite(suite, testInfo, 'beforeAll', extraAnnotations); } private async _runAllHooksForSuite(suite: Suite, testInfo: TestInfoImpl, type: 'beforeAll' | 'afterAll', extraAnnotations?: Annotation[]) { // Always run all the hooks, and capture the first error. - await testInfo._runAsStage({}, async () => { + await testInfo._runAsStage({ title: `${type} hooks`, continueOnChildTimeout: true }, async () => { for (const hook of this._collectHooksAndModifiers(suite, type, testInfo)) { - debugTest(`${hook.type} hook at "${formatLocation(hook.location)}" started`); // Separate time slot for each beforeAll/afterAll hook. const timeSlot = { timeout: this._project.project.timeout, elapsed: 0 }; const stage: TestStage = { + title: hook.title, runnableType: hook.type, runnableSlot: timeSlot, - stepInfo: { category: 'hook', title: hook.title }, + stepCategory: 'hook', location: hook.location, + continueOnChildTimeout: true, // Make sure to teardown the scope even after hook timeout. }; await testInfo._runAsStage(stage, async () => { const existingAnnotations = new Set(testInfo.annotations); @@ -500,33 +496,33 @@ export class WorkerMain extends ProcessRunner { // Note: we must teardown even after hook fails, because we'll run more hooks. await this._fixtureRunner.teardownScope('test', testInfo); }); - if (stage.error && !this._skipRemainingTestsInSuite) { + if ((stage.error || stage.triggeredTimeout) && type === 'beforeAll' && !this._skipRemainingTestsInSuite) { // This will inform dispatcher that we should not run more tests from this group // because we had a beforeAll error. // This behavior avoids getting the same common error for each test. this._skipRemainingTestsInSuite = suite; } - debugTest(`${hook.type} hook at "${formatLocation(hook.location)}" finished`); } }); } private async _runAfterAllHooksForSuite(suite: Suite, testInfo: TestInfoImpl) { if (!this._activeSuites.has(suite)) - return 'success'; + return; this._activeSuites.delete(suite); - return await this._runAllHooksForSuite(suite, testInfo, 'afterAll'); + await this._runAllHooksForSuite(suite, testInfo, 'afterAll'); } private async _runEachHooksForSuites(suites: Suite[], type: 'beforeEach' | 'afterEach', testInfo: TestInfoImpl) { - // Always run all the hooks, and capture the first error. - await testInfo._runAsStage({}, async () => { + // Wrap hooks in a stage, to always run all of them and capture the first error. + await testInfo._runAsStage({ title: `${type} hooks` }, async () => { const hooks = suites.map(suite => this._collectHooksAndModifiers(suite, type, testInfo)).flat(); for (const hook of hooks) { await testInfo._runAsStage({ + title: hook.title, runnableType: hook.type, location: hook.location, - stepInfo: { category: 'hook', title: hook.title }, + stepCategory: 'hook', }, async () => { await this._fixtureRunner.resolveParametersAndRunFunction(hook.fn, testInfo, 'test'); }); diff --git a/tests/playwright-test/basic.spec.ts b/tests/playwright-test/basic.spec.ts index 4c4b28ceeb..6476255936 100644 --- a/tests/playwright-test/basic.spec.ts +++ b/tests/playwright-test/basic.spec.ts @@ -559,7 +559,7 @@ test('should not allow mixing test types', async ({ runInlineTest }) => { export const test2 = test.extend({ value: 42, }); - + test.describe("test1 suite", () => { test2("test 2", async () => {}); }); diff --git a/tests/playwright-test/timeout.spec.ts b/tests/playwright-test/timeout.spec.ts index 741b10e62f..bed9429ad3 100644 --- a/tests/playwright-test/timeout.spec.ts +++ b/tests/playwright-test/timeout.spec.ts @@ -455,3 +455,27 @@ test('should respect test.describe.configure', async ({ runInlineTest }) => { expect(result.output).toContain('test1-1000'); expect(result.output).toContain('test2-2000'); }); + +test('beforeEach timeout should prevent others from running', async ({ runInlineTest }) => { + const result = await runInlineTest({ + 'a.spec.ts': ` + import { test, expect } from '@playwright/test'; + test.beforeEach(async () => { + console.log('\\n%%beforeEach1'); + await new Promise(f => setTimeout(f, 2500)); + }); + test.beforeEach(async () => { + console.log('\\n%%beforeEach2'); + }); + test('test', async ({}) => { + }); + test.afterEach(async () => { + console.log('\\n%%afterEach'); + await new Promise(f => setTimeout(f, 1500)); + }); + ` + }, { timeout: 2000 }); + expect(result.exitCode).toBe(1); + expect(result.failed).toBe(1); + expect(result.outputLines).toEqual(['beforeEach1', 'afterEach']); +});