diff --git a/src/node/db/Pad.ts b/src/node/db/Pad.ts index dba21da275e..06e2a1d9569 100644 --- a/src/node/db/Pad.ts +++ b/src/node/db/Pad.ts @@ -51,6 +51,27 @@ type PadSettings = { [pluginKey: string]: any; }; +// Prefixes an error's message with context, keeping `err.stack` in sync. +// +// `err.stack` is rendered from the message when the error is constructed, so +// assigning to `err.message` alone leaves the stack showing the original, +// context-free text. Everything that reports a failed `pad.check()` logs +// `err.stack` (Cleanup.checkTodos and the admin `cleanupPadRevisions` +// handler both do), so without this the pad/revision that actually failed +// never reaches the log and admins have to bisect the database by hand. +// See #8134. +const addErrorContext = (err: Error, context: string): Error => { + const oldMessage = err.message; + err.message = `${context} ${oldMessage}`; + // Only the first occurrence is replaced, which is the message in the + // stack's header line. Guard against an empty message: `''` matches at + // offset 0 and would corrupt the stack. + if (oldMessage && typeof err.stack === 'string' && err.stack.includes(oldMessage)) { + err.stack = err.stack.replace(oldMessage, err.message); + } + return err; +}; + const PLUGIN_KEY_RE = /^ep_[a-z0-9_]+$/; // Per-key serialized JSON size cap: ~64 KB. Pad-wide settings are persisted // with the pad and broadcast to every connected client on every change, so @@ -975,8 +996,7 @@ class Pad { isKeyRev ? this._getKeyRevisionAText(r) : null, ]); } catch (err:any) { - err.message = `(pad ${this.id} revision ${r}) ${err.message}`; - throw err; + throw addErrorContext(err, `(pad ${this.id} revision ${r})`); } }) .batch(100).buffer(99); @@ -1014,8 +1034,7 @@ class Pad { atext = applyToAText(changeset, atext, pool); if (isKeyRev) assert.deepEqual(keyAText, atext); } catch (err:any) { - err.message = `(pad ${this.id} revision ${r}) ${err.message}`; - throw err; + throw addErrorContext(err, `(pad ${this.id} revision ${r})`); } } assert.equal(this.text(), atext.text); @@ -1032,8 +1051,7 @@ class Pad { assert(msg != null); assert(msg instanceof ChatMessage); } catch (err:any) { - err.message = `(pad ${this.id} chat message ${c}) ${err.message}`; - throw err; + throw addErrorContext(err, `(pad ${this.id} chat message ${c})`); } }) .batch(100).buffer(99); diff --git a/src/tests/backend/specs/padCheckErrorContext.ts b/src/tests/backend/specs/padCheckErrorContext.ts new file mode 100644 index 00000000000..bbc3a07a740 --- /dev/null +++ b/src/tests/backend/specs/padCheckErrorContext.ts @@ -0,0 +1,109 @@ +'use strict'; + +// Regression coverage for #8134. +// +// `pad.check()` prefixes failures with `(pad revision )` so admins +// know which record is bad. Everything that reports a failed check logs +// `err.stack`, which is rendered from the message at construction time -- +// so assigning to `err.message` alone left the stack (and therefore the +// log) showing the context-free text. The reporter on #8134 had to bisect +// their database by hand to find the offending revision. + +const assert = require('assert').strict; +const common = require('../common'); +const padManager = require('../../../node/db/PadManager'); +const db = require('../../../node/db/DB'); +const {deleteRevisions} = require('../../../node/utils/Cleanup'); +const settings = require('../../../node/utils/Settings'); + +describe(__filename, function () { + let padId: string; + let cleanupEnabledBackup: boolean; + + before(async function () { + await common.init(); + cleanupEnabledBackup = settings.cleanup.enabled; + settings.cleanup.enabled = true; + }); + + after(function () { settings.cleanup.enabled = cleanupEnabledBackup; }); + + beforeEach(async function () { + padId = common.randomString(); + assert(!await padManager.doesPadExist(padId)); + }); + + // Produces the shape reported in #8134: `head` points past a revision + // whose `pad::revs:` record is absent. + const padWithMissingRevision = async (missingRev: number) => { + const pad = await padManager.getPad(padId); + for (let i = 0; i < 6; i++) await pad.appendText(`line ${i}\n`); + assert.ok(pad.getHeadRevisionNumber() > missingRev); + await db.remove(`pad:${padId}:revs:${missingRev}`, null); + padManager.unloadPad(padId); + return await padManager.getPad(padId); + }; + + describe('a missing revision', function () { + it('makes check() throw', async function () { + const pad = await padWithMissingRevision(3); + await assert.rejects(pad.check()); + }); + + it('names the pad and revision in err.message', async function () { + const pad = await padWithMissingRevision(3); + const err: any = await pad.check().then(() => null, (e: any) => e); + assert.ok(err != null, 'expected check() to throw'); + assert.match(err.message, new RegExp(`\\(pad ${padId} revision 3\\)`)); + }); + + it('names the pad and revision in err.stack too', async function () { + // This is what the admin handler and Cleanup.checkTodos actually log. + const pad = await padWithMissingRevision(3); + const err: any = await pad.check().then(() => null, (e: any) => e); + assert.ok(err != null, 'expected check() to throw'); + assert.match(err.stack, new RegExp(`\\(pad ${padId} revision 3\\)`), + `err.stack lost the revision context:\n${err.stack}`); + }); + + it('does not duplicate the context in the stack', async function () { + const pad = await padWithMissingRevision(3); + const err: any = await pad.check().then(() => null, (e: any) => e); + const occurrences = err.stack.split(`(pad ${padId} revision 3)`).length - 1; + assert.equal(occurrences, 1, `context appears ${occurrences}x in the stack`); + }); + + it('keeps the original assertion text and stack frames', async function () { + const pad = await padWithMissingRevision(3); + const err: any = await pad.check().then(() => null, (e: any) => e); + assert.match(err.stack, /assert\(timestamp != null\)/); + assert.match(err.stack, /at Pad\.check/); + }); + + it('surfaces the revision through deleteRevisions()', async function () { + // deleteRevisions() calls pad.check() before touching anything, so + // this is the exact path from the issue report. + await padWithMissingRevision(3); + padManager.unloadPad(padId); + const err: any = await deleteRevisions(padId, 2).then(() => null, (e: any) => e); + assert.ok(err != null, 'expected deleteRevisions to throw'); + assert.match(err.stack, new RegExp(`\\(pad ${padId} revision 3\\)`), + `err.stack lost the revision context:\n${err.stack}`); + }); + }); + + it('adds context for a bad chat message as well', async function () { + const pad = await padManager.getPad(padId); + await pad.appendText('hello\n'); + const author = await common.randomString(); + await pad.appendChatMessage({text: 'hi', authorId: author, time: Date.now()}); + await db.remove(`pad:${padId}:chat:0`, null); + padManager.unloadPad(padId); + + const reloaded = await padManager.getPad(padId); + const err: any = await reloaded.check().then(() => null, (e: any) => e); + assert.ok(err != null, 'expected check() to throw'); + assert.match(err.stack, new RegExp(`\\(pad ${padId} chat message 0\\)`), + `err.stack lost the chat context:\n${err.stack}`); + }); +});