chore: introduce Progress concept (#2350)

A progress roughly corresponds to an api call. It is used:

- to collect logs related to the call;
- to handle timeout;
- to provide "cancellation token" behavior so that cancelable process can either
  early-exit with progress.throwIfCanceled() or race against it with progress.race();
- to ensure resources are disposed in the case of a failure
  with progress.cleanupWhenCanceled();
- (possibly) to log api calls if needed;
- (in the future) to augment async stacks.

src/logger.ts

@@ -57,21 +57,6 @@ export class RootLogger implements InnerLogger {
     if (this._logger.isEnabled(log.name, log.severity || 'info'))
       this._logger.log(log.name, log.severity || 'info', message, args, log.color ? { color: log.color } : {});
   }
-
-  startLaunchRecording() {
-    this._logger.add(`launch`, new RecordingLogger('browser'));
-  }
-
-  launchRecording(): string {
-    const logger = this._logger.get(`launch`) as RecordingLogger;
-    if (logger)
-      return logger.recording();
-    return '';
-  }
-
-  stopLaunchRecording() {
-    this._logger.remove(`launch`);
-  }
 }
 
 const colorMap = new Map<string, number>([
@@ -113,27 +98,6 @@ class MultiplexingLogger implements Logger {
   }
 }
 
-export class RecordingLogger implements Logger {
-  private _prefix: string;
-  private _recording: string[] = [];
-
-  constructor(prefix: string) {
-    this._prefix = prefix;
-  }
-
-  isEnabled(name: string, severity: LoggerSeverity): boolean {
-    return name.startsWith(this._prefix);
-  }
-
-  log(name: string, severity: LoggerSeverity, message: string | Error, args: any[], hints: { color?: string }) {
-    this._recording.push(String(message));
-  }
-
-  recording(): string {
-    return this._recording.join('\n');
-  }
-}
-
 class DebugLogger implements Logger {
   private _debuggers = new Map<string, debug.IDebugger>();
 

src/progress.ts

@@ -0,0 +1,116 @@
+/**
+ * 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 { InnerLogger, Log } from './logger';
+import { TimeoutError } from './errors';
+import { helper } from './helper';
+import * as types from './types';
+import { DEFAULT_TIMEOUT, TimeoutSettings } from './timeoutSettings';
+import { getCurrentApiCall, rewriteErrorMessage } from './debug/stackTrace';
+
+class AbortError extends Error {}
+
+export class Progress {
+  static async runCancelableTask<T>(task: (progress: Progress) => Promise<T>, timeoutOptions: types.TimeoutOptions, logger: InnerLogger, apiName?: string): Promise<T> {
+    let resolveCancelation = () => {};
+    const progress = new Progress(timeoutOptions, logger, new Promise(resolve => resolveCancelation = resolve), apiName);
+
+    const { timeout = DEFAULT_TIMEOUT } = timeoutOptions;
+    const timeoutError = new TimeoutError(`Timeout ${timeout}ms exceeded during ${progress.apiName}.`);
+    let rejectWithTimeout: (error: Error) => void;
+    const timeoutPromise = new Promise<T>((resolve, x) => rejectWithTimeout = x);
+    const timeoutTimer = setTimeout(() => rejectWithTimeout(timeoutError), helper.timeUntilDeadline(progress.deadline));
+
+    try {
+      const promise = task(progress);
+      const result = await Promise.race([promise, timeoutPromise]);
+      clearTimeout(timeoutTimer);
+      progress._running = false;
+      progress._logRecording = [];
+      return result;
+    } catch (e) {
+      resolveCancelation();
+      rewriteErrorMessage(e, e.message + formatLogRecording(progress._logRecording, progress.apiName));
+      clearTimeout(timeoutTimer);
+      progress._running = false;
+      progress._logRecording = [];
+      await Promise.all(progress._cleanups.splice(0).map(cleanup => runCleanup(cleanup)));
+      throw e;
+    }
+  }
+
+  readonly apiName: string;
+  readonly deadline: number;  // To be removed?
+  readonly _canceled: Promise<any>;
+
+  private _logger: InnerLogger;
+  private _logRecording: string[] = [];
+  private _cleanups: (() => any)[] = [];
+  private _running = true;
+
+  constructor(options: types.TimeoutOptions, logger: InnerLogger, canceled: Promise<any>, apiName?: string) {
+    this.apiName = apiName || getCurrentApiCall();
+    this.deadline = TimeoutSettings.computeDeadline(options.timeout);
+    this._canceled = canceled;
+    this._logger = logger;
+  }
+
+  cleanupWhenCanceled(cleanup: () => any) {
+    if (this._running)
+      this._cleanups.push(cleanup);
+    else
+      runCleanup(cleanup);
+  }
+
+  throwIfCanceled() {
+    if (!this._running)
+      throw new AbortError();
+  }
+
+  race<T>(promise: Promise<T>, cleanup?: () => any): Promise<T> {
+    const canceled = this._canceled.then(async error => {
+      if (cleanup)
+        await runCleanup(cleanup);
+      throw error;
+    });
+    const success = promise.then(result => {
+      cleanup = undefined;
+      return result;
+    });
+    return Promise.race<T>([success, canceled]);
+  }
+
+  log(log: Log, message: string | Error): void {
+    if (this._running)
+      this._logRecording.push(message.toString());
+    this._logger._log(log, message);
+  }
+}
+
+async function runCleanup(cleanup: () => any) {
+  try {
+    await cleanup();
+  } catch (e) {
+  }
+}
+
+function formatLogRecording(log: string[], name: string): string {
+  name = ` ${name} logs `;
+  const headerLength = 60;
+  const leftLength = (headerLength - name.length) / 2;
+  const rightLength = headerLength - name.length - leftLength;
+  return `\n${'='.repeat(leftLength)}${name}${'='.repeat(rightLength)}\n${log.join('\n')}\n${'='.repeat(headerLength)}`;
+}

src/server/browserServer.ts

@@ -15,8 +15,8 @@
  */
 
 import { ChildProcess } from 'child_process';
-import { EventEmitter } from 'events';
 import { helper } from '../helper';
+import { EventEmitter } from 'events';
 
 export class WebSocketWrapper {
   readonly wsEndpoint: string;

src/server/browserType.ts

@@ -24,13 +24,11 @@ import * as browserPaths from '../install/browserPaths';
 import { Logger, RootLogger, InnerLogger } from '../logger';
 import { ConnectionTransport, WebSocketTransport } from '../transport';
 import { BrowserBase, BrowserOptions, Browser } from '../browser';
-import { assert, helper } from '../helper';
+import { assert } from '../helper';
-import { TimeoutSettings } from '../timeoutSettings';
 import { launchProcess, Env, waitForLine } from './processLauncher';
 import { Events } from '../events';
-import { rewriteErrorMessage } from '../debug/stackTrace';
-import { TimeoutError } from '../errors';
 import { PipeTransport } from './pipeTransport';
+import { Progress } from '../progress';
 
 export type BrowserArgOptions = {
   headless?: boolean,
@@ -102,56 +100,36 @@ export abstract class BrowserTypeBase implements BrowserType {
   async launch(options: LaunchOptions = {}): Promise<Browser> {
     assert(!(options as any).userDataDir, 'userDataDir option is not supported in `browserType.launch`. Use `browserType.launchPersistentContext` instead');
     assert(!(options as any).port, 'Cannot specify a port without launching as a server.');
-    return this._innerLaunch(options, undefined);
+    const logger = new RootLogger(options.logger);
+    const browser = await Progress.runCancelableTask(progress => this._innerLaunch(progress, options, logger, undefined), options, logger);
+    return browser;
   }
 
   async launchPersistentContext(userDataDir: string, options: LaunchOptions & PersistentContextOptions = {}): Promise<BrowserContext> {
     assert(!(options as any).port, 'Cannot specify a port without launching as a server.');
     const persistent = validatePersistentContextOptions(options);
-    const browser = await this._innerLaunch(options, persistent, userDataDir);
+    const logger = new RootLogger(options.logger);
+    const browser = await Progress.runCancelableTask(progress => this._innerLaunch(progress, options, logger, persistent, userDataDir), options, logger);
     return browser._defaultContext!;
   }
 
-  async _innerLaunch(options: LaunchOptions, persistent: PersistentContextOptions | undefined, userDataDir?: string): Promise<BrowserBase> {
+  async _innerLaunch(progress: Progress, options: LaunchOptions, logger: RootLogger, persistent: PersistentContextOptions | undefined, userDataDir?: string): Promise<BrowserBase> {
-    const deadline = TimeoutSettings.computeDeadline(options.timeout);
+    const { browserServer, downloadsPath, transport } = await this._launchServer(progress, options, !!persistent, logger, userDataDir);
-    const logger = new RootLogger(options.logger);
+    if ((options as any).__testHookBeforeCreateBrowser)
-    logger.startLaunchRecording();
+      await (options as any).__testHookBeforeCreateBrowser();
-
+    const browserOptions: BrowserOptions = {
-    let browserServer: BrowserServer | undefined;
+      slowMo: options.slowMo,
-    try {
+      persistent,
-      const launched = await this._launchServer(options, !!persistent, logger, deadline, userDataDir);
+      headful: !processBrowserArgOptions(options).headless,
-      browserServer = launched.browserServer;
+      logger,
-      const browserOptions: BrowserOptions = {
+      downloadsPath,
-        slowMo: options.slowMo,
+      ownedServer: browserServer,
-        persistent,
+    };
-        headful: !processBrowserArgOptions(options).headless,
+    copyTestHooks(options, browserOptions);
-        logger,
-        downloadsPath: launched.downloadsPath,
-        ownedServer: browserServer,
-      };
-      copyTestHooks(options, browserOptions);
-      const hasCustomArguments = !!options.ignoreDefaultArgs && !Array.isArray(options.ignoreDefaultArgs);
-      const promise = this._innerCreateBrowser(launched.transport, browserOptions, hasCustomArguments);
-      const browser = await helper.waitWithDeadline(promise, 'the browser to launch', deadline, 'pw:browser*');
-      return browser;
-    } catch (e) {
-      rewriteErrorMessage(e, e.message + '\n=============== Process output during launch: ===============\n' +
-          logger.launchRecording() +
-          '\n=============================================================');
-      if (browserServer)
-        await browserServer._closeOrKill(deadline);
-      throw e;
-    } finally {
-      logger.stopLaunchRecording();
-    }
-  }
-
-  async _innerCreateBrowser(transport: ConnectionTransport, browserOptions: BrowserOptions, hasCustomArguments: boolean): Promise<BrowserBase> {
-    if ((browserOptions as any).__testHookBeforeCreateBrowser)
-      await (browserOptions as any).__testHookBeforeCreateBrowser();
     const browser = await this._connectToTransport(transport, browserOptions);
     // We assume no control when using custom arguments, and do not prepare the default context in that case.
-    if (browserOptions.persistent && !hasCustomArguments)
+    const hasCustomArguments = !!options.ignoreDefaultArgs && !Array.isArray(options.ignoreDefaultArgs);
+    if (persistent && !hasCustomArguments)
       await browser._defaultContext!._loadDefaultContext();
     return browser;
   }
@@ -160,44 +138,26 @@ export abstract class BrowserTypeBase implements BrowserType {
     assert(!(options as any).userDataDir, 'userDataDir option is not supported in `browserType.launchServer`. Use `browserType.launchPersistentContext` instead');
     const { port = 0 } = options;
     const logger = new RootLogger(options.logger);
-    const { browserServer, transport } = await this._launchServer(options, false, logger, TimeoutSettings.computeDeadline(options.timeout));
+    return Progress.runCancelableTask(async progress => {
-    browserServer._webSocketWrapper = this._wrapTransportWithWebSocket(transport, logger, port);
+      const { browserServer, transport } = await this._launchServer(progress, options, false, logger);
-    return browserServer;
+      browserServer._webSocketWrapper = this._wrapTransportWithWebSocket(transport, logger, port);
+      return browserServer;
+    }, options, logger);
   }
 
   async connect(options: ConnectOptions): Promise<Browser> {
-    const deadline = TimeoutSettings.computeDeadline(options.timeout);
     const logger = new RootLogger(options.logger);
-    logger.startLaunchRecording();
+    return Progress.runCancelableTask(async progress => {
-
+      const transport = await WebSocketTransport.connect(progress, options.wsEndpoint);
-    let transport: ConnectionTransport | undefined;
+      progress.cleanupWhenCanceled(() => transport.closeAndWait());
-    try {
+      if ((options as any).__testHookBeforeCreateBrowser)
-      transport = await WebSocketTransport.connect(options.wsEndpoint, logger, deadline);
+        await (options as any).__testHookBeforeCreateBrowser();
-      const browserOptions: BrowserOptions = {
+      const browser = await this._connectToTransport(transport, { slowMo: options.slowMo, logger });
-        slowMo: options.slowMo,
-        logger,
-      };
-      copyTestHooks(options, browserOptions);
-      const promise = this._innerCreateBrowser(transport, browserOptions, false);
-      const browser = await helper.waitWithDeadline(promise, 'connect to browser', deadline, 'pw:browser*');
-      logger.stopLaunchRecording();
       return browser;
-    } catch (e) {
+    }, options, logger);
-      rewriteErrorMessage(e, e.message + '\n=============== Process output during connect: ===============\n' +
-          logger.launchRecording() +
-          '\n=============================================================');
-      try {
-        if (transport)
-          transport.close();
-      } catch (e) {
-      }
-      throw e;
-    } finally {
-      logger.stopLaunchRecording();
-    }
   }
 
-  private async _launchServer(options: LaunchServerOptions, isPersistent: boolean, logger: RootLogger, deadline: number, userDataDir?: string): Promise<{ browserServer: BrowserServer, downloadsPath: string, transport: ConnectionTransport }> {
+  private async _launchServer(progress: Progress, options: LaunchServerOptions, isPersistent: boolean, logger: RootLogger, userDataDir?: string): Promise<{ browserServer: BrowserServer, downloadsPath: string, transport: ConnectionTransport }> {
     const {
       ignoreDefaultArgs = false,
       args = [],
@@ -238,7 +198,7 @@ export abstract class BrowserTypeBase implements BrowserType {
       handleSIGINT,
       handleSIGTERM,
       handleSIGHUP,
-      logger,
+      progress,
       pipe: !this._webSocketRegexNotPipe,
       tempDirectories,
       attemptToGracefullyClose: async () => {
@@ -254,23 +214,17 @@ export abstract class BrowserTypeBase implements BrowserType {
           browserServer.emit(Events.BrowserServer.Close, exitCode, signal);
       },
     });
-
-    try {
-      if (this._webSocketRegexNotPipe) {
-        const timeoutError = new TimeoutError(`Timed out while trying to connect to the browser!`);
-        const match = await waitForLine(launchedProcess, launchedProcess.stdout, this._webSocketRegexNotPipe, helper.timeUntilDeadline(deadline), timeoutError);
-        const innerEndpoint = match[1];
-        transport = await WebSocketTransport.connect(innerEndpoint, logger, deadline);
-      } else {
-        const stdio = launchedProcess.stdio as unknown as [NodeJS.ReadableStream, NodeJS.WritableStream, NodeJS.WritableStream, NodeJS.WritableStream, NodeJS.ReadableStream];
-        transport = new PipeTransport(stdio[3], stdio[4], logger);
-      }
-    } catch (e) {
-      // If we can't establish a connection, kill the process and exit.
-      helper.killProcess(launchedProcess);
-      throw e;
-    }
     browserServer = new BrowserServer(launchedProcess, gracefullyClose, kill);
+    progress.cleanupWhenCanceled(() => browserServer && browserServer._closeOrKill(progress.deadline));
+
+    if (this._webSocketRegexNotPipe) {
+      const match = await waitForLine(progress, launchedProcess, launchedProcess.stdout, this._webSocketRegexNotPipe);
+      const innerEndpoint = match[1];
+      transport = await WebSocketTransport.connect(progress, innerEndpoint);
+    } else {
+      const stdio = launchedProcess.stdio as unknown as [NodeJS.ReadableStream, NodeJS.WritableStream, NodeJS.WritableStream, NodeJS.WritableStream, NodeJS.ReadableStream];
+      transport = new PipeTransport(stdio[3], stdio[4], logger);
+    }
     return { browserServer, downloadsPath, transport };
   }
 

src/server/electron.ts

@@ -18,10 +18,8 @@ import * as path from 'path';
 import { CRBrowser, CRBrowserContext } from '../chromium/crBrowser';
 import { CRConnection, CRSession } from '../chromium/crConnection';
 import { CRExecutionContext } from '../chromium/crExecutionContext';
-import { TimeoutError } from '../errors';
 import { Events } from '../events';
 import { ExtendedEventEmitter } from '../extendedEventEmitter';
-import { helper } from '../helper';
 import * as js from '../javascript';
 import { InnerLogger, Logger, RootLogger } from '../logger';
 import { Page } from '../page';
@@ -32,6 +30,7 @@ import { BrowserServer } from './browserServer';
 import { launchProcess, waitForLine } from './processLauncher';
 import { BrowserContext } from '../browserContext';
 import type {BrowserWindow} from 'electron';
+import { Progress } from '../progress';
 
 type ElectronLaunchOptions = {
   args?: string[],
@@ -168,40 +167,39 @@ export class Electron  {
       handleSIGTERM = true,
       handleSIGHUP = true,
     } = options;
-    const deadline = TimeoutSettings.computeDeadline(options.timeout);
-    let app: ElectronApplication | undefined = undefined;
-
     const logger = new RootLogger(options.logger);
-    const electronArguments = ['--inspect=0', '--remote-debugging-port=0', '--require', path.join(__dirname, 'electronLoader.js'), ...args];
+    return Progress.runCancelableTask(async progress => {
-    const { launchedProcess, gracefullyClose, kill } = await launchProcess({
+      let app: ElectronApplication | undefined = undefined;
-      executablePath,
+      const electronArguments = ['--inspect=0', '--remote-debugging-port=0', '--require', path.join(__dirname, 'electronLoader.js'), ...args];
-      args: electronArguments,
+      const { launchedProcess, gracefullyClose, kill } = await launchProcess({
-      env,
+        executablePath,
-      handleSIGINT,
+        args: electronArguments,
-      handleSIGTERM,
+        env,
-      handleSIGHUP,
+        handleSIGINT,
-      logger,
+        handleSIGTERM,
-      pipe: true,
+        handleSIGHUP,
-      cwd: options.cwd,
+        progress,
-      tempDirectories: [],
+        pipe: true,
-      attemptToGracefullyClose: () => app!.close(),
+        cwd: options.cwd,
-      onExit: (exitCode, signal) => {
+        tempDirectories: [],
-        if (app)
+        attemptToGracefullyClose: () => app!.close(),
-          app.emit(ElectronEvents.ElectronApplication.Close, exitCode, signal);
+        onExit: (exitCode, signal) => {
-      },
+          if (app)
-    });
+            app.emit(ElectronEvents.ElectronApplication.Close, exitCode, signal);
+        },
+      });
 
-    const timeoutError = new TimeoutError(`Timed out while trying to connect to Electron!`);
+      const nodeMatch = await waitForLine(progress, launchedProcess, launchedProcess.stderr, /^Debugger listening on (ws:\/\/.*)$/);
-    const nodeMatch = await waitForLine(launchedProcess, launchedProcess.stderr, /^Debugger listening on (ws:\/\/.*)$/, helper.timeUntilDeadline(deadline), timeoutError);
+      const nodeTransport = await WebSocketTransport.connect(progress, nodeMatch[1]);
-    const nodeTransport = await WebSocketTransport.connect(nodeMatch[1], logger, deadline);
+      const nodeConnection = new CRConnection(nodeTransport, logger);
-    const nodeConnection = new CRConnection(nodeTransport, logger);
 
-    const chromeMatch = await waitForLine(launchedProcess, launchedProcess.stderr, /^DevTools listening on (ws:\/\/.*)$/, helper.timeUntilDeadline(deadline), timeoutError);
+      const chromeMatch = await waitForLine(progress, launchedProcess, launchedProcess.stderr, /^DevTools listening on (ws:\/\/.*)$/);
-    const chromeTransport = await WebSocketTransport.connect(chromeMatch[1], logger, deadline);
+      const chromeTransport = await WebSocketTransport.connect(progress, chromeMatch[1]);
-    const browserServer = new BrowserServer(launchedProcess, gracefullyClose, kill);
+      const browserServer = new BrowserServer(launchedProcess, gracefullyClose, kill);
-    const browser = await CRBrowser.connect(chromeTransport, { headful: true, logger, persistent: { viewport: null }, ownedServer: browserServer });
+      const browser = await CRBrowser.connect(chromeTransport, { headful: true, logger, persistent: { viewport: null }, ownedServer: browserServer });
-    app = new ElectronApplication(logger, browser, nodeConnection);
+      app = new ElectronApplication(logger, browser, nodeConnection);
-    await app._init();
+      await app._init();
-    return app;
+      return app;
+    }, options, logger);
   }
 }

src/server/processLauncher.ts

@@ -16,17 +16,17 @@
  */
 
 import * as childProcess from 'child_process';
-import { Log, RootLogger } from '../logger';
+import { Log } from '../logger';
 import * as readline from 'readline';
 import * as removeFolder from 'rimraf';
 import * as stream from 'stream';
 import * as util from 'util';
-import { TimeoutError } from '../errors';
 import { helper } from '../helper';
+import { Progress } from '../progress';
 
 const removeFolderAsync = util.promisify(removeFolder);
 
-const browserLog: Log = {
+export const browserLog: Log = {
   name: 'browser',
 };
 
@@ -57,7 +57,7 @@ export type LaunchProcessOptions = {
   // Note: attemptToGracefullyClose should reject if it does not close the browser.
   attemptToGracefullyClose: () => Promise<any>,
   onExit: (exitCode: number | null, signal: string | null) => void,
-  logger: RootLogger,
+  progress: Progress,
 };
 
 type LaunchResult = {
@@ -73,9 +73,9 @@ export async function launchProcess(options: LaunchProcessOptions): Promise<Laun
     }));
   };
 
-  const logger = options.logger;
+  const progress = options.progress;
   const stdio: ('ignore' | 'pipe')[] = options.pipe ? ['ignore', 'pipe', 'pipe', 'pipe', 'pipe'] : ['ignore', 'pipe', 'pipe'];
-  logger._log(browserLog, `<launching> ${options.executablePath} ${options.args.join(' ')}`);
+  progress.log(browserLog, `<launching> ${options.executablePath} ${options.args.join(' ')}`);
   const spawnedProcess = childProcess.spawn(
       options.executablePath,
       options.args,
@@ -97,16 +97,16 @@ export async function launchProcess(options: LaunchProcessOptions): Promise<Laun
     });
     return cleanup().then(() => failedPromise).then(e => Promise.reject(e));
   }
-  logger._log(browserLog, `<launched> pid=${spawnedProcess.pid}`);
+  progress.log(browserLog, `<launched> pid=${spawnedProcess.pid}`);
 
   const stdout = readline.createInterface({ input: spawnedProcess.stdout });
   stdout.on('line', (data: string) => {
-    logger._log(browserStdOutLog, data);
+    progress.log(browserStdOutLog, data);
   });
 
   const stderr = readline.createInterface({ input: spawnedProcess.stderr });
   stderr.on('line', (data: string) => {
-    logger._log(browserStdErrLog, data);
+    progress.log(browserStdErrLog, data);
   });
 
   let processClosed = false;
@@ -115,7 +115,7 @@ export async function launchProcess(options: LaunchProcessOptions): Promise<Laun
   let fulfillCleanup = () => {};
   const waitForCleanup = new Promise<void>(f => fulfillCleanup = f);
   spawnedProcess.once('exit', (exitCode, signal) => {
-    logger._log(browserLog, `<process did exit ${exitCode}, ${signal}>`);
+    progress.log(browserLog, `<process did exit: exitCode=${exitCode}, signal=${signal}>`);
     processClosed = true;
     helper.removeEventListeners(listeners);
     options.onExit(exitCode, signal);
@@ -142,21 +142,21 @@ export async function launchProcess(options: LaunchProcessOptions): Promise<Laun
     // reentrancy to this function, for example user sends SIGINT second time.
     // In this case, let's forcefully kill the process.
     if (gracefullyClosing) {
-      logger._log(browserLog, `<forecefully close>`);
+      progress.log(browserLog, `<forecefully close>`);
       killProcess();
       await waitForClose;  // Ensure the process is dead and we called options.onkill.
       return;
     }
     gracefullyClosing = true;
-    logger._log(browserLog, `<gracefully close start>`);
+    progress.log(browserLog, `<gracefully close start>`);
     await options.attemptToGracefullyClose().catch(() => killProcess());
     await waitForCleanup;  // Ensure the process is dead and we have cleaned up.
-    logger._log(browserLog, `<gracefully close end>`);
+    progress.log(browserLog, `<gracefully close end>`);
   }
 
   // This method has to be sync to be used as 'exit' event handler.
   function killProcess() {
-    logger._log(browserLog, `<kill>`);
+    progress.log(browserLog, `<kill>`);
     helper.removeEventListeners(listeners);
     if (spawnedProcess.pid && !spawnedProcess.killed && !processClosed) {
       // Force kill the browser.
@@ -184,36 +184,19 @@ export async function launchProcess(options: LaunchProcessOptions): Promise<Laun
   return { launchedProcess: spawnedProcess, gracefullyClose, kill: killAndWait };
 }
 
-export function waitForLine(process: childProcess.ChildProcess, inputStream: stream.Readable, regex: RegExp, timeout: number, timeoutError: TimeoutError): Promise<RegExpMatchArray> {
+export function waitForLine(progress: Progress, process: childProcess.ChildProcess, inputStream: stream.Readable, regex: RegExp): Promise<RegExpMatchArray> {
   return new Promise((resolve, reject) => {
     const rl = readline.createInterface({ input: inputStream });
-    let stderr = '';
     const listeners = [
       helper.addEventListener(rl, 'line', onLine),
-      helper.addEventListener(rl, 'close', () => onClose()),
+      helper.addEventListener(rl, 'close', reject),
-      helper.addEventListener(process, 'exit', () => onClose()),
+      helper.addEventListener(process, 'exit', reject),
-      helper.addEventListener(process, 'error', error => onClose(error))
+      helper.addEventListener(process, 'error', reject)
     ];
-    const timeoutId = timeout ? setTimeout(onTimeout, timeout) : 0;
 
-    function onClose(error?: Error) {
+    progress.cleanupWhenCanceled(cleanup);
-      cleanup();
-      reject(new Error([
-        'Failed to launch browser!' + (error ? ' ' + error.message : ''),
-        stderr,
-        '',
-        'TROUBLESHOOTING: https://github.com/Microsoft/playwright/blob/master/docs/troubleshooting.md',
-        '',
-      ].join('\n')));
-    }
-
-    function onTimeout() {
-      cleanup();
-      reject(timeoutError);
-    }
 
     function onLine(line: string) {
-      stderr += line + '\n';
       const match = line.match(regex);
       if (!match)
         return;
@@ -222,8 +205,6 @@ export function waitForLine(process: childProcess.ChildProcess, inputStream: str
     }
 
     function cleanup() {
-      if (timeoutId)
-        clearTimeout(timeoutId);
       helper.removeEventListeners(listeners);
     }
   });

src/timeoutSettings.ts

@@ -19,7 +19,7 @@ import { TimeoutOptions } from './types';
 import { helper } from './helper';
 import * as debugSupport from './debug/debugSupport';
 
-const DEFAULT_TIMEOUT = debugSupport.isDebugMode() ? 0 : 30000;
+export const DEFAULT_TIMEOUT = debugSupport.isDebugMode() ? 0 : 30000;
 
 export class TimeoutSettings {
   private _parent: TimeoutSettings | undefined;

src/transport.ts

@@ -17,7 +17,9 @@
 
 import * as WebSocket from 'ws';
 import { helper } from './helper';
-import { Log, InnerLogger } from './logger';
+import { Log } from './logger';
+import { Progress } from './progress';
+import { browserLog } from './server/processLauncher';
 
 export type ProtocolRequest = {
   id: number;
@@ -120,34 +122,35 @@ export class DeferWriteTransport implements ConnectionTransport {
 
 export class WebSocketTransport implements ConnectionTransport {
   private _ws: WebSocket;
-  private _logger: InnerLogger;
+  private _progress: Progress;
 
   onmessage?: (message: ProtocolResponse) => void;
   onclose?: () => void;
 
-  static connect(url: string, logger: InnerLogger, deadline: number): Promise<ConnectionTransport> {
+  static connect(progress: Progress, url: string): Promise<WebSocketTransport> {
-    logger._log({ name: 'browser' }, `<ws connecting> ${url}`);
+    progress.log(browserLog, `<ws connecting> ${url}`);
-    const transport = new WebSocketTransport(url, logger, deadline);
+    const transport = new WebSocketTransport(progress, url);
-    return new Promise<ConnectionTransport>((fulfill, reject) => {
+    const promise = new Promise<WebSocketTransport>((fulfill, reject) => {
       transport._ws.addEventListener('open', async () => {
-        logger._log({ name: 'browser' }, `<ws connected> ${url}`);
+        progress.log(browserLog, `<ws connected> ${url}`);
         fulfill(transport);
       });
       transport._ws.addEventListener('error', event => {
-        logger._log({ name: 'browser' }, `<ws connect error> ${url} ${event.message}`);
+        progress.log(browserLog, `<ws connect error> ${url} ${event.message}`);
         reject(new Error('WebSocket error: ' + event.message));
         transport._ws.close();
       });
     });
+    return progress.race(promise, () => transport.closeAndWait());
   }
 
-  constructor(url: string, logger: InnerLogger, deadline: number) {
+  constructor(progress: Progress, url: string) {
     this._ws = new WebSocket(url, [], {
       perMessageDeflate: false,
       maxPayload: 256 * 1024 * 1024, // 256Mb,
-      handshakeTimeout: helper.timeUntilDeadline(deadline)
+      handshakeTimeout: helper.timeUntilDeadline(progress.deadline)
     });
-    this._logger = logger;
+    this._progress = progress;
     // The 'ws' module in node sometimes sends us multiple messages in a single task.
     // In Web, all IO callbacks (e.g. WebSocket callbacks)
     // are dispatched into separate tasks, so there's no need
@@ -162,7 +165,7 @@ export class WebSocketTransport implements ConnectionTransport {
     });
 
     this._ws.addEventListener('close', event => {
-      this._logger && this._logger._log({ name: 'browser' }, `<ws server disconnected> ${url}`);
+      this._progress && this._progress.log(browserLog, `<ws disconnected> ${url}`);
       if (this.onclose)
         this.onclose.call(null);
     });
@@ -175,9 +178,15 @@ export class WebSocketTransport implements ConnectionTransport {
   }
 
   close() {
-    this._logger && this._logger._log({ name: 'browser' }, `<ws disconnecting> ${this._ws.url}`);
+    this._progress && this._progress.log(browserLog, `<ws disconnecting> ${this._ws.url}`);
     this._ws.close();
   }
+
+  async closeAndWait() {
+    const promise = new Promise(f => this.onclose = f);
+    this.close();
+    return promise; // Make sure to await the actual disconnect.
+  }
 }
 
 export class SequenceNumberMixer<V> {

test/defaultbrowsercontext.spec.js

@@ -363,7 +363,7 @@ describe('launchPersistentContext()', function() {
     const userDataDir = await makeUserDataDir();
     const options = { ...defaultBrowserOptions, timeout: 5000, __testHookBeforeCreateBrowser: () => new Promise(f => setTimeout(f, 6000)) };
     const error = await browserType.launchPersistentContext(userDataDir, options).catch(e => e);
-    expect(error.message).toContain('Waiting for the browser to launch failed: timeout exceeded. Re-run with the DEBUG=pw:browser* env variable to see the debug log.');
+    expect(error.message).toContain(`Timeout 5000ms exceeded during ${browserType.name()}.launchPersistentContext.`);
     await removeUserDataDir(userDataDir);
   });
   it('should handle exception', async({browserType, defaultBrowserOptions}) => {

test/launcher.spec.js

@@ -53,7 +53,7 @@ describe('Playwright', function() {
     it('should handle timeout', async({browserType, defaultBrowserOptions}) => {
       const options = { ...defaultBrowserOptions, timeout: 5000, __testHookBeforeCreateBrowser: () => new Promise(f => setTimeout(f, 6000)) };
       const error = await browserType.launch(options).catch(e => e);
-      expect(error.message).toContain('Waiting for the browser to launch failed: timeout exceeded. Re-run with the DEBUG=pw:browser* env variable to see the debug log.');
+      expect(error.message).toContain(`Timeout 5000ms exceeded during ${browserType.name()}.launch.`);
     });
     it('should handle exception', async({browserType, defaultBrowserOptions}) => {
       const e = new Error('Dummy');
@@ -285,11 +285,10 @@ describe('browserType.connect', function() {
   });
   it.slow()('should handle exceptions during connect', async({browserType, defaultBrowserOptions, server}) => {
     const browserServer = await browserType.launchServer(defaultBrowserOptions);
-    const e = new Error('Dummy');
+    const __testHookBeforeCreateBrowser = () => { throw new Error('Dummy') };
-    const __testHookBeforeCreateBrowser = () => { throw e };
     const error = await browserType.connect({ wsEndpoint: browserServer.wsEndpoint(), __testHookBeforeCreateBrowser }).catch(e => e);
     await browserServer._checkLeaks();
     await browserServer.close();
-    expect(error).toBe(e);
+    expect(error.message).toContain('Dummy');
   });
 });