chrome: improve error messages on vscode side (#27521)

examples/todomvc/tests/integration.spec.ts

@@ -17,8 +17,9 @@ const TODO_ITEMS = [
 
 test.describe('New Todo', () => {
   test('should allow me to add todo items', async ({ page }) => {
+    test.setTimeout(5000);
     // create a new todo locator
-    const newTodo = page.getByPlaceholder('What needs to be done?');
+    const newTodo = page.getByPlaceholder('What needs to be completed?');
     // Create 1st todo.
     await newTodo.fill(TODO_ITEMS[0]);
     await newTodo.press('Enter');

packages/playwright-core/src/client/browser.ts

@@ -72,6 +72,12 @@ export class Browser extends ChannelOwner<channels.BrowserChannel> implements ap
     }, true);
   }
 
+  async _stopPendingOperations(reason: string) {
+    return await this._wrapApiCall(async () => {
+      await this._channel.stopPendingOperations({ reason });
+    }, true);
+  }
+
   async _innerNewContext(options: BrowserContextOptions = {}, forReuse: boolean): Promise<BrowserContext> {
     options = { ...this._browserType._defaultContextOptions, ...options };
     const contextOptions = await prepareBrowserContextParams(options);

packages/playwright-core/src/client/connection.ts

@@ -35,7 +35,7 @@ import { WritableStream } from './writableStream';
 import { debugLogger } from '../common/debugLogger';
 import { SelectorsOwner } from './selectors';
 import { Android, AndroidSocket, AndroidDevice } from './android';
-import { captureLibraryStackText, stringifyStackFrames } from '../utils/stackTrace';
+import { captureLibraryStackText } from '../utils/stackTrace';
 import { Artifact } from './artifact';
 import { EventEmitter } from 'events';
 import { JsonPipe } from './jsonPipe';
@@ -65,7 +65,7 @@ export class Connection extends EventEmitter {
   readonly _objects = new Map<string, ChannelOwner>();
   onmessage = (message: object): void => {};
   private _lastId = 0;
-  private _callbacks = new Map<number, { resolve: (a: any) => void, reject: (a: Error) => void, apiName: string | undefined, frames: channels.StackFrame[], type: string, method: string }>();
+  private _callbacks = new Map<number, { resolve: (a: any) => void, reject: (a: Error) => void, apiName: string | undefined, type: string, method: string }>();
   private _rootObject: Root;
   private _closedErrorMessage: string | undefined;
   private _isRemote = false;
@@ -98,16 +98,6 @@ export class Connection extends EventEmitter {
     return await this._rootObject.initialize();
   }
 
-  pendingProtocolCalls(): String {
-    const lines: string[] = [];
-    for (const call of this._callbacks.values()) {
-      if (!call.apiName)
-        continue;
-      lines.push(`  - ${call.apiName}\n${stringifyStackFrames(call.frames)}\n`);
-    }
-    return lines.length ? 'Pending operations:\n' + lines.join('\n') : '';
-  }
-
   getObjectWithKnownName(guid: string): any {
     return this._objects.get(guid)!;
   }
@@ -129,16 +119,16 @@ export class Connection extends EventEmitter {
     const type = object._type;
     const id = ++this._lastId;
     const message = { id, guid, method, params };
-    if (debugLogger.isEnabled('channel:command')) {
+    if (debugLogger.isEnabled('channel')) {
       // Do not include metadata in debug logs to avoid noise.
-      debugLogger.log('channel:command', JSON.stringify(message));
+      debugLogger.log('channel', 'SEND> ' + JSON.stringify(message));
     }
     const location = frames[0] ? { file: frames[0].file, line: frames[0].line, column: frames[0].column } : undefined;
     const metadata: channels.Metadata = { wallTime, apiName, location, internal: !apiName };
     if (this._tracingCount && frames && type !== 'LocalUtils')
       this._localUtils?._channel.addStackToTracingNoReply({ callData: { stack: frames, id } }).catch(() => {});
     this.onmessage({ ...message, metadata });
-    return await new Promise((resolve, reject) => this._callbacks.set(id, { resolve, reject, apiName, frames, type, method }));
+    return await new Promise((resolve, reject) => this._callbacks.set(id, { resolve, reject, apiName, type, method }));
   }
 
   dispatch(message: object) {
@@ -147,8 +137,8 @@ export class Connection extends EventEmitter {
 
     const { id, guid, method, params, result, error } = message as any;
     if (id) {
-      if (debugLogger.isEnabled('channel:response'))
-        debugLogger.log('channel:response', JSON.stringify(message));
+      if (debugLogger.isEnabled('channel'))
+        debugLogger.log('channel', '<RECV ' + JSON.stringify(message));
       const callback = this._callbacks.get(id);
       if (!callback)
         throw new Error(`Cannot find command to respond: ${id}`);
@@ -162,8 +152,8 @@ export class Connection extends EventEmitter {
       return;
     }
 
-    if (debugLogger.isEnabled('channel:event'))
-      debugLogger.log('channel:event', JSON.stringify(message));
+    if (debugLogger.isEnabled('channel'))
+      debugLogger.log('channel', '<EVENT ' + JSON.stringify(message));
     if (method === '__create__') {
       this._createRemoteObject(guid, params.type, params.guid, params.initializer);
       return;

packages/playwright-core/src/common/debugLogger.ts

@@ -25,9 +25,7 @@ const debugLoggerColorMap = {
   'browser': 0, // reset
   'socks': 92, // purple
   'error': 160, // red,
-  'channel:command': 33, // blue
-  'channel:response': 202, // orange
-  'channel:event': 207, // magenta
+  'channel': 33, // blue
   'server': 45, // cyan
   'server:channel': 34, // green
 };
@@ -55,7 +53,7 @@ class DebugLogger {
     if (!cachedDebugger) {
       cachedDebugger = debug(`pw:${name}`);
       this._debuggers.set(name, cachedDebugger);
-      (cachedDebugger as any).color = debugLoggerColorMap[name];
+      (cachedDebugger as any).color = debugLoggerColorMap[name] || 0;
     }
     cachedDebugger(message);
   }

packages/playwright-core/src/protocol/validator.ts

@@ -718,6 +718,10 @@ scheme.BrowserNewContextForReuseParams = tObject({
 scheme.BrowserNewContextForReuseResult = tObject({
   context: tChannel(['BrowserContext']),
 });
+scheme.BrowserStopPendingOperationsParams = tObject({
+  reason: tString,
+});
+scheme.BrowserStopPendingOperationsResult = tOptional(tObject({}));
 scheme.BrowserNewBrowserCDPSessionParams = tOptional(tObject({}));
 scheme.BrowserNewBrowserCDPSessionResult = tObject({
   session: tChannel(['CDPSession']),

packages/playwright-core/src/remote/playwrightConnection.ts

@@ -211,7 +211,7 @@ export class PlaywrightConnection {
           if (!context.pages().length)
             await context.close(serverSideCallMetadata());
           else
-            await context.stopPendingOperations();
+            await context.stopPendingOperations('Connection closed');
         }
         if (!browser.contexts())
           await browser.close();

packages/playwright-core/src/server/browser.ts

@@ -94,10 +94,14 @@ export abstract class Browser extends SdkObject {
       this._contextForReuse = { context: await this.newContext(metadata, params), hash };
       return { context: this._contextForReuse.context, needsReset: false };
     }
-    await this._contextForReuse.context.stopPendingOperations();
+    await this._contextForReuse.context.stopPendingOperations('Context recreated');
     return { context: this._contextForReuse.context, needsReset: true };
   }
 
+  async stopPendingOperations(reason: string) {
+    await this._contextForReuse?.context?.stopPendingOperations(reason);
+  }
+
   _downloadCreated(page: Page, uuid: string, url: string, suggestedFilename?: string) {
     const download = new Download(page, this.options.downloadsPath || '', uuid, url, suggestedFilename);
     this._downloads.set(uuid, download);

packages/playwright-core/src/server/browserContext.ts

@@ -157,9 +157,13 @@ export abstract class BrowserContext extends SdkObject {
     return true;
   }
 
-  async stopPendingOperations() {
+  async stopPendingOperations(reason: string) {
+    // When using context reuse, stop pending operations to gracefully terminate all the actions
+    // with a user-friendly error message containing operation log.
     for (const controller of this._activeProgressControllers)
-      controller.abort(new Error(`Context was reset for reuse.`));
+      controller.abort(new Error(reason));
+    // Let rejections in microtask generate events before returning.
+    await new Promise(f => setTimeout(f, 0));
   }
 
   static reusableContextHash(params: channels.BrowserNewContextForReuseParams): string {

packages/playwright-core/src/server/dispatchers/browserDispatcher.ts

@@ -52,6 +52,10 @@ export class BrowserDispatcher extends Dispatcher<Browser, channels.BrowserChann
     return await newContextForReuse(this._object, this, params, null, metadata);
   }
 
+  async stopPendingOperations(params: channels.BrowserStopPendingOperationsParams, metadata: CallMetadata): Promise<channels.BrowserStopPendingOperationsResult> {
+    await this._object.stopPendingOperations(params.reason);
+  }
+
   async close(): Promise<void> {
     await this._object.close();
   }
@@ -113,6 +117,10 @@ export class ConnectedBrowserDispatcher extends Dispatcher<Browser, channels.Bro
     return await newContextForReuse(this._object, this as any as BrowserDispatcher, params, this.selectors, metadata);
   }
 
+  async stopPendingOperations(params: channels.BrowserStopPendingOperationsParams, metadata: CallMetadata): Promise<channels.BrowserStopPendingOperationsResult> {
+    await this._object.stopPendingOperations(params.reason);
+  }
+
   async close(): Promise<void> {
     // Client should not send us Browser.close.
   }

packages/playwright/src/index.ts

@@ -330,8 +330,6 @@ const playwrightFixtures: Fixtures<TestFixtures, WorkerFixtures> = ({
       return context;
     });
 
-    const prependToError = testInfoImpl._didTimeout ? (browser as any)._connection.pendingProtocolCalls() : '';
-
     let counter = 0;
     await Promise.all([...contexts.keys()].map(async context => {
       (context as any)[kStartedContextTearDown] = true;
@@ -356,8 +354,6 @@ const playwrightFixtures: Fixtures<TestFixtures, WorkerFixtures> = ({
       }
     }));
 
-    if (prependToError)
-      testInfo.errors.push({ message: prependToError });
   }, { scope: 'test',  _title: 'context' } as any],
 
   _contextReuseMode: process.env.PW_TEST_REUSE_CONTEXT === 'when-possible' ? 'when-possible' : (process.env.PW_TEST_REUSE_CONTEXT ? 'force' : 'none'),
@@ -378,6 +374,7 @@ const playwrightFixtures: Fixtures<TestFixtures, WorkerFixtures> = ({
     const context = await (browser as any)._newContextForReuse(defaultContextOptions);
     (context as any)[kIsReusedContext] = true;
     await use(context);
+    await (browser as any)._stopPendingOperations('Test ended');
   },
 
   page: async ({ context, _reuseContext }, use) => {

packages/protocol/src/channels.ts

@@ -1085,6 +1085,7 @@ export interface BrowserChannel extends BrowserEventTarget, Channel {
   defaultUserAgentForTest(params?: BrowserDefaultUserAgentForTestParams, metadata?: CallMetadata): Promise<BrowserDefaultUserAgentForTestResult>;
   newContext(params: BrowserNewContextParams, metadata?: CallMetadata): Promise<BrowserNewContextResult>;
   newContextForReuse(params: BrowserNewContextForReuseParams, metadata?: CallMetadata): Promise<BrowserNewContextForReuseResult>;
+  stopPendingOperations(params: BrowserStopPendingOperationsParams, metadata?: CallMetadata): Promise<BrowserStopPendingOperationsResult>;
   newBrowserCDPSession(params?: BrowserNewBrowserCDPSessionParams, metadata?: CallMetadata): Promise<BrowserNewBrowserCDPSessionResult>;
   startTracing(params: BrowserStartTracingParams, metadata?: CallMetadata): Promise<BrowserStartTracingResult>;
   stopTracing(params?: BrowserStopTracingParams, metadata?: CallMetadata): Promise<BrowserStopTracingResult>;
@@ -1339,6 +1340,13 @@ export type BrowserNewContextForReuseOptions = {
 export type BrowserNewContextForReuseResult = {
   context: BrowserContextChannel,
 };
+export type BrowserStopPendingOperationsParams = {
+  reason: string,
+};
+export type BrowserStopPendingOperationsOptions = {
+
+};
+export type BrowserStopPendingOperationsResult = void;
 export type BrowserNewBrowserCDPSessionParams = {};
 export type BrowserNewBrowserCDPSessionOptions = {};
 export type BrowserNewBrowserCDPSessionResult = {

packages/protocol/src/protocol.yml

@@ -955,6 +955,10 @@ Browser:
       returns:
         context: BrowserContext
 
+    stopPendingOperations:
+      parameters:
+        reason: string
+
     newBrowserCDPSession:
       returns:
         session: CDPSession

tests/playwright-test/expect.spec.ts

@@ -630,7 +630,6 @@ test('should print pending operations for toHaveText', async ({ runInlineTest })
   expect(result.failed).toBe(1);
   expect(result.exitCode).toBe(1);
   const output = result.output;
-  expect(output).toContain('Pending operations:');
   expect(output).toContain(`expect(locator).toHaveText(expected)`);
   expect(output).toContain('Expected string: "Text"');
   expect(output).toContain('Received string: ""');

tests/playwright-test/playwright.spec.ts

@@ -339,13 +339,8 @@ test('should report error and pending operations on timeout', async ({ runInline
   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('- locator.click');
-  expect(result.output).toContain('a.test.ts:6:37');
-  expect(result.output).toContain('- locator.textContent');
+  expect(result.output).toContain('Error: locator.textContent: Page closed');
   expect(result.output).toContain('a.test.ts:7:42');
-  expect(result.output).toContain('waiting for');
-  expect(result.output).toContain(`7 |           page.getByText('More missing').textContent(),`);
 });
 
 test('should report error on timeout with shared page', async ({ runInlineTest }) => {
@@ -411,8 +406,7 @@ test('should not report waitForEventInfo as pending', async ({ runInlineTest })
   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');
+  expect(result.output).toContain('page.click');
   expect(result.output).toContain('a.test.ts:6:20');
   expect(result.output).not.toContain('- page.waitForLoadState');
 });

tests/playwright-test/timeout.spec.ts

@@ -273,16 +273,16 @@ test('fixture timeout in beforeAll hook should not affect test', async ({ runInl
       import { test as base, expect } from '@playwright/test';
       const test = base.extend({
         fixture: [async ({}, use) => {
-          await new Promise(f => setTimeout(f, 500));
+          await new Promise(f => setTimeout(f, 1000));
           await use('hey');
-        }, { timeout: 800 }],
+        }, { timeout: 1600 }],
       });
       test.beforeAll(async ({ fixture }) => {
         // Nothing to see here.
       });
       test('test ok', async ({}) => {
-        test.setTimeout(1000);
-        await new Promise(f => setTimeout(f, 800));
+        test.setTimeout(2000);
+        await new Promise(f => setTimeout(f, 1600));
       });
     `
   });