From aad60b795ab79ab300dc2573055051ff3e8dbb15 Mon Sep 17 00:00:00 2001 From: thePR0M3TH3AN <53631862+PR0M3TH3AN@users.noreply.github.com> Date: Sat, 14 Feb 2026 19:47:32 -0500 Subject: [PATCH] test: add publish retry matrix coverage for lock backend --- package.json | 1 + src/lock-ops.mjs | 12 +- test/lock-ops-publish-retry.test.mjs | 192 +++++++++++++++++++++++++++ 3 files changed, 204 insertions(+), 1 deletion(-) create mode 100644 test/lock-ops-publish-retry.test.mjs diff --git a/package.json b/package.json index 07d720a..040eed5 100644 --- a/package.json +++ b/package.json @@ -29,6 +29,7 @@ ], "scripts": { "test": "npm run validate:scheduler && node --test test/*.test.mjs tests/*.test.js", + "test:unit:lock-backend": "node --test test/lock-ops.test.mjs test/lock-ops-publish-retry.test.mjs", "lock:check:daily": "node bin/torch-lock.mjs check --cadence daily", "lock:check:weekly": "node bin/torch-lock.mjs check --cadence weekly", "lock:list": "node bin/torch-lock.mjs list", diff --git a/src/lock-ops.mjs b/src/lock-ops.mjs index 0f89217..4a19761 100644 --- a/src/lock-ops.mjs +++ b/src/lock-ops.mjs @@ -471,6 +471,7 @@ export async function publishLock(relays, event, deps = {}) { let lastAttemptState = null; const retryTimeline = []; const overallStartedAt = Date.now(); + let terminalFailureCategory = 'relay_publish_non_retryable'; for (let attemptNumber = 1; attemptNumber <= maxAttempts; attemptNumber += 1) { const startedAtMs = Date.now(); lastAttemptState = await publishOnce(); @@ -506,6 +507,14 @@ export async function publishLock(relays, event, deps = {}) { const hasPermanentFailure = lastAttemptState.failures.some((failure) => !isTransientPublishCategory(failure.category)); const canRetry = attemptNumber < maxAttempts && hasTransientFailure && !hasPermanentFailure; + if (hasTransientFailure && !hasPermanentFailure && attemptNumber >= maxAttempts) { + terminalFailureCategory = 'relay_publish_quorum_failure'; + } else if (hasPermanentFailure) { + terminalFailureCategory = 'relay_publish_non_retryable'; + } else { + terminalFailureCategory = 'relay_publish_quorum_failure'; + } + if (!canRetry) { break; } @@ -548,6 +557,7 @@ export async function publishLock(relays, event, deps = {}) { event: 'lock_publish_quorum_failed', correlationId, attemptId, + errorCategory: terminalFailureCategory, successCount: lastAttemptState.successCount, relayAttemptedCount: lastAttemptState.attempted.size, requiredSuccesses: minSuccesses, @@ -561,7 +571,7 @@ export async function publishLock(relays, event, deps = {}) { maybeLogHealthSnapshot(allRelays, healthConfig, healthLogger, 'publish:failure', true); throw new Error( `Failed relay publish quorum in publish phase: ${lastAttemptState.successCount}/${lastAttemptState.attempted.size} successful ` - + `(required=${minSuccesses}, timeout=${publishTimeoutMs}ms, attempts=${maxAttempts}, attempt_id=${attemptId}, correlation_id=${correlationId}, total_retry_timeline_ms=${Date.now() - overallStartedAt})\n` + + `(required=${minSuccesses}, timeout=${publishTimeoutMs}ms, attempts=${maxAttempts}, attempt_id=${attemptId}, correlation_id=${correlationId}, error_category=${terminalFailureCategory}, total_retry_timeline_ms=${Date.now() - overallStartedAt})\n` + ` retry timeline: ${retryTimeline.map((item) => `#${item.publishAttempt}:${item.elapsedMs}ms`).join(', ')}\n` + ` ${failureLines.join('\n ')}`, ); diff --git a/test/lock-ops-publish-retry.test.mjs b/test/lock-ops-publish-retry.test.mjs new file mode 100644 index 0000000..ad35d14 --- /dev/null +++ b/test/lock-ops-publish-retry.test.mjs @@ -0,0 +1,192 @@ +import { describe, it, beforeEach, afterEach, mock } from 'node:test'; +import assert from 'node:assert'; +import { publishLock, _resetRelayHealthState } from '../src/lock-ops.mjs'; + +function createScriptedPool(scriptedOutcomesByAttempt, relaysSeen) { + let publishCallCount = 0; + return { + publish: (relays) => { + publishCallCount += 1; + relaysSeen.push({ publishAttempt: publishCallCount, relays: [...relays] }); + const attemptOutcomes = scriptedOutcomesByAttempt[publishCallCount - 1] || {}; + return relays.map((relay) => { + const outcome = attemptOutcomes[relay] || { ok: true }; + return outcome.ok ? Promise.resolve('ok') : Promise.reject(new Error(outcome.message)); + }); + }, + close: () => {}, + getPublishCallCount: () => publishCallCount, + }; +} + +const parseTelemetry = (logs) => logs.map((line) => JSON.parse(line)); + +describe('publishLock retry behavior', { concurrency: false }, () => { + beforeEach(() => { + _resetRelayHealthState(); + }); + + afterEach(() => { + mock.timers.reset(); + }); + + it('succeeds immediately on first attempt without retries', async () => { + const telemetryLogs = []; + const relaysSeen = []; + const mockPool = createScriptedPool([ + { 'wss://relay-a': { ok: true } }, + ], relaysSeen); + + const event = { id: 'evt-immediate' }; + const result = await publishLock(['wss://relay-a'], event, { + poolFactory: () => mockPool, + getPublishTimeoutMsFn: () => 200, + getMinSuccessfulRelayPublishesFn: () => 1, + getRelayFallbacksFn: () => [], + getMinActiveRelayPoolFn: () => 1, + retryAttempts: 4, + telemetryLogger: (line) => telemetryLogs.push(line), + healthLogger: () => {}, + }); + + assert.strictEqual(result, event); + assert.strictEqual(mockPool.getPublishCallCount(), 1); + assert.deepStrictEqual(relaysSeen, [{ publishAttempt: 1, relays: ['wss://relay-a'] }]); + + const telemetry = parseTelemetry(telemetryLogs); + assert.strictEqual(telemetry.filter((entry) => entry.event === 'lock_publish_retry').length, 0); + const metEvent = telemetry.find((entry) => entry.event === 'lock_publish_quorum_met'); + assert.ok(metEvent); + assert.strictEqual(metEvent.publishAttempt, 1); + }); + + it('retries a transient failure then succeeds within retry budget with bounded jitter', async () => { + mock.timers.enable({ apis: ['Date', 'setTimeout'] }); + + const telemetryLogs = []; + const relaysSeen = []; + const sleepCalls = []; + const mockPool = createScriptedPool([ + { 'wss://relay-a': { ok: false, message: 'connection reset by peer' } }, + { 'wss://relay-a': { ok: true } }, + ], relaysSeen); + + const result = await publishLock(['wss://relay-a'], { id: 'evt-retry-success' }, { + poolFactory: () => mockPool, + getPublishTimeoutMsFn: () => 200, + getMinSuccessfulRelayPublishesFn: () => 1, + getRelayFallbacksFn: () => [], + getMinActiveRelayPoolFn: () => 1, + retryAttempts: 3, + retryBaseDelayMs: 100, + retryCapDelayMs: 500, + randomFn: () => 0.25, + sleepFn: async (delayMs) => { + sleepCalls.push(delayMs); + mock.timers.tick(delayMs); + }, + telemetryLogger: (line) => telemetryLogs.push(line), + healthLogger: () => {}, + }); + + assert.strictEqual(result.id, 'evt-retry-success'); + assert.deepStrictEqual(sleepCalls, [25]); + assert.strictEqual(mockPool.getPublishCallCount(), 2); + + const telemetry = parseTelemetry(telemetryLogs); + const retryEvents = telemetry.filter((entry) => entry.event === 'lock_publish_retry'); + assert.strictEqual(retryEvents.length, 1); + assert.strictEqual(retryEvents[0].publishAttempt, 1); + assert.strictEqual(retryEvents[0].relayUrl, 'wss://relay-a'); + assert.ok(retryEvents[0].nextDelayMs >= 0 && retryEvents[0].nextDelayMs <= 100); + }); + + it('returns terminal relay_publish_quorum_failure after exhausting retry budget', async () => { + mock.timers.enable({ apis: ['Date', 'setTimeout'] }); + + const telemetryLogs = []; + const relaysSeen = []; + const sleepCalls = []; + const randomValues = [0.1, 0.9]; + const mockPool = createScriptedPool([ + { 'wss://relay-a': { ok: false, message: 'relay unavailable' } }, + { 'wss://relay-a': { ok: false, message: 'relay unavailable' } }, + { 'wss://relay-a': { ok: false, message: 'relay unavailable' } }, + ], relaysSeen); + + await assert.rejects( + () => publishLock(['wss://relay-a'], { id: 'evt-exhausted' }, { + poolFactory: () => mockPool, + getPublishTimeoutMsFn: () => 200, + getMinSuccessfulRelayPublishesFn: () => 1, + getRelayFallbacksFn: () => [], + getMinActiveRelayPoolFn: () => 1, + retryAttempts: 3, + retryBaseDelayMs: 100, + retryCapDelayMs: 250, + randomFn: () => randomValues.shift() ?? 0, + sleepFn: async (delayMs) => { + sleepCalls.push(delayMs); + mock.timers.tick(delayMs); + }, + telemetryLogger: (line) => telemetryLogs.push(line), + healthLogger: () => {}, + }), + /error_category=relay_publish_quorum_failure/, + ); + + assert.strictEqual(mockPool.getPublishCallCount(), 3); + assert.deepStrictEqual(sleepCalls, [10, 180]); + assert.deepStrictEqual(relaysSeen.map((entry) => entry.publishAttempt), [1, 2, 3]); + + const telemetry = parseTelemetry(telemetryLogs); + const retryEvents = telemetry.filter((entry) => entry.event === 'lock_publish_retry'); + assert.strictEqual(retryEvents.length, 2); + assert.strictEqual(retryEvents[0].publishAttempt, 1); + assert.strictEqual(retryEvents[0].relayUrl, 'wss://relay-a'); + assert.ok(retryEvents[0].nextDelayMs >= 0 && retryEvents[0].nextDelayMs <= 100); + assert.strictEqual(retryEvents[1].publishAttempt, 2); + assert.strictEqual(retryEvents[1].relayUrl, 'wss://relay-a'); + assert.ok(retryEvents[1].nextDelayMs >= retryEvents[0].nextDelayMs); + assert.ok(retryEvents[1].nextDelayMs <= 200); + + const failedEvent = telemetry.find((entry) => entry.event === 'lock_publish_quorum_failed'); + assert.ok(failedEvent); + assert.strictEqual(failedEvent.errorCategory, 'relay_publish_quorum_failure'); + assert.strictEqual(failedEvent.attempts, 3); + }); + + it('short-circuits non-retryable failures without extra attempts', async () => { + const telemetryLogs = []; + const relaysSeen = []; + const mockPool = createScriptedPool([ + { 'wss://relay-a': { ok: false, message: 'validation failed: invalid signature' } }, + { 'wss://relay-a': { ok: true } }, + ], relaysSeen); + + await assert.rejects( + () => publishLock(['wss://relay-a'], { id: 'evt-permanent' }, { + poolFactory: () => mockPool, + getPublishTimeoutMsFn: () => 200, + getMinSuccessfulRelayPublishesFn: () => 1, + getRelayFallbacksFn: () => [], + getMinActiveRelayPoolFn: () => 1, + retryAttempts: 4, + telemetryLogger: (line) => telemetryLogs.push(line), + healthLogger: () => {}, + }), + /error_category=relay_publish_non_retryable/, + ); + + assert.strictEqual(mockPool.getPublishCallCount(), 1); + assert.deepStrictEqual(relaysSeen, [{ publishAttempt: 1, relays: ['wss://relay-a'] }]); + + const telemetry = parseTelemetry(telemetryLogs); + assert.strictEqual(telemetry.filter((entry) => entry.event === 'lock_publish_retry').length, 0); + + const failedEvent = telemetry.find((entry) => entry.event === 'lock_publish_quorum_failed'); + assert.ok(failedEvent); + assert.strictEqual(failedEvent.errorCategory, 'relay_publish_non_retryable'); + assert.notStrictEqual(failedEvent.errorCategory, 'relay_publish_quorum_failure'); + }); +});