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

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(() => {

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)

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 || {}),
   }

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({})