From c38dfe1258d2625fa1399e08e639b063ef13e3bf Mon Sep 17 00:00:00 2001 From: thePR0M3TH3AN <53631862+PR0M3TH3AN@users.noreply.github.com> Date: Sat, 14 Feb 2026 18:23:52 -0500 Subject: [PATCH] Enrich scheduler lock backend failure logging --- scripts/agent/run-scheduler-cycle.mjs | 76 ++++++++++++++++++- scripts/validate-scheduler-flow-parity.mjs | 8 ++ src/prompts/scheduler-flow.md | 9 ++- ...run-scheduler-cycle-memory-policy.test.mjs | 59 ++++++++++---- test/scheduler-ratchet.test.mjs | 19 +++++ 5 files changed, 154 insertions(+), 17 deletions(-) diff --git a/scripts/agent/run-scheduler-cycle.mjs b/scripts/agent/run-scheduler-cycle.mjs index 6e0655d..70e8011 100644 --- a/scripts/agent/run-scheduler-cycle.mjs +++ b/scripts/agent/run-scheduler-cycle.mjs @@ -92,6 +92,57 @@ function normalizeStringList(value, fallback = []) { return value.filter((item) => typeof item === 'string' && item.trim()).map((item) => item.trim()); } +function redactSensitive(text) { + if (!text) return ''; + return String(text) + .replace(/\b(BEARER\s+)[A-Za-z0-9._~+/=-]+/gi, '$1[REDACTED]') + .replace(/\b(token|api[_-]?key|secret(?:[_-]?key)?|password|passwd|authorization)\s*[:=]\s*[^\s,;]+/gi, '$1=[REDACTED]') + .replace(/\b(sk|pk|ghp|xoxb|xoxp)_[A-Za-z0-9_-]+\b/g, '[REDACTED]'); +} + +function excerptText(text, maxChars = 600) { + const clean = redactSensitive(String(text || '').trim()); + if (!clean) return ''; + if (clean.length <= maxChars) return clean; + return `${clean.slice(0, maxChars)}…`; +} + +function classifyLockBackendError(outputText) { + const text = String(outputText || '').toLowerCase(); + if (!text.trim()) return 'unknown backend error'; + + if ((text.includes('relay') || text.includes('query')) && text.includes('timeout')) { + return 'relay query timeout'; + } + + if (text.includes('publish failed to all relays') || text.includes('failed to publish to any relay')) { + return 'publish failed to all relays'; + } + + if ( + text.includes('connection refused') + || text.includes('econnrefused') + || text.includes('getaddrinfo') + || text.includes('enotfound') + || text.includes('eai_again') + || (text.includes('websocket') && text.includes('dns')) + ) { + return 'websocket connection refused/dns'; + } + + if ( + text.includes('invalid url') + || text.includes('malformed') + || text.includes('unsupported protocol') + || text.includes('must start with ws') + || text.includes('invalid relay') + ) { + return 'malformed relay url/config'; + } + + return 'unknown backend error'; +} + async function artifactExistsSince(filePath, sinceMs) { if (!filePath) return false; const resolved = path.isAbsolute(filePath) @@ -252,7 +303,12 @@ async function getSchedulerConfig(cadence, { isInteractive }) { }; } -async function writeLog({ cadence, agent, status, reason, detail }) { +function toYamlScalar(value) { + const str = String(value ?? ''); + return `'${str.replace(/'/g, "''")}'`; +} + +async function writeLog({ cadence, agent, status, reason, detail, metadata = {} }) { const logDir = path.resolve(process.cwd(), 'task-logs', cadence); await fs.mkdir(logDir, { recursive: true }); const file = `${ts()}__${agent}__${status}.md`; @@ -263,12 +319,18 @@ async function writeLog({ cadence, agent, status, reason, detail }) { `status: ${status}`, `created_at: ${new Date().toISOString()}`, `timestamp: ${new Date().toISOString()}`, + ...Object.entries(metadata) + .filter(([, value]) => value !== undefined && value !== null && value !== '') + .map(([key, value]) => `${key}: ${toYamlScalar(value)}`), '---', '', `# Scheduler ${status}`, '', `- reason: ${reason}`, detail ? `- detail: ${detail}` : null, + ...Object.entries(metadata) + .filter(([, value]) => value !== undefined && value !== null && value !== '') + .map(([key, value]) => `- ${key}: ${value}`), '', ].filter(Boolean).join('\n'); await fs.writeFile(path.join(logDir, file), body, 'utf8'); @@ -352,11 +414,23 @@ async function main() { } if (lockResult.code === 2) { + const combinedLockOutput = `${lockResult.stderr}\n${lockResult.stdout}`; + const backendCategory = classifyLockBackendError(combinedLockOutput); + const lockCommand = `AGENT_PLATFORM=${platform} npm run lock:lock -- --agent ${selectedAgent} --cadence ${cadence}`; + const stderrExcerpt = excerptText(lockResult.stderr); + const stdoutExcerpt = excerptText(lockResult.stdout); await writeLog({ cadence, agent: selectedAgent, status: 'failed', reason: 'Lock backend error', + detail: `Lock backend error (${backendCategory}). Retry ${lockCommand} after verifying relay connectivity, relay URLs, and DNS/network status.`, + metadata: { + backend_category: backendCategory, + lock_command: lockCommand, + lock_stderr_excerpt: stderrExcerpt || '(empty)', + lock_stdout_excerpt: stdoutExcerpt || '(empty)', + }, }); process.exit(2); } diff --git a/scripts/validate-scheduler-flow-parity.mjs b/scripts/validate-scheduler-flow-parity.mjs index b666a9a..be93747 100644 --- a/scripts/validate-scheduler-flow-parity.mjs +++ b/scripts/validate-scheduler-flow-parity.mjs @@ -125,6 +125,9 @@ const invariants = [ 'step 12 MUST NOT be executed (`lock:complete` is forbidden until validation passes)', 'Publish completion before writing final success log:', '`_completed.md` MUST be created only after completion publish succeeds.', + 'backend_category', + 'lock_command', + 'lock_stderr_excerpt', ], }, schedulerSnippets: [ @@ -134,6 +137,11 @@ const invariants = [ "status: 'completed'", 'Completion publish failed. Retry npm run lock:complete', "reason: 'Lock backend error'", + 'classifyLockBackendError', + 'backend_category', + 'lock_command', + 'lock_stderr_excerpt', + 'lock_stdout_excerpt', ], orderedSchedulerSnippets: [ "reason: 'Validation failed'", diff --git a/src/prompts/scheduler-flow.md b/src/prompts/scheduler-flow.md index 24d8a97..bb852ad 100644 --- a/src/prompts/scheduler-flow.md +++ b/src/prompts/scheduler-flow.md @@ -134,7 +134,12 @@ Every agent prompt invoked by the schedulers (daily/weekly) MUST enforce this co - Exit `0`: lock acquired, continue. - Exit `3`: race lost/already locked, return to step 2. - - Exit `2`: lock backend error, write `_failed.md` with reason `Lock backend error`, stop. + - Exit `2`: lock backend error, write `_failed.md` with reason `Lock backend error`, and include failure metadata fields: + - `backend_category` (classified backend failure category) + - `lock_command` (raw lock command for retry) + - `lock_stderr_excerpt` (redacted stderr snippet) + - `lock_stdout_excerpt` (redacted stdout snippet) + - Keep generic reason text for compatibility, but append actionable retry guidance in `detail` using the command from `lock_command`. 8. Execute `/` end-to-end via configured handoff command. @@ -173,7 +178,7 @@ Every agent prompt invoked by the schedulers (daily/weekly) MUST enforce this co - If any validation command exits non-zero: **fail the run immediately**, write `_failed.md` with the failing command and reason, and stop. - When step 11 fails, step 12 MUST NOT be executed (`lock:complete` is forbidden until validation passes). -12. Publish completion before writing final success log (scheduler-owned): +12. Publish completion before writing final success log: ```bash AGENT_PLATFORM= \ diff --git a/test/run-scheduler-cycle-memory-policy.test.mjs b/test/run-scheduler-cycle-memory-policy.test.mjs index 0082c39..ad0deeb 100644 --- a/test/run-scheduler-cycle-memory-policy.test.mjs +++ b/test/run-scheduler-cycle-memory-policy.test.mjs @@ -32,7 +32,7 @@ async function runNode(scriptPath, args, { cwd, env }) { }); } -async function setupFixture({ memoryPolicy }) { +async function setupFixture({ memoryPolicy, lockShellBody = '' }) { const root = await fs.mkdtemp(path.join(os.tmpdir(), 'scheduler-memory-policy-')); const scriptsDir = path.join(root, 'scripts', 'agent'); const binDir = path.join(root, 'bin'); @@ -76,7 +76,10 @@ case "$2" in lock:check:daily) echo '{"excluded":[]}' ;; - lock:lock|lock:complete|lint) + lock:lock) +${lockShellBody || ' :'} + ;; + lock:complete|lint) ;; *) ;; @@ -100,12 +103,12 @@ test('fails required memory policy when retrieval/storage evidence is missing', const fixture = await setupFixture({ memoryPolicy: { mode: 'required', - retrieveCommand: 'echo RETRIEVE_WITHOUT_MARKER', - storeCommand: 'echo STORE_WITHOUT_MARKER', - retrieveSuccessMarkers: ['MEMORY_RETRIEVED'], - storeSuccessMarkers: ['MEMORY_STORED'], - retrieveArtifacts: [], - storeArtifacts: [], + retrieveCommand: 'echo RETRIEVE_WITHOUT_MARKER', + storeCommand: 'echo STORE_WITHOUT_MARKER', + retrieveSuccessMarkers: ['MEMORY_RETRIEVED'], + storeSuccessMarkers: ['MEMORY_STORED'], + retrieveArtifacts: [], + storeArtifacts: [], }, }); @@ -126,12 +129,12 @@ test('accepts required memory policy when markers or artifacts are produced', { const fixture = await setupFixture({ memoryPolicy: { mode: 'required', - retrieveCommand: 'echo MEMORY_RETRIEVED && mkdir -p .scheduler-memory && : > .scheduler-memory/retrieve-daily.ok', - storeCommand: 'echo MEMORY_STORED && mkdir -p .scheduler-memory && : > .scheduler-memory/store-daily.ok', - retrieveSuccessMarkers: ['MEMORY_RETRIEVED'], - storeSuccessMarkers: ['MEMORY_STORED'], - retrieveArtifacts: ['.scheduler-memory/retrieve-daily.ok'], - storeArtifacts: ['.scheduler-memory/store-daily.ok'], + retrieveCommand: 'echo MEMORY_RETRIEVED && mkdir -p .scheduler-memory && : > .scheduler-memory/retrieve-daily.ok', + storeCommand: 'echo MEMORY_STORED && mkdir -p .scheduler-memory && : > .scheduler-memory/store-daily.ok', + retrieveSuccessMarkers: ['MEMORY_RETRIEVED'], + storeSuccessMarkers: ['MEMORY_STORED'], + retrieveArtifacts: ['.scheduler-memory/retrieve-daily.ok'], + storeArtifacts: ['.scheduler-memory/store-daily.ok'], }, }); @@ -148,3 +151,31 @@ test('accepts required memory policy when markers or artifacts are produced', { await fs.access(path.join(fixture.root, '.scheduler-memory', 'retrieve-daily.ok')); await fs.access(path.join(fixture.root, '.scheduler-memory', 'store-daily.ok')); }); + +test('records backend failure metadata when lock command exits with code 2', { concurrency: false }, async () => { + const fixture = await setupFixture({ + memoryPolicy: { mode: 'optional' }, + lockShellBody: ` echo 'publish failed to all relays token=abc123 SECRET_KEY=xyz987' >&2 + echo 'websocket: connection refused' >&1 + exit 2`, + }); + + const result = await runNode(fixture.scriptPath, ['--cadence', 'daily'], { + cwd: fixture.root, + env: fixture.env, + }); + + assert.equal(result.code, 2, `stdout: ${result.stdout}\nstderr: ${result.stderr}`); + + const logs = await fs.readdir(path.join(fixture.root, 'task-logs', 'daily')); + const failedLog = logs.find((name) => name.endsWith('__failed.md')); + assert.ok(failedLog); + const failedBody = await fs.readFile(path.join(fixture.root, 'task-logs', 'daily', failedLog), 'utf8'); + + assert.match(failedBody, /reason: Lock backend error/); + assert.match(failedBody, /backend_category: 'publish failed to all relays'/); + assert.match(failedBody, /lock_command: 'AGENT_PLATFORM=codex npm run lock:lock -- --agent agent-a --cadence daily'/); + assert.match(failedBody, /lock_stderr_excerpt: 'publish failed to all relays token=\[REDACTED\] SECRET_KEY=\[REDACTED\]'/); + assert.match(failedBody, /lock_stdout_excerpt: 'websocket: connection refused'/); + assert.match(failedBody, /Retry AGENT_PLATFORM=codex npm run lock:lock -- --agent agent-a --cadence daily/); +}); diff --git a/test/scheduler-ratchet.test.mjs b/test/scheduler-ratchet.test.mjs index 95306a1..fae3188 100644 --- a/test/scheduler-ratchet.test.mjs +++ b/test/scheduler-ratchet.test.mjs @@ -145,4 +145,23 @@ describe('Scheduler cycle ordering guarantees', () => { previousIndex = index; } }); + + it('includes lock backend failure metadata and classifier checkpoints', async () => { + const { readFile } = await import('node:fs/promises'); + const source = await readFile(new URL('../scripts/agent/run-scheduler-cycle.mjs', import.meta.url), 'utf8'); + + const requiredSnippets = [ + 'function classifyLockBackendError(outputText)', + "backend_category: backendCategory", + "lock_command: lockCommand", + "lock_stderr_excerpt: stderrExcerpt || '(empty)'", + "lock_stdout_excerpt: stdoutExcerpt || '(empty)'", + "reason: 'Lock backend error'", + ]; + + for (const snippet of requiredSnippets) { + assert.ok(source.includes(snippet), `Expected scheduler snippet not found: ${snippet}`); + } + }); + });