diff --git a/packages/playwright-core/src/utils/async.ts b/packages/playwright-core/src/utils/async.ts index e91702cad6..2648fcaac8 100644 --- a/packages/playwright-core/src/utils/async.ts +++ b/packages/playwright-core/src/utils/async.ts @@ -19,7 +19,7 @@ import { monotonicTime } from './utils'; export class TimeoutRunnerError extends Error {} type TimeoutRunnerData = { - start: number, + lastElapsedSync: number, timer: NodeJS.Timer | undefined, timeoutPromise: ManualPromise, }; @@ -35,7 +35,7 @@ export class TimeoutRunner { async run(cb: () => Promise): Promise { const running = this._running = { - start: monotonicTime(), + lastElapsedSync: monotonicTime(), timer: undefined, timeoutPromise: new ManualPromise(), }; @@ -47,7 +47,6 @@ export class TimeoutRunner { this._updateTimeout(running, this._timeout); return await resultPromise; } finally { - this._elapsed += monotonicTime() - running.start; this._updateTimeout(running, 0); if (this._running === running) this._running = undefined; @@ -59,15 +58,27 @@ export class TimeoutRunner { this._updateTimeout(this._running, -1); } - updateTimeout(timeout: number) { + elapsed() { + this._syncElapsedAndStart(); + return this._elapsed; + } + + updateTimeout(timeout: number, elapsed?: number) { this._timeout = timeout; + if (elapsed !== undefined) { + this._syncElapsedAndStart(); + this._elapsed = elapsed; + } if (this._running) this._updateTimeout(this._running, timeout); } - resetTimeout(timeout: number) { - this._elapsed = 0; - this.updateTimeout(timeout); + private _syncElapsedAndStart() { + if (this._running) { + const now = monotonicTime(); + this._elapsed += now - this._running.lastElapsedSync; + this._running.lastElapsedSync = now; + } } private _updateTimeout(running: TimeoutRunnerData, timeout: number) { @@ -75,10 +86,10 @@ export class TimeoutRunner { clearTimeout(running.timer); running.timer = undefined; } + this._syncElapsedAndStart(); if (timeout === 0) return; - const elapsed = (monotonicTime() - running.start) + this._elapsed; - timeout = timeout - elapsed; + timeout = timeout - this._elapsed; if (timeout <= 0) running.timeoutPromise.reject(new TimeoutRunnerError()); else diff --git a/packages/playwright-test/src/index.ts b/packages/playwright-test/src/index.ts index fc772b95a4..e563b08d61 100644 --- a/packages/playwright-test/src/index.ts +++ b/packages/playwright-test/src/index.ts @@ -519,10 +519,9 @@ function formatStackFrame(frame: StackFrame) { } function hookType(testInfo: TestInfo): 'beforeAll' | 'afterAll' | undefined { - const impl = testInfo as import('./testInfo').TestInfoImpl; - if (impl._currentRunnable?.type === 'beforeAll') + if ((testInfo as any)._currentRunnable?.type === 'beforeAll') return 'beforeAll'; - if (impl._currentRunnable?.type === 'afterAll') + if ((testInfo as any)._currentRunnable?.type === 'afterAll') return 'afterAll'; } diff --git a/packages/playwright-test/src/testInfo.ts b/packages/playwright-test/src/testInfo.ts index 399ca57f00..074f36f631 100644 --- a/packages/playwright-test/src/testInfo.ts +++ b/packages/playwright-test/src/testInfo.ts @@ -31,6 +31,8 @@ import { addSuffixToFilePath, getContainedPath, monotonicTime, sanitizeForFilePa type RunnableDescription = { type: 'test' | 'beforeAll' | 'afterAll' | 'beforeEach' | 'afterEach' | 'slow' | 'skip' | 'fail' | 'fixme' | 'teardown'; location?: Location; + // When runnable has a separate timeout, it does not count into the "shared time pool" for the test. + timeout?: number; }; export class TestInfoImpl implements TestInfo { @@ -41,7 +43,9 @@ export class TestInfoImpl implements TestInfo { readonly _startTime: number; readonly _startWallTime: number; private _hasHardError: boolean = false; - _currentRunnable: RunnableDescription | undefined; + private _currentRunnable: RunnableDescription = { type: 'test' }; + // Holds elapsed time of the "time pool" shared between fixtures, each hooks and test itself. + private _elapsedTestTime = 0; // ------------ TestInfo fields ------------ readonly repeatEachIndex: number; @@ -167,6 +171,16 @@ export class TestInfoImpl implements TestInfo { } } + _setCurrentRunnable(runnable: RunnableDescription) { + if (this._currentRunnable.timeout === undefined) + this._elapsedTestTime = this._timeoutRunner.elapsed(); + this._currentRunnable = runnable; + if (runnable.timeout === undefined) + this._timeoutRunner.updateTimeout(this.timeout, this._elapsedTestTime); + else + this._timeoutRunner.updateTimeout(runnable.timeout, 0); + } + async _runWithTimeout(cb: () => Promise): Promise { try { await this._timeoutRunner.run(cb); @@ -178,8 +192,8 @@ export class TestInfoImpl implements TestInfo { this.status = 'timedOut'; const title = titleForRunnable(this._currentRunnable); const suffix = title ? ` in ${title}` : ''; - const message = colors.red(`Timeout of ${this.timeout}ms exceeded${suffix}.`); - const location = this._currentRunnable?.location; + const message = colors.red(`Timeout of ${this._currentRunnable.timeout ?? this.timeout}ms exceeded${suffix}.`); + const location = this._currentRunnable.location; this.errors.push({ message, // Include location for hooks and modifiers to distinguish between them. @@ -281,19 +295,24 @@ export class TestInfoImpl implements TestInfo { } setTimeout(timeout: number) { - if (!this.timeout) - return; // Zero timeout means some debug mode - do not set a timeout. - this.timeout = timeout; - this._timeoutRunner.updateTimeout(timeout); + if (this._currentRunnable.timeout !== undefined) { + if (!this._currentRunnable.timeout) + return; // Zero timeout means some debug mode - do not set a timeout. + this._currentRunnable.timeout = timeout; + this._timeoutRunner.updateTimeout(timeout); + } else { + if (!this.timeout) + return; // Zero timeout means some debug mode - do not set a timeout. + this.timeout = timeout; + this._timeoutRunner.updateTimeout(timeout); + } } } class SkipError extends Error { } -function titleForRunnable(runnable: RunnableDescription | undefined): string { - if (!runnable) - return ''; +function titleForRunnable(runnable: RunnableDescription): string { switch (runnable.type) { case 'test': return ''; diff --git a/packages/playwright-test/src/workerRunner.ts b/packages/playwright-test/src/workerRunner.ts index d1ad385f61..b4c06d4259 100644 --- a/packages/playwright-test/src/workerRunner.ts +++ b/packages/playwright-test/src/workerRunner.ts @@ -270,7 +270,7 @@ export class WorkerRunner extends EventEmitter { forceNoParent: true }); - // Note: wrap all preparation steps together, because failure in any of them + // Note: wrap all preparation steps together, because failure/skip in any of them // prevents further setup and/or test from running. const maybeError = await testInfo._runFn(async () => { // Run "beforeAll" modifiers on parent suites, unless already run during previous tests. @@ -297,7 +297,7 @@ export class WorkerRunner extends EventEmitter { await this._runEachHooksForSuites(suites, 'beforeEach', testInfo); // Setup fixtures required by the test. - testInfo._currentRunnable = { type: 'test' }; + testInfo._setCurrentRunnable({ type: 'test' }); const params = await this._fixtureRunner.resolveParametersForFunction(test.fn, testInfo); beforeHooksStep.complete(); // Report fixture hooks step as completed. @@ -326,7 +326,7 @@ export class WorkerRunner extends EventEmitter { if (testInfo.status === 'timedOut') { // A timed-out test gets a full additional timeout to run after hooks. - testInfo._timeoutRunner.resetTimeout(testInfo.timeout); + testInfo._timeoutRunner.updateTimeout(testInfo.timeout, 0); } await testInfo._runWithTimeout(async () => { // Note: do not wrap all teardown steps together, because failure in any of them @@ -348,7 +348,7 @@ export class WorkerRunner extends EventEmitter { } // Teardown test-scoped fixtures. - testInfo._currentRunnable = { type: 'teardown' }; + testInfo._setCurrentRunnable({ type: 'teardown' }); const testScopeError = await testInfo._runFn(() => this._fixtureRunner.teardownScope('test')); firstAfterHooksError = firstAfterHooksError || testScopeError; }); @@ -363,13 +363,13 @@ export class WorkerRunner extends EventEmitter { this._didRunFullCleanup = true; // Give it more time for the full cleanup. - testInfo._timeoutRunner.resetTimeout(this._project.config.timeout); + testInfo._timeoutRunner.updateTimeout(this._project.config.timeout, 0); await testInfo._runWithTimeout(async () => { for (const suite of reversedSuites) { const afterAllError = await this._runAfterAllHooksForSuite(suite, testInfo); firstAfterHooksError = firstAfterHooksError || afterAllError; } - testInfo._currentRunnable = { type: 'teardown' }; + testInfo._setCurrentRunnable({ type: 'teardown', timeout: this._project.config.timeout }); const testScopeError = await testInfo._runFn(() => this._fixtureRunner.teardownScope('test')); firstAfterHooksError = firstAfterHooksError || testScopeError; const workerScopeError = await testInfo._runFn(() => this._fixtureRunner.teardownScope('worker')); @@ -393,7 +393,7 @@ export class WorkerRunner extends EventEmitter { const actualScope = this._fixtureRunner.dependsOnWorkerFixturesOnly(modifier.fn, modifier.location) ? 'worker' : 'test'; if (actualScope !== scope) continue; - testInfo._currentRunnable = { type: modifier.type, location: modifier.location }; + testInfo._setCurrentRunnable({ type: modifier.type, location: modifier.location, timeout: scope === 'worker' ? this._project.config.timeout : undefined }); const result = await this._fixtureRunner.resolveParametersAndRunFunction(modifier.fn, testInfo); if (result && extraAnnotations) extraAnnotations.push({ type: modifier.type, description: modifier.description }); @@ -410,7 +410,7 @@ export class WorkerRunner extends EventEmitter { if (hook.type !== 'beforeAll') continue; try { - testInfo._currentRunnable = { type: 'beforeAll', location: hook.location }; + testInfo._setCurrentRunnable({ type: 'beforeAll', location: hook.location, timeout: this._project.config.timeout }); await this._fixtureRunner.resolveParametersAndRunFunction(hook.fn, testInfo); } catch (e) { // Always run all the hooks, and capture the first error. @@ -430,7 +430,7 @@ export class WorkerRunner extends EventEmitter { if (hook.type !== 'afterAll') continue; const afterAllError = await testInfo._runFn(async () => { - testInfo._currentRunnable = { type: 'afterAll', location: hook.location }; + testInfo._setCurrentRunnable({ type: 'afterAll', location: hook.location, timeout: this._project.config.timeout }); await this._fixtureRunner.resolveParametersAndRunFunction(hook.fn, testInfo); }); firstError = firstError || afterAllError; @@ -443,7 +443,7 @@ export class WorkerRunner extends EventEmitter { let error: Error | undefined; for (const hook of hooks) { try { - testInfo._currentRunnable = { type, location: hook.location }; + testInfo._setCurrentRunnable({ type, location: hook.location }); await this._fixtureRunner.resolveParametersAndRunFunction(hook.fn, testInfo); } catch (e) { // Always run all the hooks, and capture the first error. diff --git a/tests/playwright-test/hooks.spec.ts b/tests/playwright-test/hooks.spec.ts index 55c0595f1c..9d0ecda089 100644 --- a/tests/playwright-test/hooks.spec.ts +++ b/tests/playwright-test/hooks.spec.ts @@ -496,6 +496,7 @@ test('afterAll timeout should be reported, run other afterAll hooks, and continu await new Promise(f => setTimeout(f, 5000)); }); test('runs', () => { + test.setTimeout(2000); console.log('\\n%%test1'); }); }); @@ -670,3 +671,84 @@ test('unhandled rejection during beforeAll should be reported and prevent more t expect(result.output).toContain('Error: Oh my'); expect(stripAnsi(result.output)).toContain(`> 9 | throw new Error('Oh my');`); }); + +test('beforeAll and afterAll should have a separate timeout', async ({ runInlineTest }) => { + const result = await runInlineTest({ + 'a.test.js': ` + const { test } = pwt; + test.beforeAll(async () => { + console.log('\\n%%beforeAll'); + await new Promise(f => setTimeout(f, 300)); + }); + test.beforeAll(async () => { + console.log('\\n%%beforeAll2'); + await new Promise(f => setTimeout(f, 300)); + }); + test('passed', async () => { + console.log('\\n%%test'); + await new Promise(f => setTimeout(f, 300)); + }); + test.afterAll(async () => { + console.log('\\n%%afterAll'); + await new Promise(f => setTimeout(f, 300)); + }); + test.afterAll(async () => { + console.log('\\n%%afterAll2'); + await new Promise(f => setTimeout(f, 300)); + }); + `, + }, { timeout: '500' }); + expect(result.exitCode).toBe(0); + expect(result.passed).toBe(1); + expect(result.output.split('\n').filter(line => line.startsWith('%%'))).toEqual([ + '%%beforeAll', + '%%beforeAll2', + '%%test', + '%%afterAll', + '%%afterAll2', + ]); +}); + +test('test.setTimeout should work separately in beforeAll', async ({ runInlineTest }) => { + const result = await runInlineTest({ + 'a.test.js': ` + const { test } = pwt; + test.beforeAll(async () => { + console.log('\\n%%beforeAll'); + test.setTimeout(100); + }); + test('passed', async () => { + console.log('\\n%%test'); + await new Promise(f => setTimeout(f, 800)); + }); + `, + }, { timeout: '1000' }); + expect(result.exitCode).toBe(0); + expect(result.passed).toBe(1); + expect(result.output.split('\n').filter(line => line.startsWith('%%'))).toEqual([ + '%%beforeAll', + '%%test', + ]); +}); + +test('test.setTimeout should work separately in afterAll', async ({ runInlineTest }) => { + const result = await runInlineTest({ + 'a.test.js': ` + const { test } = pwt; + test('passed', async () => { + console.log('\\n%%test'); + }); + test.afterAll(async () => { + console.log('\\n%%afterAll'); + test.setTimeout(1000); + await new Promise(f => setTimeout(f, 800)); + }); + `, + }, { timeout: '100' }); + expect(result.exitCode).toBe(0); + expect(result.passed).toBe(1); + expect(result.output.split('\n').filter(line => line.startsWith('%%'))).toEqual([ + '%%test', + '%%afterAll', + ]); +});