Enrich scheduler lock backend failure logging

This commit is contained in:
thePR0M3TH3AN committed 2026-02-14 18:23:52 -05:00
1 parent 4831d64533
commit c38dfe1258
5 files changed
+154 -17

No files matched your search

+75 -1
View File
@@ -92,6 +92,57 @@ function normalizeStringList(value, fallback = []) {
return value.filter((item) => typeof item === 'string' && item.trim()).map((item) => item.trim()); 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) { async function artifactExistsSince(filePath, sinceMs) {
if (!filePath) return false; if (!filePath) return false;
const resolved = path.isAbsolute(filePath) 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); const logDir = path.resolve(process.cwd(), 'task-logs', cadence);
await fs.mkdir(logDir, { recursive: true }); await fs.mkdir(logDir, { recursive: true });
const file = `${ts()}__${agent}__${status}.md`; const file = `${ts()}__${agent}__${status}.md`;
@@ -263,12 +319,18 @@ async function writeLog({ cadence, agent, status, reason, detail }) {
`status: ${status}`, `status: ${status}`,
`created_at: ${new Date().toISOString()}`, `created_at: ${new Date().toISOString()}`,
`timestamp: ${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}`, `# Scheduler ${status}`,
'', '',
`- reason: ${reason}`, `- reason: ${reason}`,
detail ? `- detail: ${detail}` : null, detail ? `- detail: ${detail}` : null,
...Object.entries(metadata)
.filter(([, value]) => value !== undefined && value !== null && value !== '')
.map(([key, value]) => `- ${key}: ${value}`),
'', '',
].filter(Boolean).join('\n'); ].filter(Boolean).join('\n');
await fs.writeFile(path.join(logDir, file), body, 'utf8'); await fs.writeFile(path.join(logDir, file), body, 'utf8');
@@ -352,11 +414,23 @@ async function main() {
} }
if (lockResult.code === 2) { 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({ await writeLog({
cadence, cadence,
agent: selectedAgent, agent: selectedAgent,
status: 'failed', status: 'failed',
reason: 'Lock backend error', 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); process.exit(2);
} }
@@ -125,6 +125,9 @@ const invariants = [
'step 12 MUST NOT be executed (`lock:complete` is forbidden until validation passes)', 'step 12 MUST NOT be executed (`lock:complete` is forbidden until validation passes)',
'Publish completion before writing final success log:', 'Publish completion before writing final success log:',
'`_completed.md` MUST be created only after completion publish succeeds.', '`_completed.md` MUST be created only after completion publish succeeds.',
'backend_category',
'lock_command',
'lock_stderr_excerpt',
], ],
}, },
schedulerSnippets: [ schedulerSnippets: [
@@ -134,6 +137,11 @@ const invariants = [
"status: 'completed'", "status: 'completed'",
'Completion publish failed. Retry npm run lock:complete', 'Completion publish failed. Retry npm run lock:complete',
"reason: 'Lock backend error'", "reason: 'Lock backend error'",
'classifyLockBackendError',
'backend_category',
'lock_command',
'lock_stderr_excerpt',
'lock_stdout_excerpt',
], ],
orderedSchedulerSnippets: [ orderedSchedulerSnippets: [
"reason: 'Validation failed'", "reason: 'Validation failed'",
+7 -2
View File
@@ -134,7 +134,12 @@ Every agent prompt invoked by the schedulers (daily/weekly) MUST enforce this co
- Exit `0`: lock acquired, continue. - Exit `0`: lock acquired, continue.
- Exit `3`: race lost/already locked, return to step 2. - 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 `<prompt_dir>/<prompt-file>` end-to-end via configured handoff command. 8. Execute `<prompt_dir>/<prompt-file>` 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. - 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). - 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 ```bash
AGENT_PLATFORM=<platform> \ AGENT_PLATFORM=<platform> \
+45 -14
View File
@@ -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 root = await fs.mkdtemp(path.join(os.tmpdir(), 'scheduler-memory-policy-'));
const scriptsDir = path.join(root, 'scripts', 'agent'); const scriptsDir = path.join(root, 'scripts', 'agent');
const binDir = path.join(root, 'bin'); const binDir = path.join(root, 'bin');
@@ -76,7 +76,10 @@ case "$2" in
lock:check:daily) lock:check:daily)
echo '{"excluded":[]}' 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({ const fixture = await setupFixture({
memoryPolicy: { memoryPolicy: {
mode: 'required', mode: 'required',
retrieveCommand: 'echo RETRIEVE_WITHOUT_MARKER', retrieveCommand: 'echo RETRIEVE_WITHOUT_MARKER',
storeCommand: 'echo STORE_WITHOUT_MARKER', storeCommand: 'echo STORE_WITHOUT_MARKER',
retrieveSuccessMarkers: ['MEMORY_RETRIEVED'], retrieveSuccessMarkers: ['MEMORY_RETRIEVED'],
storeSuccessMarkers: ['MEMORY_STORED'], storeSuccessMarkers: ['MEMORY_STORED'],
retrieveArtifacts: [], retrieveArtifacts: [],
storeArtifacts: [], storeArtifacts: [],
}, },
}); });
@@ -126,12 +129,12 @@ test('accepts required memory policy when markers or artifacts are produced', {
const fixture = await setupFixture({ const fixture = await setupFixture({
memoryPolicy: { memoryPolicy: {
mode: 'required', mode: 'required',
retrieveCommand: 'echo MEMORY_RETRIEVED && mkdir -p .scheduler-memory && : > .scheduler-memory/retrieve-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', storeCommand: 'echo MEMORY_STORED && mkdir -p .scheduler-memory && : > .scheduler-memory/store-daily.ok',
retrieveSuccessMarkers: ['MEMORY_RETRIEVED'], retrieveSuccessMarkers: ['MEMORY_RETRIEVED'],
storeSuccessMarkers: ['MEMORY_STORED'], storeSuccessMarkers: ['MEMORY_STORED'],
retrieveArtifacts: ['.scheduler-memory/retrieve-daily.ok'], retrieveArtifacts: ['.scheduler-memory/retrieve-daily.ok'],
storeArtifacts: ['.scheduler-memory/store-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', 'retrieve-daily.ok'));
await fs.access(path.join(fixture.root, '.scheduler-memory', 'store-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/);
});
+19
View File
@@ -145,4 +145,23 @@ describe('Scheduler cycle ordering guarantees', () => {
previousIndex = index; 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}`);
}
});
}); });