[web] Add startup metrics (#25277)

* [web] refactor startup sequence

The primary objective here is to call loadGlobalBlobs() only once.
But to get there, we need to reorder things and add extra try/catch
sections to ensure we are not letting the global uncaughtException
handler catch startup errors.

Co-authored-by: Antoine Clausse <antoine.clausse@overleaf.com>

* [web] add metrics for startup steps

Co-authored-by: Antoine Clausse <antoine.clausse@overleaf.com>

---------

Co-authored-by: Jakob Ackermann <jakob.ackermann@overleaf.com>
GitOrigin-RevId: c73edea02516e919d55b896588dcd1862835fedf

libraries/metrics/initialize.js

@@ -5,6 +5,8 @@
  * before any other module to support code instrumentation.
  */
 
+const metricsModuleImportStartTime = performance.now()
+
 const APP_NAME = process.env.METRICS_APP_NAME || 'unknown'
 const BUILD_VERSION = process.env.BUILD_VERSION
 const ENABLE_PROFILE_AGENT = process.env.ENABLE_PROFILE_AGENT === 'true'
@@ -103,3 +105,5 @@ function recordProcessStart() {
   const metrics = require('.')
   metrics.inc('process_startup')
 }
+
+module.exports = { metricsModuleImportStartTime }

services/web/app.mjs

@@ -1,5 +1,5 @@
 // Metrics must be initialized before importing anything else
-import '@overleaf/metrics/initialize.js'
+import { metricsModuleImportStartTime } from '@overleaf/metrics/initialize.js'
 
 import Modules from './app/src/infrastructure/Modules.js'
 import metrics from '@overleaf/metrics'
@@ -20,6 +20,13 @@ import FileWriter from './app/src/infrastructure/FileWriter.js'
 import { fileURLToPath } from 'node:url'
 import Features from './app/src/infrastructure/Features.js'
 
+metrics.gauge(
+  'web_startup',
+  performance.now() - metricsModuleImportStartTime,
+  1,
+  { path: 'imports' }
+)
+
 logger.initialize(process.env.METRICS_APP_NAME || 'web')
 logger.logger.serializers.user = Serializers.user
 logger.logger.serializers.docs = Serializers.docs
@@ -58,6 +65,29 @@ if (
   )
 }
 
+// handle SIGTERM for graceful shutdown in kubernetes
+process.on('SIGTERM', function (signal) {
+  triggerGracefulShutdown(Server.server, signal)
+})
+
+const beforeWaitForMongoAndGlobalBlobs = performance.now()
+try {
+  await Promise.all([
+    mongodb.connectionPromise,
+    mongoose.connectionPromise,
+    HistoryManager.promises.loadGlobalBlobs(),
+  ])
+} catch (err) {
+  logger.fatal({ err }, 'Cannot connect to mongo. Exiting.')
+  process.exit(1)
+}
+metrics.gauge(
+  'web_startup',
+  performance.now() - beforeWaitForMongoAndGlobalBlobs,
+  1,
+  { path: 'waitForMongoAndGlobalBlobs' }
+)
+
 const port = Settings.port || Settings.internal.web.port || 3000
 const host = Settings.internal.web.host || '127.0.0.1'
 if (process.argv[1] === fileURLToPath(import.meta.url)) {
@@ -69,42 +99,33 @@ if (process.argv[1] === fileURLToPath(import.meta.url)) {
 
   PlansLocator.ensurePlansAreSetupCorrectly()
 
-  Promise.all([
-    mongodb.connectionPromise,
-    mongoose.connectionPromise,
-    HistoryManager.promises.loadGlobalBlobs(),
-  ])
-    .then(async () => {
-      Server.server.listen(port, host, function () {
-        logger.debug(`web starting up, listening on ${host}:${port}`)
-        logger.debug(`${http.globalAgent.maxSockets} sockets enabled`)
-        // wait until the process is ready before monitoring the event loop
-        metrics.event_loop.monitor(logger)
-      })
-      QueueWorkers.start()
-      await Modules.start()
-    })
-    .catch(err => {
-      logger.fatal({ err }, 'Cannot connect to mongo. Exiting.')
-      process.exit(1)
-    })
-}
+  Server.server.listen(port, host, function () {
+    logger.debug(`web starting up, listening on ${host}:${port}`)
+    logger.debug(`${http.globalAgent.maxSockets} sockets enabled`)
+    // wait until the process is ready before monitoring the event loop
+    metrics.event_loop.monitor(logger)
 
-// initialise site admin tasks
-Promise.all([
-  mongodb.connectionPromise,
-  mongoose.connectionPromise,
-  HistoryManager.promises.loadGlobalBlobs(),
-])
-  .then(() => SiteAdminHandler.initialise())
-  .catch(err => {
-    logger.fatal({ err }, 'Cannot connect to mongo. Exiting.')
-    process.exit(1)
+    // Record metrics for the total startup time before listening on HTTP.
+    metrics.gauge(
+      'web_startup',
+      performance.now() - metricsModuleImportStartTime,
+      1,
+      { path: 'metricsModuleImportToHTTPListen' }
+    )
   })
+  try {
+    QueueWorkers.start()
+  } catch (err) {
+    logger.fatal({ err }, 'failed to start queue processing')
+  }
+  try {
+    await Modules.start()
+  } catch (err) {
+    logger.fatal({ err }, 'failed to start web module background jobs')
+  }
+}
 
-// handle SIGTERM for graceful shutdown in kubernetes
-process.on('SIGTERM', function (signal) {
-  triggerGracefulShutdown(Server.server, signal)
-})
+// initialise site admin tasks
+SiteAdminHandler.initialise()
 
 export default Server.server

services/web/app/src/infrastructure/Modules.js

@@ -4,6 +4,7 @@ const { promisify, callbackify } = require('util')
 const Settings = require('@overleaf/settings')
 const Views = require('./Views')
 const _ = require('lodash')
+const Metrics = require('@overleaf/metrics')
 
 const MODULE_BASE_PATH = Path.join(__dirname, '/../../../modules')
 
@@ -15,7 +16,11 @@ let _viewIncludes = {}
 
 async function modules() {
   if (!_modulesLoaded) {
+    const beforeLoadModules = performance.now()
     await loadModules()
+    Metrics.gauge('web_startup', performance.now() - beforeLoadModules, 1, {
+      path: 'loadModules',
+    })
   }
   return _modules
 }

services/web/app/src/infrastructure/Server.mjs

@@ -372,6 +372,10 @@ if (Settings.enabledServices.includes('web')) {
 metrics.injectMetricsRoute(webRouter)
 metrics.injectMetricsRoute(privateApiRouter)
 
+const beforeRouterInitialize = performance.now()
 await Router.initialize(webRouter, privateApiRouter, publicApiRouter)
+metrics.gauge('web_startup', performance.now() - beforeRouterInitialize, 1, {
+  path: 'Router.initialize',
+})
 
 export default { app, server }