feat(perf): Add new event to report modern performance metrics (#1138)

Co-authored-by: mergify[bot] <37929162+mergify[bot]@users.noreply.github.com>

src/lib/Preview.js

@@ -11,6 +11,7 @@ import loaderList from './loaders';
 import Cache from './Cache';
 import PreviewError from './PreviewError';
 import PreviewErrorViewer from './viewers/error/PreviewErrorViewer';
+import PreviewPerf from './PreviewPerf';
 import PreviewUI from './PreviewUI';
 import getTokens from './tokens';
 import Timer from './Timer';
@@ -198,18 +199,16 @@ class Preview extends EventEmitter {
                 const previewDurationTag = Timer.createTag(this.file.id, DURATION_METRIC);
                 const previewDurationTimer = Timer.get(previewDurationTag);
                 Timer.stop(previewDurationTag);
+                const previewDuration = previewDurationTimer ? previewDurationTimer.elapsed : null;
+                Timer.reset(previewDurationTag);
 
-                const event = {
+                this.emitLogEvent(PREVIEW_METRIC, {
                     event_name: PREVIEW_END_EVENT,
                     value: {
-                        duration: previewDurationTimer ? previewDurationTimer.elapsed : null,
+                        duration: previewDuration,
                         viewer_status: this.viewer.getLoadStatus(),
                     },
-                    ...this.createLogEvent(),
-                };
-
-                Timer.reset(previewDurationTag);
-                this.emit(PREVIEW_METRIC, event);
+                });
             }
 
             // Eject http interceptors
@@ -241,6 +240,9 @@ class Preview extends EventEmitter {
             throw new Error('Bad access token!');
         }
 
+        // Initalize performance observers
+        this.perf = new PreviewPerf();
+
         // Update the optional file navigation collection and caches
         // if proper valid file objects were passed in.
         this.updateCollection(options.collection);
@@ -265,6 +267,11 @@ class Preview extends EventEmitter {
         // Destroy the viewer and cleanup preview
         this.destroy();
 
+        // Destroy pefromance observers
+        if (this.perf) {
+            this.perf.destroy();
+        }
+
         // Clean the UI
         this.ui.cleanup();
 
@@ -560,13 +567,10 @@ class Preview extends EventEmitter {
                 });
         }
 
