chore(test runner): move timeout handling to the top, stop inheriting runnable (#29857)

This commit is contained in:
Dmitry Gozman 2024-03-08 15:19:36 -08:00 committed by GitHub
parent 8f2c372bd8
commit d214778548
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
10 changed files with 213 additions and 176 deletions

View File

@ -17,7 +17,7 @@
import { formatLocation, filterStackFile } from '../util';
import { ManualPromise } from 'playwright-core/lib/utils';
import type { TestInfoImpl } from './testInfo';
import { TimeoutManagerError, type FixtureDescription } from './timeoutManager';
import { TimeoutManagerError, type FixtureDescription, type RunnableDescription } from './timeoutManager';
import { fixtureParameterNames, type FixturePool, type FixtureRegistration, type FixtureScope } from '../common/fixtures';
import type { WorkerInfo } from '../../types/test';
import type { Location } from '../../types/testReporter';
@ -32,8 +32,7 @@ class Fixture {
private _selfTeardownComplete: Promise<void> | undefined;
private _setupDescription: FixtureDescription;
private _teardownDescription: FixtureDescription;
private _shouldGenerateStep = false;
private _isInternalFixture = false;
private _stepInfo: { category: 'fixture', location?: Location } | undefined;
_deps = new Set<Fixture>();
_usages = new Set<Fixture>();
@ -41,22 +40,24 @@ class Fixture {
this.runner = runner;
this.registration = registration;
this.value = null;
const shouldGenerateStep = !this.registration.hideStep && !this.registration.name.startsWith('_') && !this.registration.option;
const isInternalFixture = this.registration.location && filterStackFile(this.registration.location.file);
const title = this.registration.customTitle || this.registration.name;
const location = isInternalFixture ? this.registration.location : undefined;
this._stepInfo = shouldGenerateStep ? { category: 'fixture', location } : undefined;
this._setupDescription = {
title,
phase: 'setup',
location: registration.location,
location,
slot: this.registration.timeout === undefined ? undefined : {
timeout: this.registration.timeout,
elapsed: 0,
}
};
this._teardownDescription = { ...this._setupDescription, phase: 'teardown' };
this._shouldGenerateStep = !this.registration.hideStep && !this.registration.name.startsWith('_') && !this.registration.option;
this._isInternalFixture = this.registration.location && filterStackFile(this.registration.location.file);
}
async setup(testInfo: TestInfoImpl) {
async setup(testInfo: TestInfoImpl, runnable: RunnableDescription) {
this.runner.instanceForId.set(this.registration.id, this);
if (typeof this.registration.fn !== 'function') {
@ -66,13 +67,10 @@ class Fixture {
await testInfo._runAsStage({
title: `fixture: ${this.registration.name}`,
canTimeout: true,
location: this._isInternalFixture ? this.registration.location : undefined,
stepCategory: this._shouldGenerateStep ? 'fixture' : undefined,
runnable: { ...runnable, fixture: this._setupDescription },
stepInfo: this._stepInfo,
}, async () => {
testInfo._timeoutManager.setCurrentFixture(this._setupDescription);
await this._setupInternal(testInfo);
testInfo._timeoutManager.setCurrentFixture(undefined);
});
}
@ -126,16 +124,13 @@ class Fixture {
await useFuncStarted;
}
async teardown(testInfo: TestInfoImpl) {
async teardown(testInfo: TestInfoImpl, runnable: RunnableDescription) {
await testInfo._runAsStage({
title: `fixture: ${this.registration.name}`,
canTimeout: true,
location: this._isInternalFixture ? this.registration.location : undefined,
stepCategory: this._shouldGenerateStep ? 'fixture' : undefined,
runnable: { ...runnable, fixture: this._teardownDescription },
stepInfo: this._stepInfo,
}, async () => {
testInfo._timeoutManager.setCurrentFixture(this._teardownDescription);
await this._teardownInternal();
testInfo._timeoutManager.setCurrentFixture(undefined);
});
}
@ -202,7 +197,7 @@ export class FixtureRunner {
collector.add(registration);
}
async teardownScope(scope: FixtureScope, testInfo: TestInfoImpl) {
async teardownScope(scope: FixtureScope, testInfo: TestInfoImpl, runnable: RunnableDescription) {
// Teardown fixtures in the reverse order.
const fixtures = Array.from(this.instanceForId.values()).reverse();
const collector = new Set<Fixture>();
@ -212,7 +207,7 @@ export class FixtureRunner {
let firstError: Error | undefined;
for (const fixture of collector) {
try {
await fixture.teardown(testInfo);
await fixture.teardown(testInfo, runnable);
} catch (error) {
if (error instanceof TimeoutManagerError)
throw error;
@ -231,7 +226,7 @@ export class FixtureRunner {
}
}
async resolveParametersForFunction(fn: Function, testInfo: TestInfoImpl, autoFixtures: 'worker' | 'test' | 'all-hooks-only'): Promise<object | null> {
async resolveParametersForFunction(fn: Function, testInfo: TestInfoImpl, autoFixtures: 'worker' | 'test' | 'all-hooks-only', runnable: RunnableDescription): Promise<object | null> {
const collector = new Set<FixtureRegistration>();
// Collect automatic fixtures.
@ -256,7 +251,7 @@ export class FixtureRunner {
// Setup fixtures.
for (const registration of collector)
await this._setupFixtureForRegistration(registration, testInfo);
await this._setupFixtureForRegistration(registration, testInfo, runnable);
// Create params object.
const params: { [key: string]: any } = {};
@ -270,18 +265,18 @@ export class FixtureRunner {
return params;
}
async resolveParametersAndRunFunction(fn: Function, testInfo: TestInfoImpl, autoFixtures: 'worker' | 'test' | 'all-hooks-only') {
const params = await this.resolveParametersForFunction(fn, testInfo, autoFixtures);
async resolveParametersAndRunFunction(fn: Function, testInfo: TestInfoImpl, autoFixtures: 'worker' | 'test' | 'all-hooks-only', runnable: RunnableDescription) {
const params = await this.resolveParametersForFunction(fn, testInfo, autoFixtures, runnable);
if (params === null) {
// Do not run the function when fixture setup has already failed.
return null;
}
await testInfo._runAsStage({ title: 'run function', canTimeout: true }, async () => {
await testInfo._runAsStage({ title: 'run function', runnable }, async () => {
await fn(params, testInfo);
});
}
private async _setupFixtureForRegistration(registration: FixtureRegistration, testInfo: TestInfoImpl): Promise<Fixture> {
private async _setupFixtureForRegistration(registration: FixtureRegistration, testInfo: TestInfoImpl, runnable: RunnableDescription): Promise<Fixture> {
if (registration.scope === 'test')
this.testScopeClean = false;
@ -290,7 +285,7 @@ export class FixtureRunner {
return fixture;
fixture = new Fixture(this, registration);
await fixture.setup(testInfo);
await fixture.setup(testInfo, runnable);
return fixture;
}

View File

@ -21,7 +21,7 @@ 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, TimeoutManagerError } from './timeoutManager';
import type { RunnableDescription, RunnableType, TimeSlot } from './timeoutManager';
import type { RunnableDescription } from './timeoutManager';
import type { Annotation, FullConfigInternal, FullProjectInternal } from '../common/config';
import type { Location } from '../../types/testReporter';
import { debugTest, filteredStackTrace, formatLocation, getContainedPath, normalizeAndSaveAttachment, serializeError, trimLongString } from '../util';
@ -50,12 +50,8 @@ export interface TestStepInternal {
export type TestStage = {
title: string;
location?: Location;
stepCategory?: 'hook' | 'fixture';
runnableType?: RunnableType;
runnableSlot?: TimeSlot;
canTimeout?: boolean;
allowSkip?: boolean;
stepInfo?: { category: 'hook' | 'fixture', location?: Location };
runnable?: RunnableDescription;
step?: TestStepInternal;
};
@ -69,7 +65,6 @@ export class TestInfoImpl implements TestInfo {
private _hasHardError: boolean = false;
readonly _tracing: TestTracing;
_didTimeout = false;
_wasInterrupted = false;
_lastStepId = 0;
private readonly _requireFile: string;
@ -79,6 +74,7 @@ export class TestInfoImpl implements TestInfo {
_onDidFinishTestFunction: (() => Promise<void>) | undefined;
private readonly _stages: TestStage[] = [];
_hasNonRetriableError = false;
_allowSkips = false;
// ------------ TestInfo fields ------------
readonly testId: string;
@ -354,13 +350,13 @@ export class TestInfoImpl implements TestInfo {
// Do not overwrite any previous hard errors.
// Some (but not all) scenarios include:
// - expect() that fails after uncaught exception.
// - fail after the timeout, e.g. due to fixture teardown.
// - fail in fixture teardown after the test failure.
if (isHardError && this._hasHardError)
return;
if (isHardError)
this._hasHardError = true;
if (this.status === 'passed' || this.status === 'skipped')
this.status = 'failed';
this.status = error instanceof TimeoutManagerError ? 'timedOut' : 'failed';
const serialized = serializeError(error);
const step = (error as any)[stepSymbol] as TestStepInternal | undefined;
if (step && step.boxedStack)
@ -370,43 +366,29 @@ export class TestInfoImpl implements TestInfo {
}
async _runAsStage(stage: TestStage, cb: () => Promise<any>) {
// Inherit some properties from parent.
const parent = this._stages[this._stages.length - 1];
stage.allowSkip = stage.allowSkip ?? parent?.allowSkip ?? false;
if (debugTest.enabled) {
const location = stage.location ? ` at "${formatLocation(stage.location)}"` : ``;
const location = stage.runnable?.location ? ` at "${formatLocation(stage.runnable.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;
stage.step = stage.stepInfo ? this._addStep({ ...stage.stepInfo, title: stage.title, 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;
}
}
try {
await this._timeoutManager.withRunnable(runnable, async () => {
// Note: separate try/catch is here to report errors after timeout.
// This way we get a nice "locator.click" error after the test times out and closes the page.
await this._timeoutManager.withRunnable(stage.runnable, async () => {
try {
await cb();
} catch (e) {
if (stage.allowSkip && (e instanceof SkipError)) {
if (this._allowSkips && (e instanceof SkipError)) {
if (this.status === 'passed')
this.status = 'skipped';
} else if (!(e instanceof TimeoutManagerError)) {
// Do not consider timeout errors in child stages as a regular "hard error".
// Note: we handle timeout errors at the top level, so ignore them here.
// Unfortunately, we cannot ignore user errors here. Consider the following scenario:
// - locator.click times out
// - all stages containing the test function finish with TimeoutManagerError
// - test finishes, the page is closed and this triggers locator.click error
// - we would like to present the locator.click error to the user
// - therefore, we need a try/catch inside the "run with timeout" block and capture the error
this._failWithError(e, true /* isHardError */, true /* retriable */);
}
throw e;
@ -414,17 +396,6 @@ export class TestInfoImpl implements TestInfo {
});
stage.step?.complete({});
} catch (error) {
// When interrupting, we arrive here with a TimeoutManagerError, but we should not
// consider it a timeout.
if (!this._wasInterrupted && !this._didTimeout && (error instanceof TimeoutManagerError)) {
this._didTimeout = true;
const serialized = serializeError(error);
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';
}
stage.step?.complete({ error });
throw error;
} finally {
@ -435,6 +406,13 @@ export class TestInfoImpl implements TestInfo {
}
}
_handlePossibleTimeoutError(error: Error) {
// When interrupting, we arrive here with a TimeoutManagerError, but we should not
// consider it a timeout.
if (!this._wasInterrupted && (error instanceof TimeoutManagerError))
this._failWithError(error, false /* isHardError */, true /* retriable */);
}
_isFailure() {
return this.status !== 'skipped' && this.status !== this.expectedStatus;
}

View File

@ -23,32 +23,30 @@ export type TimeSlot = {
elapsed: number;
};
export type RunnableType = 'test' | 'beforeAll' | 'afterAll' | 'beforeEach' | 'afterEach' | 'afterHooks' | 'slow' | 'skip' | 'fail' | 'fixme' | 'teardown';
type RunnableType = 'test' | 'beforeAll' | 'afterAll' | 'beforeEach' | 'afterEach' | 'slow' | 'skip' | 'fail' | 'fixme' | 'teardown';
export type RunnableDescription = {
type: RunnableType;
location?: Location;
slot?: TimeSlot; // Falls back to test slot.
fixture?: FixtureDescription;
};
export type FixtureDescription = {
title: string;
phase: 'setup' | 'teardown';
location?: Location;
slot?: TimeSlot; // Falls back to current runnable slot.
slot?: TimeSlot; // Falls back to the runnable slot.
};
export class TimeoutManager {
private _defaultSlot: TimeSlot;
private _defaultRunnable: RunnableDescription;
private _runnable: RunnableDescription;
private _fixture: FixtureDescription | undefined;
private _timeoutRunner: TimeoutRunner;
constructor(timeout: number) {
this._defaultSlot = { timeout, elapsed: 0 };
this._defaultRunnable = { type: 'test', slot: this._defaultSlot };
this._runnable = this._defaultRunnable;
this._runnable = { type: 'test' };
this._timeoutRunner = new TimeoutRunner(timeout);
}
@ -59,11 +57,7 @@ export class TimeoutManager {
async withRunnable<T>(runnable: RunnableDescription | undefined, cb: () => Promise<T>): Promise<T> {
if (!runnable)
return await cb();
const existingRunnable = this._runnable;
const effectiveRunnable = { ...runnable };
if (!effectiveRunnable.slot)
effectiveRunnable.slot = this._runnable.slot;
this._updateRunnables(effectiveRunnable, undefined);
this._updateRunnable(runnable);
try {
return await this._timeoutRunner.run(cb);
} catch (error) {
@ -71,14 +65,10 @@ export class TimeoutManager {
throw error;
throw this._createTimeoutError();
} finally {
this._updateRunnables(existingRunnable, undefined);
this._updateRunnable({ type: 'test' });
}
}
setCurrentFixture(fixture: FixtureDescription | undefined) {
this._updateRunnables(this._runnable, fixture);
}
defaultSlotTimings() {
const slot = this._currentSlot();
slot.elapsed = this._timeoutRunner.elapsed();
@ -100,7 +90,7 @@ export class TimeoutManager {
}
currentRunnableType() {
return this._runnable.type;
return this._runnable?.type || 'test';
}
currentSlotDeadline() {
@ -108,15 +98,14 @@ export class TimeoutManager {
}
private _currentSlot() {
return this._fixture?.slot || this._runnable.slot || this._defaultSlot;
return this._runnable.fixture?.slot || this._runnable.slot || this._defaultSlot;
}
private _updateRunnables(runnable: RunnableDescription, fixture: FixtureDescription | undefined) {
private _updateRunnable(runnable: RunnableDescription) {
let slot = this._currentSlot();
slot.elapsed = this._timeoutRunner.elapsed();
this._runnable = runnable;
this._fixture = fixture;
slot = this._currentSlot();
this._timeoutRunner.updateTimeout(slot.timeout, slot.elapsed);
@ -125,15 +114,14 @@ export class TimeoutManager {
private _createTimeoutError(): Error {
let message = '';
const timeout = this._currentSlot().timeout;
switch (this._runnable.type) {
case 'afterHooks':
switch (this._runnable.type || 'test') {
case 'test': {
if (this._fixture) {
if (this._fixture.phase === 'setup') {
message = `Test timeout of ${timeout}ms exceeded while setting up "${this._fixture.title}".`;
if (this._runnable.fixture) {
if (this._runnable.fixture.phase === 'setup') {
message = `Test timeout of ${timeout}ms exceeded while setting up "${this._runnable.fixture.title}".`;
} else {
message = [
`Test finished within timeout of ${timeout}ms, but tearing down "${this._fixture.title}" ran out of time.`,
`Test finished within timeout of ${timeout}ms, but tearing down "${this._runnable.fixture.title}" ran out of time.`,
`Please allow more time for the test, since teardown is attributed towards the test timeout budget.`,
].join('\n');
}
@ -151,8 +139,8 @@ export class TimeoutManager {
message = `"${this._runnable.type}" hook timeout of ${timeout}ms exceeded.`;
break;
case 'teardown': {
if (this._fixture)
message = `Worker teardown timeout of ${timeout}ms exceeded while ${this._fixture.phase === 'setup' ? 'setting up' : 'tearing down'} "${this._fixture.title}".`;
if (this._runnable.fixture)
message = `Worker teardown timeout of ${timeout}ms exceeded while ${this._runnable.fixture.phase === 'setup' ? 'setting up' : 'tearing down'} "${this._runnable.fixture.title}".`;
else
message = `Worker teardown timeout of ${timeout}ms exceeded.`;
break;
@ -164,7 +152,7 @@ export class TimeoutManager {
message = `"${this._runnable.type}" modifier timeout of ${timeout}ms exceeded.`;
break;
}
const fixtureWithSlot = this._fixture?.slot ? this._fixture : undefined;
const fixtureWithSlot = this._runnable.fixture?.slot ? this._runnable.fixture : undefined;
if (fixtureWithSlot)
message = `Fixture "${fixtureWithSlot.title}" timeout of ${timeout}ms exceeded during ${fixtureWithSlot.phase}.`;
message = colors.red(message);

View File

@ -31,7 +31,7 @@ import { PoolBuilder } from '../common/poolBuilder';
import type { TestInfoError } from '../../types/test';
import type { Location } from '../../types/testReporter';
import { inheritFixutreNames } from '../common/fixtures';
import { TimeoutManagerError } from './timeoutManager';
import { type TimeSlot, TimeoutManagerError } from './timeoutManager';
export class WorkerMain extends ProcessRunner {
private _params: WorkerInitParams;
@ -145,15 +145,10 @@ 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({ title: 'teardown scopes', runnableType: 'teardown' }, async () => {
try {
await this._fixtureRunner.teardownScope('test', fakeTestInfo);
} finally {
await this._fixtureRunner.teardownScope('worker', fakeTestInfo);
}
});
const runnable = { type: 'teardown' } as const;
await this._fixtureRunner.teardownScope('test', fakeTestInfo, runnable).catch(error => fakeTestInfo._handlePossibleTimeoutError(error));
await this._fixtureRunner.teardownScope('worker', fakeTestInfo, runnable).catch(error => fakeTestInfo._handlePossibleTimeoutError(error));
this._fatalErrors.push(...fakeTestInfo.errors);
}
@ -310,8 +305,9 @@ export class WorkerMain extends ProcessRunner {
this._lastRunningTests.shift();
let shouldRunAfterEachHooks = false;
await testInfo._runAsStage({ title: 'setup and test', runnableType: 'test', allowSkip: true }, async () => {
await testInfo._runAsStage({ title: 'start tracing', canTimeout: true }, async () => {
testInfo._allowSkips = true;
await testInfo._runAsStage({ title: 'setup and test' }, async () => {
await testInfo._runAsStage({ title: 'start tracing', runnable: { type: 'test' } }, 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.
@ -336,7 +332,7 @@ export class WorkerMain extends ProcessRunner {
await removeFolders([testInfo.outputDir]);
let testFunctionParams: object | null = null;
await testInfo._runAsStage({ title: 'Before Hooks', stepCategory: 'hook' }, async () => {
await testInfo._runAsStage({ title: 'Before Hooks', stepInfo: { category: 'hook' } }, async () => {
// Run "beforeAll" hooks, unless already run during previous tests.
for (const suite of suites)
await this._runBeforeAllHooksForSuite(suite, testInfo);
@ -346,7 +342,7 @@ export class WorkerMain extends ProcessRunner {
await this._runEachHooksForSuites(suites, 'beforeEach', testInfo);
// Setup fixtures required by the test.
testFunctionParams = await this._fixtureRunner.resolveParametersForFunction(test.fn, testInfo, 'test');
testFunctionParams = await this._fixtureRunner.resolveParametersForFunction(test.fn, testInfo, 'test', { type: 'test' });
});
if (testFunctionParams === null) {
@ -354,58 +350,54 @@ export class WorkerMain extends ProcessRunner {
return;
}
await testInfo._runAsStage({ title: 'test function', canTimeout: true }, async () => {
await testInfo._runAsStage({ title: 'test function', runnable: { type: 'test' } }, 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);
});
}).catch(() => {}); // Ignore top-level error, we still have to run after hooks.
}).catch(error => testInfo._handlePossibleTimeoutError(error));
// Update duration, so it is available in fixture teardown and afterEach hooks.
testInfo.duration = testInfo._timeoutManager.defaultSlotTimings().elapsed | 0;
// No skips in after hooks.
testInfo._allowSkips = true;
// After hooks get an additional timeout.
const afterHooksTimeout = calculateMaxTimeout(this._project.project.timeout, testInfo.timeout);
const afterHooksSlot = { timeout: afterHooksTimeout, elapsed: 0 };
await testInfo._runAsStage({
title: 'After Hooks',
stepCategory: 'hook',
runnableType: 'afterHooks',
runnableSlot: afterHooksSlot,
}, async () => {
await testInfo._runAsStage({ title: 'After Hooks', stepInfo: { category: 'hook' } }, async () => {
let firstAfterHooksError: Error | undefined;
let didTimeoutInRegularCleanup = false;
let didTimeoutInAfterHooks = false;
try {
// Run "immediately upon test function finish" callback.
await testInfo._runAsStage({ title: 'on-test-function-finish', canTimeout: true }, async () => testInfo._onDidFinishTestFunction?.());
await testInfo._runAsStage({ title: 'on-test-function-finish', runnable: { type: 'test', slot: afterHooksSlot } }, async () => testInfo._onDidFinishTestFunction?.());
} catch (error) {
if (error instanceof TimeoutManagerError)
didTimeoutInRegularCleanup = true;
didTimeoutInAfterHooks = true;
firstAfterHooksError = firstAfterHooksError ?? error;
}
try {
// Run "afterEach" hooks, unless we failed at beforeAll stage.
if (!didTimeoutInRegularCleanup && shouldRunAfterEachHooks)
await this._runEachHooksForSuites(reversedSuites, 'afterEach', testInfo);
if (!didTimeoutInAfterHooks && shouldRunAfterEachHooks)
await this._runEachHooksForSuites(reversedSuites, 'afterEach', testInfo, afterHooksSlot);
} catch (error) {
if (error instanceof TimeoutManagerError)
didTimeoutInRegularCleanup = true;
didTimeoutInAfterHooks = true;
firstAfterHooksError = firstAfterHooksError ?? error;
}
try {
if (!didTimeoutInRegularCleanup) {
if (!didTimeoutInAfterHooks) {
// Teardown test-scoped fixtures. Attribute to 'test' so that users understand
// they should probably increase the test timeout to fix this issue.
await testInfo._runAsStage({ title: 'teardown test scope', runnableType: 'test' }, async () => {
await this._fixtureRunner.teardownScope('test', testInfo);
});
await this._fixtureRunner.teardownScope('test', testInfo, { type: 'test', slot: afterHooksSlot });
}
} catch (error) {
if (error instanceof TimeoutManagerError)
didTimeoutInRegularCleanup = true;
didTimeoutInAfterHooks = true;
firstAfterHooksError = firstAfterHooksError ?? error;
}
@ -422,51 +414,54 @@ export class WorkerMain extends ProcessRunner {
}
}
}
if (firstAfterHooksError)
throw firstAfterHooksError;
}).catch(error => testInfo._handlePossibleTimeoutError(error));
if (testInfo._isFailure())
this._isStopped = true;
if (testInfo._isFailure())
this._isStopped = true;
if (this._isStopped) {
// Run all remaining "afterAll" hooks and teardown all fixtures when worker is shutting down.
// Mark as "cleaned up" early to avoid running cleanup twice.
this._didRunFullCleanup = true;
if (this._isStopped) {
// Run all remaining "afterAll" hooks and teardown all fixtures when worker is shutting down.
// Mark as "cleaned up" early to avoid running cleanup twice.
this._didRunFullCleanup = true;
await testInfo._runAsStage({ title: 'Worker Cleanup', stepInfo: { category: 'hook' } }, async () => {
let firstWorkerCleanupError: Error | undefined;
// Give it more time for the full cleanup.
const teardownSlot = { timeout: this._project.project.timeout, elapsed: 0 };
try {
// 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', runnableSlot: teardownSlot }, async () => {
await this._fixtureRunner.teardownScope('test', testInfo);
});
await this._fixtureRunner.teardownScope('test', testInfo, { type: 'test', slot: teardownSlot });
} catch (error) {
firstAfterHooksError = firstAfterHooksError ?? error;
firstWorkerCleanupError = firstWorkerCleanupError ?? error;
}
for (const suite of reversedSuites) {
try {
await this._runAfterAllHooksForSuite(suite, testInfo);
} catch (error) {
firstAfterHooksError = firstAfterHooksError ?? error;
firstWorkerCleanupError = firstWorkerCleanupError ?? error;
}
}
try {
// Attribute to 'teardown' because worker fixtures are not perceived as a part of a test.
await testInfo._runAsStage({ title: 'teardown worker scope', runnableType: 'teardown', runnableSlot: teardownSlot }, async () => {
await this._fixtureRunner.teardownScope('worker', testInfo);
});
await this._fixtureRunner.teardownScope('worker', testInfo, { type: 'teardown', slot: teardownSlot });
} catch (error) {
firstAfterHooksError = firstAfterHooksError ?? error;
firstWorkerCleanupError = firstWorkerCleanupError ?? error;
}
}
if (firstAfterHooksError)
throw firstAfterHooksError;
}).catch(() => {}); // Ignore top-level error.
if (firstWorkerCleanupError)
throw firstWorkerCleanupError;
}).catch(error => testInfo._handlePossibleTimeoutError(error));
}
await testInfo._runAsStage({ title: 'stop tracing' }, async () => {
const tracingSlot = { timeout: this._project.project.timeout, elapsed: 0 };
await testInfo._runAsStage({ title: 'stop tracing', runnable: { type: 'test', slot: tracingSlot } }, async () => {
await testInfo._tracing.stopIfNeeded();
}).catch(() => {}); // Ignore top-level error.
}).catch(error => testInfo._handlePossibleTimeoutError(error));
testInfo.duration = (testInfo._timeoutManager.defaultSlotTimings().elapsed + afterHooksSlot.elapsed) | 0;
@ -517,18 +512,13 @@ export class WorkerMain extends ProcessRunner {
let firstError: Error | undefined;
for (const hook of this._collectHooksAndModifiers(suite, type, testInfo)) {
try {
// Separate time slot for each beforeAll/afterAll hook.
const timeSlot = { timeout: this._project.project.timeout, elapsed: 0 };
await testInfo._runAsStage({
title: hook.title,
runnableType: hook.type,
runnableSlot: timeSlot,
stepCategory: 'hook',
location: hook.location,
}, async () => {
await testInfo._runAsStage({ title: hook.title, stepInfo: { category: 'hook', location: hook.location } }, async () => {
// Separate time slot for each beforeAll/afterAll hook.
const timeSlot = { timeout: this._project.project.timeout, elapsed: 0 };
const runnable = { type: hook.type, slot: timeSlot, location: hook.location };
const existingAnnotations = new Set(testInfo.annotations);
try {
await this._fixtureRunner.resolveParametersAndRunFunction(hook.fn, testInfo, 'all-hooks-only');
await this._fixtureRunner.resolveParametersAndRunFunction(hook.fn, testInfo, 'all-hooks-only', runnable);
} finally {
if (extraAnnotations) {
// Inherit all annotations defined in the beforeAll/modifer to all tests in the suite.
@ -537,7 +527,7 @@ export class WorkerMain extends ProcessRunner {
}
// Each beforeAll/afterAll hook has its own scope for test fixtures. Attribute to the same runnable and timeSlot.
// Note: we must teardown even after hook fails, because we'll run more hooks.
await this._fixtureRunner.teardownScope('test', testInfo);
await this._fixtureRunner.teardownScope('test', testInfo, runnable);
}
});
} catch (error) {
@ -564,19 +554,15 @@ export class WorkerMain extends ProcessRunner {
await this._runAllHooksForSuite(suite, testInfo, 'afterAll');
}
private async _runEachHooksForSuites(suites: Suite[], type: 'beforeEach' | 'afterEach', testInfo: TestInfoImpl) {
private async _runEachHooksForSuites(suites: Suite[], type: 'beforeEach' | 'afterEach', testInfo: TestInfoImpl, slot?: TimeSlot) {
// Always run all the hooks, unless one of the times out, and capture the first error.
let firstError: Error | undefined;
const hooks = suites.map(suite => this._collectHooksAndModifiers(suite, type, testInfo)).flat();
for (const hook of hooks) {
try {
await testInfo._runAsStage({
title: hook.title,
runnableType: hook.type,
location: hook.location,
stepCategory: 'hook',
}, async () => {
await this._fixtureRunner.resolveParametersAndRunFunction(hook.fn, testInfo, 'test');
await testInfo._runAsStage({ title: hook.title, stepInfo: { category: 'hook', location: hook.location } }, async () => {
const runnable = { type: hook.type, location: hook.location, slot };
await this._fixtureRunner.resolveParametersAndRunFunction(hook.fn, testInfo, 'test', runnable);
});
} catch (error) {
if (error instanceof TimeoutManagerError)

View File

@ -526,7 +526,7 @@ test('afterAll timeout should be reported, run other afterAll hooks, and continu
test.afterAll(async () => {
console.log('\\n%%afterAll2');
});
test('does not run', () => {
test('run in a different worker', () => {
console.log('\\n%%test2');
});
`,

View File

@ -129,6 +129,7 @@ test('should record api trace', async ({ runInlineTest, server }, testInfo) => {
' fixture: context',
' fixture: request',
' apiRequestContext.dispose',
'Worker Cleanup',
' fixture: browser',
]);
});
@ -332,6 +333,7 @@ test('should not override trace file in afterAll', async ({ runInlineTest, serve
' apiRequestContext.get',
' fixture: request',
' apiRequestContext.dispose',
'Worker Cleanup',
' fixture: browser',
]);
expect(trace1.errors).toEqual([`'oh no!'`]);
@ -667,6 +669,7 @@ test('should show non-expect error in trace', async ({ runInlineTest }, testInfo
'After Hooks',
' fixture: page',
' fixture: context',
'Worker Cleanup',
' fixture: browser',
]);
expect(trace.errors).toEqual(['ReferenceError: undefinedVariable1 is not defined']);
@ -985,6 +988,7 @@ test('should record nested steps, even after timeout', async ({ runInlineTest },
' barPage teardown',
' step in barPage teardown',
' page.close',
'Worker Cleanup',
' fixture: browser',
]);
});
@ -1029,6 +1033,7 @@ test('should attribute worker fixture teardown to the right test', async ({ runI
expect(trace2.actionTree).toEqual([
'Before Hooks',
'After Hooks',
'Worker Cleanup',
' fixture: foo',
' step in foo teardown',
]);

View File

@ -277,6 +277,8 @@ for (const useIntermediateMergeReport of [false, true] as const) {
`end {\"title\":\"expect.toBeTruthy\",\"category\":\"expect\",\"error\":{\"message\":\"Error: \\u001b[2mexpect(\\u001b[22m\\u001b[31mreceived\\u001b[39m\\u001b[2m).\\u001b[22mtoBeTruthy\\u001b[2m()\\u001b[22m\\n\\nReceived: \\u001b[31mfalse\\u001b[39m\",\"stack\":\"<stack>\",\"location\":\"<location>\",\"snippet\":\"<snippet>\"}}`,
`begin {\"title\":\"After Hooks\",\"category\":\"hook\"}`,
`end {\"title\":\"After Hooks\",\"category\":\"hook\"}`,
`begin {\"title\":\"Worker Cleanup\",\"category\":\"hook\"}`,
`end {\"title\":\"Worker Cleanup\",\"category\":\"hook\"}`,
`begin {\"title\":\"Before Hooks\",\"category\":\"hook\"}`,
`end {\"title\":\"Before Hooks\",\"category\":\"hook\"}`,
`begin {\"title\":\"expect.not.toBeTruthy\",\"category\":\"expect\"}`,
@ -460,9 +462,11 @@ for (const useIntermediateMergeReport of [false, true] as const) {
`end {\"title\":\"fixture: page\",\"category\":\"fixture\"}`,
`begin {\"title\":\"fixture: context\",\"category\":\"fixture\"}`,
`end {\"title\":\"fixture: context\",\"category\":\"fixture\"}`,
`end {\"title\":\"After Hooks\",\"category\":\"hook\",\"steps\":[{\"title\":\"fixture: page\",\"category\":\"fixture\"},{\"title\":\"fixture: context\",\"category\":\"fixture\"}]}`,
`begin {\"title\":\"Worker Cleanup\",\"category\":\"hook\"}`,
`begin {\"title\":\"fixture: browser\",\"category\":\"fixture\"}`,
`end {\"title\":\"fixture: browser\",\"category\":\"fixture\"}`,
`end {\"title\":\"After Hooks\",\"category\":\"hook\",\"steps\":[{\"title\":\"fixture: page\",\"category\":\"fixture\"},{\"title\":\"fixture: context\",\"category\":\"fixture\"},{\"title\":\"fixture: browser\",\"category\":\"fixture\"}]}`,
`end {\"title\":\"Worker Cleanup\",\"category\":\"hook\",\"steps\":[{\"title\":\"fixture: browser\",\"category\":\"fixture\"}]}`,
]);
});

View File

@ -261,6 +261,10 @@ test('should report before hooks step error', async ({ runInlineTest }) => {
category: 'hook',
title: 'After Hooks',
},
{
category: 'hook',
title: 'Worker Cleanup',
},
{
error: expect.any(Object)
}
@ -345,6 +349,12 @@ test('should not report nested after hooks', async ({ runInlineTest }) => {
category: 'fixture',
title: 'fixture: context',
},
],
},
{
category: 'hook',
title: 'Worker Cleanup',
steps: [
{
category: 'fixture',
title: 'fixture: browser',
@ -577,6 +587,10 @@ test('should report custom expect steps', async ({ runInlineTest }) => {
category: 'hook',
title: 'After Hooks',
},
{
category: 'hook',
title: 'Worker Cleanup',
},
{
error: expect.any(Object)
}
@ -658,6 +672,7 @@ test('should mark step as failed when soft expect fails', async ({ runInlineTest
location: { file: 'a.test.ts', line: expect.any(Number), column: expect.any(Number) }
},
{ title: 'After Hooks', category: 'hook' },
{ title: 'Worker Cleanup', category: 'hook' },
{ error: expect.any(Object) }
]);
});
@ -972,6 +987,12 @@ test('should not mark page.close as failed when page.click fails', async ({ runI
},
],
},
],
},
{
category: 'hook',
title: 'Worker Cleanup',
steps: [
{
category: 'fixture',
title: 'fixture: browser',
@ -1168,6 +1189,10 @@ test('should show final toPass error', async ({ runInlineTest }) => {
title: 'After Hooks',
category: 'hook',
},
{
title: 'Worker Cleanup',
category: 'hook',
},
{
error: {
message: expect.stringContaining('Error: expect(received).toBe(expected)'),
@ -1255,6 +1280,10 @@ test('should propagate nested soft errors', async ({ runInlineTest }) => {
category: 'hook',
title: 'After Hooks',
},
{
category: 'hook',
title: 'Worker Cleanup',
},
{
error: {
message: expect.stringContaining('Error: expect(received).toBe(expected)'),
@ -1348,6 +1377,10 @@ test('should not propagate nested hard errors', async ({ runInlineTest }) => {
category: 'hook',
title: 'After Hooks',
},
{
category: 'hook',
title: 'Worker Cleanup',
},
{
error: {
message: expect.stringContaining('Error: expect(received).toBe(expected)'),
@ -1404,6 +1437,10 @@ test('should step w/o box', async ({ runInlineTest }) => {
category: 'hook',
title: 'After Hooks',
},
{
category: 'hook',
title: 'Worker Cleanup',
},
{
error: {
message: expect.stringContaining('Error: expect(received).toBe(expected)'),
@ -1453,6 +1490,10 @@ test('should step w/ box', async ({ runInlineTest }) => {
category: 'hook',
title: 'After Hooks',
},
{
category: 'hook',
title: 'Worker Cleanup',
},
{
error: {
message: expect.stringContaining('expect(received).toBe(expected)'),
@ -1502,6 +1543,10 @@ test('should soft step w/ box', async ({ runInlineTest }) => {
category: 'hook',
title: 'After Hooks',
},
{
category: 'hook',
title: 'Worker Cleanup',
},
{
error: {
message: expect.stringContaining('Error: expect(received).toBe(expected)'),

View File

@ -479,3 +479,38 @@ test('beforeEach timeout should prevent others from running', async ({ runInline
expect(result.failed).toBe(1);
expect(result.outputLines).toEqual(['beforeEach1', 'afterEach']);
});
test('should report up to 3 timeout errors', async ({ runInlineTest }) => {
const result = await runInlineTest({
'a.spec.ts': `
import { test as base } from '@playwright/test';
const test = base.extend<{}, { autoWorker: void }>({
autoWorker: [
async ({}, use) => {
await use();
await new Promise(() => {});
},
{ scope: 'worker', auto: true },
],
})
test('test1', async () => {
await new Promise(() => {});
});
test.afterEach(async () => {
await new Promise(() => {});
});
test.afterAll(async () => {
await new Promise(() => {});
});
`
}, { timeout: 1000 });
expect(result.exitCode).toBe(1);
expect(result.failed).toBe(1);
expect(result.output).toContain('Test timeout of 1000ms exceeded.');
expect(result.output).toContain('Test timeout of 1000ms exceeded while running "afterEach" hook.');
expect(result.output).toContain('Worker teardown timeout of 1000ms exceeded while tearing down "autoWorker".');
});

View File

@ -96,6 +96,7 @@ test('should merge screenshot assertions', async ({ runUITest }, testInfo) => {
/expect.toHaveScreenshot[\d.]+m?s/,
/attach "trace-test-1-actual.png/,
/After Hooks[\d.]+m?s/,
/Worker Cleanup[\d.]+m?s/,
]);
});