diff --git a/packages/playwright/src/worker/fixtureRunner.ts b/packages/playwright/src/worker/fixtureRunner.ts index 0d94f40631..e67393eb0d 100644 --- a/packages/playwright/src/worker/fixtureRunner.ts +++ b/packages/playwright/src/worker/fixtureRunner.ts @@ -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, type RunnableDescription } from './timeoutManager'; +import { 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'; @@ -125,38 +125,41 @@ class Fixture { } async teardown(testInfo: TestInfoImpl, runnable: RunnableDescription) { - await testInfo._runAsStage({ - title: `fixture: ${this.registration.name}`, - runnable: { ...runnable, fixture: this._teardownDescription }, - stepInfo: this._stepInfo, - }, async () => { - await this._teardownInternal(); - }); + try { + const fixtureRunnable = { ...runnable, fixture: this._teardownDescription }; + // Do not even start the teardown for a fixture that does not have any + // time remaining in the time slot. This avoids cascading timeouts. + if (!testInfo._timeoutManager.isTimeExhaustedFor(fixtureRunnable)) { + await testInfo._runAsStage({ + title: `fixture: ${this.registration.name}`, + runnable: fixtureRunnable, + stepInfo: this._stepInfo, + }, async () => { + await this._teardownInternal(); + }); + } + } finally { + // To preserve fixtures integrity, forcefully cleanup fixtures + // that cannnot teardown due to a timeout or an error. + for (const dep of this._deps) + dep._usages.delete(this); + this.runner.instanceForId.delete(this.registration.id); + } } private async _teardownInternal() { if (typeof this.registration.fn !== 'function') return; - try { - if (this._usages.size !== 0) { - // TODO: replace with assert. - console.error('Internal error: fixture integrity at', this._teardownDescription.title); // eslint-disable-line no-console - this._usages.clear(); - } - if (this._useFuncFinished) { - this._useFuncFinished.resolve(); - this._useFuncFinished = undefined; - await this._selfTeardownComplete; - } - } finally { - this._cleanupInstance(); + if (this._usages.size !== 0) { + // TODO: replace with assert. + console.error('Internal error: fixture integrity at', this._teardownDescription.title); // eslint-disable-line no-console + this._usages.clear(); + } + if (this._useFuncFinished) { + this._useFuncFinished.resolve(); + this._useFuncFinished = undefined; + await this._selfTeardownComplete; } - } - - _cleanupInstance() { - for (const dep of this._deps) - dep._usages.delete(this); - this.runner.instanceForId.delete(this.registration.id); } _collectFixturesInTeardownOrder(scope: FixtureScope, collector: Set) { @@ -203,27 +206,18 @@ export class FixtureRunner { const collector = new Set(); for (const fixture of fixtures) fixture._collectFixturesInTeardownOrder(scope, collector); - try { - let firstError: Error | undefined; - for (const fixture of collector) { - try { - await fixture.teardown(testInfo, runnable); - } catch (error) { - if (error instanceof TimeoutManagerError) - throw error; - firstError = firstError ?? error; - } + let firstError: Error | undefined; + for (const fixture of collector) { + try { + await fixture.teardown(testInfo, runnable); + } catch (error) { + firstError = firstError ?? error; } - if (firstError) - throw firstError; - } finally { - // To preserve fixtures integrity, forcefully cleanup fixtures that did not teardown - // due to a timeout in one of them. - for (const fixture of collector) - fixture._cleanupInstance(); - if (scope === 'test') - this.testScopeClean = true; } + if (scope === 'test') + this.testScopeClean = true; + if (firstError) + throw firstError; } async resolveParametersForFunction(fn: Function, testInfo: TestInfoImpl, autoFixtures: 'worker' | 'test' | 'all-hooks-only', runnable: RunnableDescription): Promise { diff --git a/packages/playwright/src/worker/timeoutManager.ts b/packages/playwright/src/worker/timeoutManager.ts index 0be072d173..e88af26933 100644 --- a/packages/playwright/src/worker/timeoutManager.ts +++ b/packages/playwright/src/worker/timeoutManager.ts @@ -67,6 +67,12 @@ export class TimeoutManager { this._running.timeoutPromise.reject(this._createTimeoutError(this._running)); } + isTimeExhaustedFor(runnable: RunnableDescription) { + const slot = runnable.fixture?.slot || runnable.slot || this._defaultSlot; + // Note: the "-1" here matches the +1 in _updateTimeout. + return slot.timeout > 0 && (slot.elapsed >= slot.timeout - 1); + } + async withRunnable(runnable: RunnableDescription | undefined, cb: () => Promise): Promise { if (!runnable) return await cb(); @@ -104,7 +110,10 @@ export class TimeoutManager { return; } running.deadline = running.start + (running.slot.timeout - running.slot.elapsed); - const timeout = running.deadline - monotonicTime(); + // Compensate for Node.js troubles with timeouts that can fire too early. + // We add an extra millisecond which seems to be enough. + // See https://github.com/nodejs/node/issues/26578. + const timeout = running.deadline - monotonicTime() + 1; if (timeout <= 0) running.timeoutPromise.reject(this._createTimeoutError(running)); else diff --git a/packages/playwright/src/worker/workerMain.ts b/packages/playwright/src/worker/workerMain.ts index 26048e6542..f180f3d08b 100644 --- a/packages/playwright/src/worker/workerMain.ts +++ b/packages/playwright/src/worker/workerMain.ts @@ -31,7 +31,7 @@ import { PoolBuilder } from '../common/poolBuilder'; import type { TestInfoError } from '../../types/test'; import type { Location } from '../../types/testReporter'; import { inheritFixtureNames } from '../common/fixtures'; -import { type TimeSlot, TimeoutManagerError } from './timeoutManager'; +import { type TimeSlot } from './timeoutManager'; export class WorkerMain extends ProcessRunner { private _params: WorkerInitParams; @@ -368,36 +368,27 @@ export class WorkerMain extends ProcessRunner { const afterHooksSlot = { timeout: afterHooksTimeout, elapsed: 0 }; await testInfo._runAsStage({ title: 'After Hooks', stepInfo: { category: 'hook' } }, async () => { let firstAfterHooksError: Error | undefined; - let didTimeoutInAfterHooks = false; try { // Run "immediately upon test function finish" callback. await testInfo._runAsStage({ title: 'on-test-function-finish', runnable: { type: 'test', slot: afterHooksSlot } }, async () => testInfo._onDidFinishTestFunction?.()); } catch (error) { - if (error instanceof TimeoutManagerError) - didTimeoutInAfterHooks = true; firstAfterHooksError = firstAfterHooksError ?? error; } try { // Run "afterEach" hooks, unless we failed at beforeAll stage. - if (!didTimeoutInAfterHooks && shouldRunAfterEachHooks) + if (shouldRunAfterEachHooks) await this._runEachHooksForSuites(reversedSuites, 'afterEach', testInfo, afterHooksSlot); } catch (error) { - if (error instanceof TimeoutManagerError) - didTimeoutInAfterHooks = true; firstAfterHooksError = firstAfterHooksError ?? error; } try { - 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 this._fixtureRunner.teardownScope('test', testInfo, { type: 'test', slot: afterHooksSlot }); - } + // Teardown test-scoped fixtures. Attribute to 'test' so that users understand + // they should probably increase the test timeout to fix this issue. + await this._fixtureRunner.teardownScope('test', testInfo, { type: 'test', slot: afterHooksSlot }); } catch (error) { - if (error instanceof TimeoutManagerError) - didTimeoutInAfterHooks = true; firstAfterHooksError = firstAfterHooksError ?? error; } @@ -559,14 +550,16 @@ export class WorkerMain extends ProcessRunner { let firstError: Error | undefined; const hooks = suites.map(suite => this._collectHooksAndModifiers(suite, type, testInfo)).flat(); for (const hook of hooks) { + const runnable = { type: hook.type, location: hook.location, slot }; + if (testInfo._timeoutManager.isTimeExhaustedFor(runnable)) { + // Do not run hooks that will timeout right away. + continue; + } try { 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) - throw error; firstError = firstError ?? error; // Skip in modifier prevents others from running. if (error instanceof SkipError) diff --git a/tests/playwright-test/hooks.spec.ts b/tests/playwright-test/hooks.spec.ts index d72cd7abb1..60a8700b82 100644 --- a/tests/playwright-test/hooks.spec.ts +++ b/tests/playwright-test/hooks.spec.ts @@ -625,7 +625,31 @@ test('uncaught error in beforeEach should not be masked by another error', async expect(result.output).toContain('Received: 1'); }); -test('should report error from fixture teardown when beforeAll times out', async ({ runInlineTest }) => { +test('should report error from worker fixture teardown when beforeAll times out', async ({ runInlineTest }) => { + const result = await runInlineTest({ + 'a.test.js': ` + import { test as base, expect } from '@playwright/test'; + const test = base.extend({ + foo: [async ({}, use) => { + let cb; + await use(new Promise((f, r) => cb = r)); + cb(new Error('Oh my!')); + }, { scope: 'worker' }], + }); + test.beforeAll(async ({ foo }, testInfo) => { + await foo; + }); + test('passing', () => { + }); + `, + }, { timeout: 1000 }); + expect(result.exitCode).toBe(1); + expect(result.failed).toBe(1); + expect(result.output).toContain('"beforeAll" hook timeout of 1000ms exceeded.'); + expect(result.output).toContain('Error: Oh my!'); +}); + +test('should not report error from test fixture teardown when beforeAll times out', async ({ runInlineTest }) => { const result = await runInlineTest({ 'a.test.js': ` import { test as base, expect } from '@playwright/test'; @@ -646,7 +670,7 @@ test('should report error from fixture teardown when beforeAll times out', async expect(result.exitCode).toBe(1); expect(result.failed).toBe(1); expect(result.output).toContain('"beforeAll" hook timeout of 1000ms exceeded.'); - expect(result.output).toContain('Error: Oh my!'); + expect(result.output).not.toContain('Error: Oh my!'); }); test('should not hang and report results when worker process suddenly exits during afterAll', async ({ runInlineTest }) => { diff --git a/tests/playwright-test/timeout.spec.ts b/tests/playwright-test/timeout.spec.ts index 4cfd4f7ee9..cb4e365b4b 100644 --- a/tests/playwright-test/timeout.spec.ts +++ b/tests/playwright-test/timeout.spec.ts @@ -559,6 +559,74 @@ test('should allow custom worker fixture timeout longer than force exit cap', as expect(result.output).toContain(`1 error was not a part of any test, see above for details`); }); +test('should run fixture teardown with custom timeout after test timeout', { + annotation: { type: 'issue', description: 'https://github.com/microsoft/playwright/issues/31537' }, +}, async ({ runInlineTest }) => { + const result = await runInlineTest({ + 'a.spec.ts': ` + import { test as base, expect } from '@playwright/test'; + const test = base.extend({ + foo: [async ({}, use) => { + console.log('\\n%%foo setup'); + await use('foo'); + console.log('\\n%%foo teardown'); + }, { timeout: 2000 }], + }); + test('times out', async ({ foo }) => { + console.log('\\n%%test start'); + await new Promise(() => {}); + console.log('\\n%%test end'); + }); + ` + }, { timeout: 2000 }); + expect(result.exitCode).toBe(1); + expect(result.failed).toBe(1); + expect(result.outputLines).toEqual([ + 'foo setup', + 'test start', + 'foo teardown', + ]); +}); + +test('should run fixture teardown with custom timeout after afterEach timeout', async ({ runInlineTest }) => { + const result = await runInlineTest({ + 'a.spec.ts': ` + import { test as base, expect } from '@playwright/test'; + let counter = 0; + const test = base.extend({ + foo: [async ({}, use) => { + console.log('\\n%%foo setup'); + await use('foo' + (++counter)); + console.log('\\n%%foo teardown'); + }, { timeout: 2000 }], + }); + test.afterEach(async () => { + console.log('\\n%%afterEach start'); + await new Promise(() => {}); + console.log('\\n%%afterEach end'); + }); + test.afterAll(async ({ foo }) => { + // Note: afterAll should receive a new instance of the "foo" fixture. + console.log('\\n%%afterAll - ' + foo); + }); + test('times out', async ({ foo }) => { + console.log('\\n%%test - ' + foo); + }); + ` + }, { timeout: 2000 }); + expect(result.exitCode).toBe(1); + expect(result.failed).toBe(1); + expect(result.outputLines).toEqual([ + 'foo setup', + 'test - foo1', + 'afterEach start', + 'foo teardown', + 'foo setup', + 'afterAll - foo2', + 'foo teardown', + ]); +}); + test('test.setTimeout should be able to change custom fixture timeout', async ({ runInlineTest }) => { const result = await runInlineTest({ 'a.spec.ts': `