[web] gracefully access compile stats for event (#24818)

* [web] gracefully access compile stats for event

* [clsi] always emit stats and timings

GitOrigin-RevId: 959e5fe1508245ffecfab1219fd86e53b210fca1

services/clsi/app/js/CompileController.js

@@ -30,115 +30,124 @@ function compile(req, res, next) {
         if (error) {
           return next(error)
         }
-        CompileManager.doCompileWithLock(request, (error, result) => {
-          let { buildId, outputFiles, stats, timings } = result || {}
-          let code, status
-          if (outputFiles == null) {
-            outputFiles = []
-          }
-          if (error instanceof Errors.AlreadyCompilingError) {
-            code = 423 // Http 423 Locked
-            status = 'compile-in-progress'
-          } else if (error instanceof Errors.FilesOutOfSyncError) {
-            code = 409 // Http 409 Conflict
-            status = 'retry'
-            logger.warn(
-              {
+        const stats = {}
+        const timings = {}
+        CompileManager.doCompileWithLock(
+          request,
+          stats,
+          timings,
+          (error, result) => {
+            let { buildId, outputFiles } = result || {}
+            let code, status
+            if (outputFiles == null) {
+              outputFiles = []
+            }
+            if (error instanceof Errors.AlreadyCompilingError) {
+              code = 423 // Http 423 Locked
+              status = 'compile-in-progress'
+            } else if (error instanceof Errors.FilesOutOfSyncError) {
+              code = 409 // Http 409 Conflict
+              status = 'retry'
+              logger.warn(
+                {
+                  projectId: request.project_id,
+                  userId: request.user_id,
+                },
+                'files out of sync, please retry'
+              )
+            } else if (
+              error?.code === 'EPIPE' ||
+              error instanceof Errors.TooManyCompileRequestsError
+            ) {
+              // docker returns EPIPE when shutting down
+              code = 503 // send 503 Unavailable response
+              status = 'unavailable'
+            } else if (error?.terminated) {
+              status = 'terminated'
+            } else if (error?.validate) {
+              status = `validation-${error.validate}`
+            } else if (error?.timedout) {
+              status = 'timedout'
+              logger.debug(
+                { err: error, projectId: request.project_id },
+                'timeout running compile'
+              )
+            } else if (error) {
+              status = 'error'
+              code = 500
+              logger.error(
+                { err: error, projectId: request.project_id },
+                'error running compile'
+              )
+            } else {
+              if (
+                outputFiles.some(
+                  file => file.path === 'output.pdf' && file.size > 0
+                )
+              ) {
+                status = 'success'
+                lastSuccessfulCompileTimestamp = Date.now()
+              } else if (request.stopOnFirstError) {
+                status = 'stopped-on-first-error'
+              } else {
+                status = 'failure'
+                logger.warn(
+                  { projectId: request.project_id, outputFiles },
+                  'project failed to compile successfully, no output.pdf generated'
+                )
+              }
+
+              // log an error if any core files are found
+              if (outputFiles.some(file => file.path === 'core')) {
+                logger.error(
+                  { projectId: request.project_id, req, outputFiles },
+                  'core file found in output'
+                )
+              }
+            }
+
+            if (error) {
+              outputFiles = error.outputFiles || []
+              buildId = error.buildId
+            }
+
+            if (
+              status === 'success' &&
+              request.editorId &&
+              request.populateClsiCache
+            ) {
+              notifyCLSICacheAboutBuild({
                 projectId: request.project_id,
                 userId: request.user_id,
+                buildId: outputFiles[0].build,
+                editorId: request.editorId,
+                outputFiles,
+                compileGroup: request.compileGroup,
+              })
+            }
+
+            timer.done()
+            res.status(code || 200).send({
+              compile: {
+                status,
+                error: error?.message || error,
+                stats,
+                timings,
+                buildId,
+                outputUrlPrefix: Settings.apis.clsi.outputUrlPrefix,
+                outputFiles: outputFiles.map(file => ({
+                  url:
+                    `${Settings.apis.clsi.url}/project/${request.project_id}` +
+                    (request.user_id != null
+                      ? `/user/${request.user_id}`
+                      : '') +
+                    `/build/${file.build}/output/${file.path}`,
+                  ...file,
+                })),
               },
-              'files out of sync, please retry'
-            )
-          } else if (
-            error?.code === 'EPIPE' ||
-            error instanceof Errors.TooManyCompileRequestsError
-          ) {
-            // docker returns EPIPE when shutting down
-            code = 503 // send 503 Unavailable response
-            status = 'unavailable'
-          } else if (error?.terminated) {
-            status = 'terminated'
-          } else if (error?.validate) {
-            status = `validation-${error.validate}`
-          } else if (error?.timedout) {
-            status = 'timedout'
-            logger.debug(
-              { err: error, projectId: request.project_id },
-              'timeout running compile'
-            )
-          } else if (error) {
-            status = 'error'
-            code = 500
-            logger.error(
-              { err: error, projectId: request.project_id },
-              'error running compile'
-            )
-          } else {
-            if (
-              outputFiles.some(
-                file => file.path === 'output.pdf' && file.size > 0
-              )
-            ) {
-              status = 'success'
-              lastSuccessfulCompileTimestamp = Date.now()
-            } else if (request.stopOnFirstError) {
-              status = 'stopped-on-first-error'
-            } else {
-              status = 'failure'
-              logger.warn(
-                { projectId: request.project_id, outputFiles },
-                'project failed to compile successfully, no output.pdf generated'
-              )
-            }
-
-            // log an error if any core files are found
-            if (outputFiles.some(file => file.path === 'core')) {
-              logger.error(
-                { projectId: request.project_id, req, outputFiles },
-                'core file found in output'
-              )
-            }
-          }
-
-          if (error) {
-            outputFiles = error.outputFiles || []
-            buildId = error.buildId
-          }
-
-          if (
-            status === 'success' &&
-            request.editorId &&
-            request.populateClsiCache
-          ) {
-            notifyCLSICacheAboutBuild({
-              projectId: request.project_id,
-              userId: request.user_id,
-              buildId: outputFiles[0].build,
-              editorId: request.editorId,
-              outputFiles,
-              compileGroup: request.compileGroup,
             })
           }
-
-          timer.done()
-          res.status(code || 200).send({
-            compile: {
-              status,
-              error: error?.message || error,
-              stats,
-              timings,
-              buildId,
-              outputUrlPrefix: Settings.apis.clsi.outputUrlPrefix,
-              outputFiles: outputFiles.map(file => ({
-                url:
-                  `${Settings.apis.clsi.url}/project/${request.project_id}` +
-                  (request.user_id != null ? `/user/${request.user_id}` : '') +
-                  `/build/${file.build}/output/${file.path}`,
-                ...file,
-              })),
-            },
-          })
-        })
+        )
       }
     )
   })

services/clsi/app/js/CompileManager.js

@@ -46,24 +46,22 @@ function getOutputDir(projectId, userId) {
   return Path.join(Settings.path.outputDir, getCompileName(projectId, userId))
 }
 
-async function doCompileWithLock(request) {
+async function doCompileWithLock(request, stats, timings) {
   const compileDir = getCompileDir(request.project_id, request.user_id)
   request.isInitialCompile =
     (await fsPromises.mkdir(compileDir, { recursive: true })) === compileDir
   // prevent simultaneous compiles
   const lock = LockManager.acquire(compileDir)
   try {
-    return await doCompile(request)
+    return await doCompile(request, stats, timings)
   } finally {
     lock.release()
   }
 }
 
-async function doCompile(request) {
+async function doCompile(request, stats, timings) {
   const { project_id: projectId, user_id: userId } = request
   const compileDir = getCompileDir(request.project_id, request.user_id)
-  const stats = {}
-  const timings = {}
 
   const timerE2E = new Metrics.Timer(
     'compile-e2e-v2',
@@ -321,7 +319,7 @@ async function doCompile(request) {
     emitPdfStats(stats, timings, request)
   }
 
-  return { outputFiles, stats, timings, buildId }
+  return { outputFiles, buildId }
 }
 
 async function _saveOutputFiles({

services/clsi/test/acceptance/js/BrokenLatexFileTests.js

@@ -11,6 +11,7 @@
 const Client = require('./helpers/Client')
 const request = require('request')
 const ClsiApp = require('./helpers/ClsiApp')
+const { expect } = require('chai')
 
 describe('Broken LaTeX file', function () {
   before(function (done) {
@@ -62,6 +63,10 @@ Hello world
       return this.body.compile.status.should.equal('failure')
     })
 
+    it('should return isInitialCompile flag', function () {
+      expect(this.body.compile.stats.isInitialCompile).to.equal(1)
+    })
+
     it('should return output files', function () {
       // NOTE: No output.pdf file.
       this.body.compile.outputFiles
@@ -98,6 +103,10 @@ Hello world
       return this.body.compile.status.should.equal('failure')
     })
 
+    it('should not return isInitialCompile flag', function () {
+      expect(this.body.compile.stats.isInitialCompile).to.not.exist
+    })
+
     it('should return output files', function () {
       // NOTE: No output.pdf file.
       this.body.compile.outputFiles

services/clsi/test/acceptance/js/TimeoutTests.js

@@ -11,6 +11,7 @@
 const Client = require('./helpers/Client')
 const request = require('request')
 const ClsiApp = require('./helpers/ClsiApp')
+const { expect } = require('chai')
 
 describe('Timed out compile', function () {
   before(function (done) {
@@ -54,6 +55,10 @@ describe('Timed out compile', function () {
     return this.body.compile.status.should.equal('timedout')
   })
 
+  it('should return isInitialCompile flag', function () {
+    expect(this.body.compile.stats.isInitialCompile).to.equal(1)
+  })
+
   return it('should return the log output file name', function () {
     const outputFilePaths = this.body.compile.outputFiles.map(x => x.path)
     return outputFilePaths.should.include('output.log')

services/clsi/test/unit/js/CompileControllerTests.js

@@ -80,16 +80,21 @@ describe('CompileController', function () {
       this.timings = { bar: 2 }
       this.res.status = sinon.stub().returnsThis()
       this.res.send = sinon.stub()
+
+      this.CompileManager.doCompileWithLock = sinon
+        .stub()
+        .callsFake((_req, stats, timings, cb) => {
+          Object.assign(stats, this.stats)
+          Object.assign(timings, this.timings)
+          cb(null, {
+            outputFiles: this.output_files,
+            buildId: this.buildId,
+          })
+        })
     })
 
     describe('successfully', function () {
       beforeEach(function () {
-        this.CompileManager.doCompileWithLock = sinon.stub().yields(null, {
-          outputFiles: this.output_files,
-          stats: this.stats,
-          timings: this.timings,
-          buildId: this.buildId,
-        })
         this.CompileController.compile(this.req, this.res)
       })
 
@@ -133,12 +138,6 @@ describe('CompileController', function () {
     describe('without a outputUrlPrefix', function () {
       beforeEach(function () {
         this.Settings.apis.clsi.outputUrlPrefix = ''
-        this.CompileManager.doCompileWithLock = sinon.stub().yields(null, {
-          outputFiles: this.output_files,
-          stats: this.stats,
-          timings: this.timings,
-          buildId: this.buildId,
-        })
         this.CompileController.compile(this.req, this.res)
       })
 
@@ -177,33 +176,35 @@ describe('CompileController', function () {
             build: 1234,
           },
         ]
-        this.CompileManager.doCompileWithLock = sinon.stub().yields(null, {
-          outputFiles: this.output_files,
-          stats: this.stats,
-          timings: this.timings,
-          buildId: this.buildId,
-        })
+        this.CompileManager.doCompileWithLock = sinon
+          .stub()
+          .callsFake((_req, stats, timings, cb) => {
+            Object.assign(stats, this.stats)
+            Object.assign(timings, this.timings)
+            cb(null, {
+              outputFiles: this.output_files,
+              buildId: this.buildId,
+            })
+          })
         this.CompileController.compile(this.req, this.res)
       })
 
       it('should return the JSON response with status failure', function () {
         this.res.status.calledWith(200).should.equal(true)
-        this.res.send
-          .calledWith({
-            compile: {
-              status: 'failure',
-              error: null,
-              stats: this.stats,
-              timings: this.timings,
-              outputUrlPrefix: '/zone/b',
-              buildId: this.buildId,
-              outputFiles: this.output_files.map(file => ({
-                url: `${this.Settings.apis.clsi.url}/project/${this.project_id}/build/${file.build}/output/${file.path}`,
-                ...file,
-              })),
-            },
-          })
-          .should.equal(true)
+        this.res.send.should.have.been.calledWith({
+          compile: {
+            status: 'failure',
+            error: null,
+            stats: this.stats,
+            timings: this.timings,
+            outputUrlPrefix: '/zone/b',
+            buildId: this.buildId,
+            outputFiles: this.output_files.map(file => ({
+              url: `${this.Settings.apis.clsi.url}/project/${this.project_id}/build/${file.build}/output/${file.path}`,
+              ...file,
+            })),
+          },
+        })
       })
     })
 
@@ -222,33 +223,35 @@ describe('CompileController', function () {
             build: 1234,
           },
         ]
-        this.CompileManager.doCompileWithLock = sinon.stub().yields(null, {
-          outputFiles: this.output_files,
-          stats: this.stats,
-          timings: this.timings,
-          buildId: this.buildId,
-        })
+        this.CompileManager.doCompileWithLock = sinon
+          .stub()
+          .callsFake((_req, stats, timings, cb) => {
+            Object.assign(stats, this.stats)
+            Object.assign(timings, this.timings)
+            cb(null, {
+              outputFiles: this.output_files,
+              buildId: this.buildId,
+            })
+          })
         this.CompileController.compile(this.req, this.res)
       })
 
       it('should return the JSON response with status failure', function () {
         this.res.status.calledWith(200).should.equal(true)
-        this.res.send
-          .calledWith({
-            compile: {
-              status: 'failure',
-              error: null,
-              stats: this.stats,
-              buildId: this.buildId,
-              timings: this.timings,
-              outputUrlPrefix: '/zone/b',
-              outputFiles: this.output_files.map(file => ({
-                url: `${this.Settings.apis.clsi.url}/project/${this.project_id}/build/${file.build}/output/${file.path}`,
-                ...file,
-              })),
-            },
-          })
-          .should.equal(true)
+        this.res.send.should.have.been.calledWith({
+          compile: {
+            status: 'failure',
+            error: null,
+            stats: this.stats,
+            buildId: this.buildId,
+            timings: this.timings,
+            outputUrlPrefix: '/zone/b',
+            outputFiles: this.output_files.map(file => ({
+              url: `${this.Settings.apis.clsi.url}/project/${this.project_id}/build/${file.build}/output/${file.path}`,
+              ...file,
+            })),
+          },
+        })
       })
     })
 
@@ -258,7 +261,11 @@ describe('CompileController', function () {
         error.buildId = this.buildId
         this.CompileManager.doCompileWithLock = sinon
           .stub()
-          .callsArgWith(1, error, null)
+          .callsFake((_req, stats, timings, cb) => {
+            Object.assign(stats, this.stats)
+            Object.assign(timings, this.timings)
+            cb(error)
+          })
         this.CompileController.compile(this.req, this.res)
       })
 
@@ -272,9 +279,8 @@ describe('CompileController', function () {
               outputUrlPrefix: '/zone/b',
               outputFiles: [],
               buildId: this.buildId,
-              // JSON.stringify will omit these
-              stats: undefined,
-              timings: undefined,
+              stats: this.stats,
+              timings: this.timings,
             },
           })
           .should.equal(true)
@@ -288,7 +294,11 @@ describe('CompileController', function () {
         )
         this.CompileManager.doCompileWithLock = sinon
           .stub()
-          .callsArgWith(1, error, null)
+          .callsFake((_req, stats, timings, cb) => {
+            Object.assign(stats, this.stats)
+            Object.assign(timings, this.timings)
+            cb(error)
+          })
         this.CompileController.compile(this.req, this.res)
       })
 
@@ -301,9 +311,10 @@ describe('CompileController', function () {
               error: 'too many concurrent compile requests',
               outputUrlPrefix: '/zone/b',
               outputFiles: [],
+              stats: this.stats,
+              timings: this.timings,
+              // JSON.stringify will omit these undefined values
               buildId: undefined,
-              stats: undefined,
-              timings: undefined,
             },
           })
           .should.equal(true)
@@ -316,7 +327,11 @@ describe('CompileController', function () {
         this.error.timedout = true
         this.CompileManager.doCompileWithLock = sinon
           .stub()
-          .callsArgWith(1, this.error, null)
+          .callsFake((_req, stats, timings, cb) => {
+            Object.assign(stats, this.stats)
+            Object.assign(timings, this.timings)
+            cb(this.error)
+          })
         this.CompileController.compile(this.req, this.res)
       })
 
@@ -329,10 +344,10 @@ describe('CompileController', function () {
               error: this.message,
               outputUrlPrefix: '/zone/b',
               outputFiles: [],
-              // JSON.stringify will omit these
+              stats: this.stats,
+              timings: this.timings,
+              // JSON.stringify will omit these undefined values
               buildId: undefined,
-              stats: undefined,
-              timings: undefined,
             },
           })
           .should.equal(true)
@@ -343,7 +358,11 @@ describe('CompileController', function () {
       beforeEach(function () {
         this.CompileManager.doCompileWithLock = sinon
           .stub()
-          .callsArgWith(1, null, [])
+          .callsFake((_req, stats, timings, cb) => {
+            Object.assign(stats, this.stats)
+            Object.assign(timings, this.timings)
+            cb(null, {})
+          })
         this.CompileController.compile(this.req, this.res)
       })
 
@@ -356,10 +375,10 @@ describe('CompileController', function () {
               status: 'failure',
               outputUrlPrefix: '/zone/b',
               outputFiles: [],
-              // JSON.stringify will omit these
+              stats: this.stats,
+              timings: this.timings,
+              // JSON.stringify will omit these undefined values
               buildId: undefined,
-              stats: undefined,
-              timings: undefined,
             },
           })
           .should.equal(true)

services/clsi/test/unit/js/CompileManagerTests.js

@@ -199,7 +199,7 @@ describe('CompileManager', function () {
         const error = new Error('locked')
         this.LockManager.acquire.throws(error)
         await expect(
-          this.CompileManager.promises.doCompileWithLock(this.request)
+          this.CompileManager.promises.doCompileWithLock(this.request, {}, {})
         ).to.be.rejectedWith(error)
       })
 
@@ -217,7 +217,9 @@ describe('CompileManager', function () {
     describe('normally', function () {
       beforeEach(async function () {
         this.result = await this.CompileManager.promises.doCompileWithLock(
-          this.request
+          this.request,
+          {},
+          {}
         )
       })
 
@@ -271,7 +273,11 @@ describe('CompileManager', function () {
     describe('with draft mode', function () {
       beforeEach(async function () {
         this.request.draft = true
-        await this.CompileManager.promises.doCompileWithLock(this.request)
+        await this.CompileManager.promises.doCompileWithLock(
+          this.request,
+          {},
+          {}
+        )
       })
 
       it('should inject the draft mode header', function () {
@@ -284,7 +290,11 @@ describe('CompileManager', function () {
     describe('with a check option', function () {
       beforeEach(async function () {
         this.request.check = 'error'
-        await this.CompileManager.promises.doCompileWithLock(this.request)
+        await this.CompileManager.promises.doCompileWithLock(
+          this.request,
+          {},
+          {}
+        )
       })
 
       it('should run chktex', function () {
@@ -316,7 +326,11 @@ describe('CompileManager', function () {
       beforeEach(async function () {
         this.request.rootResourcePath = 'main.Rtex'
         this.request.check = 'error'
-        await this.CompileManager.promises.doCompileWithLock(this.request)
+        await this.CompileManager.promises.doCompileWithLock(
+          this.request,
+          {},
+          {}
+        )
       })
 
       it('should not run chktex', function () {
@@ -345,7 +359,7 @@ describe('CompileManager', function () {
         error.timedout = true
         this.LatexRunner.promises.runLatex.rejects(error)
         await expect(
-          this.CompileManager.promises.doCompileWithLock(this.request)
+          this.CompileManager.promises.doCompileWithLock(this.request, {}, {})
         ).to.be.rejected
       })
 
@@ -368,7 +382,7 @@ describe('CompileManager', function () {
         error.terminated = true
         this.LatexRunner.promises.runLatex.rejects(error)
         await expect(
-          this.CompileManager.promises.doCompileWithLock(this.request)
+          this.CompileManager.promises.doCompileWithLock(this.request, {}, {})
         ).to.be.rejected
       })
 

services/web/app/src/Features/Compile/CompileController.js

@@ -226,8 +226,8 @@ module.exports = CompileController = {
                 timeout: limits.timeout === 60 ? 'short' : 'long',
                 server: clsiServerId?.includes('-c2d-') ? 'faster' : 'normal',
                 isAutoCompile,
-                isInitialCompile: stats.isInitialCompile === 1,
-                restoredClsiCache: stats.restoredClsiCache === 1,
+                isInitialCompile: stats?.isInitialCompile === 1,
+                restoredClsiCache: stats?.restoredClsiCache === 1,
                 stopOnFirstError,
               }
             )