Merge pull request #35 from commandlayer/codex/update-chain-test-to-improve-logging-and-timeout-handling

[runtime] improve chain test failure diagnostics

Author: GsCommand

runtime/tests/runtime-signing.test.mjs

@@ -441,7 +441,7 @@ test("full chain clean -> summarize -> classify verifies with schema using parti
 
   async function runVerb(base, verb, content) {
     const controller = new AbortController();
-    const timeout = setTimeout(() => controller.abort(), 10000);
+    const timeout = setTimeout(() => controller.abort(), 5000);
 
     try {
       const res = await fetch(`${base}/${verb}/v1.1.0`, {
@@ -460,58 +460,99 @@ test("full chain clean -> summarize -> classify verifies with schema using parti
         throw new Error(`HTTP ${res.status}: ${text}`);
       }
 
-      const json = JSON.parse(text);
-      return json;
-
+      return JSON.parse(text);
     } catch (err) {
-      const cause = err?.cause?.code || err?.cause || err.message;
-      throw new Error(`runVerb(${verb}) failed: ${cause}`);
+      const message = err?.name === "AbortError" ? "AbortError" : err?.message || String(err);
+      throw new Error(`runVerb(${verb}) failed: ${message}`);
     } finally {
       clearTimeout(timeout);
     }
   }
 
-  try {
-    const source = "Hello world. This is a test document. It contains multiple sentences.";
-    let finalReceipt;
+  async function verifyReceiptWithTimeout(receipt) {
+    const controller = new AbortController();
+    const timeout = setTimeout(() => controller.abort(), 5000);
 
     try {
-      const clean = await runVerb(srv.base, "clean", source);
+      const res = await fetch(`${srv.base}/verify?schema=1`, {
+        method: "POST",
+        headers: { "content-type": "application/json" },
+        body: JSON.stringify(receipt),
+        signal: controller.signal,
+      });
+      const text = await res.text();
+      let json;
+
+      try {
+        json = JSON.parse(text);
+      } catch {
+        json = null;
+      }
 
-      assert.ok(clean?.receipt?.result?.cleaned_content, "clean step missing cleaned_content");
-      const cleanText = clean.receipt.result.cleaned_content;
+      if (!res.ok && res.status !== 202) {
+        throw new Error(`HTTP ${res.status}: ${text}`);
+      }
 
-      const summarize = await runVerb(srv.base, "summarize", cleanText);
+      return { res, text, json };
+    } catch (err) {
+      const message = err?.name === "AbortError" ? "AbortError" : err?.message || String(err);
+      throw new Error(`verify failed: ${message}`);
+    } finally {
+      clearTimeout(timeout);
+    }
+  }
 
-      assert.ok(summarize?.receipt?.result?.summary, "summarize step missing summary");
-      const summary = summarize.receipt.result.summary;
+  try {
+    const source = "Hello world. This is a test document. It contains multiple sentences.";
 
-      const classify = await runVerb(srv.base, "classify", summary);
+    console.log("[chain] before clean request");
+    const clean = await runVerb(srv.base, "clean", source);
+    console.log("[chain] after clean response");
+    assert.ok(clean?.receipt?.result?.cleaned_content, "clean step missing cleaned_content");
+    const cleanText = clean.receipt.result.cleaned_content;
 
-      assert.ok(classify?.receipt, "classify step missing receipt");
-      finalReceipt = classify.receipt;
+    console.log("[chain] before summarize request");
+    const summarize = await runVerb(srv.base, "summarize", cleanText);
+    console.log("[chain] after summarize response");
+    assert.ok(summarize?.receipt?.result?.summary, "summarize step missing summary");
+    const summary = summarize.receipt.result.summary;
 
-    } catch (err) {
-      console.error("CHAIN FAILURE DEBUG:");
-      console.error(err);
-      throw err;
-    }
+    console.log("[chain] before classify request");
+    const classify = await runVerb(srv.base, "classify", summary);
+    console.log("[chain] after classify response");
+    assert.ok(classify?.receipt, "classify step missing receipt");
+    const finalReceipt = classify.receipt;
 
     assert.equal(finalReceipt.x402.entry, "x402://classifyagent.eth/classify/v1.1.0");
 
-    const verifyRes = await fetch(`${srv.base}/verify?schema=1`, {
-      method: "POST",
-      headers: { "content-type": "application/json" },
-      body: JSON.stringify(finalReceipt),
-    });
-    const verifyJson = await verifyRes.json();
+    console.log("[chain] before verify request");
+    let verifyAttempt = await verifyReceiptWithTimeout(finalReceipt);
+    console.log("[chain] after verify response", verifyAttempt.res.status, verifyAttempt.json ?? verifyAttempt.text);
+
+    if (
+      verifyAttempt.res.status === 202
+      && verifyAttempt.json?.reason === "validator_not_warmed_yet"
+    ) {
+      console.log("[chain] verify warmup 202 response", verifyAttempt.json);
+      await new Promise((resolve) => setTimeout(resolve, 1200));
+      console.log("[chain] before verify request retry");
+      verifyAttempt = await verifyReceiptWithTimeout(finalReceipt);
+      console.log("[chain] after verify response retry", verifyAttempt.res.status, verifyAttempt.json ?? verifyAttempt.text);
+    }
 
-    console.log("VERIFY RESULT:", verifyJson);
+    const verifyRes = verifyAttempt.res;
+    const verifyJson = verifyAttempt.json;
 
+    assert.ok(verifyJson, "verify returned non-JSON response");
     assert.equal(verifyRes.status, 200);
     assert.equal(verifyJson.checks.signature_valid, true);
     assert.equal(verifyJson.checks.hash_matches, true);
     assert.equal(verifyJson.checks.schema_valid, true);
+  } catch (err) {
+    console.error("CHAIN FAILURE DEBUG:");
+    console.error(err);
+    console.error("SERVER STDERR:", srv.stderr());
+    throw err;
   } finally {
     await stop(srv.proc);
   }