feat(logs): add wrapApiCall for logging to many api methods (#5093)

Some methods (quite a few!) were missing the wrapper that produces the log.

src/client/download.ts

@@ -69,18 +69,24 @@ export class Download extends ChannelOwner<channels.DownloadChannel, channels.Do
   }
 
   async failure(): Promise<string | null> {
+    return this._wrapApiCall('download.failure', async () => {
       return (await this._channel.failure()).error || null;
+    });
   }
 
   async createReadStream(): Promise<Readable | null> {
+    return this._wrapApiCall('download.createReadStream', async () => {
       const result = await this._channel.stream();
       if (!result.stream)
         return null;
       const stream = Stream.from(result.stream);
       return stream.stream();
+    });
   }
 
   async delete(): Promise<void> {
+    return this._wrapApiCall('download.delete', async () => {
       return this._channel.delete();
+    });
   }
 }

src/client/electron.ts

@@ -86,14 +86,18 @@ export class ElectronApplication extends ChannelOwner<channels.ElectronApplicati
   }
 
   async firstWindow(): Promise<electronApi.ElectronPage> {
+    return this._wrapApiCall('electronApplication.firstWindow', async () => {
       if (this._windows.size)
         return this._windows.values().next().value;
       return this.waitForEvent('window');
+    });
   }
 
   async newBrowserWindow(options: any): Promise<electronApi.ElectronPage> {
+    return this._wrapApiCall('electronApplication.newBrowserWindow', async () => {
       const result = await this._channel.newBrowserWindow({ arg: serializeArgument(options) });
       return Page.from(result.page) as any as electronApi.ElectronPage;
+    });
   }
 
   context(): ChromiumBrowserContext {
@@ -117,12 +121,16 @@ export class ElectronApplication extends ChannelOwner<channels.ElectronApplicati
   }
 
   async evaluate<R, Arg>(pageFunction: structs.PageFunctionOn<ElectronAppType, Arg, R>, arg: Arg): Promise<R> {
+    return this._wrapApiCall('electronApplication.evaluate', async () => {
       const result = await this._channel.evaluateExpression({ expression: String(pageFunction), isFunction: typeof pageFunction === 'function', arg: serializeArgument(arg) });
       return parseResult(result.value);
+    });
   }
 
   async evaluateHandle<R, Arg>(pageFunction: structs.PageFunctionOn<ElectronAppType, Arg, R>, arg: Arg): Promise<structs.SmartHandle<R>> {
+    return this._wrapApiCall('electronApplication.evaluateHandle', async () => {
       const result = await this._channel.evaluateExpressionHandle({ expression: String(pageFunction), isFunction: typeof pageFunction === 'function', arg: serializeArgument(arg) });
       return JSHandle.from(result.handle) as any as structs.SmartHandle<R>;
+    });
   }
 }

src/client/fileChooser.ts

@@ -44,6 +44,8 @@ export class FileChooser implements api.FileChooser {
   }
 
   async setFiles(files: string | FilePayload | string[] | FilePayload[], options?: channels.ElementHandleSetInputFilesOptions) {
+    return this._page._wrapApiCall('fileChooser.setFiles', async () => {
       return this._elementHandle.setInputFiles(files, options);
+    });
   }
 }

src/client/frame.ts

