Update messaging for measuring message delay between App and Hub

apps/teams-test-app/src/components/AppAPIs.tsx

@@ -3,6 +3,7 @@ import {
   Context,
   executeDeepLink,
   getContext,
+  HostToAppPerformanceMetrics,
   registerOnThemeChangeHandler,
   ResumeContext,
 } from '@microsoft/teams-js';
@@ -64,6 +65,20 @@ const OpenLink = (): ReactElement =>
     defaultInput: '"https://teams.microsoft.com/l/call/0/0?users=testUser1,testUser2&withVideo=true&source=test"',
   });
 
+const RegisterHostToAppPerformanceMetricsHandler = (): ReactElement =>
+  ApiWithoutInput({
+    name: 'registerHostToAppPerformanceMetricsHandler',
+    title: 'Register Host to App performance metrics handler',
+    onClick: async (setResult) => {
+      const handler = (v: HostToAppPerformanceMetrics): void => {
+        console.log(v);
+        setResult(JSON.stringify(v));
+      };
+      app.registerHostToAppPerformanceMetricsHandler(handler);
+      return 'Registered callback!';
+    },
+  });
+
 const RegisterOnThemeChangeHandler = (): ReactElement =>
   ApiWithoutInput({
     name: 'registerOnThemeChangeHandler',
@@ -128,6 +143,7 @@ const AppAPIs = (): ReactElement => (
   <ModuleWrapper title="App">
     <GetContext />
     <OpenLink />
+    <RegisterHostToAppPerformanceMetricsHandler />
     <RegisterOnThemeChangeHandler />
     <RegisterBeforeSuspendOrTerminateHandler />
     <RegisterOnResumeHandler />

change/@microsoft-teams-js-42d39be6-18d9-4619-ab76-a1360275873c.json

@@ -0,0 +1,7 @@
+{
+  "type": "minor",
+  "comment": "Added new timestamp and handler for analyzing latencies due to message delays between app and hub.",
+  "packageName": "@microsoft/teams-js",
+  "email": "[email protected]",
+  "dependentChangeType": "patch"
+}

packages/teams-js/src/internal/communication.ts

@@ -10,6 +10,7 @@ import { ISerializable, isSerializable } from '../public/serializable.interface'
 import { version } from '../public/version';
 import { GlobalVars } from './globalVars';
 import { callHandler } from './handlers';
+import HostToAppMessageDelayTelemetry from './hostToAppTelemetry';
 import { DOMMessageEvent, ExtendedWindow } from './interfaces';
 import {
   deserializeMessageRequest,
@@ -31,7 +32,7 @@ import {
 } from './nestedAppAuthUtils';
 import { ResponseHandler, SimpleType } from './responseHandler';
 import { getLogger, isFollowingApiVersionTagFormat } from './telemetry';
-import { ssrSafeWindow } from './utils';
+import { getCurrentTimestamp, ssrSafeWindow } from './utils';
 import { UUID as MessageUUID } from './uuidObject';
 import { validateOrigin } from './validOrigins';
 
@@ -160,6 +161,7 @@ export function uninitializeCommunication(): void {
   CommunicationPrivate.promiseCallbacks.clear();
   CommunicationPrivate.portCallbacks.clear();
   CommunicationPrivate.legacyMessageIdsToUuidMap = {};
+  HostToAppMessageDelayTelemetry.clearMessages();
 }
 
 /**
@@ -518,9 +520,12 @@ function sendMessageToParentHelper(
   args: any[] | undefined,
 ): MessageRequestWithRequiredProperties {
   const logger = sendMessageToParentHelperLogger;
-
   const targetWindow = Communication.parentWindow;
   const request = createMessageRequest(apiVersionTag, actionName, args);
+  HostToAppMessageDelayTelemetry.storeCallbackInformation(request.uuid, {
+    name: actionName,
+    calledAt: request.timestamp,
+  });
 
   logger('Message %s information: %o', getMessageIdsAsLogString(request), { actionName, args });
 
@@ -798,6 +803,7 @@ function removeMessageHandlers(message: MessageResponse, map: Map<MessageUUID, F
  */
 function handleIncomingMessageFromParent(evt: DOMMessageEvent): void {
   const logger = handleIncomingMessageFromParentLogger;
+  const timeWhenMessageArrived = getCurrentTimestamp();
 
   if ('id' in evt.data && typeof evt.data.id === 'number') {
     // Call any associated Communication.callbacks
@@ -807,6 +813,7 @@ function handleIncomingMessageFromParent(evt: DOMMessageEvent): void {
     if (callbackId) {
       const callback = CommunicationPrivate.callbacks.get(callbackId);
       logger('Received a response from parent for message %s', callbackId.toString());
+      HostToAppMessageDelayTelemetry.handlePerformanceMetrics(callbackId, message, logger, timeWhenMessageArrived);
       if (callback) {
         logger(
           'Invoking the registered callback for message %s with arguments %o',
@@ -858,6 +865,7 @@ function handleIncomingMessageFromParent(evt: DOMMessageEvent): void {
   } else if ('func' in evt.data && typeof evt.data.func === 'string') {
     // Delegate the request to the proper handler
     const message = evt.data as MessageRequest;
+    HostToAppMessageDelayTelemetry.handleOneWayPerformanceMetrics(message, logger, timeWhenMessageArrived);
     logger('Received a message from parent %s, action: "%s"', getMessageIdsAsLogString(message), message.func);
     callHandler(message.func, message.args);
   } else {
@@ -1090,6 +1098,7 @@ function createMessageRequest(
     uuid: messageUuid,
     func: func,
     timestamp: Date.now(),
+    monotonicTimestamp: getCurrentTimestamp(),
     args: args || [],
     apiVersionTag: apiVersionTag,
   };
@@ -1115,6 +1124,7 @@ function createNestedAppAuthRequest(message: string): NestedAppAuthRequest {
     uuid: messageUuid,
     func: 'nestedAppAuth.execute',
     timestamp: Date.now(),
+    monotonicTimestamp: getCurrentTimestamp(),
     // Since this is a nested app auth request, we don't need to send any args.
     // We avoid overloading the args array with the message to avoid potential issues processing of these messages on the hubSDK.
     args: [],

packages/teams-js/src/internal/handlers.ts

@@ -2,7 +2,7 @@
 
 import { ApiName, ApiVersionNumber, getApiVersionTag } from '../internal/telemetry';
 import { FrameContexts } from '../public/constants';
-import { LoadContext, ResumeContext } from '../public/interfaces';
+import { HostToAppPerformanceMetrics, LoadContext, ResumeContext } from '../public/interfaces';
 import * as pages from '../public/pages/pages';
 import { runtime } from '../public/runtime';
 import { Communication, sendMessageEventToChild, sendMessageToParent } from './communication';
@@ -31,6 +31,7 @@ class HandlersPrivate {
   public static beforeUnloadHandler: null | ((readyToUnload: () => void) => boolean) = null;
   public static beforeSuspendOrTerminateHandler: null | (() => Promise<void>) = null;
   public static resumeHandler: null | ((context: ResumeContext) => void) = null;
+  public static hostToAppPerformanceMetricsHandler: null | ((metrics: HostToAppPerformanceMetrics) => void) = null;
 
   /**
    * @internal
@@ -182,6 +183,27 @@ export function handleThemeChange(theme: string): void {
   }
 }
 
+/**
+ * @internal
+ * Limited to Microsoft-internal use
+ */
+export function registerHostToAppPerformanceMetricsHandler(
+  handler: (metrics: HostToAppPerformanceMetrics) => void,
+): void {
+  HandlersPrivate.hostToAppPerformanceMetricsHandler = handler;
+}
+
+/**
+ * @internal
+ * Limited to Microsoft-internal use
+ */
+export function handleHostToAppPerformanceMetrics(metrics: HostToAppPerformanceMetrics): void {
+  if (!HandlersPrivate.hostToAppPerformanceMetricsHandler) {
+    return;
+  }
+  HandlersPrivate.hostToAppPerformanceMetricsHandler(metrics);
+}
+
 /**
  * @internal
  * Limited to Microsoft-internal use

packages/teams-js/src/internal/hostToAppTelemetry.ts

@@ -0,0 +1,96 @@
+import { Debugger } from 'debug';
+
+import { handleHostToAppPerformanceMetrics } from './handlers';
+import { CallbackInformation } from './interfaces';
+import { MessageRequest, MessageResponse } from './messageObjects';
+import { UUID as MessageUUID } from './uuidObject';
+
+/**
+ * @internal
+ * Limited to Microsoft-internal use
+ */
+export default class HostToAppMessageDelayTelemetry {
+  private static callbackInformation: Map<MessageUUID, CallbackInformation> = new Map();
+
+  /**
+   * @internal
+   * Limited to Microsoft-internal use
+   *
+   * Store information about a particular message.
+   * @param messageUUID The message id for the request.
+   * @param callbackInformation The information of the callback.
+   */
+  public static storeCallbackInformation(messageUUID: MessageUUID, callbackInformation: CallbackInformation): void {
+    HostToAppMessageDelayTelemetry.callbackInformation.set(messageUUID, callbackInformation);
+  }
+
+  /**
+   * @internal
+   * Limited to Microsoft-internal use
+   */
+  public static clearMessages(): void {
+    HostToAppMessageDelayTelemetry.callbackInformation.clear();
+  }
+
+  /**
+   * @internal
+   * Limited to Microsoft-internal use
+   */
+  public static deleteMessageInformation(callbackId: MessageUUID): void {
+    HostToAppMessageDelayTelemetry.callbackInformation.delete(callbackId);
+  }
+  /**
+   * @internal
+   * Limited to Microsoft-internal use
+   *
+   * Executes telemetry actions related to host to app performance metrics where event is raised in the host.
+   * @param message The request from the host.
+   * @param logger The logger in case an error occurs.
+   * @param endTime The ending time for calculating the elapsed time
+   */
+  public static handleOneWayPerformanceMetrics(message: MessageRequest, logger: Debugger, endTime: number): void {
+    const timestamp = message.monotonicTimestamp;
+    if (!timestamp) {
+      logger('Unable to send performance metrics for event %s', message.func);
+      return;
+    }
+    handleHostToAppPerformanceMetrics({
+      actionName: message.func,
+      messageDelay: endTime - timestamp,
+      requestStartedAt: timestamp,
+    });
+  }
+
+  /**
+   * @internal
+   * Limited to Microsoft-internal use
+   *
+   * Executes telemetry actions related to host to app performance metrics.
+   * @param callbackId The message id for the request.
+   * @param message The response from the host.
+   * @param logger The logger in case an error occurs.
+   * @param endTime The ending time for calculating the elapsed time
+   */
+  public static handlePerformanceMetrics(
+    callbackID: MessageUUID,
+    message: MessageResponse,
+    logger: Debugger,
+    endTime: number,
+  ): void {
+    const callbackInformation = HostToAppMessageDelayTelemetry.callbackInformation.get(callbackID);
+    if (!callbackInformation || !message.monotonicTimestamp) {
+      logger(
+        'Unable to send performance metrics for callback %s with arguments %o',
+        callbackID.toString(),
+        message.args,
+      );
+      return;
+    }
+    handleHostToAppPerformanceMetrics({
+      actionName: callbackInformation.name,
+      messageDelay: endTime - message.monotonicTimestamp,
+      requestStartedAt: callbackInformation.calledAt,
+    });
+    HostToAppMessageDelayTelemetry.deleteMessageInformation(callbackID);
+  }
+}

packages/teams-js/src/internal/interfaces.ts

@@ -50,3 +50,15 @@ export interface DOMMessageEvent {
   func: string;
   args?: any[];
 }
+
+/**
+ * @hidden
+ * Meant for providing information related to certain callback context.
+ *
+ * @internal
+ * Limited to Microsoft-internal use
+ */
+export interface CallbackInformation {
+  name: string;
+  calledAt: number;
+}

packages/teams-js/src/internal/messageObjects.ts

@@ -17,6 +17,7 @@ export interface MessageRequest {
   uuid?: MessageUUID;
   func: string;
   timestamp?: number;
+  monotonicTimestamp?: number;
   // eslint-disable-next-line @typescript-eslint/no-explicit-any
   args?: any[];
   apiVersionTag?: string;
@@ -32,6 +33,7 @@ export interface SerializedMessageRequest {
   uuidAsString?: string;
   func: string;
   timestamp?: number;
+  monotonicTimestamp?: number;
   // eslint-disable-next-line @typescript-eslint/no-explicit-any
   args?: any[];
   apiVersionTag?: string;
@@ -46,6 +48,7 @@ export interface SerializedMessageResponse {
   uuidAsString?: string;
   // eslint-disable-next-line @typescript-eslint/no-explicit-any
   args?: any[];
+  monotonicTimestamp?: number;
   isPartialResponse?: boolean; // If the message is partial, then there will be more future responses for the given message ID.
 }
 
@@ -58,6 +61,7 @@ export interface MessageResponse {
   uuid?: MessageUUID;
   // eslint-disable-next-line @typescript-eslint/no-explicit-any
   args?: any[];
+  monotonicTimestamp?: number;
   isPartialResponse?: boolean; // If the message is partial, then there will be more future responses for the given message ID.
 }
 
@@ -75,7 +79,9 @@ export interface MessageResponse {
 export interface MessageRequestWithRequiredProperties extends MessageRequest {
   id: MessageID;
   uuid: MessageUUID;
+  /** Deprecated field, is still here for backwards compatibility */
   timestamp: number;
+  monotonicTimestamp: number;
 }
 
 export const serializeMessageRequest = (message: MessageRequest): SerializedMessageRequest => {

packages/teams-js/src/internal/utils.ts

@@ -504,3 +504,17 @@ export function validateUuid(id: string | undefined | null): void {
     throw new Error('id must be a valid UUID');
   }
 }
+
+/**
+ * Cache if performance timers are available to avoid redoing this on each function call.
+ */
+const supportsPerformanceTimers = !!performance && 'now' in performance;
+
+/**
+ * @internal
+ * Limited to Microsoft-internal use
+ * @returns current timestamp in milliseconds
+ */
+export function getCurrentTimestamp(): number {
+  return supportsPerformanceTimers ? performance.now() + performance.timeOrigin : new Date().getTime();
+}

packages/teams-js/src/public/app/app.ts

@@ -12,7 +12,13 @@ import { inServerSideRenderingEnvironment } from '../../internal/utils';
 import { prefetchOriginsFromCDN } from '../../internal/validOrigins';
 import { messageChannels } from '../../private/messageChannels';
 import { ChannelType, FrameContexts, HostClientType, HostName, TeamType, UserTeamRole } from '../constants';
-import { ActionInfo, Context as LegacyContext, FileOpenPreference, LocaleInfo } from '../interfaces';
+import {
+  ActionInfo,
+  Context as LegacyContext,
+  FileOpenPreference,
+  HostToAppPerformanceMetrics,
+  LocaleInfo,
+} from '../interfaces';
 import { version } from '../version';
 import * as lifecycle from './lifecycle';
 
@@ -548,6 +554,11 @@ export interface Context {
  */
 export type themeHandler = (theme: string) => void;
 
+/**
+ * This function is passed to registerHostToAppPerformanceMetricsHandler. It is called every time a response is received from the host with metrics for analyzing message delay. See {@link HostToAppPerformanceMetrics} to see which metrics are passed to the handler.
+ */
+export type HostToAppPerformanceMetricsHandler = (metrics: HostToAppPerformanceMetrics) => void;
+
 /**
  * Checks whether the Teams client SDK has been initialized.
  * @returns whether the Teams client SDK has been initialized.
@@ -719,6 +730,18 @@ export function registerOnThemeChangeHandler(handler: themeHandler): void {
   );
 }
 
+/**
+ * Registers a function for handling data of host to app message delay.
+ *
+ * @remarks
+ * Only one handler can be registered at a time. A subsequent registration replaces an existing registration.
+ *
+ * @param handler - The handler to invoke when the metrics are available on each function response.
+ */
+export function registerHostToAppPerformanceMetricsHandler(handler: HostToAppPerformanceMetricsHandler): void {
+  Handlers.registerHostToAppPerformanceMetricsHandler(handler);
+}
+
 /**
  * This function opens deep links to other modules in the host such as chats or channels or
  * general-purpose links (to external websites). It should not be used for navigating to your

packages/teams-js/src/public/index.ts

@@ -25,6 +25,7 @@ export {
   FileOpenPreference,
   FrameContext,
   FrameInfo,
+  HostToAppPerformanceMetrics,
   LoadContext,
   LocaleInfo,
   M365ContentAction,