fix: extended telemetry data for the signal websocket (#1881)

Adds more telemetry data collection for the signal web socket.

Author: oliverlaz

packages/client/src/StreamSfuClient.ts

@@ -274,6 +274,7 @@ export class StreamSfuClient {
     this.signalWs = createWebSocketSignalChannel({
       tag: this.tag,
       endpoint: `${this.credentials.server.ws_endpoint}?${new URLSearchParams(params).toString()}`,
+      tracer: this.tracer,
       onMessage: (message) => {
         this.lastMessageTimestamp = new Date();
         this.scheduleConnectionCheck();
@@ -285,10 +286,14 @@ export class StreamSfuClient {
       },
     });
 
+    let timeoutId: NodeJS.Timeout;
     this.signalReady = makeSafePromise(
       Promise.race<WebSocket>([
         new Promise((resolve, reject) => {
+          let didOpen = false;
           const onOpen = () => {
+            didOpen = true;
+            clearTimeout(timeoutId);
             this.signalWs.removeEventListener('open', onOpen);
             resolve(this.signalWs);
           };
@@ -298,28 +303,28 @@ export class StreamSfuClient {
           this.signalWs.addEventListener('close', (e) => {
             this.handleWebSocketClose(e);
             // Normally, this shouldn't have any effect, because WS should never emit 'close'
-            // before emitting 'open'. However, strager things have happened, and we don't
-            // want to leave signalReady in pending state.
-            reject(
-              new Error(`SFU WS closed or connection can't be established`),
-            );
+            // before emitting 'open'. However, stranger things have happened, and we don't
+            // want to leave signalReady in a pending state.
+            const message = didOpen
+              ? `SFU WS closed: ${e.code} ${e.reason}`
+              : `SFU WS connection can't be established: ${e.code} ${e.reason}`;
+            this.tracer?.trace('signal.close', message);
+            clearTimeout(timeoutId);
+            reject(new Error(message));
           });
         }),
 
         new Promise((resolve, reject) => {
-          setTimeout(
-            () => reject(new Error('SFU WS connection timed out')),
-            this.joinResponseTimeout,
-          );
+          timeoutId = setTimeout(() => {
+            const message = `SFU WS connection failed to open after ${this.joinResponseTimeout}ms`;
+            this.tracer?.trace('signal.timeout', message);
+            reject(new Error(message));
+          }, this.joinResponseTimeout);
         }),
       ]),
     );
   };
 
-  private cleanUpWebSocket = () => {
-    this.signalWs.removeEventListener('close', this.handleWebSocketClose);
-  };
-
   get isHealthy() {
     return (
       this.signalWs.readyState === WebSocket.OPEN &&
@@ -343,7 +348,7 @@ export class StreamSfuClient {
     if (this.signalWs.readyState === WebSocket.OPEN) {
       this.logger('debug', `Closing SFU WS connection: ${code} - ${reason}`);
       this.signalWs.close(code, `js-client: ${reason}`);
-      this.cleanUpWebSocket();
+      this.signalWs.removeEventListener('close', this.handleWebSocketClose);
     }
     this.dispose();
   };

packages/client/src/rtc/signal.ts

@@ -1,28 +1,33 @@
 import { SfuEvent } from '../gen/video/sfu/event/events';
 import { getLogger } from '../logger';
 import { DispatchableMessage, SfuEventKinds } from './Dispatcher';
+import { Tracer } from '../stats';
 
 export const createWebSocketSignalChannel = (opts: {
   endpoint: string;
   onMessage: <K extends SfuEventKinds>(message: DispatchableMessage<K>) => void;
   tag: string;
+  tracer: Tracer | undefined;
 }) => {
-  const { endpoint, onMessage, tag } = opts;
+  const { endpoint, onMessage, tag, tracer } = opts;
   const logger = getLogger(['SfuClientWS', tag]);
   logger('debug', 'Creating signaling WS channel:', endpoint);
   const ws = new WebSocket(endpoint);
   ws.binaryType = 'arraybuffer'; // do we need this?
 
   ws.addEventListener('error', (e) => {
     logger('error', 'Signaling WS channel error', e);
+    tracer?.trace('signal.ws.error', e);
   });
 
   ws.addEventListener('close', (e) => {
     logger('info', 'Signaling WS channel is closed', e);
+    tracer?.trace('signal.ws.close', e);
   });
 
   ws.addEventListener('open', (e) => {
     logger('info', 'Signaling WS channel is open', e);
+    tracer?.trace('signal.ws.open', e);
   });
 
   ws.addEventListener('message', (e) => {
@@ -34,11 +39,10 @@ export const createWebSocketSignalChannel = (opts: {
 
       onMessage(message as DispatchableMessage<SfuEventKinds>);
     } catch (err) {
-      logger(
-        'error',
-        'Failed to decode a message. Check whether the Proto models match.',
-        { event: e, error: err },
-      );
+      const message =
+        'Failed to decode a message. Check whether the Proto models match.';
+      logger('error', message, { event: e, error: err });
+      tracer?.trace('signal.ws.message.error', message);
     }
   });
   return ws;