microsoft/playwright
1
1
Fork 0
mirror of https://github.com/microsoft/playwright.git synced 2025-01-05 19:04:43 +03:00
Code Issues Projects Releases Wiki Activity

reland(hooks): separate test timeout from beforeAll/afterAll timeouts (#12609)

Browse Source 
This makes it possible to have longer `beforeAll`/`afterAll` and not
affect first/last test timeout.
This commit is contained in:
Dmitry Gozman 2022-03-08 19:05:23 -08:00 committed by GitHub
parent 176846672f
commit 682eeb4ae0
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
5 changed files with 143 additions and 32 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

29
packages/playwright-core/src/utils/async.ts
View File

@ -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<any>,
};
@ -35,7 +35,7 @@ export class TimeoutRunner {
async run<T>(cb: () => Promise<T>): Promise<T> {
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

5
packages/playwright-test/src/index.ts
View File

@ -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';
}

39
packages/playwright-test/src/testInfo.ts
View File

@ -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<any>): Promise<void> {
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 '';

20
packages/playwright-test/src/workerRunner.ts
View File

@ -274,7 +274,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.
@ -301,7 +301,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.
@ -330,7 +330,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
@ -352,7 +352,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;
});
@ -367,13 +367,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'));
@ -397,7 +397,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 });
@ -414,7 +414,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.
@ -434,7 +434,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;
@ -447,7 +447,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.

82
tests/playwright-test/hooks.spec.ts
View File

@ -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',
]);
});