mattermost-mobile-upstream/app/managers/performance_metrics_manager/index.test.ts

// Copyright (c) 2015-present Mattermost, Inc. All Rights Reserved.
// See LICENSE.txt for license information.

import RNUtils from '@mattermost/rnutils';
import {AppState} from 'react-native';
import performance from 'react-native-performance';

import {mockApiClient} from '@test/mock_api_client';
import TestHelper from '@test/test_helper';
import {logInfo, logWarning} from '@utils/log';

import NetworkManager from '../network_manager';

import {NetworkRequestMetrics} from './constant';
import {testExports as batcherTestExports} from './performance_metrics_batcher';
import {getBaseReportRequest} from './test_utils';

import {testExports} from './index';

const PerformanceMetricsManagerClass = testExports.PerformanceMetricsManagerSingleton;
const {
    RETRY_TIME,
    MAX_RETRIES,
} = testExports;

const {
    INTERVAL_TIME,
} = batcherTestExports;

const TEST_EPOCH = 1577836800000;

jest.mock('@utils/log', () => ({
    logDebug: jest.fn(),
    logInfo: jest.fn(),
    logWarning: jest.fn(),
}));

performance.timeOrigin = TEST_EPOCH;

describe('performance_metrics_manager', () => {
    const serverUrl = 'http://www.someserverurl.com/';
    const expectedUrl = `${serverUrl}/api/v4/client_perf`;
    let PerformanceMetricsManager = new PerformanceMetricsManagerClass();

    beforeEach(async () => {
        jest.useFakeTimers({doNotFake: [
            'cancelAnimationFrame',
            'cancelIdleCallback',
            'clearImmediate',
            'clearInterval',
            'clearTimeout',
            'hrtime',
            'nextTick',
            'queueMicrotask',
            'requestAnimationFrame',
            'requestIdleCallback',
            'setImmediate',
            'setInterval',
        ]}).setSystemTime(new Date(TEST_EPOCH));

        NetworkManager.createClient(serverUrl);
        const {operator} = await TestHelper.setupServerDatabase(serverUrl);
        await operator.handleConfigs({configs: [{id: 'EnableClientMetrics', value: 'true'}], configsToDelete: [], prepareRecordsOnly: false});
    });

    afterEach(async () => {
        NetworkManager.invalidateClient(serverUrl);
        await TestHelper.tearDown();

        jest.clearAllMocks();

        jest.useRealTimers();
    });
    describe('load metrics', () => {
        const getMeasure = (timestamp: number, value: number): PerformanceReportMeasure => {
            return {
                metric: 'mobile_load',
                timestamp,
                value,
            };
        };

        beforeEach(async () => {
            PerformanceMetricsManager = new PerformanceMetricsManagerClass();

            const mockHasRegisteredLoad = {hasRegisteredLoad: false};
            jest.mocked(RNUtils.setHasRegisteredLoad).mockImplementation(() => {
                mockHasRegisteredLoad.hasRegisteredLoad = true;
            });
            jest.mocked(RNUtils.getHasRegisteredLoad).mockImplementation(() => mockHasRegisteredLoad);
        });
        afterEach(async () => {
            performance.clearMarks();
        });

        it('only load on target', async () => {
            performance.mark('nativeLaunchStart');
            const measure = getMeasure(TEST_EPOCH + INTERVAL_TIME, INTERVAL_TIME);
            const expectedRequest = getBaseReportRequest(measure.timestamp, measure.timestamp + 1);
            expectedRequest.body.histograms = [measure];

            PerformanceMetricsManager.setLoadTarget('CHANNEL');
            PerformanceMetricsManager.finishLoad('HOME', serverUrl);
            await TestHelper.tick();
            jest.advanceTimersByTime(INTERVAL_TIME);
            await TestHelper.tick();
            expect(mockApiClient.post).not.toHaveBeenCalled();
            PerformanceMetricsManager.finishLoad('CHANNEL', serverUrl);
            await TestHelper.tick();
            jest.advanceTimersByTime(INTERVAL_TIME);
            await TestHelper.tick();
            expect(mockApiClient.post).toHaveBeenCalledWith(expectedUrl, expectedRequest);
        });

        it('only register load once', async () => {
            performance.mark('nativeLaunchStart');
            const measure = getMeasure(TEST_EPOCH, 0);
            const expectedRequest = getBaseReportRequest(measure.timestamp, measure.timestamp + 1);
            expectedRequest.body.histograms = [measure];

            PerformanceMetricsManager.setLoadTarget('HOME');
            PerformanceMetricsManager.finishLoad('HOME', serverUrl);
            await TestHelper.tick();
            jest.advanceTimersByTime(INTERVAL_TIME);
            await TestHelper.tick();
            expect(mockApiClient.post).toHaveBeenCalledWith(expectedUrl, expectedRequest);
            mockApiClient.post.mockClear();
            PerformanceMetricsManager.finishLoad('HOME', serverUrl);
            await TestHelper.tick();
            jest.advanceTimersByTime(INTERVAL_TIME);
            await TestHelper.tick();
            expect(mockApiClient.post).not.toHaveBeenCalled();
        });

        it('retry if the mark is not yet present', async () => {
            const measure = getMeasure(TEST_EPOCH + (RETRY_TIME * 2), RETRY_TIME);
            const expectedRequest = getBaseReportRequest(measure.timestamp, measure.timestamp + 1);
            expectedRequest.body.histograms = [measure];

            PerformanceMetricsManager.setLoadTarget('CHANNEL');
            PerformanceMetricsManager.finishLoad('CHANNEL', serverUrl);
            await TestHelper.tick();
            jest.advanceTimersByTime(RETRY_TIME);
            await TestHelper.tick();
            performance.mark('nativeLaunchStart');
            await TestHelper.tick();
            jest.advanceTimersByTime(RETRY_TIME);
            await TestHelper.tick();
            await TestHelper.tick();
            jest.advanceTimersByTime(INTERVAL_TIME);
            await TestHelper.tick();
            expect(mockApiClient.post).toHaveBeenCalledWith(expectedUrl, expectedRequest);
        });

        it('fail graciously if no measure is set', async () => {
            PerformanceMetricsManager.setLoadTarget('CHANNEL');
            PerformanceMetricsManager.finishLoad('CHANNEL', serverUrl);
            for (let i = 0; i < MAX_RETRIES; i++) {
            // eslint-disable-next-line no-await-in-loop
                await TestHelper.tick();
                jest.advanceTimersByTime(MAX_RETRIES);
                // eslint-disable-next-line no-await-in-loop
                await TestHelper.tick();
            }
            await TestHelper.tick();
            jest.advanceTimersByTime(INTERVAL_TIME);
            await TestHelper.tick();
            expect(mockApiClient.post).not.toHaveBeenCalled();
            expect(logWarning).toHaveBeenCalled();
        });
    });

    describe('app state changes', () => {
        const getMeasure = (timestamp: number, value: number): PerformanceReportMeasure => {
            return {
                metric: 'mobile_channel_switch',
                timestamp,
                value,
            };
        };

        beforeEach(async () => {
            AppState.currentState = 'active';

            PerformanceMetricsManager = new PerformanceMetricsManagerClass();
        });

        it('forces send on app state change to inactive, or anything other than active', async () => {
            const appStateSpy = jest.spyOn(AppState, 'addEventListener');

            const measure = getMeasure(TEST_EPOCH, 0);

            PerformanceMetricsManager.startMetric('mobile_channel_switch');
            PerformanceMetricsManager.endMetric('mobile_channel_switch', serverUrl);

            appStateSpy.mock.calls[0][1]('inactive');

            await TestHelper.tick();

            const expectedRequest = getBaseReportRequest(measure.timestamp, measure.timestamp + 1);
            expectedRequest.body.histograms = [measure];
            expect(mockApiClient.post).toHaveBeenCalled();

            expect(mockApiClient.post).toHaveBeenCalledWith(`${serverUrl}/api/v4/client_perf`, expectedRequest);
        });
    });

    describe('time to interaction', () => {
        beforeEach(() => {
            PerformanceMetricsManager = new PerformanceMetricsManagerClass();
        });

        it('measures time to interaction correctly', () => {
            PerformanceMetricsManager.startTimeToInteraction();
            jest.advanceTimersByTime(100);
            const result = PerformanceMetricsManager.measureTimeToInteraction();
            expect(result?.duration).toBe(100);
        });

        it('handles missing TTI mark gracefully', () => {
            const result = PerformanceMetricsManager.measureTimeToInteraction();
            expect(result).toBeUndefined();
        });
    });

    describe('network request metrics', () => {
        beforeEach(async () => {
            PerformanceMetricsManager = new PerformanceMetricsManagerClass();
        });

        afterEach(async () => {
            NetworkManager.invalidateClient(serverUrl);
            await TestHelper.tearDown();
        });

        it('collects network request metrics', async () => {
            const timestamp = TEST_EPOCH;
            jest.setSystemTime(new Date(timestamp));

            PerformanceMetricsManager.collectNetworkRequestData(
                NetworkRequestMetrics.ElapsedTime,
                100,
                {serverUrl, groupLabel: 'Login'},
            );

            jest.advanceTimersByTime(INTERVAL_TIME);
            await TestHelper.tick();

            const expectedRequest = getBaseReportRequest(timestamp, timestamp + 1);
            expectedRequest.body.histograms = [{
                metric: NetworkRequestMetrics.ElapsedTime,
                value: 100,
                timestamp,
                label: {network_request_group: 'Login'},
            }];

            expect(mockApiClient.post).toHaveBeenCalledWith(
                `${serverUrl}/api/v4/client_perf`,
                expectedRequest,
            );
        });
    });

    describe('other metrics', () => {
        const serverUrl1 = 'http://www.someserverurl.com/';
        const expectedUrl1 = `${serverUrl1}/api/v4/client_perf`;

        const serverUrl2 = 'http://www.otherserverurl.com/';
        const expectedUrl2 = `${serverUrl2}/api/v4/client_perf`;

        const measure1: PerformanceReportMeasure = {
            metric: 'mobile_channel_switch',
            timestamp: TEST_EPOCH + 100,
            value: 100,
        };

        const measure2: PerformanceReportMeasure = {
            metric: 'mobile_team_switch',
            timestamp: TEST_EPOCH + 150 + 50,
            value: 150,
        };

        beforeEach(async () => {
            NetworkManager.createClient(serverUrl1);
            NetworkManager.createClient(serverUrl2);
            const {operator: operator1} = await TestHelper.setupServerDatabase(serverUrl1);
            const {operator: operator2} = await TestHelper.setupServerDatabase(serverUrl2);
            await operator1.handleConfigs({configs: [{id: 'EnableClientMetrics', value: 'true'}], configsToDelete: [], prepareRecordsOnly: false});
            await operator2.handleConfigs({configs: [{id: 'EnableClientMetrics', value: 'true'}], configsToDelete: [], prepareRecordsOnly: false});
        });
        afterEach(async () => {
            NetworkManager.invalidateClient(serverUrl1);
            NetworkManager.invalidateClient(serverUrl2);

            performance.clearMarks();
        });

        it('do not send metrics when we do not start them', async () => {
            PerformanceMetricsManager.endMetric('mobile_channel_switch', serverUrl1);

            jest.advanceTimersByTime(INTERVAL_TIME);
            await TestHelper.tick();
            expect(mockApiClient.post).not.toHaveBeenCalled();
        });

        it('send metric after it has been started', async () => {
            const expectedRequest = getBaseReportRequest(measure1.timestamp, measure1.timestamp + 1);
            expectedRequest.body.histograms = [measure1];

            PerformanceMetricsManager.startMetric('mobile_channel_switch');
            jest.advanceTimersByTime(100);

            PerformanceMetricsManager.endMetric('mobile_channel_switch', serverUrl1);
            await TestHelper.tick();

            jest.advanceTimersByTime(INTERVAL_TIME);
            await TestHelper.tick();
            expect(mockApiClient.post).toHaveBeenCalledWith(expectedUrl1, expectedRequest);
        });

        it('a second end metric does not generate a second measure', async () => {
            const expectedRequest = getBaseReportRequest(measure1.timestamp, measure1.timestamp + 1);
            expectedRequest.body.histograms = [measure1];

            PerformanceMetricsManager.startMetric('mobile_channel_switch');
            jest.advanceTimersByTime(100);

            PerformanceMetricsManager.endMetric('mobile_channel_switch', serverUrl1);
            await TestHelper.tick();
            jest.advanceTimersByTime(100);

            PerformanceMetricsManager.endMetric('mobile_channel_switch', serverUrl1);
            await TestHelper.tick();

            jest.advanceTimersByTime(INTERVAL_TIME);
            await TestHelper.tick();
            expect(mockApiClient.post).toHaveBeenCalledWith(expectedUrl1, expectedRequest);
        });

        it('different metrics do not interfere', async () => {
            const expectedRequest = getBaseReportRequest(measure1.timestamp, measure2.timestamp);
            expectedRequest.body.histograms = [measure1, measure2];

            PerformanceMetricsManager.startMetric('mobile_channel_switch');
            jest.advanceTimersByTime(50);
            PerformanceMetricsManager.startMetric('mobile_team_switch');
            jest.advanceTimersByTime(50);

            PerformanceMetricsManager.endMetric('mobile_channel_switch', serverUrl1);
            await TestHelper.tick();
            jest.advanceTimersByTime(100);
            PerformanceMetricsManager.endMetric('mobile_team_switch', serverUrl1);
            await TestHelper.tick();

            jest.advanceTimersByTime(INTERVAL_TIME);
            await TestHelper.tick();
            expect(mockApiClient.post).toHaveBeenCalledWith(expectedUrl1, expectedRequest);
        });

        it('metrics to different servers do not interfere', async () => {
            const expectedRequest1 = getBaseReportRequest(measure1.timestamp, measure1.timestamp + 1);
            expectedRequest1.body.histograms = [measure1];

            const expectedRequest2 = getBaseReportRequest(measure2.timestamp, measure2.timestamp + 1);
            expectedRequest2.body.histograms = [measure2];

            PerformanceMetricsManager.startMetric('mobile_channel_switch');
            jest.advanceTimersByTime(50);
            PerformanceMetricsManager.startMetric('mobile_team_switch');
            jest.advanceTimersByTime(50);

            PerformanceMetricsManager.endMetric('mobile_channel_switch', serverUrl1);
            await TestHelper.tick();
            jest.advanceTimersByTime(100);
            PerformanceMetricsManager.endMetric('mobile_team_switch', serverUrl2);
            await TestHelper.tick();

            jest.advanceTimersByTime(INTERVAL_TIME);
            await TestHelper.tick();
            expect(mockApiClient.post).toHaveBeenCalledWith(expectedUrl1, expectedRequest1);
            expect(mockApiClient.post).toHaveBeenCalledWith(expectedUrl2, expectedRequest2);
        });

        it('handles multiple marks with detailed logging', async () => {
            const timestamp = TEST_EPOCH + 200;
            const expectedRequest = getBaseReportRequest(timestamp, timestamp + 1);
            expectedRequest.body.histograms = [{
                metric: 'mobile_channel_switch',
                timestamp,
                value: 50,
            }];

            PerformanceMetricsManager.startMetric('mobile_channel_switch');
            jest.advanceTimersByTime(50);
            PerformanceMetricsManager.mark('mobile_channel_switch', {detail: 'middle'});
            jest.advanceTimersByTime(150);
            PerformanceMetricsManager.endMetric('mobile_channel_switch', serverUrl1);
            await TestHelper.tick();

            jest.advanceTimersByTime(INTERVAL_TIME);
            await TestHelper.tick();
            expect(mockApiClient.post).toHaveBeenCalledWith(expectedUrl1, expectedRequest);

            expect(logInfo).toHaveBeenCalledWith('Performance marks for mobile_channel_switch:');
            expect(logInfo).toHaveBeenCalledWith('Mark 0 => 1:      50.00ms    [startMetric => middle]');
            expect(logInfo).toHaveBeenCalledWith('Total:            50.00ms');
        });
    });
});