Merge pull request #253 from overleaf/jpa-debug-slow-pdf-caching

[misc] ContentCacheMetrics: log slow pdf caching performance

services/clsi/app/js/ContentCacheMetrics.js

@@ -1,4 +1,20 @@
+const logger = require('logger-sharelatex')
 const Metrics = require('./Metrics')
+const os = require('os')
+
+let CACHED_LOAD = {
+  expires: -1,
+  load: [0, 0, 0]
+}
+function getSystemLoad() {
+  if (CACHED_LOAD.expires < Date.now()) {
+    CACHED_LOAD = {
+      expires: Date.now() + 10 * 1000,
+      load: os.loadavg()
+    }
+  }
+  return CACHED_LOAD.load
+}
 
 const ONE_MB = 1024 * 1024
 
@@ -14,12 +30,25 @@ function emitPdfStats(stats, timings) {
 function emitPdfCachingStats(stats, timings) {
   if (!stats['pdf-size']) return // double check
 
+  // How much extra time did we spent in PDF.js?
+  Metrics.timing('compute-pdf-caching', timings['compute-pdf-caching'])
+
   // How large is the overhead of hashing up-front?
   const fraction =
     timings.compileE2E - timings['compute-pdf-caching'] !== 0
       ? timings.compileE2E /
         (timings.compileE2E - timings['compute-pdf-caching'])
       : 1
+  if (fraction > 1.5 && timings.compileE2E > 10 * 1000) {
+    logger.warn(
+      {
+        stats,
+        timings,
+        load: getSystemLoad()
+      },
+      'slow pdf caching'
+    )
+  }
   Metrics.summary('overhead-compute-pdf-ranges', fraction * 100 - 100)
 
   // How does the hashing scale to pdf size in MB?