Merge pull request #8757 from overleaf/em-clear-cache-on-timeout

Clear project after a compile has been interrupted

GitOrigin-RevId: 1b8e85c39843de3f63b7119f3a8a433567f57bcb

services/clsi/app/js/CompileManager.js

@@ -62,7 +62,8 @@ async function doCompileWithLock(request) {
 
 async function doCompile(request) {
   const compileDir = getCompileDir(request.project_id, request.user_id)
-  const outputDir = getOutputDir(request.project_id, request.user_id)
+  const stats = {}
+  const timings = {}
 
   const timerE2E = new Metrics.Timer(
     'compile-e2e-v2',
@@ -109,7 +110,7 @@ async function doCompile(request) {
     },
     'written files to disk'
   )
-  const syncStage = writeToDiskTimer.done()
+  timings.sync = writeToDiskTimer.done()
 
   // set up environment variables for chktex
   const env = {}
@@ -170,9 +171,8 @@ async function doCompile(request) {
   Metrics.inc(`compiles-with-image.${tag}`, 1, request.metricsOpts)
   const compileName = getCompileName(request.project_id, request.user_id)
 
-  let compileResult
   try {
-    compileResult = await LatexRunner.promises.runLatex(compileName, {
+    await LatexRunner.promises.runLatex(compileName, {
       directory: compileDir,
       mainFile: request.rootResourcePath,
       compiler: request.compiler,
@@ -182,6 +182,8 @@ async function doCompile(request) {
       environment: env,
       compileGroup: request.compileGroup,
       stopOnFirstError: request.stopOnFirstError,
+      stats,
+      timings,
     })
 
     // We use errors to return the validation state. It would be nice to use a
@@ -205,26 +207,29 @@ async function doCompile(request) {
       error.validate = 'fail'
     }
 
-    // compile was killed by user, was a validation, or a compile which failed validation
+    // record timeout errors as a separate counter, success is recorded later
-    if (error.terminated || error.validate || error.timedout) {
+    if (error.timedout) {
-      // record timeout errors as a separate counter, success is recorded later
+      Metrics.inc('compiles-timeout', 1, request.metricsOpts)
-      if (error.timedout) {
-        Metrics.inc('compiles-timeout', 1, request.metricsOpts)
-      }
-
-      const { outputFiles } = await OutputFileFinder.promises.findOutputFiles(
-        resourceList,
-        compileDir
-      )
-      error.outputFiles = outputFiles // return output files so user can check logs
     }
+
+    const outputFiles = await _saveOutputFiles({
+      request,
+      compileDir,
+      resourceList,
+      stats,
+      timings,
+    })
+    error.outputFiles = outputFiles // return output files so user can check logs
+
+    // Clear project if this compile was abruptly terminated
+    if (error.terminated || error.timedout) {
+      await clearProject(request.project_id, request.user_id)
+    }
+
     throw error
   }
 
   // compile completed normally
-  let { stats, timings } = compileResult
-  stats = stats || {}
-  timings = timings || {}
   Metrics.inc('compiles-succeeded', 1, request.metricsOpts)
   for (const metricKey in stats) {
     const metricValue = stats[metricKey]
@@ -275,11 +280,38 @@ async function doCompile(request) {
   // Emit compile time.
   timings.compile = ts
 
-  const outputStageTimer = new Metrics.Timer(
+  const outputFiles = await _saveOutputFiles({
+    request,
+    compileDir,
+    resourceList,
+    stats,
+    timings,
+  })
+
+  // Emit e2e compile time.
+  timings.compileE2E = timerE2E.done()
+  Metrics.timing('compile-e2e-v2', timings.compileE2E, 1, request.metricsOpts)
+
+  if (stats['pdf-size']) {
+    emitPdfStats(stats, timings, request)
+  }
+
+  return { outputFiles, stats, timings }
+}
+
+async function _saveOutputFiles({
+  request,
+  compileDir,
+  resourceList,
+  stats,
+  timings,
+}) {
+  const timer = new Metrics.Timer(
     'process-output-files',
     1,
     request.metricsOpts
   )
+  const outputDir = getOutputDir(request.project_id, request.user_id)
 
   let { outputFiles } = await OutputFileFinder.promises.findOutputFiles(
     resourceList,
@@ -298,19 +330,8 @@ async function doCompile(request) {
     logger.err({ projectId, userId, err }, 'failed to save output files')
   }
 
-  const outputStage = outputStageTimer.done()
+  timings.output = timer.done()
-  timings.sync = syncStage
+  return outputFiles
-  timings.output = outputStage
-
-  // Emit e2e compile time.
-  timings.compileE2E = timerE2E.done()
-  Metrics.timing('compile-e2e-v2', timings.compileE2E, 1, request.metricsOpts)
-
-  if (stats['pdf-size']) {
-    emitPdfStats(stats, timings, request)
-  }
-
-  return { outputFiles, stats, timings }
 }
 
 async function stopCompile(projectId, userId) {

services/clsi/app/js/LatexRunner.js

@@ -29,6 +29,8 @@ function runLatex(projectId, options, callback) {
     flags,
     compileGroup,
     stopOnFirstError,
+    stats,
+    timings,
   } = options
   const compiler = options.compiler || 'pdflatex'
   const timeout = options.timeout || 60000 // milliseconds
@@ -77,14 +79,12 @@ function runLatex(projectId, options, callback) {
         output?.stderr?.match(/^Run number \d+ of .*latex/gm)?.length || 0
       const failed = output?.stdout?.match(/^Latexmk: Errors/m) != null ? 1 : 0
       // counters from latexmk output
-      const stats = {}
       stats['latexmk-errors'] = failed
       stats['latex-runs'] = runs
       stats['latex-runs-with-errors'] = failed ? runs : 0
       stats[`latex-runs-${runs}`] = 1
       stats[`latex-runs-with-errors-${runs}`] = failed ? 1 : 0
       // timing information from /usr/bin/time
-      const timings = {}
       const stderr = (output && output.stderr) || ''
       if (stderr.includes('Command being timed:')) {
         // Add metrics for runs with `$ time -v ...`
@@ -97,7 +97,7 @@ function runLatex(projectId, options, callback) {
       }
       // record output files
       _writeLogOutput(projectId, directory, output, () => {
-        callback(error, output, stats, timings)
+        callback(error, output)
       })
     }
   )
@@ -194,16 +194,7 @@ module.exports = {
   runLatex,
   killLatex,
   promises: {
-    runLatex: (projectId, options) =>
+    runLatex: promisify(runLatex),
-      new Promise((resolve, reject) => {
-        runLatex(projectId, options, (err, output, stats, timing) => {
-          if (err) {
-            reject(err)
-          } else {
-            resolve({ output, stats, timing })
-          }
-        })
-      }),
     killLatex: promisify(killLatex),
   },
 }

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

@@ -1,3 +1,4 @@
+const Path = require('path')
 const SandboxedModule = require('sandboxed-module')
 const { expect } = require('chai')
 const sinon = require('sinon')
@@ -105,11 +106,21 @@ describe('CompileManager', function () {
       parseEditOutput: sinon.stub(),
     }
 
+    this.dirStats = {
+      isDirectory: sinon.stub().returns(true),
+    }
+    this.fileStats = {
+      isFile: sinon.stub().returns(true),
+    }
     this.fsPromises = {
       lstat: sinon.stub(),
       stat: sinon.stub(),
       readFile: sinon.stub(),
     }
+    this.fsPromises.lstat.withArgs(this.compileDir).resolves(this.dirStats)
+    this.fsPromises.stat
+      .withArgs(Path.join(this.compileDir, 'output.synctex.gz'))
+      .resolves(this.fileStats)
     this.fse = {
       ensureDir: sinon.stub().resolves(),
     }
@@ -198,6 +209,8 @@ describe('CompileManager', function () {
             environment: this.env,
             compileGroup: this.compileGroup,
             stopOnFirstError: this.request.stopOnFirstError,
+            stats: sinon.match.object,
+            timings: sinon.match.object,
           }
         )
       })
@@ -254,6 +267,8 @@ describe('CompileManager', function () {
             },
             compileGroup: this.compileGroup,
             stopOnFirstError: this.request.stopOnFirstError,
+            stats: sinon.match.object,
+            timings: sinon.match.object,
           }
         )
       })
@@ -279,21 +294,57 @@ describe('CompileManager', function () {
             environment: this.env,
             compileGroup: this.compileGroup,
             stopOnFirstError: this.request.stopOnFirstError,
+            stats: sinon.match.object,
+            timings: sinon.match.object,
           }
         )
       })
     })
+
+    describe('when the compile times out', function () {
+      beforeEach(async function () {
+        const error = new Error('timed out!')
+        error.timedout = true
+        this.LatexRunner.promises.runLatex.rejects(error)
+        await expect(
+          this.CompileManager.promises.doCompileWithLock(this.request)
+        ).to.be.rejected
+      })
+
+      it('should clear the compile directory', function () {
+        expect(this.child_process.execFile).to.have.been.calledWith('rm', [
+          '-r',
+          '-f',
+          '--',
+          this.compileDir,
+        ])
+      })
+    })
+
+    describe('when the compile is manually stopped', function () {
+      beforeEach(async function () {
+        const error = new Error('terminated!')
+        error.terminated = true
+        this.LatexRunner.promises.runLatex.rejects(error)
+        await expect(
+          this.CompileManager.promises.doCompileWithLock(this.request)
+        ).to.be.rejected
+      })
+
+      it('should clear the compile directory', function () {
+        expect(this.child_process.execFile).to.have.been.calledWith('rm', [
+          '-r',
+          '-f',
+          '--',
+          this.compileDir,
+        ])
+      })
+    })
   })
 
   describe('clearProject', function () {
-    describe('succesfully', function () {
+    describe('successfully', function () {
       beforeEach(async function () {
-        this.Settings.compileDir = 'compiles'
-        this.fsPromises.lstat.resolves({
-          isDirectory() {
-            return true
-          },
-        })
         await this.CompileManager.promises.clearProject(
           this.projectId,
           this.userId
@@ -312,12 +363,6 @@ describe('CompileManager', function () {
 
     describe('with a non-success status code', function () {
       beforeEach(async function () {
-        this.Settings.compileDir = 'compiles'
-        this.fsPromises.lstat.resolves({
-          isDirectory() {
-            return true
-          },
-        })
         this.child_process.execFile.yields(new Error('oops'))
         await expect(
           this.CompileManager.promises.clearProject(this.projectId, this.userId)
@@ -349,11 +394,6 @@ describe('CompileManager', function () {
 
     describe('syncFromCode', function () {
       beforeEach(function () {
-        this.fsPromises.stat.resolves({
-          isFile() {
-            return true
-          },
-        })
         this.records = [{ page: 1, h: 2, v: 3, width: 4, height: 5 }]
         this.SynctexOutputParser.parseViewOutput
           .withArgs(this.commandOutput)
@@ -434,11 +474,6 @@ describe('CompileManager', function () {
 
     describe('syncFromPdf', function () {
       beforeEach(function () {
-        this.fsPromises.stat.resolves({
-          isFile() {
-            return true
-          },
-        })
         this.records = [{ file: 'main.tex', line: 1, column: 1 }]
         this.SynctexOutputParser.parseEditOutput
           .withArgs(this.commandOutput, this.compileDir)
@@ -515,7 +550,9 @@ describe('CompileManager', function () {
   describe('wordcount', function () {
     beforeEach(async function () {
       this.stdout = 'Encoding: ascii\nWords in text: 2'
-      this.fsPromises.readFile.resolves(this.stdout)
+      this.fsPromises.readFile
+        .withArgs(Path.join(this.compileDir, 'main.tex.wc'))
+        .resolves(this.stdout)
 
       this.timeout = 60 * 1000
       this.filename = 'main.tex'

services/clsi/test/unit/js/LatexRunnerTests.js

@@ -43,6 +43,8 @@ describe('LatexRunner', function () {
     this.timeout = 42000
     this.flags = []
     this.stopOnFirstError = false
+    this.stats = {}
+    this.timings = {}
 
     this.call = function (callback) {
       this.LatexRunner.runLatex(
@@ -57,11 +59,10 @@ describe('LatexRunner', function () {
           compileGroup: this.compileGroup,
           flags: this.flags,
           stopOnFirstError: this.stopOnFirstError,
+          timings: this.timings,
+          stats: this.stats,
         },
-        (error, output, stats, timings) => {
+        callback
-          this.timings = timings
-          callback(error)
-        }
       )
     }
   })