godcrm/scripts/smoke-adr0030-p6.mjs
GOD CRM Release f89e074dd1
Some checks failed
CI / Lint / Typecheck / Test / Build (push) Has been cancelled
CI / PostgreSQL Integration Tests (push) Has been cancelled
GOD CRM — public scrubbed snapshot
Governed substrate for autonomous agents: scoped identity (passports),
audited actions, MCP workspace. Infra IPs and secrets redacted for public release.
2026-08-10 04:01:45 +03:00

523 lines
19 KiB
JavaScript

#!/usr/bin/env node
/**
* Smoke test for ADR-0030 Phase 6 — stall detection + retry with backoff.
*
* Runs against the LOCAL godcrm_test DB (per ADR-0009 isolation rules).
* Does NOT hit PROD or DEV.
*
* Cases (10 total — covers T-140111 acceptance criteria 1..7):
* 1. Stall → retry_after with computed backoff window + audit entry.
* 2. Stall on max-attempts ticket → terminal failed + reason='stall'.
* 3. awaiting_approval is EXCLUDED from stall detection.
* 4. Fresh ticket (last event 10s ago) is UNTOUCHED.
* 5. idle ticket (regardless of last_event_at) is UNTOUCHED.
* 6. SIGTERM/SIGKILL of a tracked PID — process gone within grace.
* 7. computeBackoff math: 1→10000, 2→20000, 3→40000, 4→40000.
* 8. Hot-reload: shrink stall_timeout_ms via _workflow_config.
* 9. End-to-end runTick: 'running' ticket with old event → retry_after.
* 10. Retry pickup: claimReady picks up ready retry, skips not-yet-due.
*/
// ─── Force test DB BEFORE any module import (ADR-0009 boot guard) ──
process.env.POSTGRES_HOST = 'localhost';
process.env.POSTGRES_DB = 'godcrm_test';
process.env.POSTGRES_USER = 'godcrm';
process.env.POSTGRES_PASSWORD = 'godcrm_dev_2026';
process.env.POSTGRES_PORT = '5432';
process.env.AGENT_RUN_DISPATCHER_ENABLED = 'false'; // we drive ticks manually
process.env.RUN_DISPATCHER_PHASE = 'dryrun'; // P6 doesn't need live runs
process.env.RUN_REQUIRE_APPROVAL = 'false';
process.env.NODE_ENV = 'test';
delete process.env.BUSINESS_CRM_IS_PROD;
// Defer setup-guard import until AFTER the env mutations above; static
// `import` statements are hoisted and would run before our env tweaks.
await import('../backend/test/setup.js');
const { spawn } = await import('node:child_process');
const dispatcher = await import(
'../backend/services/agent-run-dispatcher/index.js'
);
const {
runStallDetect,
runTick,
loadConfig,
computeBackoff,
_getActiveAttemptsForTest,
} = dispatcher;
const { dbGet, dbRun, dbAll } = await import('../backend/database/connection.js');
const TICKETS_TABLE_ID = 1708;
const AGENTS_TABLE_ID = 1784;
const WORKFLOW_CONFIG_TABLE_ID = 100000;
const STATE_BACKLOG = 24275;
const SMOKE_TAG = 'smoke-adr0030-p6';
let pass = 0;
let fail = 0;
const insertedRowIds = []; // { table_id, id }
const childProcs = []; // spawned children for case 6
let originalConfigRow = null; // captured for hot-reload restore
function assert(label, cond, extra = '') {
if (cond) {
console.log(` PASS ${label}`);
pass++;
} else {
console.log(` FAIL ${label} ${extra}`);
fail++;
}
}
function genBaseId() {
const alphabet = 'ABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789';
let s = '';
for (let i = 0; i < 8; i++) s += alphabet[Math.floor(Math.random() * alphabet.length)];
return s;
}
async function insertRow(tableId, data) {
const row = await dbGet(
`INSERT INTO table_rows (table_id, base_id, data, created_at, updated_at)
VALUES ($1, $2, $3::jsonb, NOW(), NOW())
RETURNING id`,
[tableId, genBaseId(), JSON.stringify(data)]
);
insertedRowIds.push({ table_id: tableId, id: row.id });
return row.id;
}
async function getTicketData(ticketId) {
const row = await dbGet(
`SELECT data FROM table_rows WHERE table_id = $1 AND id = $2`,
[TICKETS_TABLE_ID, ticketId]
);
if (!row?.data) return null;
return typeof row.data === 'string' ? JSON.parse(row.data) : row.data;
}
async function makeStalledTicket({
runState = 'running',
runAttempt = 1,
ageMinutes = 10,
extra = {},
} = {}) {
const lastEventAt = new Date(Date.now() - ageMinutes * 60_000).toISOString();
const agentId = await insertRow(AGENTS_TABLE_ID, {
name: 'Smoke Agent P6',
smoke_tag: SMOKE_TAG,
});
const ticketId = await insertRow(TICKETS_TABLE_ID, {
state: STATE_BACKLOG,
assigned_to: String(agentId),
title: 'P6 smoke ticket',
what: 'P6 smoke ticket',
smoke_tag: SMOKE_TAG,
run_state: runState,
run_attempt: runAttempt,
run_started_at: new Date(Date.now() - 11 * 60_000).toISOString(),
run_last_event_at: lastEventAt,
...extra,
});
return { agentId, ticketId, lastEventAt };
}
async function cleanup() {
if (insertedRowIds.length > 0) {
const ids = insertedRowIds.map((r) => r.id);
try {
await dbRun(`DELETE FROM table_rows WHERE id = ANY($1::int[])`, [ids]);
} catch { /* best-effort */ }
}
// Catch orphans by smoke_tag.
await dbRun(
`DELETE FROM table_rows WHERE data->>'smoke_tag' = $1`,
[SMOKE_TAG]
).catch(() => {});
// Kill any test children that survived.
for (const c of childProcs) {
try {
if (!c.killed) c.kill('SIGKILL');
} catch { /* gone */ }
}
// Restore original _workflow_config row if we mutated it.
if (originalConfigRow) {
try {
await dbRun(
`UPDATE table_rows SET data = $2::jsonb, updated_at = NOW()
WHERE table_id = $1 AND id = $3`,
[WORKFLOW_CONFIG_TABLE_ID, JSON.stringify(originalConfigRow.data), originalConfigRow.id]
);
} catch { /* best-effort */ }
}
}
async function main() {
console.log('ADR-0030 Phase 6 smoke test (godcrm_test) — start');
// Pre-flight scrub.
await dbRun(
`DELETE FROM table_rows WHERE data->>'smoke_tag' = $1`,
[SMOKE_TAG]
);
// Capture _workflow_config row so we can restore later (case 8 mutates it).
originalConfigRow = await dbGet(
`SELECT id, data FROM table_rows WHERE table_id = $1 ORDER BY id ASC LIMIT 1`,
[WORKFLOW_CONFIG_TABLE_ID]
);
if (originalConfigRow && typeof originalConfigRow.data === 'string') {
originalConfigRow.data = JSON.parse(originalConfigRow.data);
}
// Force config reload with brief defaults (40000 cap, 10000 min, 300000 stall).
// The DB has retry_backoff_max_ms=300000 — override for deterministic test.
if (originalConfigRow) {
const merged = {
...originalConfigRow.data,
stall_timeout_ms: 300_000,
retry_backoff_min_ms: 10_000,
retry_backoff_max_ms: 40_000,
max_attempts: 3,
paused: false,
};
await dbRun(
`UPDATE table_rows SET data = $2::jsonb, updated_at = NOW()
WHERE table_id = $1 AND id = $3`,
[WORKFLOW_CONFIG_TABLE_ID, JSON.stringify(merged), originalConfigRow.id]
);
}
await loadConfig({ force: true });
// ── Case 1: stall → retry_after + backoff + audit
console.log('\nCase 1: stall → retry_after with backoff window');
{
const { ticketId } = await makeStalledTicket({ runAttempt: 1, ageMinutes: 10 });
const t0 = Date.now();
await runStallDetect({ source: 'smoke_p6_case_1' });
const data = await getTicketData(ticketId);
assert('run_state === retry_after',
data.run_state === 'retry_after', `got ${data?.run_state}`);
assert('run_next_attempt_after present', !!data.run_next_attempt_after);
if (data.run_next_attempt_after) {
const delay = Date.parse(data.run_next_attempt_after) - t0;
// attempt=1 → 10000ms backoff (allow ±2000 fuzz).
assert('backoff ~10s for attempt=1',
delay > 8_000 && delay < 12_000,
`delay=${delay}ms`);
}
assert('run_terminal_reason NOT set (non-terminal)',
!data.run_terminal_reason, `got ${data?.run_terminal_reason}`);
const audit = data.run_audit_log || [];
const stallEntry = audit.find(
(e) => e.reason === 'stall' && e.to === 'retry_after'
);
assert('audit entry reason=stall to=retry_after',
!!stallEntry, JSON.stringify(audit));
if (stallEntry) {
assert('audit.from === running',
stallEntry.from === 'running', JSON.stringify(stallEntry));
assert('audit.attempt === 1',
stallEntry.attempt === 1, JSON.stringify(stallEntry));
assert('audit.source === tick_part_a',
stallEntry.source === 'tick_part_a', JSON.stringify(stallEntry));
}
}
// ── Case 2: max-attempts → terminal failed
console.log('\nCase 2: max_attempts exhausted → terminal failed');
{
const { ticketId } = await makeStalledTicket({ runAttempt: 3, ageMinutes: 10 });
await runStallDetect({ source: 'smoke_p6_case_2' });
const data = await getTicketData(ticketId);
assert('run_state === failed',
data.run_state === 'failed', `got ${data?.run_state}`);
assert('run_terminal_reason === stall',
data.run_terminal_reason === 'stall',
`got ${data?.run_terminal_reason}`);
assert('run_next_attempt_after NOT set on terminal',
data.run_next_attempt_after == null,
`got ${data?.run_next_attempt_after}`);
assert('run_finished_at set', !!data.run_finished_at);
const audit = data.run_audit_log || [];
const failEntry = audit.find(
(e) => e.reason === 'stall' && e.to === 'failed'
);
assert('audit reason=stall to=failed', !!failEntry, JSON.stringify(audit));
}
// ── Case 3: awaiting_approval EXCLUDED
console.log('\nCase 3: awaiting_approval is EXCLUDED');
{
const { ticketId } = await makeStalledTicket({
runState: 'awaiting_approval',
runAttempt: 1,
ageMinutes: 10,
});
await runStallDetect({ source: 'smoke_p6_case_3' });
const data = await getTicketData(ticketId);
assert('run_state stays awaiting_approval',
data.run_state === 'awaiting_approval', `got ${data?.run_state}`);
assert('no run_terminal_reason set',
!data.run_terminal_reason, `got ${data?.run_terminal_reason}`);
const audit = data.run_audit_log || [];
assert('no stall audit entries',
!audit.some((e) => e.reason === 'stall'),
JSON.stringify(audit));
}
// ── Case 4: fresh ticket UNTOUCHED
console.log('\nCase 4: fresh ticket (10s old) UNTOUCHED');
{
const fresh = new Date(Date.now() - 10_000).toISOString();
const agentId = await insertRow(AGENTS_TABLE_ID, {
name: 'Smoke Agent P6 fresh', smoke_tag: SMOKE_TAG,
});
const ticketId = await insertRow(TICKETS_TABLE_ID, {
state: STATE_BACKLOG,
assigned_to: String(agentId),
title: 'P6 fresh ticket',
what: 'P6 fresh ticket',
smoke_tag: SMOKE_TAG,
run_state: 'running',
run_attempt: 1,
run_last_event_at: fresh,
});
await runStallDetect({ source: 'smoke_p6_case_4' });
const data = await getTicketData(ticketId);
assert('run_state stays running',
data.run_state === 'running', `got ${data?.run_state}`);
}
// ── Case 5: idle ticket UNTOUCHED (not in STALL_CHECK_RUN_STATES)
console.log('\nCase 5: idle ticket UNTOUCHED even with old last_event_at');
{
const old = new Date(Date.now() - 60 * 60_000).toISOString();
const agentId = await insertRow(AGENTS_TABLE_ID, {
name: 'Smoke Agent P6 idle', smoke_tag: SMOKE_TAG,
});
const ticketId = await insertRow(TICKETS_TABLE_ID, {
state: STATE_BACKLOG,
assigned_to: String(agentId),
title: 'P6 idle ticket',
what: 'P6 idle ticket',
smoke_tag: SMOKE_TAG,
run_state: 'idle',
run_attempt: 0,
run_last_event_at: old,
});
await runStallDetect({ source: 'smoke_p6_case_5' });
const data = await getTicketData(ticketId);
assert('idle ticket stays idle',
data.run_state === 'idle', `got ${data?.run_state}`);
}
// ── Case 6: SIGTERM/SIGKILL of tracked PID
console.log('\nCase 6: SIGTERM tracked PID — process gone within grace');
{
// Long-running child that ignores nothing (default Node handles SIGTERM
// and exits cleanly).
const child = spawn(
process.execPath,
['-e', 'setTimeout(()=>{},60_000)'],
{ stdio: 'ignore', detached: false }
);
childProcs.push(child);
// Wait for spawn to register.
await new Promise((r) => setTimeout(r, 50));
const pid = child.pid;
assert('child spawned with pid', typeof pid === 'number' && pid > 0,
`pid=${pid}`);
const { ticketId } = await makeStalledTicket({ runAttempt: 1, ageMinutes: 10 });
// Inject the PID into the dispatcher's active-attempts map.
const map = _getActiveAttemptsForTest();
map.set(ticketId, { agent_id: 'test', claimedAt: Date.now(), pid });
// Kick stall detect — this should SIGTERM the child synchronously and
// return after the 5s grace.
const t0 = Date.now();
await runStallDetect({ source: 'smoke_p6_case_6' });
const elapsed = Date.now() - t0;
// Probe: child should be gone now.
let alive = true;
try { process.kill(pid, 0); } catch (e) { if (e.code === 'ESRCH') alive = false; }
assert('child PID is gone after stall kill', !alive, `pid=${pid} elapsed=${elapsed}ms`);
assert('elapsed within ~6s', elapsed < 6500, `elapsed=${elapsed}ms`);
assert('_activeAttempts entry was freed',
!map.has(ticketId), `still has entry`);
}
// ── Case 7: computeBackoff math
console.log('\nCase 7: computeBackoff math (10000 / 20000 / 40000 cap)');
{
const cfg = {
retry_backoff_min_ms: 10_000,
retry_backoff_max_ms: 40_000,
};
assert('attempt=1 → 10000', computeBackoff(1, cfg) === 10_000,
`got ${computeBackoff(1, cfg)}`);
assert('attempt=2 → 20000', computeBackoff(2, cfg) === 20_000,
`got ${computeBackoff(2, cfg)}`);
assert('attempt=3 → 40000', computeBackoff(3, cfg) === 40_000,
`got ${computeBackoff(3, cfg)}`);
assert('attempt=4 → 40000 (capped)',
computeBackoff(4, cfg) === 40_000,
`got ${computeBackoff(4, cfg)}`);
assert('attempt=10 → 40000 (capped)',
computeBackoff(10, cfg) === 40_000,
`got ${computeBackoff(10, cfg)}`);
}
// ── Case 8: hot-reload of stall_timeout_ms
console.log('\nCase 8: hot-reload stall_timeout_ms via _workflow_config');
{
if (!originalConfigRow) {
console.log(' SKIP (no _workflow_config row in test DB)');
} else {
// Set stall_timeout_ms = 60000 (1 minute) in _workflow_config.
const updated = {
...originalConfigRow.data,
stall_timeout_ms: 60_000,
retry_backoff_min_ms: 10_000,
retry_backoff_max_ms: 40_000,
max_attempts: 3,
paused: false,
};
await dbRun(
`UPDATE table_rows SET data = $2::jsonb, updated_at = NOW()
WHERE table_id = $1 AND id = $3`,
[WORKFLOW_CONFIG_TABLE_ID, JSON.stringify(updated), originalConfigRow.id]
);
const newConfig = await loadConfig({ force: true });
assert('config.stall_timeout_ms == 60000',
newConfig.stall_timeout_ms === 60_000,
`got ${newConfig.stall_timeout_ms}`);
// 65s old ticket — beyond shrunk threshold, would NOT have stalled
// under the 5min default.
const sixtyFiveSec = new Date(Date.now() - 65_000).toISOString();
const agentId = await insertRow(AGENTS_TABLE_ID, {
name: 'Smoke Agent P6 hotreload', smoke_tag: SMOKE_TAG,
});
const ticketId = await insertRow(TICKETS_TABLE_ID, {
state: STATE_BACKLOG,
assigned_to: String(agentId),
title: 'P6 hotreload',
what: 'P6 hotreload',
smoke_tag: SMOKE_TAG,
run_state: 'running',
run_attempt: 1,
run_last_event_at: sixtyFiveSec,
});
await runStallDetect({ source: 'smoke_p6_case_8' });
const data = await getTicketData(ticketId);
assert('shrunken threshold marked 65s ticket stalled',
data.run_state === 'retry_after', `got ${data?.run_state}`);
}
}
// ── Case 9: end-to-end runTick — running ticket stalls into retry_after
console.log('\nCase 9: runTick end-to-end → retry_after');
{
// Use default 300_000 stall_timeout_ms and a 10-min-old event.
if (originalConfigRow) {
const reset = {
...originalConfigRow.data,
stall_timeout_ms: 300_000,
retry_backoff_min_ms: 10_000,
retry_backoff_max_ms: 40_000,
max_attempts: 3,
paused: false,
};
await dbRun(
`UPDATE table_rows SET data = $2::jsonb, updated_at = NOW()
WHERE table_id = $1 AND id = $3`,
[WORKFLOW_CONFIG_TABLE_ID, JSON.stringify(reset), originalConfigRow.id]
);
await loadConfig({ force: true });
}
const { ticketId } = await makeStalledTicket({ runAttempt: 2, ageMinutes: 10 });
const stats = await runTick({ source: 'smoke_p6_case_9' });
assert('tick stats.stalled >= 1',
stats.stalled >= 1, JSON.stringify(stats));
assert('tick stats.stall_retried >= 1',
stats.stall_retried >= 1, JSON.stringify(stats));
const data = await getTicketData(ticketId);
assert('runTick flipped ticket to retry_after',
data.run_state === 'retry_after', `got ${data?.run_state}`);
if (data.run_next_attempt_after) {
const delay = Date.parse(data.run_next_attempt_after) - Date.now();
// attempt=2 → ~20000ms backoff.
assert('backoff ~20s for attempt=2',
delay > 17_000 && delay < 22_000,
`delay=${delay}ms`);
}
}
// ── Case 10: retry pickup — claimReady picks ready, skips not-yet-due
console.log('\nCase 10: retry pickup — past vs future run_next_attempt_after');
{
// Two retry_after tickets: one past-due, one future.
const past = new Date(Date.now() - 30_000).toISOString();
const future = new Date(Date.now() + 5 * 60_000).toISOString();
const agentIdA = await insertRow(AGENTS_TABLE_ID, {
name: 'P6 retry A', smoke_tag: SMOKE_TAG,
});
const agentIdB = await insertRow(AGENTS_TABLE_ID, {
name: 'P6 retry B', smoke_tag: SMOKE_TAG,
});
const readyId = await insertRow(TICKETS_TABLE_ID, {
state: STATE_BACKLOG,
assigned_to: String(agentIdA),
title: 'P6 retry ready',
what: 'P6 retry ready',
smoke_tag: SMOKE_TAG,
run_state: 'retry_after',
run_attempt: 1,
run_next_attempt_after: past,
});
const notYetId = await insertRow(TICKETS_TABLE_ID, {
state: STATE_BACKLOG,
assigned_to: String(agentIdB),
title: 'P6 retry not yet',
what: 'P6 retry not yet',
smoke_tag: SMOKE_TAG,
run_state: 'retry_after',
run_attempt: 1,
run_next_attempt_after: future,
});
// RUN_DISPATCHER_PHASE='dryrun' — runTick will claim + cancel any
// ready ticket. notYetId should NOT be claimed.
const stats = await runTick({ source: 'smoke_p6_case_10' });
assert('tick.picked >= 1', stats.picked >= 1, JSON.stringify(stats));
const readyData = await getTicketData(readyId);
const notYetData = await getTicketData(notYetId);
assert('past-due retry was picked up (state moved off retry_after)',
readyData.run_state !== 'retry_after',
`got ${readyData?.run_state}`);
assert('future retry was SKIPPED',
notYetData.run_state === 'retry_after',
`got ${notYetData?.run_state}`);
assert('skipped ticket retains run_next_attempt_after',
notYetData.run_next_attempt_after === future,
`got ${notYetData?.run_next_attempt_after}`);
}
console.log(`\n${pass + fail} assertions: ${pass} pass / ${fail} fail`);
if (fail === 0) console.log('all assertions passed');
}
main()
.catch((err) => {
console.error('SMOKE FAILED with exception:', err);
fail++;
})
.finally(async () => {
try { await cleanup(); } catch (err) { console.error('cleanup error:', err); }
process.exit(fail === 0 ? 0 : 1);
});