[web] add retries to history calls in compile from history (#35191)

* [web] add retries to history calls in compile from history

* [web] address review feedback

GitOrigin-RevId: f22e0d1515dd22a0a43a0faf28c370e4f196e1da
This commit is contained in:
Jakob Ackermann
2026-09-17 11:17:58 +00:00
committed by Copybot
parent d2c848320e
commit 70a9069015
5 changed files with 251 additions and 107 deletions
@@ -43,6 +43,10 @@ const CLSI_COOKIES_ENABLED = (Settings.clsiCookie?.key ?? '') !== ''
// The timeout in services/clsi/app.js is 10 minutes, so we'll be on the safe side with 12 minutes
const COMPILE_REQUEST_TIMEOUT_MS = 12 * 60 * 1000
// Number of times to attempt each project-history operation (flush, chunk
// fetch) when compiling from history before giving up.
const HISTORY_MAX_ATTEMPTS = 3
// Enable clsi-cache for all compiles for 20min when detecting low capacity.
const ENABLE_COMPILE_FROM_CACHE_ON_503_MS = 20 * 60 * 1000
let enableCompileFromCacheUntil = 0
@@ -924,13 +928,57 @@ function collectGlobalBlobsFromRawSnapshot(rawSnapshot, globalBlobs) {
}
}
/**
* Run an async project-history operation.
*
* Try at most HISTORY_MAX_ATTEMPTS times before throwing an error.
*
* @template T
* @param {() => Promise<T>} fn
* @param {string} metricName
* @param {string} msg
* @param {object} info
* @return {Promise<T>}
*/
async function withRetries(fn, metricName, msg, info) {
let lastErr
for (let attempt = 1; attempt <= HISTORY_MAX_ATTEMPTS; attempt++) {
if (lastErr) {
Metrics.inc(metricName)
logger.warn({ err: lastErr, attempt, ...info }, `${msg}, retrying`)
}
try {
return await fn()
} catch (err) {
lastErr = err
}
}
throw OError.tag(lastErr, msg, info)
}
/**
* Flush pending updates to project-history before compiling from history,
* retrying on any error.
*
* @param {string} projectId
* @param {string} historyId
*/
async function _flushHistoryForCompile(projectId, historyId) {
await withRetries(
() => HistoryManager.promises.flushProject(projectId),
'compile-from-history-flush-retry',
'failed to flush project for compile-from-history',
{ projectId, historyId }
)
}
async function _buildRequestFromHistoryFull(
projectId,
historyId,
options,
project
) {
await HistoryManager.promises.flushProject(projectId)
await _flushHistoryForCompile(projectId, historyId)
const [
{
chunk: {
@@ -940,7 +988,12 @@ async function _buildRequestFromHistoryFull(
},
/* ensureNoResyncPending throws */
] = await Promise.all([
HistoryManager.promises.getLatestHistoryWithHistoryId(historyId),
withRetries(
() => HistoryManager.promises.getLatestHistoryWithHistoryId(historyId),
'compile-from-history-chunk-retry',
'failed to get history chunk',
{ projectId, historyId }
),
HistoryManager.promises.ensureNoResyncPending(projectId),
])
const rawChangeOperations = _rawChangeOperationsFromChanges(rawChanges)
@@ -965,7 +1018,7 @@ async function _buildRequestFromHistoryIncremental(
project,
baseHistoryVersion
) {
await HistoryManager.promises.flushProject(projectId)
await _flushHistoryForCompile(projectId, historyId)
const rawChangeOperations = []
let hasMore = true
let since = baseHistoryVersion
@@ -973,7 +1026,13 @@ async function _buildRequestFromHistoryIncremental(
while (hasMore) {
let changes
;[{ changes, hasMore } /* resyncPending throws */] = await Promise.all([
HistoryManager.promises.getChangesWithHistoryId(historyId, { since }),
withRetries(
() =>
HistoryManager.promises.getChangesWithHistoryId(historyId, { since }),
'compile-from-history-changes-retry',
'failed to get history changes',
{ projectId, historyId, since }
),
HistoryManager.promises.ensureNoResyncPending(projectId),
])
since += changes.length
@@ -68,6 +68,8 @@ class V1HistoryNotSyncedError extends BackwardCompatibleError {}
class ProjectHistoryDisabledError extends BackwardCompatibleError {}
class HistoryResyncPendingError extends OError {}
class V1ConnectionError extends BackwardCompatibleError {}
class UnconfirmedEmailError extends BackwardCompatibleError {}
@@ -405,6 +407,7 @@ module.exports = {
UnsupportedExportRecordsError,
V1HistoryNotSyncedError,
ProjectHistoryDisabledError,
HistoryResyncPendingError,
V1ConnectionError,
UnconfirmedEmailError,
EmailExistsError,
@@ -14,7 +14,7 @@ import ProjectGetter from '../Project/ProjectGetter.mjs'
import HistoryBackupDeletionHandler from './HistoryBackupDeletionHandler.mjs'
import { db, waitForDb } from '../../infrastructure/mongodb.mjs'
import Metrics from '@overleaf/metrics'
import { NotFoundError } from '../Errors/Errors.js'
import { NotFoundError, HistoryResyncPendingError } from '../Errors/Errors.js'
const HISTORY_V1_URL = settings.apis.v1_history.url
const HISTORY_V1_BASIC_AUTH = {
@@ -323,7 +323,11 @@ async function ensureNoResyncPending(projectId) {
const { resyncPending } = await fetchJson(
`${settings.apis.project_history.url}/project/${projectId}/resync-pending`
)
if (resyncPending) throw new OError('broken history with pending resync')
if (resyncPending) {
throw new HistoryResyncPendingError('broken history with pending resync', {
projectId,
})
}
}
async function getDebugInfo(projectId) {
@@ -3,6 +3,7 @@ import { setTimeout } from 'node:timers/promises'
import sinon from 'sinon'
import tk from 'timekeeper'
import { RequestFailedError } from '@overleaf/fetch-utils'
import Errors from '../../../../app/src/Features/Errors/Errors.js'
import _ from 'lodash'
const FILESTORE_URL = 'http://filestore.example.com'
@@ -204,6 +205,16 @@ describe('ClsiManager', function () {
ctx.HistoryManager = {
promises: {
flushProject: sinon.stub().resolves(),
getLatestHistoryWithHistoryId: sinon.stub().resolves({
chunk: {
history: { snapshot: { files: {} }, changes: [] },
startVersion: 0,
},
}),
getChangesWithHistoryId: sinon
.stub()
.resolves({ changes: [], hasMore: false }),
ensureNoResyncPending: sinon.stub().resolves(),
},
getFilestoreBlobURL: sinon.stub().callsFake((historyId, hash) => {
if (hash === GLOBAL_BLOB_HASH) {
@@ -290,6 +301,12 @@ describe('ClsiManager', function () {
default: ctx.HistoryManager,
}))
// Re-export the real Errors module so instanceof checks in ClsiManager use
// the same class instances as this test.
vi.doMock('../../../../app/src/Features/Errors/Errors.js', () => ({
default: Errors,
}))
vi.doMock(
'../../../../app/src/Features/Analytics/AnalyticsManager',
() => ({
@@ -517,10 +534,36 @@ describe('ClsiManager', function () {
})
})
describe('with compile from history fallback to incremental', function () {
describe('with compile from history', function () {
const buildId = '18fbe9e7564-30dcb2f71250c690'
beforeEach(async function (ctx) {
function makeLockedError() {
return new RequestFailedError(
'http://project-history/project/x/flush',
{ method: 'POST' },
{ status: 423 },
'{"message":"redis lock is taken"}'
)
}
function sendHistoryRequest(ctx, options = {}) {
return ctx.ClsiManager.promises.sendRequest(
null,
ctx.project._id,
ctx.user_id,
{
compileBackendClass: 'free',
compileGroup: 'standard',
timeout: 100,
compileFromHistory: true,
incrementalCompilesEnabled: true,
rootResourcePath: 'main.tex',
...options,
}
)
}
beforeEach(function (ctx) {
ctx.outputFiles = [
{
url: `/project/${ctx.project_id}/user/${ctx.user_id}/build/${buildId}/output/output.pdf`,
@@ -542,8 +585,8 @@ describe('ClsiManager', function () {
})
)
ctx.responseBody.compile.buildId = buildId
ctx.timeout = 100
ctx.HistoryManager.promises.flushProject.rejects()
// stubs for the legacy compile fallback path
const doc = ctx.docs['/main.tex']
ctx.DocumentUpdaterHandler.promises.getProjectDocsIfMatch.resolves([
{ _id: doc._id, lines: doc.lines, v: 123 },
@@ -551,119 +594,133 @@ describe('ClsiManager', function () {
ctx.ProjectEntityHandler.getAllDocPathsFromProject.returns({
'mock-doc-id-1': 'main.tex',
})
ctx.result = await ctx.ClsiManager.promises.sendRequest(
null,
ctx.project._id,
ctx.user_id,
{
compileBackendClass: 'free',
compileGroup: 'standard',
timeout: ctx.timeout,
compileFromHistory: true,
incrementalCompilesEnabled: true,
}
)
})
it('should send the request to the CLSI', function (ctx) {
const doc = ctx.docs['/main.tex']
ctx.FetchUtils.fetchStringWithResponse.should.have.been.calledWith(
sinon.match(
url =>
url.host === CLSI_HOST &&
url.pathname ===
`/project/${ctx.project._id}/user/${ctx.user_id}/compile` &&
url.searchParams.get('compileBackendClass') === 'free' &&
url.searchParams.get('compileGroup') === 'standard'
),
{
method: 'POST',
json: sinon.match({
compile: {
options: {
compiler: ctx.project.compiler,
imageName: ctx.project.imageName,
timeout: ctx.timeout,
draft: false,
compileGroup: 'standard',
metricsMethod: 'standard',
stopOnFirstError: false,
syncType: 'incremental',
syncState: '01234567890abcdef',
},
rootResourcePath: 'main.tex',
resources: [
{ path: 'main.tex', content: doc.lines.join('\n') },
],
},
}),
headers: {
Accept: 'application/json',
'Content-Type': 'application/json',
Cookie: `${ctx.clsiCookieKey}=${ctx.clsiServerId}`,
},
signal: sinon.match.instanceOf(AbortSignal),
}
)
})
describe('when the flush fails then succeeds', function () {
beforeEach(async function (ctx) {
ctx.HistoryManager.promises.flushProject
.onFirstCall()
.rejects(makeLockedError())
.onSecondCall()
.resolves()
ctx.result = await sendHistoryRequest(ctx, { baseHistoryVersion: -1 })
})
it('should compute the hash with the full project', function (ctx) {
ctx.ClsiStateManager.computeHash.should.have.been.calledWithMatch({
rootFolder: ctx.project.rootFolder,
it('should retry the flush', function (ctx) {
expect(ctx.HistoryManager.promises.flushProject.callCount).to.equal(2)
})
it('should compile from history without downgrading', function (ctx) {
expect(ctx.HistoryManager.promises.getLatestHistoryWithHistoryId).to
.have.been.called
expect(ctx.DocumentUpdaterHandler.promises.getProjectDocsIfMatch).to
.not.have.been.called
expect(ctx.result.status).to.equal('success')
})
})
it('should get the project with the required fields', function (ctx) {
ctx.ProjectGetter.promises.getProject.should.have.been.calledWith(
ctx.project._id,
{
compiler: 1,
rootDoc_id: 1,
imageName: 1,
rootFolder: 1,
'overleaf.history.id': 1,
}
)
describe('when the flush fails on every attempt', function () {
beforeEach(async function (ctx) {
// any error is retried, not just a locked (423) response
ctx.HistoryManager.promises.flushProject.rejects(new Error('boom'))
ctx.result = await sendHistoryRequest(ctx, { baseHistoryVersion: -1 })
})
it('should retry up to the maximum before giving up', function (ctx) {
expect(ctx.HistoryManager.promises.flushProject.callCount).to.equal(3)
})
it('should fall back to a legacy compile', function (ctx) {
expect(
ctx.DocumentUpdaterHandler.promises.getProjectDocsIfMatch
).to.have.been.calledWith(ctx.project._id)
expect(ctx.result.status).to.equal('success')
})
})
it('should get only the live docs from the docupdater with a background flush in docupdater', function (ctx) {
ctx.DocumentUpdaterHandler.promises.getProjectDocsIfMatch.should.have.been.calledWith(
ctx.project._id
)
describe('when getting the latest history fails once (full sync)', function () {
beforeEach(async function (ctx) {
ctx.HistoryManager.promises.getLatestHistoryWithHistoryId
.onFirstCall()
.rejects(new Error('history-v1 unavailable'))
ctx.result = await sendHistoryRequest(ctx, { baseHistoryVersion: -1 })
})
it('should retry the chunk fetch once and succeed', function (ctx) {
expect(
ctx.HistoryManager.promises.getLatestHistoryWithHistoryId.callCount
).to.equal(2)
expect(ctx.result.status).to.equal('success')
})
})
it('should not get any docs from mongo', function (ctx) {
ctx.ProjectEntityHandler.promises.getAllDocs.should.not.have.been.calledWith(
ctx.project._id
)
describe('when getting changes fails once (incremental sync)', function () {
beforeEach(async function (ctx) {
ctx.HistoryManager.promises.getChangesWithHistoryId
.onFirstCall()
.rejects(new Error('history-v1 unavailable'))
ctx.result = await sendHistoryRequest(ctx, { baseHistoryVersion: 5 })
})
it('should retry the chunk fetch once and succeed', function (ctx) {
expect(
ctx.HistoryManager.promises.getChangesWithHistoryId.callCount
).to.equal(2)
expect(ctx.result.status).to.equal('success')
})
})
it('should not get any of the files', function (ctx) {
ctx.ProjectEntityHandler.promises.getAllFiles.should.not.have.been
.called
describe('when getting the chunk fails on every attempt', function () {
beforeEach(async function (ctx) {
ctx.HistoryManager.promises.getLatestHistoryWithHistoryId.rejects(
new Error('history-v1 unavailable')
)
ctx.result = await sendHistoryRequest(ctx, { baseHistoryVersion: -1 })
})
it('should retry up to the maximum before giving up', function (ctx) {
expect(
ctx.HistoryManager.promises.getLatestHistoryWithHistoryId.callCount
).to.equal(3)
})
it('should fall back to a legacy compile', function (ctx) {
expect(
ctx.DocumentUpdaterHandler.promises.getProjectDocsIfMatch
).to.have.been.calledWith(ctx.project._id)
expect(ctx.result.status).to.equal('success')
})
})
it('should return the status and output files', function (ctx) {
expect(ctx.result.status).to.equal('success')
expect(ctx.result.outputFiles.map(f => f.path)).to.have.members(
ctx.outputFiles.map(f => f.path)
)
})
describe('when a resync is pending', function () {
beforeEach(async function (ctx) {
ctx.HistoryManager.promises.ensureNoResyncPending.rejects(
new Errors.HistoryResyncPendingError(
'broken history with pending resync'
)
)
ctx.result = await sendHistoryRequest(ctx, { baseHistoryVersion: -1 })
})
it('should return the buildId', function (ctx) {
expect(ctx.result.buildId).to.equal(buildId)
})
it('should fall back to a legacy compile', function (ctx) {
expect(
ctx.DocumentUpdaterHandler.promises.getProjectDocsIfMatch
).to.have.been.calledWith(ctx.project._id)
expect(ctx.result.status).to.equal('success')
})
it('should persist the cookie from the response', function (ctx) {
expect(
ctx.ClsiCookieManager.promises.setServerId
).to.have.been.calledWith(
ctx.project._id,
ctx.user_id,
'standard',
'free',
`${ctx.newClsiServerId}1`
)
it('should get the project with the legacy compile fields', function (ctx) {
ctx.ProjectGetter.promises.getProject.should.have.been.calledWith(
ctx.project._id,
{
compiler: 1,
rootDoc_id: 1,
imageName: 1,
rootFolder: 1,
'overleaf.history.id': 1,
}
)
})
})
})
@@ -191,6 +191,27 @@ describe('HistoryManager', function () {
})
})
describe('ensureNoResyncPending', function () {
const projectId = 'project-123'
it('should resolve when no resync is pending', async function (ctx) {
ctx.FetchUtils.fetchJson.resolves({ resyncPending: false })
await ctx.HistoryManager.promises.ensureNoResyncPending(projectId)
ctx.FetchUtils.fetchJson.should.have.been.calledWithMatch(
`${ctx.settings.apis.project_history.url}/project/${projectId}/resync-pending`
)
})
it('should throw a HistoryResyncPendingError when a resync is pending', async function (ctx) {
ctx.FetchUtils.fetchJson.resolves({ resyncPending: true })
const error = await ctx.HistoryManager.promises
.ensureNoResyncPending(projectId)
.catch(err => err)
expect(error).to.be.an('error')
expect(error.name).to.equal('HistoryResyncPendingError')
})
})
describe('injectUserDetails', function () {
beforeEach(function (ctx) {
ctx.user1 = {