From 985ad8ff5b9cbae70ce7ee210f6a29f6c205f0d9 Mon Sep 17 00:00:00 2001 From: Jakob Ackermann Date: Mon, 18 Jul 2022 11:24:31 +0100 Subject: [PATCH] Merge pull request #8879 from overleaf/jpa-fix-pdf-detach-delivery-latency [web] collect fetch and render latency in the scope of the viewer GitOrigin-RevId: 3bf6c5ffc01df705605c873a130f0a645fdc66c4 --- .../pdf-preview/components/pdf-js-viewer.js | 91 +++++++++++-------- .../js/features/pdf-preview/util/compiler.js | 3 +- .../js/features/pdf-preview/util/metrics.js | 46 ++++------ .../shared/context/local-compile-context.js | 4 +- 4 files changed, 74 insertions(+), 70 deletions(-) diff --git a/services/web/frontend/js/features/pdf-preview/components/pdf-js-viewer.js b/services/web/frontend/js/features/pdf-preview/components/pdf-js-viewer.js index 1f81ddb633..fc6fc8c09b 100644 --- a/services/web/frontend/js/features/pdf-preview/components/pdf-js-viewer.js +++ b/services/web/frontend/js/features/pdf-preview/components/pdf-js-viewer.js @@ -57,54 +57,69 @@ function PdfJsViewer({ url, pdfFile }) { [setError] ) - // fetch and render times - const times = useRef({}) + const [startFetch, setStartFetch] = useState(0) - // listen for initialize event + // listen for events and trigger rendering. + // Do everything in one effect to mitigate de-sync between events. useEffect(() => { - if (pdfJsWrapper && firstRenderDone) { - const handlePagesinit = () => { - setInitialised(true) - times.current.timePDFFetched = performance.now() - const visible = !document.hidden - if (!visible) { - // Rendering does not start in case we are hidden. - firstRenderDone(times.current) - } - } - // `pagesinit` fires when the data for rendering the first page is ready. - pdfJsWrapper.eventBus.on('pagesinit', handlePagesinit) - return () => pdfJsWrapper.eventBus.off('pagesinit', handlePagesinit) - } - }, [pdfJsWrapper, firstRenderDone, times]) + if (!pdfJsWrapper || !firstRenderDone) return - // list for page rendered event - useEffect(() => { - if (pdfJsWrapper && firstRenderDone) { - const handleRendered = () => { - const visible = !document.hidden - if (!visible) { - // The render time is not accurate in case we are hidden. - firstRenderDone(times.current) - } else { - times.current.timePDFRendered = performance.now() - firstRenderDone(times.current) - } - // Only get the times for the first page. - pdfJsWrapper.eventBus.off('pagerendered', handleRendered) + let timePDFFetched + let timePDFRendered + const submitLatencies = () => { + if (!timePDFFetched) { + // The pagerendered event was attached after pagesinit fired. :/ + return } - // `pagerendered` fires when a page was actually rendered. - pdfJsWrapper.eventBus.on('pagerendered', handleRendered) - return () => pdfJsWrapper.eventBus.off('pagerendered', handleRendered) + + const latencyFetch = Math.ceil(timePDFFetched - startFetch) + let latencyRender + if (timePDFRendered) { + // The renderer does not yield in case the browser tab is hidden. + // It will yield when the browser tab is visible again. + // This will skew our performance metrics for rendering! + // We are omitting the render time in case we detect this state. + latencyRender = Math.ceil(timePDFRendered - timePDFFetched) + } + firstRenderDone({ latencyFetch, latencyRender }) } - }, [pdfJsWrapper, firstRenderDone, times]) + + const handlePagesinit = () => { + setInitialised(true) + timePDFFetched = performance.now() + if (document.hidden) { + // Rendering does not start in case we are hidden. See comment above. + submitLatencies() + } + } + + const handleRendered = () => { + if (!document.hidden) { + // The render time is not accurate in case we are hidden. See above. + timePDFRendered = performance.now() + } + submitLatencies() + + // Only get the times for the first page. + pdfJsWrapper.eventBus.off('pagerendered', handleRendered) + } + + // `pagesinit` fires when the data for rendering the first page is ready. + pdfJsWrapper.eventBus.on('pagesinit', handlePagesinit) + // `pagerendered` fires when a page was actually rendered. + pdfJsWrapper.eventBus.on('pagerendered', handleRendered) + return () => { + pdfJsWrapper.eventBus.off('pagesinit', handlePagesinit) + pdfJsWrapper.eventBus.off('pagerendered', handleRendered) + } + }, [pdfJsWrapper, firstRenderDone, startFetch]) // load the PDF document from the URL useEffect(() => { if (pdfJsWrapper && url) { setInitialised(false) setError(undefined) - times.current = {} + setStartFetch(performance.now()) pdfJsWrapper.loadDocument(url, pdfFile).catch(error => { console.error(error) @@ -112,7 +127,7 @@ function PdfJsViewer({ url, pdfFile }) { }) return () => pdfJsWrapper.abortDocumentLoading() } - }, [pdfJsWrapper, url, pdfFile, setError, times]) + }, [pdfJsWrapper, url, pdfFile, setError, setStartFetch]) // listen for scroll events useEffect(() => { diff --git a/services/web/frontend/js/features/pdf-preview/util/compiler.js b/services/web/frontend/js/features/pdf-preview/util/compiler.js index 4a78f4a459..f0736ce723 100644 --- a/services/web/frontend/js/features/pdf-preview/util/compiler.js +++ b/services/web/frontend/js/features/pdf-preview/util/compiler.js @@ -105,7 +105,8 @@ export default class DocumentCompiler { const compileTimeClientE2E = Math.ceil(performance.now() - t0) const { deliveryLatencies, firstRenderDone } = trackPdfDownload( data, - compileTimeClientE2E + compileTimeClientE2E, + t0 ) this.setDeliveryLatencies(() => deliveryLatencies) this.setFirstRenderDone(() => firstRenderDone) diff --git a/services/web/frontend/js/features/pdf-preview/util/metrics.js b/services/web/frontend/js/features/pdf-preview/util/metrics.js index 84c3ebc66e..6068c04fc6 100644 --- a/services/web/frontend/js/features/pdf-preview/util/metrics.js +++ b/services/web/frontend/js/features/pdf-preview/util/metrics.js @@ -15,45 +15,36 @@ export function setCachingMetrics(metrics) { pdfCachingMetrics = metrics } -export function trackPdfDownload(response, compileTimeClientE2E) { - const { stats, timings } = response +export function trackPdfDownload(response, compileTimeClientE2E, t0) { + const { timings } = response - const t0 = performance.now() const deliveryLatencies = { compileTimeClientE2E, compileTimeServerE2E: timings?.compileE2E, } - function firstRenderDone({ timePDFFetched, timePDFRendered }) { - const latencyFetch = Math.ceil(timePDFFetched - t0) + // There can be multiple "first" renderings with two pdf viewers. + // E.g. two pdf detach tabs or pdf detacher plus pdf detach. + let isFirstRender = true + function firstRenderDone({ latencyFetch, latencyRender }) { + if (!isFirstRender) return + isFirstRender = false + + const totalDeliveryTime = Math.ceil(performance.now() - t0) + deliveryLatencies.totalDeliveryTime = totalDeliveryTime deliveryLatencies.latencyFetch = latencyFetch - // The renderer does not yield in case the browser tab is hidden. - // It will yield when the browser tab is visible again. - // This will skew our performance metrics for rendering! - // We are omitting the render time in case we detect this state. - let latencyRender - if (timePDFRendered) { - latencyRender = Math.ceil(timePDFRendered - timePDFFetched) + if (latencyRender) { deliveryLatencies.latencyRender = latencyRender } - done({ latencyFetch, latencyRender }) - } - let done - const onFirstRenderDone = new Promise(resolve => { - done = resolve - }) - - if (getMeta('ol-trackPdfDownload')) { - // Submit latency along with compile context. - onFirstRenderDone.then(({ latencyFetch, latencyRender }) => { + if (getMeta('ol-trackPdfDownload')) { + // Submit latency along with compile context. submitCompileMetrics({ + totalDeliveryTime, latencyFetch, latencyRender, compileTimeClientE2E, - stats, - timings, }) - }) + } } return { @@ -63,12 +54,9 @@ export function trackPdfDownload(response, compileTimeClientE2E) { } function submitCompileMetrics(metrics) { - const { latencyFetch, latencyRender, compileTimeClientE2E } = metrics const leanMetrics = { version: VERSION, - latencyFetch, - latencyRender, - compileTimeClientE2E, + ...metrics, id: EDITOR_SESSION_ID, ...(pdfCachingMetrics || {}), } diff --git a/services/web/frontend/js/shared/context/local-compile-context.js b/services/web/frontend/js/shared/context/local-compile-context.js index a56fe7b113..bcae753c88 100644 --- a/services/web/frontend/js/shared/context/local-compile-context.js +++ b/services/web/frontend/js/shared/context/local-compile-context.js @@ -71,7 +71,7 @@ export const CompileContextPropTypes = { stoppedOnFirstError: PropTypes.bool.isRequired, uncompiled: PropTypes.bool, validationIssues: PropTypes.object, - firstRenderDone: PropTypes.func, + firstRenderDone: PropTypes.func.isRequired, cleanupCompileResult: PropTypes.func, }), } @@ -128,7 +128,7 @@ export function LocalCompileProvider({ children }) { const [data, setData] = useState() // callback to be invoked for PdfJsMetrics - const [firstRenderDone, setFirstRenderDone] = useState() + const [firstRenderDone, setFirstRenderDone] = useState(() => () => {}) // latencies of compile/pdf download/rendering const [deliveryLatencies, setDeliveryLatencies] = useState({})