diff --git a/src/lib/Preview.js b/src/lib/Preview.js index fea3aac5e..c523cb852 100644 --- a/src/lib/Preview.js +++ b/src/lib/Preview.js @@ -753,6 +753,10 @@ class Preview extends EventEmitter { ); } + // Start the preview duration timer when the user starts to perceive preview's load + const tag = Timer.createTag(this.file.id, LOAD_METRIC.previewLoadTime); + Timer.start(tag); + // If file version ID is specified, increment retry count if it matches current file version ID if (fileVersionId) { if (fileVersionId === currentFileVersionId) { @@ -1245,8 +1249,10 @@ class Preview extends EventEmitter { */ finishLoading(data = {}) { if (this.file && this.file.id) { - const tag = Timer.createTag(this.file.id, LOAD_METRIC.fullDocumentLoadTime); - Timer.stop(tag); + const contentLoadTag = Timer.createTag(this.file.id, LOAD_METRIC.contentLoadTime); + Timer.stop(contentLoadTag); + const previewLoadTag = Timer.createTag(this.file.id, LOAD_METRIC.previewLoadTime); + Timer.stop(previewLoadTag); } // Log now that loading is finished @@ -1530,34 +1536,34 @@ class Preview extends EventEmitter { return; } - const infoTag = Timer.createTag(this.file.id, LOAD_METRIC.fileInfoTime); - const convertTag = Timer.createTag(this.file.id, LOAD_METRIC.convertTime); - const downloadTag = Timer.createTag(this.file.id, LOAD_METRIC.downloadResponseTime); - const fullLoadTag = Timer.createTag(this.file.id, LOAD_METRIC.fullDocumentLoadTime); + const { id } = this.file; + + const infoTag = Timer.createTag(id, LOAD_METRIC.fileInfoTime); + const convertTag = Timer.createTag(id, LOAD_METRIC.convertTime); + const downloadTag = Timer.createTag(id, LOAD_METRIC.downloadResponseTime); + const contentLoadTag = Timer.createTag(id, LOAD_METRIC.contentLoadTime); + const previewLoadTag = Timer.createTag(id, LOAD_METRIC.previewLoadTime); - const timerList = [ - Timer.get(infoTag) || {}, - Timer.get(convertTag) || {}, - Timer.get(downloadTag) || {}, - Timer.get(fullLoadTag) || {} - ]; - const times = timerList.map((timer) => parseInt(timer.elapsed, 10) || 0); - const total = times.reduce((acc, current) => acc + current); + const infoTime = Timer.get(infoTag) || {}; + const convertTime = Timer.get(convertTag) || {}; + const downloadTime = Timer.get(downloadTag) || {}; + const contentLoadTime = Timer.get(contentLoadTag) || {}; + const previewLoadTime = Timer.get(previewLoadTag) || {}; const event = { encoding, event_name: LOAD_METRIC.previewLoadEvent, - value: total, // Sum of all available load times. - [LOAD_METRIC.fileInfoTime]: times[0], - [LOAD_METRIC.convertTime]: times[1], - [LOAD_METRIC.downloadResponseTime]: times[2], - [LOAD_METRIC.fullDocumentLoadTime]: times[3], + 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, fullLoadTag]); + Timer.reset([infoTag, convertTag, downloadTag, contentLoadTag, previewLoadTag]); } /** diff --git a/src/lib/__tests__/Preview-test.js b/src/lib/__tests__/Preview-test.js index 6aaecae83..0da224f5e 100644 --- a/src/lib/__tests__/Preview-test.js +++ b/src/lib/__tests__/Preview-test.js @@ -1061,6 +1061,18 @@ describe('lib/Preview', () => { ); }); + it('should start a timer for the total preview load time, for the file', () => { + const id = 'my_file_id'; + const tag = Timer.createTag(id, LOAD_METRIC.previewLoadTime); + + preview.load({ id }); + + const timer = Timer.get(tag); + + expect(timer).to.exist; + expect(timer.start).to.exist; + }); + it('should get the tokens when file id is available', () => { preview.previewOptions.token = 'token'; @@ -1951,7 +1963,15 @@ describe('lib/Preview', () => { it('should stop the timer for full document load if a file exists', () => { preview.file.id = 1234; - const expectedTag = Timer.createTag(preview.file.id, LOAD_METRIC.fullDocumentLoadTime); + const expectedTag = Timer.createTag(preview.file.id, LOAD_METRIC.contentLoadTime); + sandbox.stub(Timer, 'stop'); + preview.finishLoading(); + expect(Timer.stop).to.be.calledWith(expectedTag); + }); + + it('should stop the timer for preview load if a file exists', () => { + preview.file.id = 1234; + const expectedTag = Timer.createTag(preview.file.id, LOAD_METRIC.previewLoadTime); sandbox.stub(Timer, 'stop'); preview.finishLoading(); expect(Timer.stop).to.be.calledWith(expectedTag); @@ -2299,17 +2319,11 @@ describe('lib/Preview', () => { describe('emitLoadMetrics()', () => { const fileId = 123456; - const fileInfoTag = Timer.createTag(fileId, LOAD_METRIC.fileInfoTime); beforeEach(() => { preview.file = { id: fileId }; - - // Make sure the first milestone (fileInfoTime) has been met - Timer.start(fileInfoTag); - Timer.stop(fileInfoTag); - Timer.get(fileInfoTag).elapsed = 20; }); afterEach(() => { @@ -2340,29 +2354,13 @@ describe('lib/Preview', () => { preview.emitLoadMetrics(); }); - it('should emit a preview_metric event where the value property equals the sum of all load events', (done) => { - const tag = Timer.createTag(preview.file.id, LOAD_METRIC.fullDocumentLoadTime); - Timer.start(tag); - Timer.stop(tag); - - Timer.get(tag).elapsed = 10; - Timer.get(fileInfoTag).elapsed = 20; - - const expectedTime = 30; // 10ms + 20ms - - preview.once(PREVIEW_METRIC, (metric) => { - expect(metric.value).to.equal(expectedTime); - done(); - }); - preview.emitLoadMetrics(); - }); - it('should emit a preview_metric event with an object, with all of the proper load properties', (done) => { preview.once(PREVIEW_METRIC, (metric) => { expect(metric[LOAD_METRIC.fileInfoTime]).to.exist; expect(metric[LOAD_METRIC.convertTime]).to.exist; expect(metric[LOAD_METRIC.downloadResponseTime]).to.exist; - expect(metric[LOAD_METRIC.fullDocumentLoadTime]).to.exist; + expect(metric[LOAD_METRIC.contentLoadTime]).to.exist; + expect(metric.value).to.exist; done(); }); preview.emitLoadMetrics(); @@ -2376,18 +2374,6 @@ describe('lib/Preview', () => { expect(preview.emit).to.be.called; }); - it('should default all un-hit milestones, after the first, to 0, and cast float values to ints', (done) => { - Timer.get(fileInfoTag).elapsed = 1.00001236712394687; - preview.once(PREVIEW_METRIC, (metric) => { - expect(metric[LOAD_METRIC.fileInfoTime]).to.equal(1); // Converted to int - expect(metric[LOAD_METRIC.convertTime]).to.equal(0); - expect(metric[LOAD_METRIC.downloadResponseTime]).to.equal(0); - expect(metric[LOAD_METRIC.fullDocumentLoadTime]).to.equal(0); - done(); - }); - preview.emitLoadMetrics(); - }); - it('should append encoding field to load metric, when provided', (done) => { preview.once(PREVIEW_METRIC, (metric) => { expect(metric.encoding).to.equal(ENCODING_TYPES.GZIP); diff --git a/src/lib/events.js b/src/lib/events.js index 2c37aa252..93353c71b 100644 --- a/src/lib/events.js +++ b/src/lib/events.js @@ -55,8 +55,9 @@ export const LOAD_METRIC = { fileInfoTime: 'file_info_time', // Round trip time from file info request to received file info. convertTime: 'convert_time', // Time it took from receiving file info to being able to request the rep. downloadResponseTime: 'download_response_time', // Time it took for TTFB when requesting a rep. - fullDocumentLoadTime: 'full_document_load_time', // How long it took to load the document so it could be previewed. - preloadTime: 'preload_time' // How long it takes to preload the document. + contentLoadTime: 'full_document_load_time', // How long it took to load the document so it could be previewed. + preloadTime: 'preload_time', // How long it takes to preload the document. + previewLoadTime: 'preview_loading' // Total preview load time. Maps to "value" of load event }; export const DURATION_METRIC = 'preview_duration_metric'; diff --git a/src/lib/viewers/BaseViewer.js b/src/lib/viewers/BaseViewer.js index fa5a8729e..7e56232b7 100644 --- a/src/lib/viewers/BaseViewer.js +++ b/src/lib/viewers/BaseViewer.js @@ -285,14 +285,14 @@ class BaseViewer extends EventEmitter { } /** - * Start the load timer for fullDocumentLoad event. + * Start the load timer for contentLoadTime event. * * @protected * @return {void} */ startLoadTimer() { const { file } = this.options; - const tag = Timer.createTag(file.id, LOAD_METRIC.fullDocumentLoadTime); + const tag = Timer.createTag(file.id, LOAD_METRIC.contentLoadTime); Timer.start(tag); } diff --git a/src/lib/viewers/__tests__/BaseViewer-test.js b/src/lib/viewers/__tests__/BaseViewer-test.js index 7c90019df..624a1755d 100644 --- a/src/lib/viewers/__tests__/BaseViewer-test.js +++ b/src/lib/viewers/__tests__/BaseViewer-test.js @@ -195,11 +195,11 @@ describe('lib/viewers/BaseViewer', () => { }); describe('startLoadTimer()', () => { - it('should start a timer for the fullDocumentLoadTime metric', () => { + it('should start a timer for the contentLoadTime metric', () => { base.options.file.id = '1234'; base.startLoadTimer(); - const tag = Timer.createTag(base.options.file.id, LOAD_METRIC.fullDocumentLoadTime); + const tag = Timer.createTag(base.options.file.id, LOAD_METRIC.contentLoadTime); expect(Timer.get(tag)).to.exist; }); });