Merge pull request #1776 from aspnet/release/2.1

Client logging fixes and improvements (#1773)

clients/ts/FunctionalTests/ts/TestLogger.ts

@@ -1,12 +1,17 @@
-import { ILogger, LogLevel } from "@aspnet/signalr";
+import { ConsoleLogger, ILogger, LogLevel } from "@aspnet/signalr";
 
 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 log(logLevel: LogLevel, message: string): void {
+        // Capture log message so it can be reported later
         this.messages.push([logLevel, message]);
+
+        // Also write to browser console
+        TestLogger.consoleLogger.log(logLevel, message);
     }
 
     public static getMessagesAndReset(): Array<[LogLevel, string]> {

clients/ts/signalr/src/HttpClient.ts

@@ -3,6 +3,7 @@
 
 import { AbortSignal } from "./AbortController";
 import { HttpError, TimeoutError } from "./Errors";
+import { ILogger, LogLevel } from "./ILogger";
 
 export interface HttpRequest {
     method?: string;
@@ -49,6 +50,13 @@ export abstract class HttpClient {
 }
 
 export class DefaultHttpClient extends HttpClient {
+    private readonly logger: ILogger;
+
+    constructor(logger: ILogger) {
+        super();
+        this.logger = logger;
+    }
+
     public send(request: HttpRequest): Promise<HttpResponse> {
         return new Promise<HttpResponse>((resolve, reject) => {
             const xhr = new XMLHttpRequest();
@@ -89,10 +97,12 @@ export class DefaultHttpClient extends HttpClient {
             };
 
             xhr.onerror = () => {
+                this.logger.log(LogLevel.Warning, `Error from HTTP request. ${xhr.status}: ${xhr.statusText}`);
                 reject(new HttpError(xhr.statusText, xhr.status));
             };
 
             xhr.ontimeout = () => {
+                this.logger.log(LogLevel.Warning, `Timeout from HTTP request.`);
                 reject(new TimeoutError());
             };
 

clients/ts/signalr/src/HttpConnection.ts

@@ -54,7 +54,7 @@ export class HttpConnection implements IConnection {
         options = options || {};
         options.accessTokenFactory = options.accessTokenFactory || (() => null);
 
-        this.httpClient = options.httpClient || new DefaultHttpClient();
+        this.httpClient = options.httpClient || new DefaultHttpClient(this.logger);
         this.connectionState = ConnectionState.Disconnected;
         this.options = options;
     }
@@ -63,6 +63,8 @@ export class HttpConnection implements IConnection {
         Arg.isRequired(transferFormat, "transferFormat");
         Arg.isIn(transferFormat, TransferFormat, "transferFormat");
 
+        this.logger.log(LogLevel.Trace, `Starting connection with transfer format '${TransferFormat[transferFormat]}'.`);
+
         if (this.connectionState !== ConnectionState.Disconnected) {
             return Promise.reject(new Error("Cannot start a connection that is not in the 'Disconnected' state."));
         }
@@ -114,11 +116,18 @@ export class HttpConnection implements IConnection {
     }
 
     private async getNegotiationResponse(headers: any): Promise<INegotiateResponse> {
-        const response =  await this.httpClient.post(this.resolveNegotiateUrl(this.baseUrl), {
+        const negotiateUrl = this.resolveNegotiateUrl(this.baseUrl);
-            content: "",
+        this.logger.log(LogLevel.Trace, `Sending negotiation request: ${negotiateUrl}`);
-            headers,
+        try {
-        });
+            const response =  await this.httpClient.post(negotiateUrl, {
-        return JSON.parse(response.content as string);
+                content: "",
+                headers,
+            });
+            return JSON.parse(response.content as string);
+        } catch (e) {
+            this.logger.log(LogLevel.Error, "Failed to complete negotiation with the server: " + e);
+            throw e;
+        }
     }
 
     private updateConnectionId(negotiateResponse: INegotiateResponse) {
@@ -154,7 +163,7 @@ export class HttpConnection implements IConnection {
                     this.changeState(ConnectionState.Connecting, ConnectionState.Connected);
                     return;
                 } catch (ex) {
-                    this.logger.log(LogLevel.Error, `Failed to start the transport' ${TransportType[transport]}:' transport'${ex}'`);
+                    this.logger.log(LogLevel.Error, `Failed to start the transport '${TransportType[transport]}': ${ex}`);
                     this.connectionState = ConnectionState.Disconnected;
                     negotiateResponse.connectionId = null;
                 }

clients/ts/signalr/src/HubConnection.ts

@@ -204,10 +204,13 @@ export class HubConnection {
     }
 
     public async start(): Promise<void> {
+        this.logger.log(LogLevel.Trace, "Starting HubConnection.");
+
         this.receivedHandshakeResponse = false;
 
         await this.connection.start(this.protocol.transferFormat);
 
+        this.logger.log(LogLevel.Trace, "Sending handshake request.");
         // Handshake request is always JSON
         await this.connection.send(
             TextMessageFormat.write(
@@ -221,6 +224,8 @@ export class HubConnection {
     }
 
     public stop(): Promise<void> {
+        this.logger.log(LogLevel.Trace, "Stopping HubConnection.");
+
         this.cleanupTimeout();
         return this.connection.stop();
     }

clients/ts/signalr/src/Transports.ts

@@ -48,6 +48,8 @@ export class WebSocketTransport implements ITransport {
             throw new Error("'WebSocket' is not supported in your environment.");
         }
 
+        this.logger.log(LogLevel.Trace, "(WebSockets transport) Connecting");
+
         return new Promise<void>((resolve, reject) => {
             url = url.replace(/^http/, "ws");
             const token = this.accessTokenFactory();
@@ -71,7 +73,7 @@ export class WebSocketTransport implements ITransport {
             };
 
             webSocket.onmessage = (message: MessageEvent) => {
-                this.logger.log(LogLevel.Trace, `(WebSockets transport) data received. Length ${getDataLength(message.data)}.`);
+                this.logger.log(LogLevel.Trace, `(WebSockets transport) data received. ${getDataDetail(message.data)}.`);
                 if (this.onreceive) {
                     this.onreceive(message.data);
                 }
@@ -92,6 +94,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.webSocket.send(data);
             return Promise.resolve();
         }
@@ -134,6 +137,8 @@ export class ServerSentEventsTransport implements ITransport {
             throw new Error("'EventSource' is not supported in your environment.");
         }
 
+        this.logger.log(LogLevel.Trace, "(SSE transport) Connecting");
+
         this.url = url;
         return new Promise<void>((resolve, reject) => {
             if (transferFormat !== TransferFormat.Text) {
@@ -151,7 +156,7 @@ export class ServerSentEventsTransport implements ITransport {
                 eventSource.onmessage = (e: MessageEvent) => {
                     if (this.onreceive) {
                         try {
-                            this.logger.log(LogLevel.Trace, `(SSE transport) data received. Length ${getDataLength(e.data)}.`);
+                            this.logger.log(LogLevel.Trace, `(SSE transport) data received. ${getDataDetail(e.data)}.`);
                             this.onreceive(e.data);
                         } catch (error) {
                             if (this.onclose) {
@@ -184,7 +189,7 @@ export class ServerSentEventsTransport implements ITransport {
     }
 
     public async send(data: any): Promise<void> {
-        return send(this.httpClient, this.url, this.accessTokenFactory, data);
+        return send(this.logger, "SSE", this.httpClient, this.url, this.accessTokenFactory, data);
     }
 
     public stop(): Promise<void> {
@@ -223,6 +228,8 @@ export class LongPollingTransport implements ITransport {
 
         this.url = url;
 
+        this.logger.log(LogLevel.Trace, "(LongPolling transport) Connecting");
+
         // Set a flag indicating we have inherent keep-alive in this transport.
         connection.features.inherentKeepAlive = true;
 
@@ -276,7 +283,7 @@ export class LongPollingTransport implements ITransport {
                 } else {
                     // Process the response
                     if (response.content) {
-                        this.logger.log(LogLevel.Trace, `(LongPolling transport) data received. Length ${getDataLength(response.content)}.`);
+                        this.logger.log(LogLevel.Trace, `(LongPolling transport) data received. ${getDataDetail(response.content)}.`);
                         if (this.onreceive) {
                             this.onreceive(response.content);
                         }
@@ -301,7 +308,7 @@ export class LongPollingTransport implements ITransport {
     }
 
     public async send(data: any): Promise<void> {
-        return send(this.httpClient, this.url, this.accessTokenFactory, data);
+        return send(this.logger, "LongPolling", this.httpClient, this.url, this.accessTokenFactory, data);
     }
 
     public stop(): Promise<void> {
@@ -313,17 +320,17 @@ export class LongPollingTransport implements ITransport {
     public onclose: TransportClosed;
 }
 
-function getDataLength(data: any): number {
+function getDataDetail(data: any): string {
-    let length: number = null;
+    let length: string = null;
     if (data instanceof ArrayBuffer) {
-        length = data.byteLength;
+        length = `Binary data of length ${data.byteLength}`;
-    } else if (data instanceof String) {
+    } else if (typeof data === "string") {
-        length = data.length;
+        length = `String data of length ${data.length}`;
     }
     return length;
 }
 
-async function send(httpClient: HttpClient, url: string, accessTokenFactory: () => string, content: string | ArrayBuffer): Promise<void> {
+async function send(logger: ILogger, transportName: string, httpClient: HttpClient, url: string, accessTokenFactory: () => string, content: string | ArrayBuffer): Promise<void> {
     let headers;
     const token = accessTokenFactory();
     if (token) {
@@ -332,8 +339,12 @@ async function send(httpClient: HttpClient, url: string, accessTokenFactory: ()
         };
     }
 
-    await httpClient.post(url, {
+    logger.log(LogLevel.Trace, `(${transportName} transport) sending data. ${getDataDetail(content)}.`);
+
+    const response = await httpClient.post(url, {
         content,
         headers,
     });
+
+    logger.log(LogLevel.Trace, `(${transportName} transport) request complete. Response status: ${response.statusCode}.`);
 }