Skip to content

Commit

Permalink
feat(perf): Add new event to report modern performance metrics (#1138)
Browse files Browse the repository at this point in the history
Co-authored-by: mergify[bot] <37929162+mergify[bot]@users.noreply.github.com>
  • Loading branch information
jstoffan and mergify[bot] committed Jan 9, 2020
1 parent f3b8b8a commit 8f9d0a3
Show file tree
Hide file tree
Showing 6 changed files with 345 additions and 107 deletions.
129 changes: 76 additions & 53 deletions src/lib/Preview.js
Original file line number Diff line number Diff line change
Expand Up @@ -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';
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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);
Expand All @@ -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();

Expand Down Expand Up @@ -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);
});
}

/**
Expand Down Expand Up @@ -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);
});
}

/**
Expand Down Expand Up @@ -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
Expand All @@ -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);
Expand Down Expand Up @@ -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.
*
Expand All @@ -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);
});
}

/**
Expand Down Expand Up @@ -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.
*
Expand Down
73 changes: 73 additions & 0 deletions src/lib/PreviewPerf.ts
Original file line number Diff line number Diff line change
@@ -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);
}
}
Loading

0 comments on commit 8f9d0a3

Please sign in to comment.