From ea8f0079a88555a08cf9d1fbe89511dbcb1faf49 Mon Sep 17 00:00:00 2001 From: tiahan Date: Tue, 26 May 2026 14:44:12 +0800 Subject: [PATCH 01/29] feat(meetings,llm): add webinar LLM connect and locus sync latency diagnostics --- .../@webex/internal-plugin-llm/src/index.ts | 2 + .../@webex/internal-plugin-llm/src/llm.ts | 31 +++- .../internal-plugin-llm/src/llm.types.ts | 13 +- .../internal-plugin-llm/test/unit/spec/llm.js | 52 +++++++ .../plugin-meetings/src/breakouts/events.ts | 35 ++++- .../plugin-meetings/src/breakouts/index.ts | 2 + .../src/hashTree/hashTreeParser.ts | 132 +++++++++++++++++ .../plugin-meetings/src/locus-info/index.ts | 6 + .../plugin-meetings/src/meeting/index.ts | 140 +++++++++++++++++- .../test/unit/spec/breakouts/events.ts | 35 ++++- .../test/unit/spec/hashTree/hashTreeParser.ts | 78 ++++++++++ 11 files changed, 508 insertions(+), 18 deletions(-) diff --git a/packages/@webex/internal-plugin-llm/src/index.ts b/packages/@webex/internal-plugin-llm/src/index.ts index f92ad446e30..ee92de33d1d 100644 --- a/packages/@webex/internal-plugin-llm/src/index.ts +++ b/packages/@webex/internal-plugin-llm/src/index.ts @@ -2,6 +2,8 @@ import * as WebexCore from '@webex/webex-core'; import LLMChannel, {config} from './llm'; import {DataChannelTokenType} from './llm.types'; +export type {RegisterAndConnectTiming} from './llm.types'; + WebexCore.registerInternalPlugin('llm', LLMChannel, { config, }); diff --git a/packages/@webex/internal-plugin-llm/src/llm.ts b/packages/@webex/internal-plugin-llm/src/llm.ts index 775a37cdd7b..0dfc794330e 100644 --- a/packages/@webex/internal-plugin-llm/src/llm.ts +++ b/packages/@webex/internal-plugin-llm/src/llm.ts @@ -10,7 +10,7 @@ import { SUBSCRIPTION_AWARE_SUBCHANNELS_PARAM, LLM_DEFAULT_SESSION, } from './constants'; -import {ILLMChannel, DataChannelTokenType} from './llm.types'; +import {ILLMChannel, DataChannelTokenType, RegisterAndConnectTiming} from './llm.types'; export const config = { llm: { @@ -125,7 +125,9 @@ export default class LLMChannel extends (Mercury as any) implements ILLMChannel datachannelUrl: string, datachannelToken?: string, sessionId: string = LLM_DEFAULT_SESSION - ): Promise => { + ): Promise => { + const registerStart = performance.now(); + // Pre-populate locusUrl and datachannelUrl before register() fires the // HTTP POST, so that any token refresh triggered during registration can // be routed via connections without falling back to a locusInfo URL scan. @@ -139,18 +141,30 @@ export default class LLMChannel extends (Mercury as any) implements ILLMChannel return this.register(datachannelUrl, datachannelToken, sessionId).then(async () => { if (!locusUrl || !datachannelUrl) return undefined; + const clientLLMDatachannelResponseTime = Math.round(performance.now() - registerStart); + // locusUrl and datachannelUrl were pre-populated before register(); here // we only need to read the existing session data to get webSocketUrl/binding // that register() filled in. const sessionData = this.connections.get(sessionId) || {}; + if (!sessionData.webSocketUrl) { + return undefined; + } + const isDataChannelTokenEnabled = await this.isDataChannelTokenEnabled(); const connectUrl = isDataChannelTokenEnabled ? LLMChannel.buildUrlWithAwareSubchannels(sessionData.webSocketUrl, AWARE_DATA_CHANNEL) : sessionData.webSocketUrl; - return this.connect(connectUrl, sessionId); + const connectStart = performance.now(); + + await this.connect(connectUrl, sessionId); + + const clientLLMWebSocketConnectTime = Math.round(performance.now() - connectStart); + + return {clientLLMDatachannelResponseTime, clientLLMWebSocketConnectTime}; }); }; @@ -198,6 +212,17 @@ export default class LLMChannel extends (Mercury as any) implements ILLMChannel return sessionData?.datachannelUrl; }; + /** + * Get WebSocket URL for the connection + * @param {string} sessionId - Connection identifier + * @returns {string | undefined} WebSocket URL + */ + public getWebSocketUrl = (sessionId = LLM_DEFAULT_SESSION): string | undefined => { + const sessionData = this.connections.get(sessionId); + + return sessionData?.webSocketUrl; + }; + /** * Set the owner meeting ID for a given LLM session. Used by the meetings * plugin to tag which Meeting instance currently owns the (default) LLM diff --git a/packages/@webex/internal-plugin-llm/src/llm.types.ts b/packages/@webex/internal-plugin-llm/src/llm.types.ts index 3d9aec3234e..280a056cd74 100644 --- a/packages/@webex/internal-plugin-llm/src/llm.types.ts +++ b/packages/@webex/internal-plugin-llm/src/llm.types.ts @@ -5,17 +5,26 @@ export enum DataChannelTokenType { type DataChannelTokenKey = DataChannelTokenType | string; +/** + * Latencies (in milliseconds) captured during register + websocket connect. + */ +type RegisterAndConnectTiming = { + clientLLMDatachannelResponseTime?: number; + clientLLMWebSocketConnectTime?: number; +}; + interface ILLMChannel { registerAndConnect: ( locusUrl: string, datachannelUrl: string, datachannelToken?: string, sessionId?: string - ) => Promise; + ) => Promise; isConnected: (sessionId?: string) => boolean; getBinding: (sessionId?: string) => string; getLocusUrl: (sessionId?: string) => string; getDatachannelUrl: (sessionId?: string) => string; + getWebSocketUrl: (sessionId?: string) => string | undefined; disconnectLLM: ( options: {code: number; reason: string}, sessionId?: string, @@ -66,4 +75,4 @@ interface ILLMChannel { } // eslint-disable-next-line import/prefer-default-export -export type {ILLMChannel, DataChannelTokenKey}; +export type {ILLMChannel, DataChannelTokenKey, RegisterAndConnectTiming}; diff --git a/packages/@webex/internal-plugin-llm/test/unit/spec/llm.js b/packages/@webex/internal-plugin-llm/test/unit/spec/llm.js index 67eee6fd537..8f8ed02192c 100644 --- a/packages/@webex/internal-plugin-llm/test/unit/spec/llm.js +++ b/packages/@webex/internal-plugin-llm/test/unit/spec/llm.js @@ -709,5 +709,57 @@ describe('plugin-llm', () => { }); }); + describe('#registerAndConnect timing', () => { + it('returns timing data on successful connection', async () => { + llmService.register = sinon.stub().callsFake(async () => { + const sessionData = llmService.connections.get('llm-default-session') || {}; + + sessionData.webSocketUrl = 'wss://example.com/socket'; + sessionData.binding = 'binding'; + llmService.connections.set('llm-default-session', sessionData); + }); + + const result = await llmService.registerAndConnect(locusUrl, datachannelUrl, undefined); + + assert.isDefined(result); + assert.isNumber(result.clientLLMDatachannelResponseTime); + assert.isNumber(result.clientLLMWebSocketConnectTime); + assert.isAtLeast(result.clientLLMDatachannelResponseTime, 0); + assert.isAtLeast(result.clientLLMWebSocketConnectTime, 0); + }); + + it('returns undefined when locusUrl is empty', async () => { + llmService.register = sinon.stub().resolves(); + + const result = await llmService.registerAndConnect('', datachannelUrl, undefined); + + assert.isUndefined(result); + }); + }); + + describe('#getWebSocketUrl', () => { + it('returns the websocket URL for default session', () => { + llmService.connections.set('llm-default-session', { + webSocketUrl: 'wss://test.example.com/ws', + }); + + assert.equal(llmService.getWebSocketUrl(), 'wss://test.example.com/ws'); + }); + + it('returns undefined when no connection exists', () => { + llmService.connections.clear(); + + assert.isUndefined(llmService.getWebSocketUrl()); + }); + + it('returns the websocket URL for custom session', () => { + llmService.connections.set('custom-session', { + webSocketUrl: 'wss://custom.example.com/ws', + }); + + assert.equal(llmService.getWebSocketUrl('custom-session'), 'wss://custom.example.com/ws'); + }); + }); + }); }); diff --git a/packages/@webex/plugin-meetings/src/breakouts/events.ts b/packages/@webex/plugin-meetings/src/breakouts/events.ts index 75af6400583..be5f619e76f 100644 --- a/packages/@webex/plugin-meetings/src/breakouts/events.ts +++ b/packages/@webex/plugin-meetings/src/breakouts/events.ts @@ -36,19 +36,40 @@ const breakoutEvent: { if (!eventInfo?.breakoutMoveId || !eventInfo?.meeting) { return; } + if (event === 'client.breakout-session.join.response' && !eventInfo?.llmLatency) { + return; + } if (!eventInfo.meeting.meetingInfo?.enableConvergedArchitecture) { return; } + + const payload: any = { + ...(eventInfo?.llmLatency && {llmLatency: eventInfo.llmLatency}), + identifiers: { + breakoutMoveId: eventInfo.breakoutMoveId, + breakoutSessionId: eventInfo?.currentSession?.sessionId, + breakoutGroupId: eventInfo?.currentSession?.groupId, + ...(eventInfo?.llmWebsocketUrl && {llmWebsocketUrl: eventInfo.llmWebsocketUrl}), + }, + }; + + // eslint-disable-next-line no-console + console.log(`[metrics] ${event}`, { + name: event, + payload, + options: { + meetingId: eventInfo.meeting.id, + ...(eventInfo?.error && {rawError: eventInfo.error}), + }, + }); + submitClientEvent({ name: event, - payload: { - identifiers: { - breakoutMoveId: eventInfo.breakoutMoveId, - breakoutSessionId: eventInfo?.currentSession?.sessionId, - breakoutGroupId: eventInfo?.currentSession?.groupId, - }, + payload, + options: { + meetingId: eventInfo.meeting.id, + ...(eventInfo?.error && {rawError: eventInfo.error}), }, - options: {meetingId: eventInfo.meeting.id}, }); }, }; diff --git a/packages/@webex/plugin-meetings/src/breakouts/index.ts b/packages/@webex/plugin-meetings/src/breakouts/index.ts index e1063c69da3..835abf7cc29 100644 --- a/packages/@webex/plugin-meetings/src/breakouts/index.ts +++ b/packages/@webex/plugin-meetings/src/breakouts/index.ts @@ -32,6 +32,7 @@ const Breakouts = WebexPlugin.extend({ name: 'string', // only present when in a breakout session sessionId: 'string', // appears from the moment you enable breakouts sessionType: 'string', // appears from the moment you enable breakouts + breakoutMoveId: 'string', // used to correlate breakout move/join diagnostics startTime: 'string', // appears once breakouts start status: 'string', // only present when in a breakout session url: 'string', // appears from the moment you enable breakouts @@ -328,6 +329,7 @@ const Breakouts = WebexPlugin.extend({ */ updateBreakout(params) { this.set(params); + this.set('breakoutMoveId', params.breakoutMoveId); // These values are set manually so they are unset when they are not included in params this.set('groups', params.groups); this.set('startTime', params.startTime); diff --git a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts index 21764ea4607..dfe8afa1269 100644 --- a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts @@ -58,6 +58,8 @@ interface InternalDataSet extends DataSet { timer?: ReturnType; heartbeatWatchdogTimer?: ReturnType; syncAbortController?: AbortController; + // Actual random backoff used by runSyncAlgorithm (excluding idleMs) + lastBackoffTime?: number; } type WebexRequestMethod = (options: Record) => Promise; @@ -84,6 +86,39 @@ export type LocusInfoUpdate = { export type LocusInfoUpdateCallback = (update: LocusInfoUpdate) => void; +export interface SyncLatencyMetrics { + randomBackoffTime: number; + hashtreePrepTime: number; + hashtreeResponseTime: number; + syncPrepTime: number; + syncResponseTime: number; + syncMessageReceiveTime: number; + totalTime: number; +} + +export type SyncMetricsCallback = (metrics: { + dataSet: string; + syncLatency: SyncLatencyMetrics; +}) => void; + +const SYNC_METRICS_DATA_SETS = [ + DataSetNames.MAIN, + DataSetNames.ATD_ACTIVE, + DataSetNames.ATD_UNMUTED, +]; + +interface PendingSyncMetrics { + syncResponseReceivedAt: number; + totalStartTime: number; + randomBackoffTime: number; + hashtreePrepTime: number; + hashtreeResponseTime: number; + syncPrepTime: number; + syncResponseTime: number; + dataSetName: string; + dataSetVersion: number; +} + interface LeafInfo { type: ObjectType; id: number; @@ -136,6 +171,8 @@ class HashTreeParser { private syncQueueProcessingPromise: Promise = Promise.resolve(); // top-level heartbeat interval from the most recent message, used as fallback when dataset-level value is missing private topLevelHeartbeatIntervalMs?: number; + public syncMetricsCallback?: SyncMetricsCallback; + private pendingSyncMetrics: Map = new Map(); /** * Constructor for HashTreeParser @@ -1175,6 +1212,8 @@ class HashTreeParser { this.handleRootHashHeartBeatMessage(message); this.resetHeartbeatWatchdogs(message.dataSets); } else { + this.tryCompletePendingSyncMetrics(message); + const updatedObjects = this.parseMessage(message, debugText); this.resetHeartbeatWatchdogs(message.dataSets); @@ -1185,6 +1224,62 @@ class HashTreeParser { } } + /** + * Completes any pending sync metrics when a qualifying LLM message arrives. + * + * @param {HashTreeMessage} message + * @returns {void} + */ + private tryCompletePendingSyncMetrics(message: HashTreeMessage): void { + if (this.pendingSyncMetrics.size === 0) { + return; + } + + const messageReceivedAt = performance.now(); + + for (const dataSet of message.dataSets) { + const pending = this.pendingSyncMetrics.get(dataSet.name); + + if (pending && dataSet.version >= pending.dataSetVersion) { + this.completeSyncMetrics(dataSet.name, messageReceivedAt); + } + } + } + + /** + * Finalize pending sync metrics and invoke callback. + * + * @param {string} dataSetName + * @param {number} messageReceivedAt + * @returns {void} + */ + private completeSyncMetrics(dataSetName: string, messageReceivedAt: number): void { + const pending = this.pendingSyncMetrics.get(dataSetName); + + if (!pending) { + return; + } + + this.pendingSyncMetrics.delete(dataSetName); + + const syncMessageReceiveTime = Math.round(messageReceivedAt - pending.syncResponseReceivedAt); + const totalTime = Math.round(messageReceivedAt - pending.totalStartTime); + + const syncLatency: SyncLatencyMetrics = { + randomBackoffTime: pending.randomBackoffTime, + hashtreePrepTime: pending.hashtreePrepTime, + hashtreeResponseTime: pending.hashtreeResponseTime, + syncPrepTime: pending.syncPrepTime, + syncResponseTime: pending.syncResponseTime, + syncMessageReceiveTime, + totalTime, + }; + + if (this.syncMetricsCallback) { + this.syncMetricsCallback({dataSet: pending.dataSetName, syncLatency}); + } + } + /** * Calls the updateInfo callback if there are any updates to report * @@ -1281,6 +1376,10 @@ class HashTreeParser { const {hashTree} = dataSet; const rootHash = hashTree.getRootHash(); + const shouldCollectMetrics = !isInitialization && SYNC_METRICS_DATA_SETS.includes(dataSet.name); + const totalStart = shouldCollectMetrics ? performance.now() : 0; + let hashtreePrepStart = 0; + let hashtreeResponseTime = 0; try { LoggerProxy.logger.info( @@ -1293,6 +1392,8 @@ class HashTreeParser { if (dataSet.leafCount !== 1) { let receivedHashes; + hashtreePrepStart = shouldCollectMetrics ? performance.now() : 0; + try { // request hashes from sender const hashesResult = await this.getHashesFromLocus(dataSet.name, rootHash); @@ -1317,6 +1418,10 @@ class HashTreeParser { throw error; } + hashtreeResponseTime = shouldCollectMetrics + ? Math.round(performance.now() - hashtreePrepStart) + : 0; + // identify mismatched leaves const mismatchedLeaveIndexes = hashTree.diffHashes(receivedHashes); @@ -1337,6 +1442,7 @@ class HashTreeParser { } // request sync for mismatched leaves let syncResponse: HashTreeMessage | null = null; + const syncPrepStart = shouldCollectMetrics ? performance.now() : 0; if (isInitialization) { syncResponse = await this.sendSyncRequestToLocus(dataSet, {isInitialization: true}); @@ -1346,6 +1452,30 @@ class HashTreeParser { }); } + const syncResponseReceivedAt = shouldCollectMetrics ? performance.now() : 0; + + // Record pending metrics and complete them when the matching LLM broadcast arrives. + if (shouldCollectMetrics && syncResponse !== null) { + const hashtreePrepTimeVal = + hashtreePrepStart > 0 ? Math.round(hashtreePrepStart - totalStart) : 0; + const syncPrepTimeVal = Math.round( + syncPrepStart - (totalStart + hashtreePrepTimeVal + hashtreeResponseTime) + ); + const syncResponseTimeVal = Math.round(syncResponseReceivedAt - syncPrepStart); + + this.pendingSyncMetrics.set(dataSet.name, { + syncResponseReceivedAt, + totalStartTime: totalStart, + randomBackoffTime: Math.round(dataSet.lastBackoffTime || 0), + hashtreePrepTime: hashtreePrepTimeVal, + hashtreeResponseTime, + syncPrepTime: syncPrepTimeVal, + syncResponseTime: syncResponseTimeVal, + dataSetName: dataSet.name, + dataSetVersion: dataSet.version, + }); + } + // sync API may return nothing (in that case data will arrive via messages) // or it may return a response in the same format as messages // We still need to restart the sync timer as a safety net in case the messages don't arrive. @@ -1657,6 +1787,7 @@ class HashTreeParser { dataSet.timer = setTimeout(() => { dataSet.timer = undefined; + dataSet.lastBackoffTime = delay - dataSet.idleMs; if (!dataSet.hashTree) { LoggerProxy.logger.warn( @@ -1761,6 +1892,7 @@ class HashTreeParser { this.topLevelHeartbeatIntervalMs = undefined; this.syncAllBackoffType = SyncAllBackoffType.NONE; this.dataSetsSyncedDuringBackoff = new Set(); + this.pendingSyncMetrics.clear(); Object.values(this.dataSets).forEach((dataSet) => { dataSet.syncAbortController?.abort(); dataSet.syncAbortController = undefined; diff --git a/packages/@webex/plugin-meetings/src/locus-info/index.ts b/packages/@webex/plugin-meetings/src/locus-info/index.ts index bc240a230f4..e94309e7e78 100644 --- a/packages/@webex/plugin-meetings/src/locus-info/index.ts +++ b/packages/@webex/plugin-meetings/src/locus-info/index.ts @@ -37,6 +37,7 @@ import HashTreeParser, { LocusInfoUpdate, LocusInfoUpdateType, Metadata, + SyncMetricsCallback, } from '../hashTree/hashTreeParser'; import {HashTreeObject, ObjectType, ObjectTypeToLocusKeyMap} from '../hashTree/types'; import {isMetadata, isSelf} from '../hashTree/utils'; @@ -286,6 +287,7 @@ export default class LocusInfo extends EventsScope { hashTreeParsers: Map; hashTreeObjectId2ParticipantId: Map; // mapping of hash tree object ids to participant ids classicVsHashTreeMismatchMetricCounter = 0; + syncMetricsCallback?: SyncMetricsCallback; /** * Constructor @@ -559,6 +561,10 @@ export default class LocusInfo extends EventsScope { excludedDataSets: this.webex.config.meetings.locus?.excludedDataSets, }); + if (this.syncMetricsCallback) { + parser.syncMetricsCallback = this.syncMetricsCallback; + } + // When a new HashTreeParser is created, previous one should be stopped. // Locus will only be sending us updates for the current one. for (const [existingLocusUrl, existingEntry] of this.hashTreeParsers) { diff --git a/packages/@webex/plugin-meetings/src/meeting/index.ts b/packages/@webex/plugin-meetings/src/meeting/index.ts index d1007380104..82bed8ad7b2 100644 --- a/packages/@webex/plugin-meetings/src/meeting/index.ts +++ b/packages/@webex/plugin-meetings/src/meeting/index.ts @@ -33,7 +33,7 @@ import { MediaCodecMimeType, } from '@webex/internal-media-core'; -import {DataChannelTokenType} from '@webex/internal-plugin-llm'; +import {DataChannelTokenType, type RegisterAndConnectTiming} from '@webex/internal-plugin-llm'; import { LocalStream, @@ -164,6 +164,7 @@ import { RelayEvent, } from '../reactions/reactions.type'; import Breakouts from '../breakouts'; +import breakoutEvent from '../breakouts/events'; import SimultaneousInterpretation from '../interpretation'; import Annotation from '../annotation'; import Webinar from '../webinar'; @@ -183,7 +184,7 @@ import JoinForbiddenError from '../common/errors/join-forbidden-error'; import {ReachabilityMetrics} from '../reachability/reachability.types'; import {SetStageOptions, SetStageVideoLayout, UnsetStageVideoLayout} from './request.type'; import {Invitee} from './type'; -import {DataSet, HashTreeMessage, Metadata} from '../hashTree/hashTreeParser'; +import {DataSet, HashTreeMessage, Metadata, SyncLatencyMetrics} from '../hashTree/hashTreeParser'; import {LocusDTO} from '../locus-info/types'; import AIEnableRequest from '../aiEnableRequest'; @@ -1383,6 +1384,12 @@ export default class Meeting extends StatelessWebexPlugin { */ // @ts-ignore - Fix type this.locusInfo = new LocusInfo(this.updateMeetingObject.bind(this), this.webex, this.id); + this.locusInfo.syncMetricsCallback = (metrics: { + dataSet: string; + syncLatency: SyncLatencyMetrics; + }) => { + this.sendSyncCompleteMetric(metrics); + }; // We had to add listeners first before setting up the locus instance /** @@ -6372,7 +6379,7 @@ export default class Meeting extends StatelessWebexPlugin { this.webex.internal.llm.off('online', this.handleLLMOnline); // @ts-ignore this.webex.internal.llm.on('online', this.handleLLMOnline); - this.updateLLMConnection() + this.updateLLMConnection({isInitialJoinPhase: true}) .catch((error) => { LoggerProxy.logger.error( 'Meeting:index#join --> Transcription Socket Connection Failed', @@ -6643,9 +6650,11 @@ export default class Meeting extends StatelessWebexPlugin { /** * Connects to low latency mercury and reconnects if the address has changed * It will also disconnect if called when the meeting has ended + * @param {Object} [options] + * @param {boolean} [options.isInitialJoinPhase] true when called from initial join flow * @returns {Promise} */ - async updateLLMConnection() { + async updateLLMConnection({isInitialJoinPhase = false}: {isInitialJoinPhase?: boolean} = {}) { // @ts-ignore - Fix type const {url = undefined, info: {datachannelUrl = undefined} = {}} = this.locusInfo || {}; @@ -6783,10 +6792,133 @@ export default class Meeting extends StatelessWebexPlugin { this.startLLMHealthCheckTimer(); + if (registerAndConnectResult) { + if (isInitialJoinPhase) { + this.sendLLMConnectMetric(registerAndConnectResult); + } + + if (this.breakouts?.breakoutMoveId) { + // @ts-ignore + const llmWebsocketUrl = this.webex.internal.llm.getWebSocketUrl?.() || undefined; + + breakoutEvent.onBreakoutJoinResponse( + { + currentSession: this.breakouts?.currentBreakoutSession, + meeting: this, + breakoutMoveId: this.breakouts.breakoutMoveId, + llmLatency: registerAndConnectResult, + llmWebsocketUrl, + }, + // @ts-ignore + this.webex.internal.newMetrics.submitClientEvent.bind(this.webex.internal.newMetrics) + ); + } + } + return Promise.resolve(registerAndConnectResult); + }) + .catch((error) => { + if (isInitialJoinPhase) { + this.sendLLMConnectMetric( + { + clientLLMDatachannelResponseTime: 0, + clientLLMWebSocketConnectTime: 0, + }, + error + ); + } + + if (this.breakouts?.breakoutMoveId) { + // @ts-ignore + const llmWebsocketUrl = this.webex.internal.llm.getWebSocketUrl?.() || undefined; + + breakoutEvent.onBreakoutJoinResponse( + { + currentSession: this.breakouts?.currentBreakoutSession, + meeting: this, + breakoutMoveId: this.breakouts.breakoutMoveId, + llmLatency: { + clientLLMDatachannelResponseTime: 0, + clientLLMWebSocketConnectTime: 0, + }, + llmWebsocketUrl, + error, + }, + // @ts-ignore + this.webex.internal.newMetrics.submitClientEvent.bind(this.webex.internal.newMetrics) + ); + } + + return Promise.reject(error); }); } + /** + * Sends LLM connect latencies for initial join flow. + * @param {RegisterAndConnectTiming} timings + * @param {any} [error] + * @returns {void} + */ + private sendLLMConnectMetric(timings: RegisterAndConnectTiming, error?: any) { + // @ts-ignore + const llmWebsocketUrl = this.webex.internal.llm.getWebSocketUrl?.() || undefined; + + const payload: any = { + llmLatency: { + clientLLMDatachannelResponseTime: timings?.clientLLMDatachannelResponseTime ?? 0, + ...(timings?.clientLLMWebSocketConnectTime !== undefined && { + clientLLMWebSocketConnectTime: timings.clientLLMWebSocketConnectTime, + }), + }, + }; + + if (llmWebsocketUrl) { + payload.identifiers = {llmWebsocketUrl}; + } + + // @ts-ignore + this.webex.internal.newMetrics.submitClientEvent({ + name: 'client.llm.connect.response', + payload, + options: { + meetingId: this.id, + ...(error && {rawError: error}), + }, + }); + } + + /** + * Sends sync latency metrics when a sync-initiating client receives LLM sync message. + * @param {Object} metrics + * @param {string} metrics.dataSet + * @param {SyncLatencyMetrics} metrics.syncLatency + * @returns {void} + */ + private sendSyncCompleteMetric(metrics: {dataSet: string; syncLatency: SyncLatencyMetrics}) { + // @ts-ignore + const llmWebsocketUrl = this.webex.internal.llm.getWebSocketUrl?.() || undefined; + + const payload: any = { + syncLatency: metrics.syncLatency, + llmInfo: { + dataSet: metrics.dataSet, + }, + }; + + if (llmWebsocketUrl) { + payload.identifiers = {llmWebsocketUrl}; + } + + // @ts-ignore + this.webex.internal.newMetrics.submitClientEvent({ + name: 'client.locus.sync.complete', + payload, + options: { + meetingId: this.id, + }, + }); + } + /** * Use phone for meeting audio * @param {String} phoneNumber If provided, it will dial-out using this number. If not provided, dial-in will be used diff --git a/packages/@webex/plugin-meetings/test/unit/spec/breakouts/events.ts b/packages/@webex/plugin-meetings/test/unit/spec/breakouts/events.ts index 52065e7d949..ccde056381f 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/breakouts/events.ts +++ b/packages/@webex/plugin-meetings/test/unit/spec/breakouts/events.ts @@ -29,15 +29,29 @@ describe('plugin-meetings', () => { describe('postMoveCallAnalyzer', () => { it('send metric as expected', () => { const submitClientEvent = sinon.stub(); - const eventInfo = {currentSession: newSession, meeting: mockMeeting, breakoutMoveId}; + const eventInfo = { + currentSession: newSession, + meeting: mockMeeting, + breakoutMoveId, + llmLatency: { + clientLLMDatachannelResponseTime: 10, + clientLLMWebSocketConnectTime: 20, + }, + llmWebsocketUrl: 'wss://example.com/ws', + }; breakoutEvent.postMoveCallAnalyzer('client.breakout-session.join.response', eventInfo, submitClientEvent); assert.calledWithMatch(submitClientEvent, { name: 'client.breakout-session.join.response', payload: { + llmLatency: { + clientLLMDatachannelResponseTime: 10, + clientLLMWebSocketConnectTime: 20, + }, identifiers: { breakoutMoveId: 'breakoutMoveId', breakoutSessionId: 'sessionId', breakoutGroupId: 'groupId', + llmWebsocketUrl: 'wss://example.com/ws', }, }, options: {meetingId: 'activeMeetingId'}, @@ -79,10 +93,27 @@ describe('plugin-meetings', () => { sinon.stub(submitClientEvent, 'bind').returns(webex.internal.newMetrics.submitClientEvent); breakoutEvent.postMoveCallAnalyzer = sinon.stub(); - const eventInfo = {newSession, mockMeeting, breakoutMoveId}; + const eventInfo = { + newSession, + mockMeeting, + breakoutMoveId, + llmLatency: {clientLLMDatachannelResponseTime: 10, clientLLMWebSocketConnectTime: 20}, + }; breakoutEvent.onBreakoutJoinResponse(eventInfo, submitClientEvent); assert.calledWith(breakoutEvent.postMoveCallAnalyzer, 'client.breakout-session.join.response', eventInfo, submitClientEvent); }); + + it('does not emit join response metric without llmLatency', () => { + const submitClientEvent = sinon.stub(); + + breakoutEvent.postMoveCallAnalyzer( + 'client.breakout-session.join.response', + {currentSession: newSession, meeting: mockMeeting, breakoutMoveId}, + submitClientEvent + ); + + assert.notCalled(submitClientEvent); + }); }); }); diff --git a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts index 9523c2f78c4..b377ab8ab41 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts @@ -5325,4 +5325,82 @@ describe('HashTreeParser', () => { expect(parser.dataSets).to.deep.equal({}); }); }); + + describe('#syncMetrics', () => { + it('invokes syncMetricsCallback when matching dataset version arrives', () => { + const parser = createHashTreeParser(); + const syncMetricsCallback = sinon.stub(); + + parser.syncMetricsCallback = syncMetricsCallback; + parser['pendingSyncMetrics'].set('main', { + syncResponseReceivedAt: 100, + totalStartTime: 50, + randomBackoffTime: 10, + hashtreePrepTime: 5, + hashtreeResponseTime: 20, + syncPrepTime: 3, + syncResponseTime: 15, + dataSetName: 'main', + dataSetVersion: 1000, + } as any); + + parser.handleMessage({ + dataSets: [ + { + ...createDataSet('main', 16, 1001), + root: 'newroot', + }, + ], + visibleDataSetsUrl, + locusUrl, + locusStateElements: [], + }); + + assert.calledOnce(syncMetricsCallback); + const arg = syncMetricsCallback.firstCall.args[0]; + + assert.equal(arg.dataSet, 'main'); + assert.isNumber(arg.syncLatency.randomBackoffTime); + assert.isNumber(arg.syncLatency.hashtreePrepTime); + assert.isNumber(arg.syncLatency.hashtreeResponseTime); + assert.isNumber(arg.syncLatency.syncPrepTime); + assert.isNumber(arg.syncLatency.syncResponseTime); + assert.isNumber(arg.syncLatency.syncMessageReceiveTime); + assert.isNumber(arg.syncLatency.totalTime); + assert.isFalse(parser['pendingSyncMetrics'].has('main')); + }); + + it('does not complete pending metrics when message version is below pending version', () => { + const parser = createHashTreeParser(); + const syncMetricsCallback = sinon.stub(); + + parser.syncMetricsCallback = syncMetricsCallback; + parser['pendingSyncMetrics'].set('main', { + syncResponseReceivedAt: 100, + totalStartTime: 50, + randomBackoffTime: 10, + hashtreePrepTime: 5, + hashtreeResponseTime: 20, + syncPrepTime: 3, + syncResponseTime: 15, + dataSetName: 'main', + dataSetVersion: 1005, + } as any); + + parser.handleMessage({ + dataSets: [ + { + ...createDataSet('main', 16, 1004), + root: 'newroot', + }, + ], + visibleDataSetsUrl, + locusUrl, + locusStateElements: [], + }); + + assert.notCalled(syncMetricsCallback); + assert.isTrue(parser['pendingSyncMetrics'].has('main')); + }); + }); }); From 47d0606deff74a6e9c441017d75f99e7603d9a09 Mon Sep 17 00:00:00 2001 From: tiahan Date: Tue, 26 May 2026 15:40:48 +0800 Subject: [PATCH 02/29] fix(meetings): emit breakout join response metric once per breakoutMoveId --- .../plugin-meetings/src/breakouts/events.ts | 10 ------ .../plugin-meetings/src/meeting/index.ts | 32 ++++++++++++++++--- .../test/unit/spec/meeting/index.js | 29 +++++++++++++++++ 3 files changed, 57 insertions(+), 14 deletions(-) diff --git a/packages/@webex/plugin-meetings/src/breakouts/events.ts b/packages/@webex/plugin-meetings/src/breakouts/events.ts index be5f619e76f..d7f16bace6a 100644 --- a/packages/@webex/plugin-meetings/src/breakouts/events.ts +++ b/packages/@webex/plugin-meetings/src/breakouts/events.ts @@ -53,16 +53,6 @@ const breakoutEvent: { }, }; - // eslint-disable-next-line no-console - console.log(`[metrics] ${event}`, { - name: event, - payload, - options: { - meetingId: eventInfo.meeting.id, - ...(eventInfo?.error && {rawError: eventInfo.error}), - }, - }); - submitClientEvent({ name: event, payload, diff --git a/packages/@webex/plugin-meetings/src/meeting/index.ts b/packages/@webex/plugin-meetings/src/meeting/index.ts index 82bed8ad7b2..fa1217f8af8 100644 --- a/packages/@webex/plugin-meetings/src/meeting/index.ts +++ b/packages/@webex/plugin-meetings/src/meeting/index.ts @@ -739,6 +739,7 @@ export default class Meeting extends StatelessWebexPlugin { isMoveToInProgress = false; registrationIdStatus: string; brbState: BrbState; + private emittedBreakoutJoinResponseMoveIds: Set = new Set(); voiceaListenerCallbacks: object = { [VOICEAEVENTS.VOICEA_ANNOUNCEMENT]: (payload: Transcription['languageOptions']) => { @@ -6797,7 +6798,9 @@ export default class Meeting extends StatelessWebexPlugin { this.sendLLMConnectMetric(registerAndConnectResult); } - if (this.breakouts?.breakoutMoveId) { + const breakoutMoveId = this.breakouts?.breakoutMoveId; + + if (this.shouldEmitBreakoutJoinResponseMetric(breakoutMoveId)) { // @ts-ignore const llmWebsocketUrl = this.webex.internal.llm.getWebSocketUrl?.() || undefined; @@ -6805,7 +6808,7 @@ export default class Meeting extends StatelessWebexPlugin { { currentSession: this.breakouts?.currentBreakoutSession, meeting: this, - breakoutMoveId: this.breakouts.breakoutMoveId, + breakoutMoveId, llmLatency: registerAndConnectResult, llmWebsocketUrl, }, @@ -6828,7 +6831,9 @@ export default class Meeting extends StatelessWebexPlugin { ); } - if (this.breakouts?.breakoutMoveId) { + const breakoutMoveId = this.breakouts?.breakoutMoveId; + + if (this.shouldEmitBreakoutJoinResponseMetric(breakoutMoveId)) { // @ts-ignore const llmWebsocketUrl = this.webex.internal.llm.getWebSocketUrl?.() || undefined; @@ -6836,7 +6841,7 @@ export default class Meeting extends StatelessWebexPlugin { { currentSession: this.breakouts?.currentBreakoutSession, meeting: this, - breakoutMoveId: this.breakouts.breakoutMoveId, + breakoutMoveId, llmLatency: { clientLLMDatachannelResponseTime: 0, clientLLMWebSocketConnectTime: 0, @@ -6853,6 +6858,25 @@ export default class Meeting extends StatelessWebexPlugin { }); } + /** + * Ensures breakout join response metric is emitted only once per breakout move id. + * @param {string | undefined} breakoutMoveId + * @returns {boolean} + */ + private shouldEmitBreakoutJoinResponseMetric(breakoutMoveId?: string): boolean { + if (!breakoutMoveId) { + return false; + } + + if (this.emittedBreakoutJoinResponseMoveIds.has(breakoutMoveId)) { + return false; + } + + this.emittedBreakoutJoinResponseMoveIds.add(breakoutMoveId); + + return true; + } + /** * Sends LLM connect latencies for initial join flow. * @param {RegisterAndConnectTiming} timings diff --git a/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js b/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js index 8b19f6e74c1..3a7b7041560 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js +++ b/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js @@ -2626,6 +2626,35 @@ describe('plugin-meetings', () => { ); }); + it('emits breakout join response metric only once per breakoutMoveId', async () => { + sinon.stub(meeting, 'isJoined').returns(true); + sinon.stub(meeting.webex.internal.llm, 'isConnected').returns(false); + sinon.stub(meeting.webex.internal.llm, 'registerAndConnect').resolves({ + clientLLMDatachannelResponseTime: 10, + clientLLMWebSocketConnectTime: 20, + }); + + meeting.meetingInfo.enableConvergedArchitecture = true; + meeting.breakouts.set('breakoutMoveId', 'move-id-1'); + meeting.breakouts.set('currentBreakoutSession', { + sessionId: 'session-id-1', + groupId: 'group-id-1', + }); + + webex.internal.newMetrics.submitClientEvent.resetHistory(); + meeting.updateLLMConnection.restore(); + + await meeting.updateLLMConnection(); + await meeting.updateLLMConnection(); + + const joinResponseCalls = webex.internal.newMetrics.submitClientEvent + .getCalls() + .filter((call) => call.args[0]?.name === 'client.breakout-session.join.response'); + + assert.lengthOf(joinResponseCalls, 1); + assert.equal(joinResponseCalls[0].args[0].options.meetingId, meeting.id); + }); + it('clears the LLM health check timer when disconnecting LLM', async () => { const isJoinedStub = sinon.stub(meeting, 'isJoined'); sinon.stub(meeting.webex.internal.llm, 'isConnected'); From 1b82b71b8e0ab0bdb1e24f39d195f1fb6e16f188 Mon Sep 17 00:00:00 2001 From: tiahan Date: Thu, 28 May 2026 14:17:42 +0800 Subject: [PATCH 03/29] feat(meetings): add Locus sync latency metric callbacks --- .../src/hashTree/hashTreeParser.ts | 23 ++++++++++------- .../plugin-meetings/src/locus-info/index.ts | 25 ++++++++++++------- .../plugin-meetings/src/meeting/index.ts | 17 +++++++------ .../test/unit/spec/hashTree/hashTreeParser.ts | 14 ++++++----- .../test/unit/spec/locus-info/index.js | 19 ++++++++++---- 5 files changed, 62 insertions(+), 36 deletions(-) diff --git a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts index dfe8afa1269..a850ce7b58c 100644 --- a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts @@ -101,6 +101,11 @@ export type SyncMetricsCallback = (metrics: { syncLatency: SyncLatencyMetrics; }) => void; +export type HashTreeParserCallbacks = { + locusInfoUpdateCallback: LocusInfoUpdateCallback; + syncMetricsCallback: SyncMetricsCallback; +}; + const SYNC_METRICS_DATA_SETS = [ DataSetNames.MAIN, DataSetNames.ATD_ACTIVE, @@ -157,7 +162,7 @@ class HashTreeParser { dataSets: Record = {}; visibleDataSetsUrl: string; // url from which we can get info about all data sets webexRequest: WebexRequestMethod; - locusInfoUpdateCallback: LocusInfoUpdateCallback; + private callbacks: HashTreeParserCallbacks; visibleDataSets: VisibleDataSetInfo[]; debugId: string; private excludedDataSets: string[]; @@ -171,7 +176,6 @@ class HashTreeParser { private syncQueueProcessingPromise: Promise = Promise.resolve(); // top-level heartbeat interval from the most recent message, used as fallback when dataset-level value is missing private topLevelHeartbeatIntervalMs?: number; - public syncMetricsCallback?: SyncMetricsCallback; private pendingSyncMetrics: Map = new Map(); /** @@ -186,7 +190,7 @@ class HashTreeParser { }; metadata: Metadata | null; webexRequest: WebexRequestMethod; - locusInfoUpdateCallback: LocusInfoUpdateCallback; + callbacks: HashTreeParserCallbacks; debugId: string; excludedDataSets?: string[]; }) { @@ -194,7 +198,7 @@ class HashTreeParser { this.debugId = options.debugId; this.webexRequest = options.webexRequest; - this.locusInfoUpdateCallback = options.locusInfoUpdateCallback; + this.callbacks = options.callbacks; this.excludedDataSets = options.excludedDataSets || []; this.visibleDataSetsUrl = locus?.links?.resources?.visibleDataSets?.url; this.setVisibleDataSets(options.metadata?.visibleDataSets || [], dataSets); @@ -1275,9 +1279,10 @@ class HashTreeParser { totalTime, }; - if (this.syncMetricsCallback) { - this.syncMetricsCallback({dataSet: pending.dataSetName, syncLatency}); - } + this.callbacks.syncMetricsCallback({ + dataSet: pending.dataSetName, + syncLatency, + }); } /** @@ -1333,10 +1338,10 @@ class HashTreeParser { }); if (filteredUpdates.length > 0) { - this.locusInfoUpdateCallback({updateType, updatedObjects: filteredUpdates}); + this.callbacks.locusInfoUpdateCallback({updateType, updatedObjects: filteredUpdates}); } } else if (updateType !== LocusInfoUpdateType.OBJECTS_UPDATED) { - this.locusInfoUpdateCallback({updateType}); + this.callbacks.locusInfoUpdateCallback({updateType}); } } diff --git a/packages/@webex/plugin-meetings/src/locus-info/index.ts b/packages/@webex/plugin-meetings/src/locus-info/index.ts index e94309e7e78..700e0586717 100644 --- a/packages/@webex/plugin-meetings/src/locus-info/index.ts +++ b/packages/@webex/plugin-meetings/src/locus-info/index.ts @@ -95,6 +95,11 @@ export type HashTreeParserEntry = { initializedFromHashTree: boolean; }; +export type LocusInfoCallbacks = { + updateMeeting: (object: any) => void; + syncMetricsCallback: SyncMetricsCallback; +}; + /** * Gets the replacement information * @@ -287,25 +292,28 @@ export default class LocusInfo extends EventsScope { hashTreeParsers: Map; hashTreeObjectId2ParticipantId: Map; // mapping of hash tree object ids to participant ids classicVsHashTreeMismatchMetricCounter = 0; - syncMetricsCallback?: SyncMetricsCallback; + private callbacks: LocusInfoCallbacks; /** * Constructor - * @param {function} updateMeeting callback to update the meeting object from an object + * @param {Object} callbacks callbacks used by LocusInfo + * @param {function} callbacks.updateMeeting callback to update the meeting object from an object + * @param {function} callbacks.syncMetricsCallback callback to report sync metrics * @param {object} webex * @param {string} meetingId * @returns {undefined} */ - constructor(updateMeeting, webex, meetingId) { + constructor(callbacks: LocusInfoCallbacks, webex: any, meetingId: any) { super(); this.parsedLocus = { states: [], }; + this.callbacks = callbacks; this.webex = webex; this.emitChange = false; this.compareAndUpdateFlags = {}; this.meetingId = meetingId; - this.updateMeeting = updateMeeting; + this.updateMeeting = callbacks.updateMeeting; this.locusParser = new LocusDeltaParser(); this.hashTreeParsers = new Map(); this.hashTreeObjectId2ParticipantId = new Map(); @@ -556,15 +564,14 @@ export default class LocusInfo extends EventsScope { initialLocus, metadata, webexRequest: this.webex.request.bind(this.webex), - locusInfoUpdateCallback: this.updateFromHashTree.bind(this, locusUrl), + callbacks: { + locusInfoUpdateCallback: this.updateFromHashTree.bind(this, locusUrl), + syncMetricsCallback: this.callbacks.syncMetricsCallback, + }, debugId: `HT-${locusUrl.split('/')?.pop()?.substring(0, 4)}`, excludedDataSets: this.webex.config.meetings.locus?.excludedDataSets, }); - if (this.syncMetricsCallback) { - parser.syncMetricsCallback = this.syncMetricsCallback; - } - // When a new HashTreeParser is created, previous one should be stopped. // Locus will only be sending us updates for the current one. for (const [existingLocusUrl, existingEntry] of this.hashTreeParsers) { diff --git a/packages/@webex/plugin-meetings/src/meeting/index.ts b/packages/@webex/plugin-meetings/src/meeting/index.ts index fa1217f8af8..c9600332b08 100644 --- a/packages/@webex/plugin-meetings/src/meeting/index.ts +++ b/packages/@webex/plugin-meetings/src/meeting/index.ts @@ -1384,13 +1384,16 @@ export default class Meeting extends StatelessWebexPlugin { * @memberof Meeting */ // @ts-ignore - Fix type - this.locusInfo = new LocusInfo(this.updateMeetingObject.bind(this), this.webex, this.id); - this.locusInfo.syncMetricsCallback = (metrics: { - dataSet: string; - syncLatency: SyncLatencyMetrics; - }) => { - this.sendSyncCompleteMetric(metrics); - }; + this.locusInfo = new LocusInfo( + { + updateMeeting: this.updateMeetingObject.bind(this), + syncMetricsCallback: (metrics: {dataSet: string; syncLatency: SyncLatencyMetrics}) => { + this.sendSyncCompleteMetric(metrics); + }, + }, + this.webex, + this.id + ); // We had to add listeners first before setting up the locus instance /** diff --git a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts index b377ab8ab41..bf7d3942da1 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts @@ -177,13 +177,17 @@ describe('HashTreeParser', () => { function createHashTreeParser( initialLocus: any = exampleInitialLocus, metadata: any = exampleMetadata, - excludedDataSets?: string[] + excludedDataSets?: string[], + syncMetricsCallback: sinon.SinonStub = sinon.stub() ) { return new HashTreeParser({ initialLocus, metadata, webexRequest, - locusInfoUpdateCallback: callback, + callbacks: { + locusInfoUpdateCallback: callback, + syncMetricsCallback, + }, debugId: 'test', excludedDataSets, }); @@ -5328,10 +5332,9 @@ describe('HashTreeParser', () => { describe('#syncMetrics', () => { it('invokes syncMetricsCallback when matching dataset version arrives', () => { - const parser = createHashTreeParser(); const syncMetricsCallback = sinon.stub(); + const parser = createHashTreeParser(undefined, undefined, undefined, syncMetricsCallback); - parser.syncMetricsCallback = syncMetricsCallback; parser['pendingSyncMetrics'].set('main', { syncResponseReceivedAt: 100, totalStartTime: 50, @@ -5371,10 +5374,9 @@ describe('HashTreeParser', () => { }); it('does not complete pending metrics when message version is below pending version', () => { - const parser = createHashTreeParser(); const syncMetricsCallback = sinon.stub(); + const parser = createHashTreeParser(undefined, undefined, undefined, syncMetricsCallback); - parser.syncMetricsCallback = syncMetricsCallback; parser['pendingSyncMetrics'].set('main', { syncResponseReceivedAt: 100, totalStartTime: 50, diff --git a/packages/@webex/plugin-meetings/test/unit/spec/locus-info/index.js b/packages/@webex/plugin-meetings/test/unit/spec/locus-info/index.js index 3c98fcee319..b19531fd035 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/locus-info/index.js +++ b/packages/@webex/plugin-meetings/test/unit/spec/locus-info/index.js @@ -56,7 +56,7 @@ describe('plugin-meetings', () => { beforeEach(() => { mockMeeting = {}; - locusInfo = new LocusInfo(updateMeeting, webex, meetingId); + locusInfo = new LocusInfo({updateMeeting, syncMetricsCallback: sinon.stub()}, webex, meetingId); locusInfo.init(locus); @@ -148,7 +148,10 @@ describe('plugin-meetings', () => { visibleDataSets, }, webexRequest: sinon.match.func, - locusInfoUpdateCallback: sinon.match.func, + callbacks: sinon.match({ + locusInfoUpdateCallback: sinon.match.func, + syncMetricsCallback: sinon.match.func, + }), debugId: sinon.match.string, }) ); @@ -198,7 +201,10 @@ describe('plugin-meetings', () => { }, metadata, webexRequest: sinon.match.func, - locusInfoUpdateCallback: sinon.match.func, + callbacks: sinon.match({ + locusInfoUpdateCallback: sinon.match.func, + syncMetricsCallback: sinon.match.func, + }), debugId: sinon.match.string, }) ); @@ -279,7 +285,10 @@ describe('plugin-meetings', () => { dataSets: [], }, webexRequest: sinon.match.func, - locusInfoUpdateCallback: sinon.match.func, + callbacks: sinon.match({ + locusInfoUpdateCallback: sinon.match.func, + syncMetricsCallback: sinon.match.func, + }), debugId: sinon.match.string, metadata: null, }) @@ -355,7 +364,7 @@ describe('plugin-meetings', () => { }, }); - locusInfoUpdateCallback = HashTreeParserStub.firstCall.args[0].locusInfoUpdateCallback; + locusInfoUpdateCallback = HashTreeParserStub.firstCall.args[0].callbacks.locusInfoUpdateCallback; assert.isDefined(locusInfoUpdateCallback); From f15504d61e5d3b57b0df6101b6d60e276bf3e5c9 Mon Sep 17 00:00:00 2001 From: tiahan Date: Thu, 28 May 2026 14:31:02 +0800 Subject: [PATCH 04/29] refactor(meetings): simplify LLM metric payload construction --- .../plugin-meetings/src/breakouts/events.ts | 30 ++++++++++++------- .../plugin-meetings/src/meeting/index.ts | 29 +++++++++++------- 2 files changed, 38 insertions(+), 21 deletions(-) diff --git a/packages/@webex/plugin-meetings/src/breakouts/events.ts b/packages/@webex/plugin-meetings/src/breakouts/events.ts index d7f16bace6a..b4556bf7283 100644 --- a/packages/@webex/plugin-meetings/src/breakouts/events.ts +++ b/packages/@webex/plugin-meetings/src/breakouts/events.ts @@ -36,30 +36,38 @@ const breakoutEvent: { if (!eventInfo?.breakoutMoveId || !eventInfo?.meeting) { return; } - if (event === 'client.breakout-session.join.response' && !eventInfo?.llmLatency) { + + const {breakoutMoveId, currentSession, error, llmLatency, llmWebsocketUrl, meeting} = eventInfo; + + if (event === 'client.breakout-session.join.response' && !llmLatency) { return; } - if (!eventInfo.meeting.meetingInfo?.enableConvergedArchitecture) { + if (!meeting.meetingInfo?.enableConvergedArchitecture) { return; } const payload: any = { - ...(eventInfo?.llmLatency && {llmLatency: eventInfo.llmLatency}), + llmLatency, identifiers: { - breakoutMoveId: eventInfo.breakoutMoveId, - breakoutSessionId: eventInfo?.currentSession?.sessionId, - breakoutGroupId: eventInfo?.currentSession?.groupId, - ...(eventInfo?.llmWebsocketUrl && {llmWebsocketUrl: eventInfo.llmWebsocketUrl}), + breakoutMoveId, + breakoutSessionId: currentSession?.sessionId, + breakoutGroupId: currentSession?.groupId, + llmWebsocketUrl, }, }; + const options: any = { + meetingId: meeting.id, + }; + + if (error) { + options.rawError = error; + } + submitClientEvent({ name: event, payload, - options: { - meetingId: eventInfo.meeting.id, - ...(eventInfo?.error && {rawError: eventInfo.error}), - }, + options, }); }, }; diff --git a/packages/@webex/plugin-meetings/src/meeting/index.ts b/packages/@webex/plugin-meetings/src/meeting/index.ts index c9600332b08..196216d87ad 100644 --- a/packages/@webex/plugin-meetings/src/meeting/index.ts +++ b/packages/@webex/plugin-meetings/src/meeting/index.ts @@ -6889,28 +6889,37 @@ export default class Meeting extends StatelessWebexPlugin { private sendLLMConnectMetric(timings: RegisterAndConnectTiming, error?: any) { // @ts-ignore const llmWebsocketUrl = this.webex.internal.llm.getWebSocketUrl?.() || undefined; + const {clientLLMDatachannelResponseTime = 0, clientLLMWebSocketConnectTime} = timings || {}; + + const llmLatency: any = { + clientLLMDatachannelResponseTime, + }; + + if (clientLLMWebSocketConnectTime !== undefined) { + llmLatency.clientLLMWebSocketConnectTime = clientLLMWebSocketConnectTime; + } const payload: any = { - llmLatency: { - clientLLMDatachannelResponseTime: timings?.clientLLMDatachannelResponseTime ?? 0, - ...(timings?.clientLLMWebSocketConnectTime !== undefined && { - clientLLMWebSocketConnectTime: timings.clientLLMWebSocketConnectTime, - }), - }, + llmLatency, }; if (llmWebsocketUrl) { payload.identifiers = {llmWebsocketUrl}; } + const options: any = { + meetingId: this.id, + }; + + if (error) { + options.rawError = error; + } + // @ts-ignore this.webex.internal.newMetrics.submitClientEvent({ name: 'client.llm.connect.response', payload, - options: { - meetingId: this.id, - ...(error && {rawError: error}), - }, + options, }); } From 3335dc8100cf44693c36e45ba8c9e67b110378de Mon Sep 17 00:00:00 2001 From: tiahan Date: Thu, 28 May 2026 15:51:38 +0800 Subject: [PATCH 05/29] refactor(metrics): align locus sync latency tracking with internal timestamp pattern --- .../call-diagnostic-metrics-latencies.ts | 209 +++++++++++++++++- .../src/metrics.types.ts | 8 +- .../call-diagnostic-metrics-latencies.ts | 102 +++++++++ .../src/hashTree/hashTreeParser.ts | 123 +++++++---- .../plugin-meetings/src/locus-info/index.ts | 3 + .../plugin-meetings/src/meeting/index.ts | 1 + .../test/unit/spec/hashTree/hashTreeParser.ts | 48 ++-- 7 files changed, 423 insertions(+), 71 deletions(-) diff --git a/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts b/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts index 36ca15f932b..1d0cbff5cf4 100644 --- a/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts +++ b/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts @@ -7,6 +7,30 @@ import {MetricEventNames, PreComputedLatencies} from '../metrics.types'; // we only care about client event and feature event for now +type LocusSyncLatencyMilestone = { + dataSetName: string; + key: MetricEventNames; + value: number; +}; + +type SaveTimestampOptions = { + meetingId?: string; + dataSetName?: string; + randomBackoffTime?: number; +}; + +type LocusSyncLatencyRecord = { + randomBackoffTime: number; + syncStart?: number; + hashTreeRequest?: number; + hashTreeResponse?: number; + syncRequest?: number; + syncResponse?: number; + messageReceived?: number; +}; + +type LocusSyncLatencyTimestampKey = Exclude; + /** * @description Helper class to store latencies timestamp and to calculate various latencies for CA. * @exports @@ -15,6 +39,7 @@ import {MetricEventNames, PreComputedLatencies} from '../metrics.types'; export default class CallDiagnosticLatencies extends WebexPlugin { latencyTimestamps: Map; precomputedLatencies: Map; + locusSyncLatencies: Map; // meetingId that the current latencies are for private meetingId?: string; private MAX_INTEGER = 2147483647; @@ -26,6 +51,7 @@ export default class CallDiagnosticLatencies extends WebexPlugin { super(...args); this.latencyTimestamps = new Map(); this.precomputedLatencies = new Map(); + this.locusSyncLatencies = new Map(); } /** @@ -34,6 +60,175 @@ export default class CallDiagnosticLatencies extends WebexPlugin { public clearTimestamps() { this.latencyTimestamps.clear(); this.precomputedLatencies.clear(); + this.locusSyncLatencies.clear(); + } + + /** + * Clear tracked Locus sync latency state for a dataset. + * @param dataSetName dataset name + */ + public clearLocusSyncLatency(dataSetName: string) { + this.locusSyncLatencies.delete(dataSetName); + } + + /** + * Calculates Locus sync latency values from stored milestone timestamps. + * @param dataSetName dataset name + * @returns sync latency metrics + */ + public getLocusSyncLatency(dataSetName: string) { + const record = this.locusSyncLatencies.get(dataSetName); + + if (!record) { + return undefined; + } + + const hashtreePrepTime = + this.getDiffBetweenLocusSyncTimestamps(record, 'syncStart', 'hashTreeRequest') ?? 0; + const hashtreeResponseTime = + this.getDiffBetweenLocusSyncTimestamps(record, 'hashTreeRequest', 'hashTreeResponse') ?? 0; + const syncPrepStart = this.getLocusSyncPrepStart(record); + const syncPrepTime = this.getDiffBetweenLocusSyncTimestamps( + record, + syncPrepStart, + 'syncRequest' + ); + const syncResponseTime = this.getDiffBetweenLocusSyncTimestamps( + record, + 'syncRequest', + 'syncResponse' + ); + const syncMessageReceiveTime = this.getDiffBetweenLocusSyncTimestamps( + record, + 'syncResponse', + 'messageReceived' + ); + const totalTime = this.getDiffBetweenLocusSyncTimestamps( + record, + 'syncStart', + 'messageReceived' + ); + + if ( + typeof syncPrepTime !== 'number' || + typeof syncResponseTime !== 'number' || + typeof syncMessageReceiveTime !== 'number' || + typeof totalTime !== 'number' + ) { + return undefined; + } + + return { + randomBackoffTime: this.getClampedLocusSyncLatency(record.randomBackoffTime), + hashtreePrepTime, + hashtreeResponseTime, + syncPrepTime, + syncResponseTime, + syncMessageReceiveTime, + totalTime, + }; + } + + /** + * Helper to calculate end - start for Locus sync milestones. + * @param record tracked milestone timestamps + * @param a start milestone + * @param b end milestone + * @returns latency + */ + private getDiffBetweenLocusSyncTimestamps( + record: LocusSyncLatencyRecord, + a: LocusSyncLatencyTimestampKey, + b: LocusSyncLatencyTimestampKey + ) { + const start = record[a]; + const end = record[b]; + + if (typeof start !== 'number' || typeof end !== 'number') { + return undefined; + } + + return this.getClampedLocusSyncLatency(end - start); + } + + /** + * Get the timestamp that starts the sync prep segment. + * @param record tracked milestone timestamps + * @returns sync prep start milestone + */ + private getLocusSyncPrepStart(record: LocusSyncLatencyRecord): LocusSyncLatencyTimestampKey { + return typeof record.hashTreeResponse === 'number' ? 'hashTreeResponse' : 'syncStart'; + } + + /** + * Round and clamp Locus sync latency values. + * @param latency latency value + * @returns rounded latency + */ + private getClampedLocusSyncLatency(latency: number) { + return Math.round(clamp(latency, 0, this.MAX_INTEGER)); + } + + /** + * Checks if metric event name is a Locus sync latency milestone. + * @param key event name + * @returns whether event is Locus sync latency milestone + */ + private isLocusSyncLatencyEvent(key: MetricEventNames) { + return [ + 'internal.client.locus.sync.start', + 'internal.client.locus.hashtree.request', + 'internal.client.locus.hashtree.response', + 'internal.client.locus.sync.request', + 'internal.client.locus.sync.response', + 'internal.client.locus.sync.message.received', + ].includes(key); + } + + /** + * Stores a Locus sync latency milestone timestamp. + * @param options options + */ + private saveLocusSyncLatencyTimestamp({ + dataSetName, + key, + value, + randomBackoffTime = 0, + }: LocusSyncLatencyMilestone & {randomBackoffTime?: number}) { + if (key === 'internal.client.locus.sync.start') { + this.locusSyncLatencies.set(dataSetName, { + randomBackoffTime, + syncStart: value, + }); + + return; + } + + const record = this.locusSyncLatencies.get(dataSetName); + + if (!record) { + return; + } + + switch (key) { + case 'internal.client.locus.hashtree.request': + record.hashTreeRequest = value; + break; + case 'internal.client.locus.hashtree.response': + record.hashTreeResponse = value; + break; + case 'internal.client.locus.sync.request': + record.syncRequest = value; + break; + case 'internal.client.locus.sync.response': + record.syncResponse = value; + break; + case 'internal.client.locus.sync.message.received': + record.messageReceived = value; + break; + default: + break; + } } /** @@ -72,13 +267,25 @@ export default class CallDiagnosticLatencies extends WebexPlugin { }: { key: MetricEventNames; value?: number; - options?: {meetingId?: string}; + options?: SaveTimestampOptions; }) { // save the meetingId so we can use the meeting object in latency calculations if needed const {meetingId} = options; if (meetingId) { this.setMeetingId(meetingId); } + + if (this.isLocusSyncLatencyEvent(key) && options.dataSetName) { + this.saveLocusSyncLatencyTimestamp({ + dataSetName: options.dataSetName, + key, + value, + randomBackoffTime: options.randomBackoffTime, + }); + + return; + } + // for some events we're only interested in the first timestamp not last // as these events can happen multiple times if ( diff --git a/packages/@webex/internal-plugin-metrics/src/metrics.types.ts b/packages/@webex/internal-plugin-metrics/src/metrics.types.ts index 7527feafa99..b6b3308a174 100644 --- a/packages/@webex/internal-plugin-metrics/src/metrics.types.ts +++ b/packages/@webex/internal-plugin-metrics/src/metrics.types.ts @@ -162,7 +162,13 @@ export type InternalEvent = { | 'internal.client.add-media.turn-discovery.start' | 'internal.client.add-media.turn-discovery.end' | 'internal.client.share.initiated' - | 'internal.client.share.stopped'; + | 'internal.client.share.stopped' + | 'internal.client.locus.sync.start' + | 'internal.client.locus.hashtree.request' + | 'internal.client.locus.hashtree.response' + | 'internal.client.locus.sync.request' + | 'internal.client.locus.sync.response' + | 'internal.client.locus.sync.message.received'; payload?: never; options?: never; diff --git a/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts b/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts index 23265e4354c..8bd7637d2d2 100644 --- a/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts +++ b/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts @@ -108,11 +108,113 @@ describe('internal-plugin-metrics', () => { assert.deepEqual(cdl.latencyTimestamps.size, 2); cdl.saveLatency('internal.api.fetch.intelligence.models', 42); assert.deepEqual(cdl.precomputedLatencies.size, 1); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.start', + value: 1, + options: {dataSetName: 'main', randomBackoffTime: 10}, + }); + assert.deepEqual(cdl.locusSyncLatencies.size, 1); cdl.clearTimestamps(); assert.deepEqual(cdl.latencyTimestamps.size, 0); assert.deepEqual(cdl.precomputedLatencies.size, 0); + assert.deepEqual(cdl.locusSyncLatencies.size, 0); + }); + + describe('locus sync latencies', () => { + it('calculates sync latency values from milestones', () => { + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.start', + value: 100, + options: {dataSetName: 'main', randomBackoffTime: 10.4}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.hashtree.request', + value: 105, + options: {dataSetName: 'main'}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.hashtree.response', + value: 125, + options: {dataSetName: 'main'}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.request', + value: 128, + options: {dataSetName: 'main'}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.response', + value: 143, + options: {dataSetName: 'main'}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.message.received', + value: 150, + options: {dataSetName: 'main'}, + }); + + assert.deepEqual(cdl.getLocusSyncLatency('main'), { + randomBackoffTime: 10, + hashtreePrepTime: 5, + hashtreeResponseTime: 20, + syncPrepTime: 3, + syncResponseTime: 15, + syncMessageReceiveTime: 7, + totalTime: 50, + }); + }); + + it('calculates sync latency values when hash tree request is skipped', () => { + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.start', + value: 100, + options: {dataSetName: 'main', randomBackoffTime: 0}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.request', + value: 110, + options: {dataSetName: 'main'}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.response', + value: 130, + options: {dataSetName: 'main'}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.message.received', + value: 140, + options: {dataSetName: 'main'}, + }); + + assert.deepEqual(cdl.getLocusSyncLatency('main'), { + randomBackoffTime: 0, + hashtreePrepTime: 0, + hashtreeResponseTime: 0, + syncPrepTime: 10, + syncResponseTime: 20, + syncMessageReceiveTime: 10, + totalTime: 40, + }); + }); + + it('returns undefined and clears state when required milestones are missing', () => { + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.start', + value: 100, + options: {dataSetName: 'main', randomBackoffTime: 0}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.message.received', + value: 140, + options: {dataSetName: 'main'}, + }); + + assert.isUndefined(cdl.getLocusSyncLatency('main')); + cdl.clearLocusSyncLatency('main'); + assert.isFalse(cdl.locusSyncLatencies.has('main')); + }); }); it('should calculate diff between timestamps correctly', () => { diff --git a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts index a850ce7b58c..df420823bf2 100644 --- a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts @@ -101,9 +101,25 @@ export type SyncMetricsCallback = (metrics: { syncLatency: SyncLatencyMetrics; }) => void; +export type SyncLatencyTracker = { + saveTimestamp: (options: { + key: + | 'internal.client.locus.sync.start' + | 'internal.client.locus.hashtree.request' + | 'internal.client.locus.hashtree.response' + | 'internal.client.locus.sync.request' + | 'internal.client.locus.sync.response' + | 'internal.client.locus.sync.message.received'; + options: {dataSetName: string; randomBackoffTime?: number}; + }) => void; + getLocusSyncLatency: (dataSetName: string) => SyncLatencyMetrics | undefined; + clearLocusSyncLatency: (dataSetName: string) => void; +}; + export type HashTreeParserCallbacks = { locusInfoUpdateCallback: LocusInfoUpdateCallback; syncMetricsCallback: SyncMetricsCallback; + syncLatencyTracker?: SyncLatencyTracker; }; const SYNC_METRICS_DATA_SETS = [ @@ -113,13 +129,6 @@ const SYNC_METRICS_DATA_SETS = [ ]; interface PendingSyncMetrics { - syncResponseReceivedAt: number; - totalStartTime: number; - randomBackoffTime: number; - hashtreePrepTime: number; - hashtreeResponseTime: number; - syncPrepTime: number; - syncResponseTime: number; dataSetName: string; dataSetVersion: number; } @@ -163,6 +172,7 @@ class HashTreeParser { visibleDataSetsUrl: string; // url from which we can get info about all data sets webexRequest: WebexRequestMethod; private callbacks: HashTreeParserCallbacks; + private syncLatencyTracker?: SyncLatencyTracker; visibleDataSets: VisibleDataSetInfo[]; debugId: string; private excludedDataSets: string[]; @@ -199,6 +209,7 @@ class HashTreeParser { this.debugId = options.debugId; this.webexRequest = options.webexRequest; this.callbacks = options.callbacks; + this.syncLatencyTracker = options.callbacks.syncLatencyTracker; this.excludedDataSets = options.excludedDataSets || []; this.visibleDataSetsUrl = locus?.links?.resources?.visibleDataSets?.url; this.setVisibleDataSets(options.metadata?.visibleDataSets || [], dataSets); @@ -1239,13 +1250,11 @@ class HashTreeParser { return; } - const messageReceivedAt = performance.now(); - for (const dataSet of message.dataSets) { const pending = this.pendingSyncMetrics.get(dataSet.name); if (pending && dataSet.version >= pending.dataSetVersion) { - this.completeSyncMetrics(dataSet.name, messageReceivedAt); + this.completeSyncMetrics(dataSet.name); } } } @@ -1254,10 +1263,9 @@ class HashTreeParser { * Finalize pending sync metrics and invoke callback. * * @param {string} dataSetName - * @param {number} messageReceivedAt * @returns {void} */ - private completeSyncMetrics(dataSetName: string, messageReceivedAt: number): void { + private completeSyncMetrics(dataSetName: string): void { const pending = this.pendingSyncMetrics.get(dataSetName); if (!pending) { @@ -1265,19 +1273,17 @@ class HashTreeParser { } this.pendingSyncMetrics.delete(dataSetName); + this.syncLatencyTracker?.saveTimestamp({ + key: 'internal.client.locus.sync.message.received', + options: {dataSetName}, + }); + const syncLatency = this.syncLatencyTracker?.getLocusSyncLatency(dataSetName); - const syncMessageReceiveTime = Math.round(messageReceivedAt - pending.syncResponseReceivedAt); - const totalTime = Math.round(messageReceivedAt - pending.totalStartTime); - - const syncLatency: SyncLatencyMetrics = { - randomBackoffTime: pending.randomBackoffTime, - hashtreePrepTime: pending.hashtreePrepTime, - hashtreeResponseTime: pending.hashtreeResponseTime, - syncPrepTime: pending.syncPrepTime, - syncResponseTime: pending.syncResponseTime, - syncMessageReceiveTime, - totalTime, - }; + this.syncLatencyTracker?.clearLocusSyncLatency(dataSetName); + + if (!syncLatency) { + return; + } this.callbacks.syncMetricsCallback({ dataSet: pending.dataSetName, @@ -1381,10 +1387,20 @@ class HashTreeParser { const {hashTree} = dataSet; const rootHash = hashTree.getRootHash(); - const shouldCollectMetrics = !isInitialization && SYNC_METRICS_DATA_SETS.includes(dataSet.name); - const totalStart = shouldCollectMetrics ? performance.now() : 0; - let hashtreePrepStart = 0; - let hashtreeResponseTime = 0; + const shouldCollectMetrics = Boolean( + this.syncLatencyTracker && !isInitialization && SYNC_METRICS_DATA_SETS.includes(dataSet.name) + ); + let syncMetricsPending = false; + + if (shouldCollectMetrics) { + this.syncLatencyTracker?.saveTimestamp({ + key: 'internal.client.locus.sync.start', + options: { + dataSetName: dataSet.name, + randomBackoffTime: Math.round(dataSet.lastBackoffTime || 0), + }, + }); + } try { LoggerProxy.logger.info( @@ -1397,12 +1413,24 @@ class HashTreeParser { if (dataSet.leafCount !== 1) { let receivedHashes; - hashtreePrepStart = shouldCollectMetrics ? performance.now() : 0; + if (shouldCollectMetrics) { + this.syncLatencyTracker?.saveTimestamp({ + key: 'internal.client.locus.hashtree.request', + options: {dataSetName: dataSet.name}, + }); + } try { // request hashes from sender const hashesResult = await this.getHashesFromLocus(dataSet.name, rootHash); + if (shouldCollectMetrics) { + this.syncLatencyTracker?.saveTimestamp({ + key: 'internal.client.locus.hashtree.response', + options: {dataSetName: dataSet.name}, + }); + } + if (!hashesResult) { // hashes match, no sync needed return; @@ -1423,10 +1451,6 @@ class HashTreeParser { throw error; } - hashtreeResponseTime = shouldCollectMetrics - ? Math.round(performance.now() - hashtreePrepStart) - : 0; - // identify mismatched leaves const mismatchedLeaveIndexes = hashTree.diffHashes(receivedHashes); @@ -1447,7 +1471,13 @@ class HashTreeParser { } // request sync for mismatched leaves let syncResponse: HashTreeMessage | null = null; - const syncPrepStart = shouldCollectMetrics ? performance.now() : 0; + + if (shouldCollectMetrics) { + this.syncLatencyTracker?.saveTimestamp({ + key: 'internal.client.locus.sync.request', + options: {dataSetName: dataSet.name}, + }); + } if (isInitialization) { syncResponse = await this.sendSyncRequestToLocus(dataSet, {isInitialization: true}); @@ -1457,28 +1487,20 @@ class HashTreeParser { }); } - const syncResponseReceivedAt = shouldCollectMetrics ? performance.now() : 0; + if (shouldCollectMetrics) { + this.syncLatencyTracker?.saveTimestamp({ + key: 'internal.client.locus.sync.response', + options: {dataSetName: dataSet.name}, + }); + } // Record pending metrics and complete them when the matching LLM broadcast arrives. if (shouldCollectMetrics && syncResponse !== null) { - const hashtreePrepTimeVal = - hashtreePrepStart > 0 ? Math.round(hashtreePrepStart - totalStart) : 0; - const syncPrepTimeVal = Math.round( - syncPrepStart - (totalStart + hashtreePrepTimeVal + hashtreeResponseTime) - ); - const syncResponseTimeVal = Math.round(syncResponseReceivedAt - syncPrepStart); - this.pendingSyncMetrics.set(dataSet.name, { - syncResponseReceivedAt, - totalStartTime: totalStart, - randomBackoffTime: Math.round(dataSet.lastBackoffTime || 0), - hashtreePrepTime: hashtreePrepTimeVal, - hashtreeResponseTime, - syncPrepTime: syncPrepTimeVal, - syncResponseTime: syncResponseTimeVal, dataSetName: dataSet.name, dataSetVersion: dataSet.version, }); + syncMetricsPending = true; } // sync API may return nothing (in that case data will arrive via messages) @@ -1508,6 +1530,9 @@ class HashTreeParser { ); } } finally { + if (shouldCollectMetrics && !syncMetricsPending) { + this.syncLatencyTracker?.clearLocusSyncLatency(dataSet.name); + } dataSet.syncAbortController = undefined; } } diff --git a/packages/@webex/plugin-meetings/src/locus-info/index.ts b/packages/@webex/plugin-meetings/src/locus-info/index.ts index 700e0586717..628f9e2778b 100644 --- a/packages/@webex/plugin-meetings/src/locus-info/index.ts +++ b/packages/@webex/plugin-meetings/src/locus-info/index.ts @@ -37,6 +37,7 @@ import HashTreeParser, { LocusInfoUpdate, LocusInfoUpdateType, Metadata, + SyncLatencyTracker, SyncMetricsCallback, } from '../hashTree/hashTreeParser'; import {HashTreeObject, ObjectType, ObjectTypeToLocusKeyMap} from '../hashTree/types'; @@ -98,6 +99,7 @@ export type HashTreeParserEntry = { export type LocusInfoCallbacks = { updateMeeting: (object: any) => void; syncMetricsCallback: SyncMetricsCallback; + syncLatencyTracker?: SyncLatencyTracker; }; /** @@ -567,6 +569,7 @@ export default class LocusInfo extends EventsScope { callbacks: { locusInfoUpdateCallback: this.updateFromHashTree.bind(this, locusUrl), syncMetricsCallback: this.callbacks.syncMetricsCallback, + syncLatencyTracker: this.callbacks.syncLatencyTracker, }, debugId: `HT-${locusUrl.split('/')?.pop()?.substring(0, 4)}`, excludedDataSets: this.webex.config.meetings.locus?.excludedDataSets, diff --git a/packages/@webex/plugin-meetings/src/meeting/index.ts b/packages/@webex/plugin-meetings/src/meeting/index.ts index 196216d87ad..fcf3aa10026 100644 --- a/packages/@webex/plugin-meetings/src/meeting/index.ts +++ b/packages/@webex/plugin-meetings/src/meeting/index.ts @@ -1390,6 +1390,7 @@ export default class Meeting extends StatelessWebexPlugin { syncMetricsCallback: (metrics: {dataSet: string; syncLatency: SyncLatencyMetrics}) => { this.sendSyncCompleteMetric(metrics); }, + syncLatencyTracker: (this as any).webex.internal.newMetrics.callDiagnosticLatencies, }, this.webex, this.id diff --git a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts index bf7d3942da1..631ff1614bc 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts @@ -178,7 +178,8 @@ describe('HashTreeParser', () => { initialLocus: any = exampleInitialLocus, metadata: any = exampleMetadata, excludedDataSets?: string[], - syncMetricsCallback: sinon.SinonStub = sinon.stub() + syncMetricsCallback: sinon.SinonStub = sinon.stub(), + syncLatencyTracker?: any ) { return new HashTreeParser({ initialLocus, @@ -187,6 +188,7 @@ describe('HashTreeParser', () => { callbacks: { locusInfoUpdateCallback: callback, syncMetricsCallback, + syncLatencyTracker, }, debugId: 'test', excludedDataSets, @@ -5333,16 +5335,29 @@ describe('HashTreeParser', () => { describe('#syncMetrics', () => { it('invokes syncMetricsCallback when matching dataset version arrives', () => { const syncMetricsCallback = sinon.stub(); - const parser = createHashTreeParser(undefined, undefined, undefined, syncMetricsCallback); - - parser['pendingSyncMetrics'].set('main', { - syncResponseReceivedAt: 100, - totalStartTime: 50, + const syncLatency = { randomBackoffTime: 10, hashtreePrepTime: 5, hashtreeResponseTime: 20, syncPrepTime: 3, syncResponseTime: 15, + syncMessageReceiveTime: 7, + totalTime: 50, + }; + const syncLatencyTracker = { + saveTimestamp: sinon.stub(), + getLocusSyncLatency: sinon.stub().returns(syncLatency), + clearLocusSyncLatency: sinon.stub(), + }; + const parser = createHashTreeParser( + undefined, + undefined, + undefined, + syncMetricsCallback, + syncLatencyTracker + ); + + parser['pendingSyncMetrics'].set('main', { dataSetName: 'main', dataSetVersion: 1000, } as any); @@ -5363,13 +5378,13 @@ describe('HashTreeParser', () => { const arg = syncMetricsCallback.firstCall.args[0]; assert.equal(arg.dataSet, 'main'); - assert.isNumber(arg.syncLatency.randomBackoffTime); - assert.isNumber(arg.syncLatency.hashtreePrepTime); - assert.isNumber(arg.syncLatency.hashtreeResponseTime); - assert.isNumber(arg.syncLatency.syncPrepTime); - assert.isNumber(arg.syncLatency.syncResponseTime); - assert.isNumber(arg.syncLatency.syncMessageReceiveTime); - assert.isNumber(arg.syncLatency.totalTime); + assert.deepEqual(arg.syncLatency, syncLatency); + assert.calledOnceWithExactly(syncLatencyTracker.saveTimestamp, { + key: 'internal.client.locus.sync.message.received', + options: {dataSetName: 'main'}, + }); + assert.calledOnceWithExactly(syncLatencyTracker.getLocusSyncLatency, 'main'); + assert.calledOnceWithExactly(syncLatencyTracker.clearLocusSyncLatency, 'main'); assert.isFalse(parser['pendingSyncMetrics'].has('main')); }); @@ -5378,13 +5393,6 @@ describe('HashTreeParser', () => { const parser = createHashTreeParser(undefined, undefined, undefined, syncMetricsCallback); parser['pendingSyncMetrics'].set('main', { - syncResponseReceivedAt: 100, - totalStartTime: 50, - randomBackoffTime: 10, - hashtreePrepTime: 5, - hashtreeResponseTime: 20, - syncPrepTime: 3, - syncResponseTime: 15, dataSetName: 'main', dataSetVersion: 1005, } as any); From 35ba5211a36b32a10197441f5dc65272cc1c28a7 Mon Sep 17 00:00:00 2001 From: tiahan Date: Thu, 28 May 2026 16:13:26 +0800 Subject: [PATCH 06/29] fix(metrics): record sync HTTP latency timestamps at request boundaries --- .../src/hashTree/hashTreeParser.ts | 73 +++++++++++-------- 1 file changed, 42 insertions(+), 31 deletions(-) diff --git a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts index df420823bf2..9ceb92abaaf 100644 --- a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts @@ -1259,6 +1259,19 @@ class HashTreeParser { } } + /** + * Checks if Locus sync latency metrics should be collected for a dataset. + * + * @param {string} dataSetName dataset name + * @param {boolean} [isInitialization=false] whether this is an initialization sync + * @returns {boolean} + */ + private shouldCollectSyncMetrics(dataSetName: string, isInitialization = false): boolean { + return Boolean( + this.syncLatencyTracker && !isInitialization && SYNC_METRICS_DATA_SETS.includes(dataSetName) + ); + } + /** * Finalize pending sync metrics and invoke callback. * @@ -1387,9 +1400,7 @@ class HashTreeParser { const {hashTree} = dataSet; const rootHash = hashTree.getRootHash(); - const shouldCollectMetrics = Boolean( - this.syncLatencyTracker && !isInitialization && SYNC_METRICS_DATA_SETS.includes(dataSet.name) - ); + const shouldCollectMetrics = this.shouldCollectSyncMetrics(dataSet.name, isInitialization); let syncMetricsPending = false; if (shouldCollectMetrics) { @@ -1413,24 +1424,10 @@ class HashTreeParser { if (dataSet.leafCount !== 1) { let receivedHashes; - if (shouldCollectMetrics) { - this.syncLatencyTracker?.saveTimestamp({ - key: 'internal.client.locus.hashtree.request', - options: {dataSetName: dataSet.name}, - }); - } - try { // request hashes from sender const hashesResult = await this.getHashesFromLocus(dataSet.name, rootHash); - if (shouldCollectMetrics) { - this.syncLatencyTracker?.saveTimestamp({ - key: 'internal.client.locus.hashtree.response', - options: {dataSetName: dataSet.name}, - }); - } - if (!hashesResult) { // hashes match, no sync needed return; @@ -1472,13 +1469,6 @@ class HashTreeParser { // request sync for mismatched leaves let syncResponse: HashTreeMessage | null = null; - if (shouldCollectMetrics) { - this.syncLatencyTracker?.saveTimestamp({ - key: 'internal.client.locus.sync.request', - options: {dataSetName: dataSet.name}, - }); - } - if (isInitialization) { syncResponse = await this.sendSyncRequestToLocus(dataSet, {isInitialization: true}); } else if (Object.keys(leavesData).length > 0) { @@ -1487,13 +1477,6 @@ class HashTreeParser { }); } - if (shouldCollectMetrics) { - this.syncLatencyTracker?.saveTimestamp({ - key: 'internal.client.locus.sync.response', - options: {dataSetName: dataSet.name}, - }); - } - // Record pending metrics and complete them when the matching LLM broadcast arrives. if (shouldCollectMetrics && syncResponse !== null) { this.pendingSyncMetrics.set(dataSet.name, { @@ -2048,6 +2031,13 @@ class HashTreeParser { const url = `${dataSet.url}/hashtree`; + if (this.shouldCollectSyncMetrics(dataSetName)) { + this.syncLatencyTracker?.saveTimestamp({ + key: 'internal.client.locus.hashtree.request', + options: {dataSetName}, + }); + } + return this.webexRequest({ method: HTTP_VERBS.GET, uri: url, @@ -2056,6 +2046,13 @@ class HashTreeParser { }, }) .then((response) => { + if (this.shouldCollectSyncMetrics(dataSetName)) { + this.syncLatencyTracker?.saveTimestamp({ + key: 'internal.client.locus.hashtree.response', + options: {dataSetName}, + }); + } + if (!response.body || isEmpty(response.body)) { // 204 with empty body means our hashes match Locus, no sync needed LoggerProxy.logger.info( @@ -2149,6 +2146,13 @@ class HashTreeParser { const ourCurrentRootHash = dataSet.hashTree ? dataSet.hashTree.getRootHash() : EMPTY_HASH; + if (this.shouldCollectSyncMetrics(dataSet.name, isInitialization)) { + this.syncLatencyTracker?.saveTimestamp({ + key: 'internal.client.locus.sync.request', + options: {dataSetName: dataSet.name}, + }); + } + return this.webexRequest({ method: HTTP_VERBS.POST, uri: url, @@ -2158,6 +2162,13 @@ class HashTreeParser { body, }) .then((resp) => { + if (this.shouldCollectSyncMetrics(dataSet.name, isInitialization)) { + this.syncLatencyTracker?.saveTimestamp({ + key: 'internal.client.locus.sync.response', + options: {dataSetName: dataSet.name}, + }); + } + if (!resp.body || isEmpty(resp.body)) { LoggerProxy.logger.info( `HashTreeParser#sendSyncRequestToLocus --> ${this.debugId} Got ${resp.statusCode} with empty body for sync request for data set "${dataSet.name}", data should arrive via messages` From e8311a9a6c64c5d7f0ae344db2a5ba399d765ff8 Mon Sep 17 00:00:00 2001 From: tiahan Date: Thu, 28 May 2026 16:26:24 +0800 Subject: [PATCH 07/29] refactor(metrics): simplify sync backoff tracking --- .../@webex/plugin-meetings/src/hashTree/hashTreeParser.ts | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts index 9ceb92abaaf..da905429e53 100644 --- a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts @@ -1791,16 +1791,18 @@ class HashTreeParser { dataSet.hashTree.resize(receivedDataSet.leafCount); - const delay = dataSet.idleMs + this.getWeightedBackoffTime(dataSet.backoff); + const randomBackoffTime = this.getWeightedBackoffTime(dataSet.backoff); + const delay = dataSet.idleMs + randomBackoffTime; if (delay > 0) { if (dataSet.timer) { clearTimeout(dataSet.timer); } + dataSet.lastBackoffTime = randomBackoffTime; + dataSet.timer = setTimeout(() => { dataSet.timer = undefined; - dataSet.lastBackoffTime = delay - dataSet.idleMs; if (!dataSet.hashTree) { LoggerProxy.logger.warn( From f9875b0a7cf6b625c4742da0929cafb5af6bbf13 Mon Sep 17 00:00:00 2001 From: tiahan Date: Mon, 1 Jun 2026 15:35:29 +0800 Subject: [PATCH 08/29] fix(meetings): preserve breakout join metric without LLM latency --- .../plugin-meetings/src/breakouts/events.ts | 25 +++++++++++-------- .../test/unit/spec/breakouts/events.ts | 16 ++++++++++-- 2 files changed, 29 insertions(+), 12 deletions(-) diff --git a/packages/@webex/plugin-meetings/src/breakouts/events.ts b/packages/@webex/plugin-meetings/src/breakouts/events.ts index b4556bf7283..fa88ccd35e3 100644 --- a/packages/@webex/plugin-meetings/src/breakouts/events.ts +++ b/packages/@webex/plugin-meetings/src/breakouts/events.ts @@ -39,23 +39,28 @@ const breakoutEvent: { const {breakoutMoveId, currentSession, error, llmLatency, llmWebsocketUrl, meeting} = eventInfo; - if (event === 'client.breakout-session.join.response' && !llmLatency) { - return; - } if (!meeting.meetingInfo?.enableConvergedArchitecture) { return; } + const identifiers: any = { + breakoutMoveId, + breakoutSessionId: currentSession?.sessionId, + breakoutGroupId: currentSession?.groupId, + }; + + if (llmWebsocketUrl) { + identifiers.llmWebsocketUrl = llmWebsocketUrl; + } + const payload: any = { - llmLatency, - identifiers: { - breakoutMoveId, - breakoutSessionId: currentSession?.sessionId, - breakoutGroupId: currentSession?.groupId, - llmWebsocketUrl, - }, + identifiers, }; + if (llmLatency) { + payload.llmLatency = llmLatency; + } + const options: any = { meetingId: meeting.id, }; diff --git a/packages/@webex/plugin-meetings/test/unit/spec/breakouts/events.ts b/packages/@webex/plugin-meetings/test/unit/spec/breakouts/events.ts index ccde056381f..c15f62439e3 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/breakouts/events.ts +++ b/packages/@webex/plugin-meetings/test/unit/spec/breakouts/events.ts @@ -5,6 +5,7 @@ import breakoutEvent from "../../../../src/breakouts/events"; describe('plugin-meetings', () => { describe('breakoutEvent', () => { + const originalPostMoveCallAnalyzer = breakoutEvent.postMoveCallAnalyzer; let webex; let mockMeeting = {}; let breakoutMoveId; @@ -24,6 +25,7 @@ describe('plugin-meetings', () => { groupId: "groupId", }; breakoutMoveId = 'breakoutMoveId'; + breakoutEvent.postMoveCallAnalyzer = originalPostMoveCallAnalyzer; }); describe('postMoveCallAnalyzer', () => { @@ -103,7 +105,7 @@ describe('plugin-meetings', () => { assert.calledWith(breakoutEvent.postMoveCallAnalyzer, 'client.breakout-session.join.response', eventInfo, submitClientEvent); }); - it('does not emit join response metric without llmLatency', () => { + it('emits join response metric without llmLatency', () => { const submitClientEvent = sinon.stub(); breakoutEvent.postMoveCallAnalyzer( @@ -112,7 +114,17 @@ describe('plugin-meetings', () => { submitClientEvent ); - assert.notCalled(submitClientEvent); + assert.calledOnceWithExactly(submitClientEvent, { + name: 'client.breakout-session.join.response', + payload: { + identifiers: { + breakoutMoveId: 'breakoutMoveId', + breakoutSessionId: 'sessionId', + breakoutGroupId: 'groupId', + }, + }, + options: {meetingId: 'activeMeetingId'}, + }); }); }); From a4dbd7decf53d702dacfbe128d13d96399e02032 Mon Sep 17 00:00:00 2001 From: tiahan Date: Mon, 1 Jun 2026 15:36:44 +0800 Subject: [PATCH 09/29] fix(meetings): preserve watchdog backoff in sync metrics --- .../src/hashTree/hashTreeParser.ts | 2 + .../test/unit/spec/hashTree/hashTreeParser.ts | 52 +++++++++++++++++++ 2 files changed, 54 insertions(+) diff --git a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts index da905429e53..3ca7381bd15 100644 --- a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts @@ -1857,6 +1857,8 @@ class HashTreeParser { const backoffTime = this.getWeightedBackoffTime(dataSet.backoff); const delay = heartbeatIntervalMs + backoffTime; + dataSet.lastBackoffTime = backoffTime; + dataSet.heartbeatWatchdogTimer = setTimeout(() => { dataSet.heartbeatWatchdogTimer = undefined; diff --git a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts index 631ff1614bc..1d2f6159b38 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts @@ -3103,6 +3103,58 @@ describe('HashTreeParser', () => { ); }); + it('uses the watchdog random backoff when reporting sync metrics', async () => { + const syncLatencyTracker = { + saveTimestamp: sinon.stub(), + getLocusSyncLatency: sinon.stub(), + clearLocusSyncLatency: sinon.stub(), + }; + const parser = createHashTreeParser( + undefined, + undefined, + undefined, + sinon.stub(), + syncLatencyTracker + ); + const heartbeatIntervalMs = 5000; + const mainDataSetUrl = parser.dataSets.main.url; + + mathRandomStub.onFirstCall().returns(0.1); // root-hash timer backoff = 10ms + mathRandomStub.onSecondCall().returns(0.5); // watchdog backoff = 250ms + mathRandomStub.returns(0); + + parser.handleMessage( + { + dataSets: [ + { + ...createDataSet('main', 16, 1100), + root: parser.dataSets.main.hashTree.getRootHash(), + }, + ], + visibleDataSetsUrl, + locusUrl, + }, + 'initial heartbeat' + ); + + mockGetHashesFromLocusResponse( + mainDataSetUrl, + new Array(16).fill('00000000000000000000000000000000'), + createDataSet('main', 16, 1101) + ); + mockSendSyncRequestResponse(mainDataSetUrl, null); + + await clock.tickAsync(heartbeatIntervalMs + 250); + + assert.calledWith(syncLatencyTracker.saveTimestamp, { + key: 'internal.client.locus.sync.start', + options: { + dataSetName: 'main', + randomBackoffTime: 250, + }, + }); + }); + it('calls POST sync directly for leafCount === 1 data sets', async () => { const parser = createHashTreeParser(); const heartbeatIntervalMs = 5000; From dc5d4e74da85a833e2618b153498589f743e16bb Mon Sep 17 00:00:00 2001 From: tiahan Date: Mon, 1 Jun 2026 15:41:53 +0800 Subject: [PATCH 10/29] fix(meetings): retain sync metrics for empty sync responses --- .../src/hashTree/hashTreeParser.ts | 5 +- .../test/unit/spec/hashTree/hashTreeParser.ts | 58 +++++++++++++++++++ 2 files changed, 62 insertions(+), 1 deletion(-) diff --git a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts index 3ca7381bd15..9d774f2ed96 100644 --- a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts @@ -1468,17 +1468,20 @@ class HashTreeParser { } // request sync for mismatched leaves let syncResponse: HashTreeMessage | null = null; + let syncRequestSent = false; if (isInitialization) { syncResponse = await this.sendSyncRequestToLocus(dataSet, {isInitialization: true}); + syncRequestSent = true; } else if (Object.keys(leavesData).length > 0) { syncResponse = await this.sendSyncRequestToLocus(dataSet, { mismatchedLeavesData: leavesData, }); + syncRequestSent = true; } // Record pending metrics and complete them when the matching LLM broadcast arrives. - if (shouldCollectMetrics && syncResponse !== null) { + if (shouldCollectMetrics && syncRequestSent) { this.pendingSyncMetrics.set(dataSet.name, { dataSetName: dataSet.name, dataSetVersion: dataSet.version, diff --git a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts index 1d2f6159b38..f0fb1cadc14 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts @@ -5385,6 +5385,64 @@ describe('HashTreeParser', () => { }); describe('#syncMetrics', () => { + it('records pending metrics when sync response has empty body', async () => { + const syncMetricsCallback = sinon.stub(); + const syncLatency = { + randomBackoffTime: 0, + hashtreePrepTime: 5, + hashtreeResponseTime: 20, + syncPrepTime: 3, + syncResponseTime: 15, + syncMessageReceiveTime: 7, + totalTime: 50, + }; + const syncLatencyTracker = { + saveTimestamp: sinon.stub(), + getLocusSyncLatency: sinon.stub().returns(syncLatency), + clearLocusSyncLatency: sinon.stub(), + }; + const parser = createHashTreeParser( + undefined, + undefined, + undefined, + syncMetricsCallback, + syncLatencyTracker + ); + const mainDataSetUrl = parser.dataSets.main.url; + + mockGetHashesFromLocusResponse( + mainDataSetUrl, + new Array(16).fill('00000000000000000000000000000000'), + createDataSet('main', 16, 1101) + ); + mockSendSyncRequestResponse(mainDataSetUrl, null); + + parser.handleMessage( + createHeartbeatMessage('main', 16, 1100, 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa1'), + 'trigger sync metrics' + ); + + await clock.tickAsync(1000); + + assert.isTrue(parser['pendingSyncMetrics'].has('main')); + assert.notCalled(syncMetricsCallback); + + parser.handleMessage({ + dataSets: [ + { + ...createDataSet('main', 16, 1101), + root: 'newroot', + }, + ], + visibleDataSetsUrl, + locusUrl, + locusStateElements: [], + }); + + assert.calledOnce(syncMetricsCallback); + assert.isFalse(parser['pendingSyncMetrics'].has('main')); + }); + it('invokes syncMetricsCallback when matching dataset version arrives', () => { const syncMetricsCallback = sinon.stub(); const syncLatency = { From b06fcd036d886e05dba7e5f9a8f526c50e51de83 Mon Sep 17 00:00:00 2001 From: tiahan Date: Mon, 1 Jun 2026 15:49:43 +0800 Subject: [PATCH 11/29] fix(meetings): preserve syncAll backoff in sync metrics --- .../src/hashTree/hashTreeParser.ts | 1 + .../test/unit/spec/hashTree/hashTreeParser.ts | 38 +++++++++++++++++++ 2 files changed, 39 insertions(+) diff --git a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts index 9d774f2ed96..6fddf9e686b 100644 --- a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts @@ -1744,6 +1744,7 @@ class HashTreeParser { ); for (const ds of effectiveDataSetsToSync) { + this.dataSets[ds.name].lastBackoffTime = delay; this.enqueueSyncForDataset(ds.name, 'syncAllDatasets'); } diff --git a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts index f0fb1cadc14..fd428f59c88 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts @@ -4755,6 +4755,44 @@ describe('HashTreeParser', () => { assert.neverCalledWith(webexRequest, sinon.match({method: 'GET', uri: `${selfUrl}/hashtree`})); }); + it('uses the syncAll random backoff when reporting sync metrics', async () => { + mathRandomStub.returns(0.5); // syncAll backoff = 0.5^2 * 1000 = 250ms + + const syncLatencyTracker = { + saveTimestamp: sinon.stub(), + getLocusSyncLatency: sinon.stub(), + clearLocusSyncLatency: sinon.stub(), + }; + const parser = createHashTreeParser( + undefined, + undefined, + ['atd-unmuted'], + sinon.stub(), + syncLatencyTracker + ); + const mainUrl = parser.dataSets.main.url; + + mockGetHashesFromLocusResponse( + mainUrl, + new Array(16).fill('00000000000000000000000000000000'), + createDataSet('main', 16, 1100) + ); + mockSendSyncRequestResponse(mainUrl, null); + + const syncAllPromise = parser.syncAllDatasets({onlyLLM: true}); + + await clock.tickAsync(250); + await syncAllPromise; + + assert.calledWith(syncLatencyTracker.saveTimestamp, { + key: 'internal.client.locus.sync.start', + options: { + dataSetName: 'main', + randomBackoffTime: 250, + }, + }); + }); + it('should upgrade scope from onlyLLM=true to all datasets when onlyLLM=false call arrives during backoff', async () => { // Make Math.random return 1 so backoff = 1^2 * 1000 = 1000ms (non-zero delay for interleaving) mathRandomStub.returns(1); From d151ef7b620bd2fe3585bf44b65cd1720d8fcc2d Mon Sep 17 00:00:00 2001 From: tiahan Date: Mon, 1 Jun 2026 15:56:53 +0800 Subject: [PATCH 12/29] fix(metrics): scope locus sync latency by meeting --- .../call-diagnostic-metrics-latencies.ts | 28 +++++-- .../call-diagnostic-metrics-latencies.ts | 69 ++++++++++++++++ .../src/hashTree/hashTreeParser.ts | 81 +++++++++++++++---- .../plugin-meetings/src/locus-info/index.ts | 1 + .../test/unit/spec/hashTree/hashTreeParser.ts | 55 ++++++++++++- 5 files changed, 212 insertions(+), 22 deletions(-) diff --git a/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts b/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts index 1d0cbff5cf4..ad9947babe6 100644 --- a/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts +++ b/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts @@ -8,6 +8,7 @@ import {MetricEventNames, PreComputedLatencies} from '../metrics.types'; // we only care about client event and feature event for now type LocusSyncLatencyMilestone = { + meetingId?: string; dataSetName: string; key: MetricEventNames; value: number; @@ -66,9 +67,10 @@ export default class CallDiagnosticLatencies extends WebexPlugin { /** * Clear tracked Locus sync latency state for a dataset. * @param dataSetName dataset name + * @param meetingId meeting id */ - public clearLocusSyncLatency(dataSetName: string) { - this.locusSyncLatencies.delete(dataSetName); + public clearLocusSyncLatency(dataSetName: string, meetingId?: string) { + this.locusSyncLatencies.delete(this.getLocusSyncLatencyKey(dataSetName, meetingId)); } /** @@ -76,8 +78,8 @@ export default class CallDiagnosticLatencies extends WebexPlugin { * @param dataSetName dataset name * @returns sync latency metrics */ - public getLocusSyncLatency(dataSetName: string) { - const record = this.locusSyncLatencies.get(dataSetName); + public getLocusSyncLatency(dataSetName: string, meetingId?: string) { + const record = this.locusSyncLatencies.get(this.getLocusSyncLatencyKey(dataSetName, meetingId)); if (!record) { return undefined; @@ -169,6 +171,16 @@ export default class CallDiagnosticLatencies extends WebexPlugin { return Math.round(clamp(latency, 0, this.MAX_INTEGER)); } + /** + * Build a storage key for Locus sync latency records. + * @param dataSetName dataset name + * @param meetingId meeting id + * @returns storage key + */ + private getLocusSyncLatencyKey(dataSetName: string, meetingId?: string) { + return meetingId ? `${meetingId}:${dataSetName}` : dataSetName; + } + /** * Checks if metric event name is a Locus sync latency milestone. * @param key event name @@ -190,13 +202,16 @@ export default class CallDiagnosticLatencies extends WebexPlugin { * @param options options */ private saveLocusSyncLatencyTimestamp({ + meetingId, dataSetName, key, value, randomBackoffTime = 0, }: LocusSyncLatencyMilestone & {randomBackoffTime?: number}) { + const recordKey = this.getLocusSyncLatencyKey(dataSetName, meetingId); + if (key === 'internal.client.locus.sync.start') { - this.locusSyncLatencies.set(dataSetName, { + this.locusSyncLatencies.set(recordKey, { randomBackoffTime, syncStart: value, }); @@ -204,7 +219,7 @@ export default class CallDiagnosticLatencies extends WebexPlugin { return; } - const record = this.locusSyncLatencies.get(dataSetName); + const record = this.locusSyncLatencies.get(recordKey); if (!record) { return; @@ -277,6 +292,7 @@ export default class CallDiagnosticLatencies extends WebexPlugin { if (this.isLocusSyncLatencyEvent(key) && options.dataSetName) { this.saveLocusSyncLatencyTimestamp({ + meetingId: options.meetingId, dataSetName: options.dataSetName, key, value, diff --git a/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts b/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts index 8bd7637d2d2..f56de987f92 100644 --- a/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts +++ b/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts @@ -199,6 +199,75 @@ describe('internal-plugin-metrics', () => { }); }); + it('keys sync latency records by meeting id', () => { + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.start', + value: 100, + options: {meetingId: 'meeting-1', dataSetName: 'main', randomBackoffTime: 10}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.request', + value: 110, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, + }); + + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.start', + value: 200, + options: {meetingId: 'meeting-2', dataSetName: 'main', randomBackoffTime: 20}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.request', + value: 220, + options: {meetingId: 'meeting-2', dataSetName: 'main'}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.response', + value: 240, + options: {meetingId: 'meeting-2', dataSetName: 'main'}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.message.received', + value: 260, + options: {meetingId: 'meeting-2', dataSetName: 'main'}, + }); + + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.response', + value: 125, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.message.received', + value: 150, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, + }); + + assert.deepEqual(cdl.getLocusSyncLatency('main', 'meeting-1'), { + randomBackoffTime: 10, + hashtreePrepTime: 0, + hashtreeResponseTime: 0, + syncPrepTime: 10, + syncResponseTime: 15, + syncMessageReceiveTime: 25, + totalTime: 50, + }); + assert.deepEqual(cdl.getLocusSyncLatency('main', 'meeting-2'), { + randomBackoffTime: 20, + hashtreePrepTime: 0, + hashtreeResponseTime: 0, + syncPrepTime: 20, + syncResponseTime: 20, + syncMessageReceiveTime: 20, + totalTime: 60, + }); + + cdl.clearLocusSyncLatency('main', 'meeting-1'); + + assert.isUndefined(cdl.getLocusSyncLatency('main', 'meeting-1')); + assert.isDefined(cdl.getLocusSyncLatency('main', 'meeting-2')); + }); + it('returns undefined and clears state when required milestones are missing', () => { cdl.saveTimestamp({ key: 'internal.client.locus.sync.start', diff --git a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts index 6fddf9e686b..563661283cf 100644 --- a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts @@ -110,10 +110,10 @@ export type SyncLatencyTracker = { | 'internal.client.locus.sync.request' | 'internal.client.locus.sync.response' | 'internal.client.locus.sync.message.received'; - options: {dataSetName: string; randomBackoffTime?: number}; + options: {meetingId?: string; dataSetName: string; randomBackoffTime?: number}; }) => void; - getLocusSyncLatency: (dataSetName: string) => SyncLatencyMetrics | undefined; - clearLocusSyncLatency: (dataSetName: string) => void; + getLocusSyncLatency: (dataSetName: string, meetingId?: string) => SyncLatencyMetrics | undefined; + clearLocusSyncLatency: (dataSetName: string, meetingId?: string) => void; }; export type HashTreeParserCallbacks = { @@ -173,6 +173,7 @@ class HashTreeParser { webexRequest: WebexRequestMethod; private callbacks: HashTreeParserCallbacks; private syncLatencyTracker?: SyncLatencyTracker; + private syncLatencyMeetingId?: string; visibleDataSets: VisibleDataSetInfo[]; debugId: string; private excludedDataSets: string[]; @@ -203,6 +204,7 @@ class HashTreeParser { callbacks: HashTreeParserCallbacks; debugId: string; excludedDataSets?: string[]; + syncLatencyMeetingId?: string; }) { const {dataSets, locus} = options.initialLocus; // extract dataSets from initialLocus @@ -210,6 +212,7 @@ class HashTreeParser { this.webexRequest = options.webexRequest; this.callbacks = options.callbacks; this.syncLatencyTracker = options.callbacks.syncLatencyTracker; + this.syncLatencyMeetingId = options.syncLatencyMeetingId; this.excludedDataSets = options.excludedDataSets || []; this.visibleDataSetsUrl = locus?.links?.resources?.visibleDataSets?.url; this.setVisibleDataSets(options.metadata?.visibleDataSets || [], dataSets); @@ -1272,6 +1275,54 @@ class HashTreeParser { ); } + /** + * Build options for a Locus sync latency milestone. + * @param {string} dataSetName dataset name + * @param {number} [randomBackoffTime] random backoff time + * @returns {object} sync latency timestamp options + */ + private getSyncLatencyTimestampOptions(dataSetName: string, randomBackoffTime?: number) { + const options: {meetingId?: string; dataSetName: string; randomBackoffTime?: number} = { + dataSetName, + }; + + if (this.syncLatencyMeetingId) { + options.meetingId = this.syncLatencyMeetingId; + } + + if (typeof randomBackoffTime === 'number') { + options.randomBackoffTime = randomBackoffTime; + } + + return options; + } + + /** + * Get Locus sync latency using this parser's meeting scope when available. + * @param {string} dataSetName dataset name + * @returns {SyncLatencyMetrics|undefined} sync latency metrics + */ + private getLocusSyncLatency(dataSetName: string): SyncLatencyMetrics | undefined { + return this.syncLatencyMeetingId + ? this.syncLatencyTracker?.getLocusSyncLatency(dataSetName, this.syncLatencyMeetingId) + : this.syncLatencyTracker?.getLocusSyncLatency(dataSetName); + } + + /** + * Clear Locus sync latency using this parser's meeting scope when available. + * @param {string} dataSetName dataset name + * @returns {void} + */ + private clearLocusSyncLatency(dataSetName: string): void { + if (this.syncLatencyMeetingId) { + this.syncLatencyTracker?.clearLocusSyncLatency(dataSetName, this.syncLatencyMeetingId); + + return; + } + + this.syncLatencyTracker?.clearLocusSyncLatency(dataSetName); + } + /** * Finalize pending sync metrics and invoke callback. * @@ -1288,11 +1339,11 @@ class HashTreeParser { this.pendingSyncMetrics.delete(dataSetName); this.syncLatencyTracker?.saveTimestamp({ key: 'internal.client.locus.sync.message.received', - options: {dataSetName}, + options: this.getSyncLatencyTimestampOptions(dataSetName), }); - const syncLatency = this.syncLatencyTracker?.getLocusSyncLatency(dataSetName); + const syncLatency = this.getLocusSyncLatency(dataSetName); - this.syncLatencyTracker?.clearLocusSyncLatency(dataSetName); + this.clearLocusSyncLatency(dataSetName); if (!syncLatency) { return; @@ -1406,10 +1457,10 @@ class HashTreeParser { if (shouldCollectMetrics) { this.syncLatencyTracker?.saveTimestamp({ key: 'internal.client.locus.sync.start', - options: { - dataSetName: dataSet.name, - randomBackoffTime: Math.round(dataSet.lastBackoffTime || 0), - }, + options: this.getSyncLatencyTimestampOptions( + dataSet.name, + Math.round(dataSet.lastBackoffTime || 0) + ), }); } @@ -1517,7 +1568,7 @@ class HashTreeParser { } } finally { if (shouldCollectMetrics && !syncMetricsPending) { - this.syncLatencyTracker?.clearLocusSyncLatency(dataSet.name); + this.clearLocusSyncLatency(dataSet.name); } dataSet.syncAbortController = undefined; } @@ -2042,7 +2093,7 @@ class HashTreeParser { if (this.shouldCollectSyncMetrics(dataSetName)) { this.syncLatencyTracker?.saveTimestamp({ key: 'internal.client.locus.hashtree.request', - options: {dataSetName}, + options: this.getSyncLatencyTimestampOptions(dataSetName), }); } @@ -2057,7 +2108,7 @@ class HashTreeParser { if (this.shouldCollectSyncMetrics(dataSetName)) { this.syncLatencyTracker?.saveTimestamp({ key: 'internal.client.locus.hashtree.response', - options: {dataSetName}, + options: this.getSyncLatencyTimestampOptions(dataSetName), }); } @@ -2157,7 +2208,7 @@ class HashTreeParser { if (this.shouldCollectSyncMetrics(dataSet.name, isInitialization)) { this.syncLatencyTracker?.saveTimestamp({ key: 'internal.client.locus.sync.request', - options: {dataSetName: dataSet.name}, + options: this.getSyncLatencyTimestampOptions(dataSet.name), }); } @@ -2173,7 +2224,7 @@ class HashTreeParser { if (this.shouldCollectSyncMetrics(dataSet.name, isInitialization)) { this.syncLatencyTracker?.saveTimestamp({ key: 'internal.client.locus.sync.response', - options: {dataSetName: dataSet.name}, + options: this.getSyncLatencyTimestampOptions(dataSet.name), }); } diff --git a/packages/@webex/plugin-meetings/src/locus-info/index.ts b/packages/@webex/plugin-meetings/src/locus-info/index.ts index 628f9e2778b..9a2162d05ca 100644 --- a/packages/@webex/plugin-meetings/src/locus-info/index.ts +++ b/packages/@webex/plugin-meetings/src/locus-info/index.ts @@ -573,6 +573,7 @@ export default class LocusInfo extends EventsScope { }, debugId: `HT-${locusUrl.split('/')?.pop()?.substring(0, 4)}`, excludedDataSets: this.webex.config.meetings.locus?.excludedDataSets, + syncLatencyMeetingId: this.meetingId, }); // When a new HashTreeParser is created, previous one should be stopped. diff --git a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts index fd428f59c88..e9927f7d0ec 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts @@ -179,7 +179,8 @@ describe('HashTreeParser', () => { metadata: any = exampleMetadata, excludedDataSets?: string[], syncMetricsCallback: sinon.SinonStub = sinon.stub(), - syncLatencyTracker?: any + syncLatencyTracker?: any, + syncLatencyMeetingId?: string ) { return new HashTreeParser({ initialLocus, @@ -192,6 +193,7 @@ describe('HashTreeParser', () => { }, debugId: 'test', excludedDataSets, + syncLatencyMeetingId, }); } @@ -5536,6 +5538,57 @@ describe('HashTreeParser', () => { assert.isFalse(parser['pendingSyncMetrics'].has('main')); }); + it('scopes sync metrics tracker records by meeting id', () => { + const syncMetricsCallback = sinon.stub(); + const syncLatency = { + randomBackoffTime: 10, + hashtreePrepTime: 1, + hashtreeResponseTime: 2, + syncPrepTime: 3, + syncResponseTime: 4, + syncMessageReceiveTime: 5, + totalTime: 15, + }; + const syncLatencyTracker = { + saveTimestamp: sinon.stub(), + getLocusSyncLatency: sinon.stub().returns(syncLatency), + clearLocusSyncLatency: sinon.stub(), + }; + const parser = createHashTreeParser( + undefined, + undefined, + undefined, + syncMetricsCallback, + syncLatencyTracker, + 'meeting-1' + ); + + parser['pendingSyncMetrics'].set('main', { + dataSetName: 'main', + dataSetVersion: 1000, + } as any); + + parser.handleMessage({ + dataSets: [ + { + ...createDataSet('main', 16, 1001), + root: 'newroot', + }, + ], + visibleDataSetsUrl, + locusUrl, + locusStateElements: [], + }); + + assert.calledOnceWithExactly(syncLatencyTracker.saveTimestamp, { + key: 'internal.client.locus.sync.message.received', + options: {meetingId: 'meeting-1', dataSetName: 'main'}, + }); + assert.calledOnceWithExactly(syncLatencyTracker.getLocusSyncLatency, 'main', 'meeting-1'); + assert.calledOnceWithExactly(syncLatencyTracker.clearLocusSyncLatency, 'main', 'meeting-1'); + assert.calledOnce(syncMetricsCallback); + }); + it('does not complete pending metrics when message version is below pending version', () => { const syncMetricsCallback = sinon.stub(); const parser = createHashTreeParser(undefined, undefined, undefined, syncMetricsCallback); From b243decc73edba4360e9aba58781970e129ecdb1 Mon Sep 17 00:00:00 2001 From: tiahan Date: Mon, 1 Jun 2026 16:15:58 +0800 Subject: [PATCH 13/29] fix(meetings): dedupe breakout join response metrics --- .../plugin-meetings/src/breakouts/events.ts | 8 +++ .../plugin-meetings/src/meeting/index.ts | 62 +++++++++---------- .../test/unit/spec/breakouts/events.ts | 32 ++++++++++ .../test/unit/spec/meeting/index.js | 29 +++++++++ 4 files changed, 98 insertions(+), 33 deletions(-) diff --git a/packages/@webex/plugin-meetings/src/breakouts/events.ts b/packages/@webex/plugin-meetings/src/breakouts/events.ts index fa88ccd35e3..c3a1904b447 100644 --- a/packages/@webex/plugin-meetings/src/breakouts/events.ts +++ b/packages/@webex/plugin-meetings/src/breakouts/events.ts @@ -43,6 +43,14 @@ const breakoutEvent: { return; } + if ( + event === 'client.breakout-session.join.response' && + typeof meeting.shouldEmitBreakoutJoinResponseMetric === 'function' && + !meeting.shouldEmitBreakoutJoinResponseMetric(breakoutMoveId) + ) { + return; + } + const identifiers: any = { breakoutMoveId, breakoutSessionId: currentSession?.sessionId, diff --git a/packages/@webex/plugin-meetings/src/meeting/index.ts b/packages/@webex/plugin-meetings/src/meeting/index.ts index fcf3aa10026..29671a712a8 100644 --- a/packages/@webex/plugin-meetings/src/meeting/index.ts +++ b/packages/@webex/plugin-meetings/src/meeting/index.ts @@ -6804,22 +6804,20 @@ export default class Meeting extends StatelessWebexPlugin { const breakoutMoveId = this.breakouts?.breakoutMoveId; - if (this.shouldEmitBreakoutJoinResponseMetric(breakoutMoveId)) { - // @ts-ignore - const llmWebsocketUrl = this.webex.internal.llm.getWebSocketUrl?.() || undefined; + // @ts-ignore + const llmWebsocketUrl = this.webex.internal.llm.getWebSocketUrl?.() || undefined; - breakoutEvent.onBreakoutJoinResponse( - { - currentSession: this.breakouts?.currentBreakoutSession, - meeting: this, - breakoutMoveId, - llmLatency: registerAndConnectResult, - llmWebsocketUrl, - }, - // @ts-ignore - this.webex.internal.newMetrics.submitClientEvent.bind(this.webex.internal.newMetrics) - ); - } + breakoutEvent.onBreakoutJoinResponse( + { + currentSession: this.breakouts?.currentBreakoutSession, + meeting: this, + breakoutMoveId, + llmLatency: registerAndConnectResult, + llmWebsocketUrl, + }, + // @ts-ignore + this.webex.internal.newMetrics.submitClientEvent.bind(this.webex.internal.newMetrics) + ); } return Promise.resolve(registerAndConnectResult); @@ -6837,26 +6835,24 @@ export default class Meeting extends StatelessWebexPlugin { const breakoutMoveId = this.breakouts?.breakoutMoveId; - if (this.shouldEmitBreakoutJoinResponseMetric(breakoutMoveId)) { - // @ts-ignore - const llmWebsocketUrl = this.webex.internal.llm.getWebSocketUrl?.() || undefined; + // @ts-ignore + const llmWebsocketUrl = this.webex.internal.llm.getWebSocketUrl?.() || undefined; - breakoutEvent.onBreakoutJoinResponse( - { - currentSession: this.breakouts?.currentBreakoutSession, - meeting: this, - breakoutMoveId, - llmLatency: { - clientLLMDatachannelResponseTime: 0, - clientLLMWebSocketConnectTime: 0, - }, - llmWebsocketUrl, - error, + breakoutEvent.onBreakoutJoinResponse( + { + currentSession: this.breakouts?.currentBreakoutSession, + meeting: this, + breakoutMoveId, + llmLatency: { + clientLLMDatachannelResponseTime: 0, + clientLLMWebSocketConnectTime: 0, }, - // @ts-ignore - this.webex.internal.newMetrics.submitClientEvent.bind(this.webex.internal.newMetrics) - ); - } + llmWebsocketUrl, + error, + }, + // @ts-ignore + this.webex.internal.newMetrics.submitClientEvent.bind(this.webex.internal.newMetrics) + ); return Promise.reject(error); }); diff --git a/packages/@webex/plugin-meetings/test/unit/spec/breakouts/events.ts b/packages/@webex/plugin-meetings/test/unit/spec/breakouts/events.ts index c15f62439e3..972e72a29e0 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/breakouts/events.ts +++ b/packages/@webex/plugin-meetings/test/unit/spec/breakouts/events.ts @@ -126,6 +126,38 @@ describe('plugin-meetings', () => { options: {meetingId: 'activeMeetingId'}, }); }); + + it('does not emit duplicate join response metric for the same breakoutMoveId', () => { + const submitClientEvent = sinon.stub(); + const shouldEmitBreakoutJoinResponseMetric = sinon.stub(); + + shouldEmitBreakoutJoinResponseMetric.onFirstCall().returns(true); + shouldEmitBreakoutJoinResponseMetric.onSecondCall().returns(false); + + const eventInfo = { + currentSession: newSession, + meeting: { + ...mockMeeting, + shouldEmitBreakoutJoinResponseMetric, + }, + breakoutMoveId, + }; + + breakoutEvent.postMoveCallAnalyzer( + 'client.breakout-session.join.response', + eventInfo, + submitClientEvent + ); + breakoutEvent.postMoveCallAnalyzer( + 'client.breakout-session.join.response', + eventInfo, + submitClientEvent + ); + + assert.calledTwice(shouldEmitBreakoutJoinResponseMetric); + assert.calledWithExactly(shouldEmitBreakoutJoinResponseMetric, breakoutMoveId); + assert.calledOnce(submitClientEvent); + }); }); }); diff --git a/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js b/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js index 3a7b7041560..1f2378feb8f 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js +++ b/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js @@ -2655,6 +2655,35 @@ describe('plugin-meetings', () => { assert.equal(joinResponseCalls[0].args[0].options.meetingId, meeting.id); }); + it('does not re-emit breakout join response metric if updateBreakout already emitted it', async () => { + sinon.stub(meeting, 'isJoined').returns(true); + sinon.stub(meeting.webex.internal.llm, 'isConnected').returns(false); + sinon.stub(meeting.webex.internal.llm, 'registerAndConnect').resolves({ + clientLLMDatachannelResponseTime: 10, + clientLLMWebSocketConnectTime: 20, + }); + + meeting.meetingInfo.enableConvergedArchitecture = true; + meeting.breakouts.set('breakoutMoveId', 'move-id-1'); + meeting.breakouts.set('currentBreakoutSession', { + sessionId: 'session-id-1', + groupId: 'group-id-1', + }); + + meeting.shouldEmitBreakoutJoinResponseMetric('move-id-1'); + + webex.internal.newMetrics.submitClientEvent.resetHistory(); + meeting.updateLLMConnection.restore(); + + await meeting.updateLLMConnection(); + + const joinResponseCalls = webex.internal.newMetrics.submitClientEvent + .getCalls() + .filter((call) => call.args[0]?.name === 'client.breakout-session.join.response'); + + assert.lengthOf(joinResponseCalls, 0); + }); + it('clears the LLM health check timer when disconnecting LLM', async () => { const isJoinedStub = sinon.stub(meeting, 'isJoined'); sinon.stub(meeting.webex.internal.llm, 'isConnected'); From 7ceadf9ae402bc8f9a2a8e21cf7077c7346fc673 Mon Sep 17 00:00:00 2001 From: tiahan Date: Mon, 1 Jun 2026 16:26:12 +0800 Subject: [PATCH 14/29] fix(meetings): track target sync version for metrics --- .../src/hashTree/hashTreeParser.ts | 8 +++++++- .../test/unit/spec/hashTree/hashTreeParser.ts | 15 +++++++++++++++ 2 files changed, 22 insertions(+), 1 deletion(-) diff --git a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts index 563661283cf..9670bb2133c 100644 --- a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts @@ -1453,6 +1453,7 @@ class HashTreeParser { const rootHash = hashTree.getRootHash(); const shouldCollectMetrics = this.shouldCollectSyncMetrics(dataSet.name, isInitialization); let syncMetricsPending = false; + let targetSyncVersion = dataSet.version; if (shouldCollectMetrics) { this.syncLatencyTracker?.saveTimestamp({ @@ -1485,6 +1486,7 @@ class HashTreeParser { } receivedHashes = hashesResult.hashes; + targetSyncVersion = hashesResult.dataSet?.version ?? targetSyncVersion; this.updateDataSetLeafCount(dataSet, hashesResult.dataSet.leafCount); } catch (error: any) { @@ -1531,11 +1533,15 @@ class HashTreeParser { syncRequestSent = true; } + const syncResponseDataSet = syncResponse?.dataSets?.find((ds) => ds.name === dataSet.name); + + targetSyncVersion = syncResponseDataSet?.version ?? targetSyncVersion; + // Record pending metrics and complete them when the matching LLM broadcast arrives. if (shouldCollectMetrics && syncRequestSent) { this.pendingSyncMetrics.set(dataSet.name, { dataSetName: dataSet.name, - dataSetVersion: dataSet.version, + dataSetVersion: targetSyncVersion, }); syncMetricsPending = true; } diff --git a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts index e9927f7d0ec..b7ff864bcdf 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts @@ -5467,6 +5467,21 @@ describe('HashTreeParser', () => { assert.isTrue(parser['pendingSyncMetrics'].has('main')); assert.notCalled(syncMetricsCallback); + parser.handleMessage({ + dataSets: [ + { + ...createDataSet('main', 16, 1100), + root: 'intermediate-root', + }, + ], + visibleDataSetsUrl, + locusUrl, + locusStateElements: [], + }); + + assert.notCalled(syncMetricsCallback); + assert.isTrue(parser['pendingSyncMetrics'].has('main')); + parser.handleMessage({ dataSets: [ { From 21e57eee35202b6bad17f5ecd2bceb4e65c3f08e Mon Sep 17 00:00:00 2001 From: tiahan Date: Mon, 1 Jun 2026 16:34:17 +0800 Subject: [PATCH 15/29] fix(meetings): avoid overwriting pending sync metrics --- .../src/hashTree/hashTreeParser.ts | 5 ++- .../test/unit/spec/hashTree/hashTreeParser.ts | 43 +++++++++++++++++++ 2 files changed, 47 insertions(+), 1 deletion(-) diff --git a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts index 9670bb2133c..d364e4b8f84 100644 --- a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts @@ -1271,7 +1271,10 @@ class HashTreeParser { */ private shouldCollectSyncMetrics(dataSetName: string, isInitialization = false): boolean { return Boolean( - this.syncLatencyTracker && !isInitialization && SYNC_METRICS_DATA_SETS.includes(dataSetName) + this.syncLatencyTracker && + !isInitialization && + SYNC_METRICS_DATA_SETS.includes(dataSetName) && + !this.pendingSyncMetrics.has(dataSetName) ); } diff --git a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts index b7ff864bcdf..ff5087c6ab8 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts @@ -5498,6 +5498,49 @@ describe('HashTreeParser', () => { assert.isFalse(parser['pendingSyncMetrics'].has('main')); }); + it('does not overwrite pending sync latency state when a safety-net sync runs before broadcast', async () => { + const syncMetricsCallback = sinon.stub(); + const syncLatencyTracker = { + saveTimestamp: sinon.stub(), + getLocusSyncLatency: sinon.stub(), + clearLocusSyncLatency: sinon.stub(), + }; + const parser = createHashTreeParser( + undefined, + undefined, + undefined, + syncMetricsCallback, + syncLatencyTracker + ); + const mainDataSetUrl = parser.dataSets.main.url; + + parser['pendingSyncMetrics'].set('main', { + dataSetName: 'main', + dataSetVersion: 1101, + } as any); + + mockGetHashesFromLocusResponse( + mainDataSetUrl, + new Array(16).fill('00000000000000000000000000000000'), + createDataSet('main', 16, 1102) + ); + mockSendSyncRequestResponse(mainDataSetUrl, null); + + parser.handleMessage( + createHeartbeatMessage('main', 16, 1100, 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa1'), + 'trigger safety-net sync while metrics are pending' + ); + + await clock.tickAsync(1000); + + assert.notCalled(syncLatencyTracker.saveTimestamp); + assert.notCalled(syncMetricsCallback); + assert.deepEqual(parser['pendingSyncMetrics'].get('main'), { + dataSetName: 'main', + dataSetVersion: 1101, + }); + }); + it('invokes syncMetricsCallback when matching dataset version arrives', () => { const syncMetricsCallback = sinon.stub(); const syncLatency = { From f34a260972480d824a24e9801e17c91908c278a5 Mon Sep 17 00:00:00 2001 From: tiahan Date: Mon, 1 Jun 2026 16:45:09 +0800 Subject: [PATCH 16/29] fix(meetings): preserve root sync backoff metrics --- .../src/hashTree/hashTreeParser.ts | 4 +- .../test/unit/spec/hashTree/hashTreeParser.ts | 42 +++++++++++++++++++ 2 files changed, 44 insertions(+), 2 deletions(-) diff --git a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts index d364e4b8f84..cb10f081877 100644 --- a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts @@ -1921,8 +1921,6 @@ class HashTreeParser { const backoffTime = this.getWeightedBackoffTime(dataSet.backoff); const delay = heartbeatIntervalMs + backoffTime; - dataSet.lastBackoffTime = backoffTime; - dataSet.heartbeatWatchdogTimer = setTimeout(() => { dataSet.heartbeatWatchdogTimer = undefined; @@ -1935,6 +1933,8 @@ class HashTreeParser { dataSetName: dataSet.name, }); + dataSet.lastBackoffTime = backoffTime; + this.enqueueSyncForDataset(dataSet.name, `heartbeat watchdog expired`); this.resetHeartbeatWatchdogs([dataSet]); }, delay); diff --git a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts index ff5087c6ab8..286264659de 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts @@ -3157,6 +3157,48 @@ describe('HashTreeParser', () => { }); }); + it('uses the root sync random backoff when root timer fires before watchdog', async () => { + const syncLatencyTracker = { + saveTimestamp: sinon.stub(), + getLocusSyncLatency: sinon.stub(), + clearLocusSyncLatency: sinon.stub(), + }; + const parser = createHashTreeParser( + undefined, + undefined, + undefined, + sinon.stub(), + syncLatencyTracker + ); + const mainDataSetUrl = parser.dataSets.main.url; + + mathRandomStub.onFirstCall().returns(0.1); // root-hash timer backoff = 10ms + mathRandomStub.onSecondCall().returns(0.5); // watchdog backoff = 250ms + mathRandomStub.returns(0); + + parser.handleMessage( + createHeartbeatMessage('main', 16, 1100, 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa1'), + 'root mismatch heartbeat' + ); + + mockGetHashesFromLocusResponse( + mainDataSetUrl, + new Array(16).fill('00000000000000000000000000000000'), + createDataSet('main', 16, 1101) + ); + mockSendSyncRequestResponse(mainDataSetUrl, null); + + await clock.tickAsync(1010); + + assert.calledWith(syncLatencyTracker.saveTimestamp, { + key: 'internal.client.locus.sync.start', + options: { + dataSetName: 'main', + randomBackoffTime: 10, + }, + }); + }); + it('calls POST sync directly for leafCount === 1 data sets', async () => { const parser = createHashTreeParser(); const heartbeatIntervalMs = 5000; From a36871dbabd3b6fbad48e453f48d56bd2621b359 Mon Sep 17 00:00:00 2001 From: tiahan Date: Mon, 1 Jun 2026 17:31:21 +0800 Subject: [PATCH 17/29] fix(meetings): keep breakout LLM join metric from being deduped --- .../plugin-meetings/src/breakouts/events.ts | 2 +- .../plugin-meetings/src/meeting/index.ts | 12 ++++- .../test/unit/spec/breakouts/events.ts | 45 ++++++++++++++++++- .../test/unit/spec/meeting/index.js | 8 +++- 4 files changed, 60 insertions(+), 7 deletions(-) diff --git a/packages/@webex/plugin-meetings/src/breakouts/events.ts b/packages/@webex/plugin-meetings/src/breakouts/events.ts index c3a1904b447..2e277465351 100644 --- a/packages/@webex/plugin-meetings/src/breakouts/events.ts +++ b/packages/@webex/plugin-meetings/src/breakouts/events.ts @@ -46,7 +46,7 @@ const breakoutEvent: { if ( event === 'client.breakout-session.join.response' && typeof meeting.shouldEmitBreakoutJoinResponseMetric === 'function' && - !meeting.shouldEmitBreakoutJoinResponseMetric(breakoutMoveId) + !meeting.shouldEmitBreakoutJoinResponseMetric(breakoutMoveId, Boolean(llmLatency)) ) { return; } diff --git a/packages/@webex/plugin-meetings/src/meeting/index.ts b/packages/@webex/plugin-meetings/src/meeting/index.ts index 29671a712a8..ae1e5a336af 100644 --- a/packages/@webex/plugin-meetings/src/meeting/index.ts +++ b/packages/@webex/plugin-meetings/src/meeting/index.ts @@ -6859,15 +6859,23 @@ export default class Meeting extends StatelessWebexPlugin { } /** - * Ensures breakout join response metric is emitted only once per breakout move id. + * Ensures breakout join response metric with LLM latency is emitted only once per breakout move id. * @param {string | undefined} breakoutMoveId + * @param {boolean} [hasLLMLatency=false] * @returns {boolean} */ - private shouldEmitBreakoutJoinResponseMetric(breakoutMoveId?: string): boolean { + private shouldEmitBreakoutJoinResponseMetric( + breakoutMoveId?: string, + hasLLMLatency = false + ): boolean { if (!breakoutMoveId) { return false; } + if (!hasLLMLatency) { + return true; + } + if (this.emittedBreakoutJoinResponseMoveIds.has(breakoutMoveId)) { return false; } diff --git a/packages/@webex/plugin-meetings/test/unit/spec/breakouts/events.ts b/packages/@webex/plugin-meetings/test/unit/spec/breakouts/events.ts index 972e72a29e0..6de16860c17 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/breakouts/events.ts +++ b/packages/@webex/plugin-meetings/test/unit/spec/breakouts/events.ts @@ -127,7 +127,7 @@ describe('plugin-meetings', () => { }); }); - it('does not emit duplicate join response metric for the same breakoutMoveId', () => { + it('does not emit duplicate join response metric with llmLatency for the same breakoutMoveId', () => { const submitClientEvent = sinon.stub(); const shouldEmitBreakoutJoinResponseMetric = sinon.stub(); @@ -141,6 +141,7 @@ describe('plugin-meetings', () => { shouldEmitBreakoutJoinResponseMetric, }, breakoutMoveId, + llmLatency: {clientLLMDatachannelResponseTime: 10, clientLLMWebSocketConnectTime: 20}, }; breakoutEvent.postMoveCallAnalyzer( @@ -155,9 +156,49 @@ describe('plugin-meetings', () => { ); assert.calledTwice(shouldEmitBreakoutJoinResponseMetric); - assert.calledWithExactly(shouldEmitBreakoutJoinResponseMetric, breakoutMoveId); + assert.calledWithExactly(shouldEmitBreakoutJoinResponseMetric, breakoutMoveId, true); assert.calledOnce(submitClientEvent); }); + + it('allows llmLatency join response after join response without llmLatency', () => { + const submitClientEvent = sinon.stub(); + const shouldEmitBreakoutJoinResponseMetric = sinon.stub(); + + shouldEmitBreakoutJoinResponseMetric.onFirstCall().returns(true); + shouldEmitBreakoutJoinResponseMetric.onSecondCall().returns(true); + + const baseEventInfo = { + currentSession: newSession, + meeting: { + ...mockMeeting, + shouldEmitBreakoutJoinResponseMetric, + }, + breakoutMoveId, + }; + + breakoutEvent.postMoveCallAnalyzer( + 'client.breakout-session.join.response', + baseEventInfo, + submitClientEvent + ); + breakoutEvent.postMoveCallAnalyzer( + 'client.breakout-session.join.response', + { + ...baseEventInfo, + llmLatency: {clientLLMDatachannelResponseTime: 10, clientLLMWebSocketConnectTime: 20}, + }, + submitClientEvent + ); + + assert.calledTwice(shouldEmitBreakoutJoinResponseMetric); + assert.calledWithExactly(shouldEmitBreakoutJoinResponseMetric.firstCall, breakoutMoveId, false); + assert.calledWithExactly(shouldEmitBreakoutJoinResponseMetric.secondCall, breakoutMoveId, true); + assert.calledTwice(submitClientEvent); + assert.deepEqual(submitClientEvent.secondCall.args[0].payload.llmLatency, { + clientLLMDatachannelResponseTime: 10, + clientLLMWebSocketConnectTime: 20, + }); + }); }); }); diff --git a/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js b/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js index 1f2378feb8f..c0debce71ea 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js +++ b/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js @@ -2655,7 +2655,7 @@ describe('plugin-meetings', () => { assert.equal(joinResponseCalls[0].args[0].options.meetingId, meeting.id); }); - it('does not re-emit breakout join response metric if updateBreakout already emitted it', async () => { + it('emits llm breakout join response metric even if updateBreakout already emitted one without llmLatency', async () => { sinon.stub(meeting, 'isJoined').returns(true); sinon.stub(meeting.webex.internal.llm, 'isConnected').returns(false); sinon.stub(meeting.webex.internal.llm, 'registerAndConnect').resolves({ @@ -2681,7 +2681,11 @@ describe('plugin-meetings', () => { .getCalls() .filter((call) => call.args[0]?.name === 'client.breakout-session.join.response'); - assert.lengthOf(joinResponseCalls, 0); + assert.lengthOf(joinResponseCalls, 1); + assert.deepEqual(joinResponseCalls[0].args[0].payload.llmLatency, { + clientLLMDatachannelResponseTime: 10, + clientLLMWebSocketConnectTime: 20, + }); }); it('clears the LLM health check timer when disconnecting LLM', async () => { From 70c8b96c822d9f0dd66ec4acbb1d0ff525d5c630 Mon Sep 17 00:00:00 2001 From: tiahan Date: Tue, 2 Jun 2026 10:21:31 +0800 Subject: [PATCH 18/29] fix: use heartbeat target version for single-leaf sync metrics For single-leaf datasets (leafCount === 1), preserve the heartbeat target version from the message instead of using the local version for pending sync metrics. This prevents metrics from being completed prematurely when subsequent non-root messages at the same local version arrive, before the actual remote heartbeat version broadcasts are received. Changes: - Add heartbeatVersion field to sync queue entries - Pass receivedDataSet.version from runSyncAlgorithm to enqueueSyncForDataset - Update performSync to use heartbeat version for single-leaf targetSyncVersion - This ensures pending metrics wait for the correct remote version --- .../src/hashTree/hashTreeParser.ts | 32 ++++++++++++++----- 1 file changed, 24 insertions(+), 8 deletions(-) diff --git a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts index cb10f081877..4040460bbc3 100644 --- a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts @@ -178,7 +178,13 @@ class HashTreeParser { debugId: string; private excludedDataSets: string[]; state: 'active' | 'stopped'; - private syncQueue: Array<{dataSetName: string; reason: string; isInitialization?: boolean}> = []; + private syncQueue: Array<{ + dataSetName: string; + reason: string; + isInitialization?: boolean; + heartbeatVersion?: number; + }> = []; + private isSyncInProgress = false; // tracks whether syncAllDatasets is currently in its backoff delay phase and with what scope private syncAllBackoffType: SyncAllBackoffType = SyncAllBackoffType.NONE; @@ -1438,12 +1444,14 @@ class HashTreeParser { * @param {InternalDataSet} dataSet - The data set to sync * @param {string} reason - The reason for the sync (used for logging) * @param {boolean} [isInitialization] - Whether this is an initialization sync (sends empty leaves data instead of comparing hashes) + * @param {number} [heartbeatVersion] - The target version from the heartbeat message (for single-leaf sync metrics) * @returns {Promise} */ private async performSync( dataSet: InternalDataSet, reason: string, - isInitialization?: boolean + isInitialization?: boolean, + heartbeatVersion?: number ): Promise { if (!dataSet.hashTree) { return; @@ -1456,7 +1464,11 @@ class HashTreeParser { const rootHash = hashTree.getRootHash(); const shouldCollectMetrics = this.shouldCollectSyncMetrics(dataSet.name, isInitialization); let syncMetricsPending = false; - let targetSyncVersion = dataSet.version; + // Use the heartbeat target for single-leaf sync metrics + let targetSyncVersion = + dataSet.leafCount === 1 && heartbeatVersion !== undefined + ? heartbeatVersion + : dataSet.version; if (shouldCollectMetrics) { this.syncLatencyTracker?.saveTimestamp({ @@ -1646,12 +1658,14 @@ class HashTreeParser { * @param {string} dataSetName - The name of the data set to sync * @param {string} reason - The reason for the sync (used for logging) * @param {boolean} [isInitialization=false] - Whether this is an initialization sync (uses empty leaves data instead of hash comparison) + * @param {number} [heartbeatVersion] - The target version from the heartbeat message (for single-leaf sync metrics) * @returns {void} */ private enqueueSyncForDataset( dataSetName: string, reason: string, - isInitialization = false + isInitialization = false, + heartbeatVersion: number | undefined = undefined ): void { if (this.state === 'stopped') return; @@ -1668,7 +1682,7 @@ class HashTreeParser { return; } - this.syncQueue.push({dataSetName, reason, isInitialization}); + this.syncQueue.push({dataSetName, reason, isInitialization, heartbeatVersion}); if (!this.isSyncInProgress) { this.syncQueueProcessingPromise = this.processSyncQueue(); @@ -1687,7 +1701,7 @@ class HashTreeParser { try { while (this.syncQueue.length > 0 && this.state !== 'stopped') { // eslint-disable-next-line @typescript-eslint/no-non-null-assertion - const {dataSetName, reason, isInitialization} = this.syncQueue.shift()!; + const {dataSetName, reason, isInitialization, heartbeatVersion} = this.syncQueue.shift()!; const dataSet = this.dataSets[dataSetName]; if (!dataSet?.hashTree) { @@ -1696,7 +1710,7 @@ class HashTreeParser { } // eslint-disable-next-line no-await-in-loop - await this.performSync(dataSet, reason, isInitialization); + await this.performSync(dataSet, reason, isInitialization, heartbeatVersion); } } finally { this.isSyncInProgress = false; @@ -1881,7 +1895,9 @@ class HashTreeParser { if (dataSet.root !== rootHash) { this.enqueueSyncForDataset( dataSet.name, - `Root hash mismatch: received=${dataSet.root}, ours=${rootHash}` + `Root hash mismatch: received=${dataSet.root}, ours=${rootHash}`, + false, + receivedDataSet.version ); } }, delay); From 0d54758ae8a9a4f3e85d73221fd073b2435d7307 Mon Sep 17 00:00:00 2001 From: tiahan Date: Tue, 2 Jun 2026 13:27:02 +0800 Subject: [PATCH 19/29] fix: add ts-ignore for webex property injected by registerPlugin --- packages/@webex/plugin-meetings/src/meeting/index.ts | 1 + 1 file changed, 1 insertion(+) diff --git a/packages/@webex/plugin-meetings/src/meeting/index.ts b/packages/@webex/plugin-meetings/src/meeting/index.ts index ae1e5a336af..f847f19958c 100644 --- a/packages/@webex/plugin-meetings/src/meeting/index.ts +++ b/packages/@webex/plugin-meetings/src/meeting/index.ts @@ -1392,6 +1392,7 @@ export default class Meeting extends StatelessWebexPlugin { }, syncLatencyTracker: (this as any).webex.internal.newMetrics.callDiagnosticLatencies, }, + // @ts-ignore - webex injected by registerPlugin this.webex, this.id ); From 97b7bfffa2d10644cec3258fda3c14f7037890a1 Mon Sep 17 00:00:00 2001 From: tiahan Date: Wed, 3 Jun 2026 09:14:32 +0800 Subject: [PATCH 20/29] fix: correlate sync metrics by LLM tracking id --- .../src/hashTree/hashTreeParser.ts | 45 ++++++++--- .../plugin-meetings/src/locus-info/index.ts | 17 +++- .../plugin-meetings/src/meeting/index.ts | 4 +- .../test/unit/spec/hashTree/hashTreeParser.ts | 81 ++++++++++++++++++- 4 files changed, 129 insertions(+), 18 deletions(-) diff --git a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts index 4040460bbc3..9dd21f1d942 100644 --- a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts @@ -131,6 +131,12 @@ const SYNC_METRICS_DATA_SETS = [ interface PendingSyncMetrics { dataSetName: string; dataSetVersion: number; + trackingId?: string; +} + +interface SyncRequestResult { + message: HashTreeMessage | null; + trackingId?: string; } interface LeafInfo { @@ -1214,9 +1220,10 @@ class HashTreeParser { * * @param {HashTreeMessage} message - The hash tree message containing data sets and objects to be processed * @param {string} [debugText] - Optional debug text to include in logs + * @param {string} [trackingId] top-level tracking id from LLM event or /sync response * @returns {void} */ - handleMessage(message: HashTreeMessage, debugText?: string) { + handleMessage(message: HashTreeMessage, debugText?: string, trackingId?: string) { if (this.state === 'stopped') { return; } @@ -1236,7 +1243,7 @@ class HashTreeParser { this.handleRootHashHeartBeatMessage(message); this.resetHeartbeatWatchdogs(message.dataSets); } else { - this.tryCompletePendingSyncMetrics(message); + this.tryCompletePendingSyncMetrics(message, trackingId); const updatedObjects = this.parseMessage(message, debugText); @@ -1252,9 +1259,10 @@ class HashTreeParser { * Completes any pending sync metrics when a qualifying LLM message arrives. * * @param {HashTreeMessage} message + * @param {string} [trackingId] top-level tracking id from LLM event or /sync response * @returns {void} */ - private tryCompletePendingSyncMetrics(message: HashTreeMessage): void { + private tryCompletePendingSyncMetrics(message: HashTreeMessage, trackingId?: string): void { if (this.pendingSyncMetrics.size === 0) { return; } @@ -1262,7 +1270,11 @@ class HashTreeParser { for (const dataSet of message.dataSets) { const pending = this.pendingSyncMetrics.get(dataSet.name); - if (pending && dataSet.version >= pending.dataSetVersion) { + if ( + pending && + dataSet.version >= pending.dataSetVersion && + (!pending.trackingId || pending.trackingId === trackingId) + ) { this.completeSyncMetrics(dataSet.name); } } @@ -1536,15 +1548,22 @@ class HashTreeParser { } // request sync for mismatched leaves let syncResponse: HashTreeMessage | null = null; + let syncTrackingId: string | undefined; let syncRequestSent = false; if (isInitialization) { - syncResponse = await this.sendSyncRequestToLocus(dataSet, {isInitialization: true}); + const syncResult = await this.sendSyncRequestToLocus(dataSet, {isInitialization: true}); + + syncResponse = syncResult.message; + syncTrackingId = syncResult.trackingId; syncRequestSent = true; } else if (Object.keys(leavesData).length > 0) { - syncResponse = await this.sendSyncRequestToLocus(dataSet, { + const syncResult = await this.sendSyncRequestToLocus(dataSet, { mismatchedLeavesData: leavesData, }); + + syncResponse = syncResult.message; + syncTrackingId = syncResult.trackingId; syncRequestSent = true; } @@ -1557,6 +1576,7 @@ class HashTreeParser { this.pendingSyncMetrics.set(dataSet.name, { dataSetName: dataSet.name, dataSetVersion: targetSyncVersion, + trackingId: syncTrackingId, }); syncMetricsPending = true; } @@ -1577,7 +1597,8 @@ class HashTreeParser { syncResponse, `via sync API (${ isInitialization ? 'init' : `${Object.keys(leavesData).length} mismatched leaves` - })` + })`, + syncTrackingId ); } } catch (error) { @@ -2191,12 +2212,12 @@ class HashTreeParser { * * @param {InternalDataSet} dataSet The data set to sync. * @param {Object} options Either `{ isInitialization: true }` for init syncs (uses leafCount=1 with empty leaf data) or `{ mismatchedLeavesData }` for normal syncs. - * @returns {Promise} + * @returns {Promise} */ private sendSyncRequestToLocus( dataSet: InternalDataSet, options: {isInitialization: true} | {mismatchedLeavesData: Record} - ): Promise { + ): Promise { LoggerProxy.logger.info( `HashTreeParser#sendSyncRequestToLocus --> ${this.debugId} Sending sync request for data set "${dataSet.name}"` ); @@ -2246,6 +2267,8 @@ class HashTreeParser { body, }) .then((resp) => { + const trackingId = resp.headers?.trackingid || resp.headers?.trackingId; + if (this.shouldCollectSyncMetrics(dataSet.name, isInitialization)) { this.syncLatencyTracker?.saveTimestamp({ key: 'internal.client.locus.sync.response', @@ -2258,10 +2281,10 @@ class HashTreeParser { `HashTreeParser#sendSyncRequestToLocus --> ${this.debugId} Got ${resp.statusCode} with empty body for sync request for data set "${dataSet.name}", data should arrive via messages` ); - return null; + return {message: null, trackingId}; } - return resp.body as HashTreeMessage; + return {message: resp.body as HashTreeMessage, trackingId}; }) .catch((error) => { LoggerProxy.logger.error( diff --git a/packages/@webex/plugin-meetings/src/locus-info/index.ts b/packages/@webex/plugin-meetings/src/locus-info/index.ts index 9a2162d05ca..46f4d748e0b 100644 --- a/packages/@webex/plugin-meetings/src/locus-info/index.ts +++ b/packages/@webex/plugin-meetings/src/locus-info/index.ts @@ -48,6 +48,7 @@ import {MEETING_KEY} from '../meetings/meetings.types'; import MeetingCollection from '../meetings/collection'; export type LocusLLMEvent = { + trackingId?: string; data: { eventType: typeof LOCUSEVENT.HASH_TREE_DATA_UPDATED; stateElementsMessage: HashTreeMessage; @@ -1190,9 +1191,15 @@ export default class LocusInfo extends EventsScope { * @param {Meeting} meeting - The meeting object * @param {eventType} eventType - The event type * @param {HashTreeMessage} message incoming hash tree message + * @param {string} [trackingId] top-level tracking id from LLM event * @returns {void} */ - private handleHashTreeMessage(meeting: any, eventType: LOCUSEVENT, message: HashTreeMessage) { + private handleHashTreeMessage( + meeting: any, + eventType: LOCUSEVENT, + message: HashTreeMessage, + trackingId?: string + ) { if (eventType !== LOCUSEVENT.HASH_TREE_DATA_UPDATED) { this.sendClassicVsHashTreeMismatchMetric( meeting, @@ -1212,7 +1219,7 @@ export default class LocusInfo extends EventsScope { // the check is just for typescript, the case of no entry in hashTreeParsers is handled in handleHashTreeParserSwitch() above if (entry) { - entry.parser.handleMessage(message); + entry.parser.handleMessage(message, undefined, trackingId); } } @@ -1381,10 +1388,11 @@ export default class LocusInfo extends EventsScope { /** * @param {Meeting} meeting * @param {Object} data + * @param {string} [trackingId] top-level tracking id from LLM event * @returns {undefined} * @memberof LocusInfo */ - parse(meeting: any, data: any) { + parse(meeting: any, data: any, trackingId?: string) { if (this.hashTreeParsers.size > 0) { if (data.eventType === LOCUSEVENT.SDK_LOCUS_FROM_SYNC_MEETINGS) { // sync meetings response follows the format of "not wrapped" locus API responses, @@ -1394,7 +1402,8 @@ export default class LocusInfo extends EventsScope { this.handleHashTreeMessage( meeting, data.eventType, - data.stateElementsMessage as HashTreeMessage + data.stateElementsMessage as HashTreeMessage, + trackingId ); } } else { diff --git a/packages/@webex/plugin-meetings/src/meeting/index.ts b/packages/@webex/plugin-meetings/src/meeting/index.ts index f847f19958c..a97a8be061b 100644 --- a/packages/@webex/plugin-meetings/src/meeting/index.ts +++ b/packages/@webex/plugin-meetings/src/meeting/index.ts @@ -1392,7 +1392,7 @@ export default class Meeting extends StatelessWebexPlugin { }, syncLatencyTracker: (this as any).webex.internal.newMetrics.callDiagnosticLatencies, }, - // @ts-ignore - webex injected by registerPlugin + // @ts-ignore this.webex, this.id ); @@ -5976,7 +5976,7 @@ export default class Meeting extends StatelessWebexPlugin { storeEventForDebugging('llm', event.data); } - this.locusInfo.parse(this, event.data); + this.locusInfo.parse(this, event.data, event.trackingId); } else { LoggerProxy.logger.warn( `Meeting:index#processLocusLLMEvent --> Unknown event type: ${event.data.eventType}` diff --git a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts index 286264659de..eeac3c4521d 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts @@ -234,7 +234,7 @@ describe('HashTreeParser', () => { } // Helper to mock sendSyncRequestToLocus response - function mockSendSyncRequestResponse(dataSetUrl: string, response: any) { + function mockSendSyncRequestResponse(dataSetUrl: string, response: any, headers?: any) { webexRequest .withArgs( sinon.match({ @@ -244,6 +244,7 @@ describe('HashTreeParser', () => { ) .resolves({ body: response, + headers, }); } @@ -5638,6 +5639,84 @@ describe('HashTreeParser', () => { assert.isFalse(parser['pendingSyncMetrics'].has('main')); }); + it('only completes pending sync metrics when LLM message tracking id matches sync response tracking id', async () => { + const syncMetricsCallback = sinon.stub(); + const syncLatency = { + randomBackoffTime: 0, + hashtreePrepTime: 5, + hashtreeResponseTime: 20, + syncPrepTime: 3, + syncResponseTime: 15, + syncMessageReceiveTime: 7, + totalTime: 50, + }; + const syncLatencyTracker = { + saveTimestamp: sinon.stub(), + getLocusSyncLatency: sinon.stub().returns(syncLatency), + clearLocusSyncLatency: sinon.stub(), + }; + const parser = createHashTreeParser( + undefined, + undefined, + undefined, + syncMetricsCallback, + syncLatencyTracker + ); + const mainDataSetUrl = parser.dataSets.main.url; + + mockGetHashesFromLocusResponse( + mainDataSetUrl, + new Array(16).fill('00000000000000000000000000000000'), + createDataSet('main', 16, 1101) + ); + mockSendSyncRequestResponse(mainDataSetUrl, null, {trackingid: 'our-sync-tracking-id'}); + + parser.handleMessage( + createHeartbeatMessage('main', 16, 1100, 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa1'), + 'trigger sync metrics' + ); + + await clock.tickAsync(1000); + + parser.handleMessage( + { + dataSets: [ + { + ...createDataSet('main', 16, 1101), + root: 'newroot', + }, + ], + visibleDataSetsUrl, + locusUrl, + locusStateElements: [], + }, + undefined, + 'other-client-sync-tracking-id' + ); + + assert.notCalled(syncMetricsCallback); + assert.isTrue(parser['pendingSyncMetrics'].has('main')); + + parser.handleMessage( + { + dataSets: [ + { + ...createDataSet('main', 16, 1101), + root: 'newroot', + }, + ], + visibleDataSetsUrl, + locusUrl, + locusStateElements: [], + }, + undefined, + 'our-sync-tracking-id' + ); + + assert.calledOnce(syncMetricsCallback); + assert.isFalse(parser['pendingSyncMetrics'].has('main')); + }); + it('scopes sync metrics tracker records by meeting id', () => { const syncMetricsCallback = sinon.stub(); const syncLatency = { From c3b1a10eb8b7dd9bdd2a4eec2db076ddf83bff38 Mon Sep 17 00:00:00 2001 From: tiahan Date: Wed, 3 Jun 2026 09:40:23 +0800 Subject: [PATCH 21/29] test(llm): assert registerAndConnect latency values precisely --- .../internal-plugin-llm/test/unit/spec/llm.js | 40 ++++++++++++++----- 1 file changed, 29 insertions(+), 11 deletions(-) diff --git a/packages/@webex/internal-plugin-llm/test/unit/spec/llm.js b/packages/@webex/internal-plugin-llm/test/unit/spec/llm.js index 8f8ed02192c..e59f6e5fab9 100644 --- a/packages/@webex/internal-plugin-llm/test/unit/spec/llm.js +++ b/packages/@webex/internal-plugin-llm/test/unit/spec/llm.js @@ -711,21 +711,39 @@ describe('plugin-llm', () => { describe('#registerAndConnect timing', () => { it('returns timing data on successful connection', async () => { - llmService.register = sinon.stub().callsFake(async () => { - const sessionData = llmService.connections.get('llm-default-session') || {}; + const clock = sinon.useFakeTimers(); + + llmService.isDataChannelTokenEnabled = sinon.stub().resolves(false); + llmService.register = sinon.stub().callsFake(() => { + return new Promise((resolve) => { + setTimeout(() => { + const sessionData = llmService.connections.get('llm-default-session') || {}; - sessionData.webSocketUrl = 'wss://example.com/socket'; - sessionData.binding = 'binding'; - llmService.connections.set('llm-default-session', sessionData); + sessionData.webSocketUrl = 'wss://example.com/socket'; + sessionData.binding = 'binding'; + llmService.connections.set('llm-default-session', sessionData); + + resolve(); + }, 37); + }); + }); + llmService.connect = sinon.stub().callsFake(() => { + return new Promise((resolve) => { + setTimeout(resolve, 23); + }); }); - const result = await llmService.registerAndConnect(locusUrl, datachannelUrl, undefined); + const resultPromise = llmService.registerAndConnect(locusUrl, datachannelUrl, undefined); - assert.isDefined(result); - assert.isNumber(result.clientLLMDatachannelResponseTime); - assert.isNumber(result.clientLLMWebSocketConnectTime); - assert.isAtLeast(result.clientLLMDatachannelResponseTime, 0); - assert.isAtLeast(result.clientLLMWebSocketConnectTime, 0); + await clock.tickAsync(37); + await clock.tickAsync(23); + + const result = await resultPromise; + + assert.deepEqual(result, { + clientLLMDatachannelResponseTime: 37, + clientLLMWebSocketConnectTime: 23, + }); }); it('returns undefined when locusUrl is empty', async () => { From 608910a6265fc43fee52b699a690df0f5f9af5dc Mon Sep 17 00:00:00 2001 From: tiahan Date: Wed, 3 Jun 2026 09:48:17 +0800 Subject: [PATCH 22/29] fix(metrics): require meeting id for locus sync latencies --- .../call-diagnostic-metrics-latencies.ts | 16 +++++---- .../call-diagnostic-metrics-latencies.ts | 36 +++++++++---------- .../src/hashTree/hashTreeParser.ts | 29 +++++---------- .../test/unit/spec/hashTree/hashTreeParser.ts | 11 +++--- 4 files changed, 44 insertions(+), 48 deletions(-) diff --git a/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts b/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts index ad9947babe6..97e20f6697a 100644 --- a/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts +++ b/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts @@ -8,7 +8,7 @@ import {MetricEventNames, PreComputedLatencies} from '../metrics.types'; // we only care about client event and feature event for now type LocusSyncLatencyMilestone = { - meetingId?: string; + meetingId: string; dataSetName: string; key: MetricEventNames; value: number; @@ -69,22 +69,26 @@ export default class CallDiagnosticLatencies extends WebexPlugin { * @param dataSetName dataset name * @param meetingId meeting id */ - public clearLocusSyncLatency(dataSetName: string, meetingId?: string) { + public clearLocusSyncLatency(dataSetName: string, meetingId: string) { this.locusSyncLatencies.delete(this.getLocusSyncLatencyKey(dataSetName, meetingId)); } /** * Calculates Locus sync latency values from stored milestone timestamps. * @param dataSetName dataset name + * @param meetingId meeting id * @returns sync latency metrics */ - public getLocusSyncLatency(dataSetName: string, meetingId?: string) { + public getLocusSyncLatency(dataSetName: string, meetingId: string) { const record = this.locusSyncLatencies.get(this.getLocusSyncLatencyKey(dataSetName, meetingId)); if (!record) { return undefined; } + // Some sync flows skip the /hashtree request, for example single-leaf data sets or cases + // where we already know which leaves to sync. Treat the missing hashtree segment as 0, + // while still requiring the sync request/response/message milestones below. const hashtreePrepTime = this.getDiffBetweenLocusSyncTimestamps(record, 'syncStart', 'hashTreeRequest') ?? 0; const hashtreeResponseTime = @@ -177,8 +181,8 @@ export default class CallDiagnosticLatencies extends WebexPlugin { * @param meetingId meeting id * @returns storage key */ - private getLocusSyncLatencyKey(dataSetName: string, meetingId?: string) { - return meetingId ? `${meetingId}:${dataSetName}` : dataSetName; + private getLocusSyncLatencyKey(dataSetName: string, meetingId: string) { + return `${meetingId}:${dataSetName}`; } /** @@ -290,7 +294,7 @@ export default class CallDiagnosticLatencies extends WebexPlugin { this.setMeetingId(meetingId); } - if (this.isLocusSyncLatencyEvent(key) && options.dataSetName) { + if (this.isLocusSyncLatencyEvent(key) && options.dataSetName && options.meetingId) { this.saveLocusSyncLatencyTimestamp({ meetingId: options.meetingId, dataSetName: options.dataSetName, diff --git a/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts b/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts index f56de987f92..9acefbad646 100644 --- a/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts +++ b/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts @@ -111,7 +111,7 @@ describe('internal-plugin-metrics', () => { cdl.saveTimestamp({ key: 'internal.client.locus.sync.start', value: 1, - options: {dataSetName: 'main', randomBackoffTime: 10}, + options: {meetingId: 'meeting-1', dataSetName: 'main', randomBackoffTime: 10}, }); assert.deepEqual(cdl.locusSyncLatencies.size, 1); @@ -127,35 +127,35 @@ describe('internal-plugin-metrics', () => { cdl.saveTimestamp({ key: 'internal.client.locus.sync.start', value: 100, - options: {dataSetName: 'main', randomBackoffTime: 10.4}, + options: {meetingId: 'meeting-1', dataSetName: 'main', randomBackoffTime: 10.4}, }); cdl.saveTimestamp({ key: 'internal.client.locus.hashtree.request', value: 105, - options: {dataSetName: 'main'}, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, }); cdl.saveTimestamp({ key: 'internal.client.locus.hashtree.response', value: 125, - options: {dataSetName: 'main'}, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, }); cdl.saveTimestamp({ key: 'internal.client.locus.sync.request', value: 128, - options: {dataSetName: 'main'}, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, }); cdl.saveTimestamp({ key: 'internal.client.locus.sync.response', value: 143, - options: {dataSetName: 'main'}, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, }); cdl.saveTimestamp({ key: 'internal.client.locus.sync.message.received', value: 150, - options: {dataSetName: 'main'}, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, }); - assert.deepEqual(cdl.getLocusSyncLatency('main'), { + assert.deepEqual(cdl.getLocusSyncLatency('main', 'meeting-1'), { randomBackoffTime: 10, hashtreePrepTime: 5, hashtreeResponseTime: 20, @@ -170,25 +170,25 @@ describe('internal-plugin-metrics', () => { cdl.saveTimestamp({ key: 'internal.client.locus.sync.start', value: 100, - options: {dataSetName: 'main', randomBackoffTime: 0}, + options: {meetingId: 'meeting-1', dataSetName: 'main', randomBackoffTime: 0}, }); cdl.saveTimestamp({ key: 'internal.client.locus.sync.request', value: 110, - options: {dataSetName: 'main'}, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, }); cdl.saveTimestamp({ key: 'internal.client.locus.sync.response', value: 130, - options: {dataSetName: 'main'}, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, }); cdl.saveTimestamp({ key: 'internal.client.locus.sync.message.received', value: 140, - options: {dataSetName: 'main'}, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, }); - assert.deepEqual(cdl.getLocusSyncLatency('main'), { + assert.deepEqual(cdl.getLocusSyncLatency('main', 'meeting-1'), { randomBackoffTime: 0, hashtreePrepTime: 0, hashtreeResponseTime: 0, @@ -272,17 +272,17 @@ describe('internal-plugin-metrics', () => { cdl.saveTimestamp({ key: 'internal.client.locus.sync.start', value: 100, - options: {dataSetName: 'main', randomBackoffTime: 0}, + options: {meetingId: 'meeting-1', dataSetName: 'main', randomBackoffTime: 0}, }); cdl.saveTimestamp({ key: 'internal.client.locus.sync.message.received', value: 140, - options: {dataSetName: 'main'}, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, }); - assert.isUndefined(cdl.getLocusSyncLatency('main')); - cdl.clearLocusSyncLatency('main'); - assert.isFalse(cdl.locusSyncLatencies.has('main')); + assert.isUndefined(cdl.getLocusSyncLatency('main', 'meeting-1')); + cdl.clearLocusSyncLatency('main', 'meeting-1'); + assert.isFalse(cdl.locusSyncLatencies.has('meeting-1:main')); }); }); diff --git a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts index 9dd21f1d942..7f3b18eddbf 100644 --- a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts @@ -110,10 +110,10 @@ export type SyncLatencyTracker = { | 'internal.client.locus.sync.request' | 'internal.client.locus.sync.response' | 'internal.client.locus.sync.message.received'; - options: {meetingId?: string; dataSetName: string; randomBackoffTime?: number}; + options: {meetingId: string; dataSetName: string; randomBackoffTime?: number}; }) => void; - getLocusSyncLatency: (dataSetName: string, meetingId?: string) => SyncLatencyMetrics | undefined; - clearLocusSyncLatency: (dataSetName: string, meetingId?: string) => void; + getLocusSyncLatency: (dataSetName: string, meetingId: string) => SyncLatencyMetrics | undefined; + clearLocusSyncLatency: (dataSetName: string, meetingId: string) => void; }; export type HashTreeParserCallbacks = { @@ -179,7 +179,7 @@ class HashTreeParser { webexRequest: WebexRequestMethod; private callbacks: HashTreeParserCallbacks; private syncLatencyTracker?: SyncLatencyTracker; - private syncLatencyMeetingId?: string; + private syncLatencyMeetingId: string; visibleDataSets: VisibleDataSetInfo[]; debugId: string; private excludedDataSets: string[]; @@ -216,7 +216,7 @@ class HashTreeParser { callbacks: HashTreeParserCallbacks; debugId: string; excludedDataSets?: string[]; - syncLatencyMeetingId?: string; + syncLatencyMeetingId: string; }) { const {dataSets, locus} = options.initialLocus; // extract dataSets from initialLocus @@ -1303,14 +1303,11 @@ class HashTreeParser { * @returns {object} sync latency timestamp options */ private getSyncLatencyTimestampOptions(dataSetName: string, randomBackoffTime?: number) { - const options: {meetingId?: string; dataSetName: string; randomBackoffTime?: number} = { + const options: {meetingId: string; dataSetName: string; randomBackoffTime?: number} = { + meetingId: this.syncLatencyMeetingId, dataSetName, }; - if (this.syncLatencyMeetingId) { - options.meetingId = this.syncLatencyMeetingId; - } - if (typeof randomBackoffTime === 'number') { options.randomBackoffTime = randomBackoffTime; } @@ -1324,9 +1321,7 @@ class HashTreeParser { * @returns {SyncLatencyMetrics|undefined} sync latency metrics */ private getLocusSyncLatency(dataSetName: string): SyncLatencyMetrics | undefined { - return this.syncLatencyMeetingId - ? this.syncLatencyTracker?.getLocusSyncLatency(dataSetName, this.syncLatencyMeetingId) - : this.syncLatencyTracker?.getLocusSyncLatency(dataSetName); + return this.syncLatencyTracker?.getLocusSyncLatency(dataSetName, this.syncLatencyMeetingId); } /** @@ -1335,13 +1330,7 @@ class HashTreeParser { * @returns {void} */ private clearLocusSyncLatency(dataSetName: string): void { - if (this.syncLatencyMeetingId) { - this.syncLatencyTracker?.clearLocusSyncLatency(dataSetName, this.syncLatencyMeetingId); - - return; - } - - this.syncLatencyTracker?.clearLocusSyncLatency(dataSetName); + this.syncLatencyTracker?.clearLocusSyncLatency(dataSetName, this.syncLatencyMeetingId); } /** diff --git a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts index eeac3c4521d..229930c2915 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts @@ -180,7 +180,7 @@ describe('HashTreeParser', () => { excludedDataSets?: string[], syncMetricsCallback: sinon.SinonStub = sinon.stub(), syncLatencyTracker?: any, - syncLatencyMeetingId?: string + syncLatencyMeetingId = 'meeting-1' ) { return new HashTreeParser({ initialLocus, @@ -3152,6 +3152,7 @@ describe('HashTreeParser', () => { assert.calledWith(syncLatencyTracker.saveTimestamp, { key: 'internal.client.locus.sync.start', options: { + meetingId: 'meeting-1', dataSetName: 'main', randomBackoffTime: 250, }, @@ -3194,6 +3195,7 @@ describe('HashTreeParser', () => { assert.calledWith(syncLatencyTracker.saveTimestamp, { key: 'internal.client.locus.sync.start', options: { + meetingId: 'meeting-1', dataSetName: 'main', randomBackoffTime: 10, }, @@ -4832,6 +4834,7 @@ describe('HashTreeParser', () => { assert.calledWith(syncLatencyTracker.saveTimestamp, { key: 'internal.client.locus.sync.start', options: { + meetingId: 'meeting-1', dataSetName: 'main', randomBackoffTime: 250, }, @@ -5632,10 +5635,10 @@ describe('HashTreeParser', () => { assert.deepEqual(arg.syncLatency, syncLatency); assert.calledOnceWithExactly(syncLatencyTracker.saveTimestamp, { key: 'internal.client.locus.sync.message.received', - options: {dataSetName: 'main'}, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, }); - assert.calledOnceWithExactly(syncLatencyTracker.getLocusSyncLatency, 'main'); - assert.calledOnceWithExactly(syncLatencyTracker.clearLocusSyncLatency, 'main'); + assert.calledOnceWithExactly(syncLatencyTracker.getLocusSyncLatency, 'main', 'meeting-1'); + assert.calledOnceWithExactly(syncLatencyTracker.clearLocusSyncLatency, 'main', 'meeting-1'); assert.isFalse(parser['pendingSyncMetrics'].has('main')); }); From 36a630384463e9579b605b8cf77ae493f9c8f060 Mon Sep 17 00:00:00 2001 From: tiahan Date: Wed, 3 Jun 2026 10:27:02 +0800 Subject: [PATCH 23/29] refactor(metrics): share locus sync latency event definitions --- .../call-diagnostic-metrics-latencies.ts | 15 ++++++--------- .../src/metrics.types.ts | 18 ++++++++++++------ 2 files changed, 18 insertions(+), 15 deletions(-) diff --git a/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts b/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts index 97e20f6697a..d83c512efb8 100644 --- a/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts +++ b/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts @@ -3,7 +3,11 @@ import {WebexPlugin} from '@webex/webex-core'; import {clamp} from 'lodash'; -import {MetricEventNames, PreComputedLatencies} from '../metrics.types'; +import { + LOCUS_SYNC_LATENCY_EVENT_NAMES, + MetricEventNames, + PreComputedLatencies, +} from '../metrics.types'; // we only care about client event and feature event for now @@ -191,14 +195,7 @@ export default class CallDiagnosticLatencies extends WebexPlugin { * @returns whether event is Locus sync latency milestone */ private isLocusSyncLatencyEvent(key: MetricEventNames) { - return [ - 'internal.client.locus.sync.start', - 'internal.client.locus.hashtree.request', - 'internal.client.locus.hashtree.response', - 'internal.client.locus.sync.request', - 'internal.client.locus.sync.response', - 'internal.client.locus.sync.message.received', - ].includes(key); + return LOCUS_SYNC_LATENCY_EVENT_NAMES.includes(key as any); } /** diff --git a/packages/@webex/internal-plugin-metrics/src/metrics.types.ts b/packages/@webex/internal-plugin-metrics/src/metrics.types.ts index b6b3308a174..596b903df86 100644 --- a/packages/@webex/internal-plugin-metrics/src/metrics.types.ts +++ b/packages/@webex/internal-plugin-metrics/src/metrics.types.ts @@ -149,6 +149,17 @@ export type SubmitMQEOptions = { globalMeetingId?: string; }; +export const LOCUS_SYNC_LATENCY_EVENT_NAMES = [ + 'internal.client.locus.sync.start', + 'internal.client.locus.hashtree.request', + 'internal.client.locus.hashtree.response', + 'internal.client.locus.sync.request', + 'internal.client.locus.sync.response', + 'internal.client.locus.sync.message.received', +] as const; + +export type LocusSyncLatencyEventName = (typeof LOCUS_SYNC_LATENCY_EVENT_NAMES)[number]; + export type InternalEvent = { name: | 'internal.client.meetinginfo.request' @@ -163,12 +174,7 @@ export type InternalEvent = { | 'internal.client.add-media.turn-discovery.end' | 'internal.client.share.initiated' | 'internal.client.share.stopped' - | 'internal.client.locus.sync.start' - | 'internal.client.locus.hashtree.request' - | 'internal.client.locus.hashtree.response' - | 'internal.client.locus.sync.request' - | 'internal.client.locus.sync.response' - | 'internal.client.locus.sync.message.received'; + | LocusSyncLatencyEventName; payload?: never; options?: never; From 528c8212fc3e9a5b1c0af9e5b6fd299365fc2216 Mon Sep 17 00:00:00 2001 From: tiahan Date: Wed, 3 Jun 2026 13:06:57 +0800 Subject: [PATCH 24/29] refactor(meetings): use callbacks sync latency tracker directly --- .../internal-plugin-metrics/src/index.ts | 2 ++ .../call-diagnostic-metrics-latencies.ts | 18 +++++----- .../src/hashTree/hashTreeParser.ts | 35 +++++++++---------- 3 files changed, 28 insertions(+), 27 deletions(-) diff --git a/packages/@webex/internal-plugin-metrics/src/index.ts b/packages/@webex/internal-plugin-metrics/src/index.ts index 84678f83a44..983f4b0121c 100644 --- a/packages/@webex/internal-plugin-metrics/src/index.ts +++ b/packages/@webex/internal-plugin-metrics/src/index.ts @@ -19,6 +19,7 @@ import { SubmitMQE, PreComputedLatencies, SubmitFeatureEvent, + LocusSyncLatencyEventName, } from './metrics.types'; import * as CALL_DIAGNOSTIC_CONFIG from './call-diagnostic/config'; import * as CallDiagnosticUtils from './call-diagnostic/call-diagnostic-metrics.util'; @@ -65,4 +66,5 @@ export type { SubmitBusinessEvent, PreComputedLatencies, SubmitFeatureEvent, + LocusSyncLatencyEventName, }; diff --git a/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts b/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts index 9acefbad646..fa3e5749804 100644 --- a/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts +++ b/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts @@ -214,21 +214,21 @@ describe('internal-plugin-metrics', () => { cdl.saveTimestamp({ key: 'internal.client.locus.sync.start', value: 200, - options: {meetingId: 'meeting-2', dataSetName: 'main', randomBackoffTime: 20}, + options: {meetingId: 'meeting-2', dataSetName: 'main', randomBackoffTime: 23}, }); cdl.saveTimestamp({ key: 'internal.client.locus.sync.request', - value: 220, + value: 217, options: {meetingId: 'meeting-2', dataSetName: 'main'}, }); cdl.saveTimestamp({ key: 'internal.client.locus.sync.response', - value: 240, + value: 241, options: {meetingId: 'meeting-2', dataSetName: 'main'}, }); cdl.saveTimestamp({ key: 'internal.client.locus.sync.message.received', - value: 260, + value: 268, options: {meetingId: 'meeting-2', dataSetName: 'main'}, }); @@ -253,13 +253,13 @@ describe('internal-plugin-metrics', () => { totalTime: 50, }); assert.deepEqual(cdl.getLocusSyncLatency('main', 'meeting-2'), { - randomBackoffTime: 20, + randomBackoffTime: 23, hashtreePrepTime: 0, hashtreeResponseTime: 0, - syncPrepTime: 20, - syncResponseTime: 20, - syncMessageReceiveTime: 20, - totalTime: 60, + syncPrepTime: 17, + syncResponseTime: 24, + syncMessageReceiveTime: 27, + totalTime: 68, }); cdl.clearLocusSyncLatency('main', 'meeting-1'); diff --git a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts index 7f3b18eddbf..e0f171ebe2e 100644 --- a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts @@ -1,4 +1,5 @@ import {cloneDeep, isEmpty, zip} from 'lodash'; +import type {LocusSyncLatencyEventName} from '@webex/internal-plugin-metrics'; import HashTree, {LeafDataItem} from './hashTree'; import LoggerProxy from '../common/logs/logger-proxy'; import Metrics from '../metrics'; @@ -103,13 +104,7 @@ export type SyncMetricsCallback = (metrics: { export type SyncLatencyTracker = { saveTimestamp: (options: { - key: - | 'internal.client.locus.sync.start' - | 'internal.client.locus.hashtree.request' - | 'internal.client.locus.hashtree.response' - | 'internal.client.locus.sync.request' - | 'internal.client.locus.sync.response' - | 'internal.client.locus.sync.message.received'; + key: LocusSyncLatencyEventName; options: {meetingId: string; dataSetName: string; randomBackoffTime?: number}; }) => void; getLocusSyncLatency: (dataSetName: string, meetingId: string) => SyncLatencyMetrics | undefined; @@ -178,7 +173,6 @@ class HashTreeParser { visibleDataSetsUrl: string; // url from which we can get info about all data sets webexRequest: WebexRequestMethod; private callbacks: HashTreeParserCallbacks; - private syncLatencyTracker?: SyncLatencyTracker; private syncLatencyMeetingId: string; visibleDataSets: VisibleDataSetInfo[]; debugId: string; @@ -223,7 +217,6 @@ class HashTreeParser { this.debugId = options.debugId; this.webexRequest = options.webexRequest; this.callbacks = options.callbacks; - this.syncLatencyTracker = options.callbacks.syncLatencyTracker; this.syncLatencyMeetingId = options.syncLatencyMeetingId; this.excludedDataSets = options.excludedDataSets || []; this.visibleDataSetsUrl = locus?.links?.resources?.visibleDataSets?.url; @@ -1289,7 +1282,7 @@ class HashTreeParser { */ private shouldCollectSyncMetrics(dataSetName: string, isInitialization = false): boolean { return Boolean( - this.syncLatencyTracker && + this.callbacks.syncLatencyTracker && !isInitialization && SYNC_METRICS_DATA_SETS.includes(dataSetName) && !this.pendingSyncMetrics.has(dataSetName) @@ -1321,7 +1314,10 @@ class HashTreeParser { * @returns {SyncLatencyMetrics|undefined} sync latency metrics */ private getLocusSyncLatency(dataSetName: string): SyncLatencyMetrics | undefined { - return this.syncLatencyTracker?.getLocusSyncLatency(dataSetName, this.syncLatencyMeetingId); + return this.callbacks.syncLatencyTracker?.getLocusSyncLatency( + dataSetName, + this.syncLatencyMeetingId + ); } /** @@ -1330,7 +1326,10 @@ class HashTreeParser { * @returns {void} */ private clearLocusSyncLatency(dataSetName: string): void { - this.syncLatencyTracker?.clearLocusSyncLatency(dataSetName, this.syncLatencyMeetingId); + this.callbacks.syncLatencyTracker?.clearLocusSyncLatency( + dataSetName, + this.syncLatencyMeetingId + ); } /** @@ -1347,7 +1346,7 @@ class HashTreeParser { } this.pendingSyncMetrics.delete(dataSetName); - this.syncLatencyTracker?.saveTimestamp({ + this.callbacks.syncLatencyTracker?.saveTimestamp({ key: 'internal.client.locus.sync.message.received', options: this.getSyncLatencyTimestampOptions(dataSetName), }); @@ -1472,7 +1471,7 @@ class HashTreeParser { : dataSet.version; if (shouldCollectMetrics) { - this.syncLatencyTracker?.saveTimestamp({ + this.callbacks.syncLatencyTracker?.saveTimestamp({ key: 'internal.client.locus.sync.start', options: this.getSyncLatencyTimestampOptions( dataSet.name, @@ -2126,7 +2125,7 @@ class HashTreeParser { const url = `${dataSet.url}/hashtree`; if (this.shouldCollectSyncMetrics(dataSetName)) { - this.syncLatencyTracker?.saveTimestamp({ + this.callbacks.syncLatencyTracker?.saveTimestamp({ key: 'internal.client.locus.hashtree.request', options: this.getSyncLatencyTimestampOptions(dataSetName), }); @@ -2141,7 +2140,7 @@ class HashTreeParser { }) .then((response) => { if (this.shouldCollectSyncMetrics(dataSetName)) { - this.syncLatencyTracker?.saveTimestamp({ + this.callbacks.syncLatencyTracker?.saveTimestamp({ key: 'internal.client.locus.hashtree.response', options: this.getSyncLatencyTimestampOptions(dataSetName), }); @@ -2241,7 +2240,7 @@ class HashTreeParser { const ourCurrentRootHash = dataSet.hashTree ? dataSet.hashTree.getRootHash() : EMPTY_HASH; if (this.shouldCollectSyncMetrics(dataSet.name, isInitialization)) { - this.syncLatencyTracker?.saveTimestamp({ + this.callbacks.syncLatencyTracker?.saveTimestamp({ key: 'internal.client.locus.sync.request', options: this.getSyncLatencyTimestampOptions(dataSet.name), }); @@ -2259,7 +2258,7 @@ class HashTreeParser { const trackingId = resp.headers?.trackingid || resp.headers?.trackingId; if (this.shouldCollectSyncMetrics(dataSet.name, isInitialization)) { - this.syncLatencyTracker?.saveTimestamp({ + this.callbacks.syncLatencyTracker?.saveTimestamp({ key: 'internal.client.locus.sync.response', options: this.getSyncLatencyTimestampOptions(dataSet.name), }); From a0ef7eee3e5d1c54695ede03ad71734810edcfbe Mon Sep 17 00:00:00 2001 From: tiahan Date: Wed, 3 Jun 2026 13:16:18 +0800 Subject: [PATCH 25/29] refactor(meetings): use updateMeeting callback from callbacks --- .../plugin-meetings/src/locus-info/index.ts | 28 +++++++++---------- .../test/unit/spec/locus-info/index.js | 11 ++++++-- 2 files changed, 21 insertions(+), 18 deletions(-) diff --git a/packages/@webex/plugin-meetings/src/locus-info/index.ts b/packages/@webex/plugin-meetings/src/locus-info/index.ts index 46f4d748e0b..c35ae6a95aa 100644 --- a/packages/@webex/plugin-meetings/src/locus-info/index.ts +++ b/packages/@webex/plugin-meetings/src/locus-info/index.ts @@ -271,7 +271,6 @@ export default class LocusInfo extends EventsScope { locusParser: any; meetingId: any; parsedLocus: any; - updateMeeting: any; webex: any; aclUrl: any; baseSequence: any; @@ -316,7 +315,6 @@ export default class LocusInfo extends EventsScope { this.emitChange = false; this.compareAndUpdateFlags = {}; this.meetingId = meetingId; - this.updateMeeting = callbacks.updateMeeting; this.locusParser = new LocusDeltaParser(); this.hashTreeParsers = new Map(); this.hashTreeObjectId2ParticipantId = new Map(); @@ -1770,7 +1768,7 @@ export default class LocusInfo extends EventsScope { // @ts-ignore const partner = this.getLocusPartner(this.participants, this.self); - this.updateMeeting({partner}); + this.callbacks.updateMeeting({partner}); // Check if guest user needs to be checked here @@ -2255,7 +2253,7 @@ export default class LocusInfo extends EventsScope { if (hasEntryExitToneChanged) { const {entryExitTone} = current; - this.updateMeeting({entryExitTone}); + this.callbacks.updateMeeting({entryExitTone}); this.emitScoped( { @@ -2274,7 +2272,7 @@ export default class LocusInfo extends EventsScope { if (hasVideoEnabledChanged) { const {videoEnabled} = current; - this.updateMeeting({unmuteVideoAllowed: videoEnabled}); + this.callbacks.updateMeeting({unmuteVideoAllowed: videoEnabled}); this.emitScoped( { @@ -2366,14 +2364,14 @@ export default class LocusInfo extends EventsScope { updateConversationUrl(conversationUrl: string, info: any) { if (conversationUrl && !isEqual(this.conversationUrl, conversationUrl)) { this.conversationUrl = conversationUrl; - this.updateMeeting({conversationUrl}); + this.callbacks.updateMeeting({conversationUrl}); } else if ( info && info.conversationUrl && !isEqual(this.conversationUrl, info.conversationUrl) ) { this.conversationUrl = info.conversationUrl; - this.updateMeeting({conversationUrl: info.conversationUrl}); + this.callbacks.updateMeeting({conversationUrl: info.conversationUrl}); } } @@ -2435,7 +2433,7 @@ export default class LocusInfo extends EventsScope { if (fullState && !isEqual(this.fullState, fullState)) { const result = FullState.getFullState(this.fullState, fullState); - this.updateMeeting(result.current); + this.callbacks.updateMeeting(result.current); if (result.updates.meetingStateChangedTo) { this.emitScoped( @@ -2479,7 +2477,7 @@ export default class LocusInfo extends EventsScope { if (host && !isEqual(this.host, host)) { const parsedHosts = HostUtils.getHosts(this.host, host); - this.updateMeeting(parsedHosts.current); + this.callbacks.updateMeeting(parsedHosts.current); this.parsedLocus.host = parsedHosts.current; if (parsedHosts.updates.isNewHost) { this.compareAndUpdateFlags.compareSelfAndHost = true; @@ -2537,7 +2535,7 @@ export default class LocusInfo extends EventsScope { this.info = info; this.parsedLocus.info = parsedInfo.current; // Parses the info and adds necessary values - this.updateMeeting(parsedInfo.current); + this.callbacks.updateMeeting(parsedInfo.current); this.emitScoped( { @@ -2566,7 +2564,7 @@ export default class LocusInfo extends EventsScope { const parsedEmbeddedApps = EmbeddedAppsUtils.parse(embeddedApps); - this.updateMeeting({embeddedApps: parsedEmbeddedApps}); + this.callbacks.updateMeeting({embeddedApps: parsedEmbeddedApps}); this.emitScoped( { @@ -2591,7 +2589,7 @@ export default class LocusInfo extends EventsScope { if (mediaShares && (!isEqual(this.mediaShares, mediaShares) || forceUpdate)) { const parsedMediaShares = MediaSharesUtils.getMediaShares(this.mediaShares, mediaShares); - this.updateMeeting(parsedMediaShares.current); + this.callbacks.updateMeeting(parsedMediaShares.current); this.parsedLocus.mediaShares = parsedMediaShares.current; this.mediaShares = mediaShares; this.emitScoped( @@ -2637,7 +2635,7 @@ export default class LocusInfo extends EventsScope { this.participants // using this.participants instead of locus.participants here, because with delta DTOs locus.participants will only contain a small subset of participants ); - this.updateMeeting(parsedSelves.current); + this.callbacks.updateMeeting(parsedSelves.current); this.parsedLocus.self = parsedSelves.current; const element = this.parsedLocus.states[this.parsedLocus.states.length - 1]; @@ -2655,7 +2653,7 @@ export default class LocusInfo extends EventsScope { ); if (result?.sipUri) { - this.updateMeeting(result); + this.callbacks.updateMeeting(result); } if (parsedSelves.updates.moderatorChanged) { @@ -2922,7 +2920,7 @@ export default class LocusInfo extends EventsScope { updateLocusUrl(url: string, isMainLocus = true) { if (url && this.url !== url) { this.url = url; - this.updateMeeting({locusUrl: url}); + this.callbacks.updateMeeting({locusUrl: url}); this.emitScoped( { file: 'locus-info', diff --git a/packages/@webex/plugin-meetings/test/unit/spec/locus-info/index.js b/packages/@webex/plugin-meetings/test/unit/spec/locus-info/index.js index b19531fd035..259d732e1c0 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/locus-info/index.js +++ b/packages/@webex/plugin-meetings/test/unit/spec/locus-info/index.js @@ -3448,7 +3448,7 @@ describe('plugin-meetings', () => { stateElementsMessage: message, }); - assert.calledOnceWithExactly(parserA.handleMessage, message); + assert.calledOnceWithExactly(parserA.handleMessage, message, undefined, undefined); }); it('should pass replacedAt from replaces to createHashTreeParser when creating a new parser', () => { @@ -3511,7 +3511,7 @@ describe('plugin-meetings', () => { stateElementsMessage: message, }); - assert.calledOnceWithExactly(parserA.handleMessage, message); + assert.calledOnceWithExactly(parserA.handleMessage, message, undefined, undefined); }); it('should send mismatch metric when eventType is not HASH_TREE_DATA_UPDATED', () => { @@ -5317,7 +5317,12 @@ describe('plugin-meetings', () => { locusInfo.parse(mockMeeting, data); - assert.calledOnceWithExactly(mockHashTreeParser.handleMessage, fakeHashTreeMessage); + assert.calledOnceWithExactly( + mockHashTreeParser.handleMessage, + fakeHashTreeMessage, + undefined, + undefined + ); }); it('ignores hash tree event when hashTreeParser is not created yet', () => { From 4356f3dd5dd5c5cabb6959f6d7a77d42c4cf6ed7 Mon Sep 17 00:00:00 2001 From: tiahan Date: Thu, 4 Jun 2026 09:29:26 +0800 Subject: [PATCH 26/29] fix(meetings): guard breakout LLM join metrics --- .../plugin-meetings/src/meeting/index.ts | 72 +++++++++++-------- .../test/unit/spec/meeting/index.js | 52 +++++++++++++- 2 files changed, 94 insertions(+), 30 deletions(-) diff --git a/packages/@webex/plugin-meetings/src/meeting/index.ts b/packages/@webex/plugin-meetings/src/meeting/index.ts index a97a8be061b..2a61b93d6f1 100644 --- a/packages/@webex/plugin-meetings/src/meeting/index.ts +++ b/packages/@webex/plugin-meetings/src/meeting/index.ts @@ -6804,21 +6804,28 @@ export default class Meeting extends StatelessWebexPlugin { } const breakoutMoveId = this.breakouts?.breakoutMoveId; + const currentBreakoutSession = this.breakouts?.currentBreakoutSession; - // @ts-ignore - const llmWebsocketUrl = this.webex.internal.llm.getWebSocketUrl?.() || undefined; - - breakoutEvent.onBreakoutJoinResponse( - { - currentSession: this.breakouts?.currentBreakoutSession, - meeting: this, - breakoutMoveId, - llmLatency: registerAndConnectResult, - llmWebsocketUrl, - }, + if ( + breakoutMoveId && + currentBreakoutSession?.sessionId && + currentBreakoutSession?.groupId + ) { // @ts-ignore - this.webex.internal.newMetrics.submitClientEvent.bind(this.webex.internal.newMetrics) - ); + const llmWebsocketUrl = this.webex.internal.llm.getWebSocketUrl?.() || undefined; + + breakoutEvent.onBreakoutJoinResponse( + { + currentSession: currentBreakoutSession, + meeting: this, + breakoutMoveId, + llmLatency: registerAndConnectResult, + llmWebsocketUrl, + }, + // @ts-ignore + this.webex.internal.newMetrics.submitClientEvent.bind(this.webex.internal.newMetrics) + ); + } } return Promise.resolve(registerAndConnectResult); @@ -6835,25 +6842,32 @@ export default class Meeting extends StatelessWebexPlugin { } const breakoutMoveId = this.breakouts?.breakoutMoveId; + const currentBreakoutSession = this.breakouts?.currentBreakoutSession; - // @ts-ignore - const llmWebsocketUrl = this.webex.internal.llm.getWebSocketUrl?.() || undefined; + if ( + breakoutMoveId && + currentBreakoutSession?.sessionId && + currentBreakoutSession?.groupId + ) { + // @ts-ignore + const llmWebsocketUrl = this.webex.internal.llm.getWebSocketUrl?.() || undefined; - breakoutEvent.onBreakoutJoinResponse( - { - currentSession: this.breakouts?.currentBreakoutSession, - meeting: this, - breakoutMoveId, - llmLatency: { - clientLLMDatachannelResponseTime: 0, - clientLLMWebSocketConnectTime: 0, + breakoutEvent.onBreakoutJoinResponse( + { + currentSession: currentBreakoutSession, + meeting: this, + breakoutMoveId, + llmLatency: { + clientLLMDatachannelResponseTime: 0, + clientLLMWebSocketConnectTime: 0, + }, + llmWebsocketUrl, + error, }, - llmWebsocketUrl, - error, - }, - // @ts-ignore - this.webex.internal.newMetrics.submitClientEvent.bind(this.webex.internal.newMetrics) - ); + // @ts-ignore + this.webex.internal.newMetrics.submitClientEvent.bind(this.webex.internal.newMetrics) + ); + } return Promise.reject(error); }); diff --git a/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js b/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js index c0debce71ea..ac52121ab33 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js +++ b/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js @@ -2601,7 +2601,7 @@ describe('plugin-meetings', () => { locusLLMEventListener({data: eventData}); - assert.calledOnceWithExactly(locusInfoParseStub, meeting, eventData); + assert.calledOnceWithExactly(locusInfoParseStub, meeting, eventData, undefined); }); it('UpdateLLMConnection sends a metric if not connected after timeout', async () => { @@ -2655,6 +2655,56 @@ describe('plugin-meetings', () => { assert.equal(joinResponseCalls[0].args[0].options.meetingId, meeting.id); }); + it('does not emit breakout join response metric when breakout session is missing', async () => { + sinon.stub(meeting, 'isJoined').returns(true); + sinon.stub(meeting.webex.internal.llm, 'isConnected').returns(false); + sinon.stub(meeting.webex.internal.llm, 'registerAndConnect').resolves({ + clientLLMDatachannelResponseTime: 10, + clientLLMWebSocketConnectTime: 20, + }); + + meeting.meetingInfo.enableConvergedArchitecture = true; + meeting.breakouts.set('breakoutMoveId', 'move-id-1'); + + webex.internal.newMetrics.submitClientEvent.resetHistory(); + meeting.updateLLMConnection.restore(); + + await meeting.updateLLMConnection(); + + const joinResponseCalls = webex.internal.newMetrics.submitClientEvent + .getCalls() + .filter((call) => call.args[0]?.name === 'client.breakout-session.join.response'); + + assert.lengthOf(joinResponseCalls, 0); + }); + + it('does not emit failed breakout join response metric when breakout session is missing', async () => { + sinon.stub(meeting, 'isJoined').returns(true); + sinon.stub(meeting.webex.internal.llm, 'isConnected').returns(false); + sinon + .stub(meeting.webex.internal.llm, 'registerAndConnect') + .rejects(new Error('failed to connect LLM')); + + meeting.meetingInfo.enableConvergedArchitecture = true; + meeting.breakouts.set('breakoutMoveId', 'move-id-1'); + + webex.internal.newMetrics.submitClientEvent.resetHistory(); + meeting.updateLLMConnection.restore(); + + try { + await meeting.updateLLMConnection(); + assert.fail('Expected updateLLMConnection to reject'); + } catch (error) { + assert.equal(error.message, 'failed to connect LLM'); + } + + const joinResponseCalls = webex.internal.newMetrics.submitClientEvent + .getCalls() + .filter((call) => call.args[0]?.name === 'client.breakout-session.join.response'); + + assert.lengthOf(joinResponseCalls, 0); + }); + it('emits llm breakout join response metric even if updateBreakout already emitted one without llmLatency', async () => { sinon.stub(meeting, 'isJoined').returns(true); sinon.stub(meeting.webex.internal.llm, 'isConnected').returns(false); From 444d4c562f086617b79d1ff37da4ea0af904d24c Mon Sep 17 00:00:00 2001 From: tiahan Date: Thu, 4 Jun 2026 09:42:48 +0800 Subject: [PATCH 27/29] refactor(meetings): simplify LLM metric payload construction --- .../plugin-meetings/src/breakouts/events.ts | 15 +++------------ .../plugin-meetings/src/meeting/index.ts | 19 +++++++------------ .../test/unit/spec/breakouts/events.ts | 1 + 3 files changed, 11 insertions(+), 24 deletions(-) diff --git a/packages/@webex/plugin-meetings/src/breakouts/events.ts b/packages/@webex/plugin-meetings/src/breakouts/events.ts index 2e277465351..542a41b1522 100644 --- a/packages/@webex/plugin-meetings/src/breakouts/events.ts +++ b/packages/@webex/plugin-meetings/src/breakouts/events.ts @@ -55,28 +55,19 @@ const breakoutEvent: { breakoutMoveId, breakoutSessionId: currentSession?.sessionId, breakoutGroupId: currentSession?.groupId, + llmWebsocketUrl, }; - if (llmWebsocketUrl) { - identifiers.llmWebsocketUrl = llmWebsocketUrl; - } - const payload: any = { identifiers, + ...(llmLatency && {llmLatency}), }; - if (llmLatency) { - payload.llmLatency = llmLatency; - } - const options: any = { meetingId: meeting.id, + ...(error && {rawError: error}), }; - if (error) { - options.rawError = error; - } - submitClientEvent({ name: event, payload, diff --git a/packages/@webex/plugin-meetings/src/meeting/index.ts b/packages/@webex/plugin-meetings/src/meeting/index.ts index 2a61b93d6f1..c1fa6e26e4a 100644 --- a/packages/@webex/plugin-meetings/src/meeting/index.ts +++ b/packages/@webex/plugin-meetings/src/meeting/index.ts @@ -6920,21 +6920,17 @@ export default class Meeting extends StatelessWebexPlugin { } const payload: any = { + identifiers: { + llmWebsocketUrl, + }, llmLatency, }; - if (llmWebsocketUrl) { - payload.identifiers = {llmWebsocketUrl}; - } - const options: any = { meetingId: this.id, + ...(error && {rawError: error}), }; - if (error) { - options.rawError = error; - } - // @ts-ignore this.webex.internal.newMetrics.submitClientEvent({ name: 'client.llm.connect.response', @@ -6955,16 +6951,15 @@ export default class Meeting extends StatelessWebexPlugin { const llmWebsocketUrl = this.webex.internal.llm.getWebSocketUrl?.() || undefined; const payload: any = { + identifiers: { + llmWebsocketUrl, + }, syncLatency: metrics.syncLatency, llmInfo: { dataSet: metrics.dataSet, }, }; - if (llmWebsocketUrl) { - payload.identifiers = {llmWebsocketUrl}; - } - // @ts-ignore this.webex.internal.newMetrics.submitClientEvent({ name: 'client.locus.sync.complete', diff --git a/packages/@webex/plugin-meetings/test/unit/spec/breakouts/events.ts b/packages/@webex/plugin-meetings/test/unit/spec/breakouts/events.ts index 6de16860c17..8644f9c2abd 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/breakouts/events.ts +++ b/packages/@webex/plugin-meetings/test/unit/spec/breakouts/events.ts @@ -121,6 +121,7 @@ describe('plugin-meetings', () => { breakoutMoveId: 'breakoutMoveId', breakoutSessionId: 'sessionId', breakoutGroupId: 'groupId', + llmWebsocketUrl: undefined, }, }, options: {meetingId: 'activeMeetingId'}, From 051bbd755811c43f8a7c059092b3e1a06bea9dde Mon Sep 17 00:00:00 2001 From: tiahan Date: Fri, 5 Jun 2026 17:11:22 +0800 Subject: [PATCH 28/29] fix(plugin-meetings): report locus sync complete metrics from parser messages --- .../call-diagnostic-metrics-latencies.ts | 120 +++++++- .../call-diagnostic-metrics-latencies.ts | 42 +++ .../plugin-meetings/src/breakouts/events.ts | 6 +- .../plugin-meetings/src/breakouts/index.ts | 68 +++++ .../@webex/plugin-meetings/src/constants.ts | 1 + .../src/hashTree/hashTreeParser.ts | 181 ++++-------- .../plugin-meetings/src/locus-info/index.ts | 5 +- .../plugin-meetings/src/meeting/index.ts | 101 +++---- .../test/unit/spec/hashTree/hashTreeParser.ts | 274 ++++-------------- .../test/unit/spec/locus-info/index.js | 5 +- .../test/unit/spec/meeting/index.js | 88 +++++- 11 files changed, 473 insertions(+), 418 deletions(-) diff --git a/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts b/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts index d83c512efb8..59ef8c68782 100644 --- a/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts +++ b/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts @@ -16,16 +16,21 @@ type LocusSyncLatencyMilestone = { dataSetName: string; key: MetricEventNames; value: number; + trackingId?: string; }; type SaveTimestampOptions = { meetingId?: string; dataSetName?: string; randomBackoffTime?: number; + trackingId?: string; }; type LocusSyncLatencyRecord = { + meetingId: string; + dataSetName: string; randomBackoffTime: number; + trackingId?: string; syncStart?: number; hashTreeRequest?: number; hashTreeResponse?: number; @@ -44,7 +49,7 @@ type LocusSyncLatencyTimestampKey = Exclude; precomputedLatencies: Map; - locusSyncLatencies: Map; + locusSyncLatencies: Map; // meetingId that the current latencies are for private meetingId?: string; private MAX_INTEGER = 2147483647; @@ -74,7 +79,19 @@ export default class CallDiagnosticLatencies extends WebexPlugin { * @param meetingId meeting id */ public clearLocusSyncLatency(dataSetName: string, meetingId: string) { - this.locusSyncLatencies.delete(this.getLocusSyncLatencyKey(dataSetName, meetingId)); + const records = this.locusSyncLatencies.get(meetingId); + + if (!records) { + return; + } + + const remainingRecords = records.filter((record) => record.dataSetName !== dataSetName); + + if (remainingRecords.length > 0) { + this.locusSyncLatencies.set(meetingId, remainingRecords); + } else { + this.locusSyncLatencies.delete(meetingId); + } } /** @@ -83,8 +100,8 @@ export default class CallDiagnosticLatencies extends WebexPlugin { * @param meetingId meeting id * @returns sync latency metrics */ - public getLocusSyncLatency(dataSetName: string, meetingId: string) { - const record = this.locusSyncLatencies.get(this.getLocusSyncLatencyKey(dataSetName, meetingId)); + public getLocusSyncLatency(dataSetName: string, meetingId: string, trackingId?: string) { + const record = this.getLatestLocusSyncLatencyRecord(meetingId, dataSetName, trackingId); if (!record) { return undefined; @@ -139,6 +156,39 @@ export default class CallDiagnosticLatencies extends WebexPlugin { }; } + /** + * Complete and remove the latest Locus sync latency record for a meeting. + * @param meetingId meeting id + * @param trackingId LLM event tracking id + * @returns completed sync latency metric payload + */ + public completeLocusSyncLatency(meetingId: string, trackingId?: string) { + const exactRecord = this.getLatestLocusSyncLatencyRecord(meetingId, undefined, trackingId); + const fallbackRecord = exactRecord + ? undefined + : this.getLatestLocusSyncLatencyRecord(meetingId); + const record = exactRecord ?? fallbackRecord; + + if (!record) { + return undefined; + } + + record.messageReceived = new Date().getTime(); + + const syncLatency = this.getLocusSyncLatency(record.dataSetName, meetingId, record.trackingId); + + this.removeLocusSyncLatencyRecord(record); + + if (!syncLatency) { + return undefined; + } + + return { + dataSet: record.dataSetName, + syncLatency, + }; + } + /** * Helper to calculate end - start for Locus sync milestones. * @param record tracked milestone timestamps @@ -179,14 +229,39 @@ export default class CallDiagnosticLatencies extends WebexPlugin { return Math.round(clamp(latency, 0, this.MAX_INTEGER)); } - /** - * Build a storage key for Locus sync latency records. - * @param dataSetName dataset name - * @param meetingId meeting id - * @returns storage key - */ - private getLocusSyncLatencyKey(dataSetName: string, meetingId: string) { - return `${meetingId}:${dataSetName}`; + private getLatestLocusSyncLatencyRecord( + meetingId: string, + dataSetName?: string, + trackingId?: string + ) { + const records = this.locusSyncLatencies.get(meetingId); + + if (!records) { + return undefined; + } + + return [...records].reverse().find((record) => { + const dataSetMatches = !dataSetName || record.dataSetName === dataSetName; + const trackingIdMatches = !trackingId || record.trackingId === trackingId; + + return dataSetMatches && trackingIdMatches; + }); + } + + private removeLocusSyncLatencyRecord(recordToRemove: LocusSyncLatencyRecord) { + const records = this.locusSyncLatencies.get(recordToRemove.meetingId); + + if (!records) { + return; + } + + const remainingRecords = records.filter((record) => record !== recordToRemove); + + if (remainingRecords.length > 0) { + this.locusSyncLatencies.set(recordToRemove.meetingId, remainingRecords); + } else { + this.locusSyncLatencies.delete(recordToRemove.meetingId); + } } /** @@ -207,25 +282,37 @@ export default class CallDiagnosticLatencies extends WebexPlugin { dataSetName, key, value, + trackingId, randomBackoffTime = 0, }: LocusSyncLatencyMilestone & {randomBackoffTime?: number}) { - const recordKey = this.getLocusSyncLatencyKey(dataSetName, meetingId); - if (key === 'internal.client.locus.sync.start') { - this.locusSyncLatencies.set(recordKey, { + const records = this.locusSyncLatencies.get(meetingId) ?? []; + + records.push({ + meetingId, + dataSetName, randomBackoffTime, syncStart: value, }); + this.locusSyncLatencies.set(meetingId, records); return; } - const record = this.locusSyncLatencies.get(recordKey); + const record = this.getLatestLocusSyncLatencyRecord( + meetingId, + dataSetName, + key === 'internal.client.locus.sync.response' ? undefined : trackingId + ); if (!record) { return; } + if (trackingId) { + record.trackingId = trackingId; + } + switch (key) { case 'internal.client.locus.hashtree.request': record.hashTreeRequest = value; @@ -297,6 +384,7 @@ export default class CallDiagnosticLatencies extends WebexPlugin { dataSetName: options.dataSetName, key, value, + trackingId: options.trackingId, randomBackoffTime: options.randomBackoffTime, }); diff --git a/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts b/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts index fa3e5749804..b6070878380 100644 --- a/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts +++ b/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts @@ -199,6 +199,48 @@ describe('internal-plugin-metrics', () => { }); }); + it('associates sync response tracking id and completes using the latest meeting record', () => { + const clock = sinon.useFakeTimers({now: 150}); + + try { + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.start', + value: 100, + options: {meetingId: 'meeting-1', dataSetName: 'main', randomBackoffTime: 0}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.request', + value: 110, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.response', + value: 130, + options: { + meetingId: 'meeting-1', + dataSetName: 'main', + trackingId: 'our-sync-tracking-id', + }, + }); + + assert.deepEqual(cdl.completeLocusSyncLatency('meeting-1', 'llm-event-tracking-id'), { + dataSet: 'main', + syncLatency: { + randomBackoffTime: 0, + hashtreePrepTime: 0, + hashtreeResponseTime: 0, + syncPrepTime: 10, + syncResponseTime: 20, + syncMessageReceiveTime: 20, + totalTime: 50, + }, + }); + assert.isFalse(cdl.locusSyncLatencies.has('meeting-1')); + } finally { + clock.restore(); + } + }); + it('keys sync latency records by meeting id', () => { cdl.saveTimestamp({ key: 'internal.client.locus.sync.start', diff --git a/packages/@webex/plugin-meetings/src/breakouts/events.ts b/packages/@webex/plugin-meetings/src/breakouts/events.ts index 542a41b1522..0dc51b93c0d 100644 --- a/packages/@webex/plugin-meetings/src/breakouts/events.ts +++ b/packages/@webex/plugin-meetings/src/breakouts/events.ts @@ -68,11 +68,13 @@ const breakoutEvent: { ...(error && {rawError: error}), }; - submitClientEvent({ + const metricEvent = { name: event, payload, options, - }); + }; + + submitClientEvent(metricEvent); }, }; diff --git a/packages/@webex/plugin-meetings/src/breakouts/index.ts b/packages/@webex/plugin-meetings/src/breakouts/index.ts index 835abf7cc29..19fc09c6d28 100644 --- a/packages/@webex/plugin-meetings/src/breakouts/index.ts +++ b/packages/@webex/plugin-meetings/src/breakouts/index.ts @@ -150,6 +150,10 @@ const Breakouts = WebexPlugin.extend({ this.listenTo(this.breakouts, 'change:requestedLastModifiedTime', (breakout) => { this.triggerReturnToMainEvent(breakout); }); + this.on( + BREAKOUTS.EVENTS.LLM_CONNECT_RESPONSE, + this.handleLLMBreakoutJoinResponseMetric.bind(this) + ); this.listenToCurrentSessionTypeChange(); this.listenToBreakoutRosters(); this.listenToBreakoutHelp(); @@ -370,6 +374,70 @@ const Breakouts = WebexPlugin.extend({ this.webex.internal.newMetrics.submitClientEvent.bind(this.webex.internal.newMetrics) ); } + + this.submitLLMBreakoutJoinResponseMetric(); + }, + + /** + * Stores the latest LLM connect response and tries to send the LLM-enhanced breakout join response. + * The breakout update and the LLM response are delivered independently, so either side can arrive first. + * @param {Object} eventInfo LLM connect response info + * @param {Object} eventInfo.meeting meeting instance + * @param {Object} eventInfo.llmLatency LLM latency values + * @param {Object} [eventInfo.error] LLM connection error + * @returns {void} + */ + handleLLMBreakoutJoinResponseMetric(eventInfo: any) { + this.llmBreakoutJoinResponseInfo = { + ...eventInfo, + breakoutMoveId: this.breakoutMoveId, + }; + + this.submitLLMBreakoutJoinResponseMetric(); + }, + + /** + * Sends the LLM-enhanced breakout join response metric when both breakout state and LLM latency + * are available. LLM reconnects can also happen while leaving a breakout, before stale breakout + * fields are fully cleared, so the active-breakout check lives with the breakout state. + * @returns {void} + */ + submitLLMBreakoutJoinResponseMetric() { + const eventInfo = this.llmBreakoutJoinResponseInfo; + const isActiveBreakout = + this.isActiveBreakout || + (this.sessionType === BREAKOUTS.SESSION_TYPES.BREAKOUT && + [BREAKOUTS.STATUS.OPEN, BREAKOUTS.STATUS.CLOSING].includes(this.status)); + + if ( + !eventInfo || + !this.breakoutMoveId || + eventInfo.breakoutMoveId !== this.breakoutMoveId || + !this.currentBreakoutSession?.sessionId || + !this.currentBreakoutSession?.groupId || + !isActiveBreakout + ) { + return; + } + + const meeting = eventInfo.meeting || this.webex.meetings.getMeetingByType(_ID_, this.meetingId); + // @ts-ignore + const llmWebsocketUrl = this.webex.internal.llm.getWebSocketUrl?.() || undefined; + + breakoutEvent.onBreakoutJoinResponse( + { + currentSession: this.currentBreakoutSession, + meeting, + breakoutMoveId: this.breakoutMoveId, + llmLatency: eventInfo.llmLatency, + llmWebsocketUrl, + error: eventInfo.error, + }, + // @ts-ignore + this.webex.internal.newMetrics.submitClientEvent.bind(this.webex.internal.newMetrics) + ); + + this.llmBreakoutJoinResponseInfo = undefined; }, /** diff --git a/packages/@webex/plugin-meetings/src/constants.ts b/packages/@webex/plugin-meetings/src/constants.ts index 90d235f66f7..e3e9e3ba8b0 100644 --- a/packages/@webex/plugin-meetings/src/constants.ts +++ b/packages/@webex/plugin-meetings/src/constants.ts @@ -660,6 +660,7 @@ export const BREAKOUTS = { LEAVE_BREAKOUT: 'LEAVE_BREAKOUT', ASK_FOR_HELP: 'ASK_FOR_HELP', PRE_ASSIGNMENTS_UPDATE: 'PRE_ASSIGNMENTS_UPDATE', + LLM_CONNECT_RESPONSE: 'LLM_CONNECT_RESPONSE', }, SESSION_TYPES: { MAIN: 'MAIN', diff --git a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts index e0f171ebe2e..cdca3cabe47 100644 --- a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts @@ -105,15 +105,24 @@ export type SyncMetricsCallback = (metrics: { export type SyncLatencyTracker = { saveTimestamp: (options: { key: LocusSyncLatencyEventName; - options: {meetingId: string; dataSetName: string; randomBackoffTime?: number}; + options: { + meetingId: string; + dataSetName: string; + randomBackoffTime?: number; + trackingId?: string; + }; }) => void; getLocusSyncLatency: (dataSetName: string, meetingId: string) => SyncLatencyMetrics | undefined; + completeLocusSyncLatency?: ( + meetingId: string, + trackingId?: string + ) => {dataSet: string; syncLatency: SyncLatencyMetrics} | undefined; clearLocusSyncLatency: (dataSetName: string, meetingId: string) => void; }; export type HashTreeParserCallbacks = { locusInfoUpdateCallback: LocusInfoUpdateCallback; - syncMetricsCallback: SyncMetricsCallback; + syncMetricsCallback?: SyncMetricsCallback; syncLatencyTracker?: SyncLatencyTracker; }; @@ -123,12 +132,6 @@ const SYNC_METRICS_DATA_SETS = [ DataSetNames.ATD_UNMUTED, ]; -interface PendingSyncMetrics { - dataSetName: string; - dataSetVersion: number; - trackingId?: string; -} - interface SyncRequestResult { message: HashTreeMessage | null; trackingId?: string; @@ -193,8 +196,6 @@ class HashTreeParser { private syncQueueProcessingPromise: Promise = Promise.resolve(); // top-level heartbeat interval from the most recent message, used as fallback when dataset-level value is missing private topLevelHeartbeatIntervalMs?: number; - private pendingSyncMetrics: Map = new Map(); - /** * Constructor for HashTreeParser * @param {Object} options @@ -1236,7 +1237,7 @@ class HashTreeParser { this.handleRootHashHeartBeatMessage(message); this.resetHeartbeatWatchdogs(message.dataSets); } else { - this.tryCompletePendingSyncMetrics(message, trackingId); + this.tryCompleteSyncMetricsFromMessage(message, trackingId); const updatedObjects = this.parseMessage(message, debugText); @@ -1248,31 +1249,6 @@ class HashTreeParser { } } - /** - * Completes any pending sync metrics when a qualifying LLM message arrives. - * - * @param {HashTreeMessage} message - * @param {string} [trackingId] top-level tracking id from LLM event or /sync response - * @returns {void} - */ - private tryCompletePendingSyncMetrics(message: HashTreeMessage, trackingId?: string): void { - if (this.pendingSyncMetrics.size === 0) { - return; - } - - for (const dataSet of message.dataSets) { - const pending = this.pendingSyncMetrics.get(dataSet.name); - - if ( - pending && - dataSet.version >= pending.dataSetVersion && - (!pending.trackingId || pending.trackingId === trackingId) - ) { - this.completeSyncMetrics(dataSet.name); - } - } - } - /** * Checks if Locus sync latency metrics should be collected for a dataset. * @@ -1284,19 +1260,49 @@ class HashTreeParser { return Boolean( this.callbacks.syncLatencyTracker && !isInitialization && - SYNC_METRICS_DATA_SETS.includes(dataSetName) && - !this.pendingSyncMetrics.has(dataSetName) + SYNC_METRICS_DATA_SETS.includes(dataSetName) ); } + private tryCompleteSyncMetricsFromMessage(message: HashTreeMessage, trackingId?: string) { + const hasSupportedDataSet = message.dataSets.some((dataSet) => + SYNC_METRICS_DATA_SETS.includes(dataSet.name) + ); + + if (!hasSupportedDataSet) { + return; + } + + const syncMetrics = this.callbacks.syncLatencyTracker?.completeLocusSyncLatency?.( + this.syncLatencyMeetingId, + trackingId + ); + + if (!syncMetrics) { + return; + } + + this.callbacks.syncMetricsCallback?.(syncMetrics); + } + /** * Build options for a Locus sync latency milestone. * @param {string} dataSetName dataset name * @param {number} [randomBackoffTime] random backoff time + * @param {string} [trackingId] tracking id * @returns {object} sync latency timestamp options */ - private getSyncLatencyTimestampOptions(dataSetName: string, randomBackoffTime?: number) { - const options: {meetingId: string; dataSetName: string; randomBackoffTime?: number} = { + private getSyncLatencyTimestampOptions( + dataSetName: string, + randomBackoffTime?: number, + trackingId?: string + ) { + const options: { + meetingId: string; + dataSetName: string; + randomBackoffTime?: number; + trackingId?: string; + } = { meetingId: this.syncLatencyMeetingId, dataSetName, }; @@ -1305,63 +1311,11 @@ class HashTreeParser { options.randomBackoffTime = randomBackoffTime; } - return options; - } - - /** - * Get Locus sync latency using this parser's meeting scope when available. - * @param {string} dataSetName dataset name - * @returns {SyncLatencyMetrics|undefined} sync latency metrics - */ - private getLocusSyncLatency(dataSetName: string): SyncLatencyMetrics | undefined { - return this.callbacks.syncLatencyTracker?.getLocusSyncLatency( - dataSetName, - this.syncLatencyMeetingId - ); - } - - /** - * Clear Locus sync latency using this parser's meeting scope when available. - * @param {string} dataSetName dataset name - * @returns {void} - */ - private clearLocusSyncLatency(dataSetName: string): void { - this.callbacks.syncLatencyTracker?.clearLocusSyncLatency( - dataSetName, - this.syncLatencyMeetingId - ); - } - - /** - * Finalize pending sync metrics and invoke callback. - * - * @param {string} dataSetName - * @returns {void} - */ - private completeSyncMetrics(dataSetName: string): void { - const pending = this.pendingSyncMetrics.get(dataSetName); - - if (!pending) { - return; - } - - this.pendingSyncMetrics.delete(dataSetName); - this.callbacks.syncLatencyTracker?.saveTimestamp({ - key: 'internal.client.locus.sync.message.received', - options: this.getSyncLatencyTimestampOptions(dataSetName), - }); - const syncLatency = this.getLocusSyncLatency(dataSetName); - - this.clearLocusSyncLatency(dataSetName); - - if (!syncLatency) { - return; + if (trackingId) { + options.trackingId = trackingId; } - this.callbacks.syncMetricsCallback({ - dataSet: pending.dataSetName, - syncLatency, - }); + return options; } /** @@ -1463,12 +1417,12 @@ class HashTreeParser { const {hashTree} = dataSet; const rootHash = hashTree.getRootHash(); const shouldCollectMetrics = this.shouldCollectSyncMetrics(dataSet.name, isInitialization); - let syncMetricsPending = false; // Use the heartbeat target for single-leaf sync metrics let targetSyncVersion = dataSet.leafCount === 1 && heartbeatVersion !== undefined ? heartbeatVersion : dataSet.version; + let syncRequestSent = false; if (shouldCollectMetrics) { this.callbacks.syncLatencyTracker?.saveTimestamp({ @@ -1536,14 +1490,13 @@ class HashTreeParser { } // request sync for mismatched leaves let syncResponse: HashTreeMessage | null = null; - let syncTrackingId: string | undefined; - let syncRequestSent = false; + let syncResponseTrackingId: string | undefined; if (isInitialization) { const syncResult = await this.sendSyncRequestToLocus(dataSet, {isInitialization: true}); syncResponse = syncResult.message; - syncTrackingId = syncResult.trackingId; + syncResponseTrackingId = syncResult.trackingId; syncRequestSent = true; } else if (Object.keys(leavesData).length > 0) { const syncResult = await this.sendSyncRequestToLocus(dataSet, { @@ -1551,7 +1504,7 @@ class HashTreeParser { }); syncResponse = syncResult.message; - syncTrackingId = syncResult.trackingId; + syncResponseTrackingId = syncResult.trackingId; syncRequestSent = true; } @@ -1559,16 +1512,6 @@ class HashTreeParser { targetSyncVersion = syncResponseDataSet?.version ?? targetSyncVersion; - // Record pending metrics and complete them when the matching LLM broadcast arrives. - if (shouldCollectMetrics && syncRequestSent) { - this.pendingSyncMetrics.set(dataSet.name, { - dataSetName: dataSet.name, - dataSetVersion: targetSyncVersion, - trackingId: syncTrackingId, - }); - syncMetricsPending = true; - } - // sync API may return nothing (in that case data will arrive via messages) // or it may return a response in the same format as messages // We still need to restart the sync timer as a safety net in case the messages don't arrive. @@ -1586,7 +1529,7 @@ class HashTreeParser { `via sync API (${ isInitialization ? 'init' : `${Object.keys(leavesData).length} mismatched leaves` })`, - syncTrackingId + syncResponseTrackingId ); } } catch (error) { @@ -1597,8 +1540,11 @@ class HashTreeParser { ); } } finally { - if (shouldCollectMetrics && !syncMetricsPending) { - this.clearLocusSyncLatency(dataSet.name); + if (shouldCollectMetrics && !syncRequestSent) { + this.callbacks.syncLatencyTracker?.clearLocusSyncLatency( + dataSet.name, + this.syncLatencyMeetingId + ); } dataSet.syncAbortController = undefined; } @@ -1998,7 +1944,6 @@ class HashTreeParser { this.topLevelHeartbeatIntervalMs = undefined; this.syncAllBackoffType = SyncAllBackoffType.NONE; this.dataSetsSyncedDuringBackoff = new Set(); - this.pendingSyncMetrics.clear(); Object.values(this.dataSets).forEach((dataSet) => { dataSet.syncAbortController?.abort(); dataSet.syncAbortController = undefined; @@ -2024,7 +1969,6 @@ class HashTreeParser { * @returns {void} */ public resumeFromMessage(message: HashTreeMessage) { - // check that message contains metadata with visible data sets - this is essential to be able to resume const metadataObject = message.locusStateElements?.find((el) => isMetadata(el)); if (!metadataObject?.data?.visibleDataSets) { @@ -2238,8 +2182,9 @@ class HashTreeParser { } const ourCurrentRootHash = dataSet.hashTree ? dataSet.hashTree.getRootHash() : EMPTY_HASH; + const shouldCollectMetrics = this.shouldCollectSyncMetrics(dataSet.name, isInitialization); - if (this.shouldCollectSyncMetrics(dataSet.name, isInitialization)) { + if (shouldCollectMetrics) { this.callbacks.syncLatencyTracker?.saveTimestamp({ key: 'internal.client.locus.sync.request', options: this.getSyncLatencyTimestampOptions(dataSet.name), @@ -2257,10 +2202,10 @@ class HashTreeParser { .then((resp) => { const trackingId = resp.headers?.trackingid || resp.headers?.trackingId; - if (this.shouldCollectSyncMetrics(dataSet.name, isInitialization)) { + if (shouldCollectMetrics) { this.callbacks.syncLatencyTracker?.saveTimestamp({ key: 'internal.client.locus.sync.response', - options: this.getSyncLatencyTimestampOptions(dataSet.name), + options: this.getSyncLatencyTimestampOptions(dataSet.name, undefined, trackingId), }); } diff --git a/packages/@webex/plugin-meetings/src/locus-info/index.ts b/packages/@webex/plugin-meetings/src/locus-info/index.ts index c35ae6a95aa..7fbaf9d3ca6 100644 --- a/packages/@webex/plugin-meetings/src/locus-info/index.ts +++ b/packages/@webex/plugin-meetings/src/locus-info/index.ts @@ -37,8 +37,8 @@ import HashTreeParser, { LocusInfoUpdate, LocusInfoUpdateType, Metadata, - SyncLatencyTracker, SyncMetricsCallback, + SyncLatencyTracker, } from '../hashTree/hashTreeParser'; import {HashTreeObject, ObjectType, ObjectTypeToLocusKeyMap} from '../hashTree/types'; import {isMetadata, isSelf} from '../hashTree/utils'; @@ -99,7 +99,7 @@ export type HashTreeParserEntry = { export type LocusInfoCallbacks = { updateMeeting: (object: any) => void; - syncMetricsCallback: SyncMetricsCallback; + syncMetricsCallback?: SyncMetricsCallback; syncLatencyTracker?: SyncLatencyTracker; }; @@ -300,7 +300,6 @@ export default class LocusInfo extends EventsScope { * Constructor * @param {Object} callbacks callbacks used by LocusInfo * @param {function} callbacks.updateMeeting callback to update the meeting object from an object - * @param {function} callbacks.syncMetricsCallback callback to report sync metrics * @param {object} webex * @param {string} meetingId * @returns {undefined} diff --git a/packages/@webex/plugin-meetings/src/meeting/index.ts b/packages/@webex/plugin-meetings/src/meeting/index.ts index c1fa6e26e4a..9508e4dc4f1 100644 --- a/packages/@webex/plugin-meetings/src/meeting/index.ts +++ b/packages/@webex/plugin-meetings/src/meeting/index.ts @@ -164,7 +164,6 @@ import { RelayEvent, } from '../reactions/reactions.type'; import Breakouts from '../breakouts'; -import breakoutEvent from '../breakouts/events'; import SimultaneousInterpretation from '../interpretation'; import Annotation from '../annotation'; import Webinar from '../webinar'; @@ -1387,9 +1386,7 @@ export default class Meeting extends StatelessWebexPlugin { this.locusInfo = new LocusInfo( { updateMeeting: this.updateMeetingObject.bind(this), - syncMetricsCallback: (metrics: {dataSet: string; syncLatency: SyncLatencyMetrics}) => { - this.sendSyncCompleteMetric(metrics); - }, + syncMetricsCallback: this.sendSyncCompleteMetric.bind(this), syncLatencyTracker: (this as any).webex.internal.newMetrics.callDiagnosticLatencies, }, // @ts-ignore @@ -5976,6 +5973,17 @@ export default class Meeting extends StatelessWebexPlugin { storeEventForDebugging('llm', event.data); } + // @ts-ignore + const syncMetrics = + this.webex.internal.newMetrics.callDiagnosticLatencies.completeLocusSyncLatency( + this.id, + event.trackingId + ); + + if (syncMetrics) { + this.sendSyncCompleteMetric(syncMetrics); + } + this.locusInfo.parse(this, event.data, event.trackingId); } else { LoggerProxy.logger.warn( @@ -6803,29 +6811,10 @@ export default class Meeting extends StatelessWebexPlugin { this.sendLLMConnectMetric(registerAndConnectResult); } - const breakoutMoveId = this.breakouts?.breakoutMoveId; - const currentBreakoutSession = this.breakouts?.currentBreakoutSession; - - if ( - breakoutMoveId && - currentBreakoutSession?.sessionId && - currentBreakoutSession?.groupId - ) { - // @ts-ignore - const llmWebsocketUrl = this.webex.internal.llm.getWebSocketUrl?.() || undefined; - - breakoutEvent.onBreakoutJoinResponse( - { - currentSession: currentBreakoutSession, - meeting: this, - breakoutMoveId, - llmLatency: registerAndConnectResult, - llmWebsocketUrl, - }, - // @ts-ignore - this.webex.internal.newMetrics.submitClientEvent.bind(this.webex.internal.newMetrics) - ); - } + this.breakouts?.trigger(BREAKOUTS.EVENTS.LLM_CONNECT_RESPONSE, { + meeting: this, + llmLatency: registerAndConnectResult, + }); } return Promise.resolve(registerAndConnectResult); @@ -6841,33 +6830,14 @@ export default class Meeting extends StatelessWebexPlugin { ); } - const breakoutMoveId = this.breakouts?.breakoutMoveId; - const currentBreakoutSession = this.breakouts?.currentBreakoutSession; - - if ( - breakoutMoveId && - currentBreakoutSession?.sessionId && - currentBreakoutSession?.groupId - ) { - // @ts-ignore - const llmWebsocketUrl = this.webex.internal.llm.getWebSocketUrl?.() || undefined; - - breakoutEvent.onBreakoutJoinResponse( - { - currentSession: currentBreakoutSession, - meeting: this, - breakoutMoveId, - llmLatency: { - clientLLMDatachannelResponseTime: 0, - clientLLMWebSocketConnectTime: 0, - }, - llmWebsocketUrl, - error, - }, - // @ts-ignore - this.webex.internal.newMetrics.submitClientEvent.bind(this.webex.internal.newMetrics) - ); - } + this.breakouts?.trigger(BREAKOUTS.EVENTS.LLM_CONNECT_RESPONSE, { + meeting: this, + llmLatency: { + clientLLMDatachannelResponseTime: 0, + clientLLMWebSocketConnectTime: 0, + }, + error, + }); return Promise.reject(error); }); @@ -6888,7 +6858,12 @@ export default class Meeting extends StatelessWebexPlugin { } if (!hasLLMLatency) { - return true; + // When automatic LLM is enabled, updateLLMConnection will emit this same breakout join + // response after the LLM connection finishes, including llmLatency and llmWebsocketUrl. + // Suppress the earlier non-LLM event to avoid sending two events for the same move id, + // where the first one would be missing the LLM-specific fields we want to validate. + // @ts-ignore - config coming from registerPlugin + return !this.config.enableAutomaticLLM; } if (this.emittedBreakoutJoinResponseMoveIds.has(breakoutMoveId)) { @@ -6931,12 +6906,14 @@ export default class Meeting extends StatelessWebexPlugin { ...(error && {rawError: error}), }; - // @ts-ignore - this.webex.internal.newMetrics.submitClientEvent({ + const metricEvent = { name: 'client.llm.connect.response', payload, options, - }); + }; + + // @ts-ignore + this.webex.internal.newMetrics.submitClientEvent(metricEvent); } /** @@ -6960,14 +6937,16 @@ export default class Meeting extends StatelessWebexPlugin { }, }; - // @ts-ignore - this.webex.internal.newMetrics.submitClientEvent({ + const metricEvent = { name: 'client.locus.sync.complete', payload, options: { meetingId: this.id, }, - }); + }; + + // @ts-ignore + this.webex.internal.newMetrics.submitClientEvent(metricEvent); } /** diff --git a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts index 229930c2915..db5bf32f4f4 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts @@ -5471,27 +5471,17 @@ describe('HashTreeParser', () => { }); describe('#syncMetrics', () => { - it('records pending metrics when sync response has empty body', async () => { - const syncMetricsCallback = sinon.stub(); - const syncLatency = { - randomBackoffTime: 0, - hashtreePrepTime: 5, - hashtreeResponseTime: 20, - syncPrepTime: 3, - syncResponseTime: 15, - syncMessageReceiveTime: 7, - totalTime: 50, - }; + it('records sync latency timestamps when sync response has empty body', async () => { const syncLatencyTracker = { saveTimestamp: sinon.stub(), - getLocusSyncLatency: sinon.stub().returns(syncLatency), + getLocusSyncLatency: sinon.stub(), clearLocusSyncLatency: sinon.stub(), }; const parser = createHashTreeParser( undefined, undefined, undefined, - syncMetricsCallback, + undefined, syncLatencyTracker ); const mainDataSetUrl = parser.dataSets.main.url; @@ -5510,42 +5500,30 @@ describe('HashTreeParser', () => { await clock.tickAsync(1000); - assert.isTrue(parser['pendingSyncMetrics'].has('main')); - assert.notCalled(syncMetricsCallback); - - parser.handleMessage({ - dataSets: [ - { - ...createDataSet('main', 16, 1100), - root: 'intermediate-root', - }, - ], - visibleDataSetsUrl, - locusUrl, - locusStateElements: [], + assert.calledWithExactly(syncLatencyTracker.saveTimestamp, { + key: 'internal.client.locus.sync.start', + options: {meetingId: 'meeting-1', dataSetName: 'main', randomBackoffTime: 0}, }); - - assert.notCalled(syncMetricsCallback); - assert.isTrue(parser['pendingSyncMetrics'].has('main')); - - parser.handleMessage({ - dataSets: [ - { - ...createDataSet('main', 16, 1101), - root: 'newroot', - }, - ], - visibleDataSetsUrl, - locusUrl, - locusStateElements: [], + assert.calledWithExactly(syncLatencyTracker.saveTimestamp, { + key: 'internal.client.locus.hashtree.request', + options: {meetingId: 'meeting-1', dataSetName: 'main'}, }); - - assert.calledOnce(syncMetricsCallback); - assert.isFalse(parser['pendingSyncMetrics'].has('main')); + assert.calledWithExactly(syncLatencyTracker.saveTimestamp, { + key: 'internal.client.locus.hashtree.response', + options: {meetingId: 'meeting-1', dataSetName: 'main'}, + }); + assert.calledWithExactly(syncLatencyTracker.saveTimestamp, { + key: 'internal.client.locus.sync.request', + options: {meetingId: 'meeting-1', dataSetName: 'main'}, + }); + assert.calledWithExactly(syncLatencyTracker.saveTimestamp, { + key: 'internal.client.locus.sync.response', + options: {meetingId: 'meeting-1', dataSetName: 'main'}, + }); + assert.notCalled(syncLatencyTracker.getLocusSyncLatency); }); - it('does not overwrite pending sync latency state when a safety-net sync runs before broadcast', async () => { - const syncMetricsCallback = sinon.stub(); + it('records sync response tracking id for Meeting-side completion', async () => { const syncLatencyTracker = { saveTimestamp: sinon.stub(), getLocusSyncLatency: sinon.stub(), @@ -5555,67 +5533,50 @@ describe('HashTreeParser', () => { undefined, undefined, undefined, - syncMetricsCallback, + undefined, syncLatencyTracker ); const mainDataSetUrl = parser.dataSets.main.url; - parser['pendingSyncMetrics'].set('main', { - dataSetName: 'main', - dataSetVersion: 1101, - } as any); - mockGetHashesFromLocusResponse( mainDataSetUrl, new Array(16).fill('00000000000000000000000000000000'), createDataSet('main', 16, 1102) ); - mockSendSyncRequestResponse(mainDataSetUrl, null); + mockSendSyncRequestResponse(mainDataSetUrl, null, {trackingid: 'our-sync-tracking-id'}); parser.handleMessage( createHeartbeatMessage('main', 16, 1100, 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa1'), - 'trigger safety-net sync while metrics are pending' + 'trigger sync metrics' ); await clock.tickAsync(1000); - assert.notCalled(syncLatencyTracker.saveTimestamp); - assert.notCalled(syncMetricsCallback); - assert.deepEqual(parser['pendingSyncMetrics'].get('main'), { - dataSetName: 'main', - dataSetVersion: 1101, + assert.calledWithExactly(syncLatencyTracker.saveTimestamp, { + key: 'internal.client.locus.sync.response', + options: { + meetingId: 'meeting-1', + dataSetName: 'main', + trackingId: 'our-sync-tracking-id', + }, }); + assert.notCalled(syncLatencyTracker.getLocusSyncLatency); }); - it('invokes syncMetricsCallback when matching dataset version arrives', () => { - const syncMetricsCallback = sinon.stub(); - const syncLatency = { - randomBackoffTime: 10, - hashtreePrepTime: 5, - hashtreeResponseTime: 20, - syncPrepTime: 3, - syncResponseTime: 15, - syncMessageReceiveTime: 7, - totalTime: 50, - }; + it('does not complete or clear metrics when matching dataset message arrives', () => { const syncLatencyTracker = { saveTimestamp: sinon.stub(), - getLocusSyncLatency: sinon.stub().returns(syncLatency), + getLocusSyncLatency: sinon.stub(), clearLocusSyncLatency: sinon.stub(), }; const parser = createHashTreeParser( undefined, undefined, undefined, - syncMetricsCallback, + undefined, syncLatencyTracker ); - parser['pendingSyncMetrics'].set('main', { - dataSetName: 'main', - dataSetVersion: 1000, - } as any); - parser.handleMessage({ dataSets: [ { @@ -5628,34 +5589,28 @@ describe('HashTreeParser', () => { locusStateElements: [], }); - assert.calledOnce(syncMetricsCallback); - const arg = syncMetricsCallback.firstCall.args[0]; - - assert.equal(arg.dataSet, 'main'); - assert.deepEqual(arg.syncLatency, syncLatency); - assert.calledOnceWithExactly(syncLatencyTracker.saveTimestamp, { - key: 'internal.client.locus.sync.message.received', - options: {meetingId: 'meeting-1', dataSetName: 'main'}, - }); - assert.calledOnceWithExactly(syncLatencyTracker.getLocusSyncLatency, 'main', 'meeting-1'); - assert.calledOnceWithExactly(syncLatencyTracker.clearLocusSyncLatency, 'main', 'meeting-1'); - assert.isFalse(parser['pendingSyncMetrics'].has('main')); + assert.notCalled(syncLatencyTracker.getLocusSyncLatency); + assert.notCalled(syncLatencyTracker.clearLocusSyncLatency); }); - it('only completes pending sync metrics when LLM message tracking id matches sync response tracking id', async () => { - const syncMetricsCallback = sinon.stub(); - const syncLatency = { - randomBackoffTime: 0, - hashtreePrepTime: 5, - hashtreeResponseTime: 20, - syncPrepTime: 3, - syncResponseTime: 15, - syncMessageReceiveTime: 7, - totalTime: 50, + it('passes completed sync metrics from parser to callback when matching dataset message arrives', () => { + const syncMetrics = { + dataSet: 'main', + syncLatency: { + randomBackoffTime: 0, + hashtreePrepTime: 1, + hashtreeResponseTime: 2, + syncPrepTime: 3, + syncResponseTime: 4, + syncMessageReceiveTime: 5, + totalTime: 15, + }, }; + const syncMetricsCallback = sinon.stub(); const syncLatencyTracker = { saveTimestamp: sinon.stub(), - getLocusSyncLatency: sinon.stub().returns(syncLatency), + getLocusSyncLatency: sinon.stub(), + completeLocusSyncLatency: sinon.stub().returns(syncMetrics), clearLocusSyncLatency: sinon.stub(), }; const parser = createHashTreeParser( @@ -5665,27 +5620,12 @@ describe('HashTreeParser', () => { syncMetricsCallback, syncLatencyTracker ); - const mainDataSetUrl = parser.dataSets.main.url; - - mockGetHashesFromLocusResponse( - mainDataSetUrl, - new Array(16).fill('00000000000000000000000000000000'), - createDataSet('main', 16, 1101) - ); - mockSendSyncRequestResponse(mainDataSetUrl, null, {trackingid: 'our-sync-tracking-id'}); - - parser.handleMessage( - createHeartbeatMessage('main', 16, 1100, 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa1'), - 'trigger sync metrics' - ); - - await clock.tickAsync(1000); parser.handleMessage( { dataSets: [ { - ...createDataSet('main', 16, 1101), + ...createDataSet('main', 16, 1001), root: 'newroot', }, ], @@ -5693,107 +5633,17 @@ describe('HashTreeParser', () => { locusUrl, locusStateElements: [], }, - undefined, - 'other-client-sync-tracking-id' - ); - - assert.notCalled(syncMetricsCallback); - assert.isTrue(parser['pendingSyncMetrics'].has('main')); - - parser.handleMessage( - { - dataSets: [ - { - ...createDataSet('main', 16, 1101), - root: 'newroot', - }, - ], - visibleDataSetsUrl, - locusUrl, - locusStateElements: [], - }, - undefined, + 'via sync API (1 mismatched leaves)', 'our-sync-tracking-id' ); - assert.calledOnce(syncMetricsCallback); - assert.isFalse(parser['pendingSyncMetrics'].has('main')); - }); - - it('scopes sync metrics tracker records by meeting id', () => { - const syncMetricsCallback = sinon.stub(); - const syncLatency = { - randomBackoffTime: 10, - hashtreePrepTime: 1, - hashtreeResponseTime: 2, - syncPrepTime: 3, - syncResponseTime: 4, - syncMessageReceiveTime: 5, - totalTime: 15, - }; - const syncLatencyTracker = { - saveTimestamp: sinon.stub(), - getLocusSyncLatency: sinon.stub().returns(syncLatency), - clearLocusSyncLatency: sinon.stub(), - }; - const parser = createHashTreeParser( - undefined, - undefined, - undefined, - syncMetricsCallback, - syncLatencyTracker, - 'meeting-1' + assert.calledOnceWithExactly( + syncLatencyTracker.completeLocusSyncLatency, + 'meeting-1', + 'our-sync-tracking-id' ); - - parser['pendingSyncMetrics'].set('main', { - dataSetName: 'main', - dataSetVersion: 1000, - } as any); - - parser.handleMessage({ - dataSets: [ - { - ...createDataSet('main', 16, 1001), - root: 'newroot', - }, - ], - visibleDataSetsUrl, - locusUrl, - locusStateElements: [], - }); - - assert.calledOnceWithExactly(syncLatencyTracker.saveTimestamp, { - key: 'internal.client.locus.sync.message.received', - options: {meetingId: 'meeting-1', dataSetName: 'main'}, - }); - assert.calledOnceWithExactly(syncLatencyTracker.getLocusSyncLatency, 'main', 'meeting-1'); - assert.calledOnceWithExactly(syncLatencyTracker.clearLocusSyncLatency, 'main', 'meeting-1'); - assert.calledOnce(syncMetricsCallback); - }); - - it('does not complete pending metrics when message version is below pending version', () => { - const syncMetricsCallback = sinon.stub(); - const parser = createHashTreeParser(undefined, undefined, undefined, syncMetricsCallback); - - parser['pendingSyncMetrics'].set('main', { - dataSetName: 'main', - dataSetVersion: 1005, - } as any); - - parser.handleMessage({ - dataSets: [ - { - ...createDataSet('main', 16, 1004), - root: 'newroot', - }, - ], - visibleDataSetsUrl, - locusUrl, - locusStateElements: [], - }); - - assert.notCalled(syncMetricsCallback); - assert.isTrue(parser['pendingSyncMetrics'].has('main')); + assert.calledOnceWithExactly(syncMetricsCallback, syncMetrics); + assert.notCalled(syncLatencyTracker.clearLocusSyncLatency); }); }); }); diff --git a/packages/@webex/plugin-meetings/test/unit/spec/locus-info/index.js b/packages/@webex/plugin-meetings/test/unit/spec/locus-info/index.js index 259d732e1c0..b5511a204f6 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/locus-info/index.js +++ b/packages/@webex/plugin-meetings/test/unit/spec/locus-info/index.js @@ -56,7 +56,7 @@ describe('plugin-meetings', () => { beforeEach(() => { mockMeeting = {}; - locusInfo = new LocusInfo({updateMeeting, syncMetricsCallback: sinon.stub()}, webex, meetingId); + locusInfo = new LocusInfo({updateMeeting}, webex, meetingId); locusInfo.init(locus); @@ -150,7 +150,6 @@ describe('plugin-meetings', () => { webexRequest: sinon.match.func, callbacks: sinon.match({ locusInfoUpdateCallback: sinon.match.func, - syncMetricsCallback: sinon.match.func, }), debugId: sinon.match.string, }) @@ -203,7 +202,6 @@ describe('plugin-meetings', () => { webexRequest: sinon.match.func, callbacks: sinon.match({ locusInfoUpdateCallback: sinon.match.func, - syncMetricsCallback: sinon.match.func, }), debugId: sinon.match.string, }) @@ -287,7 +285,6 @@ describe('plugin-meetings', () => { webexRequest: sinon.match.func, callbacks: sinon.match({ locusInfoUpdateCallback: sinon.match.func, - syncMetricsCallback: sinon.match.func, }), debugId: sinon.match.string, metadata: null, diff --git a/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js b/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js index ac52121ab33..88555c47839 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js +++ b/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js @@ -2636,6 +2636,8 @@ describe('plugin-meetings', () => { meeting.meetingInfo.enableConvergedArchitecture = true; meeting.breakouts.set('breakoutMoveId', 'move-id-1'); + meeting.breakouts.set('sessionType', 'BREAKOUT'); + meeting.breakouts.set('status', 'OPEN'); meeting.breakouts.set('currentBreakoutSession', { sessionId: 'session-id-1', groupId: 'group-id-1', @@ -2705,7 +2707,7 @@ describe('plugin-meetings', () => { assert.lengthOf(joinResponseCalls, 0); }); - it('emits llm breakout join response metric even if updateBreakout already emitted one without llmLatency', async () => { + it('emits llm breakout join response metric after suppressing join response without llmLatency', async () => { sinon.stub(meeting, 'isJoined').returns(true); sinon.stub(meeting.webex.internal.llm, 'isConnected').returns(false); sinon.stub(meeting.webex.internal.llm, 'registerAndConnect').resolves({ @@ -2713,14 +2715,17 @@ describe('plugin-meetings', () => { clientLLMWebSocketConnectTime: 20, }); + meeting.config.enableAutomaticLLM = true; meeting.meetingInfo.enableConvergedArchitecture = true; meeting.breakouts.set('breakoutMoveId', 'move-id-1'); + meeting.breakouts.set('sessionType', 'BREAKOUT'); + meeting.breakouts.set('status', 'OPEN'); meeting.breakouts.set('currentBreakoutSession', { sessionId: 'session-id-1', groupId: 'group-id-1', }); - meeting.shouldEmitBreakoutJoinResponseMetric('move-id-1'); + assert.isFalse(meeting.shouldEmitBreakoutJoinResponseMetric('move-id-1')); webex.internal.newMetrics.submitClientEvent.resetHistory(); meeting.updateLLMConnection.restore(); @@ -2738,6 +2743,35 @@ describe('plugin-meetings', () => { }); }); + it('does not emit breakout join response metric when leaving breakout session', async () => { + sinon.stub(meeting, 'isJoined').returns(true); + sinon.stub(meeting.webex.internal.llm, 'isConnected').returns(false); + sinon.stub(meeting.webex.internal.llm, 'registerAndConnect').resolves({ + clientLLMDatachannelResponseTime: 10, + clientLLMWebSocketConnectTime: 20, + }); + + meeting.meetingInfo.enableConvergedArchitecture = true; + meeting.breakouts.set('breakoutMoveId', 'move-id-1'); + meeting.breakouts.set('sessionType', 'MAIN'); + meeting.breakouts.set('status', 'OPEN'); + meeting.breakouts.set('currentBreakoutSession', { + sessionId: 'session-id-1', + groupId: 'group-id-1', + }); + + webex.internal.newMetrics.submitClientEvent.resetHistory(); + meeting.updateLLMConnection.restore(); + + await meeting.updateLLMConnection(); + + const joinResponseCalls = webex.internal.newMetrics.submitClientEvent + .getCalls() + .filter((call) => call.args[0]?.name === 'client.breakout-session.join.response'); + + assert.lengthOf(joinResponseCalls, 0); + }); + it('clears the LLM health check timer when disconnecting LLM', async () => { const isJoinedStub = sinon.stub(meeting, 'isJoined'); sinon.stub(meeting.webex.internal.llm, 'isConnected'); @@ -14569,6 +14603,56 @@ describe('plugin-meetings', () => { }); }); + describe('#processLocusLLMEvent', () => { + it('sends sync complete metric using the LLM event tracking id', () => { + const syncLatency = { + randomBackoffTime: 10, + hashtreePrepTime: 5, + hashtreeResponseTime: 20, + syncPrepTime: 3, + syncResponseTime: 15, + syncMessageReceiveTime: 7, + totalTime: 50, + }; + const syncMetrics = {dataSet: 'main', syncLatency}; + const event = { + data: {eventType: 'locus.state_message', dataSets: []}, + trackingId: 'our-sync-tracking-id', + }; + + webex.internal.newMetrics.submitClientEvent.resetHistory(); + webex.internal.newMetrics.callDiagnosticLatencies.completeLocusSyncLatency = sinon + .stub() + .returns(syncMetrics); + webex.internal.llm.getWebSocketUrl = sinon.stub().returns('wss://llm-websocket-url'); + meeting.locusInfo.parse = sinon.stub(); + + meeting.processLocusLLMEvent(event); + + assert.calledOnceWithExactly( + webex.internal.newMetrics.callDiagnosticLatencies.completeLocusSyncLatency, + meeting.id, + 'our-sync-tracking-id' + ); + assert.calledOnceWithExactly(meeting.locusInfo.parse, meeting, event.data, event.trackingId); + assert.calledOnceWithExactly(webex.internal.newMetrics.submitClientEvent, { + name: 'client.locus.sync.complete', + payload: { + identifiers: { + llmWebsocketUrl: 'wss://llm-websocket-url', + }, + syncLatency, + llmInfo: { + dataSet: 'main', + }, + }, + options: { + meetingId: meeting.id, + }, + }); + }); + }); + describe('#setLocus', () => { beforeEach(() => { meeting.locusInfo.initialSetup = sinon.stub().returns(true); From fdddb7f0f3f84d53900ecbbb2674536be9127be9 Mon Sep 17 00:00:00 2001 From: tiahan Date: Mon, 8 Jun 2026 14:55:54 +0800 Subject: [PATCH 29/29] fix(metrics): complete locus sync latency via sync response callback --- .../call-diagnostic-metrics-latencies.ts | 287 ++++++++++++-- .../src/metrics.types.ts | 3 +- .../call-diagnostic-metrics-latencies.ts | 355 +++++++++++++++++- .../plugin-meetings/src/breakouts/events.ts | 1 - .../src/hashTree/hashTreeParser.ts | 81 ++-- .../plugin-meetings/src/locus-info/index.ts | 13 +- .../plugin-meetings/src/meeting/index.ts | 44 ++- .../test/unit/spec/hashTree/hashTreeParser.ts | 147 +++++--- .../test/unit/spec/meeting/index.js | 94 ++++- 9 files changed, 873 insertions(+), 152 deletions(-) diff --git a/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts b/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts index 59ef8c68782..de2637cad39 100644 --- a/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts +++ b/packages/@webex/internal-plugin-metrics/src/call-diagnostic/call-diagnostic-metrics-latencies.ts @@ -26,11 +26,17 @@ type SaveTimestampOptions = { trackingId?: string; }; +type SaveLatencyOptions = { + meetingId?: string; + dataSetName?: string; +}; + type LocusSyncLatencyRecord = { meetingId: string; dataSetName: string; randomBackoffTime: number; trackingId?: string; + llmTrackingId?: string; syncStart?: number; hashTreeRequest?: number; hashTreeResponse?: number; @@ -49,7 +55,7 @@ type LocusSyncLatencyTimestampKey = Exclude; precomputedLatencies: Map; - locusSyncLatencies: Map; + meetingLatencies: Map; // meetingId that the current latencies are for private meetingId?: string; private MAX_INTEGER = 2147483647; @@ -61,7 +67,7 @@ export default class CallDiagnosticLatencies extends WebexPlugin { super(...args); this.latencyTimestamps = new Map(); this.precomputedLatencies = new Map(); - this.locusSyncLatencies = new Map(); + this.meetingLatencies = new Map(); } /** @@ -70,7 +76,7 @@ export default class CallDiagnosticLatencies extends WebexPlugin { public clearTimestamps() { this.latencyTimestamps.clear(); this.precomputedLatencies.clear(); - this.locusSyncLatencies.clear(); + this.meetingLatencies.clear(); } /** @@ -79,7 +85,7 @@ export default class CallDiagnosticLatencies extends WebexPlugin { * @param meetingId meeting id */ public clearLocusSyncLatency(dataSetName: string, meetingId: string) { - const records = this.locusSyncLatencies.get(meetingId); + const records = this.meetingLatencies.get(meetingId); if (!records) { return; @@ -88,9 +94,9 @@ export default class CallDiagnosticLatencies extends WebexPlugin { const remainingRecords = records.filter((record) => record.dataSetName !== dataSetName); if (remainingRecords.length > 0) { - this.locusSyncLatencies.set(meetingId, remainingRecords); + this.meetingLatencies.set(meetingId, remainingRecords); } else { - this.locusSyncLatencies.delete(meetingId); + this.meetingLatencies.delete(meetingId); } } @@ -130,11 +136,24 @@ export default class CallDiagnosticLatencies extends WebexPlugin { 'syncResponse', 'messageReceived' ); - const totalTime = this.getDiffBetweenLocusSyncTimestamps( + const totalTimeFromMessageReceived = this.getDiffBetweenLocusSyncTimestamps( record, 'syncStart', 'messageReceived' ); + const totalTimeFromSyncResponse = this.getDiffBetweenLocusSyncTimestamps( + record, + 'syncStart', + 'syncResponse' + ); + + // messageReceived can occasionally be out of order due to race conditions. + // Ensure totalTime is never less than syncStart->syncResponse when both exist. + const totalTime = + typeof totalTimeFromMessageReceived === 'number' && + typeof totalTimeFromSyncResponse === 'number' + ? Math.max(totalTimeFromMessageReceived, totalTimeFromSyncResponse) + : totalTimeFromMessageReceived; if ( typeof syncPrepTime !== 'number' || @@ -163,17 +182,24 @@ export default class CallDiagnosticLatencies extends WebexPlugin { * @returns completed sync latency metric payload */ public completeLocusSyncLatency(meetingId: string, trackingId?: string) { - const exactRecord = this.getLatestLocusSyncLatencyRecord(meetingId, undefined, trackingId); - const fallbackRecord = exactRecord + const exactRecord = trackingId + ? this.getLatestCompletableLocusSyncLatencyRecord(meetingId, trackingId) + : undefined; + // Fallback candidates used only when tracking id does not identify one exact record. + const completableRecords = exactRecord ? undefined - : this.getLatestLocusSyncLatencyRecord(meetingId); + : this.getCompletableLocusSyncLatencyRecords(meetingId); + const fallbackRecord = + !exactRecord && completableRecords?.length === 1 ? completableRecords[0] : undefined; const record = exactRecord ?? fallbackRecord; if (!record) { return undefined; } - record.messageReceived = new Date().getTime(); + if (typeof record.messageReceived !== 'number') { + record.messageReceived = new Date().getTime(); + } const syncLatency = this.getLocusSyncLatency(record.dataSetName, meetingId, record.trackingId); @@ -229,12 +255,32 @@ export default class CallDiagnosticLatencies extends WebexPlugin { return Math.round(clamp(latency, 0, this.MAX_INTEGER)); } + /** + * Checks whether a Locus sync latency record has the milestones required to calculate sync metrics. + * @param record Locus sync latency record + * @returns whether the record can be used to complete sync metrics + */ + private hasRequiredSyncMilestones(record: LocusSyncLatencyRecord) { + return ( + typeof record.syncStart === 'number' && + typeof record.syncRequest === 'number' && + typeof record.syncResponse === 'number' + ); + } + + /** + * Get the latest Locus sync latency record for a meeting and optional dataset/tracking id. + * @param meetingId meeting id + * @param dataSetName dataset name + * @param trackingId /sync response tracking id + * @returns latest matching Locus sync latency record + */ private getLatestLocusSyncLatencyRecord( meetingId: string, dataSetName?: string, trackingId?: string ) { - const records = this.locusSyncLatencies.get(meetingId); + const records = this.meetingLatencies.get(meetingId); if (!records) { return undefined; @@ -248,8 +294,105 @@ export default class CallDiagnosticLatencies extends WebexPlugin { }); } + /** + * Get the latest Locus sync latency record that has enough milestones to complete metrics. + * @param meetingId meeting id + * @param trackingId /sync response tracking id or LLM message tracking id + * @returns latest matching completable Locus sync latency record + */ + private getLatestCompletableLocusSyncLatencyRecord(meetingId: string, trackingId?: string) { + const records = this.meetingLatencies.get(meetingId); + + if (!records) { + return undefined; + } + + return [...records].reverse().find((record) => { + const trackingIdMatches = + !trackingId || record.trackingId === trackingId || record.llmTrackingId === trackingId; + + return trackingIdMatches && this.hasRequiredSyncMilestones(record); + }); + } + + /** + * Get all Locus sync latency records for a meeting that have enough milestones to complete metrics. + * @param meetingId meeting id + * @returns completable Locus sync latency records for the meeting + */ + private getCompletableLocusSyncLatencyRecords(meetingId: string) { + const records = this.meetingLatencies.get(meetingId); + + if (!records) { + return []; + } + + return records.filter((record) => this.hasRequiredSyncMilestones(record)); + } + + /** + * Find the most likely Locus sync latency record for an incoming LLM message.received timestamp. + * @param meetingId meeting id + * @param dataSetName dataset name + * @param trackingId LLM message tracking id + * @param messageReceivedValue message.received timestamp value + * @returns best matching Locus sync latency record for the message.received milestone + */ + private getBestRecordForMessageReceived( + meetingId: string, + dataSetName: string, + trackingId?: string, + messageReceivedValue?: number + ) { + const records = this.meetingLatencies.get(meetingId); + + if (!records || records.length === 0) { + return undefined; + } + + const dataSetRecords = records.filter((record) => record.dataSetName === dataSetName); + + if (dataSetRecords.length === 0) { + return undefined; + } + + if (trackingId) { + const exactRecord = [...dataSetRecords] + .reverse() + .find((record) => record.trackingId === trackingId || record.llmTrackingId === trackingId); + + if (exactRecord) { + return exactRecord; + } + + if (typeof messageReceivedValue === 'number') { + const closestBySyncResponse = dataSetRecords + .filter( + (record) => + this.hasRequiredSyncMilestones(record) && record.syncResponse <= messageReceivedValue + ) + .sort((a, b) => (b.syncResponse as number) - (a.syncResponse as number))[0]; + + if (closestBySyncResponse) { + return closestBySyncResponse; + } + } + } + + // Fallback candidates used only when message.received cannot be matched by id or timestamp. + const completableRecords = dataSetRecords.filter((record) => + this.hasRequiredSyncMilestones(record) + ); + + if (completableRecords.length === 1) { + return completableRecords[0]; + } + + return undefined; + } + private removeLocusSyncLatencyRecord(recordToRemove: LocusSyncLatencyRecord) { - const records = this.locusSyncLatencies.get(recordToRemove.meetingId); + const records = this.meetingLatencies.get(recordToRemove.meetingId); if (!records) { return; @@ -258,10 +401,62 @@ export default class CallDiagnosticLatencies extends WebexPlugin { const remainingRecords = records.filter((record) => record !== recordToRemove); if (remainingRecords.length > 0) { - this.locusSyncLatencies.set(recordToRemove.meetingId, remainingRecords); + this.meetingLatencies.set(recordToRemove.meetingId, remainingRecords); } else { - this.locusSyncLatencies.delete(recordToRemove.meetingId); + this.meetingLatencies.delete(recordToRemove.meetingId); + } + } + + /** + * Get the latest Locus sync latency record waiting for sync.start. + * @param meetingId meeting id + * @param dataSetName dataset name + * @returns latest pending Locus sync latency record + */ + private getLatestPendingLocusSyncLatencyRecord(meetingId: string, dataSetName: string) { + const records = this.meetingLatencies.get(meetingId); + + if (!records) { + return undefined; } + + return [...records] + .reverse() + .find((record) => record.dataSetName === dataSetName && record.syncStart === undefined); + } + + /** + * Store random backoff latency for the current or next Locus sync latency record. + * @param meetingId meeting id + * @param dataSetName dataset name + * @param randomBackoffTime random backoff latency value + * @returns void + */ + private saveLocusSyncBackoffLatency({ + meetingId, + dataSetName, + randomBackoffTime, + }: { + meetingId: string; + dataSetName: string; + randomBackoffTime: number; + }) { + const pendingRecord = this.getLatestPendingLocusSyncLatencyRecord(meetingId, dataSetName); + + if (pendingRecord) { + pendingRecord.randomBackoffTime = randomBackoffTime; + + return; + } + + const records = this.meetingLatencies.get(meetingId) ?? []; + + records.push({ + meetingId, + dataSetName, + randomBackoffTime, + }); + this.meetingLatencies.set(meetingId, records); } /** @@ -283,34 +478,54 @@ export default class CallDiagnosticLatencies extends WebexPlugin { key, value, trackingId, - randomBackoffTime = 0, + randomBackoffTime, }: LocusSyncLatencyMilestone & {randomBackoffTime?: number}) { if (key === 'internal.client.locus.sync.start') { - const records = this.locusSyncLatencies.get(meetingId) ?? []; + const pendingRecord = this.getLatestPendingLocusSyncLatencyRecord(meetingId, dataSetName); + + if (pendingRecord) { + if (typeof randomBackoffTime === 'number') { + pendingRecord.randomBackoffTime = randomBackoffTime; + } + pendingRecord.syncStart = value; + + return; + } + + const records = this.meetingLatencies.get(meetingId) ?? []; records.push({ meetingId, dataSetName, - randomBackoffTime, + randomBackoffTime: randomBackoffTime ?? 0, syncStart: value, }); - this.locusSyncLatencies.set(meetingId, records); + this.meetingLatencies.set(meetingId, records); return; } - const record = this.getLatestLocusSyncLatencyRecord( - meetingId, - dataSetName, - key === 'internal.client.locus.sync.response' ? undefined : trackingId - ); + const record = + key === 'internal.client.locus.sync.message.received' + ? this.getBestRecordForMessageReceived(meetingId, dataSetName, trackingId, value) + : this.getLatestLocusSyncLatencyRecord( + meetingId, + dataSetName, + key === 'internal.client.locus.sync.response' ? undefined : trackingId + ); if (!record) { return; } if (trackingId) { - record.trackingId = trackingId; + if (key === 'internal.client.locus.sync.response') { + record.trackingId = trackingId; + } + + if (key === 'internal.client.locus.sync.message.received') { + record.llmTrackingId = trackingId; + } } switch (key) { @@ -418,7 +633,27 @@ export default class CallDiagnosticLatencies extends WebexPlugin { * @throws * @returns */ - public saveLatency(key: PreComputedLatencies, value: number, accumulate = false) { + public saveLatency( + key: PreComputedLatencies, + value: number, + accumulateOrOptions: boolean | SaveLatencyOptions = false + ) { + if ( + key === 'internal.client.locus.sync.random.backoff' && + typeof accumulateOrOptions === 'object' && + accumulateOrOptions.meetingId && + accumulateOrOptions.dataSetName + ) { + this.saveLocusSyncBackoffLatency({ + meetingId: accumulateOrOptions.meetingId, + dataSetName: accumulateOrOptions.dataSetName, + randomBackoffTime: value, + }); + + return; + } + + const accumulate = typeof accumulateOrOptions === 'boolean' ? accumulateOrOptions : false; const existingValue = accumulate ? this.precomputedLatencies.get(key) || 0 : 0; this.precomputedLatencies.set(key, value + existingValue); } diff --git a/packages/@webex/internal-plugin-metrics/src/metrics.types.ts b/packages/@webex/internal-plugin-metrics/src/metrics.types.ts index 596b903df86..15e21513770 100644 --- a/packages/@webex/internal-plugin-metrics/src/metrics.types.ts +++ b/packages/@webex/internal-plugin-metrics/src/metrics.types.ts @@ -336,7 +336,8 @@ export type PreComputedLatencies = | 'internal.get.u2c.time' | 'internal.call.init.join.req' | 'internal.other.app.api.time' - | 'internal.api.fetch.intelligence.models'; + | 'internal.api.fetch.intelligence.models' + | 'internal.client.locus.sync.random.backoff'; export interface IdType { meetingId?: string; diff --git a/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts b/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts index b6070878380..c8dc0033c8f 100644 --- a/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts +++ b/packages/@webex/internal-plugin-metrics/test/unit/spec/call-diagnostic/call-diagnostic-metrics-latencies.ts @@ -113,16 +113,53 @@ describe('internal-plugin-metrics', () => { value: 1, options: {meetingId: 'meeting-1', dataSetName: 'main', randomBackoffTime: 10}, }); - assert.deepEqual(cdl.locusSyncLatencies.size, 1); + assert.deepEqual(cdl.meetingLatencies.size, 1); cdl.clearTimestamps(); assert.deepEqual(cdl.latencyTimestamps.size, 0); assert.deepEqual(cdl.precomputedLatencies.size, 0); - assert.deepEqual(cdl.locusSyncLatencies.size, 0); + assert.deepEqual(cdl.meetingLatencies.size, 0); }); describe('locus sync latencies', () => { + it('uses pending sync backoff latency when sync starts', () => { + cdl.saveLatency('internal.client.locus.sync.random.backoff', 10.4, { + meetingId: 'meeting-1', + dataSetName: 'main', + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.start', + value: 100, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.request', + value: 110, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.response', + value: 130, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.message.received', + value: 140, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, + }); + + assert.deepEqual(cdl.getLocusSyncLatency('main', 'meeting-1'), { + randomBackoffTime: 10, + hashtreePrepTime: 0, + hashtreeResponseTime: 0, + syncPrepTime: 10, + syncResponseTime: 20, + syncMessageReceiveTime: 10, + totalTime: 40, + }); + }); + it('calculates sync latency values from milestones', () => { cdl.saveTimestamp({ key: 'internal.client.locus.sync.start', @@ -199,7 +236,314 @@ describe('internal-plugin-metrics', () => { }); }); - it('associates sync response tracking id and completes using the latest meeting record', () => { + it('associates sync response tracking id and completes the matching meeting record', () => { + const clock = sinon.useFakeTimers({now: 150}); + + try { + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.start', + value: 100, + options: {meetingId: 'meeting-1', dataSetName: 'main', randomBackoffTime: 0}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.request', + value: 110, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.response', + value: 130, + options: { + meetingId: 'meeting-1', + dataSetName: 'main', + trackingId: 'our-sync-tracking-id', + }, + }); + cdl.saveLatency('internal.client.locus.sync.random.backoff', 99, { + meetingId: 'meeting-1', + dataSetName: 'main', + }); + + assert.deepEqual(cdl.completeLocusSyncLatency('meeting-1', 'our-sync-tracking-id'), { + dataSet: 'main', + syncLatency: { + randomBackoffTime: 0, + hashtreePrepTime: 0, + hashtreeResponseTime: 0, + syncPrepTime: 10, + syncResponseTime: 20, + syncMessageReceiveTime: 20, + totalTime: 50, + }, + }); + assert.lengthOf(cdl.meetingLatencies.get('meeting-1'), 1); + + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.start', + value: 200, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, + }); + assert.deepInclude(cdl.meetingLatencies.get('meeting-1'), { + meetingId: 'meeting-1', + dataSetName: 'main', + randomBackoffTime: 99, + syncStart: 200, + }); + } finally { + clock.restore(); + } + }); + + it('uses stored message.received timestamp even when LLM tracking id differs', () => { + const clock = sinon.useFakeTimers({now: 500}); + + try { + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.start', + value: 100, + options: {meetingId: 'meeting-1', dataSetName: 'main', randomBackoffTime: 0}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.request', + value: 110, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.response', + value: 130, + options: { + meetingId: 'meeting-1', + dataSetName: 'main', + trackingId: 'sync-tracking-id', + }, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.message.received', + value: 140, + options: { + meetingId: 'meeting-1', + dataSetName: 'main', + trackingId: 'llm-envelope-id', + }, + }); + + assert.deepEqual(cdl.completeLocusSyncLatency('meeting-1', 'llm-envelope-id'), { + dataSet: 'main', + syncLatency: { + randomBackoffTime: 0, + hashtreePrepTime: 0, + hashtreeResponseTime: 0, + syncPrepTime: 10, + syncResponseTime: 20, + syncMessageReceiveTime: 10, + totalTime: 40, + }, + }); + } finally { + clock.restore(); + } + }); + + it('does not allow totalTime to drop below sync response duration when message.received is stale', () => { + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.start', + value: 100, + options: {meetingId: 'meeting-1', dataSetName: 'main', randomBackoffTime: 0}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.request', + value: 101, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.response', + value: 475, + options: { + meetingId: 'meeting-1', + dataSetName: 'main', + trackingId: 'sync-tracking-id', + }, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.message.received', + value: 90, + options: { + meetingId: 'meeting-1', + dataSetName: 'main', + trackingId: 'llm-envelope-id', + }, + }); + + assert.deepEqual(cdl.completeLocusSyncLatency('meeting-1', 'llm-envelope-id'), { + dataSet: 'main', + syncLatency: { + randomBackoffTime: 0, + hashtreePrepTime: 0, + hashtreeResponseTime: 0, + syncPrepTime: 1, + syncResponseTime: 374, + syncMessageReceiveTime: 0, + totalTime: 375, + }, + }); + }); + + it('matches exact record by llm message tracking id on first pass', () => { + const clock = sinon.useFakeTimers({now: 300}); + + try { + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.start', + value: 100, + options: {meetingId: 'meeting-1', dataSetName: 'main', randomBackoffTime: 0}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.request', + value: 110, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.response', + value: 130, + options: { + meetingId: 'meeting-1', + dataSetName: 'main', + trackingId: 'sync-tracking-1', + }, + }); + + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.start', + value: 200, + options: {meetingId: 'meeting-1', dataSetName: 'main', randomBackoffTime: 0}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.request', + value: 210, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.response', + value: 230, + options: { + meetingId: 'meeting-1', + dataSetName: 'main', + trackingId: 'sync-tracking-2', + }, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.message.received', + value: 240, + options: { + meetingId: 'meeting-1', + dataSetName: 'main', + trackingId: 'llm-envelope-id', + }, + }); + + assert.deepEqual(cdl.completeLocusSyncLatency('meeting-1', 'llm-envelope-id'), { + dataSet: 'main', + syncLatency: { + randomBackoffTime: 0, + hashtreePrepTime: 0, + hashtreeResponseTime: 0, + syncPrepTime: 10, + syncResponseTime: 20, + syncMessageReceiveTime: 10, + totalTime: 40, + }, + }); + } finally { + clock.restore(); + } + }); + + it('does not bind message.received when tracking id is ambiguous across multiple completable records', () => { + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.start', + value: 100, + options: {meetingId: 'meeting-1', dataSetName: 'main', randomBackoffTime: 0}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.request', + value: 110, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.response', + value: 130, + options: {meetingId: 'meeting-1', dataSetName: 'main', trackingId: 'sync-tracking-1'}, + }); + + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.start', + value: 200, + options: {meetingId: 'meeting-1', dataSetName: 'main', randomBackoffTime: 0}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.request', + value: 210, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.response', + value: 230, + options: {meetingId: 'meeting-1', dataSetName: 'main', trackingId: 'sync-tracking-2'}, + }); + + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.message.received', + value: 120, + options: { + meetingId: 'meeting-1', + dataSetName: 'main', + trackingId: 'llm-unknown-id', + }, + }); + + const records = cdl.meetingLatencies.get('meeting-1'); + + assert.isDefined(records); + assert.lengthOf(records!, 2); + assert.isUndefined(records![0].messageReceived); + assert.isUndefined(records![1].messageReceived); + }); + + it('binds message.received when only one completable record exists', () => { + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.start', + value: 100, + options: {meetingId: 'meeting-1', dataSetName: 'main', randomBackoffTime: 0}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.request', + value: 110, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, + }); + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.response', + value: 130, + options: {meetingId: 'meeting-1', dataSetName: 'main', trackingId: 'sync-tracking-id'}, + }); + + cdl.saveTimestamp({ + key: 'internal.client.locus.sync.message.received', + value: 140, + options: { + meetingId: 'meeting-1', + dataSetName: 'main', + trackingId: 'llm-unknown-id', + }, + }); + + const records = cdl.meetingLatencies.get('meeting-1'); + + assert.isDefined(records); + assert.lengthOf(records!, 1); + assert.equal(records![0].messageReceived, 140); + }); + + it('falls back to the only completable record when tracking id does not match', () => { const clock = sinon.useFakeTimers({now: 150}); try { @@ -223,7 +567,7 @@ describe('internal-plugin-metrics', () => { }, }); - assert.deepEqual(cdl.completeLocusSyncLatency('meeting-1', 'llm-event-tracking-id'), { + assert.deepEqual(cdl.completeLocusSyncLatency('meeting-1', 'llm-envelope-tracking-id'), { dataSet: 'main', syncLatency: { randomBackoffTime: 0, @@ -235,7 +579,6 @@ describe('internal-plugin-metrics', () => { totalTime: 50, }, }); - assert.isFalse(cdl.locusSyncLatencies.has('meeting-1')); } finally { clock.restore(); } @@ -324,7 +667,7 @@ describe('internal-plugin-metrics', () => { assert.isUndefined(cdl.getLocusSyncLatency('main', 'meeting-1')); cdl.clearLocusSyncLatency('main', 'meeting-1'); - assert.isFalse(cdl.locusSyncLatencies.has('meeting-1:main')); + assert.isFalse(cdl.meetingLatencies.has('meeting-1')); }); }); diff --git a/packages/@webex/plugin-meetings/src/breakouts/events.ts b/packages/@webex/plugin-meetings/src/breakouts/events.ts index 0dc51b93c0d..f15bc160e27 100644 --- a/packages/@webex/plugin-meetings/src/breakouts/events.ts +++ b/packages/@webex/plugin-meetings/src/breakouts/events.ts @@ -73,7 +73,6 @@ const breakoutEvent: { payload, options, }; - submitClientEvent(metricEvent); }, }; diff --git a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts index cdca3cabe47..24470d65275 100644 --- a/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/src/hashTree/hashTreeParser.ts @@ -59,8 +59,6 @@ interface InternalDataSet extends DataSet { timer?: ReturnType; heartbeatWatchdogTimer?: ReturnType; syncAbortController?: AbortController; - // Actual random backoff used by runSyncAlgorithm (excluding idleMs) - lastBackoffTime?: number; } type WebexRequestMethod = (options: Record) => Promise; @@ -97,33 +95,31 @@ export interface SyncLatencyMetrics { totalTime: number; } -export type SyncMetricsCallback = (metrics: { - dataSet: string; - syncLatency: SyncLatencyMetrics; -}) => void; - export type SyncLatencyTracker = { + saveLatency: ( + key: 'internal.client.locus.sync.random.backoff', + value: number, + options: { + meetingId: string; + dataSetName: string; + } + ) => void; saveTimestamp: (options: { key: LocusSyncLatencyEventName; options: { meetingId: string; dataSetName: string; - randomBackoffTime?: number; trackingId?: string; }; }) => void; getLocusSyncLatency: (dataSetName: string, meetingId: string) => SyncLatencyMetrics | undefined; - completeLocusSyncLatency?: ( - meetingId: string, - trackingId?: string - ) => {dataSet: string; syncLatency: SyncLatencyMetrics} | undefined; clearLocusSyncLatency: (dataSetName: string, meetingId: string) => void; }; export type HashTreeParserCallbacks = { locusInfoUpdateCallback: LocusInfoUpdateCallback; - syncMetricsCallback?: SyncMetricsCallback; syncLatencyTracker?: SyncLatencyTracker; + syncResponseCallback?: (trackingId?: string) => void; }; const SYNC_METRICS_DATA_SETS = [ @@ -1213,8 +1209,8 @@ class HashTreeParser { * Handles incoming hash tree messages, updates the hash trees and calls locusInfoUpdateCallback * * @param {HashTreeMessage} message - The hash tree message containing data sets and objects to be processed - * @param {string} [debugText] - Optional debug text to include in logs - * @param {string} [trackingId] top-level tracking id from LLM event or /sync response + * @param {string} [debugText] - Optional text included only in parser logs to identify the caller or source flow + * @param {string} [trackingId] - Top-level tracking id from the LLM event, used for sync latency attribution * @returns {void} */ handleMessage(message: HashTreeMessage, debugText?: string, trackingId?: string) { @@ -1237,7 +1233,14 @@ class HashTreeParser { this.handleRootHashHeartBeatMessage(message); this.resetHeartbeatWatchdogs(message.dataSets); } else { - this.tryCompleteSyncMetricsFromMessage(message, trackingId); + message.dataSets.forEach((dataSet) => { + if (this.shouldCollectSyncMetrics(dataSet.name)) { + this.callbacks.syncLatencyTracker?.saveTimestamp({ + key: 'internal.client.locus.sync.message.received', + options: this.getSyncLatencyTimestampOptions(dataSet.name, undefined, trackingId), + }); + } + }); const updatedObjects = this.parseMessage(message, debugText); @@ -1264,25 +1267,23 @@ class HashTreeParser { ); } - private tryCompleteSyncMetricsFromMessage(message: HashTreeMessage, trackingId?: string) { - const hasSupportedDataSet = message.dataSets.some((dataSet) => - SYNC_METRICS_DATA_SETS.includes(dataSet.name) - ); - - if (!hasSupportedDataSet) { + private saveSyncBackoffLatency( + dataSetName: string, + randomBackoffTime: number, + isInitialization = false + ) { + if (!this.shouldCollectSyncMetrics(dataSetName, isInitialization)) { return; } - const syncMetrics = this.callbacks.syncLatencyTracker?.completeLocusSyncLatency?.( - this.syncLatencyMeetingId, - trackingId + this.callbacks.syncLatencyTracker?.saveLatency( + 'internal.client.locus.sync.random.backoff', + Math.round(randomBackoffTime), + { + meetingId: this.syncLatencyMeetingId, + dataSetName, + } ); - - if (!syncMetrics) { - return; - } - - this.callbacks.syncMetricsCallback?.(syncMetrics); } /** @@ -1427,10 +1428,7 @@ class HashTreeParser { if (shouldCollectMetrics) { this.callbacks.syncLatencyTracker?.saveTimestamp({ key: 'internal.client.locus.sync.start', - options: this.getSyncLatencyTimestampOptions( - dataSet.name, - Math.round(dataSet.lastBackoffTime || 0) - ), + options: this.getSyncLatencyTimestampOptions(dataSet.name), }); } @@ -1490,13 +1488,11 @@ class HashTreeParser { } // request sync for mismatched leaves let syncResponse: HashTreeMessage | null = null; - let syncResponseTrackingId: string | undefined; if (isInitialization) { const syncResult = await this.sendSyncRequestToLocus(dataSet, {isInitialization: true}); syncResponse = syncResult.message; - syncResponseTrackingId = syncResult.trackingId; syncRequestSent = true; } else if (Object.keys(leavesData).length > 0) { const syncResult = await this.sendSyncRequestToLocus(dataSet, { @@ -1504,7 +1500,6 @@ class HashTreeParser { }); syncResponse = syncResult.message; - syncResponseTrackingId = syncResult.trackingId; syncRequestSent = true; } @@ -1528,8 +1523,7 @@ class HashTreeParser { syncResponse, `via sync API (${ isInitialization ? 'init' : `${Object.keys(leavesData).length} mismatched leaves` - })`, - syncResponseTrackingId + })` ); } } catch (error) { @@ -1773,7 +1767,7 @@ class HashTreeParser { ); for (const ds of effectiveDataSetsToSync) { - this.dataSets[ds.name].lastBackoffTime = delay; + this.saveSyncBackoffLatency(ds.name, delay); this.enqueueSyncForDataset(ds.name, 'syncAllDatasets'); } @@ -1832,7 +1826,7 @@ class HashTreeParser { clearTimeout(dataSet.timer); } - dataSet.lastBackoffTime = randomBackoffTime; + this.saveSyncBackoffLatency(dataSet.name, randomBackoffTime); dataSet.timer = setTimeout(() => { dataSet.timer = undefined; @@ -1904,7 +1898,7 @@ class HashTreeParser { dataSetName: dataSet.name, }); - dataSet.lastBackoffTime = backoffTime; + this.saveSyncBackoffLatency(dataSet.name, backoffTime); this.enqueueSyncForDataset(dataSet.name, `heartbeat watchdog expired`); this.resetHeartbeatWatchdogs([dataSet]); @@ -2207,6 +2201,7 @@ class HashTreeParser { key: 'internal.client.locus.sync.response', options: this.getSyncLatencyTimestampOptions(dataSet.name, undefined, trackingId), }); + this.callbacks.syncResponseCallback?.(trackingId); } if (!resp.body || isEmpty(resp.body)) { diff --git a/packages/@webex/plugin-meetings/src/locus-info/index.ts b/packages/@webex/plugin-meetings/src/locus-info/index.ts index 7fbaf9d3ca6..02ad5cc5e57 100644 --- a/packages/@webex/plugin-meetings/src/locus-info/index.ts +++ b/packages/@webex/plugin-meetings/src/locus-info/index.ts @@ -37,7 +37,6 @@ import HashTreeParser, { LocusInfoUpdate, LocusInfoUpdateType, Metadata, - SyncMetricsCallback, SyncLatencyTracker, } from '../hashTree/hashTreeParser'; import {HashTreeObject, ObjectType, ObjectTypeToLocusKeyMap} from '../hashTree/types'; @@ -51,6 +50,7 @@ export type LocusLLMEvent = { trackingId?: string; data: { eventType: typeof LOCUSEVENT.HASH_TREE_DATA_UPDATED; + trackingId?: string; stateElementsMessage: HashTreeMessage; }; }; @@ -99,8 +99,8 @@ export type HashTreeParserEntry = { export type LocusInfoCallbacks = { updateMeeting: (object: any) => void; - syncMetricsCallback?: SyncMetricsCallback; syncLatencyTracker?: SyncLatencyTracker; + syncResponseCallback?: (trackingId?: string) => void; }; /** @@ -566,8 +566,8 @@ export default class LocusInfo extends EventsScope { webexRequest: this.webex.request.bind(this.webex), callbacks: { locusInfoUpdateCallback: this.updateFromHashTree.bind(this, locusUrl), - syncMetricsCallback: this.callbacks.syncMetricsCallback, syncLatencyTracker: this.callbacks.syncLatencyTracker, + syncResponseCallback: this.callbacks.syncResponseCallback, }, debugId: `HT-${locusUrl.split('/')?.pop()?.substring(0, 4)}`, excludedDataSets: this.webex.config.meetings.locus?.excludedDataSets, @@ -1124,9 +1124,10 @@ export default class LocusInfo extends EventsScope { * Checks if the hash tree message should trigger a switch to a different HashTreeParser * * @param {HashTreeMessage} message incoming hash tree message + * @param {string} [trackingId] top-level tracking id from the LLM event, passed through for sync latency attribution * @returns {boolean} true if the message was handled as a parser switch, false otherwise */ - private handleHashTreeParserSwitch(message: HashTreeMessage): boolean { + private handleHashTreeParserSwitch(message: HashTreeMessage, trackingId?: string): boolean { const entry = this.hashTreeParsers.get(message.locusUrl); const self = message.locusStateElements?.find((el) => isSelf(el))?.data; @@ -1160,7 +1161,7 @@ export default class LocusInfo extends EventsScope { }); // handle the message with the new parser - parser.handleMessage(message); + parser.handleMessage(message, undefined, trackingId); } return true; @@ -1206,7 +1207,7 @@ export default class LocusInfo extends EventsScope { return; } - const parserSwitched = this.handleHashTreeParserSwitch(message); + const parserSwitched = this.handleHashTreeParserSwitch(message, trackingId); if (parserSwitched) { return; diff --git a/packages/@webex/plugin-meetings/src/meeting/index.ts b/packages/@webex/plugin-meetings/src/meeting/index.ts index 9508e4dc4f1..297ef313716 100644 --- a/packages/@webex/plugin-meetings/src/meeting/index.ts +++ b/packages/@webex/plugin-meetings/src/meeting/index.ts @@ -1386,8 +1386,8 @@ export default class Meeting extends StatelessWebexPlugin { this.locusInfo = new LocusInfo( { updateMeeting: this.updateMeetingObject.bind(this), - syncMetricsCallback: this.sendSyncCompleteMetric.bind(this), syncLatencyTracker: (this as any).webex.internal.newMetrics.callDiagnosticLatencies, + syncResponseCallback: this.handleHashTreeSyncResponse.bind(this), }, // @ts-ignore this.webex, @@ -5973,18 +5973,31 @@ export default class Meeting extends StatelessWebexPlugin { storeEventForDebugging('llm', event.data); } - // @ts-ignore - const syncMetrics = - this.webex.internal.newMetrics.callDiagnosticLatencies.completeLocusSyncLatency( - this.id, - event.trackingId - ); + const trackingId = [ + event.data.trackingId, + (event.data as any).trackingid, + (event.data as any).headers?.trackingId, + (event.data as any).headers?.trackingid, + (event.data.stateElementsMessage as any)?.trackingId, + (event.data.stateElementsMessage as any)?.trackingid, + event.trackingId, + (event as any).trackingid, + (event as any).headers?.trackingId, + (event as any).headers?.trackingid, + ].find((id) => typeof id === 'string' && id.length > 0); + + this.locusInfo.parse(this, event.data, trackingId); + + const syncMetrics = ( + this as any + ).webex.internal.newMetrics.callDiagnosticLatencies.completeLocusSyncLatency( + this.id, + trackingId + ); if (syncMetrics) { this.sendSyncCompleteMetric(syncMetrics); } - - this.locusInfo.parse(this, event.data, event.trackingId); } else { LoggerProxy.logger.warn( `Meeting:index#processLocusLLMEvent --> Unknown event type: ${event.data.eventType}` @@ -5992,6 +6005,19 @@ export default class Meeting extends StatelessWebexPlugin { } }; + private handleHashTreeSyncResponse(trackingId?: string) { + const syncMetrics = ( + this as any + ).webex.internal.newMetrics.callDiagnosticLatencies.completeLocusSyncLatency( + this.id, + trackingId + ); + + if (syncMetrics) { + this.sendSyncCompleteMetric(syncMetrics); + } + } + /** * Verifies the relay event was delivered for the active LLM session binding. * @param {RelayEvent} event Event object coming from LLM Connection diff --git a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts index db5bf32f4f4..ce26c4b25db 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts +++ b/packages/@webex/plugin-meetings/test/unit/spec/hashTree/hashTreeParser.ts @@ -178,7 +178,6 @@ describe('HashTreeParser', () => { initialLocus: any = exampleInitialLocus, metadata: any = exampleMetadata, excludedDataSets?: string[], - syncMetricsCallback: sinon.SinonStub = sinon.stub(), syncLatencyTracker?: any, syncLatencyMeetingId = 'meeting-1' ) { @@ -188,7 +187,6 @@ describe('HashTreeParser', () => { webexRequest, callbacks: { locusInfoUpdateCallback: callback, - syncMetricsCallback, syncLatencyTracker, }, debugId: 'test', @@ -3108,6 +3106,7 @@ describe('HashTreeParser', () => { it('uses the watchdog random backoff when reporting sync metrics', async () => { const syncLatencyTracker = { + saveLatency: sinon.stub(), saveTimestamp: sinon.stub(), getLocusSyncLatency: sinon.stub(), clearLocusSyncLatency: sinon.stub(), @@ -3116,7 +3115,6 @@ describe('HashTreeParser', () => { undefined, undefined, undefined, - sinon.stub(), syncLatencyTracker ); const heartbeatIntervalMs = 5000; @@ -3149,18 +3147,20 @@ describe('HashTreeParser', () => { await clock.tickAsync(heartbeatIntervalMs + 250); - assert.calledWith(syncLatencyTracker.saveTimestamp, { - key: 'internal.client.locus.sync.start', - options: { + assert.calledWithExactly( + syncLatencyTracker.saveLatency, + 'internal.client.locus.sync.random.backoff', + 250, + { meetingId: 'meeting-1', dataSetName: 'main', - randomBackoffTime: 250, - }, - }); + } + ); }); it('uses the root sync random backoff when root timer fires before watchdog', async () => { const syncLatencyTracker = { + saveLatency: sinon.stub(), saveTimestamp: sinon.stub(), getLocusSyncLatency: sinon.stub(), clearLocusSyncLatency: sinon.stub(), @@ -3169,7 +3169,6 @@ describe('HashTreeParser', () => { undefined, undefined, undefined, - sinon.stub(), syncLatencyTracker ); const mainDataSetUrl = parser.dataSets.main.url; @@ -3192,14 +3191,15 @@ describe('HashTreeParser', () => { await clock.tickAsync(1010); - assert.calledWith(syncLatencyTracker.saveTimestamp, { - key: 'internal.client.locus.sync.start', - options: { + assert.calledWithExactly( + syncLatencyTracker.saveLatency, + 'internal.client.locus.sync.random.backoff', + 10, + { meetingId: 'meeting-1', dataSetName: 'main', - randomBackoffTime: 10, - }, - }); + } + ); }); it('calls POST sync directly for leafCount === 1 data sets', async () => { @@ -4806,6 +4806,7 @@ describe('HashTreeParser', () => { mathRandomStub.returns(0.5); // syncAll backoff = 0.5^2 * 1000 = 250ms const syncLatencyTracker = { + saveLatency: sinon.stub(), saveTimestamp: sinon.stub(), getLocusSyncLatency: sinon.stub(), clearLocusSyncLatency: sinon.stub(), @@ -4814,7 +4815,6 @@ describe('HashTreeParser', () => { undefined, undefined, ['atd-unmuted'], - sinon.stub(), syncLatencyTracker ); const mainUrl = parser.dataSets.main.url; @@ -4831,14 +4831,15 @@ describe('HashTreeParser', () => { await clock.tickAsync(250); await syncAllPromise; - assert.calledWith(syncLatencyTracker.saveTimestamp, { - key: 'internal.client.locus.sync.start', - options: { + assert.calledWithExactly( + syncLatencyTracker.saveLatency, + 'internal.client.locus.sync.random.backoff', + 250, + { meetingId: 'meeting-1', dataSetName: 'main', - randomBackoffTime: 250, - }, - }); + } + ); }); it('should upgrade scope from onlyLLM=true to all datasets when onlyLLM=false call arrives during backoff', async () => { @@ -5473,6 +5474,7 @@ describe('HashTreeParser', () => { describe('#syncMetrics', () => { it('records sync latency timestamps when sync response has empty body', async () => { const syncLatencyTracker = { + saveLatency: sinon.stub(), saveTimestamp: sinon.stub(), getLocusSyncLatency: sinon.stub(), clearLocusSyncLatency: sinon.stub(), @@ -5481,7 +5483,6 @@ describe('HashTreeParser', () => { undefined, undefined, undefined, - undefined, syncLatencyTracker ); const mainDataSetUrl = parser.dataSets.main.url; @@ -5502,7 +5503,7 @@ describe('HashTreeParser', () => { assert.calledWithExactly(syncLatencyTracker.saveTimestamp, { key: 'internal.client.locus.sync.start', - options: {meetingId: 'meeting-1', dataSetName: 'main', randomBackoffTime: 0}, + options: {meetingId: 'meeting-1', dataSetName: 'main'}, }); assert.calledWithExactly(syncLatencyTracker.saveTimestamp, { key: 'internal.client.locus.hashtree.request', @@ -5525,6 +5526,7 @@ describe('HashTreeParser', () => { it('records sync response tracking id for Meeting-side completion', async () => { const syncLatencyTracker = { + saveLatency: sinon.stub(), saveTimestamp: sinon.stub(), getLocusSyncLatency: sinon.stub(), clearLocusSyncLatency: sinon.stub(), @@ -5533,7 +5535,6 @@ describe('HashTreeParser', () => { undefined, undefined, undefined, - undefined, syncLatencyTracker ); const mainDataSetUrl = parser.dataSets.main.url; @@ -5565,6 +5566,7 @@ describe('HashTreeParser', () => { it('does not complete or clear metrics when matching dataset message arrives', () => { const syncLatencyTracker = { + saveLatency: sinon.stub(), saveTimestamp: sinon.stub(), getLocusSyncLatency: sinon.stub(), clearLocusSyncLatency: sinon.stub(), @@ -5573,7 +5575,6 @@ describe('HashTreeParser', () => { undefined, undefined, undefined, - undefined, syncLatencyTracker ); @@ -5593,33 +5594,14 @@ describe('HashTreeParser', () => { assert.notCalled(syncLatencyTracker.clearLocusSyncLatency); }); - it('passes completed sync metrics from parser to callback when matching dataset message arrives', () => { - const syncMetrics = { - dataSet: 'main', - syncLatency: { - randomBackoffTime: 0, - hashtreePrepTime: 1, - hashtreeResponseTime: 2, - syncPrepTime: 3, - syncResponseTime: 4, - syncMessageReceiveTime: 5, - totalTime: 15, - }, - }; - const syncMetricsCallback = sinon.stub(); + it('records message received timestamp with LLM tracking id', () => { const syncLatencyTracker = { + saveLatency: sinon.stub(), saveTimestamp: sinon.stub(), getLocusSyncLatency: sinon.stub(), - completeLocusSyncLatency: sinon.stub().returns(syncMetrics), clearLocusSyncLatency: sinon.stub(), }; - const parser = createHashTreeParser( - undefined, - undefined, - undefined, - syncMetricsCallback, - syncLatencyTracker - ); + const parser = createHashTreeParser(undefined, undefined, undefined, syncLatencyTracker); parser.handleMessage( { @@ -5633,17 +5615,68 @@ describe('HashTreeParser', () => { locusUrl, locusStateElements: [], }, - 'via sync API (1 mismatched leaves)', - 'our-sync-tracking-id' + 'trigger sync metrics', + 'llm-event-tracking-id' ); - assert.calledOnceWithExactly( - syncLatencyTracker.completeLocusSyncLatency, - 'meeting-1', - 'our-sync-tracking-id' + assert.calledWithExactly(syncLatencyTracker.saveTimestamp, { + key: 'internal.client.locus.sync.message.received', + options: { + meetingId: 'meeting-1', + dataSetName: 'main', + trackingId: 'llm-event-tracking-id', + }, + }); + assert.notCalled(syncLatencyTracker.getLocusSyncLatency); + }); + + it('does not complete sync metrics when sync response has body', async () => { + const syncLatencyTracker = { + saveLatency: sinon.stub(), + saveTimestamp: sinon.stub(), + getLocusSyncLatency: sinon.stub(), + clearLocusSyncLatency: sinon.stub(), + }; + const parser = createHashTreeParser(undefined, undefined, undefined, syncLatencyTracker); + const mainDataSetUrl = parser.dataSets.main.url; + const syncResponse = { + dataSets: [ + { + ...createDataSet('main', 16, 1102), + root: 'newroot', + }, + ], + visibleDataSetsUrl, + locusUrl, + locusStateElements: [], + }; + + mockGetHashesFromLocusResponse( + mainDataSetUrl, + new Array(16).fill('00000000000000000000000000000000'), + createDataSet('main', 16, 1102) ); - assert.calledOnceWithExactly(syncMetricsCallback, syncMetrics); - assert.notCalled(syncLatencyTracker.clearLocusSyncLatency); + mockSendSyncRequestResponse(mainDataSetUrl, syncResponse, { + trackingid: 'our-sync-tracking-id', + }); + + parser.handleMessage( + createHeartbeatMessage('main', 16, 1100, 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa1'), + 'trigger sync metrics' + ); + + await clock.tickAsync(1000); + + assert.calledWithExactly(syncLatencyTracker.saveTimestamp, { + key: 'internal.client.locus.sync.response', + options: { + meetingId: 'meeting-1', + dataSetName: 'main', + trackingId: 'our-sync-tracking-id', + }, + }); + assert.notCalled(syncLatencyTracker.getLocusSyncLatency); }); + }); }); diff --git a/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js b/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js index 88555c47839..6ce352ad233 100644 --- a/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js +++ b/packages/@webex/plugin-meetings/test/unit/spec/meeting/index.js @@ -14616,8 +14616,12 @@ describe('plugin-meetings', () => { }; const syncMetrics = {dataSet: 'main', syncLatency}; const event = { - data: {eventType: 'locus.state_message', dataSets: []}, - trackingId: 'our-sync-tracking-id', + data: { + eventType: 'locus.state_message', + dataSets: [], + trackingId: 'our-sync-tracking-id', + }, + trackingId: 'llm-envelope-tracking-id', }; webex.internal.newMetrics.submitClientEvent.resetHistory(); @@ -14634,7 +14638,91 @@ describe('plugin-meetings', () => { meeting.id, 'our-sync-tracking-id' ); - assert.calledOnceWithExactly(meeting.locusInfo.parse, meeting, event.data, event.trackingId); + assert.calledOnceWithExactly(meeting.locusInfo.parse, meeting, event.data, event.data.trackingId); + assert.calledOnceWithExactly(webex.internal.newMetrics.submitClientEvent, { + name: 'client.locus.sync.complete', + payload: { + identifiers: { + llmWebsocketUrl: 'wss://llm-websocket-url', + }, + syncLatency, + llmInfo: { + dataSet: 'main', + }, + }, + options: { + meetingId: meeting.id, + }, + }); + }); + + it('uses lowercase envelope trackingid when trackingId is absent', () => { + const syncMetrics = { + dataSet: 'main', + syncLatency: { + randomBackoffTime: 10, + hashtreePrepTime: 5, + hashtreeResponseTime: 20, + syncPrepTime: 3, + syncResponseTime: 15, + syncMessageReceiveTime: 7, + totalTime: 50, + }, + }; + const event = { + data: {eventType: 'locus.state_message', dataSets: []}, + trackingid: 'lowercase-envelope-tracking-id', + }; + + webex.internal.newMetrics.callDiagnosticLatencies.completeLocusSyncLatency = sinon + .stub() + .returns(syncMetrics); + meeting.locusInfo.parse = sinon.stub(); + + meeting.processLocusLLMEvent(event); + + assert.calledOnceWithExactly( + webex.internal.newMetrics.callDiagnosticLatencies.completeLocusSyncLatency, + meeting.id, + 'lowercase-envelope-tracking-id' + ); + assert.calledOnceWithExactly( + meeting.locusInfo.parse, + meeting, + event.data, + 'lowercase-envelope-tracking-id' + ); + }); + + it('completes sync metrics when hash tree sync response callback runs after initial miss', () => { + const syncLatency = { + randomBackoffTime: 10, + hashtreePrepTime: 5, + hashtreeResponseTime: 20, + syncPrepTime: 3, + syncResponseTime: 15, + syncMessageReceiveTime: 7, + totalTime: 50, + }; + const syncMetrics = {dataSet: 'main', syncLatency}; + const event = { + data: {eventType: 'locus.state_message', dataSets: [], trackingId: 'race-id'}, + }; + const completeStub = sinon.stub(); + + completeStub.onCall(0).returns(undefined); + completeStub.onCall(1).returns(syncMetrics); + + webex.internal.newMetrics.submitClientEvent.resetHistory(); + webex.internal.newMetrics.callDiagnosticLatencies.completeLocusSyncLatency = completeStub; + webex.internal.llm.getWebSocketUrl = sinon.stub().returns('wss://llm-websocket-url'); + meeting.locusInfo.parse = sinon.stub(); + + meeting.processLocusLLMEvent(event); + meeting.handleHashTreeSyncResponse('race-id'); + + assert.calledWithExactly(completeStub.firstCall, meeting.id, 'race-id'); + assert.calledWithExactly(completeStub.secondCall, meeting.id, 'race-id'); assert.calledOnceWithExactly(webex.internal.newMetrics.submitClientEvent, { name: 'client.locus.sync.complete', payload: {