From 0d1332e0dcef531fe68d4f68ff6d811293d03a9c Mon Sep 17 00:00:00 2001 From: Sean Steimer Date: Mon, 6 Jul 2026 09:52:11 -0700 Subject: [PATCH 1/5] fix(test): stub setTimeout in audit 412-retry test to prevent timeout flake writeAuditEntry retries PUT 412s with real exponential-jitter delays (worst case ~3050ms), which raced mocha's 2000ms default test timeout and intermittently failed CI. Stub setTimeout to fire immediately, same pattern already used by the neighboring backoff-assertion test. Co-Authored-By: Claude Sonnet 5 --- test/storage/version/audit.test.js | 69 ++++++++++++++++++------------ 1 file changed, 41 insertions(+), 28 deletions(-) diff --git a/test/storage/version/audit.test.js b/test/storage/version/audit.test.js index f8d04ca0..953ccf20 100644 --- a/test/storage/version/audit.test.js +++ b/test/storage/version/audit.test.js @@ -815,6 +815,14 @@ describe('Version Audit', () => { }); it('returns status 500 when PUT 412 persists across all 7 attempts', async () => { + // Stubs setTimeout so the ~3050ms worst-case retry backoff (see + // audit.js) doesn't race mocha's 2000ms default test timeout. + const originalSetTimeout = globalThis.setTimeout; + globalThis.setTimeout = (fn) => { + fn(); + return 0; + }; + let getCallCount = 0; let putCallCount = 0; @@ -825,37 +833,42 @@ describe('Version Audit', () => { }, }); - const { writeAuditEntry } = await esmock( - '../../../src/storage/version/audit.js', - { - '@aws-sdk/client-s3': { - S3Client: function S3Client() { - this.send = async (cmd) => { - if (cmd instanceof GetObjectCommand) { - getCallCount += 1; - return { Body: makeBody(), ETag: '"etag-x"' }; - } - if (cmd instanceof PutObjectCommand) { - putCallCount += 1; - const err = new Error('precondition failed'); - err.$metadata = { httpStatusCode: 412 }; - throw err; - } - return { $metadata: { httpStatusCode: 200 } }; - }; + let result; + try { + const { writeAuditEntry } = await esmock( + '../../../src/storage/version/audit.js', + { + '@aws-sdk/client-s3': { + S3Client: function S3Client() { + this.send = async (cmd) => { + if (cmd instanceof GetObjectCommand) { + getCallCount += 1; + return { Body: makeBody(), ETag: '"etag-x"' }; + } + if (cmd instanceof PutObjectCommand) { + putCallCount += 1; + const err = new Error('precondition failed'); + err.$metadata = { httpStatusCode: 412 }; + throw err; + } + return { $metadata: { httpStatusCode: 200 } }; + }; + }, + GetObjectCommand, + PutObjectCommand, }, - GetObjectCommand, - PutObjectCommand, + '../../../src/storage/utils/config.js': { default: () => ({}) }, }, - '../../../src/storage/utils/config.js': { default: () => ({}) }, - }, - ); + ); - const result = await writeAuditEntry({}, { bucket: 'b', org: 'o' }, 'repo', 'fid', { - timestamp: '5000', - users: '[{"email":"u@x.com"}]', - path: 'repo/doc.html', - }); + result = await writeAuditEntry({}, { bucket: 'b', org: 'o' }, 'repo', 'fid', { + timestamp: '5000', + users: '[{"email":"u@x.com"}]', + path: 'repo/doc.html', + }); + } finally { + globalThis.setTimeout = originalSetTimeout; + } assert.strictEqual(result.status, 500, 'persistent 412 must surface as 500 after 7 total attempts'); assert.strictEqual(result.error, 'precondition failed'); From ed6e0891c4ebd8ee2a5ac54416896bd6cf217329 Mon Sep 17 00:00:00 2001 From: Sean Steimer Date: Mon, 6 Jul 2026 10:00:06 -0700 Subject: [PATCH 2/5] refactor(test): consolidate 412 retry backoff tests under shared setTimeout hooks The three 412-retry tests each stubbed/restored setTimeout independently, duplicating the same save/restore boilerplate and risking future tests forgetting to restore it. Group them under a nested describe('412 retry backoff') with beforeEach/afterEach owning save/restore of the setTimeout reference; each test still installs whatever replacement behavior it needs (plain fire-immediately vs. delay-capturing for the jitter assertions). Also removes real-timer usage from 'succeeds on the 5th attempt after four 412s', which previously took ~500-700ms per run. Co-Authored-By: Claude Sonnet 5 --- test/storage/version/audit.test.js | 272 +++++++++++++++-------------- 1 file changed, 143 insertions(+), 129 deletions(-) diff --git a/test/storage/version/audit.test.js b/test/storage/version/audit.test.js index 953ccf20..877dd669 100644 --- a/test/storage/version/audit.test.js +++ b/test/storage/version/audit.test.js @@ -814,27 +814,40 @@ describe('Version Audit', () => { assert.strictEqual(lines.length, 2, 'both entries must be present (no collapse across mismatched users)'); }); - it('returns status 500 when PUT 412 persists across all 7 attempts', async () => { - // Stubs setTimeout so the ~3050ms worst-case retry backoff (see - // audit.js) doesn't race mocha's 2000ms default test timeout. - const originalSetTimeout = globalThis.setTimeout; - globalThis.setTimeout = (fn) => { - fn(); - return 0; - }; - - let getCallCount = 0; - let putCallCount = 0; + describe('412 retry backoff', () => { + // These tests exercise the real retry loop in writeAuditEntry, which + // sleeps between attempts with real exponential-jitter setTimeout + // delays (worst case ~3050ms across 6 retries, see audit.js). Real + // delays here would race mocha's 2000ms default test timeout, so every + // test in this block stubs setTimeout to fire immediately. The hook + // only owns save/restore of the reference — each test installs + // whatever replacement behavior it needs (some also capture delays). + let originalSetTimeout; + + beforeEach(() => { + originalSetTimeout = globalThis.setTimeout; + }); - const makeBody = () => new ReadableStream({ - start(controller) { - controller.enqueue(new TextEncoder().encode('')); - controller.close(); - }, + afterEach(() => { + globalThis.setTimeout = originalSetTimeout; }); - let result; - try { + it('returns status 500 when PUT 412 persists across all 7 attempts', async () => { + globalThis.setTimeout = (fn) => { + fn(); + return 0; + }; + + let getCallCount = 0; + let putCallCount = 0; + + const makeBody = () => new ReadableStream({ + start(controller) { + controller.enqueue(new TextEncoder().encode('')); + controller.close(); + }, + }); + const { writeAuditEntry } = await esmock( '../../../src/storage/version/audit.js', { @@ -861,36 +874,112 @@ describe('Version Audit', () => { }, ); - result = await writeAuditEntry({}, { bucket: 'b', org: 'o' }, 'repo', 'fid', { + const result = await writeAuditEntry({}, { bucket: 'b', org: 'o' }, 'repo', 'fid', { timestamp: '5000', users: '[{"email":"u@x.com"}]', path: 'repo/doc.html', }); - } finally { - globalThis.setTimeout = originalSetTimeout; - } - assert.strictEqual(result.status, 500, 'persistent 412 must surface as 500 after 7 total attempts'); - assert.strictEqual(result.error, 'precondition failed'); - assert.strictEqual(putCallCount, 7, 'must attempt PUT 7 times total (1 initial + 6 retries)'); - assert.strictEqual(getCallCount, 7, 'must re-read on each attempt'); - }); + assert.strictEqual(result.status, 500, 'persistent 412 must surface as 500 after 7 total attempts'); + assert.strictEqual(result.error, 'precondition failed'); + assert.strictEqual(putCallCount, 7, 'must attempt PUT 7 times total (1 initial + 6 retries)'); + assert.strictEqual(getCallCount, 7, 'must re-read on each attempt'); + }); - it('uses exponential jitter backoff (0-50, 0-100, 0-200, 0-400, 0-800, 0-1600 ms) across six 412 retries', async () => { - // Stubs setTimeout and Math.random to capture per-retry delays. - // Asserts per-attempt exponential upper bounds for the 6-retry ladder - // (50, 100, 200, 400, 800, 1600 ms) and total elapsed sleep ~3050 ms. - const originalSetTimeout = globalThis.setTimeout; - const originalRandom = Math.random; - const delays = []; - Math.random = () => 0.999999; - globalThis.setTimeout = (fn, ms) => { - delays.push(ms); - fn(); - return 0; - }; + it('uses exponential jitter backoff (0-50, 0-100, 0-200, 0-400, 0-800, 0-1600 ms) across six 412 retries', async () => { + // Also stubs Math.random to capture per-retry delays. Asserts + // per-attempt exponential upper bounds for the 6-retry ladder + // (50, 100, 200, 400, 800, 1600 ms) and total elapsed sleep ~3050 ms. + const originalRandom = Math.random; + const delays = []; + Math.random = () => 0.999999; + globalThis.setTimeout = (fn, ms) => { + delays.push(ms); + fn(); + return 0; + }; + + try { + const makeBody = () => new ReadableStream({ + start(controller) { + controller.enqueue(new TextEncoder().encode('')); + controller.close(); + }, + }); + + const { writeAuditEntry } = await esmock( + '../../../src/storage/version/audit.js', + { + '@aws-sdk/client-s3': { + S3Client: function S3Client() { + this.send = async (cmd) => { + if (cmd instanceof GetObjectCommand) { + return { Body: makeBody(), ETag: '"etag-x"' }; + } + if (cmd instanceof PutObjectCommand) { + const err = new Error('precondition failed'); + err.$metadata = { httpStatusCode: 412 }; + throw err; + } + return { $metadata: { httpStatusCode: 200 } }; + }; + }, + GetObjectCommand, + PutObjectCommand, + }, + '../../../src/storage/utils/config.js': { default: () => ({}) }, + }, + ); + + await writeAuditEntry({}, { bucket: 'b', org: 'o' }, 'repo', 'fid', { + timestamp: '5000', + users: '[{"email":"u@x.com"}]', + path: 'repo/doc.html', + }); + } finally { + Math.random = originalRandom; + } + + assert.strictEqual(delays.length, 6, 'must sleep between each of the 6 retries'); + const upperBounds = [50, 100, 200, 400, 800, 1600]; + delays.forEach((ms, i) => { + assert.ok( + ms >= 0 && ms < upperBounds[i], + `delay[${i}]=${ms} must be within [0, ${upperBounds[i]})`, + ); + }); + assert.ok( + delays[2] >= 150, + `delay[2]=${delays[2]} must exceed the prior linear cap of 150 ms`, + ); + assert.ok( + delays[3] >= 200, + `delay[3]=${delays[3]} must exceed the prior linear cap of 200 ms`, + ); + assert.ok( + delays[5] >= 800, + `delay[5]=${delays[5]} must reach the new 6-retry exponential ceiling (>=800 ms)`, + ); + const total = delays.reduce((a, b) => a + b, 0); + assert.ok( + total > 1500, + `total elapsed sleep ${total} must exceed prior 4-retry worst-case (~750 ms)`, + ); + assert.ok( + total < 3200, + `total elapsed sleep ${total} must stay within the new 6-retry worst-case (~3050 ms)`, + ); + }); + + it('succeeds on the 5th attempt after four 412s', async () => { + globalThis.setTimeout = (fn) => { + fn(); + return 0; + }; + + let getCallCount = 0; + let putCallCount = 0; - try { const makeBody = () => new ReadableStream({ start(controller) { controller.enqueue(new TextEncoder().encode('')); @@ -905,12 +994,17 @@ describe('Version Audit', () => { S3Client: function S3Client() { this.send = async (cmd) => { if (cmd instanceof GetObjectCommand) { - return { Body: makeBody(), ETag: '"etag-x"' }; + getCallCount += 1; + return { Body: makeBody(), ETag: `"etag-${getCallCount}"` }; } if (cmd instanceof PutObjectCommand) { - const err = new Error('precondition failed'); - err.$metadata = { httpStatusCode: 412 }; - throw err; + putCallCount += 1; + if (putCallCount < 5) { + const err = new Error('precondition failed'); + err.$metadata = { httpStatusCode: 412 }; + throw err; + } + return { $metadata: { httpStatusCode: 200 } }; } return { $metadata: { httpStatusCode: 200 } }; }; @@ -922,96 +1016,16 @@ describe('Version Audit', () => { }, ); - await writeAuditEntry({}, { bucket: 'b', org: 'o' }, 'repo', 'fid', { + const result = await writeAuditEntry({}, { bucket: 'b', org: 'o' }, 'repo', 'fid', { timestamp: '5000', users: '[{"email":"u@x.com"}]', path: 'repo/doc.html', }); - } finally { - globalThis.setTimeout = originalSetTimeout; - Math.random = originalRandom; - } - assert.strictEqual(delays.length, 6, 'must sleep between each of the 6 retries'); - const upperBounds = [50, 100, 200, 400, 800, 1600]; - delays.forEach((ms, i) => { - assert.ok( - ms >= 0 && ms < upperBounds[i], - `delay[${i}]=${ms} must be within [0, ${upperBounds[i]})`, - ); + assert.strictEqual(result.status, 200, 'must succeed on the 5th attempt'); + assert.strictEqual(putCallCount, 5, 'must have attempted PUT 5 times'); + assert.strictEqual(getCallCount, 5, 'must re-read on each attempt'); }); - assert.ok( - delays[2] >= 150, - `delay[2]=${delays[2]} must exceed the prior linear cap of 150 ms`, - ); - assert.ok( - delays[3] >= 200, - `delay[3]=${delays[3]} must exceed the prior linear cap of 200 ms`, - ); - assert.ok( - delays[5] >= 800, - `delay[5]=${delays[5]} must reach the new 6-retry exponential ceiling (>=800 ms)`, - ); - const total = delays.reduce((a, b) => a + b, 0); - assert.ok( - total > 1500, - `total elapsed sleep ${total} must exceed prior 4-retry worst-case (~750 ms)`, - ); - assert.ok( - total < 3200, - `total elapsed sleep ${total} must stay within the new 6-retry worst-case (~3050 ms)`, - ); - }); - - it('succeeds on the 5th attempt after four 412s', async () => { - let getCallCount = 0; - let putCallCount = 0; - - const makeBody = () => new ReadableStream({ - start(controller) { - controller.enqueue(new TextEncoder().encode('')); - controller.close(); - }, - }); - - const { writeAuditEntry } = await esmock( - '../../../src/storage/version/audit.js', - { - '@aws-sdk/client-s3': { - S3Client: function S3Client() { - this.send = async (cmd) => { - if (cmd instanceof GetObjectCommand) { - getCallCount += 1; - return { Body: makeBody(), ETag: `"etag-${getCallCount}"` }; - } - if (cmd instanceof PutObjectCommand) { - putCallCount += 1; - if (putCallCount < 5) { - const err = new Error('precondition failed'); - err.$metadata = { httpStatusCode: 412 }; - throw err; - } - return { $metadata: { httpStatusCode: 200 } }; - } - return { $metadata: { httpStatusCode: 200 } }; - }; - }, - GetObjectCommand, - PutObjectCommand, - }, - '../../../src/storage/utils/config.js': { default: () => ({}) }, - }, - ); - - const result = await writeAuditEntry({}, { bucket: 'b', org: 'o' }, 'repo', 'fid', { - timestamp: '5000', - users: '[{"email":"u@x.com"}]', - path: 'repo/doc.html', - }); - - assert.strictEqual(result.status, 200, 'must succeed on the 5th attempt'); - assert.strictEqual(putCallCount, 5, 'must have attempted PUT 5 times'); - assert.strictEqual(getCallCount, 5, 'must re-read on each attempt'); }); }); }); From 6e9f78ee81c8a297909e49729b855f7f6d1d3e36 Mon Sep 17 00:00:00 2001 From: Sean Steimer Date: Mon, 6 Jul 2026 10:06:16 -0700 Subject: [PATCH 3/5] style(test): trim verbose comments in audit 412-retry tests Co-Authored-By: Claude Sonnet 5 --- test/storage/version/audit.test.js | 13 +++---------- 1 file changed, 3 insertions(+), 10 deletions(-) diff --git a/test/storage/version/audit.test.js b/test/storage/version/audit.test.js index 877dd669..30e241f2 100644 --- a/test/storage/version/audit.test.js +++ b/test/storage/version/audit.test.js @@ -815,13 +815,8 @@ describe('Version Audit', () => { }); describe('412 retry backoff', () => { - // These tests exercise the real retry loop in writeAuditEntry, which - // sleeps between attempts with real exponential-jitter setTimeout - // delays (worst case ~3050ms across 6 retries, see audit.js). Real - // delays here would race mocha's 2000ms default test timeout, so every - // test in this block stubs setTimeout to fire immediately. The hook - // only owns save/restore of the reference — each test installs - // whatever replacement behavior it needs (some also capture delays). + // Real retry delays (~3050ms worst case) would exceed mocha's 2000ms + // timeout, so each test stubs setTimeout; the hook just restores it. let originalSetTimeout; beforeEach(() => { @@ -887,9 +882,7 @@ describe('Version Audit', () => { }); it('uses exponential jitter backoff (0-50, 0-100, 0-200, 0-400, 0-800, 0-1600 ms) across six 412 retries', async () => { - // Also stubs Math.random to capture per-retry delays. Asserts - // per-attempt exponential upper bounds for the 6-retry ladder - // (50, 100, 200, 400, 800, 1600 ms) and total elapsed sleep ~3050 ms. + // Also stubs Math.random to capture per-retry delays. const originalRandom = Math.random; const delays = []; Math.random = () => 0.999999; From 03354dee2d2a002656e8d6d5a7baafaa5afb660a Mon Sep 17 00:00:00 2001 From: Sean Steimer Date: Mon, 6 Jul 2026 10:07:52 -0700 Subject: [PATCH 4/5] style(test): shorten 412 retry backoff comment to one line Co-Authored-By: Claude Sonnet 5 --- test/storage/version/audit.test.js | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/test/storage/version/audit.test.js b/test/storage/version/audit.test.js index 30e241f2..99a31430 100644 --- a/test/storage/version/audit.test.js +++ b/test/storage/version/audit.test.js @@ -815,8 +815,7 @@ describe('Version Audit', () => { }); describe('412 retry backoff', () => { - // Real retry delays (~3050ms worst case) would exceed mocha's 2000ms - // timeout, so each test stubs setTimeout; the hook just restores it. + // stub/restore setTimeout to avoid exceeding mocha 2000ms timeout let originalSetTimeout; beforeEach(() => { From 5b5850117018611fc052bdfd71cdc1676a25ae03 Mon Sep 17 00:00:00 2001 From: Sean Steimer Date: Mon, 6 Jul 2026 10:08:28 -0700 Subject: [PATCH 5/5] style(test): reword Math.random stub comment Co-Authored-By: Claude Sonnet 5 --- test/storage/version/audit.test.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/storage/version/audit.test.js b/test/storage/version/audit.test.js index 99a31430..24ac0c0e 100644 --- a/test/storage/version/audit.test.js +++ b/test/storage/version/audit.test.js @@ -881,7 +881,7 @@ describe('Version Audit', () => { }); it('uses exponential jitter backoff (0-50, 0-100, 0-200, 0-400, 0-800, 0-1600 ms) across six 412 retries', async () => { - // Also stubs Math.random to capture per-retry delays. + // stub Math.random so we can capture per-retry delays const originalRandom = Math.random; const delays = []; Math.random = () => 0.999999;