diff --git a/README.md b/README.md index 31e3741..ab2ba4b 100644 --- a/README.md +++ b/README.md @@ -103,6 +103,7 @@ bandwidthRtc.sendDtmf("5", undefined, 200, 100); // 200ms tone, 100ms gap - RTCP data from the remote receiver: `remoteFractionLost`, `remoteJitter`, `rtcpRoundTripTime`. These are 0 until the first receiver report arrives. - With several audio streams, packet and byte counts are summed; jitter, loss, round trip time and audio level show the highest stream - Debug log: while connected, a snapshot is logged every 5 minutes, and a final one when the call ends (disconnect, fatal error, or the signaling socket closing for good). While in a call (a subscribe stream is available), a snapshot is also logged every 10 seconds under "In-call stats", with a final one when the call ends. The two traces run independently and may log at the same time +- Diagnostics logs: buffered logs are sent to the gateway every 5 minutes, and also when the page is hidden or unloaded (best effort, since the browser may close the connection first) ## Event Listeners diff --git a/src/v1/diagnostics.test.ts b/src/v1/diagnostics.test.ts index 0d749a3..b73356c 100644 --- a/src/v1/diagnostics.test.ts +++ b/src/v1/diagnostics.test.ts @@ -76,6 +76,17 @@ describe("DiagnosticsBatcher", () => { expect(result).toEqual({ logs: [] }); }); + test("should report whether logs are buffered", () => { + const diagnostics = new DiagnosticsBatcher(); + expect(diagnostics.hasLogs()).toBe(false); + + (diagnostics as any).handleLogEvent("info", Date.now(), "test"); + expect(diagnostics.hasLogs()).toBe(true); + + diagnostics.flushDiagnostics(); + expect(diagnostics.hasLogs()).toBe(false); + }); + test("should flush diagnostics and clear interval on shutdown", () => { const clearIntervalSpy = jest.spyOn(global, "clearInterval"); const diagnostics = new DiagnosticsBatcher(); diff --git a/src/v1/diagnostics.ts b/src/v1/diagnostics.ts index 5bcf128..a3cc72e 100644 --- a/src/v1/diagnostics.ts +++ b/src/v1/diagnostics.ts @@ -24,6 +24,10 @@ export class DiagnosticsBatcher extends EventEmitter { return { logs: this.logEvents }; } + hasLogs(): boolean { + return this.logEvents.length > 0; + } + flushDiagnostics() { this.emit("diagnostics", this.getDiagnostics()); this.logEvents = new Array(); diff --git a/src/v1/signaling.test.ts b/src/v1/signaling.test.ts index 95cee3a..640302f 100644 --- a/src/v1/signaling.test.ts +++ b/src/v1/signaling.test.ts @@ -397,6 +397,124 @@ describe("Signaling disconnect", () => { }); }); +describe("Signaling page-exit diagnostics flush", () => { + let batcher: DiagnosticsBatcher; + let signaling: Signaling; + let ws: any; + let visibility: string; + + function setVisibility(state: string) { + visibility = state; + document.dispatchEvent(new Event("visibilitychange")); + } + + // Pushes a log line into the batcher so a flush has something to send. + function bufferLog(message: string) { + (batcher as any).handleLogEvent("info", Date.now(), message); + } + + function deviceDiagnosticsCalls() { + return ws.notify.mock.calls.filter((call: any) => call[0] === "deviceDiagnostics"); + } + + beforeEach(async () => { + visibility = "visible"; + Object.defineProperty(document, "visibilityState", { configurable: true, get: () => visibility }); + batcher = new DiagnosticsBatcher(); + signaling = new Signaling(batcher); + await signaling.connect({ endpointToken: "test-token" }); + ws = (signaling as any).ws; + await ws.on.mock.calls.find((call: any) => call[0] === "open")[1](); + }); + + afterEach(() => { + signaling.disconnect(); + batcher.shutdown(); + delete (document as any).visibilityState; + }); + + test("should flush buffered logs on pagehide", () => { + bufferLog("before-pagehide"); + + window.dispatchEvent(new Event("pagehide")); + + const calls = deviceDiagnosticsCalls(); + expect(calls).toHaveLength(1); + expect(calls[0][1].logs.map((log: any) => log.message)).toContainEqual(["before-pagehide"]); + }); + + test("should flush buffered logs when the page becomes hidden", () => { + bufferLog("before-hidden"); + + setVisibility("hidden"); + + const calls = deviceDiagnosticsCalls(); + expect(calls).toHaveLength(1); + expect(calls[0][1].logs.map((log: any) => log.message)).toContainEqual(["before-hidden"]); + }); + + test("should not flush when the page becomes visible", () => { + bufferLog("before-visible"); + + setVisibility("visible"); + + expect(deviceDiagnosticsCalls()).toHaveLength(0); + }); + + test("should not register duplicate listeners on repeated opens", async () => { + const openCallback = ws.on.mock.calls.find((call: any) => call[0] === "open")[1]; + await openCallback(); + await openCallback(); + + window.dispatchEvent(new Event("pagehide")); + + expect(deviceDiagnosticsCalls()).toHaveLength(1); + }); + + test("should stop flushing after disconnect", () => { + signaling.disconnect(); + // The handler checks hasLogs() first, so a spy on it proves the listener is gone + const hasLogsSpy = jest.spyOn(batcher, "hasLogs"); + const flushSpy = jest.spyOn(batcher, "flushDiagnostics"); + bufferLog("after-disconnect"); + ws.notify.mockClear(); + + window.dispatchEvent(new Event("pagehide")); + setVisibility("hidden"); + + expect(hasLogsSpy).not.toHaveBeenCalled(); + expect(flushSpy).not.toHaveBeenCalled(); + expect(ws.notify).not.toHaveBeenCalled(); + }); + + test("should not send diagnostics when the buffer is empty", () => { + // The batcher captures every SDK log line, so drain it first + batcher.flushDiagnostics(); + ws.notify.mockClear(); + + window.dispatchEvent(new Event("pagehide")); + setVisibility("hidden"); + + expect(deviceDiagnosticsCalls()).toHaveLength(0); + }); + + test("should keep buffered logs when the socket is not open", () => { + bufferLog("while-closed"); + ws.ready = false; + + window.dispatchEvent(new Event("pagehide")); + + expect(deviceDiagnosticsCalls()).toHaveLength(0); + + ws.ready = true; + window.dispatchEvent(new Event("pagehide")); + + const calls = deviceDiagnosticsCalls(); + expect(calls).toHaveLength(1); + expect(calls[0][1].logs.map((log: any) => log.message)).toContainEqual(["while-closed"]); + }); +}); + describe("Signaling test all the smaller functions", () => { let signaling: Signaling; beforeEach(async () => { diff --git a/src/v1/signaling.ts b/src/v1/signaling.ts index 689dce0..0f3ca64 100644 --- a/src/v1/signaling.ts +++ b/src/v1/signaling.ts @@ -48,6 +48,7 @@ class Signaling extends EventEmitter { private readyMetadata: ReadyMetadata | null = null; private diagnosticsBatcher?: DiagnosticsBatcher; private rtcOptions?: RtcOptions; + private pageExitFlush?: (event: Event) => void; constructor(diagnosticsBatcher?: DiagnosticsBatcher) { super(); @@ -118,6 +119,7 @@ class Signaling extends EventEmitter { logger.debug("Websocket open"); const isReconnect = hasConnectedOnce; hasConnectedOnce = true; + this.addPageExitFlush(); if (!isReconnect && globalThis.addEventListener) { globalThis.addEventListener("beforeunload", (event) => { this.disconnect(); @@ -208,8 +210,48 @@ class Signaling extends EventEmitter { }) as Promise; } + // Best effort: the browser may close the socket before the bytes leave the page. + private addPageExitFlush() { + if (this.pageExitFlush || !this.diagnosticsBatcher) { + return; + } + this.pageExitFlush = (event: Event) => { + if (event.type === "visibilitychange" && document.visibilityState !== "hidden") { + return; + } + if (!this.diagnosticsBatcher?.hasLogs()) { + return; + } + // A flush clears the buffer, so keep the logs for a later flush while the socket is down + if (!this.socketOpen) { + return; + } + this.diagnosticsBatcher?.flushDiagnostics(); + }; + if (typeof window !== "undefined" && typeof window.addEventListener === "function") { + window.addEventListener("pagehide", this.pageExitFlush); + } + if (typeof document !== "undefined" && typeof document.addEventListener === "function") { + document.addEventListener("visibilitychange", this.pageExitFlush); + } + } + + private removePageExitFlush() { + if (!this.pageExitFlush) { + return; + } + if (typeof window !== "undefined" && typeof window.removeEventListener === "function") { + window.removeEventListener("pagehide", this.pageExitFlush); + } + if (typeof document !== "undefined" && typeof document.removeEventListener === "function") { + document.removeEventListener("visibilitychange", this.pageExitFlush); + } + this.pageExitFlush = undefined; + } + private _disconnect(notifyLeave: boolean) { logger.debug("Disconnecting websocket"); + this.removePageExitFlush(); const hadSocket = this.ws !== null; if (this.ws) { if (notifyLeave && this.socketOpen) {