@@ -441,7 +441,9 @@ export class Frame extends ChannelOwner<channels.FrameChannel, channels.FrameIni
   }
 
   async waitForTimeout(timeout: number) {
+    return this._wrapApiCall(this._apiName('waitForTimeout'), async () => {
       await new Promise(fulfill => setTimeout(fulfill, timeout));
+    });
   }
 
   async waitForFunction<R, Arg>(pageFunction: structs.PageFunction<Arg, R>, arg?: Arg, options: WaitForFunctionOptions = {}): Promise<structs.SmartHandle<R>> {

src/client/jsHandle.ts

@@ -34,29 +34,39 @@ export class JSHandle<T = any> extends ChannelOwner<channels.JSHandleChannel, ch
   }
 
   async evaluate<R, Arg>(pageFunction: structs.PageFunctionOn<T, Arg, R>, arg?: Arg): Promise<R> {
+    return this._wrapApiCall('jsHandle.evaluate', async () => {
       const result = await this._channel.evaluateExpression({ expression: String(pageFunction), isFunction: typeof pageFunction === 'function', arg: serializeArgument(arg) });
       return parseResult(result.value);
+    });
   }
 
   async evaluateHandle<R, Arg>(pageFunction: structs.PageFunctionOn<T, Arg, R>, arg?: Arg): Promise<structs.SmartHandle<R>> {
+    return this._wrapApiCall('jsHandle.evaluateHandle', async () => {
       const result = await this._channel.evaluateExpressionHandle({ expression: String(pageFunction), isFunction: typeof pageFunction === 'function', arg: serializeArgument(arg) });
       return JSHandle.from(result.handle) as any as structs.SmartHandle<R>;
+    });
   }
 
   async getProperty(propertyName: string): Promise<JSHandle> {
+    return this._wrapApiCall('jsHandle.getProperty', async () => {
       const result = await this._channel.getProperty({ name: propertyName });
       return JSHandle.from(result.handle);
+    });
   }
 
   async getProperties(): Promise<Map<string, JSHandle>> {
+    return this._wrapApiCall('jsHandle.getProperties', async () => {
       const map = new Map<string, JSHandle>();
       for (const { name, value } of (await this._channel.getPropertyList()).properties)
         map.set(name, JSHandle.from(value));
       return map;
+    });
   }
 
   async jsonValue(): Promise<T> {
+    return this._wrapApiCall('jsHandle.jsonValue', async () => {
       return parseResult((await this._channel.jsonValue()).value);
+    });
   }
 
   asElement(): T extends Node ? api.ElementHandle<T> : null {

src/client/network.ts

@@ -132,7 +132,9 @@ export class Request extends ChannelOwner<channels.RequestChannel, channels.Requ
   }
 
   async response(): Promise<Response | null> {
+    return this._wrapApiCall('request.response', async () => {
       return Response.fromNullable((await this._channel.response()).response);
+    });
   }
 
   frame(): Frame {
@@ -182,10 +184,13 @@ export class Route extends ChannelOwner<channels.RouteChannel, channels.RouteIni
   }
 
   async abort(errorCode?: string) {
+    return this._wrapApiCall('route.abort', async () => {
       await this._channel.abort({ errorCode });
+    });
   }
 
   async fulfill(options: { status?: number, headers?: Headers, contentType?: string, body?: string | Buffer, path?: string } = {}) {
+    return this._wrapApiCall('route.fulfill', async () => {
       let body = '';
       let isBase64 = false;
       let length = 0;
@@ -220,9 +225,11 @@ export class Route extends ChannelOwner<channels.RouteChannel, channels.RouteIni
         body,
         isBase64
       });
+    });
   }
 
   async continue(options: { url?: string, method?: string, headers?: Headers, postData?: string | Buffer } = {}) {
+    return this._wrapApiCall('route.continue', async () => {
       const postDataBuffer = isString(options.postData) ? Buffer.from(options.postData, 'utf8') : options.postData;
       await this._channel.continue({
         url: options.url,
@@ -230,6 +237,7 @@ export class Route extends ChannelOwner<channels.RouteChannel, channels.RouteIni
         headers: options.headers ? headersObjectToArray(options.headers) : undefined,
         postData: postDataBuffer ? postDataBuffer.toString('base64') : undefined,
       });
+    });
   }
 }
 
@@ -295,7 +303,9 @@ export class Response extends ChannelOwner<channels.ResponseChannel, channels.Re
   }
 
   async body(): Promise<Buffer> {
+    return this._wrapApiCall('response.body', async () => {
       return Buffer.from((await this._channel.body()).binary, 'base64');
+    });
   }
 
   async text(): Promise<string> {

src/client/page.ts

@@ -359,27 +359,43 @@ export class Page extends ChannelOwner<channels.PageChannel, channels.PageInitia
   }
 
   async waitForRequest(urlOrPredicate: string | RegExp | ((r: Request) => boolean), options: { timeout?: number } = {}): Promise<Request> {
+    return this._wrapApiCall('page.waitForRequest', async () => {
       const predicate = (request: Request) => {
         if (isString(urlOrPredicate) || isRegExp(urlOrPredicate))
           return urlMatches(request.url(), urlOrPredicate);
         return urlOrPredicate(request);
       };
-    return this.waitForEvent(Events.Page.Request, { predicate, timeout: options.timeout });
+      const trimmedUrl = trimUrl(urlOrPredicate);
+      const logLine = trimmedUrl ? `waiting for request "${trimmedUrl}"` : undefined;
+      return this._waitForEvent(Events.Page.Request, { predicate, timeout: options.timeout }, logLine);
+    });
   }
 
   async waitForResponse(urlOrPredicate: string | RegExp | ((r: Response) => boolean), options: { timeout?: number } = {}): Promise<Response> {
+    return this._wrapApiCall('page.waitForResponse', async () => {
       const predicate = (response: Response) => {
         if (isString(urlOrPredicate) || isRegExp(urlOrPredicate))
           return urlMatches(response.url(), urlOrPredicate);
         return urlOrPredicate(response);
       };
-    return this.waitForEvent(Events.Page.Response, { predicate, timeout: options.timeout });
+      const trimmedUrl = trimUrl(urlOrPredicate);
+      const logLine = trimmedUrl ? `waiting for response "${trimmedUrl}"` : undefined;
+      return this._waitForEvent(Events.Page.Response, { predicate, timeout: options.timeout }, logLine);
+    });
   }
 
   async waitForEvent(event: string, optionsOrPredicate: WaitForEventOptions = {}): Promise<any> {
+    return this._wrapApiCall('page.waitForEvent', async () => {
+      return this._waitForEvent(event, optionsOrPredicate, `waiting for event "${event}"`);
+    });
+  }
+
+  private async _waitForEvent(event: string, optionsOrPredicate: WaitForEventOptions, logLine?: string): Promise<any> {
     const timeout = this._timeoutSettings.timeout(typeof optionsOrPredicate === 'function' ? {} : optionsOrPredicate);
     const predicate = typeof optionsOrPredicate === 'function' ? optionsOrPredicate : optionsOrPredicate.predicate;
     const waiter = new Waiter();
+    if (logLine)
+      waiter.log(logLine);
     waiter.rejectOnTimeout(timeout, `Timeout while waiting for event "${event}"`);
     if (event !== Events.Page.Crash)
       waiter.rejectOnEvent(this, Events.Page.Crash, new Error('Page crashed'));
@@ -584,7 +600,7 @@ export class Page extends ChannelOwner<channels.PageChannel, channels.PageInitia
   }
 
   async waitForTimeout(timeout: number) {
-    await this._mainFrame.waitForTimeout(timeout);
+    return this._attributeToPage(() => this._mainFrame.waitForTimeout(timeout));
   }
 
   async waitForFunction<R, Arg>(pageFunction: structs.PageFunction<Arg, R>, arg?: Arg, options?: WaitForFunctionOptions): Promise<structs.SmartHandle<R>> {
@@ -624,6 +640,7 @@ export class Page extends ChannelOwner<channels.PageChannel, channels.PageInitia
   }
 
   async _pdf(options: PDFOptions = {}): Promise<Buffer> {
+    return this._wrapApiCall('page.pdf', async () => {
       const transportOptions: channels.PagePdfParams = { ...options } as channels.PagePdfParams;
       if (transportOptions.margin)
         transportOptions.margin = { ...transportOptions.margin };
@@ -643,6 +660,7 @@ export class Page extends ChannelOwner<channels.PageChannel, channels.PageInitia
         await fsWriteFileAsync(options.path, buffer);
       }
       return buffer;
+    });
   }
 }
 
