From 98688566dc266667f1fabc731bdf04cc2576343f Mon Sep 17 00:00:00 2001 From: JuanSe Cardenas Rodriguez Date: Mon, 2 Sep 2024 16:57:24 -0500 Subject: [PATCH 01/14] Add timestamp for each message request. With this new timestamped messaged, the host can properly compare and evaluate how much time the request got delayed to an issue on a busy event loop. --- packages/teams-js/src/internal/communication.ts | 6 +++--- packages/teams-js/src/internal/messageObjects.ts | 1 + packages/teams-js/src/internal/utils.ts | 14 ++++++++++++++ 3 files changed, 18 insertions(+), 3 deletions(-) diff --git a/packages/teams-js/src/internal/communication.ts b/packages/teams-js/src/internal/communication.ts index 8949b99449..d6225a4fa6 100644 --- a/packages/teams-js/src/internal/communication.ts +++ b/packages/teams-js/src/internal/communication.ts @@ -31,7 +31,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'; @@ -1089,7 +1089,7 @@ function createMessageRequest( id: messageId, uuid: messageUuid, func: func, - timestamp: Date.now(), + timestamp: getCurrentTimestamp(), args: args || [], apiVersionTag: apiVersionTag, }; @@ -1114,7 +1114,7 @@ function createNestedAppAuthRequest(message: string): NestedAppAuthRequest { id: messageId, uuid: messageUuid, func: 'nestedAppAuth.execute', - timestamp: Date.now(), + timestamp: 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: [], diff --git a/packages/teams-js/src/internal/messageObjects.ts b/packages/teams-js/src/internal/messageObjects.ts index 84f5f10619..bef5a4107e 100644 --- a/packages/teams-js/src/internal/messageObjects.ts +++ b/packages/teams-js/src/internal/messageObjects.ts @@ -58,6 +58,7 @@ export interface MessageResponse { uuid?: MessageUUID; // eslint-disable-next-line @typescript-eslint/no-explicit-any args?: any[]; + timestamp?: number; isPartialResponse?: boolean; // If the message is partial, then there will be more future responses for the given message ID. } diff --git a/packages/teams-js/src/internal/utils.ts b/packages/teams-js/src/internal/utils.ts index 2eb373e4c1..202056f15d 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' in window && 'now' in window.performance; + +/** + * @internal + * Limited to Microsoft-internal use + * @returns current timestamp in milliseconds + */ +export function getCurrentTimestamp(): number { + return supportsPerformanceTimers ? window.performance.now() + window.performance.timeOrigin : new Date().getTime(); +} From ec134725ab68ab266e72e1a181550df114ea28c1 Mon Sep 17 00:00:00 2001 From: JuanSe Cardenas Rodriguez Date: Mon, 2 Sep 2024 17:00:50 -0500 Subject: [PATCH 02/14] Create handler for streaming performance metrics. This new handler will allow any application developer to register a function for analyzing or storing performance metrics related to latencies due to a message delay sending the response back from the host to the app. --- .../teams-test-app/src/components/AppAPIs.tsx | 11 ++ .../teams-js/src/internal/communication.ts | 24 ++- packages/teams-js/src/internal/handlers.ts | 24 ++- packages/teams-js/src/internal/interfaces.ts | 12 ++ .../teams-js/src/internal/messageObjects.ts | 1 + packages/teams-js/src/internal/utils.ts | 4 +- packages/teams-js/src/public/app/app.ts | 25 +++- packages/teams-js/src/public/index.ts | 1 + packages/teams-js/src/public/interfaces.ts | 12 ++ .../test/internal/communication.spec.ts | 3 +- packages/teams-js/test/public/app.spec.ts | 137 ++++++++++++++++++ packages/teams-js/test/utils.ts | 12 +- 12 files changed, 257 insertions(+), 9 deletions(-) diff --git a/apps/teams-test-app/src/components/AppAPIs.tsx b/apps/teams-test-app/src/components/AppAPIs.tsx index 06f9e1cc5f..b57a4412bd 100644 --- a/apps/teams-test-app/src/components/AppAPIs.tsx +++ b/apps/teams-test-app/src/components/AppAPIs.tsx @@ -64,6 +64,16 @@ 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) => { + app.registerHostToAppPerformanceMetricsHandler((v) => setResult(JSON.stringify(v))); + return ''; + }, + }); + const RegisterOnThemeChangeHandler = (): ReactElement => ApiWithoutInput({ name: 'registerOnThemeChangeHandler', @@ -128,6 +138,7 @@ const AppAPIs = (): ReactElement => ( + diff --git a/packages/teams-js/src/internal/communication.ts b/packages/teams-js/src/internal/communication.ts index d6225a4fa6..4c2fd10257 100644 --- a/packages/teams-js/src/internal/communication.ts +++ b/packages/teams-js/src/internal/communication.ts @@ -9,8 +9,8 @@ import { latestRuntimeApiVersion } from '../public/runtime'; import { ISerializable, isSerializable } from '../public/serializable.interface'; import { version } from '../public/version'; import { GlobalVars } from './globalVars'; -import { callHandler } from './handlers'; -import { DOMMessageEvent, ExtendedWindow } from './interfaces'; +import { callHandler, handleHostToAppPerformanceMetrics } from './handlers'; +import { CallbackInformation, DOMMessageEvent, ExtendedWindow } from './interfaces'; import { deserializeMessageRequest, deserializeMessageResponse, @@ -61,6 +61,7 @@ class CommunicationPrivate { public static topMessageQueue: MessageRequest[] = []; public static nextMessageId = 0; public static callbacks: Map = new Map(); + public static callbackInformation: Map = new Map(); public static promiseCallbacks: Map void> = new Map(); public static portCallbacks: Map void> = new Map(); public static messageListener: Function; @@ -160,6 +161,7 @@ export function uninitializeCommunication(): void { CommunicationPrivate.promiseCallbacks.clear(); CommunicationPrivate.portCallbacks.clear(); CommunicationPrivate.legacyMessageIdsToUuidMap = {}; + CommunicationPrivate.callbackInformation.clear(); } /** @@ -518,9 +520,12 @@ function sendMessageToParentHelper( args: any[] | undefined, ): MessageRequestWithRequiredProperties { const logger = sendMessageToParentHelperLogger; - const targetWindow = Communication.parentWindow; const request = createMessageRequest(apiVersionTag, actionName, args); + CommunicationPrivate.callbackInformation.set(request.uuid, { + name: actionName, + calledAt: request.timestamp, + }); logger('Message %s information: %o', getMessageIdsAsLogString(request), { actionName, args }); @@ -807,6 +812,19 @@ function handleIncomingMessageFromParent(evt: DOMMessageEvent): void { if (callbackId) { const callback = CommunicationPrivate.callbacks.get(callbackId); logger('Received a response from parent for message %s', callbackId.toString()); + + // Send performance metrics information of message delay + const callbackInformation = CommunicationPrivate.callbackInformation.get(callbackId); + if (callbackInformation && message.timestamp) { + handleHostToAppPerformanceMetrics({ + actionName: callbackInformation.name, + messageDelay: getCurrentTimestamp() - message.timestamp, + messageWasCreatedAt: callbackInformation.calledAt, + }); + } else { + logger('Unable to send performance metrics for callback %i with arguments %o', callbackId, message.args); + } + if (callback) { logger( 'Invoking the registered callback for message %s with arguments %o', diff --git a/packages/teams-js/src/internal/handlers.ts b/packages/teams-js/src/internal/handlers.ts index e8e1d8935b..70565ecd76 100644 --- a/packages/teams-js/src/internal/handlers.ts +++ b/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 { pages } from '../public/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) = 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/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 bef5a4107e..7150a3f4f5 100644 --- a/packages/teams-js/src/internal/messageObjects.ts +++ b/packages/teams-js/src/internal/messageObjects.ts @@ -46,6 +46,7 @@ export interface SerializedMessageResponse { uuidAsString?: string; // eslint-disable-next-line @typescript-eslint/no-explicit-any args?: any[]; + timestamp?: number; isPartialResponse?: boolean; // If the message is partial, then there will be more future responses for the given message ID. } diff --git a/packages/teams-js/src/internal/utils.ts b/packages/teams-js/src/internal/utils.ts index 202056f15d..49eb3ba035 100644 --- a/packages/teams-js/src/internal/utils.ts +++ b/packages/teams-js/src/internal/utils.ts @@ -508,7 +508,7 @@ export function validateUuid(id: string | undefined | null): void { /** * Cache if performance timers are available to avoid redoing this on each function call. */ -const supportsPerformanceTimers = 'performance' in window && 'now' in window.performance; +const supportsPerformanceTimers = !!performance && 'now' in performance; /** * @internal @@ -516,5 +516,5 @@ const supportsPerformanceTimers = 'performance' in window && 'now' in window.per * @returns current timestamp in milliseconds */ export function getCurrentTimestamp(): number { - return supportsPerformanceTimers ? window.performance.now() + window.performance.timeOrigin : new Date().getTime(); + return supportsPerformanceTimers ? performance.now() + performance.timeOrigin : new Date().getTime(); } 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 274bef0c3c..d990e76d3f 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..b80b33042a 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 the message was originally created at */ + messageWasCreatedAt: number; +} diff --git a/packages/teams-js/test/internal/communication.spec.ts b/packages/teams-js/test/internal/communication.spec.ts index ae33db1e73..fc74c59f9a 100644 --- a/packages/teams-js/test/internal/communication.spec.ts +++ b/packages/teams-js/test/internal/communication.spec.ts @@ -12,6 +12,7 @@ import { Utils } from '../utils'; jest.mock('../../src/internal/handlers', () => ({ callHandler: jest.fn(), + handleHostToAppPerformanceMetrics: jest.fn(), })); const testApiVersion = getApiVersionTag(ApiVersionNumber.V_1, 'mockedApiName' as ApiName); @@ -276,7 +277,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..e7dd4a96fd 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,10 @@ export class Utils { public respondToMessageWithPorts = async ( message: MessageRequest | NestedAppAuthRequest, - args: unknown[] = [], + args: unknown[], ports: MessagePort[] = [], ): Promise => { + const timestamp = this.respondWithTimestamp ? { timestamp: 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 +284,7 @@ export class Utils { id: message.id, uuidAsString: getMessageUUIDString(message), args: args, + ...timestamp, } as SerializedMessageResponse, ports, } as DOMMessageEvent; @@ -288,6 +297,7 @@ export class Utils { id: message.id, uuidAsString: getMessageUUIDString(message), args: args, + ...timestamp, } as SerializedMessageResponse, ports, } as unknown as MessageEvent); From 3a342907074f086cfbd7472cee6a5ac0f6eecce9 Mon Sep 17 00:00:00 2001 From: JuanSe Cardenas Rodriguez Date: Mon, 2 Sep 2024 17:39:54 -0500 Subject: [PATCH 03/14] Add changefile. --- ...soft-teams-js-42d39be6-18d9-4619-ab76-a1360275873c.json | 7 +++++++ 1 file changed, 7 insertions(+) create mode 100644 change/@microsoft-teams-js-42d39be6-18d9-4619-ab76-a1360275873c.json 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" +} From 21cd299fa30fc7248cc457ff150b3da55e42a2e7 Mon Sep 17 00:00:00 2001 From: JuanSe Cardenas Rodriguez Date: Wed, 11 Sep 2024 13:01:16 -0500 Subject: [PATCH 04/14] Add new field with monotonic timestamp. The old field will be preserved with backwards compatibility with previous versions that still consume this field. --- packages/teams-js/src/internal/communication.ts | 6 ++++-- packages/teams-js/src/internal/messageObjects.ts | 4 ++++ 2 files changed, 8 insertions(+), 2 deletions(-) diff --git a/packages/teams-js/src/internal/communication.ts b/packages/teams-js/src/internal/communication.ts index 4c2fd10257..3f55f9a0dd 100644 --- a/packages/teams-js/src/internal/communication.ts +++ b/packages/teams-js/src/internal/communication.ts @@ -1107,7 +1107,8 @@ function createMessageRequest( id: messageId, uuid: messageUuid, func: func, - timestamp: getCurrentTimestamp(), + timestamp: Date.now(), + monotonicTimestamp: getCurrentTimestamp(), args: args || [], apiVersionTag: apiVersionTag, }; @@ -1132,7 +1133,8 @@ function createNestedAppAuthRequest(message: string): NestedAppAuthRequest { id: messageId, uuid: messageUuid, func: 'nestedAppAuth.execute', - timestamp: getCurrentTimestamp(), + 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: [], diff --git a/packages/teams-js/src/internal/messageObjects.ts b/packages/teams-js/src/internal/messageObjects.ts index 7150a3f4f5..81958ab62a 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; @@ -77,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 => { From 6894bedd86185e2fcc2c311c158627c74cf92bd1 Mon Sep 17 00:00:00 2001 From: JuanSe Cardenas Rodriguez Date: Wed, 11 Sep 2024 13:02:17 -0500 Subject: [PATCH 05/14] Organize telemetry in the correct module. All the telemetry related code is added to the telemetry module to avoid cluttering the communication layer with nuances about telemetry. --- .../teams-js/src/internal/communication.ts | 25 ++------ packages/teams-js/src/internal/telemetry.ts | 59 +++++++++++++++++++ 2 files changed, 65 insertions(+), 19 deletions(-) diff --git a/packages/teams-js/src/internal/communication.ts b/packages/teams-js/src/internal/communication.ts index 3f55f9a0dd..71057284c8 100644 --- a/packages/teams-js/src/internal/communication.ts +++ b/packages/teams-js/src/internal/communication.ts @@ -2,15 +2,15 @@ /* eslint-disable @typescript-eslint/no-explicit-any */ /* eslint-disable strict-null-checks/all */ -import { ApiName, ApiVersionNumber, getApiVersionTag } from '../internal/telemetry'; +import { ApiName, ApiVersionNumber, getApiVersionTag, HostToAppMessageDelayTelemetry } from '../internal/telemetry'; import { FrameContexts } from '../public/constants'; import { ErrorCode, isSdkError, SdkError } from '../public/interfaces'; import { latestRuntimeApiVersion } from '../public/runtime'; import { ISerializable, isSerializable } from '../public/serializable.interface'; import { version } from '../public/version'; import { GlobalVars } from './globalVars'; -import { callHandler, handleHostToAppPerformanceMetrics } from './handlers'; -import { CallbackInformation, DOMMessageEvent, ExtendedWindow } from './interfaces'; +import { callHandler } from './handlers'; +import { DOMMessageEvent, ExtendedWindow } from './interfaces'; import { deserializeMessageRequest, deserializeMessageResponse, @@ -61,7 +61,6 @@ class CommunicationPrivate { public static topMessageQueue: MessageRequest[] = []; public static nextMessageId = 0; public static callbacks: Map = new Map(); - public static callbackInformation: Map = new Map(); public static promiseCallbacks: Map void> = new Map(); public static portCallbacks: Map void> = new Map(); public static messageListener: Function; @@ -161,7 +160,7 @@ export function uninitializeCommunication(): void { CommunicationPrivate.promiseCallbacks.clear(); CommunicationPrivate.portCallbacks.clear(); CommunicationPrivate.legacyMessageIdsToUuidMap = {}; - CommunicationPrivate.callbackInformation.clear(); + HostToAppMessageDelayTelemetry.clearMessages(); } /** @@ -522,7 +521,7 @@ function sendMessageToParentHelper( const logger = sendMessageToParentHelperLogger; const targetWindow = Communication.parentWindow; const request = createMessageRequest(apiVersionTag, actionName, args); - CommunicationPrivate.callbackInformation.set(request.uuid, { + HostToAppMessageDelayTelemetry.storeCallbackInformation(request.uuid, { name: actionName, calledAt: request.timestamp, }); @@ -812,19 +811,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()); - - // Send performance metrics information of message delay - const callbackInformation = CommunicationPrivate.callbackInformation.get(callbackId); - if (callbackInformation && message.timestamp) { - handleHostToAppPerformanceMetrics({ - actionName: callbackInformation.name, - messageDelay: getCurrentTimestamp() - message.timestamp, - messageWasCreatedAt: callbackInformation.calledAt, - }); - } else { - logger('Unable to send performance metrics for callback %i with arguments %o', callbackId, message.args); - } - + HostToAppMessageDelayTelemetry.telemetryHostToAppPerformanceMetrics(callbackId, message, logger); if (callback) { logger( 'Invoking the registered callback for message %s with arguments %o', diff --git a/packages/teams-js/src/internal/telemetry.ts b/packages/teams-js/src/internal/telemetry.ts index c7960d46cd..be610f1b48 100644 --- a/packages/teams-js/src/internal/telemetry.ts +++ b/packages/teams-js/src/internal/telemetry.ts @@ -1,5 +1,10 @@ import { debug as registerLogger, Debugger } from 'debug'; +import { handleHostToAppPerformanceMetrics } from './handlers'; +import { CallbackInformation } from './interfaces'; +import { MessageResponse } from './messageObjects'; +import { getCurrentTimestamp } from './utils'; + import { UUID } from './uuidObject'; // Each teamsjs instance gets a unique identifier that will be prepended to every log statement @@ -62,6 +67,60 @@ export const enum ApiVersionNumber { V_3 = 'v3', } +/** + * @internal + * Limited to Microsoft-internal use + */ +export 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: UUID, 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 + * + * 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 A logger for logging any possible error. + */ + public static telemetryHostToAppPerformanceMetrics( + callbackID: UUID, + message: MessageResponse, + logger: debug.Debugger, + ): void { + const callbackInformation = HostToAppMessageDelayTelemetry.callbackInformation.get(callbackID); + if (callbackInformation && message.timestamp) { + handleHostToAppPerformanceMetrics({ + actionName: callbackInformation.name, + messageDelay: getCurrentTimestamp() - message.timestamp, + messageWasCreatedAt: callbackInformation.calledAt, + }); + } else { + logger('Unable to send performance metrics for callback %i with arguments %o', callbackID, message.args); + } + } +} + export const enum ApiName { App_GetContext = 'app.getContext', App_Initialize = 'app.initialize', From c961f4d0a46130a33f31bc74201a6e0e95b86506 Mon Sep 17 00:00:00 2001 From: JuanSe Cardenas Rodriguez Date: Thu, 12 Sep 2024 14:55:10 -0500 Subject: [PATCH 06/14] Delete messages after being handled. --- packages/teams-js/src/internal/telemetry.ts | 9 +++++++++ 1 file changed, 9 insertions(+) diff --git a/packages/teams-js/src/internal/telemetry.ts b/packages/teams-js/src/internal/telemetry.ts index be610f1b48..d5343992ba 100644 --- a/packages/teams-js/src/internal/telemetry.ts +++ b/packages/teams-js/src/internal/telemetry.ts @@ -94,6 +94,14 @@ export class HostToAppMessageDelayTelemetry { 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 @@ -115,6 +123,7 @@ export class HostToAppMessageDelayTelemetry { messageDelay: getCurrentTimestamp() - message.timestamp, messageWasCreatedAt: callbackInformation.calledAt, }); + HostToAppMessageDelayTelemetry.deleteMessageInformation(callbackID); } else { logger('Unable to send performance metrics for callback %i with arguments %o', callbackID, message.args); } From a2c905cd61844cee4f8330dbea2ce8a6686d145c Mon Sep 17 00:00:00 2001 From: JuanSe Cardenas Rodriguez Date: Fri, 13 Sep 2024 11:34:42 -0500 Subject: [PATCH 07/14] Avoid circular import issue. --- .../teams-js/src/internal/communication.ts | 5 +- .../src/internal/hostToAppTelemetry.ts | 66 ++++++++++++++++++ packages/teams-js/src/internal/telemetry.ts | 68 ------------------- .../test/internal/communication.spec.ts | 1 - 4 files changed, 69 insertions(+), 71 deletions(-) create mode 100644 packages/teams-js/src/internal/hostToAppTelemetry.ts diff --git a/packages/teams-js/src/internal/communication.ts b/packages/teams-js/src/internal/communication.ts index 71057284c8..c86a812e36 100644 --- a/packages/teams-js/src/internal/communication.ts +++ b/packages/teams-js/src/internal/communication.ts @@ -2,7 +2,7 @@ /* eslint-disable @typescript-eslint/no-explicit-any */ /* eslint-disable strict-null-checks/all */ -import { ApiName, ApiVersionNumber, getApiVersionTag, HostToAppMessageDelayTelemetry } from '../internal/telemetry'; +import { ApiName, ApiVersionNumber, getApiVersionTag } from '../internal/telemetry'; import { FrameContexts } from '../public/constants'; import { ErrorCode, isSdkError, SdkError } from '../public/interfaces'; import { latestRuntimeApiVersion } from '../public/runtime'; @@ -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, @@ -811,7 +812,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.telemetryHostToAppPerformanceMetrics(callbackId, message, logger); + HostToAppMessageDelayTelemetry.handlePerformanceMetrics(callbackId, message, logger); if (callback) { logger( 'Invoking the registered callback for message %s with arguments %o', diff --git a/packages/teams-js/src/internal/hostToAppTelemetry.ts b/packages/teams-js/src/internal/hostToAppTelemetry.ts new file mode 100644 index 0000000000..f04e408b3e --- /dev/null +++ b/packages/teams-js/src/internal/hostToAppTelemetry.ts @@ -0,0 +1,66 @@ +import { Debugger } from 'debug'; + +import { handleHostToAppPerformanceMetrics } from './handlers'; +import { CallbackInformation } from './interfaces'; +import { MessageResponse } from './messageObjects'; +import { getCurrentTimestamp } from './utils'; +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. + * @param callbackId The message id for the request. + * @param message The response from the host. + * @param logger The logger in case an error occurs. + */ + public static handlePerformanceMetrics(callbackID: MessageUUID, message: MessageResponse, logger: Debugger): void { + const callbackInformation = HostToAppMessageDelayTelemetry.callbackInformation.get(callbackID); + if (callbackInformation && message.timestamp) { + handleHostToAppPerformanceMetrics({ + actionName: callbackInformation.name, + messageDelay: getCurrentTimestamp() - message.timestamp, + messageWasCreatedAt: callbackInformation.calledAt, + }); + HostToAppMessageDelayTelemetry.deleteMessageInformation(callbackID); + } else { + logger('Unable to send performance metrics for callback %i with arguments %o', callbackID, message.args); + } + } +} diff --git a/packages/teams-js/src/internal/telemetry.ts b/packages/teams-js/src/internal/telemetry.ts index d5343992ba..c7960d46cd 100644 --- a/packages/teams-js/src/internal/telemetry.ts +++ b/packages/teams-js/src/internal/telemetry.ts @@ -1,10 +1,5 @@ import { debug as registerLogger, Debugger } from 'debug'; -import { handleHostToAppPerformanceMetrics } from './handlers'; -import { CallbackInformation } from './interfaces'; -import { MessageResponse } from './messageObjects'; -import { getCurrentTimestamp } from './utils'; - import { UUID } from './uuidObject'; // Each teamsjs instance gets a unique identifier that will be prepended to every log statement @@ -67,69 +62,6 @@ export const enum ApiVersionNumber { V_3 = 'v3', } -/** - * @internal - * Limited to Microsoft-internal use - */ -export 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: UUID, 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. - * @param callbackId The message id for the request. - * @param message The response from the host. - * @param logger A logger for logging any possible error. - */ - public static telemetryHostToAppPerformanceMetrics( - callbackID: UUID, - message: MessageResponse, - logger: debug.Debugger, - ): void { - const callbackInformation = HostToAppMessageDelayTelemetry.callbackInformation.get(callbackID); - if (callbackInformation && message.timestamp) { - handleHostToAppPerformanceMetrics({ - actionName: callbackInformation.name, - messageDelay: getCurrentTimestamp() - message.timestamp, - messageWasCreatedAt: callbackInformation.calledAt, - }); - HostToAppMessageDelayTelemetry.deleteMessageInformation(callbackID); - } else { - logger('Unable to send performance metrics for callback %i with arguments %o', callbackID, message.args); - } - } -} - export const enum ApiName { App_GetContext = 'app.getContext', App_Initialize = 'app.initialize', diff --git a/packages/teams-js/test/internal/communication.spec.ts b/packages/teams-js/test/internal/communication.spec.ts index fc74c59f9a..c74de88fc7 100644 --- a/packages/teams-js/test/internal/communication.spec.ts +++ b/packages/teams-js/test/internal/communication.spec.ts @@ -12,7 +12,6 @@ import { Utils } from '../utils'; jest.mock('../../src/internal/handlers', () => ({ callHandler: jest.fn(), - handleHostToAppPerformanceMetrics: jest.fn(), })); const testApiVersion = getApiVersionTag(ApiVersionNumber.V_1, 'mockedApiName' as ApiName); From c643440beb5428d2bb70be88a09c7eb293ec6331 Mon Sep 17 00:00:00 2001 From: JuanSe Cardenas Rodriguez Date: Fri, 20 Sep 2024 17:17:21 -0500 Subject: [PATCH 08/14] Add performance metrics for one way API calls. --- .../teams-js/src/internal/communication.ts | 1 + .../src/internal/hostToAppTelemetry.ts | 38 ++++++++++++++----- 2 files changed, 30 insertions(+), 9 deletions(-) diff --git a/packages/teams-js/src/internal/communication.ts b/packages/teams-js/src/internal/communication.ts index c86a812e36..332b8c5a8f 100644 --- a/packages/teams-js/src/internal/communication.ts +++ b/packages/teams-js/src/internal/communication.ts @@ -864,6 +864,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); logger('Received a message from parent %s, action: "%s"', getMessageIdsAsLogString(message), message.func); callHandler(message.func, message.args); } else { diff --git a/packages/teams-js/src/internal/hostToAppTelemetry.ts b/packages/teams-js/src/internal/hostToAppTelemetry.ts index f04e408b3e..978bce453b 100644 --- a/packages/teams-js/src/internal/hostToAppTelemetry.ts +++ b/packages/teams-js/src/internal/hostToAppTelemetry.ts @@ -2,7 +2,7 @@ import { Debugger } from 'debug'; import { handleHostToAppPerformanceMetrics } from './handlers'; import { CallbackInformation } from './interfaces'; -import { MessageResponse } from './messageObjects'; +import { MessageRequest, MessageResponse } from './messageObjects'; import { getCurrentTimestamp } from './utils'; import { UUID as MessageUUID } from './uuidObject'; @@ -40,6 +40,26 @@ export default class HostToAppMessageDelayTelemetry { 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. + */ + public static handleOneWayPerformanceMetrics(message: MessageRequest, logger: Debugger): void { + const timestamp = message.monotonicTimestamp; + if (!timestamp) { + logger('Unable to send performance metrics for event %s', message.func); + return; + } + handleHostToAppPerformanceMetrics({ + actionName: message.func, + messageDelay: getCurrentTimestamp() - timestamp, + messageWasCreatedAt: timestamp, + }); + } /** * @internal @@ -52,15 +72,15 @@ export default class HostToAppMessageDelayTelemetry { */ public static handlePerformanceMetrics(callbackID: MessageUUID, message: MessageResponse, logger: Debugger): void { const callbackInformation = HostToAppMessageDelayTelemetry.callbackInformation.get(callbackID); - if (callbackInformation && message.timestamp) { - handleHostToAppPerformanceMetrics({ - actionName: callbackInformation.name, - messageDelay: getCurrentTimestamp() - message.timestamp, - messageWasCreatedAt: callbackInformation.calledAt, - }); - HostToAppMessageDelayTelemetry.deleteMessageInformation(callbackID); - } else { + if (!callbackInformation || !message.timestamp) { logger('Unable to send performance metrics for callback %i with arguments %o', callbackID, message.args); + return; } + handleHostToAppPerformanceMetrics({ + actionName: callbackInformation.name, + messageDelay: getCurrentTimestamp() - message.timestamp, + messageWasCreatedAt: callbackInformation.calledAt, + }); + HostToAppMessageDelayTelemetry.deleteMessageInformation(callbackID); } } From 58bd878f77006339420588399124f1b4d1679326 Mon Sep 17 00:00:00 2001 From: JuanSe Cardenas Rodriguez Date: Mon, 23 Sep 2024 16:02:50 -0500 Subject: [PATCH 09/14] Fix callback id logging in hostToApp telemetry. --- packages/teams-js/src/internal/hostToAppTelemetry.ts | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/packages/teams-js/src/internal/hostToAppTelemetry.ts b/packages/teams-js/src/internal/hostToAppTelemetry.ts index 978bce453b..a88e28b2fb 100644 --- a/packages/teams-js/src/internal/hostToAppTelemetry.ts +++ b/packages/teams-js/src/internal/hostToAppTelemetry.ts @@ -73,7 +73,11 @@ export default class HostToAppMessageDelayTelemetry { public static handlePerformanceMetrics(callbackID: MessageUUID, message: MessageResponse, logger: Debugger): void { const callbackInformation = HostToAppMessageDelayTelemetry.callbackInformation.get(callbackID); if (!callbackInformation || !message.timestamp) { - logger('Unable to send performance metrics for callback %i with arguments %o', callbackID, message.args); + logger( + 'Unable to send performance metrics for callback %s with arguments %o', + callbackID.toString(), + message.args, + ); return; } handleHostToAppPerformanceMetrics({ From 0ced08a3694a13b9ec1eea2780cdd736459e806d Mon Sep 17 00:00:00 2001 From: JuanSe Cardenas Rodriguez Date: Wed, 9 Oct 2024 14:29:54 -0500 Subject: [PATCH 10/14] Use standarized name for monotonic timestamp. --- packages/teams-js/src/internal/hostToAppTelemetry.ts | 4 ++-- packages/teams-js/src/internal/messageObjects.ts | 4 ++-- packages/teams-js/test/utils.ts | 4 +++- 3 files changed, 7 insertions(+), 5 deletions(-) diff --git a/packages/teams-js/src/internal/hostToAppTelemetry.ts b/packages/teams-js/src/internal/hostToAppTelemetry.ts index a88e28b2fb..92259a472a 100644 --- a/packages/teams-js/src/internal/hostToAppTelemetry.ts +++ b/packages/teams-js/src/internal/hostToAppTelemetry.ts @@ -72,7 +72,7 @@ export default class HostToAppMessageDelayTelemetry { */ public static handlePerformanceMetrics(callbackID: MessageUUID, message: MessageResponse, logger: Debugger): void { const callbackInformation = HostToAppMessageDelayTelemetry.callbackInformation.get(callbackID); - if (!callbackInformation || !message.timestamp) { + if (!callbackInformation || !message.monotonicTimestamp) { logger( 'Unable to send performance metrics for callback %s with arguments %o', callbackID.toString(), @@ -82,7 +82,7 @@ export default class HostToAppMessageDelayTelemetry { } handleHostToAppPerformanceMetrics({ actionName: callbackInformation.name, - messageDelay: getCurrentTimestamp() - message.timestamp, + messageDelay: getCurrentTimestamp() - message.monotonicTimestamp, messageWasCreatedAt: callbackInformation.calledAt, }); HostToAppMessageDelayTelemetry.deleteMessageInformation(callbackID); diff --git a/packages/teams-js/src/internal/messageObjects.ts b/packages/teams-js/src/internal/messageObjects.ts index 81958ab62a..0c856f4a5a 100644 --- a/packages/teams-js/src/internal/messageObjects.ts +++ b/packages/teams-js/src/internal/messageObjects.ts @@ -48,7 +48,7 @@ export interface SerializedMessageResponse { uuidAsString?: string; // eslint-disable-next-line @typescript-eslint/no-explicit-any args?: any[]; - timestamp?: number; + monotonicTimestamp?: number; isPartialResponse?: boolean; // If the message is partial, then there will be more future responses for the given message ID. } @@ -61,7 +61,7 @@ export interface MessageResponse { uuid?: MessageUUID; // eslint-disable-next-line @typescript-eslint/no-explicit-any args?: any[]; - timestamp?: number; + monotonicTimestamp?: number; isPartialResponse?: boolean; // If the message is partial, then there will be more future responses for the given message ID. } diff --git a/packages/teams-js/test/utils.ts b/packages/teams-js/test/utils.ts index e7dd4a96fd..e24cd3bead 100644 --- a/packages/teams-js/test/utils.ts +++ b/packages/teams-js/test/utils.ts @@ -273,7 +273,9 @@ export class Utils { args: unknown[], ports: MessagePort[] = [], ): Promise => { - const timestamp = this.respondWithTimestamp ? { timestamp: performance.now() + performance.timeOrigin } : {}; + 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`, From 95935f13fe70f9d29aada14e4dea16cf1a4f2445 Mon Sep 17 00:00:00 2001 From: JuanSe Cardenas Rodriguez Date: Tue, 22 Oct 2024 20:55:00 -0500 Subject: [PATCH 11/14] Log handled metrics. --- apps/teams-test-app/src/components/AppAPIs.tsx | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) diff --git a/apps/teams-test-app/src/components/AppAPIs.tsx b/apps/teams-test-app/src/components/AppAPIs.tsx index b57a4412bd..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'; @@ -69,8 +70,12 @@ const RegisterHostToAppPerformanceMetricsHandler = (): ReactElement => name: 'registerHostToAppPerformanceMetricsHandler', title: 'Register Host to App performance metrics handler', onClick: async (setResult) => { - app.registerHostToAppPerformanceMetricsHandler((v) => setResult(JSON.stringify(v))); - return ''; + const handler = (v: HostToAppPerformanceMetrics): void => { + console.log(v); + setResult(JSON.stringify(v)); + }; + app.registerHostToAppPerformanceMetricsHandler(handler); + return 'Registered callback!'; }, }); From 8f30c515fb63d9b4719decb4b66bc249230fe62f Mon Sep 17 00:00:00 2001 From: JuanSe Cardenas Rodriguez Date: Wed, 23 Oct 2024 14:53:26 -0500 Subject: [PATCH 12/14] Use common ending time in telemetry. --- packages/teams-js/src/internal/communication.ts | 5 +++-- .../teams-js/src/internal/hostToAppTelemetry.ts | 16 +++++++++++----- 2 files changed, 14 insertions(+), 7 deletions(-) diff --git a/packages/teams-js/src/internal/communication.ts b/packages/teams-js/src/internal/communication.ts index 332b8c5a8f..29e6134e47 100644 --- a/packages/teams-js/src/internal/communication.ts +++ b/packages/teams-js/src/internal/communication.ts @@ -803,6 +803,7 @@ function removeMessageHandlers(message: MessageResponse, map: Map Date: Wed, 23 Oct 2024 14:54:23 -0500 Subject: [PATCH 13/14] Rewrite field for clarity. --- packages/teams-js/src/internal/hostToAppTelemetry.ts | 4 ++-- packages/teams-js/src/public/interfaces.ts | 4 ++-- 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/packages/teams-js/src/internal/hostToAppTelemetry.ts b/packages/teams-js/src/internal/hostToAppTelemetry.ts index 13d402b50d..24fb90761e 100644 --- a/packages/teams-js/src/internal/hostToAppTelemetry.ts +++ b/packages/teams-js/src/internal/hostToAppTelemetry.ts @@ -57,7 +57,7 @@ export default class HostToAppMessageDelayTelemetry { handleHostToAppPerformanceMetrics({ actionName: message.func, messageDelay: endTime - timestamp, - messageWasCreatedAt: timestamp, + requestStartedAt: timestamp, }); } @@ -89,7 +89,7 @@ export default class HostToAppMessageDelayTelemetry { handleHostToAppPerformanceMetrics({ actionName: callbackInformation.name, messageDelay: endTime - message.monotonicTimestamp, - messageWasCreatedAt: callbackInformation.calledAt, + requestStartedAt: callbackInformation.calledAt, }); HostToAppMessageDelayTelemetry.deleteMessageInformation(callbackID); } diff --git a/packages/teams-js/src/public/interfaces.ts b/packages/teams-js/src/public/interfaces.ts index b80b33042a..ab607a1864 100644 --- a/packages/teams-js/src/public/interfaces.ts +++ b/packages/teams-js/src/public/interfaces.ts @@ -1293,6 +1293,6 @@ export interface HostToAppPerformanceMetrics { actionName: string; /** The delay the message took traveling from host to app */ messageDelay: number; - /** The time the message was originally created at */ - messageWasCreatedAt: number; + /** The time when the request was dispatched */ + requestStartedAt: number; } From 26698e7ae57f4e526fa7dd832c2441a3de9b8474 Mon Sep 17 00:00:00 2001 From: JuanSe Cardenas Rodriguez Date: Wed, 30 Oct 2024 18:33:14 -0500 Subject: [PATCH 14/14] Do not mix up date and monotonic timers. --- packages/teams-js/src/internal/hostToAppTelemetry.ts | 8 ++++---- packages/teams-js/src/internal/messageObjects.ts | 1 - packages/teams-js/src/internal/utils.ts | 4 ++-- 3 files changed, 6 insertions(+), 7 deletions(-) diff --git a/packages/teams-js/src/internal/hostToAppTelemetry.ts b/packages/teams-js/src/internal/hostToAppTelemetry.ts index 24fb90761e..80d58d2d40 100644 --- a/packages/teams-js/src/internal/hostToAppTelemetry.ts +++ b/packages/teams-js/src/internal/hostToAppTelemetry.ts @@ -48,9 +48,9 @@ export default class HostToAppMessageDelayTelemetry { * @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 { + public static handleOneWayPerformanceMetrics(message: MessageRequest, logger: Debugger, endTime?: number): void { const timestamp = message.monotonicTimestamp; - if (!timestamp) { + if (!timestamp || !endTime) { logger('Unable to send performance metrics for event %s', message.func); return; } @@ -75,10 +75,10 @@ export default class HostToAppMessageDelayTelemetry { callbackID: MessageUUID, message: MessageResponse, logger: Debugger, - endTime: number, + endTime?: number, ): void { const callbackInformation = HostToAppMessageDelayTelemetry.callbackInformation.get(callbackID); - if (!callbackInformation || !message.monotonicTimestamp) { + if (!callbackInformation || !message.monotonicTimestamp || !endTime) { logger( 'Unable to send performance metrics for callback %s with arguments %o', callbackID.toString(), diff --git a/packages/teams-js/src/internal/messageObjects.ts b/packages/teams-js/src/internal/messageObjects.ts index 0c856f4a5a..b49c8213f1 100644 --- a/packages/teams-js/src/internal/messageObjects.ts +++ b/packages/teams-js/src/internal/messageObjects.ts @@ -81,7 +81,6 @@ export interface MessageRequestWithRequiredProperties extends MessageRequest { uuid: MessageUUID; /** Deprecated field, is still here for backwards compatibility */ timestamp: number; - monotonicTimestamp: number; } export const serializeMessageRequest = (message: MessageRequest): SerializedMessageRequest => { diff --git a/packages/teams-js/src/internal/utils.ts b/packages/teams-js/src/internal/utils.ts index d49ea58a5e..db832f91bd 100644 --- a/packages/teams-js/src/internal/utils.ts +++ b/packages/teams-js/src/internal/utils.ts @@ -515,6 +515,6 @@ const supportsPerformanceTimers = !!performance && 'now' in performance; * Limited to Microsoft-internal use * @returns current timestamp in milliseconds */ -export function getCurrentTimestamp(): number { - return supportsPerformanceTimers ? performance.now() + performance.timeOrigin : new Date().getTime(); +export function getCurrentTimestamp(): number | undefined { + return supportsPerformanceTimers ? performance.now() + performance.timeOrigin : undefined; }