diff --git a/change/@microsoft-teams-js-4885f2ff-afee-4756-9192-4731c184d1ba.json b/change/@microsoft-teams-js-4885f2ff-afee-4756-9192-4731c184d1ba.json new file mode 100644 index 0000000000..fd43407a10 --- /dev/null +++ b/change/@microsoft-teams-js-4885f2ff-afee-4756-9192-4731c184d1ba.json @@ -0,0 +1,7 @@ +{ + "type": "patch", + "comment": "Started collection of `video` performance data", + "packageName": "@microsoft/teams-js", + "email": "wenghe@microsoft.com", + "dependentChangeType": "patch" +} diff --git a/packages/teams-js/src/internal/videoFrameTick.ts b/packages/teams-js/src/internal/videoFrameTick.ts new file mode 100644 index 0000000000..c33a9f11ef --- /dev/null +++ b/packages/teams-js/src/internal/videoFrameTick.ts @@ -0,0 +1,56 @@ +import { generateGUID } from './utils'; + +export class VideoFrameTick { + private static readonly setTimeoutCallbacks: { + [key: string]: { + callback: () => void; + startedAtInMs: number; + timeoutInMs: number; + }; + } = {}; + + public static setTimeout(callback: () => void, timeoutInMs: number): string { + const startedAtInMs = performance.now(); + const id = generateGUID(); + VideoFrameTick.setTimeoutCallbacks[id] = { + callback, + timeoutInMs, + startedAtInMs, + }; + return id; + } + + public static clearTimeout(id: string): void { + delete VideoFrameTick.setTimeoutCallbacks[id]; + } + + public static setInterval(callback: () => void, intervalInMs: number): void { + VideoFrameTick.setTimeout(function next() { + callback(); + VideoFrameTick.setTimeout(next, intervalInMs); + }, intervalInMs); + } + + /** + * Call this function whenever a frame comes in, it will check if any timeout is due and call the callback + */ + public static tick(): void { + const now = performance.now(); + const timeoutIds = []; + // find all the timeouts that are due, + // not to invoke them in the loop to avoid modifying the collection while iterating + for (const key in VideoFrameTick.setTimeoutCallbacks) { + const callback = VideoFrameTick.setTimeoutCallbacks[key]; + const start = callback.startedAtInMs; + if (now - start >= callback.timeoutInMs) { + timeoutIds.push(key); + } + } + // invoke the callbacks + for (const id of timeoutIds) { + const callback = VideoFrameTick.setTimeoutCallbacks[id]; + callback.callback(); + delete VideoFrameTick.setTimeoutCallbacks[id]; + } + } +} diff --git a/packages/teams-js/src/internal/videoPerformanceMonitor.ts b/packages/teams-js/src/internal/videoPerformanceMonitor.ts new file mode 100644 index 0000000000..9e0bee7ad7 --- /dev/null +++ b/packages/teams-js/src/internal/videoPerformanceMonitor.ts @@ -0,0 +1,154 @@ +import { VideoFrameTick } from './videoFrameTick'; +import { VideoPerformanceStatistics } from './videoPerformanceStatistics'; + +/** + * This class is used to monitor the performance of video processing, and report performance events. + */ +export class VideoPerformanceMonitor { + private static readonly distributionBinSize = 1000; + private static readonly calculateFPSInterval = 1000; + + private isFirstFrameProcessed = false; + + // The effect that the user last selected: + private applyingEffect: { + effectId: string; + effectParam?: string; + }; + + // The effect that is currently applied to the video: + private appliedEffect: { + effectId: string; + effectParam?: string; + }; + + private frameProcessTimeLimit = 100; + private gettingTextureStreamStartedAt: number; + private currentStreamId: string; + private frameProcessingStartedAt = 0; + private frameProcessingTimeCost = 0; + private processedFrameCount = 0; + + private performanceStatistics: VideoPerformanceStatistics; + + public constructor(private reportPerformanceEvent: (actionName: string, args: unknown[]) => void) { + this.performanceStatistics = new VideoPerformanceStatistics(VideoPerformanceMonitor.distributionBinSize, (result) => + this.reportPerformanceEvent('video.performance.performanceDataGenerated', [result]), + ); + } + + /** + * Start to check frame processing time intervally + * and report performance event if the average frame processing time is too long. + */ + public startMonitorSlowFrameProcessing(): void { + VideoFrameTick.setInterval(() => { + if (this.processedFrameCount === 0) { + return; + } + const averageFrameProcessingTime = this.frameProcessingTimeCost / this.processedFrameCount; + if (averageFrameProcessingTime > this.frameProcessTimeLimit) { + this.reportPerformanceEvent('video.performance.frameProcessingSlow', [averageFrameProcessingTime]); + } + this.frameProcessingTimeCost = 0; + this.processedFrameCount = 0; + }, VideoPerformanceMonitor.calculateFPSInterval); + } + + /** + * Define the time limit of frame processing. + * When the average frame processing time is longer than the time limit, a "video.performance.frameProcessingSlow" event will be reported. + * @param timeLimit + */ + public setFrameProcessTimeLimit(timeLimit: number): void { + this.frameProcessTimeLimit = timeLimit; + } + + /** + * Call this function when the app starts to switch to the new video effect + */ + public reportApplyingVideoEffect(effectId: string, effectParam?: string): void { + if (this.applyingEffect?.effectId === effectId && this.applyingEffect?.effectParam === effectParam) { + return; + } + this.applyingEffect = { + effectId, + effectParam, + }; + this.appliedEffect = undefined; + } + + /** + * Call this function when the new video effect is ready + */ + public reportVideoEffectChanged(effectId: string, effectParam?: string): void { + if ( + this.applyingEffect === undefined || + (this.applyingEffect.effectId !== effectId && this.applyingEffect.effectParam !== effectParam) + ) { + // don't handle obsoleted event + return; + } + this.appliedEffect = { + effectId, + effectParam, + }; + this.applyingEffect = undefined; + this.isFirstFrameProcessed = false; + } + + /** + * Call this function when the app starts to process a video frame + */ + public reportStartFrameProcessing(frameWidth: number, frameHeight: number): void { + VideoFrameTick.tick(); + if (!this.appliedEffect) { + return; + } + this.frameProcessingStartedAt = performance.now(); + this.performanceStatistics.processStarts( + this.appliedEffect.effectId, + frameWidth, + frameHeight, + this.appliedEffect.effectParam, + ); + } + + /** + * Call this function when the app finishes successfully processing a video frame + */ + public reportFrameProcessed(): void { + if (!this.appliedEffect) { + return; + } + this.processedFrameCount++; + this.frameProcessingTimeCost += performance.now() - this.frameProcessingStartedAt; + this.performanceStatistics.processEnds(); + if (!this.isFirstFrameProcessed) { + this.isFirstFrameProcessed = true; + this.reportPerformanceEvent('video.performance.firstFrameProcessed', [ + Date.now(), + this.appliedEffect.effectId, + this.appliedEffect?.effectParam, + ]); + } + } + + /** + * Call this function when the app starts to get the texture stream + */ + public reportGettingTextureStream(streamId: string): void { + this.gettingTextureStreamStartedAt = performance.now(); + this.currentStreamId = streamId; + } + + /** + * Call this function when the app finishes successfully getting the texture stream + */ + public reportTextureStreamAcquired(): void { + if (this.gettingTextureStreamStartedAt !== undefined) { + const timeTaken = performance.now() - this.gettingTextureStreamStartedAt; + this.reportPerformanceEvent('video.performance.textureStreamAcquired', [this.currentStreamId, timeTaken]); + } + } +} diff --git a/packages/teams-js/src/internal/videoPerformanceStatistics.ts b/packages/teams-js/src/internal/videoPerformanceStatistics.ts new file mode 100644 index 0000000000..62f070d379 --- /dev/null +++ b/packages/teams-js/src/internal/videoPerformanceStatistics.ts @@ -0,0 +1,152 @@ +import { VideoFrameTick } from './videoFrameTick'; + +export type VideoPerformanceStatisticsResult = { + effectId: string; + effectParam?: string; + frameWidth: number; + frameHeight: number; + /** + * The duration in milliseconds that the data were collected + */ + duration: number; + /** + * The number of frames that were processed in the duration + */ + sampleCount: number; + /** + * An array that presents counts of frames that were finished in n milliseconds: + * distributionBins[frameProcessingDurationInMs]=frameCount. + * For example, distributionBins[10] = 5 means that 5 frames were processed in 10 milliseconds. + */ + distributionBins: Uint32Array; +}; + +export class VideoPerformanceStatistics { + private static readonly initialSessionTimeoutInMs = 1000; + private static readonly maxSessionTimeoutInMs = 1000 * 30; + + private currentSession: { + startedAtInMs: number; + timeoutInMs: number; + effectId: string; + effectParam?: string; + frameWidth: number; + frameHeight: number; + }; + + private frameProcessingStartedAt: number; + private distributionBins: Uint32Array; + private sampleCount = 0; + private timeoutId: string; + + public constructor( + distributionBinSize: number, + /** + * Function to report the statistics result + */ + private reportStatisticsResult: (result: VideoPerformanceStatisticsResult) => void, + ) { + this.distributionBins = new Uint32Array(distributionBinSize); + } + + /** + * Call this function before processing every frame + */ + public processStarts(effectId: string, frameWidth: number, frameHeight: number, effectParam?: string): void { + VideoFrameTick.tick(); + if (!this.suitableForThisSession(effectId, frameWidth, frameHeight, effectParam)) { + this.reportAndResetSession(this.getStatistics(), effectId, effectParam, frameWidth, frameHeight); + } + this.start(); + } + + public processEnds(): void { + // calculate duration of the process and record it + const durationInMillisecond = performance.now() - this.frameProcessingStartedAt; + const binIndex = Math.floor(Math.max(0, Math.min(this.distributionBins.length - 1, durationInMillisecond))); + this.distributionBins[binIndex] += 1; + this.sampleCount += 1; + } + + private getStatistics(): VideoPerformanceStatisticsResult { + if (!this.currentSession) { + return null; + } + return { + effectId: this.currentSession.effectId, + effectParam: this.currentSession.effectParam, + frameHeight: this.currentSession.frameHeight, + frameWidth: this.currentSession.frameWidth, + duration: performance.now() - this.currentSession.startedAtInMs, + sampleCount: this.sampleCount, + distributionBins: this.distributionBins.slice(), + }; + } + + private start(): void { + this.frameProcessingStartedAt = performance.now(); + } + + private suitableForThisSession( + effectId: string, + frameWidth: number, + frameHeight: number, + effectParam?: string, + ): boolean { + return ( + this.currentSession && + this.currentSession.effectId === effectId && + this.currentSession.effectParam === effectParam && + this.currentSession.frameWidth === frameWidth && + this.currentSession.frameHeight === frameHeight + ); + } + + private reportAndResetSession(result, effectId, effectParam, frameWidth, frameHeight): void { + result && this.reportStatisticsResult(result); + this.resetCurrentSession( + this.getNextTimeout(effectId, this.currentSession), + effectId, + effectParam, + frameWidth, + frameHeight, + ); + if (this.timeoutId) { + VideoFrameTick.clearTimeout(this.timeoutId); + } + this.timeoutId = VideoFrameTick.setTimeout( + (() => this.reportAndResetSession(this.getStatistics(), effectId, effectParam, frameWidth, frameHeight)).bind( + this, + ), + this.currentSession.timeoutInMs, + ); + } + + private resetCurrentSession( + timeoutInMs: number, + effectId: string, + effectParam: string, + frameWidth: number, + frameHeight: number, + ): void { + this.currentSession = { + startedAtInMs: performance.now(), + timeoutInMs, + effectId, + effectParam, + frameWidth, + frameHeight, + }; + this.sampleCount = 0; + this.distributionBins.fill(0); + } + + // send the statistics result every n second, where n starts from 1, 2, 4...and finally stays at every 30 seconds. + private getNextTimeout(effectId: string, currentSession?: { timeoutInMs: number; effectId: string }): number { + // only reset timeout when new session or effect changed + if (!currentSession || currentSession.effectId !== effectId) { + return VideoPerformanceStatistics.initialSessionTimeoutInMs; + } + return Math.min(VideoPerformanceStatistics.maxSessionTimeoutInMs, currentSession.timeoutInMs * 2); + } +} diff --git a/packages/teams-js/src/internal/videoUtils.ts b/packages/teams-js/src/internal/videoUtils.ts index c370e755c9..ce7d6aaeae 100644 --- a/packages/teams-js/src/internal/videoUtils.ts +++ b/packages/teams-js/src/internal/videoUtils.ts @@ -12,6 +12,7 @@ import { VideoFrameInit, VideoPixelFormat, } from './VideoFrameTypes'; +import { VideoPerformanceMonitor } from './videoPerformanceMonitor'; /** * @hidden @@ -66,9 +67,10 @@ export async function processMediaStream( streamId: string, videoFrameHandler: video.VideoFrameHandler, notifyError: (string) => void, + videoPerformanceMonitor?: VideoPerformanceMonitor, ): Promise { return createProcessedStreamGenerator( - await getInputVideoTrack(streamId, notifyError), + await getInputVideoTrack(streamId, notifyError, videoPerformanceMonitor), new DefaultTransformer(notifyError, videoFrameHandler), ); } @@ -85,9 +87,10 @@ export async function processMediaStreamWithMetadata( streamId: string, videoFrameHandler: videoEx.VideoFrameHandler, notifyError: (string) => void, + videoPerformanceMonitor?: VideoPerformanceMonitor, ): Promise { return createProcessedStreamGenerator( - await getInputVideoTrack(streamId, notifyError), + await getInputVideoTrack(streamId, notifyError, videoPerformanceMonitor), new TransformerWithMetadata(notifyError, videoFrameHandler), ); } @@ -95,18 +98,24 @@ export async function processMediaStreamWithMetadata( /** * Get the video track from the media stream gotten from chrome.webview.getTextureStream(streamId). */ -async function getInputVideoTrack(streamId: string, notifyError: (string) => void): Promise { +async function getInputVideoTrack( + streamId: string, + notifyError: (string) => void, + videoPerformanceMonitor?: VideoPerformanceMonitor, +): Promise { if (inServerSideRenderingEnvironment()) { throw errorNotSupportedOnPlatform; } // eslint-disable-next-line @typescript-eslint/no-explicit-any const chrome = window['chrome'] as any; try { + videoPerformanceMonitor?.reportGettingTextureStream(streamId); const mediaStream = await chrome.webview.getTextureStream(streamId); const tracks = mediaStream.getVideoTracks(); if (tracks.length === 0) { throw new Error(`No video track in stream ${streamId}`); } + videoPerformanceMonitor?.reportTextureStreamAcquired(); return tracks[0]; } catch (error) { const errorMsg = `Failed to get video track from stream ${streamId}, error: ${error}`; @@ -402,10 +411,16 @@ type VideoEffectCallBack = (effectId: string | undefined, effectParam?: string) /** * @hidden */ -export function createEffectParameterChangeCallback(callback: VideoEffectCallBack) { +export function createEffectParameterChangeCallback( + callback: VideoEffectCallBack, + videoPerformanceMonitor?: VideoPerformanceMonitor, +) { return (effectId: string | undefined, effectParam?: string): void => { + videoPerformanceMonitor?.reportApplyingVideoEffect(effectId || '', effectParam); + callback(effectId, effectParam) .then(() => { + videoPerformanceMonitor?.reportVideoEffectChanged(effectId || '', effectParam); sendMessageToParent('video.videoEffectReadiness', [true, effectId, undefined, effectParam]); }) .catch((reason) => { diff --git a/packages/teams-js/src/private/videoEx.ts b/packages/teams-js/src/private/videoEx.ts index 54319034f1..8e43774f4e 100644 --- a/packages/teams-js/src/private/videoEx.ts +++ b/packages/teams-js/src/private/videoEx.ts @@ -1,6 +1,7 @@ import { sendMessageToParent } from '../internal/communication'; import { registerHandler } from '../internal/handlers'; import { ensureInitialized } from '../internal/internalAPIs'; +import { VideoPerformanceMonitor } from '../internal/videoPerformanceMonitor'; import { createEffectParameterChangeCallback, DefaultVideoEffectCallBack as VideoEffectCallBack, @@ -21,6 +22,9 @@ import { inServerSideRenderingEnvironment } from './inServerSideRenderingEnviron * Limited to Microsoft-internal use */ export namespace videoEx { + const videoPerformanceMonitor = inServerSideRenderingEnvironment() + ? undefined + : new VideoPerformanceMonitor(sendMessageToParent); /** * @hidden * Error level when notifying errors to the host, the host will decide what to do acording to the error level. @@ -187,14 +191,24 @@ export namespace videoEx { } if (ensureInitialized(runtime, FrameContexts.sidePanel)) { + registerHandler( + 'video.setFrameProcessTimeLimit', + (timeLimit: number) => videoPerformanceMonitor?.setFrameProcessTimeLimit(timeLimit), + false, + ); if (runtime.supports.video?.mediaStream) { registerHandler( 'video.startVideoExtensibilityVideoStream', async (mediaStreamInfo: { streamId: string; metadataInTexture?: boolean }) => { const { streamId, metadataInTexture } = mediaStreamInfo; const generator = metadataInTexture - ? await processMediaStreamWithMetadata(streamId, parameters.videoFrameHandler, notifyError) - : await processMediaStream(streamId, parameters.videoFrameHandler, notifyError); + ? await processMediaStreamWithMetadata( + streamId, + parameters.videoFrameHandler, + notifyError, + videoPerformanceMonitor, + ) + : await processMediaStream(streamId, parameters.videoFrameHandler, notifyError, videoPerformanceMonitor); // register the video track with processed frames back to the stream !inServerSideRenderingEnvironment() && window['chrome']?.webview?.registerTextureStream(streamId, generator); @@ -207,10 +221,12 @@ export namespace videoEx { 'video.newVideoFrame', (videoBufferData: VideoBufferData | LegacyVideoBufferData) => { if (videoBufferData) { + videoPerformanceMonitor?.reportStartFrameProcessing(videoBufferData.width, videoBufferData.height); const timestamp = videoBufferData.timestamp; parameters.videoBufferHandler( normalizedVideoBufferData(videoBufferData), () => { + videoPerformanceMonitor?.reportFrameProcessed(); notifyVideoFrameProcessed(timestamp); }, notifyError, @@ -224,6 +240,7 @@ export namespace videoEx { // should not happen if isSupported() is true throw errorNotSupportedOnPlatform; } + videoPerformanceMonitor?.startMonitorSlowFrameProcessing(); } } @@ -273,7 +290,11 @@ export namespace videoEx { throw errorNotSupportedOnPlatform; } - registerHandler('video.effectParameterChange', createEffectParameterChangeCallback(callback), false); + registerHandler( + 'video.effectParameterChange', + createEffectParameterChangeCallback(callback, videoPerformanceMonitor), + false, + ); sendMessageToParent('video.registerForVideoEffect'); } diff --git a/packages/teams-js/src/public/video.ts b/packages/teams-js/src/public/video.ts index 899d8d03f2..cd3b83db84 100644 --- a/packages/teams-js/src/public/video.ts +++ b/packages/teams-js/src/public/video.ts @@ -1,6 +1,7 @@ import { sendMessageToParent } from '../internal/communication'; import { registerHandler } from '../internal/handlers'; import { ensureInitialized } from '../internal/internalAPIs'; +import { VideoPerformanceMonitor } from '../internal/videoPerformanceMonitor'; import { createEffectParameterChangeCallback, processMediaStream } from '../internal/videoUtils'; import { inServerSideRenderingEnvironment } from '../private/inServerSideRenderingEnvironment'; import { errorNotSupportedOnPlatform, FrameContexts } from './constants'; @@ -11,6 +12,10 @@ import { runtime } from './runtime'; * @beta */ export namespace video { + const videoPerformanceMonitor = inServerSideRenderingEnvironment() + ? undefined + : new VideoPerformanceMonitor(sendMessageToParent); + /** Notify video frame processed function type */ type notifyVideoFrameProcessedFunctionType = () => void; /** Notify error function type */ @@ -217,6 +222,12 @@ export namespace video { if (!parameters.videoFrameHandler || !parameters.videoBufferHandler) { throw new Error('Both videoFrameHandler and videoBufferHandler must be provided'); } + registerHandler( + 'video.setFrameProcessTimeLimit', + (timeLimitInfo: { timeLimit: number }) => + videoPerformanceMonitor?.setFrameProcessTimeLimit(timeLimitInfo.timeLimit), + false, + ); if (doesSupportMediaStream()) { registerForMediaStream(parameters.videoFrameHandler, parameters.config); } else if (doesSupportSharedFrame()) { @@ -225,6 +236,7 @@ export namespace video { // should not happen if isSupported() is true throw errorNotSupportedOnPlatform; } + videoPerformanceMonitor?.startMonitorSlowFrameProcessing(); } /** @@ -256,8 +268,11 @@ export namespace video { if (!isSupported()) { throw errorNotSupportedOnPlatform; } - - registerHandler('video.effectParameterChange', createEffectParameterChangeCallback(callback), false); + registerHandler( + 'video.effectParameterChange', + createEffectParameterChangeCallback(callback, videoPerformanceMonitor), + false, + ); sendMessageToParent('video.registerForVideoEffect'); } @@ -307,7 +322,13 @@ export namespace video { async (mediaStreamInfo: { streamId: string }) => { // when a new streamId is ready: const { streamId } = mediaStreamInfo; - const generator = await processMediaStream(streamId, videoFrameHandler, notifyError); + const monitoredVideoFrameHandler = createMonitoredVideoFrameHandler(videoFrameHandler, videoPerformanceMonitor); + const generator = await processMediaStream( + streamId, + monitoredVideoFrameHandler, + notifyError, + videoPerformanceMonitor, + ); // register the video track with processed frames back to the stream: !inServerSideRenderingEnvironment() && window['chrome']?.webview?.registerTextureStream(streamId, generator); }, @@ -317,6 +338,20 @@ export namespace video { sendMessageToParent('video.mediaStream.registerForVideoFrame', [config]); } + function createMonitoredVideoFrameHandler( + videoFrameHandler: VideoFrameHandler, + videoPerformanceMonitor?: VideoPerformanceMonitor, + ): VideoFrameHandler { + return async (videoFrameData: VideoFrameData): Promise => { + // eslint-disable-next-line @typescript-eslint/no-explicit-any + const originalFrame = videoFrameData.videoFrame as any; + videoPerformanceMonitor?.reportStartFrameProcessing(originalFrame.codedWidth, originalFrame.codedHeight); + const processedFrame = await videoFrameHandler(videoFrameData); + videoPerformanceMonitor?.reportFrameProcessed(); + return processedFrame; + }; + } + /** * Old video frame data structure, almost identical to the {@link VideoBufferData} except `videoFrameBuffer` is named as `data`. * Old host like the old Teams passes this data to the SDK. It will be deprecated in the future. @@ -340,9 +375,11 @@ export namespace video { (videoBufferData: VideoBufferData | LegacyVideoBufferData) => { if (videoBufferData) { const timestamp = videoBufferData.timestamp; + videoPerformanceMonitor?.reportStartFrameProcessing(videoBufferData.width, videoBufferData.height); videoBufferHandler( normalizeVideoBufferData(videoBufferData), () => { + videoPerformanceMonitor?.reportFrameProcessed(); notifyVideoFrameProcessed(timestamp); }, notifyError, diff --git a/packages/teams-js/test/internal/videoFrameTick.spec.ts b/packages/teams-js/test/internal/videoFrameTick.spec.ts new file mode 100644 index 0000000000..bd1195938a --- /dev/null +++ b/packages/teams-js/test/internal/videoFrameTick.spec.ts @@ -0,0 +1,67 @@ +import { VideoFrameTick } from '../../src/internal/videoFrameTick'; +jest.useFakeTimers(); +describe('videoFrameTick', () => { + describe('setTimeout', () => { + it('should invoke callback after timeout', () => { + const callback = jest.fn(); + const timeoutInMs = 1000; + const id = VideoFrameTick.setTimeout(callback, timeoutInMs); + expect(callback).not.toBeCalled(); + jest.advanceTimersByTime(timeoutInMs); + VideoFrameTick.tick(); + expect(callback).toBeCalled(); + expect(id).toBeDefined(); + }); + + it('should not invoke callback before timeout', () => { + const callback1 = jest.fn(); + const timeoutInMs1 = 1000; + const callback2 = jest.fn(); + const timeoutInMs2 = 2000; + VideoFrameTick.setTimeout(callback1, timeoutInMs1); + VideoFrameTick.setTimeout(callback2, timeoutInMs2); + jest.advanceTimersByTime(timeoutInMs1); + VideoFrameTick.tick(); + expect(callback1).toBeCalled(); + expect(callback2).not.toBeCalled(); + }); + + it('should not invoke callback when it is cleared before timeout', () => { + const callback = jest.fn(); + const timeoutInMs = 1000; + const id = VideoFrameTick.setTimeout(callback, timeoutInMs); + VideoFrameTick.clearTimeout(id); + jest.advanceTimersByTime(timeoutInMs); + VideoFrameTick.tick(); + expect(callback).not.toBeCalled(); + }); + + it('should involek callback only once', () => { + const callback = jest.fn(); + const timeoutInMs = 1000; + VideoFrameTick.setTimeout(callback, timeoutInMs); + expect(callback).not.toBeCalled(); + jest.advanceTimersByTime(timeoutInMs); + VideoFrameTick.tick(); + expect(callback).toBeCalled(); + jest.advanceTimersByTime(timeoutInMs); + VideoFrameTick.tick(); + expect(callback).toBeCalledTimes(1); + }); + }); + describe('setInterval', () => { + it('should invoke callback after interval', () => { + const callback = jest.fn(); + const intervalInMs = 1000; + VideoFrameTick.setInterval(callback, intervalInMs); + expect(callback).not.toBeCalled(); + for (let i = 1; i <= 100; i++) { + jest.advanceTimersByTime(intervalInMs); + VideoFrameTick.tick(); + expect(callback).toBeCalledTimes(i); + VideoFrameTick.tick(); + expect(callback).toBeCalledTimes(i); + } + }); + }); +}); diff --git a/packages/teams-js/test/internal/videoPerformanceMonitor.spec.ts b/packages/teams-js/test/internal/videoPerformanceMonitor.spec.ts new file mode 100644 index 0000000000..2131bb9cb0 --- /dev/null +++ b/packages/teams-js/test/internal/videoPerformanceMonitor.spec.ts @@ -0,0 +1,72 @@ +/* eslint-disable strict-null-checks/all */ +import { VideoFrameTick } from '../../src/internal/videoFrameTick'; +import { VideoPerformanceMonitor } from '../../src/internal/videoPerformanceMonitor'; + +jest.useFakeTimers(); +function advanceTimersByTime(time: number): void { + jest.advanceTimersByTime(time); + VideoFrameTick.tick(); +} +const processStartsMock = jest.fn(); +const processEndsMock = jest.fn(); +jest.mock('../../src/internal/videoPerformanceStatistics', () => { + return { + VideoPerformanceStatistics: jest.fn().mockImplementation(() => { + return { + processStarts: processStartsMock, + processEnds: processEndsMock, + }; + }), + }; +}); + +describe('VideoPerformanceMonitor', () => { + const reportPerformanceEvent = jest.fn(); + let videoPerformanceMonitor: VideoPerformanceMonitor; + beforeEach(() => { + jest.clearAllMocks(); + videoPerformanceMonitor = new VideoPerformanceMonitor(reportPerformanceEvent); + }); + + it('should report firstFrameProcessed event', () => { + videoPerformanceMonitor.reportApplyingVideoEffect('effectId1', 'effectParam'); + videoPerformanceMonitor.reportApplyingVideoEffect('effectId2', 'effectParam'); + videoPerformanceMonitor.reportVideoEffectChanged('effectId2', 'effectParam'); + videoPerformanceMonitor.reportVideoEffectChanged('effectId1', 'effectParam'); + advanceTimersByTime(10); + videoPerformanceMonitor.reportFrameProcessed(); + expect(reportPerformanceEvent).toBeCalledWith('video.performance.firstFrameProcessed', [ + expect.any(Number), // timestamp + 'effectId2', + 'effectParam', + ]); + }); + + it('should report processStarts/ends', () => { + videoPerformanceMonitor.reportApplyingVideoEffect('effectId', 'effectParam'); + videoPerformanceMonitor.reportVideoEffectChanged('effectId', 'effectParam'); + videoPerformanceMonitor.reportStartFrameProcessing(100, 100); + videoPerformanceMonitor.reportFrameProcessed(); + expect(processStartsMock).toBeCalledWith('effectId', 100, 100, 'effectParam'); + }); + + it('should report TextureStreamAcquired event', () => { + videoPerformanceMonitor.reportGettingTextureStream('streamId'); + advanceTimersByTime(10); + videoPerformanceMonitor.reportTextureStreamAcquired(); + expect(reportPerformanceEvent).toBeCalledWith('video.performance.textureStreamAcquired', ['streamId', 10]); + }); + + it('should report videoExtensibilityFrameProcessingSlow event', async () => { + videoPerformanceMonitor.reportApplyingVideoEffect('effectId', 'effectParam'); + videoPerformanceMonitor.reportVideoEffectChanged('effectId', 'effectParam'); + videoPerformanceMonitor.startMonitorSlowFrameProcessing(); + advanceTimersByTime(101); + for (let i = 0; i < 10; i++) { + videoPerformanceMonitor.reportStartFrameProcessing(100, 100); + advanceTimersByTime(101); + videoPerformanceMonitor.reportFrameProcessed(); + } + expect(reportPerformanceEvent).toBeCalledWith('video.performance.frameProcessingSlow', [101]); + }); +}); diff --git a/packages/teams-js/test/internal/videoPerformanceStatistics.spec.ts b/packages/teams-js/test/internal/videoPerformanceStatistics.spec.ts new file mode 100644 index 0000000000..0758eb1dda --- /dev/null +++ b/packages/teams-js/test/internal/videoPerformanceStatistics.spec.ts @@ -0,0 +1,150 @@ +/* eslint-disable @typescript-eslint/no-explicit-any */ +/* eslint-disable strict-null-checks/all */ +import { VideoFrameTick } from '../../src/internal/videoFrameTick'; +import { + VideoPerformanceStatistics, + VideoPerformanceStatisticsResult, +} from '../../src/internal/videoPerformanceStatistics'; + +jest.useFakeTimers(); +function advanceTimersByTime(time: number): void { + jest.advanceTimersByTime(time); + VideoFrameTick.tick(); +} + +describe('PerformanceStatistics', () => { + let result: VideoPerformanceStatisticsResult | undefined; + let performanceStatistics: VideoPerformanceStatistics; + let reportFunc = jest.fn(); + reportFunc.mockImplementation((r) => (result = r)); + + beforeEach(() => { + result = undefined; + reportFunc = jest.fn(); + reportFunc.mockImplementation((r) => (result = r)); + performanceStatistics = new VideoPerformanceStatistics(1000, reportFunc); + }); + afterEach(() => { + jest.clearAllMocks(); + jest.clearAllTimers(); + }); + + it('reports statistics on timeout', () => { + performanceStatistics.processStarts('effectId', 100, 100); + performanceStatistics.processEnds(); + advanceTimersByTime(1000); + expect(result).toEqual({ + effectId: 'effectId', + frameHeight: 100, + frameWidth: 100, + duration: expect.any(Number), + sampleCount: 1, + distributionBins: expect.anything(), + }); + expect(result?.distributionBins[0]).toEqual(1); + }); + + it('reports statistics on effect change', () => { + performanceStatistics.processStarts('effectId1', 100, 100); + advanceTimersByTime(10); + performanceStatistics.processEnds(); + performanceStatistics.processStarts('effectId2', 100, 100); + advanceTimersByTime(20); + performanceStatistics.processEnds(); + expect(result).toEqual({ + effectId: 'effectId1', + frameHeight: 100, + frameWidth: 100, + duration: 10, + sampleCount: 1, + distributionBins: expect.anything(), + }); + expect(result?.distributionBins[10]).toEqual(1); + }); + + it('reports statistics on effect parameters change', () => { + performanceStatistics.processStarts('effectId1', 100, 100, 'param1'); + advanceTimersByTime(10); + performanceStatistics.processEnds(); + performanceStatistics.processStarts('effectId1', 100, 100, 'param2'); + advanceTimersByTime(20); + performanceStatistics.processEnds(); + expect(result).toEqual({ + effectId: 'effectId1', + effectParam: 'param1', + frameHeight: 100, + frameWidth: 100, + duration: 10, + sampleCount: 1, + distributionBins: expect.anything(), + }); + expect(result?.distributionBins[10]).toEqual(1); + }); + + it('reports statistics on frame size change', () => { + performanceStatistics.processStarts('effectId', 100, 100); + advanceTimersByTime(10); + performanceStatistics.processEnds(); + performanceStatistics.processStarts('effectId', 200, 200); + advanceTimersByTime(20); + performanceStatistics.processEnds(); + expect(result).toEqual({ + effectId: 'effectId', + frameHeight: 100, + frameWidth: 100, + duration: 10, + sampleCount: 1, + distributionBins: expect.anything(), + }); + expect(result?.distributionBins[10]).toEqual(1); + }); + + it("don't report statistics when session is not created", () => { + performanceStatistics.processEnds(); + expect(result).toBeUndefined(); + }); + + it("don't report statistics before timeout", () => { + performanceStatistics.processStarts('effectId', 100, 100); + advanceTimersByTime(10); + performanceStatistics.processEnds(); + expect(result).toBeUndefined(); + }); + + it("don't report statistics when no data", () => { + performanceStatistics.processStarts('effectId', 100, 100); + performanceStatistics.processStarts('effectId', 100, 100); + expect(result).toBeUndefined(); + }); + + it('timeout duration is increased over time when effectId is not changed', () => { + performanceStatistics.processStarts('effectId', 100, 100); + performanceStatistics.processEnds(); + advanceTimersByTime(1000); + expect(reportFunc).toBeCalledTimes(1); + performanceStatistics.processStarts('effectId', 100, 100); + performanceStatistics.processEnds(); + advanceTimersByTime(2000); + expect(reportFunc).toBeCalledTimes(2); + performanceStatistics.processStarts('effectId', 100, 100); + performanceStatistics.processEnds(); + advanceTimersByTime(4000); + expect(reportFunc).toBeCalledTimes(3); + performanceStatistics.processStarts('effectId', 100, 100); + performanceStatistics.processEnds(); + advanceTimersByTime(8000); + expect(reportFunc).toBeCalledTimes(4); + performanceStatistics.processStarts('effectId', 100, 100); + performanceStatistics.processEnds(); + advanceTimersByTime(16000); + expect(reportFunc).toBeCalledTimes(5); + performanceStatistics.processStarts('effectId', 100, 100); + performanceStatistics.processEnds(); + advanceTimersByTime(30000); + expect(reportFunc).toBeCalledTimes(6); + performanceStatistics.processStarts('effectId', 100, 100); + performanceStatistics.processEnds(); + advanceTimersByTime(30000); + expect(reportFunc).toBeCalledTimes(7); + }); +}); diff --git a/packages/teams-js/test/private/videoEx.spec.ts b/packages/teams-js/test/private/videoEx.spec.ts index ec4eaa6a5b..eac5bfd556 100644 --- a/packages/teams-js/test/private/videoEx.spec.ts +++ b/packages/teams-js/test/private/videoEx.spec.ts @@ -1,5 +1,6 @@ import { GlobalVars } from '../../src/internal/globalVars'; import { DOMMessageEvent, MessageRequest } from '../../src/internal/interfaces'; +import { VideoPerformanceMonitor } from '../../src/internal/videoPerformanceMonitor'; import { videoEx } from '../../src/private/videoEx'; import { app } from '../../src/public/app'; import { errorNotSupportedOnPlatform, FrameContexts } from '../../src/public/constants'; @@ -91,6 +92,15 @@ describe('videoEx', () => { it('should successfully invoke video frame event handler', async () => { await utils.initializeWithContext(FrameContexts.sidePanel); + const reportStartFrameProcessingSpy = jest.spyOn( + VideoPerformanceMonitor.prototype, + 'reportStartFrameProcessing', + ); + const reportFrameProcessedSpy = jest.spyOn(VideoPerformanceMonitor.prototype, 'reportFrameProcessed'); + const startMonitorSlowFrameProcessingSpy = jest.spyOn( + VideoPerformanceMonitor.prototype, + 'startMonitorSlowFrameProcessing', + ); let returnedVideoFrame: videoEx.VideoBufferData; let handlerInvoked = false; //callback @@ -101,6 +111,7 @@ describe('videoEx', () => { ): void => { handlerInvoked = true; returnedVideoFrame = _videoBufferData; + _notifyVideoFrameProcessed(); }; videoEx.registerForVideoFrame({ ...registerForVideoFrameParameters, @@ -119,6 +130,9 @@ describe('videoEx', () => { } as DOMMessageEvent); expect(handlerInvoked).toBeTruthy(); expect(returnedVideoFrame!).toEqual(videoFrameMock); + expect(reportStartFrameProcessingSpy).toBeCalledWith(30, 40); + expect(startMonitorSlowFrameProcessingSpy).toBeCalledTimes(1); + expect(reportFrameProcessedSpy).toBeCalledTimes(1); }); it('should invoke video frame event handler and successfully send videoFrameProcessed', async () => { @@ -242,6 +256,24 @@ describe('videoEx', () => { expect(handlerInvoked).toBe(false); }); + it('should listen to video.setFrameProcessTimeLimit', async () => { + expect.assertions(2); + await utils.initializeWithContext(FrameContexts.sidePanel); + const setFrameProcessTimeLimitSpy = jest.spyOn(VideoPerformanceMonitor.prototype, 'setFrameProcessTimeLimit'); + // Act + videoEx.registerForVideoFrame(registerForVideoFrameParameters); + utils.respondToFramelessMessage({ + data: { + func: 'video.setFrameProcessTimeLimit', + args: [100], + }, + } as DOMMessageEvent); + + // Assert + expect(setFrameProcessTimeLimitSpy).toBeCalledTimes(1); + expect(setFrameProcessTimeLimitSpy.mock.calls[0][0]).toEqual(100); + }); + describe('mediaStream', () => { let restoreMediaStreamAPI: () => void; beforeEach(async () => { diff --git a/packages/teams-js/test/public/video.spec.ts b/packages/teams-js/test/public/video.spec.ts index ac8f66ff84..5791f42067 100644 --- a/packages/teams-js/test/public/video.spec.ts +++ b/packages/teams-js/test/public/video.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 { VideoPerformanceMonitor } from '../../src/internal/videoPerformanceMonitor'; import { app } from '../../src/public/app'; import { errorNotSupportedOnPlatform, FrameContexts } from '../../src/public/constants'; import { video } from '../../src/public/video'; @@ -101,6 +102,18 @@ describe('video', () => { const messageForRegister = utils.findMessageByFunc('registerHandler'); expect(messageForRegister).toBeNull(); }); + + it('should listen to video.setFrameProcessTimeLimit', () => { + expect.assertions(2); + const setFrameProcessTimeLimitSpy = jest.spyOn(VideoPerformanceMonitor.prototype, 'setFrameProcessTimeLimit'); + // Act + video.registerForVideoFrame(registerForVideoFrameParameters); + sendMessage('video.setFrameProcessTimeLimit', { timeLimit: 100 }); + + // Assert + expect(setFrameProcessTimeLimitSpy).toBeCalledTimes(1); + expect(setFrameProcessTimeLimitSpy.mock.calls[0][0]).toEqual(100); + }); }); describe('sharedFrame', () => { @@ -135,10 +148,19 @@ describe('video', () => { }); it('should invoke video frame event handler and successfully send videoFrameProcessed', async () => { - expect.assertions(3); + expect.assertions(6); // Arrange const videoBufferHandler: video.VideoBufferHandler = (_frame, onSuccess) => onSuccess(); + const reportStartFrameProcessingSpy = jest.spyOn( + VideoPerformanceMonitor.prototype, + 'reportStartFrameProcessing', + ); + const reportFrameProcessedSpy = jest.spyOn(VideoPerformanceMonitor.prototype, 'reportFrameProcessed'); + const startMonitorSlowFrameProcessingSpy = jest.spyOn( + VideoPerformanceMonitor.prototype, + 'startMonitorSlowFrameProcessing', + ); // Act video.registerForVideoFrame({ ...registerForVideoFrameParameters, videoBufferHandler }); @@ -146,6 +168,9 @@ describe('video', () => { sendMessage('video.newVideoFrame', videoFrameMock); // Assert + expect(reportStartFrameProcessingSpy).toBeCalledWith(30, 40); + expect(reportFrameProcessedSpy).toBeCalledTimes(1); + expect(startMonitorSlowFrameProcessingSpy).toBeCalledTimes(1); const message = utils.findMessageByFunc('video.videoFrameProcessed'); expect(message).not.toBeNull(); expect(message?.args?.length).toBe(1); @@ -196,11 +221,15 @@ describe('video', () => { }); it('should successfully invoke videoFrameHandler', async () => { - expect.assertions(1); + expect.assertions(3); // Arrange const videoFrameHandler = jest.fn(); - + const reportStartFrameProcessingSpy = jest.spyOn( + VideoPerformanceMonitor.prototype, + 'reportStartFrameProcessing', + ); + const reportFrameProcessedSpy = jest.spyOn(VideoPerformanceMonitor.prototype, 'reportFrameProcessed'); // Act video.registerForVideoFrame({ ...registerForVideoFrameParameters, @@ -210,6 +239,8 @@ describe('video', () => { await utils.flushPromises(); // Assert + expect(reportStartFrameProcessingSpy).toBeCalledWith(100, 100); + expect(reportFrameProcessedSpy).toBeCalledTimes(1); expect(videoFrameHandler).toHaveBeenCalledTimes(1); }); @@ -297,11 +328,13 @@ describe('video', () => { }); it('should successfully invoke effectParameterChange handler', async () => { - expect.assertions(2); + expect.assertions(6); // Arrange await utils.initializeWithContext(FrameContexts.sidePanel); const videoEffectCallBack = jest.fn().mockResolvedValue(undefined); + const reportApplyingVideoEffectSpy = jest.spyOn(VideoPerformanceMonitor.prototype, 'reportApplyingVideoEffect'); + const reportVideoEffectChangedSpy = jest.spyOn(VideoPerformanceMonitor.prototype, 'reportVideoEffectChanged'); // Act video.registerForVideoEffect(videoEffectCallBack); @@ -309,8 +342,13 @@ describe('video', () => { sendMessage('video.effectParameterChange', effectId); // Assert + expect(reportApplyingVideoEffectSpy).toHaveBeenCalledTimes(1); + expect(reportApplyingVideoEffectSpy.mock.calls[0][0]).toEqual(effectId); expect(videoEffectCallBack).toHaveBeenCalledTimes(1); expect(videoEffectCallBack.mock.lastCall[0]).toEqual(effectId); + await utils.flushPromises(); + expect(reportVideoEffectChangedSpy).toHaveBeenCalledTimes(1); + expect(reportVideoEffectChangedSpy.mock.calls[0][0]).toEqual(effectId); }); it('should invoke videoEffectReadiness handler on callback resolved', async () => { @@ -451,6 +489,8 @@ function mockMediaStreamAPI() { /* mock VideoFrame */ { timestamp: 0, + codedWidth: 100, + codedHeight: 100, // eslint-disable-next-line @typescript-eslint/no-empty-function close: () => {}, },