diff --git a/services/clsi/app/js/CompileManager.js b/services/clsi/app/js/CompileManager.js index e51052c85c..3be3c3c93d 100644 --- a/services/clsi/app/js/CompileManager.js +++ b/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 - if (error.terminated || error.validate || error.timedout) { - // record timeout errors as a separate counter, success is recorded later - 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 + // record timeout errors as a separate counter, success is recorded later + if (error.timedout) { + Metrics.inc('compiles-timeout', 1, request.metricsOpts) } + + 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.sync = syncStage - 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 } + timings.output = timer.done() + return outputFiles } async function stopCompile(projectId, userId) { diff --git a/services/clsi/app/js/LatexRunner.js b/services/clsi/app/js/LatexRunner.js index bc877809c5..e8748bd4fe 100644 --- a/services/clsi/app/js/LatexRunner.js +++ b/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) => - new Promise((resolve, reject) => { - runLatex(projectId, options, (err, output, stats, timing) => { - if (err) { - reject(err) - } else { - resolve({ output, stats, timing }) - } - }) - }), + runLatex: promisify(runLatex), killLatex: promisify(killLatex), }, } diff --git a/services/clsi/test/unit/js/CompileManagerTests.js b/services/clsi/test/unit/js/CompileManagerTests.js index 128222b0b1..6e11161c02 100644 --- a/services/clsi/test/unit/js/CompileManagerTests.js +++ b/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' diff --git a/services/clsi/test/unit/js/LatexRunnerTests.js b/services/clsi/test/unit/js/LatexRunnerTests.js index 0ac3c299ec..4da40837c4 100644 --- a/services/clsi/test/unit/js/LatexRunnerTests.js +++ b/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) => { - this.timings = timings - callback(error) - } + callback ) } })