-        const downloadAttemptEvent = {
+        this.emitLogEvent(PREVIEW_METRIC, {
             event_name: PREVIEW_DOWNLOAD_ATTEMPT_EVENT,
             value: this.viewer ? this.viewer.getLoadStatus() : null,
-            ...this.createLogEvent(),
-        };
-
-        this.emit(PREVIEW_METRIC, downloadAttemptEvent);
+        });
     }
 
     /**
@@ -1266,13 +1270,10 @@ class Preview extends EventEmitter {
      * @return {void}
      */
     handleViewerMetrics(data) {
-        const formattedEvent = {
+        this.emitLogEvent(PREVIEW_METRIC, {
             event_name: data.event,
             value: data.data,
-            ...this.createLogEvent(),
-        };
-
-        this.emit(PREVIEW_METRIC, formattedEvent);
+        });
     }
 
     /**
@@ -1316,8 +1317,8 @@ class Preview extends EventEmitter {
             });
 
             // Explicit preview failure
-            this.handleViewerMetrics({
-                event: 'failure',
+            this.emitLogEvent(PREVIEW_METRIC, {
+                event_name: 'failure',
             });
 
             // Hookup for phantom JS health check
@@ -1336,10 +1337,13 @@ class Preview extends EventEmitter {
             });
 
             // Explicit preview success
-            this.handleViewerMetrics({
-                event: 'success',
+            this.emitLogEvent(PREVIEW_METRIC, {
+                event_name: 'success',
             });
 
+            // Emit performance metrics after rendering has settled
+            setTimeout(this.emitPerfMetrics.bind(this), 3000);
+
             // If there wasn't an error and event logging is not disabled, use Events API to log a preview
             if (!this.options.disableEventLog) {
                 this.logPreviewEvent(this.file.id, this.options);
@@ -1518,28 +1522,6 @@ class Preview extends EventEmitter {
         this.viewer.load(err);
     }
 
-    /**
-     * Create a generic log Object.
-     *
-     * @private
-     * @return {Object} Log details for viewer session and current file.
-     */
-    createLogEvent() {
-        const file = this.file || {};
-        const log = {
-            timestamp: getISOTime(),
-            file_id: getProp(file, 'id', ''),
-            file_version_id: getProp(file, 'file_version.id', ''),
-            content_type: getProp(this.viewer, 'options.viewer.NAME', ''),
-            extension: file.extension || '',
-            locale: getProp(this.location, 'locale', ''),
-            rep_type: getProp(this.viewer, 'options.representation.representation', '').toLowerCase(),
-            ...getClientLogDetails(),
-        };
-
-        return log;
-    }
-
     /**
      * Message, to any listeners of Preview, that an error has occurred.
      *
@@ -1558,12 +1540,9 @@ class Preview extends EventEmitter {
         sanitizedError.displayMessage = stripAuthFromString(displayMessage);
         sanitizedError.message = stripAuthFromString(message);
 
-        const errorLog = {
+        this.emitLogEvent(PREVIEW_ERROR, {
             error: sanitizedError,
-            ...this.createLogEvent(),
-        };
-
-        this.emit(PREVIEW_ERROR, errorLog);
+        });
     }
 
     /**
@@ -1594,22 +1573,66 @@ class Preview extends EventEmitter {
         const contentLoadTime = Timer.get(contentLoadTag) || {};
         const previewLoadTime = Timer.get(previewLoadTag) || {};
 
-        const event = {
+        this.emitLogEvent(PREVIEW_METRIC, {
             encoding,
             event_name: LOAD_METRIC.previewLoadEvent,
             value: previewLoadTime.elapsed || 0,
             [LOAD_METRIC.fileInfoTime]: infoTime.elapsed || 0,
             [LOAD_METRIC.convertTime]: convertTime.elapsed || 0,
             [LOAD_METRIC.downloadResponseTime]: downloadTime.elapsed || 0,
             [LOAD_METRIC.contentLoadTime]: contentLoadTime.elapsed || 0,
-            ...this.createLogEvent(),
-        };
-
-        this.emit(PREVIEW_METRIC, event);
+        });
 
         Timer.reset([infoTag, convertTag, downloadTag, contentLoadTag, previewLoadTag]);
     }
 
+    /**
+     * Emit events to log preview-specific performance metrics if they exist and are non-zero
+     *
+     * @private
+     * @return {void}
+     */
+    emitPerfMetrics() {
+        const { fcp, lcp } = this.perf.report();
+
+        if (fcp) {
+            this.emitLogEvent(PREVIEW_METRIC, {
+                event_name: 'preview_perf_fcp',
+                value: fcp,
+            });
+        }
+
+        if (lcp) {
+            this.emitLogEvent(PREVIEW_METRIC, {
+                event_name: 'preview_perf_lcp',
+                value: lcp,
+            });
+        }
+    }
+
+    /**
+     * Emit an event that includes a standard set of preview-specific properties for logging
+     *
+     * @private
+     * @param {string} name - event name
+     * @param {Object} payload - event payload object
+     */
+    emitLogEvent(name, payload = {}) {
+        const file = this.file || {};
+
+        this.emit(name, {
+            ...payload,
+            content_type: getProp(this.viewer, 'options.viewer.NAME', ''),
+            extension: file.extension || '',
+            file_id: getProp(file, 'id', ''),
+            file_version_id: getProp(file, 'file_version.id', ''),
+            locale: getProp(this.location, 'locale', ''),
+            rep_type: getProp(this.viewer, 'options.representation.representation', '').toLowerCase(),
+            timestamp: getISOTime(),
+            ...getClientLogDetails(),
+        });
+    }
+
     /**
      * Builds a list of required XHR headers.
      *

src/lib/PreviewPerf.ts

@@ -0,0 +1,73 @@
+interface PerformancePaintTiming {
+    loadTime?: DOMHighResTimeStamp;
+    renderTime?: DOMHighResTimeStamp;
+}
+
+interface PerformanceReport {
+    fcp?: number;
+    lcp?: number;
+}
+
+export default class PreviewPerf {
+    private fcpObserver: PerformanceObserver;
+
+    private lcpObserver: PerformanceObserver;
+
+    private performanceReport: PerformanceReport = {};
+
+    /**
+     * Performance metrics are recorded in a global context. We use only unbuffered metrics to avoid skewed data,
+     * as buffered values can be set based on whatever page the user *first* landed on, which may not be preview.
+     *
+     * Glossary:
+     *  - FCP - First Contentful Paint (usually loading screen)
+     *  - LCP - Largest Contentful Paint (usually full content preview)
+     */
+    constructor() {
+        // Bind handlers to the current instance
+        this.handleFcp = this.handleFcp.bind(this);
+        this.handleLcp = this.handleLcp.bind(this);
+
+        // Intialize the performance observers
+        this.fcpObserver = new window.PerformanceObserver(this.handleFcp);
+        this.lcpObserver = new window.PerformanceObserver(this.handleLcp);
+
+        try {
+            this.fcpObserver.observe({ entryTypes: ['paint'] });
+            this.lcpObserver.observe({ entryTypes: ['largest-contentful-paint'] });
+        } catch (e) {
+            // We're unable to collect these metrics from legacy browsers, such as IE11/Edge (non-Chromium)
+        }
+    }
+
+    /**
+     * Disconnect active observers to avoid memory leaks
+     */
+    public destroy(): void {
+        this.fcpObserver.disconnect();
+        this.lcpObserver.disconnect();
+    }
+
+    /**
+     * Returns defined metrics if the following conditions are satisfied:
+     *  1) it's recorded by the browser at all (some are Chrome-only, for now)
+     *  2) if it was logged *after* the Preview SDK was loaded (not buffered)
+     */
+    public report(): PerformanceReport {
+        return this.performanceReport;
+    }
+
+    protected handleFcp(list: PerformanceObserverEntryList): void {
+        const fcpEntries = list.getEntriesByName('first-contentful-paint') || [];
+        const fcpEntry = fcpEntries[0] || {};
+
+        this.performanceReport.fcp = Math.round(fcpEntry.startTime || 0);
+    }
+
+    protected handleLcp(list: PerformanceObserverEntryList): void {
+        const lcpEntries = (list.getEntriesByType('largest-contentful-paint') as PerformancePaintTiming[]) || [];
+        const lcpEntry = lcpEntries[lcpEntries.length - 1] || {};
+
+        this.performanceReport.lcp = Math.round(lcpEntry.renderTime || lcpEntry.loadTime || 0);
+    }
+}