diff --git a/docs/revendor-inventory.md b/docs/revendor-inventory.md index 530db4784..8b5d18a6d 100644 --- a/docs/revendor-inventory.md +++ b/docs/revendor-inventory.md @@ -923,3 +923,77 @@ model turn. The first REAL token is proof 3's reply. the tie alphabetically and `all-minilm` can win the bench default. The harness narrows the bench catalog to its one pinned model through the catalog API before it asserts anything about a turn. + +## CL-6365: why the restored run comes back terminal + +Reproduced on a second real stack (scratch database, real signup, real +Ollama), with one correction to the harness first. + +### The kill has to be mid-turn, and it was not + +Proof 4's kill window was three seconds after "count slowly from one to +twenty". On an instance whose model answers that in about one second, +the turn had already completed and the run had parked by the time the +sidecar came down — so the restart that followed was a clean restart, +not a crash, and proof 4 passed. It passes that way at this branch's +tip; the whole finding turns on the kill actually landing while +inference is running. + +Proof 4 now sends a workload no model finishes inside the window and +asserts, at the moment of the kill, that nothing has answered yet. +"Mid-turn" is a claim the harness checks rather than a sleep it hopes +for. With that in place the failure is deterministic. + +### What the mid-turn kill leaves behind + +Both top-level runs — the folded chat run and the section deployment — +end up `workflow_run.status = 'failed'` in the hub's own database. The +sidecar's SIGTERM drain tears the workflow-process child down while the +step is in flight, and the resulting terminal event is committed to the +run's durable event log before the process exits. + +Boot restore then does its half correctly: the scan finds the +deployment records, replays each pin, re-materializes the closure, and +the address is routable again (`liveness: "ok"` about ten seconds after +the restart). But the run inside it is over: + +- the section deployment answers `POST /workflows/:id/mail` with `409 +workflow_run_terminal`; +- the folded chat run's mail is dequeued and dropped by + `vendor/intx/workflow-host/src/supervisor/supervisor.ts`, which finds + no in-memory cohort for the run, reads + `readWorkflowRunLifecycle` off the durable log, sees `terminal`, and + rejects permanently. + +`onBodyFailure: "continue"` cannot rescue either shape: the failure is +on the TOP-LEVEL run, not on a body occurrence. + +### Why "wake it again" is not the fix by itself + +`@corbits/chat`'s `wakeByAddress` returns early for any routable +address (CL-6267 handed respawn of a parked-but-announced deployment to +the sidecar's own park/wake handler), so a routable-but-dead run is +never woken. Restoring the deleted CL-6147 branch — undeploy the +resident, then redeploy — is necessary but not sufficient, for two +reasons found while tracing it: + +1. A run's id is derived from its address + (`deriveWorkflowRunId(deploymentMailAddress)`), so redeploying the + same address re-creates the _same_ run id. +2. The destructive teardown (`teardownDeployment` with `reclaimDirs`) + removes the deployment record and the per-step scratch, but NOT the + workflow-run repo that holds the run's durable event log. The + terminal event survives the redeploy, and the supervisor rejects the + next message for exactly the same reason. + +So a relaunch has to produce a genuinely new run, not the same one +again — either a fresh run id adopting the room's continuity (the room +is data now, so no history is lost), or a destructive teardown that +also reclaims the run's durable log. Which of the two is right is the +open design decision; the detection signal it hangs off is already +available to the hub as `workflow_run.status`. + +The hub-side detection and the relaunch itself are not implemented +here. What is on the record is a deterministic red: the proof now fails +at "PROOF 4 — the section survives the restart and runs its next +occurrence" with `409 workflow_run_terminal`, every time. diff --git a/scripts/e2e/cl-6324-launch-proof.ts b/scripts/e2e/cl-6324-launch-proof.ts index 899cf0478..3cb6291da 100644 --- a/scripts/e2e/cl-6324-launch-proof.ts +++ b/scripts/e2e/cl-6324-launch-proof.ts @@ -101,6 +101,18 @@ const proofModelSource = { const TURN_TIMEOUT_MS = 300_000; +/** + * Proof 4's mid-turn workload. Deliberately far longer than any model + * can finish inside `MID_TURN_KILL_DELAY_MS`, so the kill lands while + * inference is genuinely running rather than in the quiet gap after a + * short turn already completed — the distinction between proving + * crash-recovery and proving a clean restart. + */ +const MID_TURN_PROMPT = + "Count slowly from one to four hundred, one number per line. " + + "Write every number out; do not stop early and do not summarise."; +const MID_TURN_KILL_DELAY_MS = 3000; + const tracked: SpawnedApp[] = []; const tempDir = (prefix: string) => mkdtemp(pathJoin(tmpdir(), prefix)); const track = (app: SpawnedApp) => { @@ -1079,7 +1091,7 @@ async function main(): Promise { parts: [ { kind: "text", - text: "Count slowly from one to twenty, one number per line.", + text: MID_TURN_PROMPT, }, ], }, @@ -1093,13 +1105,27 @@ async function main(): Promise { hub.baseUrl, "POST", `/api/tenants/${tenant.tenantId}/workflows/${sectionDeploymentId}/mail`, - { content: "Count slowly from one to twenty, one number per line." }, + { content: MID_TURN_PROMPT }, user.cookies, ); expectStatus("send the mid-turn section message", sectionSent, 202); // Long enough that the turn is genuinely in flight — the child has // the mail and inference is running — but well short of a reply. - await Bun.sleep(3000); + await Bun.sleep(MID_TURN_KILL_DELAY_MS); + // "Mid-turn" is asserted, not assumed: the prompt above cannot be + // answered in the kill window on any model, so an answer already + // sitting in the room would mean the kill landed BETWEEN turns and + // the proof would be testing the easy case. + const answeredEarly = (await listAgentMessages()).filter( + (m) => !seenIds.has(m.id), + ); + if (answeredEarly.length > 0) { + throw new Error( + `the mid-turn kill was not mid-turn: the agent already answered ` + + `within ${String(MID_TURN_KILL_DELAY_MS)}ms — ` + + `${JSON.stringify(answeredEarly.map((m) => m.text))}`, + ); + } await sidecar.stop(); }); @@ -1156,9 +1182,6 @@ async function main(): Promise { ), ); - // Whatever the killed turn produced (a partial reply, or nothing) is - // not the proof; the proof is that the NEXT message is answered. - for (const m of await listAgentMessages()) seenIds.add(m.id); // Same rule for the section: the occurrence that died in the kill may // already have committed its `RunStarted`, so it is not evidence that // the section still answers. Only an occurrence started AFTER the @@ -1191,6 +1214,39 @@ async function main(): Promise { ), ); + // Whatever the killed turn produced is not the proof that the agent + // still works — that is the NEXT message's job. But it must not have + // produced NOTHING: a turn that died with the sidecar has to reach + // the reader as a partial answer or as the product's own visible + // notice ("I didn't get that one — send it again"), never as a + // message that was accepted and then silently swallowed. + await hop( + "PROOF 4 — the turn the kill interrupted surfaces visibly", + async () => { + const deadline = Date.now() + 120_000; + for (;;) { + const fresh = (await listAgentMessages()).filter( + (m) => !seenIds.has(m.id), + ); + if (fresh.length > 0) { + console.log( + ` TRANSCRIPT — the interrupted turn surfaced as: ` + + JSON.stringify(fresh.map((m) => m.text)), + ); + for (const m of fresh) seenIds.add(m.id); + return; + } + if (Date.now() > deadline) { + throw new Error( + "the turn the sidecar kill interrupted left NOTHING in the " + + "room: no partial answer and no undelivered notice, so the " + + "reader's message was accepted and silently dropped", + ); + } + await Bun.sleep(2000); + } + }, + ); await hop("PROOF 4 — the next message is answered after the restart", () => sendAndAwaitReply("Are you still there? One sentence.", "proof 4", 2), );