chore(logs): Add new log level to capture client-server message's metadata information (#28141)

Goal - Capture minimal diagnostic information for each message being
sent between the playwright client and server.

---------

Co-authored-by: Siddharth Singha Roy <ssingharoy@microsoft.com>
This commit is contained in:
Siddharth Singha Roy 2023-11-16 05:07:14 +05:30 committed by GitHub
parent 80bab8afae
commit 4575c9a182
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
2 changed files with 18 additions and 1 deletions

View File

@ -28,6 +28,7 @@ const debugLoggerColorMap = {
'channel': 33, // blue 'channel': 33, // blue
'server': 45, // cyan 'server': 45, // cyan
'server:channel': 34, // green 'server:channel': 34, // green
'server:metadata': 33, // blue
}; };
export type LogName = keyof typeof debugLoggerColorMap; export type LogName = keyof typeof debugLoggerColorMap;

View File

@ -76,15 +76,20 @@ export class PlaywrightConnection {
const messageString = JSON.stringify(message); const messageString = JSON.stringify(message);
if (debugLogger.isEnabled('server:channel')) if (debugLogger.isEnabled('server:channel'))
debugLogger.log('server:channel', `[${this._id}] ${monotonicTime() * 1000} SEND ► ${messageString}`); debugLogger.log('server:channel', `[${this._id}] ${monotonicTime() * 1000} SEND ► ${messageString}`);
if (debugLogger.isEnabled('server:metadata'))
this.logServerMetadata(message, messageString, 'SEND');
ws.send(messageString); ws.send(messageString);
} }
}; };
ws.on('message', async (message: string) => { ws.on('message', async (message: string) => {
await lock; await lock;
const messageString = Buffer.from(message).toString(); const messageString = Buffer.from(message).toString();
const jsonMessage = JSON.parse(messageString);
if (debugLogger.isEnabled('server:channel')) if (debugLogger.isEnabled('server:channel'))
debugLogger.log('server:channel', `[${this._id}] ${monotonicTime() * 1000} ◀ RECV ${messageString}`); debugLogger.log('server:channel', `[${this._id}] ${monotonicTime() * 1000} ◀ RECV ${messageString}`);
this._dispatcherConnection.dispatch(JSON.parse(messageString)); if (debugLogger.isEnabled('server:metadata'))
this.logServerMetadata(jsonMessage, messageString, 'RECV');
this._dispatcherConnection.dispatch(jsonMessage);
}); });
ws.on('close', () => this._onDisconnect()); ws.on('close', () => this._onDisconnect());
@ -245,6 +250,17 @@ export class PlaywrightConnection {
debugLogger.log('server', `[${this._id}] finished cleanup`); debugLogger.log('server', `[${this._id}] finished cleanup`);
} }
private logServerMetadata(message: object, messageString: string, direction: 'SEND' | 'RECV') {
const serverLogMetadata = {
wallTime: Date.now(),
id: (message as any).id,
guid: (message as any).guid,
method: (message as any).method,
payloadSizeInBytes: Buffer.byteLength(messageString, 'utf-8')
};
debugLogger.log('server:metadata', (direction === 'SEND' ? 'SEND ► ' : '◀ RECV ') + JSON.stringify(serverLogMetadata));
}
async close(reason?: { code: number, reason: string }) { async close(reason?: { code: number, reason: string }) {
if (this._disconnected) if (this._disconnected)
return; return;