Skip to content

Commit 82cab09

Browse files
dgozmandgozman
authored
feat(logging): add logging to websocket transport (#2289)
1 parent 5a6973f commit 82cab09

File tree

9 files changed

+79
-50
lines changed

9 files changed

+79
-50
lines changed

‎src/server/chromium.ts

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -155,11 +155,12 @@ export class Chromium extends AbstractBrowserType<CRBrowser> {
155155
}
156156

157157
async connect(options: ConnectOptions): Promise<CRBrowser> {
158+
const logger = new RootLogger(options.logger);
158159
return await WebSocketTransport.connect(options.wsEndpoint, async transport => {
159160
if ((options as any).__testHookBeforeCreateBrowser)
160161
await (options as any).__testHookBeforeCreateBrowser();
161-
return CRBrowser.connect(transport, { slowMo: options.slowMo, logger: new RootLogger(options.logger), downloadsPath: '' });
162-
});
162+
return CRBrowser.connect(transport, { slowMo: options.slowMo, logger, downloadsPath: '' });
163+
}, logger);
163164
}
164165

165166
private _defaultArgs(options: BrowserArgOptions = {}, launchType: LaunchType, userDataDir: string): string[] {

‎src/server/electron.ts

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -202,7 +202,7 @@ export class Electron {
202202
const chromeMatch = await waitForLine(launchedProcess, launchedProcess.stderr, /^DevTools listening on (ws:\/\/.*)$/, helper.timeUntilDeadline(deadline), timeoutError);
203203
const chromeTransport = await WebSocketTransport.connect(chromeMatch[1], transport => {
204204
return transport;
205-
});
205+
}, logger);
206206
const browserServer = new BrowserServer(launchedProcess, gracefullyClose, null);
207207
const browser = await CRBrowser.connect(chromeTransport, { headful: true, logger, persistent: true, viewport: null, ownedServer: browserServer, downloadsPath: '' });
208208
app = new ElectronApplication(logger, browser, nodeConnection);

‎src/server/firefox.ts

Lines changed: 8 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -58,7 +58,7 @@ export class Firefox extends AbstractBrowserType<FFBrowser> {
5858
headful: !processBrowserArgOptions(options).headless,
5959
ownedServer: browserServer,
6060
});
61-
});
61+
}, logger);
6262
return browser;
6363
});
6464
}
@@ -83,7 +83,7 @@ export class Firefox extends AbstractBrowserType<FFBrowser> {
8383
ownedServer: browserServer,
8484
headful: !processBrowserArgOptions(options).headless,
8585
});
86-
});
86+
}, logger);
8787
const context = browser._defaultContext!;
8888
if (!options.ignoreDefaultArgs || Array.isArray(options.ignoreDefaultArgs))
8989
await context._loadDefaultContext();
@@ -159,18 +159,21 @@ export class Firefox extends AbstractBrowserType<FFBrowser> {
159159
const match = await waitForLine(launchedProcess, launchedProcess.stdout, /^Juggler listening on (ws:\/\/.*)$/, timeout, timeoutError);
160160
const innerEndpoint = match[1];
161161

162-
const webSocketWrapper = launchType === 'server' ? (await WebSocketTransport.connect(innerEndpoint, t => wrapTransportWithWebSocket(t, logger, port))) : new WebSocketWrapper(innerEndpoint, []);
162+
const webSocketWrapper = launchType === 'server' ?
163+
(await WebSocketTransport.connect(innerEndpoint, t => wrapTransportWithWebSocket(t, logger, port), logger)) :
164+
new WebSocketWrapper(innerEndpoint, []);
163165
browserWSEndpoint = webSocketWrapper.wsEndpoint;
164166
browserServer = new BrowserServer(launchedProcess, gracefullyClose, webSocketWrapper);
165167
return { browserServer, downloadsPath, logger };
166168
}
167169

168170
async connect(options: ConnectOptions): Promise<FFBrowser> {
171+
const logger = new RootLogger(options.logger);
169172
return await WebSocketTransport.connect(options.wsEndpoint, async transport => {
170173
if ((options as any).__testHookBeforeCreateBrowser)
171174
await (options as any).__testHookBeforeCreateBrowser();
172-
return FFBrowser.connect(transport, { slowMo: options.slowMo, logger: new RootLogger(options.logger), downloadsPath: '' });
173-
});
175+
return FFBrowser.connect(transport, { slowMo: options.slowMo, logger, downloadsPath: '' });
176+
}, logger);
174177
}
175178

176179
private _defaultArgs(options: BrowserArgOptions = {}, launchType: LaunchType, userDataDir: string, port: number): string[] {

‎src/server/webkit.ts

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -150,11 +150,12 @@ export class WebKit extends AbstractBrowserType<WKBrowser> {
150150
}
151151

152152
async connect(options: ConnectOptions): Promise<WKBrowser> {
153+
const logger = new RootLogger(options.logger);
153154
return await WebSocketTransport.connect(options.wsEndpoint, async transport => {
154155
if ((options as any).__testHookBeforeCreateBrowser)
155156
await (options as any).__testHookBeforeCreateBrowser();
156-
return WKBrowser.connect(transport, { slowMo: options.slowMo, logger: new RootLogger(options.logger), downloadsPath: '' });
157-
});
157+
return WKBrowser.connect(transport, { slowMo: options.slowMo, logger, downloadsPath: '' });
158+
}, logger);
158159
}
159160

