diff --git a/packages/playwright-core/src/client/browserContext.ts b/packages/playwright-core/src/client/browserContext.ts index bafb4f9d5f..737ae38dca 100644 --- a/packages/playwright-core/src/client/browserContext.ts +++ b/packages/playwright-core/src/client/browserContext.ts @@ -147,7 +147,7 @@ export class BrowserContext extends ChannelOwner if (routeHandler.handle(route, request)) { this._routes.splice(this._routes.indexOf(routeHandler), 1); if (!this._routes.length) - this._wrapApiCall(channel => this._disableInterception(channel), undefined, true).catch(() => {}); + this._wrapApiCall(channel => this._disableInterception(channel), true).catch(() => {}); } return; } diff --git a/packages/playwright-core/src/client/browserType.ts b/packages/playwright-core/src/client/browserType.ts index 1a2d39eab4..d3c7494c6d 100644 --- a/packages/playwright-core/src/client/browserType.ts +++ b/packages/playwright-core/src/client/browserType.ts @@ -82,7 +82,7 @@ export class BrowserType extends ChannelOwner imple browser._logger = logger; browser._setBrowserType(this); return browser; - }, logger); + }); } async launchServer(options: LaunchServerOptions = {}): Promise { @@ -113,7 +113,7 @@ export class BrowserType extends ChannelOwner imple context._setBrowserType(this); await this._onDidCreateContext?.(context); return context; - }, logger); + }); } connect(options: api.ConnectOptions & { wsEndpoint?: string }): Promise; @@ -190,7 +190,7 @@ export class BrowserType extends ChannelOwner imple closePipe(); throw new Error(`Timeout ${params.timeout}ms exceeded`); } - }, logger); + }); } connectOverCDP(options: api.ConnectOverCDPOptions & { wsEndpoint?: string }): Promise; @@ -222,6 +222,6 @@ export class BrowserType extends ChannelOwner imple browser._logger = logger; browser._setBrowserType(this); return browser; - }, logger); + }); } } diff --git a/packages/playwright-core/src/client/channelOwner.ts b/packages/playwright-core/src/client/channelOwner.ts index b2dce54cd6..1db2dc1c44 100644 --- a/packages/playwright-core/src/client/channelOwner.ts +++ b/packages/playwright-core/src/client/channelOwner.ts @@ -18,8 +18,9 @@ import { EventEmitter } from 'events'; import * as channels from '../protocol/channels'; import { createScheme, ValidationError, Validator } from '../protocol/validator'; import { debugLogger } from '../utils/debugLogger'; -import { captureStackTrace, ParsedStackTrace } from '../utils/stackTrace'; +import { captureRawStack, captureStackTrace, ParsedStackTrace } from '../utils/stackTrace'; import { isUnderTest } from '../utils/utils'; +import { zones } from '../utils/zones'; import { ClientInstrumentation } from './clientInstrumentation'; import type { Connection } from './connection'; import type { Logger } from './types'; @@ -51,7 +52,7 @@ export abstract class ChannelOwner { if (prop === 'debugScopeState') - return (params: any) => this._connection.sendMessageToServer(this, prop, params, stackTrace); + return (params: any) => this._connection.sendMessageToServer(this, prop, params, null); if (typeof prop === 'string') { const validator = scheme[paramsName(this._type, prop)]; if (validator) { return (params: any) => { - if (callCookie && csi) { - csi.onApiCallBegin(renderCallWithParams(stackTrace!.apiName!, params), stackTrace, callCookie); - csi = undefined; - } - return this._connection.sendMessageToServer(this, prop, validator(params, ''), stackTrace); + return this._wrapApiCall((channel, apiZone) => { + const { stackTrace, csi, callCookie } = apiZone.reported ? { csi: undefined, callCookie: undefined, stackTrace: null } : apiZone; + apiZone.reported = true; + if (csi && stackTrace && stackTrace.apiName) + csi.onApiCallBegin(renderCallWithParams(stackTrace.apiName, params), stackTrace, callCookie); + return this._connection.sendMessageToServer(this, prop, validator(params, ''), stackTrace); + }); }; } } @@ -98,22 +101,27 @@ export abstract class ChannelOwner(func: (channel: C, stackTrace: ParsedStackTrace) => Promise, logger?: Logger, isInternal?: boolean): Promise { - logger = logger || this._logger; - const stackTrace = captureStackTrace(); - const { apiName, frameTexts } = stackTrace; + async _wrapApiCall(func: (channel: C, apiZone: ApiZone) => Promise, isInternal = false): Promise { + const logger = this._logger; + const stack = captureRawStack(); + const apiZone = zones.zoneData('apiZone', stack); + if (apiZone) + return func(this._channel as any, apiZone); - // Do not report nested async calls to _wrapApiCall. - isInternal = isInternal || stackTrace.allFrames.filter(f => f.function?.includes('_wrapApiCall')).length > 1; + const stackTrace = captureStackTrace(stack); if (isInternal) delete stackTrace.apiName; const csi = isInternal ? undefined : this._instrumentation; const callCookie: any = {}; + const { apiName, frameTexts } = stackTrace; + try { logApiCall(logger, `=> ${apiName} started`, isInternal); - const channel = this._createChannel({}, stackTrace, csi, callCookie); - const result = await func(channel as any, stackTrace); + const apiZone = { stackTrace, isInternal, reported: false, csi, callCookie }; + const result = await zones.run('apiZone', apiZone, async () => { + return await func(this._channel as any, apiZone); + }); csi?.onApiCallEnd(callCookie); logApiCall(logger, `<= ${apiName} succeeded`, isInternal); return result; @@ -173,3 +181,11 @@ const tChannel = (name: string): Validator => { }; const scheme = createScheme(tChannel); + +type ApiZone = { + stackTrace: ParsedStackTrace; + isInternal: boolean; + reported: boolean; + csi: ClientInstrumentation | undefined; + callCookie: any; +}; diff --git a/packages/playwright-core/src/client/connection.ts b/packages/playwright-core/src/client/connection.ts index eb02ecc8d2..4c3946c861 100644 --- a/packages/playwright-core/src/client/connection.ts +++ b/packages/playwright-core/src/client/connection.ts @@ -58,7 +58,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, stackTrace: ParsedStackTrace }>(); + private _callbacks = new Map void, reject: (a: Error) => void, stackTrace: ParsedStackTrace | null }>(); private _rootObject: Root; private _closedErrorMessage: string | undefined; private _isRemote = false; @@ -81,20 +81,19 @@ export class Connection extends EventEmitter { } pendingProtocolCalls(): ParsedStackTrace[] { - return Array.from(this._callbacks.values()).map(callback => callback.stackTrace); + return Array.from(this._callbacks.values()).map(callback => callback.stackTrace).filter(Boolean) as ParsedStackTrace[]; } getObjectWithKnownName(guid: string): any { return this._objects.get(guid)!; } - async sendMessageToServer(object: ChannelOwner, method: string, params: any, maybeStackTrace: ParsedStackTrace | null): Promise { + async sendMessageToServer(object: ChannelOwner, method: string, params: any, stackTrace: ParsedStackTrace | null): Promise { if (this._closedErrorMessage) throw new Error(this._closedErrorMessage); + const { apiName, frames } = stackTrace || { apiName: '', frames: [] }; const guid = object._guid; - const stackTrace: ParsedStackTrace = maybeStackTrace || { frameTexts: [], frames: [], apiName: '', allFrames: [] }; - const { frames, apiName } = stackTrace; const id = ++this._lastId; const converted = { id, guid, method, params }; // Do not include metadata in debug logs to avoid noise. diff --git a/packages/playwright-core/src/client/network.ts b/packages/playwright-core/src/client/network.ts index 8ceea26543..97a42985b3 100644 --- a/packages/playwright-core/src/client/network.ts +++ b/packages/playwright-core/src/client/network.ts @@ -170,7 +170,7 @@ export class Request extends ChannelOwner implements ap async _internalResponse(): Promise { return this._wrapApiCall(async (channel: channels.RequestChannel) => { return Response.fromNullable((await channel.response()).response); - }, undefined, true); + }, true); } frame(): Frame { @@ -309,7 +309,7 @@ export class Route extends ChannelOwner implements api.Ro headers: options.headers ? headersObjectToArray(options.headers) : undefined, postData: postDataBuffer ? postDataBuffer.toString('base64') : undefined, })); - }, undefined, isInternal); + }, isInternal); } } diff --git a/packages/playwright-core/src/client/page.ts b/packages/playwright-core/src/client/page.ts index a3cfbc5f05..aaefcb16fd 100644 --- a/packages/playwright-core/src/client/page.ts +++ b/packages/playwright-core/src/client/page.ts @@ -173,7 +173,7 @@ export class Page extends ChannelOwner implements api.Page if (routeHandler.handle(route, request)) { this._routes.splice(this._routes.indexOf(routeHandler), 1); if (!this._routes.length) - this._wrapApiCall(channel => this._disableInterception(channel), undefined, true).catch(() => {}); + this._wrapApiCall(channel => this._disableInterception(channel), true).catch(() => {}); } return; } diff --git a/packages/playwright-core/src/utils/stackTrace.ts b/packages/playwright-core/src/utils/stackTrace.ts index d038d6b6e2..fc90f4db67 100644 --- a/packages/playwright-core/src/utils/stackTrace.ts +++ b/packages/playwright-core/src/utils/stackTrace.ts @@ -33,6 +33,8 @@ export function rewriteErrorMessage(e: E, newMessage: string): const CORE_DIR = path.resolve(__dirname, '..', '..'); const CLIENT_LIB = path.join(CORE_DIR, 'lib', 'client'); const CLIENT_SRC = path.join(CORE_DIR, 'src', 'client'); +const UTIL_LIB = path.join(CORE_DIR, 'lib', 'util'); +const UTIL_SRC = path.join(CORE_DIR, 'src', 'util'); const TEST_DIR_SRC = path.resolve(CORE_DIR, '..', 'playwright-test'); const TEST_DIR_LIB = path.resolve(CORE_DIR, '..', '@playwright', 'test'); const WS_LIB = path.relative(process.cwd(), path.dirname(require.resolve('ws'))); @@ -44,12 +46,17 @@ export type ParsedStackTrace = { apiName: string | undefined; }; -export function captureStackTrace(): ParsedStackTrace { +export function captureRawStack(): string { const stackTraceLimit = Error.stackTraceLimit; Error.stackTraceLimit = 30; const error = new Error(); const stack = error.stack!; Error.stackTraceLimit = stackTraceLimit; + return stack; +} + +export function captureStackTrace(rawStack?: string): ParsedStackTrace { + const stack = rawStack || captureRawStack(); const isTesting = isUnderTest(); type ParsedFrame = { @@ -80,7 +87,7 @@ export function captureStackTrace(): ParsedStackTrace { fileName = path.resolve(process.cwd(), frame.file); if (isTesting && fileName.includes(path.join('playwright', 'tests', 'config', 'coverage.js'))) return null; - const inClient = fileName.startsWith(CLIENT_LIB) || fileName.startsWith(CLIENT_SRC); + const inClient = fileName.startsWith(CLIENT_LIB) || fileName.startsWith(CLIENT_SRC) || fileName.startsWith(UTIL_LIB) || fileName.startsWith(UTIL_SRC); const parsed: ParsedFrame = { frame: { file: fileName, diff --git a/packages/playwright-core/src/utils/zones.ts b/packages/playwright-core/src/utils/zones.ts new file mode 100644 index 0000000000..65f09ece42 --- /dev/null +++ b/packages/playwright-core/src/utils/zones.ts @@ -0,0 +1,71 @@ +/** + * Copyright (c) Microsoft Corporation. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +import { captureRawStack } from './stackTrace'; + +class ZoneManager { + lastZoneId = 0; + readonly _zones = new Map(); + + constructor() { + } + + async run(type: string, data: T, func: () => Promise): Promise { + const zone = new Zone(this, ++this.lastZoneId, type, data); + this._zones.set(zone.id, zone); + return zone.run(func); + } + + zoneData(type: string, rawStack?: string): T | null { + const stack = rawStack || captureRawStack(); + + for (const line of stack.split('\n')) { + const index = line.indexOf('__PWZONE__['); + if (index !== -1) { + const zoneId = + line.substring(index + '__PWZONE__['.length, line.indexOf(']', index)); + const zone = this._zones.get(zoneId); + if (zone && zone.type === type) + return zone.data; + } + } + return null; + } +} + +class Zone { + private _manager: ZoneManager; + readonly id: number; + readonly type: string; + readonly data: any = {}; + + constructor(manager: ZoneManager, id: number, type: string, data: any) { + this._manager = manager; + this.id = id; + this.type = type; + this.data = data; + } + + async run(func: () => Promise): Promise { + Object.defineProperty(func, 'name', { value: `__PWZONE__[${this.id}]` }); + try { + return await func(); + } finally { + this._manager._zones.delete(this.id); + } + } +} + +export const zones = new ZoneManager(); diff --git a/tests/logger.spec.ts b/tests/logger.spec.ts index 2b4c7218c1..ffe12a0719 100644 --- a/tests/logger.spec.ts +++ b/tests/logger.spec.ts @@ -26,8 +26,8 @@ it('should log', async ({ browserType }) => { await browser.close(); expect(log.length > 0).toBeTruthy(); expect(log.filter(item => item.severity === 'info').length > 0).toBeTruthy(); - expect(log.filter(item => item.message.includes('browserType.launch started')).length > 0).toBeTruthy(); - expect(log.filter(item => item.message.includes('browserType.launch succeeded')).length > 0).toBeTruthy(); + expect(log.filter(item => item.message.includes('browser.newContext started')).length > 0).toBeTruthy(); + expect(log.filter(item => item.message.includes('browser.newContext succeeded')).length > 0).toBeTruthy(); }); it('should log context-level', async ({ browserType }) => { diff --git a/tests/playwright-test/playwright.spec.ts b/tests/playwright-test/playwright.spec.ts index 14d3fc9f01..ad58a06e20 100644 --- a/tests/playwright-test/playwright.spec.ts +++ b/tests/playwright-test/playwright.spec.ts @@ -234,12 +234,12 @@ test('should call logger from launchOptions config', async ({ runInlineTest }, t } }); - test('should support config logger', async ({browser}) => { + test('should support config logger', async ({browser, context}) => { expect(browser.version()).toBeTruthy(); expect(log.length > 0).toBeTruthy(); expect(log.filter(item => item.severity === 'info').length > 0).toBeTruthy(); - expect(log.filter(item => item.message.includes('browserType.launch started')).length > 0).toBeTruthy(); - expect(log.filter(item => item.message.includes('browserType.launch succeeded')).length > 0).toBeTruthy(); + expect(log.filter(item => item.message.includes('browser.newContext started')).length > 0).toBeTruthy(); + expect(log.filter(item => item.message.includes('browser.newContext succeeded')).length > 0).toBeTruthy(); }); `, }, { workers: 1 }); diff --git a/tests/selectors-register.spec.ts b/tests/selectors-register.spec.ts index c2642e450f..c5afda5166 100644 --- a/tests/selectors-register.spec.ts +++ b/tests/selectors-register.spec.ts @@ -107,17 +107,17 @@ it('should handle errors', async ({ playwright, browser }) => { }); error = await playwright.selectors.register('$', createDummySelector).catch(e => e); - expect(error.message).toBe('Selector engine name may only contain [a-zA-Z0-9_] characters'); + expect(error.message).toBe('selectors.register: Selector engine name may only contain [a-zA-Z0-9_] characters'); // Selector names are case-sensitive. await playwright.selectors.register('dummy', createDummySelector); await playwright.selectors.register('duMMy', createDummySelector); error = await playwright.selectors.register('dummy', createDummySelector).catch(e => e); - expect(error.message).toBe('"dummy" selector engine has been already registered'); + expect(error.message).toBe('selectors.register: "dummy" selector engine has been already registered'); error = await playwright.selectors.register('css', createDummySelector).catch(e => e); - expect(error.message).toBe('"css" is a predefined selector engine'); + expect(error.message).toBe('selectors.register: "css" is a predefined selector engine'); await page.close(); }); diff --git a/tests/trace-viewer/trace-viewer.spec.ts b/tests/trace-viewer/trace-viewer.spec.ts index f5e0a6ba1b..c727be0ac7 100644 --- a/tests/trace-viewer/trace-viewer.spec.ts +++ b/tests/trace-viewer/trace-viewer.spec.ts @@ -194,6 +194,7 @@ test('should open simple trace viewer', async ({ showTraceViewer }) => { /page.gotohttp:\/\/localhost:\d+\/frames\/frame.html/, /route.continue/, /page.setViewportSize/, + /browserContext.close/, ]); });