diff --git a/apps/teams-test-app/src/components/AppAPIs.tsx b/apps/teams-test-app/src/components/AppAPIs.tsx index 06f9e1cc5f..c7da2095ed 100644 --- a/apps/teams-test-app/src/components/AppAPIs.tsx +++ b/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 => ( + diff --git a/change/@microsoft-teams-js-42d39be6-18d9-4619-ab76-a1360275873c.json b/change/@microsoft-teams-js-42d39be6-18d9-4619-ab76-a1360275873c.json new file mode 100644 index 0000000000..53a63d9d0e --- /dev/null +++ b/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": "jcardenasr123@gmail.com", + "dependentChangeType": "patch" +} diff --git a/packages/teams-js/src/internal/communication.ts b/packages/teams-js/src/internal/communication.ts index 8949b99449..29e6134e47 100644 --- a/packages/teams-js/src/internal/communication.ts +++ b/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 void) => boolean) = null; public static beforeSuspendOrTerminateHandler: null | (() => Promise) = 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 diff --git a/packages/teams-js/src/internal/hostToAppTelemetry.ts b/packages/teams-js/src/internal/hostToAppTelemetry.ts new file mode 100644 index 0000000000..80d58d2d40 --- /dev/null +++ b/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 = 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 || !endTime) { + 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 || !endTime) { + 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); + } +} diff --git a/packages/teams-js/src/internal/interfaces.ts b/packages/teams-js/src/internal/interfaces.ts index d6433da27a..1b95ceb4a2 100644 --- a/packages/teams-js/src/internal/interfaces.ts +++ b/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; +} diff --git a/packages/teams-js/src/internal/messageObjects.ts b/packages/teams-js/src/internal/messageObjects.ts index 84f5f10619..b49c8213f1 100644 --- a/packages/teams-js/src/internal/messageObjects.ts +++ b/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,6 +79,7 @@ export interface MessageResponse { export interface MessageRequestWithRequiredProperties extends MessageRequest { id: MessageID; uuid: MessageUUID; + /** Deprecated field, is still here for backwards compatibility */ timestamp: number; } diff --git a/packages/teams-js/src/internal/utils.ts b/packages/teams-js/src/internal/utils.ts index d6193c8edf..db832f91bd 100644 --- a/packages/teams-js/src/internal/utils.ts +++ b/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 | undefined { + return supportsPerformanceTimers ? performance.now() + performance.timeOrigin : undefined; +} diff --git a/packages/teams-js/src/public/app/app.ts b/packages/teams-js/src/public/app/app.ts index 3636e23864..9493cfae16 100644 --- a/packages/teams-js/src/public/app/app.ts +++ b/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 diff --git a/packages/teams-js/src/public/index.ts b/packages/teams-js/src/public/index.ts index 1072d51859..84902d221a 100644 --- a/packages/teams-js/src/public/index.ts +++ b/packages/teams-js/src/public/index.ts @@ -25,6 +25,7 @@ export { FileOpenPreference, FrameContext, FrameInfo, + HostToAppPerformanceMetrics, LoadContext, LocaleInfo, M365ContentAction, diff --git a/packages/teams-js/src/public/interfaces.ts b/packages/teams-js/src/public/interfaces.ts index 9e6ded08a9..ab607a1864 100644 --- a/packages/teams-js/src/public/interfaces.ts +++ b/packages/teams-js/src/public/interfaces.ts @@ -1284,3 +1284,15 @@ export interface ClipboardParams { /** Blob content in Base64 string format */ content: string; } + +/** + * Meant for passing data to the app related to host-to-app message performance metrics. + */ +export interface HostToAppPerformanceMetrics { + /** The name of the action the host is responding to. */ + actionName: string; + /** The delay the message took traveling from host to app */ + messageDelay: number; + /** The time when the request was dispatched */ + requestStartedAt: number; +} diff --git a/packages/teams-js/test/internal/communication.spec.ts b/packages/teams-js/test/internal/communication.spec.ts index ae33db1e73..c74de88fc7 100644 --- a/packages/teams-js/test/internal/communication.spec.ts +++ b/packages/teams-js/test/internal/communication.spec.ts @@ -276,7 +276,7 @@ describe('Testing communication', () => { it('should set Communication.parentWindow and Communication.parentOrigin to null if the parent window is closed during the initialization call', async () => { expect.assertions(4); - /* + /* This promise is intentionally not being awaited If the parent window is closed during the initialize call, the initialize response never resolves (even though we receive it) diff --git a/packages/teams-js/test/public/app.spec.ts b/packages/teams-js/test/public/app.spec.ts index e7cc70a7ca..5127049fe1 100644 --- a/packages/teams-js/test/public/app.spec.ts +++ b/packages/teams-js/test/public/app.spec.ts @@ -1,6 +1,7 @@ import { errorLibraryNotInitialized } from '../../src/internal/constants'; import { GlobalVars } from '../../src/internal/globalVars'; import { DOMMessageEvent } from '../../src/internal/interfaces'; +import { UUID } from '../../src/internal/uuidObject'; import { authentication, dialog, menus, pages } from '../../src/public'; import * as app from '../../src/public/app/app'; import { @@ -58,6 +59,7 @@ describe('Testing app capability', () => { utils.childMessages = []; utils.childWindow.closed = false; utils.mockWindow.parent = utils.parentWindow; + utils.setRespondWithTimestamp(false); // Set a mock window for testing app._initialize(utils.mockWindow); @@ -797,6 +799,73 @@ describe('Testing app capability', () => { }); }); + describe('Testing hostToAppPerformanceMetricsHandler', () => { + it('app.registerHostToAppPerformanceMetricsHandler registered function should get called when api SDK call has timestamp', async () => { + await utils.initializeWithContext('content'); + utils.setRespondWithTimestamp(true); + + const handler = jest.fn(); + app.registerHostToAppPerformanceMetricsHandler(handler); + + // Call an sdk function such as getcontext + app.getContext(); + const getContextMessage = utils.findMessageByFunc('getContext'); + if (!getContextMessage) { + fail('Get context message was never created'); + } + await utils.respondToMessage(getContextMessage, {}); + expect(handler).toBeCalled(); + }); + + it('app.registerHostToAppPerformanceMetricsHandler registered function should not get called when api SDK call does not have timestamp', async () => { + await utils.initializeWithContext('content'); + + const handler = jest.fn(); + app.registerHostToAppPerformanceMetricsHandler(handler); + + // Call an sdk function such as getcontext + app.getContext(); + const getContextMessage = utils.findMessageByFunc('getContext'); + if (!getContextMessage) { + fail('Get context message was never created'); + } + await utils.respondToMessage(getContextMessage, {}); + expect(handler).not.toBeCalled(); + }); + + it('app.registerHostToAppPerformanceMetricsHandler registered function should not get called when api SDK call response has no info', async () => { + await utils.initializeWithContext('content'); + + const handler = jest.fn(); + app.registerHostToAppPerformanceMetricsHandler(handler); + + // Call an sdk function such as getcontext + app.getContext(); + await utils.respondToMessage({ uuid: new UUID(), func: 'weirdFunc' }, {}); + expect(handler).not.toBeCalled(); + }); + + it('app.registerHostToAppPerformanceMetricsHandler should replace previously registered handler', async () => { + await utils.initializeWithContext('content'); + utils.setRespondWithTimestamp(true); + + const handlerOne = jest.fn(); + app.registerHostToAppPerformanceMetricsHandler(handlerOne); + const handlerTwo = jest.fn(); + app.registerHostToAppPerformanceMetricsHandler(handlerTwo); + + // Call an sdk function such as getcontext + app.getContext(); + const getContextMessage = utils.findMessageByFunc('getContext'); + if (!getContextMessage) { + fail('Get context message was never created'); + } + await utils.respondToMessage(getContextMessage, {}); + expect(handlerTwo).toBeCalled(); + expect(handlerOne).not.toBeCalled(); + }); + }); + describe('Testing app.registerOnThemeChangeHandler function', () => { it('app.registerOnThemeChangeHandler should not allow calls before initialization', () => { // eslint-disable-next-line @typescript-eslint/no-empty-function @@ -946,6 +1015,7 @@ describe('Testing app capability', () => { utils = new Utils(); utils.mockWindow.parent = undefined; utils.messages = []; + utils.setRespondWithTimestamp(false); app._initialize(utils.mockWindow); GlobalVars.isFramelessWindow = false; }); @@ -1594,6 +1664,73 @@ describe('Testing app capability', () => { }); }); + describe('Testing hostToAppPerformanceMetricsHandler', () => { + it('app.registerHostToAppPerformanceMetricsHandler registered function should get called when api SDK call has timestamp', async () => { + await utils.initializeWithContext('content'); + utils.setRespondWithTimestamp(true); + + const handler = jest.fn(); + app.registerHostToAppPerformanceMetricsHandler(handler); + + // Call an sdk function such as getcontext + app.getContext(); + const getContextMessage = utils.findMessageByFunc('getContext'); + if (!getContextMessage) { + fail('Get context message was never created'); + } + await utils.respondToMessage(getContextMessage, {}); + expect(handler).toBeCalled(); + }); + + it('app.registerHostToAppPerformanceMetricsHandler registered function should not get called when api SDK call does not have timestamp', async () => { + await utils.initializeWithContext('content'); + + const handler = jest.fn(); + app.registerHostToAppPerformanceMetricsHandler(handler); + + // Call an sdk function such as getcontext + app.getContext(); + const getContextMessage = utils.findMessageByFunc('getContext'); + if (!getContextMessage) { + fail('Get context message was never created'); + } + await utils.respondToMessage(getContextMessage, {}); + expect(handler).not.toBeCalled(); + }); + + it('app.registerHostToAppPerformanceMetricsHandler registered function should not get called when api SDK call response has no info', async () => { + await utils.initializeWithContext('content'); + + const handler = jest.fn(); + app.registerHostToAppPerformanceMetricsHandler(handler); + + // Call an sdk function such as getcontext + app.getContext(); + await utils.respondToMessage({ uuid: new UUID(), func: 'weirdFunc' }, {}); + expect(handler).not.toBeCalled(); + }); + + it('app.registerHostToAppPerformanceMetricsHandler should replace previously registered handler', async () => { + await utils.initializeWithContext('content'); + utils.setRespondWithTimestamp(true); + + const handlerOne = jest.fn(); + app.registerHostToAppPerformanceMetricsHandler(handlerOne); + const handlerTwo = jest.fn(); + app.registerHostToAppPerformanceMetricsHandler(handlerTwo); + + // Call an sdk function such as getcontext + app.getContext(); + const getContextMessage = utils.findMessageByFunc('getContext'); + if (!getContextMessage) { + fail('Get context message was never created'); + } + await utils.respondToMessage(getContextMessage, {}); + expect(handlerTwo).toBeCalled(); + expect(handlerOne).not.toBeCalled(); + }); + }); + describe('Testing app.registerOnThemeChangeHandler function', () => { it('app.registerOnThemeChangeHandler should not allow calls before initialization', () => { // eslint-disable-next-line @typescript-eslint/no-empty-function diff --git a/packages/teams-js/test/utils.ts b/packages/teams-js/test/utils.ts index ce5eaec1c0..e24cd3bead 100644 --- a/packages/teams-js/test/utils.ts +++ b/packages/teams-js/test/utils.ts @@ -39,11 +39,14 @@ export class Utils { public parentWindow: Window; public topWindow: Window; + public respondWithTimestamp: boolean; + private onMessageSent: null | ((messageRequest: MessageRequest) => void) = null; public constructor() { this.messages = []; this.childMessages = []; + this.respondWithTimestamp = false; this.parentWindow = { postMessage: (serializedMessage: SerializedMessageRequest, targetOrigin: string): void => { @@ -148,6 +151,10 @@ export class Utils { public processMessage: null | ((ev: MessageEvent) => Promise); + public setRespondWithTimestamp(respondWithTimestamp: boolean): void { + this.respondWithTimestamp = respondWithTimestamp; + } + public initializeWithContext = async ( frameContext: string, hostClientType: string = HostClientType.web, @@ -263,9 +270,12 @@ export class Utils { public respondToMessageWithPorts = async ( message: MessageRequest | NestedAppAuthRequest, - args: unknown[] = [], + args: unknown[], ports: MessagePort[] = [], ): Promise => { + const timestamp = this.respondWithTimestamp + ? { monotonicTimestamp: performance.now() + performance.timeOrigin } + : {}; if (this.processMessage === null) { throw Error( `Cannot respond to message ${message.id} because processMessage function has not been set and is null`, @@ -276,6 +286,7 @@ export class Utils { id: message.id, uuidAsString: getMessageUUIDString(message), args: args, + ...timestamp, } as SerializedMessageResponse, ports, } as DOMMessageEvent; @@ -288,6 +299,7 @@ export class Utils { id: message.id, uuidAsString: getMessageUUIDString(message), args: args, + ...timestamp, } as SerializedMessageResponse, ports, } as unknown as MessageEvent);