From ce2c0c59a76b3759023832e4f20eaab6f0b1eb32 Mon Sep 17 00:00:00 2001 From: Dmitry Gozman Date: Wed, 17 Nov 2021 17:28:30 -0800 Subject: [PATCH] feat(expect): show expect timeout in the error message (#10388) Makes it easier to understand that expect does indeed have a separate timeout. ``` Error: expect(received).toHaveCount(expected) // deep equality Expected: 0 Received: 1 Call log: - expect.toHaveCount with timeout 500ms - waiting for selector "span" - selector resolved to 1 element - unexpected value "1" - selector resolved to 1 element - unexpected value "1" - selector resolved to 1 element - unexpected value "1" ``` --- packages/playwright-core/src/server/frames.ts | 83 ++++++++++--------- .../src/matchers/toMatchText.ts | 3 +- .../playwright.expect.misc.spec.ts | 4 +- 3 files changed, 47 insertions(+), 43 deletions(-) diff --git a/packages/playwright-core/src/server/frames.ts b/packages/playwright-core/src/server/frames.ts index fbd705556f..df8af491ba 100644 --- a/packages/playwright-core/src/server/frames.ts +++ b/packages/playwright-core/src/server/frames.ts @@ -1223,6 +1223,7 @@ export class Frame extends SdkObject { const controller = new ProgressController(metadata, this); const isArray = options.expression === 'to.have.count' || options.expression.endsWith('.array'); const mainWorld = options.expression === 'to.have.property'; + const timeout = this._page._timeoutSettings.timeout(options); // List all combinations that are satisfied with the detached node(s). let omitAttached = false; @@ -1239,38 +1240,41 @@ export class Frame extends SdkObject { else if (options.isNot && options.expression.endsWith('.array') && options.expectedText!.length > 0) omitAttached = true; - return await this._scheduleRerunnableTaskWithController(controller, selector, (progress, element, options, elements) => { - let result: { matches: boolean, received?: any }; + return controller.run(async outerProgress => { + outerProgress.log(`${metadata.apiName}${timeout ? ` with timeout ${timeout}ms` : ''}`); + return await this._scheduleRerunnableTaskWithProgress(outerProgress, selector, (progress, element, options, elements) => { + let result: { matches: boolean, received?: any }; - if (options.isArray) { - result = progress.injectedScript.expectArray(elements, options); - } else { - if (!element) { - // expect(locator).toBeHidden() passes when there is no element. - if (!options.isNot && options.expression === 'to.be.hidden') - return { matches: true }; - // expect(locator).not.toBeVisible() passes when there is no element. - if (options.isNot && options.expression === 'to.be.visible') - return { matches: false }; - // When none of the above applies, keep waiting for the element. + if (options.isArray) { + result = progress.injectedScript.expectArray(elements, options); + } else { + if (!element) { + // expect(locator).toBeHidden() passes when there is no element. + if (!options.isNot && options.expression === 'to.be.hidden') + return { matches: true }; + // expect(locator).not.toBeVisible() passes when there is no element. + if (options.isNot && options.expression === 'to.be.visible') + return { matches: false }; + // When none of the above applies, keep waiting for the element. + return progress.continuePolling; + } + result = progress.injectedScript.expectSingleElement(progress, element, options); + } + + if (result.matches === options.isNot) { + // Keep waiting in these cases: + // expect(locator).conditionThatDoesNotMatch + // expect(locator).not.conditionThatDoesMatch + progress.setIntermediateResult(result.received); + if (!Array.isArray(result.received)) + progress.log(` unexpected value "${result.received}"`); return progress.continuePolling; } - result = progress.injectedScript.expectSingleElement(progress, element, options); - } - if (result.matches === options.isNot) { - // Keep waiting in these cases: - // expect(locator).conditionThatDoesNotMatch - // expect(locator).not.conditionThatDoesMatch - progress.setIntermediateResult(result.received); - if (!Array.isArray(result.received)) - progress.log(` unexpected value "${result.received}"`); - return progress.continuePolling; - } - - // Reached the expected state! - return result; - }, { ...options, isArray }, { strict: true, querySelectorAll: isArray, mainWorld, omitAttached, logScale: true, ...options }).catch(e => { + // Reached the expected state! + return result; + }, { ...options, isArray }, { strict: true, querySelectorAll: isArray, mainWorld, omitAttached, logScale: true, ...options }); + }, timeout).catch(e => { // Q: Why not throw upon isSessionClosedError(e) as in other places? // A: We want user to receive a friendly message containing the last intermediate result. if (js.isJavaScriptErrorInEvaluate(e)) @@ -1342,26 +1346,25 @@ export class Frame extends SdkObject { private async _scheduleRerunnableTask(metadata: CallMetadata, selector: string, body: DomTaskBody, taskData: T, options: types.TimeoutOptions & types.StrictOptions & { mainWorld?: boolean } = {}): Promise { const controller = new ProgressController(metadata, this); - return this._scheduleRerunnableTaskWithController(controller, selector, body as DomTaskBody, taskData, options); + return controller.run(async progress => { + return await this._scheduleRerunnableTaskWithProgress(progress, selector, body as DomTaskBody, taskData, options); + }, this._page._timeoutSettings.timeout(options)); } - private async _scheduleRerunnableTaskWithController( - controller: ProgressController, + private async _scheduleRerunnableTaskWithProgress( + progress: Progress, selector: string, body: DomTaskBody, taskData: T, options: types.TimeoutOptions & types.StrictOptions & { mainWorld?: boolean, querySelectorAll?: boolean, logScale?: boolean, omitAttached?: boolean } = {}): Promise { const callbackText = body.toString(); - - return controller.run(async progress => { - return this.retryWithProgress(progress, selector, options, async selectorInFrame => { - // Be careful, |this| can be different from |frame|. - progress.log(`waiting for selector "${selector}"`); - const { frame, info } = selectorInFrame || { frame: this, info: { parsed: { parts: [{ name: 'control', body: 'return-empty', source: 'control=return-empty' }] }, world: 'utility', strict: !!options.strict } }; - return await frame._scheduleRerunnableTaskInFrame(progress, info, callbackText, taskData, options); - }); - }, this._page._timeoutSettings.timeout(options)); + return this.retryWithProgress(progress, selector, options, async selectorInFrame => { + // Be careful, |this| can be different from |frame|. + progress.log(`waiting for selector "${selector}"`); + const { frame, info } = selectorInFrame || { frame: this, info: { parsed: { parts: [{ name: 'control', body: 'return-empty', source: 'control=return-empty' }] }, world: 'utility', strict: !!options.strict } }; + return await frame._scheduleRerunnableTaskInFrame(progress, info, callbackText, taskData, options); + }); } private async _scheduleRerunnableTaskInFrame( diff --git a/packages/playwright-test/src/matchers/toMatchText.ts b/packages/playwright-test/src/matchers/toMatchText.ts index 31a1ff2af8..2739e2addf 100644 --- a/packages/playwright-test/src/matchers/toMatchText.ts +++ b/packages/playwright-test/src/matchers/toMatchText.ts @@ -120,8 +120,7 @@ export function callLogText(log: string[] | undefined): string { if (!log) return ''; return ` - Call log: - - ${colors.dim((log || []).join('\n - '))} + ${colors.dim('- ' + (log || []).join('\n - '))} `; } diff --git a/tests/playwright-test/playwright.expect.misc.spec.ts b/tests/playwright-test/playwright.expect.misc.spec.ts index 062f4e9bc4..7c1c4e9ac9 100644 --- a/tests/playwright-test/playwright.expect.misc.spec.ts +++ b/tests/playwright-test/playwright.expect.misc.spec.ts @@ -86,6 +86,7 @@ test('should support toHaveCount', async ({ runInlineTest }) => { expect(result.exitCode).toBe(1); expect(output).toContain('Expected: 0'); expect(output).toContain('Received: 1'); + expect(output).toContain('expect.toHaveCount with timeout 500ms'); }); test('should support toHaveJSProperty', async ({ runInlineTest }) => { @@ -311,7 +312,7 @@ test('should support toHaveURL with baseURL from webServer', async ({ runInlineT expect(result.exitCode).toBe(1); }); -test('should support respect expect.timeout', async ({ runInlineTest }) => { +test('should respect expect.timeout', async ({ runInlineTest }) => { const result = await runInlineTest({ 'playwright.config.js': `module.exports = { expect: { timeout: 1000 } }`, 'a.test.ts': ` @@ -328,6 +329,7 @@ test('should support respect expect.timeout', async ({ runInlineTest }) => { }, { workers: 1 }); const output = stripAscii(result.output); expect(output).toContain('expect(received).toHaveURL(expected)'); + expect(output).toContain('expect.toHaveURL with timeout 1000ms'); expect(result.failed).toBe(1); expect(result.exitCode).toBe(1); });