160161
_defaultArgs(options: BrowserArgOptions = {}, launchType: LaunchType, userDataDir: string, port: number): string[] {

‎src/transport.ts

Lines changed: 15 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -17,7 +17,7 @@
1717

1818
import * as WebSocket from 'ws';
1919
import { helper } from './helper';
20-
import { Log } from './logger';
20+
import { Log, InnerLogger } from './logger';
2121

2222
export type ProtocolRequest = {
2323
id: number;
@@ -120,32 +120,40 @@ export class DeferWriteTransport implements ConnectionTransport {
120120

121121
export class WebSocketTransport implements ConnectionTransport {
122122
_ws: WebSocket;
123+
_logger?: InnerLogger;
123124

124125
onmessage?: (message: ProtocolResponse) => void;
125126
onclose?: () => void;
126127

127128
// 'onmessage' handler must be installed synchronously when 'onopen' callback is invoked to
128129
// avoid missing incoming messages.
129-
static connect<T>(url: string, onopen: (transport: ConnectionTransport) => Promise<T> | T): Promise<T> {
130-
const transport = new WebSocketTransport(url);
130+
static connect<T>(url: string, onopen: (transport: ConnectionTransport) => Promise<T> | T, logger?: InnerLogger): Promise<T> {
131+
logger && logger._log({ name: 'browser' }, `<ws connecting> ${url}`);
132+
const transport = new WebSocketTransport(url, logger);
131133
return new Promise<T>((fulfill, reject) => {
132134
transport._ws.addEventListener('open', async () => {
135+
logger && logger._log({ name: 'browser' }, `<ws connected> ${url}`);
133136
try {
134137
fulfill(await onopen(transport));
135138
} catch (e) {
139+
logger && logger._log({ name: 'browser' }, `<ws disconnecting> ${url}`);
136140
try { transport._ws.close(); } catch (ignored) {}
137141
reject(e);
138142
}
139143
});
140-
transport._ws.addEventListener('error', event => reject(new Error('WebSocket error: ' + event.message)));
144+
transport._ws.addEventListener('error', event => {
145+
logger && logger._log({ name: 'browser' }, `<ws connect error> ${url} ${event.message}`);
146+
reject(new Error('WebSocket error: ' + event.message));
147+
});
141148
});
142149
}
143150

144-
constructor(url: string) {
151+
constructor(url: string, logger: InnerLogger | undefined) {
145152
this._ws = new WebSocket(url, [], {
146153
perMessageDeflate: false,
147154
maxPayload: 256 * 1024 * 1024, // 256Mb
148155
});
156+
this._logger = logger;
149157
// The 'ws' module in node sometimes sends us multiple messages in a single task.
150158
// In Web, all IO callbacks (e.g. WebSocket callbacks)
151159
// are dispatched into separate tasks, so there's no need
@@ -160,6 +168,7 @@ export class WebSocketTransport implements ConnectionTransport {
160168
});
161169

162170
this._ws.addEventListener('close', event => {
171+
this._logger && this._logger._log({ name: 'browser' }, `<ws server disconnected> ${url}`);
163172
if (this.onclose)
164173
this.onclose.call(null);
165174
});
@@ -172,6 +181,7 @@ export class WebSocketTransport implements ConnectionTransport {
172181
}
173182

174183
close() {
184+
this._logger && this._logger._log({ name: 'browser' }, `<ws disconnecting> ${this._ws.url}`);
175185
this._ws.close();
176186
}
177187
}

‎test/fixtures.spec.js

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -25,6 +25,7 @@ async function testSignal(state, action, exitOnClose) {
2525
handleSIGTERM: true,
2626
handleSIGHUP: true,
2727
executablePath: state.browserType.executablePath(),
28+
logger: undefined,
2829
});
2930
const res = spawn('node', [path.join(__dirname, 'fixtures', 'closeme.js'), path.join(state.playwrightPath, 'index-for-dev'), state.browserType.name(), JSON.stringify(options), exitOnClose ? 'true' : '']);
3031
let wsEndPointCallback;

‎test/test.config.js

Lines changed: 10 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,7 @@
1818
const fs = require('fs');
1919
const path = require('path');
2020
const rm = require('rimraf').sync;
21+
const utils = require('./utils');
2122
const {TestServer} = require('../utils/testserver/');
2223
const {Environment} = require('../utils/testrunner/Test');
2324

@@ -44,10 +45,12 @@ serverEnvironment.beforeAll(async state => {
4445
state.httpsServer.CROSS_PROCESS_PREFIX = `https://127.0.0.1:${httpsPort}`;
4546
state.httpsServer.EMPTY_PAGE = `https://localhost:${httpsPort}/empty.html`;
4647

48+
state._extraLogger = utils.createTestLogger(valueFromEnv('DEBUGP', false), null, 'extra');
4749
state.defaultBrowserOptions = {
4850
handleSIGINT: false,
4951
slowMo: valueFromEnv('SLOW_MO', 0),
5052
headless: !!valueFromEnv('HEADLESS', true),
53+
logger: state._extraLogger,
5154
};
5255
state.playwrightPath = playwrightPath;
5356
});
@@ -57,9 +60,13 @@ serverEnvironment.afterAll(async({server, httpsServer}) => {
5760
httpsServer.stop(),
5861
]);
5962
});
60-
serverEnvironment.beforeEach(async({server, httpsServer}) => {
61-
server.reset();
62-
httpsServer.reset();
63+
serverEnvironment.beforeEach(async(state, testRun) => {
64+
state.server.reset();
65+
state.httpsServer.reset();
66+
state._extraLogger.setTestRun(testRun);
67+
});
68+
serverEnvironment.afterEach(async(state) => {
69+
state._extraLogger.setTestRun(null);
6370
});
6471

6572
const customEnvironment = new Environment('Golden+CheckContexts');

‎test/test.js

Lines changed: 5 additions & 26 deletions
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,7 @@
1717

1818
const fs = require('fs');
1919
const path = require('path');
20+
const utils = require('./utils');
2021
const TestRunner = require('../utils/testrunner/');
2122
const {Environment} = require('../utils/testrunner/Test');
2223

@@ -120,41 +121,19 @@ function collect(browserNames) {
120121

121122
const browserEnvironment = new Environment(browserName);
122123
browserEnvironment.beforeAll(async state => {
123-
state._logger = null;
124-
state.browser = await state.browserType.launch({...launchOptions, logger: {
125-
isEnabled: (name, severity) => {
126-
return name === 'browser' ||
127-
(name === 'protocol' && config.dumpProtocolOnFailure);
128-
},
129-
log: (name, severity, message, args) => {
130-
if (state._logger)
131-
state._logger(name, severity, message);
132-
}
133-
}});
124+
state._logger = utils.createTestLogger(config.dumpProtocolOnFailure);
125+
state.browser = await state.browserType.launch({...launchOptions, logger: state._logger});
134126
});
135127
browserEnvironment.afterAll(async state => {
136128
await state.browser.close();
137129
delete state.browser;
138130
delete state._logger;
139131
});
140132
browserEnvironment.beforeEach(async(state, testRun) => {
141-
state._logger = (name, severity, message) => {
142-
if (name === 'browser') {
143-
if (severity === 'warning')
144-
testRun.log(`\x1b[31m[browser]\x1b[0m ${message}`)
145-
else
146-
testRun.log(`\x1b[33m[browser]\x1b[0m ${message}`)
147-
} else if (name === 'protocol' && config.dumpProtocolOnFailure) {
148-
testRun.log(`\x1b[32m[protocol]\x1b[0m ${message}`)
149-
}
150-
}
133+
state._logger.setTestRun(testRun);
151134
});
152135
browserEnvironment.afterEach(async (state, testRun) => {
153-
state._logger = null;
154-
if (config.dumpProtocolOnFailure) {
155-
if (testRun.ok())
156-
testRun.output().splice(0);
157-
}
136+
state._logger.setTestRun(null);
158137
});
159138

160139
const pageEnvironment = new Environment('Page');

‎test/utils.js

Lines changed: 33 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -191,10 +191,37 @@ const utils = module.exports = {
191191
// To support isplaywrightready.
192192
platform = p;
193193
},
194-
};
195194

196-
function valueFromEnv(name, defaultValue) {
197-
if (!(name in process.env))
198-
return defaultValue;
199-
return JSON.parse(process.env[name]);
200-
}
195+
createTestLogger(dumpProtocolOnFailure = true, testRun = null, prefix = '') {
196+
const colors = [31, 32, 33, 34, 35, 36, 37];
197+
let colorIndex = 0;
198+
for (let i = 0; i < prefix.length; i++)
199+
colorIndex += prefix.charCodeAt(i);
200+
const color = colors[colorIndex % colors.length];
201+
prefix = prefix ? `\x1b[${color}m[${prefix}]\x1b[0m ` : '';
202+
203+
const logger = {
204+
isEnabled: (name, severity) => {
205+
return name === 'browser' || (name === 'protocol' && dumpProtocolOnFailure);
206+
},
207+
log: (name, severity, message, args) => {
208+
if (!testRun)
209+
return;
210+
if (name === 'browser') {
211+
if (severity === 'warning')
212+
testRun.log(`${prefix}\x1b[31m[browser]\x1b[0m ${message}`)
213+
else
214+
testRun.log(`${prefix}\x1b[33m[browser]\x1b[0m ${message}`)
215+
} else if (name === 'protocol' && dumpProtocolOnFailure) {
216+
testRun.log(`${prefix}\x1b[32m[protocol]\x1b[0m ${message}`)
217+
}
218+
},
219+
setTestRun(tr) {
220+
if (testRun && testRun.ok())
221+
testRun.output().splice(0);
222+
testRun = tr;
223+
},
224+
};
225+
return logger;
226+
},
227+
};

0 commit comments

Comments
 (0)