diff --git a/src/client/channelOwner.ts b/src/client/channelOwner.ts index 92b6c15018..66c9922193 100644 --- a/src/client/channelOwner.ts +++ b/src/client/channelOwner.ts @@ -74,11 +74,11 @@ export abstract class ChannelOwner { if (prop === 'debugScopeState') - return (params: any) => this._connection.sendMessageToServer(this._guid, prop, params, apiName); + return (params: any) => this._connection.sendMessageToServer(this, prop, params, apiName); if (typeof prop === 'string') { const validator = scheme[paramsName(this._type, prop)]; if (validator) - return (params: any) => this._connection.sendMessageToServer(this._guid, prop, validator(params, ''), apiName); + return (params: any) => this._connection.sendMessageToServer(this, prop, validator(params, ''), apiName); } return obj[prop]; }, @@ -103,15 +103,15 @@ export abstract class ChannelOwner {}); + this._connection.sendMessageToServer(this, 'waitForEventInfo', { info: { apiName, waitId, phase: 'before' } }, undefined).catch(() => {}); } _waitForEventInfoAfter(waitId: string, error?: string) { - this._connection.sendMessageToServer(this._guid, 'waitForEventInfo', { info: { waitId, phase: 'after', error } }, undefined).catch(() => {}); + this._connection.sendMessageToServer(this, 'waitForEventInfo', { info: { waitId, phase: 'after', error } }, undefined).catch(() => {}); } _waitForEventInfoLog(waitId: string, message: string) { - this._connection.sendMessageToServer(this._guid, 'waitForEventInfo', { info: { waitId, phase: 'log', message } }, undefined).catch(() => {}); + this._connection.sendMessageToServer(this, 'waitForEventInfo', { info: { waitId, phase: 'log', message } }, undefined).catch(() => {}); } private toJSON() { diff --git a/src/client/connection.ts b/src/client/connection.ts index 91028975da..eae714fcf5 100644 --- a/src/client/connection.ts +++ b/src/client/connection.ts @@ -52,7 +52,7 @@ export class Connection extends EventEmitter { private _waitingForObject = new Map(); onmessage = (message: object): void => {}; private _lastId = 0; - private _callbacks = new Map void, reject: (a: Error) => void }>(); + private _callbacks = new Map void, reject: (a: Error) => void, metadata: channels.Metadata }>(); private _rootObject: ChannelOwner; private _disconnectedErrorMessage: string | undefined; private _onClose?: () => void; @@ -69,21 +69,27 @@ export class Connection extends EventEmitter { return new Promise(f => this._waitingForObject.set(guid, f)); } + pendingProtocolCalls(): channels.Metadata[] { + return Array.from(this._callbacks.values()).map(callback => callback.metadata); + } + getObjectWithKnownName(guid: string): any { return this._objects.get(guid)!; } - async sendMessageToServer(guid: string, method: string, params: any, apiName: string | undefined): Promise { + async sendMessageToServer(object: ChannelOwner, method: string, params: any, apiName: string | undefined): Promise { + const guid = object._guid; const { stack, frames } = captureStackTrace(); const id = ++this._lastId; const converted = { id, guid, method, params }; // Do not include metadata in debug logs to avoid noise. debugLogger.log('channel:command', converted); - this.onmessage({ ...converted, metadata: { stack: frames, apiName } }); + const metadata: channels.Metadata = { stack: frames, apiName }; + this.onmessage({ ...converted, metadata }); try { if (this._disconnectedErrorMessage) throw new Error(this._disconnectedErrorMessage); - return await new Promise((resolve, reject) => this._callbacks.set(id, { resolve, reject })); + return await new Promise((resolve, reject) => this._callbacks.set(id, { resolve, reject, metadata })); } catch (e) { const innerStack = ((process.env.PWDEBUGIMPL || isUnderTest()) && e.stack) ? e.stack.substring(e.stack.indexOf(e.message) + e.message.length) : ''; e.stack = e.message + innerStack + '\n' + stack; diff --git a/src/test/index.ts b/src/test/index.ts index 76023b640f..a88ef9f02e 100644 --- a/src/test/index.ts +++ b/src/test/index.ts @@ -17,8 +17,8 @@ import * as fs from 'fs'; import * as path from 'path'; import * as os from 'os'; -import type { LaunchOptions, BrowserContextOptions, Page, ViewportSize } from '../../types/types'; -import type { TestType, PlaywrightTestArgs, PlaywrightTestOptions, PlaywrightWorkerArgs, PlaywrightWorkerOptions } from '../../types/test'; +import type { LaunchOptions, BrowserContextOptions, Page, BrowserContext } from '../../types/types'; +import type { TestType, PlaywrightTestArgs, PlaywrightTestOptions, PlaywrightWorkerArgs, PlaywrightWorkerOptions, FullConfig, TestInfo } from '../../types/test'; import { rootTestType } from './testType'; import { createGuid, removeFolders } from '../utils/utils'; export { expect } from './expect'; @@ -167,7 +167,18 @@ export const test = _baseTest.extend {}); })); } + + const prependToError = testInfo.status === 'timedOut' ? formatPendingCalls((context as any)._connection.pendingProtocolCalls(), testInfo) : ''; await context.close(); + if (prependToError) { + if (!testInfo.error) { + testInfo.error = { value: prependToError }; + } else if (testInfo.error.message) { + testInfo.error.message = prependToError + testInfo.error.message; + if (testInfo.error.stack) + testInfo.error.stack = prependToError + testInfo.error.stack; + } + } const preserveVideo = captureVideo && (videoMode === 'on' || (testFailed && videoMode === 'retain-on-failure') || (videoMode === 'on-first-retry' && testInfo.retry === 1)); if (preserveVideo) { @@ -191,3 +202,29 @@ export const test = _baseTest.extend { + const frame = call.stack && call.stack[0] ? formatStackFrame(testInfo.config, call.stack[0]) : ''; + return ` - ${call.apiName} at ${frame}\n`; + }).join('') + '\n'; +} + +function formatStackFrame(config: FullConfig, frame: StackFrame) { + const file = path.relative(config.rootDir, frame.file) || path.basename(frame.file); + return `${file}:${frame.line || 1}:${frame.column || 1}`; +} + +type StackFrame = { + file: string, + line?: number, + column?: number, + function?: string, +}; + +type ProtocolCall = { + stack?: StackFrame[], + apiName?: string, +}; diff --git a/src/test/reporters/base.ts b/src/test/reporters/base.ts index c189355fc4..27776b75e7 100644 --- a/src/test/reporters/base.ts +++ b/src/test/reporters/base.ts @@ -185,6 +185,8 @@ function formatFailedResult(test: Test, result: TestResult): string { if (result.status === 'timedOut') { tokens.push(''); tokens.push(indent(colors.red(`Timeout of ${test.timeout}ms exceeded.`), ' ')); + if (result.error !== undefined) + tokens.push(indent(formatError(result.error, test.spec.file), ' ')); } else { tokens.push(indent(formatError(result.error!, test.spec.file), ' ')); } diff --git a/src/test/workerRunner.ts b/src/test/workerRunner.ts index 8db588a368..77339f9855 100644 --- a/src/test/workerRunner.ts +++ b/src/test/workerRunner.ts @@ -331,11 +331,12 @@ export class WorkerRunner extends EventEmitter { testInfo.status = 'skipped'; } else { // We might fail after the timeout, e.g. due to fixture teardown. - // Do not overwrite the timeout status with this error. - if (testInfo.status === 'passed') { + // Do not overwrite the timeout status. + if (testInfo.status === 'passed') testInfo.status = 'failed'; + // Keep the error even in the case of timeout, if there was no error before. + if (!('error' in testInfo)) testInfo.error = serializeError(error); - } } } } @@ -344,21 +345,23 @@ export class WorkerRunner extends EventEmitter { try { await this._runHooks(test.spec.parent!, 'afterEach', testInfo); } catch (error) { - // Do not overwrite test failure error. - if (!(error instanceof SkipError) && testInfo.status === 'passed') { - testInfo.status = 'failed'; - testInfo.error = serializeError(error); + if (!(error instanceof SkipError)) { + if (testInfo.status === 'passed') + testInfo.status = 'failed'; + // Do not overwrite test failure error. + if (!('error' in testInfo)) + testInfo.error = serializeError(error); // Continue running even after the failure. } } try { await this._fixtureRunner.teardownScope('test'); } catch (error) { - // Do not overwrite test failure error. - if (testInfo.status === 'passed') { + if (testInfo.status === 'passed') testInfo.status = 'failed'; + // Do not overwrite test failure error. + if (!('error' in testInfo)) testInfo.error = serializeError(error); - } } } diff --git a/src/utils/stackTrace.ts b/src/utils/stackTrace.ts index 374e7a667b..3adb05716b 100644 --- a/src/utils/stackTrace.ts +++ b/src/utils/stackTrace.ts @@ -59,10 +59,10 @@ export function captureStackTrace(): { stack: string, frames: StackFrame[] } { const fileName = path.resolve(process.cwd(), frame.file); if (PW_LIB_DIRS.some(libDir => fileName.includes(libDir))) continue; - // for tests. - if (isUnderTest() && fileName.includes(path.join('playwright', 'src'))) + const isTesting = process.env.PWTEST_CLI_ALLOW_TEST_COMMAND || isUnderTest(); + if (isTesting && fileName.includes(path.join('playwright', 'src'))) continue; - if (isUnderTest() && fileName.includes(path.join('playwright', 'tests', 'config', 'coverage.js'))) + if (isTesting && fileName.includes(path.join('playwright', 'tests', 'config', 'coverage.js'))) continue; frames.push({ file: fileName, diff --git a/tests/playwright-test/playwright.spec.ts b/tests/playwright-test/playwright.spec.ts index 251bdc8335..6923ec3d60 100644 --- a/tests/playwright-test/playwright.spec.ts +++ b/tests/playwright-test/playwright.spec.ts @@ -14,7 +14,7 @@ * limitations under the License. */ -import { test, expect } from './playwright-test-fixtures'; +import { test, expect, stripAscii } from './playwright-test-fixtures'; import fs from 'fs'; import path from 'path'; import { spawnSync } from 'child_process'; @@ -122,6 +122,30 @@ test('should complain with projects and --browser', async ({ runInlineTest }) => expect(result.output).toContain('Cannot use --browser option when configuration file defines projects'); }); +test('should report error and pending operations on timeout', async ({ runInlineTest }, testInfo) => { + const result = await runInlineTest({ + 'a.test.ts': ` + const { test } = pwt; + test('timedout', async ({ page }) => { + await page.setContent('
Click me
'); + await Promise.all([ + page.click('text=Missing'), + page.textContent('text=More missing'), + ]); + }); + `, + }, { workers: 1, timeout: 2000 }); + + expect(result.exitCode).toBe(1); + expect(result.passed).toBe(0); + expect(result.failed).toBe(1); + expect(result.output).toContain('Pending operations:'); + expect(result.output).toContain('- page.click at a.test.ts:9:16'); + expect(result.output).toContain('- page.textContent at a.test.ts:10:16'); + expect(result.output).toContain('retrieving textContent from "text=More missing"'); + expect(stripAscii(result.output)).toContain(`10 | page.textContent('text=More missing'),`); +}); + test('should work with screenshot: only-on-failure', async ({ runInlineTest }, testInfo) => { const result = await runInlineTest({ 'playwright.config.ts': `