From ef4b34fb7a3b3238ba0676515dd744cbf2507a3d Mon Sep 17 00:00:00 2001 From: Andrey Lushnikov Date: Fri, 11 Mar 2022 23:40:28 -0700 Subject: [PATCH] feat(toHaveScreenshot): enhance messaging in case of failures (#12677) This patch: - adds call logs to track screenshot timeouts, e.g. due to waiting for web fonts - makes sure all snapshot expectations have `.png` extension - throws a polite error when given a buffer or a string instead of a page or a locator - removes stray NL between error description and call log - makes sure `apiName` is always correct (and adds a test for it) --- packages/playwright-core/src/server/page.ts | 19 ++++++++++-- .../src/server/screenshotter.ts | 8 +++++ .../playwright-test/src/matchers/matchers.ts | 4 +-- .../src/matchers/toBeTruthy.ts | 4 +-- .../playwright-test/src/matchers/toEqual.ts | 4 +-- .../src/matchers/toMatchSnapshot.ts | 19 ++++++------ .../src/matchers/toMatchText.ts | 4 +-- packages/playwright-test/src/util.ts | 10 ++++-- tests/page/page-screenshot.spec.ts | 7 +++++ tests/playwright-test/reporter-html.spec.ts | 2 +- .../to-have-screenshot.spec.ts | 31 ++++++++++++++++++- 11 files changed, 87 insertions(+), 25 deletions(-) diff --git a/packages/playwright-core/src/server/page.ts b/packages/playwright-core/src/server/page.ts index ab65c54b42..51be7ca751 100644 --- a/packages/playwright-core/src/server/page.ts +++ b/packages/playwright-core/src/server/page.ts @@ -458,16 +458,24 @@ export class Page extends SdkObject { errorMessage?: string, diff?: Buffer, } | undefined = undefined; + const callTimeout = this._timeoutSettings.timeout(options); return controller.run(async progress => { let actual: Buffer | undefined; let previous: Buffer | undefined; const pollIntervals = [0, 100, 250, 500]; + progress.log(`${metadata.apiName}${callTimeout ? ` with timeout ${callTimeout}ms` : ''}`); + if (isGeneratingNewScreenshot) + progress.log(` generating new screenshot expectation: waiting for 2 consecutive screenshots to match`); + else + progress.log(` waiting for screenshot to match expectation`); while (true) { progress.throwIfAborted(); if (this.isClosed()) throw new Error('The page has closed'); let comparatorResult: ComparatorResult | undefined; const screenshotTimeout = pollIntervals.shift() ?? 1000; + if (screenshotTimeout) + progress.log(`waiting ${screenshotTimeout}ms before taking screenshot`); if (isGeneratingNewScreenshot) { previous = actual; actual = await rafrafScreenshot(progress, screenshotTimeout).catch(e => undefined); @@ -478,18 +486,23 @@ export class Page extends SdkObject { } if (comparatorResult !== undefined && !!comparatorResult === !!options.isNot) break; - if (comparatorResult) + if (comparatorResult) { + if (isGeneratingNewScreenshot) + progress.log(`2 last screenshots do not match: ${comparatorResult.errorMessage}`); + else + progress.log(`screenshot does not match expectation: ${comparatorResult.errorMessage}`); intermediateResult = { errorMessage: comparatorResult.errorMessage, diff: comparatorResult.diff, actual, previous }; + } } return isGeneratingNewScreenshot ? { actual } : {}; - }, this._timeoutSettings.timeout(options)).catch(e => { + }, callTimeout).catch(e => { // Q: Why not throw upon isSessionClosedError(e) as in other places? // A: We want user to receive a friendly diff between actual and expected/previous. if (js.isJavaScriptErrorInEvaluate(e) || isInvalidSelectorError(e)) throw e; return { - log: metadata.log, + log: e.message ? [...metadata.log, e.message] : metadata.log, ...intermediateResult, errorMessage: intermediateResult?.errorMessage ?? e.message, }; diff --git a/packages/playwright-core/src/server/screenshotter.ts b/packages/playwright-core/src/server/screenshotter.ts index d6522dc0de..56c63316a5 100644 --- a/packages/playwright-core/src/server/screenshotter.ts +++ b/packages/playwright-core/src/server/screenshotter.ts @@ -84,6 +84,7 @@ export class Screenshotter { async screenshotPage(progress: Progress, options: ScreenshotOptions): Promise { const format = validateScreenshotOptions(options); return this._queue.postTask(async () => { + progress.log('taking page screenshot'); const { viewportSize } = await this._originalViewportSize(progress); await this._preparePageForScreenshot(progress, options.animations === 'disabled', options.fonts === 'ready'); progress.throwIfAborted(); // Avoid restoring after failure - should be done by cleanup. @@ -111,6 +112,7 @@ export class Screenshotter { async screenshotElement(progress: Progress, handle: dom.ElementHandle, options: ScreenshotOptions): Promise { const format = validateScreenshotOptions(options); return this._queue.postTask(async () => { + progress.log('taking element screenshot'); const { viewportSize } = await this._originalViewportSize(progress); await this._preparePageForScreenshot(progress, options.animations === 'disabled', options.fonts === 'ready'); @@ -138,6 +140,10 @@ export class Screenshotter { } async _preparePageForScreenshot(progress: Progress, disableAnimations: boolean, waitForFonts: boolean) { + if (disableAnimations) + progress.log(' disabled all CSS animations'); + if (waitForFonts) + progress.log(' waiting for fonts to load...'); await Promise.all(this._page.frames().map(async frame => { await frame.nonStallingEvaluateInExistingContext('(' + (async function(disableAnimations: boolean, waitForFonts: boolean) { const styleTag = document.createElement('style'); @@ -218,6 +224,8 @@ export class Screenshotter { await document.fonts.ready; }).toString() + `)(${disableAnimations}, ${waitForFonts})`, false, 'utility').catch(() => {}); })); + if (waitForFonts) + progress.log(' fonts in all frames are loaded'); progress.cleanupWhenAborted(() => this._restorePageAfterScreenshot()); } diff --git a/packages/playwright-test/src/matchers/matchers.ts b/packages/playwright-test/src/matchers/matchers.ts index 53b48eee64..60e48673fc 100644 --- a/packages/playwright-test/src/matchers/matchers.ts +++ b/packages/playwright-test/src/matchers/matchers.ts @@ -18,7 +18,7 @@ import { Locator, Page, APIResponse } from 'playwright-core'; import { FrameExpectOptions } from 'playwright-core/lib/client/types'; import { constructURLBasedOnBaseURL } from 'playwright-core/lib/utils/utils'; import type { Expect } from '../types'; -import { expectType, callLogText } from '../util'; +import { expectTypes, callLogText } from '../util'; import { toBeTruthy } from './toBeTruthy'; import { toEqual } from './toEqual'; import { toExpectedTextValues, toMatchText } from './toMatchText'; @@ -275,7 +275,7 @@ export async function toBeOK( response: APIResponseEx ) { const matcherName = 'toBeOK'; - expectType(response, 'APIResponse', matcherName); + expectTypes(response, ['APIResponse'], matcherName); const log = (this.isNot === response.ok()) ? await response._fetchLog() : []; const message = () => this.utils.matcherHint(matcherName, undefined, '', { isNot: this.isNot }) + callLogText(log); const pass = response.ok(); diff --git a/packages/playwright-test/src/matchers/toBeTruthy.ts b/packages/playwright-test/src/matchers/toBeTruthy.ts index 2a048141f2..7159185d53 100644 --- a/packages/playwright-test/src/matchers/toBeTruthy.ts +++ b/packages/playwright-test/src/matchers/toBeTruthy.ts @@ -15,7 +15,7 @@ */ import type { Expect } from '../types'; -import { expectType, callLogText, currentExpectTimeout } from '../util'; +import { expectTypes, callLogText, currentExpectTimeout } from '../util'; export async function toBeTruthy( this: ReturnType, @@ -25,7 +25,7 @@ export async function toBeTruthy( query: (isNot: boolean, timeout: number) => Promise<{ matches: boolean, log?: string[] }>, options: { timeout?: number } = {}, ) { - expectType(receiver, receiverType, matcherName); + expectTypes(receiver, [receiverType], matcherName); const matcherOptions = { isNot: this.isNot, diff --git a/packages/playwright-test/src/matchers/toEqual.ts b/packages/playwright-test/src/matchers/toEqual.ts index 35b36ad4e2..cd9b2f44ee 100644 --- a/packages/playwright-test/src/matchers/toEqual.ts +++ b/packages/playwright-test/src/matchers/toEqual.ts @@ -15,7 +15,7 @@ */ import type { Expect } from '../types'; -import { expectType } from '../util'; +import { expectTypes } from '../util'; import { callLogText, currentExpectTimeout } from '../util'; // Omit colon and one or more spaces, so can call getLabelPrinter. @@ -34,7 +34,7 @@ export async function toEqual( expected: T, options: { timeout?: number, contains?: boolean } = {}, ) { - expectType(receiver, receiverType, matcherName); + expectTypes(receiver, [receiverType], matcherName); const matcherOptions = { comment: options.contains ? '' : 'deep equality', diff --git a/packages/playwright-test/src/matchers/toMatchSnapshot.ts b/packages/playwright-test/src/matchers/toMatchSnapshot.ts index b2eb81e4fb..c5dff94b9d 100644 --- a/packages/playwright-test/src/matchers/toMatchSnapshot.ts +++ b/packages/playwright-test/src/matchers/toMatchSnapshot.ts @@ -21,7 +21,7 @@ import type { Expect } from '../types'; import { currentTestInfo } from '../globals'; import { mimeTypeToComparator, ImageComparatorOptions, Comparator } from 'playwright-core/lib/utils/comparators'; import type { PageScreenshotOptions } from 'playwright-core/types/types'; -import { addSuffixToFilePath, serializeError, sanitizeForFilePath, trimLongString, callLogText, currentExpectTimeout } from '../util'; +import { addSuffixToFilePath, serializeError, sanitizeForFilePath, trimLongString, callLogText, currentExpectTimeout, expectTypes } from '../util'; import { UpdateSnapshots } from '../types'; import colors from 'colors/safe'; import fs from 'fs'; @@ -197,14 +197,12 @@ class SnapshotHelper { colors.red(title), '', ]; - if (diffError) { - output.push(...[ - indent(diffError, ' '), - '', - ]); - } + if (diffError) + output.push(indent(diffError, ' ')); if (log?.length) output.push(callLogText(log)); + else + output.push(''); if (expected !== undefined) { writeFileSync(this.expectedPath, expected); @@ -296,6 +294,9 @@ export async function toHaveScreenshot( threshold: config?.threshold, }, nameOrOptions, optOptions); + if (!helper.snapshotPath.toLowerCase().endsWith('.png')) + throw new Error(`Screenshot name "${path.basename(helper.snapshotPath)}" must have '.png' extension`); + expectTypes(pageOrLocator, ['Page', 'Locator'], 'toHaveScreenshot'); const [page, locator] = pageOrLocator.constructor.name === 'Page' ? [(pageOrLocator as PageEx), undefined] : [(pageOrLocator as Locator).page() as PageEx, pageOrLocator as LocatorEx]; const screenshotOptions = { animations: config?.animations ?? 'disabled', @@ -347,8 +348,8 @@ export async function toHaveScreenshot( // This can be due to e.g. spinning animation, so we want to show it as a diff. if (errorMessage) { const title = actual && previous ? - `Timeout ${timeout}ms exceeded while generating screenshot because ${locator ? 'element' : 'page'} kept changing:` : - `Timeout ${timeout}ms exceeded while generating screenshot:`; + `Timeout ${timeout}ms exceeded while generating screenshot because ${locator ? 'element' : 'page'} kept changing` : + `Timeout ${timeout}ms exceeded while generating screenshot`; return helper.handleDifferent(actual, undefined, previous, diff, undefined, log, title); } diff --git a/packages/playwright-test/src/matchers/toMatchText.ts b/packages/playwright-test/src/matchers/toMatchText.ts index 778ad37d69..ed860b6055 100644 --- a/packages/playwright-test/src/matchers/toMatchText.ts +++ b/packages/playwright-test/src/matchers/toMatchText.ts @@ -18,7 +18,7 @@ import type { ExpectedTextValue } from 'playwright-core/lib/protocol/channels'; import { isRegExp, isString } from 'playwright-core/lib/utils/utils'; import type { Expect } from '../types'; -import { expectType, callLogText, currentExpectTimeout } from '../util'; +import { expectTypes, callLogText, currentExpectTimeout } from '../util'; import { printReceivedStringContainExpectedResult, printReceivedStringContainExpectedSubstring @@ -33,7 +33,7 @@ export async function toMatchText( expected: string | RegExp, options: { timeout?: number, matchSubstring?: boolean } = {}, ) { - expectType(receiver, receiverType, matcherName); + expectTypes(receiver, [receiverType], matcherName); const matcherOptions = { isNot: this.isNot, diff --git a/packages/playwright-test/src/util.ts b/packages/playwright-test/src/util.ts index 42bb520678..8244eee7b5 100644 --- a/packages/playwright-test/src/util.ts +++ b/packages/playwright-test/src/util.ts @@ -170,9 +170,13 @@ export function errorWithLocation(location: Location, message: string) { return new Error(`${formatLocation(location)}: ${message}`); } -export function expectType(receiver: any, type: string, matcherName: string) { - if (typeof receiver !== 'object' || receiver.constructor.name !== type) - throw new Error(`${matcherName} can be only used with ${type} object`); +export function expectTypes(receiver: any, types: string[], matcherName: string) { + if (typeof receiver !== 'object' || !types.includes(receiver.constructor.name)) { + const commaSeparated = types.slice(); + const lastType = commaSeparated.pop(); + const typesString = commaSeparated.length ? commaSeparated.join(', ') + ' or ' + lastType : lastType; + throw new Error(`${matcherName} can be only used with ${typesString} object${types.length > 1 ? 's' : ''}`); + } } export function sanitizeForFilePath(s: string) { diff --git a/tests/page/page-screenshot.spec.ts b/tests/page/page-screenshot.spec.ts index 04acb48cf1..f48225b868 100644 --- a/tests/page/page-screenshot.spec.ts +++ b/tests/page/page-screenshot.spec.ts @@ -724,6 +724,13 @@ it.describe('page screenshot animations', () => { }); // Make sure we can take screenshot. const noIconsScreenshot = await page.screenshot(); + // Make sure screenshot times out while webfont is stalled. + const error = await page.screenshot({ + fonts: 'ready', + timeout: 200, + }).catch(e => e); + expect(error.message).toContain('waiting for fonts to load...'); + expect(error.message).toContain('Timeout 200ms exceeded'); const [iconsScreenshot] = await Promise.all([ page.screenshot({ fonts: 'ready' }), server.serveFile(serverRequest, serverResponse), diff --git a/tests/playwright-test/reporter-html.spec.ts b/tests/playwright-test/reporter-html.spec.ts index 3a562d0308..961e38b8f7 100644 --- a/tests/playwright-test/reporter-html.spec.ts +++ b/tests/playwright-test/reporter-html.spec.ts @@ -194,7 +194,7 @@ test('should include image diff when screenshot failed to generate due to animat await page.click('text=fails'); await expect(page.locator('text=Image mismatch')).toHaveCount(1); await expect(page.locator('text=Snapshot mismatch')).toHaveCount(0); - await expect(page.locator('text=Screenshots')).toHaveCount(0); + await expect(page.locator('.chip-header', { hasText: 'Screenshots' })).toHaveCount(0); const imageDiff = page.locator('data-testid=test-result-image-mismatch'); const image = imageDiff.locator('img'); await expect(image).toHaveAttribute('src', /.*png/); diff --git a/tests/playwright-test/to-have-screenshot.spec.ts b/tests/playwright-test/to-have-screenshot.spec.ts index 3cb9f096c1..601e3cc18a 100644 --- a/tests/playwright-test/to-have-screenshot.spec.ts +++ b/tests/playwright-test/to-have-screenshot.spec.ts @@ -51,6 +51,8 @@ test('should fail to screenshot a page with infinite animation', async ({ runInl }); expect(result.exitCode).toBe(1); expect(stripAnsi(result.output)).toContain(`Timeout 2000ms exceeded while generating screenshot because page kept changing`); + expect(stripAnsi(result.output)).toContain(`expect.toHaveScreenshot with timeout 2000ms`); + expect(stripAnsi(result.output)).toContain(`generating new screenshot expectation: waiting for 2 consecutive screenshots to match`); expect(fs.existsSync(testInfo.outputPath('test-results', 'a-is-a-test', 'is-a-test-1-actual.png'))).toBe(true); expect(fs.existsSync(testInfo.outputPath('test-results', 'a-is-a-test', 'is-a-test-1-expected.png'))).toBe(false); expect(fs.existsSync(testInfo.outputPath('test-results', 'a-is-a-test', 'is-a-test-1-previous.png'))).toBe(true); @@ -367,9 +369,35 @@ test('should fail when screenshot is different size', async ({ runInlineTest }) ` }); expect(result.exitCode).toBe(1); + expect(stripAnsi(result.output)).toContain(`Timeout 2000ms exceeded`); + expect(stripAnsi(result.output)).toContain(`waiting for screenshot to match expectation`); expect(result.output).toContain('Expected an image 22px by 33px, received 1280px by 720px.'); }); +test('should fail when given non-png snapshot name', async ({ runInlineTest }) => { + const result = await runInlineTest({ + 'a.spec.js': ` + pwt.test('is a test', async ({ page }) => { + await expect(page).toHaveScreenshot('snapshot.jpeg'); + }); + ` + }); + expect(result.exitCode).toBe(1); + expect(stripAnsi(result.output)).toContain(`Screenshot name "snapshot.jpeg" must have '.png' extension`); +}); + +test('should fail when given buffer', async ({ runInlineTest }) => { + const result = await runInlineTest({ + 'a.spec.js': ` + pwt.test('is a test', async ({ page }) => { + await expect(Buffer.from([1])).toHaveScreenshot(); + }); + ` + }); + expect(result.exitCode).toBe(1); + expect(stripAnsi(result.output)).toContain(`toHaveScreenshot can be only used with Page or Locator objects`); +}); + test('should fail when screenshot is different pixels', async ({ runInlineTest }) => { const result = await runInlineTest({ ...playwrightConfig({ screenshotsDir: '__screenshots__' }), @@ -382,8 +410,9 @@ test('should fail when screenshot is different pixels', async ({ runInlineTest } }); expect(result.exitCode).toBe(1); expect(result.output).toContain('Screenshot comparison failed'); + expect(result.output).toContain(`Timeout 2000ms exceeded`); expect(result.output).toContain('12345 pixels'); - expect(result.output).not.toContain('Call log'); + expect(result.output).toContain('Call log'); expect(result.output).toContain('ratio 0.02'); expect(result.output).toContain('Expected:'); expect(result.output).toContain('Received:');