feat(metrics): related to conference.init execution.

Adds logs and analytics events with time measurements for the different stages of conference.init execution.
jitsi · Oct 31, 2024 · 61a0247 · 61a0247
1 parent 7b4965f
commit 61a0247
Show file tree

Hide file tree

Showing 8 changed files with 89 additions and 16 deletions.
diff --git a/conference.js b/conference.js
@@ -136,6 +136,7 @@ import {
     isUserInteractionRequiredForUnmute
 } from './react/features/base/tracks/functions';
 import { downloadJSON } from './react/features/base/util/downloadJSON';
+import { getJitsiMeetGlobalNSConnectionTimes } from './react/features/base/util/helpers';
 import { openLeaveReasonDialog } from './react/features/conference/actions.web';
 import { showDesktopPicker } from './react/features/desktop-picker/actions';
 import { appendSuffix } from './react/features/display-name/functions';
@@ -413,9 +414,10 @@ export default {
      * without any audio tracks.
      * @param {boolean} options.startWithVideoMuted - will start the conference
      * without any video tracks.
+     * @param {boolean} recordTimeMetrics - If true time metrics will be recorded.
      * @returns {Promise<JitsiLocalTrack[]>, Object}
      */
-    createInitialLocalTracks(options = {}) {
+    createInitialLocalTracks(options = {}, recordTimeMetrics = false) {
         const errors = {};
 
         // Always get a handle on the audio input device so that we have statistics (such as "No audio input" or
@@ -487,7 +489,7 @@ export default {
                 devices: initialDevices,
                 timeout,
                 firePermissionPromptIsShownEvent: true
-            })).then(({ tracks, errors: pErrors }) => {
+            }, recordTimeMetrics)).then(({ tracks, errors: pErrors }) => {
                 Object.assign(errors, pErrors);
 
                 return tracks;
@@ -571,8 +573,12 @@ export default {
             startWithAudioMuted: getStartWithAudioMuted(state) || isUserInteractionRequiredForUnmute(state),
             startWithVideoMuted: getStartWithVideoMuted(state) || isUserInteractionRequiredForUnmute(state)
         };
+        const connectionTimes = getJitsiMeetGlobalNSConnectionTimes();
+        const startTime = window.performance.now();
 
-        logger.debug(`Executed conference.init with roomName: ${roomName}`);
+        connectionTimes['conference.init.start'] = startTime;
+
+        logger.debug(`Executed conference.init with roomName: ${roomName} (performance.now=${startTime})`);
 
         this.roomName = roomName;
 
@@ -605,9 +611,19 @@ export default {
             return localTracks;
         };
         const { dispatch, getState } = APP.store;
-        const { tryCreateLocalTracks, errors } = this.createInitialLocalTracks(initialOptions);
+        const createLocalTracksStart = window.performance.now();
+
+        connectionTimes['conference.init.createLocalTracks.start'] = createLocalTracksStart;
+
+        logger.debug(`(TIME) createInitialLocalTracks: ${createLocalTracksStart} `);
+
+        const { tryCreateLocalTracks, errors } = this.createInitialLocalTracks(initialOptions, true);
 
         tryCreateLocalTracks.then(async tr => {
+            const createLocalTracksEnd = window.performance.now();
+
+            connectionTimes['conference.init.createLocalTracks.end'] = createLocalTracksEnd;
+            logger.debug(`(TIME) createInitialLocalTracks finished: ${createLocalTracksEnd} `);
             const tracks = handleInitialTracks(initialOptions, tr);
 
             this._initDeviceList(true);
@@ -621,6 +637,8 @@ export default {
                 // which will guarantee us that the local tracks are added to redux before we proceed.
                 initPrejoin(tracks, errors, dispatch);
 
+                connectionTimes['conference.init.end'] = window.performance.now();
+
                 // resolve the initialGUMPromise in case connect have finished so that we can proceed to join.
                 if (initialGUMPromise) {
                     logger.debug('Resolving the initialGUM promise! (prejoinVisible=true)');
@@ -639,6 +657,7 @@ export default {
                 APP.store.dispatch(displayErrorsForCreateInitialLocalTracks(errors));
                 setGUMPendingStateOnFailedTracks(tracks, APP.store.dispatch);
 
+                connectionTimes['conference.init.end'] = window.performance.now();
                 if (initialGUMPromise) {
                     logger.debug('Resolving the initialGUM promise!');
                     initialGUMPromise.resolve({

diff --git a/react/features/base/devices/actions.web.ts b/react/features/base/devices/actions.web.ts
@@ -75,6 +75,9 @@ export function configureInitialDevices() {
         const deviceLabels = getDevicesFromURL(getState());
         let updateSettingsPromise;
 
+        logger.debug(`(TIME) configureInitialDevices: deviceLabels=${
+            Boolean(deviceLabels)}, performance.now=${window.performance.now()}`);
+
         if (deviceLabels) {
             updateSettingsPromise = dispatch(getAvailableDevices()).then(() => {
                 const state = getState();
@@ -127,6 +130,9 @@ export function configureInitialDevices() {
             .then(() => {
                 const userSelectedAudioOutputDeviceId = getUserSelectedOutputDeviceId(getState());
 
+                logger.debug(`(TIME) configureInitialDevices -> setAudioOutputDeviceId: performance.now=${
+                    window.performance.now()}`);
+
                 return setAudioOutputDeviceId(userSelectedAudioOutputDeviceId, dispatch)
                     .catch(ex => logger.warn(`Failed to set audio output device.
                         Default audio output device will be used instead ${ex}`));

diff --git a/react/features/base/tracks/actions.web.ts b/react/features/base/tracks/actions.web.ts
@@ -352,9 +352,10 @@ export function createAndAddInitialAVTracks(devices: Array<MediaType>) {
  * Creates the initial audio/video tracks.
  *
  * @param {ICreateInitialTracksOptions} options - Options for creating the audio/video tracks.
+ * @param {boolean} recordTimeMetrics - If true time metrics will be recorded.
  * @returns {Function}
  */
-export function createInitialAVTracks(options: ICreateInitialTracksOptions) {
+export function createInitialAVTracks(options: ICreateInitialTracksOptions, recordTimeMetrics = false) {
     return (dispatch: IStore['dispatch'], _getState: IStore['getState']) => {
         const {
             devices,
@@ -364,7 +365,7 @@ export function createInitialAVTracks(options: ICreateInitialTracksOptions) {
 
         dispatch(gumPending(devices, IGUMPendingState.PENDING_UNMUTE));
 
-        return createLocalTracksF(options).then(tracks => {
+        return createLocalTracksF(options, undefined, recordTimeMetrics).then(tracks => {
             return {
                 errors: {} as IInitialTracksErrors,
                 tracks

diff --git a/react/features/base/tracks/functions.web.ts b/react/features/base/tracks/functions.web.ts
@@ -11,6 +11,7 @@ import {
     getUserSelectedCameraDeviceId,
     getUserSelectedMicDeviceId
 } from '../settings/functions.web';
+import { getJitsiMeetGlobalNSConnectionTimes } from '../util/helpers';
 
 import { getCameraFacingMode } from './functions.any';
 import loadEffects from './loadEffects';
@@ -36,9 +37,10 @@ export * from './functions.any';
  * corresponding event.
  * @param {IStore} store - The redux store in the context of which the function
  * is to execute and from which state such as {@code config} is to be retrieved.
+ * @param {boolean} recordTimeMetrics - If true time metrics will be recorded.
  * @returns {Promise<JitsiLocalTrack[]>}
  */
-export function createLocalTracksF(options: ITrackOptions = {}, store?: IStore) {
+export function createLocalTracksF(options: ITrackOptions = {}, store?: IStore, recordTimeMetrics = false) {
     let { cameraDeviceId, micDeviceId } = options;
     const {
         desktopSharingSourceDevice,
@@ -69,6 +71,10 @@ export function createLocalTracksF(options: ITrackOptions = {}, store?: IStore)
 
     return (
         loadEffects(store).then((effectsArray: Object[]) => {
+            if (recordTimeMetrics) {
+                getJitsiMeetGlobalNSConnectionTimes()['trackEffects.loaded'] = window.performance.now();
+            }
+
             // Filter any undefined values returned by Promise.resolve().
             const effects = effectsArray.filter(effect => Boolean(effect));
 

diff --git a/react/features/base/tracks/loadEffects.web.ts b/react/features/base/tracks/loadEffects.web.ts
@@ -11,6 +11,7 @@ import logger from './logger';
  * @returns {Promise} - A Promise which resolves when all effects are created.
  */
 export default function loadEffects(store: IStore): Promise<any> {
+    const start = window.performance.now();
     const state = store.getState();
     const virtualBackground = state['features/virtual-background'];
     const noiseSuppression = state['features/noise-suppression'];
@@ -30,5 +31,11 @@ export default function loadEffects(store: IStore): Promise<any> {
         ? Promise.resolve(new NoiseSuppressionEffect(nsOptions))
         : Promise.resolve();
 
-    return Promise.all([ backgroundPromise, noiseSuppressionPromise ]);
+    return Promise.all([ backgroundPromise, noiseSuppressionPromise ]).then(effectsArray => {
+        const end = window.performance.now();
+
+        logger.debug(`(TIME) loadEffects() start=${start}, end=${end}, time=${end - start}`);
+
+        return effectsArray;
+    });
 }
diff --git a/react/features/base/util/helpers.ts b/react/features/base/util/helpers.ts
@@ -100,6 +100,21 @@ export function getJitsiMeetGlobalNS() {
     return window.JitsiMeetJS.app;
 }
 
+/**
+ * Returns the object that stores the connection times.
+ *
+ * @returns {Object} - The object that stores the connection times.
+ */
+export function getJitsiMeetGlobalNSConnectionTimes() {
+    const globalNS = getJitsiMeetGlobalNS();
+
+    if (!globalNS.connectionTimes) {
+        globalNS.connectionTimes = {};
+    }
+
+    return globalNS.connectionTimes;
+}
+
 /**
  * Prints the error and reports it to the global error handler.
  *

diff --git a/react/features/conference/actions.web.ts b/react/features/conference/actions.web.ts
@@ -1,6 +1,7 @@
 import { IStore } from '../app/types';
 import { configureInitialDevices, getAvailableDevices } from '../base/devices/actions.web';
 import { openDialog } from '../base/dialog/actions';
+import { getJitsiMeetGlobalNSConnectionTimes } from '../base/util/helpers';
 import { getBackendSafeRoomName } from '../base/util/uri';
 
 import { DISMISS_CALENDAR_NOTIFICATION } from './actionTypes';
@@ -37,12 +38,29 @@ export function dismissCalendarNotification() {
 /**
  * Setups initial devices. Makes sure we populate availableDevices list before configuring.
  *
+ * @param {boolean} recordTimeMetrics - If true, an analytics time metrics will be sent.
  * @returns {Promise<any>}
  */
-export function setupInitialDevices() {
+export function setupInitialDevices(recordTimeMetrics = false) {
     return async (dispatch: IStore['dispatch']) => {
+        if (recordTimeMetrics) {
+            getJitsiMeetGlobalNSConnectionTimes()['setupInitialDevices.start'] = window.performance.now();
+        }
+
         await dispatch(getAvailableDevices());
+
+        if (recordTimeMetrics) {
+            getJitsiMeetGlobalNSConnectionTimes()['setupInitialDevices.getAD.finished'] = window.performance.now();
+        }
+
         await dispatch(configureInitialDevices());
+
+        const now = window.performance.now();
+
+        if (recordTimeMetrics) {
+            getJitsiMeetGlobalNSConnectionTimes()['setupInitialDevices.end'] = now;
+        }
+        logger.debug(`(TIME) setupInitialDevices finished: ${now}`);
     };
 }
 
@@ -55,11 +73,13 @@ export function setupInitialDevices() {
  */
 export function init(shouldDispatchConnect: boolean) {
     return (dispatch: IStore['dispatch'], getState: IStore['getState']) => {
+        logger.debug(`(TIME) init action dispatched: ${window.performance.now()}`);
+
         const room = getBackendSafeRoomName(getState()['features/base/conference'].room);
 
         // XXX For web based version we use conference initialization logic
         // from the old app (at the moment of writing).
-        return dispatch(setupInitialDevices()).then(
+        return dispatch(setupInitialDevices(true)).then(
             () => APP.conference.init({
                 roomName: room,
                 shouldDispatchConnect

diff --git a/react/index.web.js b/react/index.web.js
@@ -4,7 +4,7 @@ import ReactDOM from 'react-dom';
 import { App } from './features/app/components/App.web';
 import { getLogger } from './features/base/logging/functions';
 import Platform from './features/base/react/Platform.web';
-import { getJitsiMeetGlobalNS } from './features/base/util/helpers';
+import { getJitsiMeetGlobalNS, getJitsiMeetGlobalNSConnectionTimes } from './features/base/util/helpers';
 import DialInSummaryApp from './features/invite/components/dial-in-summary/web/DialInSummaryApp';
 import PrejoinApp from './features/prejoin/components/web/PrejoinApp';
 import WhiteboardApp from './features/whiteboard/components/web/WhiteboardApp';
@@ -45,20 +45,19 @@ if (Platform.OS === 'ios') {
 }
 
 const globalNS = getJitsiMeetGlobalNS();
+const connectionTimes = getJitsiMeetGlobalNSConnectionTimes();
 
 // Used for automated performance tests.
-globalNS.connectionTimes = {
-    'index.loaded': window.indexLoadedTime
-};
+connectionTimes['index.loaded'] = window.indexLoadedTime;
 
 window.addEventListener('load', () => {
-    globalNS.connectionTimes['window.loaded'] = window.loadedEventTime;
+    connectionTimes['window.loaded'] = window.loadedEventTime;
 });
 
 document.addEventListener('DOMContentLoaded', () => {
     const now = window.performance.now();
 
-    globalNS.connectionTimes['document.ready'] = now;
+    connectionTimes['document.ready'] = now;
     logger.log('(TIME) document ready:\t', now);
 });