Add ability to log communication

This commit is contained in:
Alex Dima 2020-07-30 11:09:55 +02:00
parent 211fe2fcff
commit 4c526744f5
No known key found for this signature in database
GPG key ID: 6E58D7B045760DA0
4 changed files with 172 additions and 27 deletions

View file

@ -4,7 +4,7 @@
*--------------------------------------------------------------------------------------------*/
import { Event, Emitter } from 'vs/base/common/event';
import { IMessagePassingProtocol, IPCClient } from 'vs/base/parts/ipc/common/ipc';
import { IMessagePassingProtocol, IPCClient, IIPCLogger } from 'vs/base/parts/ipc/common/ipc';
import { IDisposable, Disposable, dispose } from 'vs/base/common/lifecycle';
import { VSBuffer } from 'vs/base/common/buffer';
import * as platform from 'vs/base/common/platform';
@ -403,8 +403,8 @@ export class Client<TContext = string> extends IPCClient<TContext> {
get onClose(): Event<void> { return this.protocol.onClose; }
constructor(private protocol: Protocol | PersistentProtocol, id: TContext) {
super(protocol, id);
constructor(private protocol: Protocol | PersistentProtocol, id: TContext, ipcLogger: IIPCLogger | null = null) {
super(protocol, id, ipcLogger);
}
dispose(): void {

View file

@ -12,7 +12,7 @@ import { VSBuffer } from 'vs/base/common/buffer';
import { getRandomElement } from 'vs/base/common/arrays';
import { isFunction, isUndefinedOrNull } from 'vs/base/common/types';
import { revive } from 'vs/base/common/marshalling';
import { isUpperAsciiLetter } from 'vs/base/common/strings';
import * as strings from 'vs/base/common/strings';
/**
* An `IChannel` is an abstraction over a collection of commands.
@ -42,6 +42,19 @@ export const enum RequestType {
EventDispose = 103
}
function requestTypeToStr(type: RequestType): string {
switch (type) {
case RequestType.Promise:
return 'req';
case RequestType.PromiseCancel:
return 'cancel';
case RequestType.EventListen:
return 'subscribe';
case RequestType.EventDispose:
return 'unsubscribe';
}
}
type IRawPromiseRequest = { type: RequestType.Promise; id: number; channelName: string; name: string; arg: any; };
type IRawPromiseCancelRequest = { type: RequestType.PromiseCancel, id: number };
type IRawEventListenRequest = { type: RequestType.EventListen; id: number; channelName: string; name: string; arg: any; };
@ -56,6 +69,20 @@ export const enum ResponseType {
EventFire = 204
}
function responseTypeToStr(type: ResponseType): string {
switch (type) {
case ResponseType.Initialize:
return `init`;
case ResponseType.PromiseSuccess:
return `reply:`;
case ResponseType.PromiseError:
case ResponseType.PromiseErrorObj:
return `replyErr:`;
case ResponseType.EventFire:
return `event:`;
}
}
type IRawInitializeResponse = { type: ResponseType.Initialize };
type IRawPromiseSuccessResponse = { type: ResponseType.PromiseSuccess; id: number; data: any };
type IRawPromiseErrorResponse = { type: ResponseType.PromiseError; id: number; data: { message: string, name: string, stack: string[] | undefined } };
@ -268,7 +295,7 @@ export class ChannelServer<TContext = string> implements IChannelServer<TContext
// They will timeout after `timeoutDelay`.
private pendingRequests = new Map<string, PendingRequest[]>();
constructor(private protocol: IMessagePassingProtocol, private ctx: TContext, private timeoutDelay: number = 1000) {
constructor(private protocol: IMessagePassingProtocol, private ctx: TContext, private logger: IIPCLogger | null = null, private timeoutDelay: number = 1000) {
this.protocolListener = this.protocol.onMessage(msg => this.onRawMessage(msg));
this.sendResponse({ type: ResponseType.Initialize });
}
@ -282,29 +309,41 @@ export class ChannelServer<TContext = string> implements IChannelServer<TContext
private sendResponse(response: IRawResponse): void {
switch (response.type) {
case ResponseType.Initialize:
return this.send([response.type]);
case ResponseType.Initialize: {
const msgLength = this.send([response.type]);
if (this.logger) {
this.logger.logOutgoing(msgLength, 0, RequestInitiator.OtherSide, responseTypeToStr(response.type));
}
return;
}
case ResponseType.PromiseSuccess:
case ResponseType.PromiseError:
case ResponseType.EventFire:
case ResponseType.PromiseErrorObj:
return this.send([response.type, response.id], response.data);
case ResponseType.PromiseErrorObj: {
const msgLength = this.send([response.type, response.id], response.data);
if (this.logger) {
this.logger.logOutgoing(msgLength, response.id, RequestInitiator.OtherSide, responseTypeToStr(response.type), response.data);
}
return;
}
}
}
private send(header: any, body: any = undefined): void {
private send(header: any, body: any = undefined): number {
const writer = new BufferWriter();
serialize(writer, header);
serialize(writer, body);
this.sendBuffer(writer.buffer);
return this.sendBuffer(writer.buffer);
}
private sendBuffer(message: VSBuffer): void {
private sendBuffer(message: VSBuffer): number {
try {
this.protocol.send(message);
return message.byteLength;
} catch (err) {
// noop
return 0;
}
}
@ -316,12 +355,24 @@ export class ChannelServer<TContext = string> implements IChannelServer<TContext
switch (type) {
case RequestType.Promise:
if (this.logger) {
this.logger.logIncoming(message.byteLength, header[1], RequestInitiator.OtherSide, `${requestTypeToStr(type)}: ${header[2]}.${header[3]}`, body);
}
return this.onPromise({ type, id: header[1], channelName: header[2], name: header[3], arg: body });
case RequestType.EventListen:
if (this.logger) {
this.logger.logIncoming(message.byteLength, header[1], RequestInitiator.OtherSide, `${requestTypeToStr(type)}: ${header[2]}.${header[3]}`, body);
}
return this.onEventListen({ type, id: header[1], channelName: header[2], name: header[3], arg: body });
case RequestType.PromiseCancel:
if (this.logger) {
this.logger.logIncoming(message.byteLength, header[1], RequestInitiator.OtherSide, `${requestTypeToStr(type)}`);
}
return this.disposeActiveRequest({ type, id: header[1] });
case RequestType.EventDispose:
if (this.logger) {
this.logger.logIncoming(message.byteLength, header[1], RequestInitiator.OtherSide, `${requestTypeToStr(type)}`);
}
return this.disposeActiveRequest({ type, id: header[1] });
}
}
@ -442,6 +493,16 @@ export class ChannelServer<TContext = string> implements IChannelServer<TContext
}
}
export const enum RequestInitiator {
LocalSide = 0,
OtherSide = 1
}
export interface IIPCLogger {
logIncoming(msgLength: number, requestId: number, initiator: RequestInitiator, str: string, data?: any): void;
logOutgoing(msgLength: number, requestId: number, initiator: RequestInitiator, str: string, data?: any): void;
}
export class ChannelClient implements IChannelClient, IDisposable {
private state: State = State.Uninitialized;
@ -449,12 +510,14 @@ export class ChannelClient implements IChannelClient, IDisposable {
private handlers = new Map<number, IHandler>();
private lastRequestId: number = 0;
private protocolListener: IDisposable | null;
private logger: IIPCLogger | null;
private readonly _onDidInitialize = new Emitter<void>();
readonly onDidInitialize = this._onDidInitialize.event;
constructor(private protocol: IMessagePassingProtocol) {
constructor(private protocol: IMessagePassingProtocol, logger: IIPCLogger | null = null) {
this.protocolListener = this.protocol.onMessage(msg => this.onBuffer(msg));
this.logger = logger;
}
getChannel<T extends IChannel>(channelName: string): T {
@ -579,27 +642,39 @@ export class ChannelClient implements IChannelClient, IDisposable {
private sendRequest(request: IRawRequest): void {
switch (request.type) {
case RequestType.Promise:
case RequestType.EventListen:
return this.send([request.type, request.id, request.channelName, request.name], request.arg);
case RequestType.EventListen: {
const msgLength = this.send([request.type, request.id, request.channelName, request.name], request.arg);
if (this.logger) {
this.logger.logOutgoing(msgLength, request.id, RequestInitiator.LocalSide, `${requestTypeToStr(request.type)}: ${request.channelName}.${request.name}`, request.arg);
}
return;
}
case RequestType.PromiseCancel:
case RequestType.EventDispose:
return this.send([request.type, request.id]);
case RequestType.EventDispose: {
const msgLength = this.send([request.type, request.id]);
if (this.logger) {
this.logger.logOutgoing(msgLength, request.id, RequestInitiator.LocalSide, requestTypeToStr(request.type));
}
return;
}
}
}
private send(header: any, body: any = undefined): void {
private send(header: any, body: any = undefined): number {
const writer = new BufferWriter();
serialize(writer, header);
serialize(writer, body);
this.sendBuffer(writer.buffer);
return this.sendBuffer(writer.buffer);
}
private sendBuffer(message: VSBuffer): void {
private sendBuffer(message: VSBuffer): number {
try {
this.protocol.send(message);
return message.byteLength;
} catch (err) {
// noop
return 0;
}
}
@ -611,12 +686,18 @@ export class ChannelClient implements IChannelClient, IDisposable {
switch (type) {
case ResponseType.Initialize:
if (this.logger) {
this.logger.logIncoming(message.byteLength, 0, RequestInitiator.LocalSide, responseTypeToStr(type));
}
return this.onResponse({ type: header[0] });
case ResponseType.PromiseSuccess:
case ResponseType.PromiseError:
case ResponseType.EventFire:
case ResponseType.PromiseErrorObj:
if (this.logger) {
this.logger.logIncoming(message.byteLength, header[1], RequestInitiator.LocalSide, responseTypeToStr(type), body);
}
return this.onResponse({ type: header[0], id: header[1], data: body });
}
}
@ -844,13 +925,13 @@ export class IPCClient<TContext = string> implements IChannelClient, IChannelSer
private channelClient: ChannelClient;
private channelServer: ChannelServer<TContext>;
constructor(protocol: IMessagePassingProtocol, ctx: TContext) {
constructor(protocol: IMessagePassingProtocol, ctx: TContext, ipcLogger: IIPCLogger | null = null) {
const writer = new BufferWriter();
serialize(writer, ctx);
protocol.send(writer.buffer);
this.channelClient = new ChannelClient(protocol);
this.channelServer = new ChannelServer(protocol, ctx);
this.channelClient = new ChannelClient(protocol, ipcLogger);
this.channelServer = new ChannelServer(protocol, ctx, ipcLogger);
}
getChannel<T extends IChannel>(channelName: string): T {
@ -1068,7 +1149,68 @@ export function createChannelSender<T>(channel: IChannel, options?: IChannelSend
function propertyIsEvent(name: string): boolean {
// Assume a property is an event if it has a form of "onSomething"
return name[0] === 'o' && name[1] === 'n' && isUpperAsciiLetter(name.charCodeAt(2));
return name[0] === 'o' && name[1] === 'n' && strings.isUpperAsciiLetter(name.charCodeAt(2));
}
//#endregion
const colorTables = [
['#2977B1', '#FC802D', '#34A13A', '#D3282F', '#9366BA'],
['#8B564C', '#E177C0', '#7F7F7F', '#BBBE3D', '#2EBECD']
];
function prettyWithoutArrays(data: any): any {
if (Array.isArray(data)) {
return data;
}
if (data && typeof data === 'object' && typeof data.toString === 'function') {
let result = data.toString();
if (result !== '[object Object]') {
return result;
}
}
return data;
}
function pretty(data: any): any {
if (Array.isArray(data)) {
return data.map(prettyWithoutArrays);
}
return prettyWithoutArrays(data);
}
export function logWithColors(direction: string, totalLength: number, msgLength: number, req: number, initiator: RequestInitiator, str: string, data: any): void {
data = pretty(data);
const colorTable = colorTables[initiator];
const color = colorTable[req % colorTable.length];
let args = [`%c[${direction}]%c[${strings.pad(totalLength, 7, ' ')}]%c[len: ${strings.pad(msgLength, 5, ' ')}]%c${strings.pad(req, 5, ' ')} - ${str}`, 'color: darkgreen', 'color: grey', 'color: grey', `color: ${color}`];
if (/\($/.test(str)) {
args = args.concat(data);
args.push(')');
} else {
args.push(data);
}
console.log.apply(console, args as [string, ...string[]]);
}
export class IPCLogger implements IIPCLogger {
private _totalIncoming = 0;
private _totalOutgoing = 0;
constructor(
private readonly _outgoingPrefix: string,
private readonly _incomingPrefix: string,
) { }
public logOutgoing(msgLength: number, requestId: number, initiator: RequestInitiator, str: string, data?: any): void {
this._totalOutgoing += msgLength;
logWithColors(this._outgoingPrefix, this._totalOutgoing, msgLength, requestId, initiator, str, data);
}
public logIncoming(msgLength: number, requestId: number, initiator: RequestInitiator, str: string, data?: any): void {
this._totalIncoming += msgLength;
logWithColors(this._incomingPrefix, this._totalIncoming, msgLength, requestId, initiator, str, data);
}
}

View file

@ -14,6 +14,7 @@ import { isPromiseCanceledError, onUnexpectedError } from 'vs/base/common/errors
import { ISignService } from 'vs/platform/sign/common/sign';
import { CancelablePromise, createCancelablePromise } from 'vs/base/common/async';
import { ILogService } from 'vs/platform/log/common/log';
import { IIPCLogger } from 'vs/base/parts/ipc/common/ipc';
export const enum ConnectionType {
Management = 1,
@ -246,6 +247,7 @@ export interface IConnectionOptions {
addressProvider: IAddressProvider;
signService: ISignService;
logService: ILogService;
ipcLogger: IIPCLogger | null;
}
async function resolveConnectionOptions(options: IConnectionOptions, reconnectionToken: string, reconnectionProtocol: PersistentProtocol | null): Promise<ISimpleConnectionOptions> {
@ -493,7 +495,7 @@ export class ManagementPersistentConnection extends PersistentConnection {
this.client = this._register(new Client<RemoteAgentConnectionContext>(protocol, {
remoteAuthority: remoteAuthority,
clientId: clientId
}));
}, options.ipcLogger));
}
protected async _reconnect(options: ISimpleConnectionOptions): Promise<void> {

View file

@ -5,7 +5,7 @@
import * as nls from 'vs/nls';
import { Disposable } from 'vs/base/common/lifecycle';
import { IChannel, IServerChannel, getDelayedChannel } from 'vs/base/parts/ipc/common/ipc';
import { IChannel, IServerChannel, getDelayedChannel, IPCLogger } from 'vs/base/parts/ipc/common/ipc';
import { Client } from 'vs/base/parts/ipc/common/ipc.net';
import { IEnvironmentService } from 'vs/platform/environment/common/environment';
import { connectRemoteAgentManagement, IConnectionOptions, ISocketFactory, PersistenConnectionEvent } from 'vs/platform/remote/common/remoteAgentConnection';
@ -167,7 +167,8 @@ export class RemoteAgentConnection extends Disposable implements IRemoteAgentCon
}
},
signService: this._signService,
logService: this._logService
logService: this._logService,
ipcLogger: false ? new IPCLogger(`Local \u2192 Remote`, `Remote \u2192 Local`) : null
};
const connection = this._register(await connectRemoteAgentManagement(options, this.remoteAuthority, `renderer`));
this._register(connection.onDidStateChange(e => this._onDidStateChange.fire(e)));