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

@@ -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,7 +1240,9 @@ 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) => {
+    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) {
@@ -1270,7 +1273,8 @@ export class Frame extends SdkObject {
 
         // Reached the expected state!
         return result;
-    }, { ...options, isArray }, { strict: true, querySelectorAll: isArray, mainWorld, omitAttached, logScale: true, ...options }).catch(e => {
+      }, { ...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<T, R>(metadata: CallMetadata, selector: string, body: DomTaskBody<T, R, Element>, taskData: T, options: types.TimeoutOptions & types.StrictOptions & { mainWorld?: boolean } = {}): Promise<R> {
     const controller = new ProgressController(metadata, this);
-    return this._scheduleRerunnableTaskWithController(controller, selector, body as DomTaskBody<T, R, Element | undefined>, taskData, options);
+    return controller.run(async progress => {
+      return await this._scheduleRerunnableTaskWithProgress(progress, selector, body as DomTaskBody<T, R, Element | undefined>, taskData, options);
+    }, this._page._timeoutSettings.timeout(options));
   }
 
-  private async _scheduleRerunnableTaskWithController<T, R>(
+  private async _scheduleRerunnableTaskWithProgress<T, R>(
-    controller: ProgressController,
+    progress: Progress,
     selector: string,
     body: DomTaskBody<T, R, Element | undefined>,
     taskData: T,
     options: types.TimeoutOptions & types.StrictOptions & { mainWorld?: boolean, querySelectorAll?: boolean, logScale?: boolean, omitAttached?: boolean } = {}): Promise<R> {
 
     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));
   }
 
   private async _scheduleRerunnableTaskInFrame<T, R>(

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  - '))}
 `;
 }

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);
 });