Performance monitoring measurements (#6041)

src/@types/global.d.ts

@@ -42,6 +42,7 @@ import {SpaceStoreClass} from "../stores/SpaceStore";
 import TypingStore from "../stores/TypingStore";
 import { EventIndexPeg } from "../indexing/EventIndexPeg";
 import {VoiceRecordingStore} from "../stores/VoiceRecordingStore";
+import PerformanceMonitor from "../performance";
 
 declare global {
     interface Window {
@@ -79,6 +80,8 @@ declare global {
         mxVoiceRecordingStore: VoiceRecordingStore;
         mxTypingStore: TypingStore;
         mxEventIndexPeg: EventIndexPeg;
+        mxPerformanceMonitor: PerformanceMonitor;
+        mxPerformanceEntryNames: any;
     }
 
     interface Document {

src/components/structures/MatrixChat.tsx

@@ -86,6 +86,8 @@ import {RoomUpdateCause} from "../../stores/room-list/models";
 import defaultDispatcher from "../../dispatcher/dispatcher";
 import SecurityCustomisations from "../../customisations/Security";
 
+import PerformanceMonitor, { PerformanceEntryNames } from "../../performance";
+
 /** constants for MatrixChat.state.view */
 export enum Views {
     // a special initial state which is only used at startup, while we are
@@ -484,42 +486,22 @@ export default class MatrixChat extends React.PureComponent<IProps, IState> {
     }
 
     startPageChangeTimer() {
-        // Tor doesn't support performance
-        if (!performance || !performance.mark) return null;
-
-        // This shouldn't happen because UNSAFE_componentWillUpdate and componentDidUpdate
-        // are used.
-        if (this.pageChanging) {
-            console.warn('MatrixChat.startPageChangeTimer: timer already started');
-            return;
-        }
-        this.pageChanging = true;
-        performance.mark('element_MatrixChat_page_change_start');
+        PerformanceMonitor.instance.start(PerformanceEntryNames.PAGE_CHANGE);
     }
 
     stopPageChangeTimer() {
-        // Tor doesn't support performance
-        if (!performance || !performance.mark) return null;
+        const perfMonitor = PerformanceMonitor.instance;
 
-        if (!this.pageChanging) {
-            console.warn('MatrixChat.stopPageChangeTimer: timer not started');
-            return;
-        }
-        this.pageChanging = false;
-        performance.mark('element_MatrixChat_page_change_stop');
-        performance.measure(
-            'element_MatrixChat_page_change_delta',
-            'element_MatrixChat_page_change_start',
-            'element_MatrixChat_page_change_stop',
-        );
-        performance.clearMarks('element_MatrixChat_page_change_start');
-        performance.clearMarks('element_MatrixChat_page_change_stop');
-        const measurement = performance.getEntriesByName('element_MatrixChat_page_change_delta').pop();
+        perfMonitor.stop(PerformanceEntryNames.PAGE_CHANGE);
 
-        // In practice, sometimes the entries list is empty, so we get no measurement
-        if (!measurement) return null;
+        const entries = perfMonitor.getEntries({
+            name: PerformanceEntryNames.PAGE_CHANGE,
+        });
+        const measurement = entries.pop();
 
-        return measurement.duration;
+        return measurement
+            ? measurement.duration
+            : null;
     }
 
     shouldTrackPageChange(prevState: IState, state: IState) {
@@ -1632,11 +1614,13 @@ export default class MatrixChat extends React.PureComponent<IProps, IState> {
                 action: 'start_registration',
                 params: params,
             });
+            PerformanceMonitor.instance.start(PerformanceEntryNames.REGISTER);
         } else if (screen === 'login') {
             dis.dispatch({
                 action: 'start_login',
                 params: params,
             });
+            PerformanceMonitor.instance.start(PerformanceEntryNames.LOGIN);
         } else if (screen === 'forgot_password') {
             dis.dispatch({
                 action: 'start_password_recovery',
@@ -1965,6 +1949,8 @@ export default class MatrixChat extends React.PureComponent<IProps, IState> {
         // Create and start the client
         await Lifecycle.setLoggedIn(credentials);
         await this.postLoginSetup();
+        PerformanceMonitor.instance.stop(PerformanceEntryNames.LOGIN);
+        PerformanceMonitor.instance.stop(PerformanceEntryNames.REGISTER);
     };
 
     // complete security / e2e setup has finished

src/performance/entry-names.ts

@@ -0,0 +1,57 @@
+/*
+Copyright 2021 The Matrix.org Foundation C.I.C.
+
+Licensed under the Apache License, Version 2.0 (the "License");
+you may not use this file except in compliance with the License.
+You may obtain a copy of the License at
+
+    http://www.apache.org/licenses/LICENSE-2.0
+
+Unless required by applicable law or agreed to in writing, software
+distributed under the License is distributed on an "AS IS" BASIS,
+WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+See the License for the specific language governing permissions and
+limitations under the License.
+*/
+
+export enum PerformanceEntryNames {
+
+    /**
+     * Application wide
+     */
+
+    APP_STARTUP = "mx_AppStartup",
+    PAGE_CHANGE = "mx_PageChange",
+
+    /**
+     * Events
+     */
+
+    RESEND_EVENT = "mx_ResendEvent",
+    SEND_E2EE_EVENT = "mx_SendE2EEEvent",
+    SEND_ATTACHMENT = "mx_SendAttachment",
+
+    /**
+     * Rooms
+     */
+
+    SWITCH_ROOM = "mx_SwithRoom",
+    JUMP_TO_ROOM = "mx_JumpToRoom",
+    JOIN_ROOM = "mx_JoinRoom",
+    CREATE_DM = "mx_CreateDM",
+    PEEK_ROOM = "mx_PeekRoom",
+
+    /**
+     * User
+     */
+
+    VERIFY_E2EE_USER = "mx_VerifyE2EEUser",
+    LOGIN = "mx_Login",
+    REGISTER = "mx_Register",
+
+    /**
+     * VoIP
+     */
+
+    SETUP_VOIP_CALL = "mx_SetupVoIPCall",
+}

src/performance/index.ts

@@ -0,0 +1,178 @@
+/*
+Copyright 2021 The Matrix.org Foundation C.I.C.
+
+Licensed under the Apache License, Version 2.0 (the "License");
+you may not use this file except in compliance with the License.
+You may obtain a copy of the License at
+
+    http://www.apache.org/licenses/LICENSE-2.0
+
+Unless required by applicable law or agreed to in writing, software
+distributed under the License is distributed on an "AS IS" BASIS,
+WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+See the License for the specific language governing permissions and
+limitations under the License.
+*/
+
+import { PerformanceEntryNames } from "./entry-names";
+
+interface GetEntriesOptions {
+    name?: string,
+    type?: string,
+}
+
+type PerformanceCallbackFunction = (entry: PerformanceEntry[]) => void;
+
+interface PerformanceDataListener {
+    entryNames?: string[],
+    callback: PerformanceCallbackFunction
+}
+
+export default class PerformanceMonitor {
+    static _instance: PerformanceMonitor;
+
+    private START_PREFIX = "start:"
+    private STOP_PREFIX = "stop:"
+
+    private listeners: PerformanceDataListener[] = []
+    private entries: PerformanceEntry[] = []
+
+    public static get instance(): PerformanceMonitor {
+        if (!PerformanceMonitor._instance) {
+            PerformanceMonitor._instance = new PerformanceMonitor();
+        }
+        return PerformanceMonitor._instance;
+    }
+
+    /**
+     * Starts a performance recording
+     * @param name Name of the recording
+     * @param id Specify an identifier appended to the measurement name
+     * @returns {void}
+     */
+    start(name: string, id?: string): void {
+        if (!this.supportsPerformanceApi()) {
+            return;
+        }
+        const key = this.buildKey(name, id);
+
+        if (performance.getEntriesByName(this.START_PREFIX + key).length > 0) {
+            console.warn(`Recording already started for: ${name}`);
+            return;
+        }
+
+        performance.mark(this.START_PREFIX + key);
+    }
+
+    /**
+     * Stops a performance recording and stores delta duration
+     * with the start marker
+     * @param name Name of the recording
+     * @param id Specify an identifier appended to the measurement name
+     * @returns {void}
+     */
+    stop(name: string, id?: string): PerformanceEntry {
+        if (!this.supportsPerformanceApi()) {
+            return;
+        }
+        const key = this.buildKey(name, id);
+        if (performance.getEntriesByName(this.START_PREFIX + key).length === 0) {
+            console.warn(`No recording started for: ${name}`);
+            return;
+        }
+
+        performance.mark(this.STOP_PREFIX + key);
+        performance.measure(
+            key,
+            this.START_PREFIX + key,
+            this.STOP_PREFIX + key,
+        );
+
+        this.clear(name, id);
+
+        const measurement = performance.getEntriesByName(key).pop();
+
+        // Keeping a reference to all PerformanceEntry created
+        // by this abstraction for historical events collection
+        // when adding a data callback
+        this.entries.push(measurement);
+
+        this.listeners.forEach(listener => {
+            if (this.shouldEmit(listener, measurement)) {
+                listener.callback([measurement])
+            }
+        });
+
+        return measurement;
+    }
+
+    clear(name: string, id?: string): void {
+        if (!this.supportsPerformanceApi()) {
+            return;
+        }
+        const key = this.buildKey(name, id);
+        performance.clearMarks(this.START_PREFIX + key);
+        performance.clearMarks(this.STOP_PREFIX + key);
+    }
+
+    getEntries({ name, type }: GetEntriesOptions = {}): PerformanceEntry[] {
+        return this.entries.filter(entry => {
+            const satisfiesName = !name || entry.name === name;
+            const satisfiedType = !type || entry.entryType === type;
+            return satisfiesName && satisfiedType;
+        });
+    }
+
+    addPerformanceDataCallback(listener: PerformanceDataListener, buffer = false) {
+        this.listeners.push(listener);
+        if (buffer) {
+            const toEmit = this.entries.filter(entry => this.shouldEmit(listener, entry));
+            if (toEmit.length > 0) {
+                listener.callback(toEmit);
+            }
+        }
+    }
+
+    removePerformanceDataCallback(callback?: PerformanceCallbackFunction) {
+        if (!callback) {
+            this.listeners = [];
+        } else {
+            this.listeners.splice(
+                this.listeners.findIndex(listener => listener.callback === callback),
+                1,
+            );
+        }
+    }
+
+    /**
+     * Tor browser does not support the Performance API
+     * @returns {boolean} true if the Performance API is supported
+     */
+    private supportsPerformanceApi(): boolean {
+        return performance !== undefined && performance.mark !== undefined;
+    }
+
+    private shouldEmit(listener: PerformanceDataListener, entry: PerformanceEntry): boolean {
+        return !listener.entryNames || listener.entryNames.includes(entry.name);
+    }
+
+    /**
+     * Internal utility to ensure consistent name for the recording
+     * @param name Name of the recording
+     * @param id Specify an identifier appended to the measurement name
+     * @returns {string} a compound of the name and identifier if present
+     */
+    private buildKey(name: string, id?: string): string {
+        return `${name}${id ? `:${id}` : ''}`;
+    }
+}
+
+
+// Convenience exports
+export {
+    PerformanceEntryNames,
+}
+
+// Exposing those to the window object to bridge them from tests
+window.mxPerformanceMonitor = PerformanceMonitor.instance;
+window.mxPerformanceEntryNames = PerformanceEntryNames;

test/end-to-end-tests/.gitignore

@@ -1,3 +1,4 @@
 node_modules
 *.png
 element/env
+performance-entries.json

test/end-to-end-tests/src/session.js

@@ -208,7 +208,7 @@ module.exports = class ElementSession {
         this.log.done();
     }
 
-    close() {
+    async close() {
         return this.browser.close();
     }
 

test/end-to-end-tests/start.js

@@ -79,8 +79,26 @@ async function runTests() {
         await new Promise((resolve) => setTimeout(resolve, 5 * 60 * 1000));
     }
 
-    await Promise.all(sessions.map((session) => session.close()));
+    const performanceEntries = {};
 
+    await Promise.all(sessions.map(async (session) => {
+        // Collecting all performance monitoring data before closing the session
+        const measurements = await session.page.evaluate(() => {
+            let measurements = [];
+            window.mxPerformanceMonitor.addPerformanceDataCallback({
+                entryNames: [
+                    window.mxPerformanceEntryNames.REGISTER,
+                ],
+                callback: (events) => {
+                    measurements = JSON.stringify(events);
+                },
+            }, true);
+            return measurements;
+        });
+        performanceEntries[session.username] = JSON.parse(measurements);
+        return session.close();
+    }));
+    fs.writeFileSync(`performance-entries.json`, JSON.stringify(performanceEntries));
     if (failure) {
         process.exit(-1);
     } else {