Add ability to log message content (#1792)

This commit is contained in:
Andrew Stanton-Nurse 2018-04-03 18:46:25 -07:00 committed by GitHub
parent 7c2d9e87e9
commit 99ae47be09
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
8 changed files with 220 additions and 72 deletions

View File

@ -19,6 +19,8 @@ Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "Solution Items", "Solution
EndProjectSection
EndProject
Project("{2150E333-8FDC-42A3-9474-1A3956D46DE8}") = "samples", "samples", "{C4BC9889-B49F-41B6-806B-F84941B2549B}"
ProjectSection(SolutionItems) = preProject
EndProjectSection
EndProject
Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "SignalRSamples", "samples\SignalRSamples\SignalRSamples.csproj", "{C4AEAB04-F341-4539-B6C0-52368FB4BF9E}"
EndProject

View File

@ -1,15 +1,20 @@
// Copyright (c) .NET Foundation. All rights reserved.
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
import { HttpConnection, LogLevel, TransferFormat, TransportType } from "@aspnet/signalr";
import { HttpConnection, IHttpConnectionOptions, LogLevel, TransferFormat, TransportType } from "@aspnet/signalr";
import { eachTransport, ECHOENDPOINT_URL } from "./Common";
import { TestLogger } from "./TestLogger";
const commonOptions: IHttpConnectionOptions = {
logMessageContent: true,
logger: TestLogger.instance,
};
describe("connection", () => {
it("can connect to the server without specifying transport explicitly", (done) => {
const message = "Hello World!";
const connection = new HttpConnection(ECHOENDPOINT_URL, {
logger: TestLogger.instance,
...commonOptions,
});
let received = "";
@ -34,33 +39,103 @@ describe("connection", () => {
});
eachTransport((transportType) => {
it("over " + TransportType[transportType] + " can send and receive messages", (done) => {
const message = "Hello World!";
// the url should be resolved relative to the document.location.host
// and the leading '/' should be automatically added to the url
const connection = new HttpConnection("echo", {
logger: TestLogger.instance,
transport: transportType,
describe(`over ${TransportType[transportType]}`, () => {
it("can send and receive messages", (done) => {
const message = "Hello World!";
// the url should be resolved relative to the document.location.host
// and the leading '/' should be automatically added to the url
const connection = new HttpConnection("echo", {
...commonOptions,
transport: transportType,
});
let received = "";
connection.onreceive = (data) => {
received += data;
if (data === message) {
connection.stop();
}
};
connection.onclose = (error) => {
expect(error).toBeUndefined();
done();
};
connection.start(TransferFormat.Text).then(() => {
connection.send(message);
}).catch((e) => {
fail(e);
done();
});
});
let received = "";
connection.onreceive = (data) => {
received += data;
if (data === message) {
connection.stop();
}
};
it("does not log content of messages sent or received by default", (done) => {
const message = "Hello World!";
connection.onclose = (error) => {
expect(error).toBeUndefined();
done();
};
// DON'T use commonOptions because we want to specifically test the scenario where logMessageContent is not set.
const connection = new HttpConnection("echo", {
transport: transportType,
});
connection.start(TransferFormat.Text).then(() => {
connection.send(message);
}).catch((e) => {
fail(e);
done();
connection.onreceive = (data) => {
if (data === message) {
connection.stop();
}
};
connection.onclose = (error) => {
// Search the logs for the message content
for (const [_, logMessage] of TestLogger.instance.currentLog.messages) {
expect(logMessage).not.toContain(message);
}
done();
};
connection.start(TransferFormat.Text).then(() => {
connection.send(message);
}).catch((e) => {
fail(e);
done();
});
});
it("does log content of messages sent or received when enabled", (done) => {
const message = "Hello World!";
// DON'T use commonOptions because we want to specifically test the scenario where logMessageContent is set to true (even if commonOptions changes).
const connection = new HttpConnection("echo", {
logMessageContent: true,
logger: TestLogger.instance,
transport: transportType,
});
connection.onreceive = (data) => {
if (data === message) {
connection.stop();
}
};
connection.onclose = (error) => {
// Search the logs for the message content
let matches = 0;
for (const [_, logMessage] of TestLogger.instance.currentLog.messages) {
if (logMessage.indexOf(message) !== -1) {
matches += 1;
}
}
// One match for send, one for receive.
expect(matches).toEqual(2);
done();
};
connection.start(TransferFormat.Text).then(() => {
connection.send(message);
}).catch((e) => {
fail(e);
done();
});
});
});
});

View File

@ -1,7 +1,7 @@
// Copyright (c) .NET Foundation. All rights reserved.
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
import { HubConnection, JsonHubProtocol, LogLevel, TransportType } from "@aspnet/signalr";
import { HubConnection, IHubConnectionOptions, JsonHubProtocol, LogLevel, TransportType } from "@aspnet/signalr";
import { MessagePackHubProtocol } from "@aspnet/signalr-protocol-msgpack";
import { eachTransport, eachTransportAndProtocol } from "./Common";
@ -10,6 +10,11 @@ import { TestLogger } from "./TestLogger";
const TESTHUBENDPOINT_URL = "/testhub";
const TESTHUB_NOWEBSOCKETS_ENDPOINT_URL = "/testhub-nowebsockets";
const commonOptions: IHubConnectionOptions = {
logMessageContent: true,
logger: TestLogger.instance,
};
describe("hubConnection", () => {
eachTransportAndProtocol((transportType, protocol) => {
describe("using " + protocol.name + " over " + TransportType[transportType] + " transport", () => {
@ -17,7 +22,7 @@ describe("hubConnection", () => {
const message = "你好,世界!";
const hubConnection = new HubConnection(TESTHUBENDPOINT_URL, {
logger: TestLogger.instance,
...commonOptions,
protocol,
transport: transportType,
});
@ -44,7 +49,7 @@ describe("hubConnection", () => {
const message = "你好,世界!";
const hubConnection = new HubConnection(TESTHUBENDPOINT_URL, {
logger: TestLogger.instance,
...commonOptions,
protocol,
transport: transportType,
});
@ -67,7 +72,7 @@ describe("hubConnection", () => {
it("can invoke server method structural object and receive structural result", (done) => {
const hubConnection = new HubConnection(TESTHUBENDPOINT_URL, {
logger: TestLogger.instance,
...commonOptions,
protocol,
transport: transportType,
});
@ -93,7 +98,7 @@ describe("hubConnection", () => {
it("can stream server method and receive result", (done) => {
const hubConnection = new HubConnection(TESTHUBENDPOINT_URL, {
logger: TestLogger.instance,
...commonOptions,
protocol,
transport: transportType,
});
@ -127,7 +132,7 @@ describe("hubConnection", () => {
it("rethrows an exception from the server when invoking", (done) => {
const errorMessage = "An unexpected error occurred invoking 'ThrowException' on the server. InvalidOperationException: An error occurred.";
const hubConnection = new HubConnection(TESTHUBENDPOINT_URL, {
logger: TestLogger.instance,
...commonOptions,
protocol,
transport: transportType,
});
@ -151,7 +156,7 @@ describe("hubConnection", () => {
it("throws an exception when invoking streaming method with invoke", (done) => {
const hubConnection = new HubConnection(TESTHUBENDPOINT_URL, {
logger: TestLogger.instance,
...commonOptions,
protocol,
transport: transportType,
});
@ -175,7 +180,7 @@ describe("hubConnection", () => {
it("throws an exception when receiving a streaming result for method called with invoke", (done) => {
const hubConnection = new HubConnection(TESTHUBENDPOINT_URL, {
logger: TestLogger.instance,
...commonOptions,
protocol,
transport: transportType,
});
@ -200,7 +205,7 @@ describe("hubConnection", () => {
it("rethrows an exception from the server when streaming", (done) => {
const errorMessage = "An unexpected error occurred invoking 'StreamThrowException' on the server. InvalidOperationException: An error occurred.";
const hubConnection = new HubConnection(TESTHUBENDPOINT_URL, {
logger: TestLogger.instance,
...commonOptions,
protocol,
transport: transportType,
});
@ -229,7 +234,7 @@ describe("hubConnection", () => {
it("throws an exception when invoking hub method with stream", (done) => {
const hubConnection = new HubConnection(TESTHUBENDPOINT_URL, {
logger: TestLogger.instance,
...commonOptions,
protocol,
transport: transportType,
});
@ -258,7 +263,7 @@ describe("hubConnection", () => {
it("can receive server calls", (done) => {
const hubConnection = new HubConnection(TESTHUBENDPOINT_URL, {
logger: TestLogger.instance,
...commonOptions,
protocol,
transport: transportType,
});
@ -290,7 +295,7 @@ describe("hubConnection", () => {
it("can receive server calls without rebinding handler when restarted", (done) => {
const hubConnection = new HubConnection(TESTHUBENDPOINT_URL, {
logger: TestLogger.instance,
...commonOptions,
protocol,
transport: transportType,
});
@ -347,7 +352,7 @@ describe("hubConnection", () => {
it("closed with error if hub cannot be created", (done) => {
const hubConnection = new HubConnection("http://" + document.location.host + "/uncreatable", {
logger: TestLogger.instance,
...commonOptions,
protocol,
transport: transportType,
});
@ -361,7 +366,7 @@ describe("hubConnection", () => {
it("can handle different types", (done) => {
const hubConnection = new HubConnection(TESTHUBENDPOINT_URL, {
logger: TestLogger.instance,
...commonOptions,
protocol,
transport: transportType,
});
@ -409,7 +414,7 @@ describe("hubConnection", () => {
const message = "你好,世界!";
const hubConnection = new HubConnection(TESTHUBENDPOINT_URL, {
logger: TestLogger.instance,
...commonOptions,
protocol,
transport: transportType,
});
@ -464,7 +469,7 @@ describe("hubConnection", () => {
const jwtToken = await getJwtToken("http://" + document.location.host + "/generateJwtToken");
const hubConnection = new HubConnection("/authorizedhub", {
accessTokenFactory: () => jwtToken,
logger: TestLogger.instance,
...commonOptions,
transport: transportType,
});
hubConnection.onclose((error) => {
@ -488,7 +493,7 @@ describe("hubConnection", () => {
if (transportType !== TransportType.LongPolling) {
it("terminates if no messages received within timeout interval", (done) => {
const hubConnection = new HubConnection(TESTHUBENDPOINT_URL, {
logger: TestLogger.instance,
...commonOptions,
timeoutInMilliseconds: 100,
transport: transportType,
});
@ -512,7 +517,7 @@ describe("hubConnection", () => {
if (typeof EventSource !== "undefined") {
it("allows Server-Sent Events when negotiating for JSON protocol", async (done) => {
const hubConnection = new HubConnection(TESTHUB_NOWEBSOCKETS_ENDPOINT_URL, {
logger: TestLogger.instance,
...commonOptions,
protocol: new JsonHubProtocol(),
});
@ -530,7 +535,7 @@ describe("hubConnection", () => {
it("skips Server-Sent Events when negotiating for MsgPack protocol", async (done) => {
const hubConnection = new HubConnection(TESTHUB_NOWEBSOCKETS_ENDPOINT_URL, {
logger: TestLogger.instance,
...commonOptions,
protocol: new MessagePackHubProtocol(),
});

View File

@ -1,22 +1,58 @@
import { ConsoleLogger, ILogger, LogLevel } from "@aspnet/signalr";
export class TestLog {
public messages: Array<[LogLevel, string]> = [];
public addMessage(logLevel: LogLevel, message: string): void {
this.messages.push([logLevel, message]);
}
public getLog(): string {
// Dump the logs to a string
let str = "";
for (const [level, message] of this.messages) {
str += `${LogLevel[level]}: ${message}\r\n`;
}
return str;
}
public getLogUrl(): string {
const log = this.getLog();
return `data:text/plain;base64,${escape(btoa(log))}`;
}
public open(): void {
window.open(this.getLogUrl());
}
}
export class TestLogger implements ILogger {
public static instance: TestLogger = new TestLogger();
private static consoleLogger: ConsoleLogger = new ConsoleLogger(LogLevel.Trace);
public messages: Array<[LogLevel, string]> = [];
public currentLog: TestLog = new TestLog();
public log(logLevel: LogLevel, message: string): void {
// Capture log message so it can be reported later
this.messages.push([logLevel, message]);
this.currentLog.addMessage(logLevel, message);
// Also write to browser console
TestLogger.consoleLogger.log(logLevel, message);
}
public static getMessagesAndReset(): Array<[LogLevel, string]> {
const messages = TestLogger.instance.messages;
TestLogger.instance = new TestLogger();
return messages;
public static saveLogsAndReset(testName: string): TestLog {
const currentLog = TestLogger.instance.currentLog;
// Stash the messages in a global to help people review them
if (window) {
const win = window as any;
if (!win.TestLogMessages) {
win.TestLogMessages = {};
}
win.TestLogMessages[testName] = currentLog;
}
TestLogger.instance.currentLog = new TestLog();
return currentLog;
}
}

View File

@ -48,7 +48,7 @@ class WebDriverReporter implements jasmine.CustomReporter {
public specDone(result: jasmine.CustomReporterResult): void {
this.concurrentSpecCount -= 1;
const messages = TestLogger.getMessagesAndReset();
const testLog = TestLogger.saveLogsAndReset(result.fullName);
if (result.status === "disabled") {
return;
} else if (result.status === "failed") {
@ -74,9 +74,9 @@ class WebDriverReporter implements jasmine.CustomReporter {
}
// Report log messages
if (messages.length > 0) {
if (testLog.messages.length > 0) {
this.taplog(" - logs: ");
for (const [level, message] of messages) {
for (const [level, message] of testLog.messages) {
this.taplog(` - level: ${LogLevel[level]}`);
this.taplog(` message: ${message}`);
}

View File

@ -7,6 +7,8 @@
<handlers>
<add name="aspNetCore" path="*" verb="*" modules="AspNetCoreModule" resourceType="Unspecified" />
</handlers>
<aspNetCore processPath="%LAUNCHER_PATH%" arguments="%LAUNCHER_ARGS%" stdoutLogEnabled="false" stdoutLogFile=".\logs\stdout" forwardWindowsAuthToken="false" startupTimeLimit="3600" requestTimeout="23:00:00" />
<aspNetCore processPath="%LAUNCHER_PATH%" arguments="%LAUNCHER_ARGS%" stdoutLogEnabled="false" stdoutLogFile=".\logs\stdout" forwardWindowsAuthToken="false" startupTimeLimit="3600" requestTimeout="23:00:00">
<environmentVariables />
</aspNetCore>
</system.webServer>
</configuration>

View File

@ -14,6 +14,7 @@ export interface IHttpConnectionOptions {
transport?: TransportType | ITransport;
logger?: ILogger | LogLevel;
accessTokenFactory?: () => string;
logMessageContent?: boolean;
}
const enum ConnectionState {
@ -53,6 +54,7 @@ export class HttpConnection implements IConnection {
options = options || {};
options.accessTokenFactory = options.accessTokenFactory || (() => null);
options.logMessageContent = options.logMessageContent || false;
this.httpClient = options.httpClient || new DefaultHttpClient(this.logger);
this.connectionState = ConnectionState.Disconnected;
@ -176,11 +178,11 @@ export class HttpConnection implements IConnection {
private constructTransport(transport: TransportType) {
switch (transport) {
case TransportType.WebSockets:
return new WebSocketTransport(this.options.accessTokenFactory, this.logger);
return new WebSocketTransport(this.options.accessTokenFactory, this.logger, this.options.logMessageContent);
case TransportType.ServerSentEvents:
return new ServerSentEventsTransport(this.httpClient, this.options.accessTokenFactory, this.logger);
return new ServerSentEventsTransport(this.httpClient, this.options.accessTokenFactory, this.logger, this.options.logMessageContent);
case TransportType.LongPolling:
return new LongPollingTransport(this.httpClient, this.options.accessTokenFactory, this.logger);
return new LongPollingTransport(this.httpClient, this.options.accessTokenFactory, this.logger, this.options.logMessageContent);
default:
throw new Error(`Unknown transport: ${transport}.`);
}

View File

@ -31,11 +31,13 @@ export interface ITransport {
export class WebSocketTransport implements ITransport {
private readonly logger: ILogger;
private readonly accessTokenFactory: () => string;
private readonly logMessageContent: boolean;
private webSocket: WebSocket;
constructor(accessTokenFactory: () => string, logger: ILogger) {
constructor(accessTokenFactory: () => string, logger: ILogger, logMessageContent: boolean) {
this.logger = logger;
this.accessTokenFactory = accessTokenFactory || (() => null);
this.logMessageContent = logMessageContent;
}
public connect(url: string, transferFormat: TransferFormat, connection: IConnection): Promise<void> {
@ -73,7 +75,7 @@ export class WebSocketTransport implements ITransport {
};
webSocket.onmessage = (message: MessageEvent) => {
this.logger.log(LogLevel.Trace, `(WebSockets transport) data received. ${getDataDetail(message.data)}.`);
this.logger.log(LogLevel.Trace, `(WebSockets transport) data received. ${getDataDetail(message.data, this.logMessageContent)}.`);
if (this.onreceive) {
this.onreceive(message.data);
}
@ -94,7 +96,7 @@ export class WebSocketTransport implements ITransport {
public send(data: any): Promise<void> {
if (this.webSocket && this.webSocket.readyState === WebSocket.OPEN) {
this.logger.log(LogLevel.Trace, `(WebSockets transport) sending data. ${getDataDetail(data)}.`);
this.logger.log(LogLevel.Trace, `(WebSockets transport) sending data. ${getDataDetail(data, this.logMessageContent)}.`);
this.webSocket.send(data);
return Promise.resolve();
}
@ -118,13 +120,15 @@ export class ServerSentEventsTransport implements ITransport {
private readonly httpClient: HttpClient;
private readonly accessTokenFactory: () => string;
private readonly logger: ILogger;
private readonly logMessageContent: boolean;
private eventSource: EventSource;
private url: string;
constructor(httpClient: HttpClient, accessTokenFactory: () => string, logger: ILogger) {
constructor(httpClient: HttpClient, accessTokenFactory: () => string, logger: ILogger, logMessageContent: boolean) {
this.httpClient = httpClient;
this.accessTokenFactory = accessTokenFactory || (() => null);
this.logger = logger;
this.logMessageContent = logMessageContent;
}
public connect(url: string, transferFormat: TransferFormat, connection: IConnection): Promise<void> {
@ -156,7 +160,7 @@ export class ServerSentEventsTransport implements ITransport {
eventSource.onmessage = (e: MessageEvent) => {
if (this.onreceive) {
try {
this.logger.log(LogLevel.Trace, `(SSE transport) data received. ${getDataDetail(e.data)}.`);
this.logger.log(LogLevel.Trace, `(SSE transport) data received. ${getDataDetail(e.data, this.logMessageContent)}.`);
this.onreceive(e.data);
} catch (error) {
if (this.onclose) {
@ -189,7 +193,7 @@ export class ServerSentEventsTransport implements ITransport {
}
public async send(data: any): Promise<void> {
return send(this.logger, "SSE", this.httpClient, this.url, this.accessTokenFactory, data);
return send(this.logger, "SSE", this.httpClient, this.url, this.accessTokenFactory, data, this.logMessageContent);
}
public stop(): Promise<void> {
@ -208,16 +212,18 @@ export class LongPollingTransport implements ITransport {
private readonly httpClient: HttpClient;
private readonly accessTokenFactory: () => string;
private readonly logger: ILogger;
private readonly logMessageContent: boolean;
private url: string;
private pollXhr: XMLHttpRequest;
private pollAbort: AbortController;
constructor(httpClient: HttpClient, accessTokenFactory: () => string, logger: ILogger) {
constructor(httpClient: HttpClient, accessTokenFactory: () => string, logger: ILogger, logMessageContent: boolean) {
this.httpClient = httpClient;
this.accessTokenFactory = accessTokenFactory || (() => null);
this.logger = logger;
this.pollAbort = new AbortController();
this.logMessageContent = logMessageContent;
}
public connect(url: string, transferFormat: TransferFormat, connection: IConnection): Promise<void> {
@ -283,7 +289,7 @@ export class LongPollingTransport implements ITransport {
} else {
// Process the response
if (response.content) {
this.logger.log(LogLevel.Trace, `(LongPolling transport) data received. ${getDataDetail(response.content)}.`);
this.logger.log(LogLevel.Trace, `(LongPolling transport) data received. ${getDataDetail(response.content, this.logMessageContent)}`);
if (this.onreceive) {
this.onreceive(response.content);
}
@ -308,7 +314,7 @@ export class LongPollingTransport implements ITransport {
}
public async send(data: any): Promise<void> {
return send(this.logger, "LongPolling", this.httpClient, this.url, this.accessTokenFactory, data);
return send(this.logger, "LongPolling", this.httpClient, this.url, this.accessTokenFactory, data, this.logMessageContent);
}
public stop(): Promise<void> {
@ -320,17 +326,37 @@ export class LongPollingTransport implements ITransport {
public onclose: TransportClosed;
}
function getDataDetail(data: any): string {
function getDataDetail(data: any, includeContent: boolean): string {
let length: string = null;
if (data instanceof ArrayBuffer) {
length = `Binary data of length ${data.byteLength}`;
length = `Binary data of length ${data.byteLength}.`;
if (includeContent) {
length += ` Content: '${formatArrayBuffer(data)}'.`;
}
} else if (typeof data === "string") {
length = `String data of length ${data.length}`;
length = `String data of length ${data.length}.`;
if (includeContent) {
length += ` Content: '${data}'.`;
}
}
return length;
}
async function send(logger: ILogger, transportName: string, httpClient: HttpClient, url: string, accessTokenFactory: () => string, content: string | ArrayBuffer): Promise<void> {
function formatArrayBuffer(data: ArrayBuffer): string {
const view = new Uint8Array(data);
// Uint8Array.map only supports returning another Uint8Array?
let str = "";
view.forEach((num) => {
const pad = num < 16 ? "0" : "";
str += `0x${pad}${num.toString(16)} `;
});
// Trim of trailing space.
return str.substr(0, str.length - 1);
}
async function send(logger: ILogger, transportName: string, httpClient: HttpClient, url: string, accessTokenFactory: () => string, content: string | ArrayBuffer, logMessageContent: boolean): Promise<void> {
let headers;
const token = accessTokenFactory();
if (token) {
@ -339,7 +365,7 @@ async function send(logger: ILogger, transportName: string, httpClient: HttpClie
};
}
logger.log(LogLevel.Trace, `(${transportName} transport) sending data. ${getDataDetail(content)}.`);
logger.log(LogLevel.Trace, `(${transportName} transport) sending data. ${getDataDetail(content, logMessageContent)}.`);
const response = await httpClient.post(url, {
content,