@@ -674,3 +692,11 @@ export class BindingCall extends ChannelOwner<channels.BindingCallChannel, chann
     }
   }
 }
+
+function trimUrl(param: any): string | undefined {
+  if (isString(param)) {
+    if (param.length > 50)
+      param = param.substring(0, 50) + '\u2026';
+    return param;
+  }
+}

src/client/waiter.ts

@@ -17,6 +17,7 @@
 import { EventEmitter } from 'events';
 import { rewriteErrorMessage } from '../utils/stackTrace';
 import { TimeoutError } from '../utils/errors';
+import { debugLogger } from '../utils/debugLogger';
 
 export class Waiter {
   private _dispose: (() => void)[] = [];
@@ -63,6 +64,7 @@ export class Waiter {
 
   log(s: string) {
     this._logs.push(s);
+    debugLogger.log('api', s);
   }
 
   private _rejectOn(promise: Promise<any>, dispose?: () => void) {

src/client/worker.ts

@@ -49,13 +49,17 @@ export class Worker extends ChannelOwner<channels.WorkerChannel, channels.Worker
 
   async evaluate<R, Arg>(pageFunction: structs.PageFunction<Arg, R>, arg?: Arg): Promise<R> {
     assertMaxArguments(arguments.length, 2);
+    return this._wrapApiCall('worker.evaluate', async () => {
       const result = await this._channel.evaluateExpression({ expression: String(pageFunction), isFunction: typeof pageFunction === 'function', arg: serializeArgument(arg) });
       return parseResult(result.value);
+    });
   }
 
   async evaluateHandle<R, Arg>(pageFunction: structs.PageFunction<Arg, R>, arg?: Arg): Promise<structs.SmartHandle<R>> {
     assertMaxArguments(arguments.length, 2);
+    return this._wrapApiCall('worker.evaluateHandle', async () => {
       const result = await this._channel.evaluateExpressionHandle({ expression: String(pageFunction), isFunction: typeof pageFunction === 'function', arg: serializeArgument(arg) });
       return JSHandle.from(result.handle) as any as structs.SmartHandle<R>;
+    });
   }
 }

test/page-wait-for-request.spec.ts

@@ -58,6 +58,11 @@ it('should respect default timeout', async ({page, playwright}) => {
   expect(error).toBeInstanceOf(playwright.errors.TimeoutError);
 });
 
+it('should log the url', async ({page}) => {
+  const error = await page.waitForRequest('long-long-long-long-long-long-long-long-long-long-long-long-long-long.css', { timeout: 100 }).catch(e => e);
+  expect(error.message).toContain('waiting for request "long-long-long-long-long-long-long-long-long-long-…"');
+});
+
 it('should work with no timeout', async ({page, server}) => {
   await page.goto(server.EMPTY_PAGE);
   const [request] = await Promise.all([

test/page-wait-for-response.spec.ts

@@ -43,6 +43,11 @@ it('should respect default timeout', async ({page, playwright}) => {
   expect(error).toBeInstanceOf(playwright.errors.TimeoutError);
 });
 
+it('should log the url', async ({page}) => {
+  const error = await page.waitForResponse('foo.css', { timeout: 100 }).catch(e => e);
+  expect(error.message).toContain('waiting for response "foo.css"');
+});
+
 it('should work with predicate', async ({page, server}) => {
   await page.goto(server.EMPTY_PAGE);
   const [response] = await Promise.all([