test(experiment): checkpoint comparison observability

2026-08-18 19:28:30 +01:00
parent 952cb442b5
commit 913dfec507
5 changed files with 464 additions and 22 deletions
@@ -0,0 +1,300 @@
+/**
+ * Non-production focused-call diagnostics harness.
+ *
+ * Makes an independent request to the configured Ollama server with the
+ * same prompt, captures raw response text and completion metadata before
+ * delegating recovery/parse to an inline implementation (recoverJson) that
+ * mirrors the production helper's behavior.
+ *
+ * Callers must handle the returned diagnostics object or any thrown
+ * DiagnosticError to capture what the focused path would have seen.
+ */
+
+const DETECTION_CACHE = new Map();
+
+/**
+ * Inline JSON recovery — mirrors the production recoverJson in lib/llm/provider.js
+ * without importing it (recoverJson is not exported).
+ */
+function recoverJson(raw) {
+  if (typeof raw !== "string") return raw;
+  const trimmed = raw.trim();
+  
+  if (trimmed.length === 0) throw new SyntaxError("Model produced empty output");
+  
+  try {
+    return JSON.parse(trimmed);
+  } catch { /* Not directly parseable */ }
+
+  let result = trimmed;
+  
+  let braceDepth = 0;
+  let bracketDepth = 0;
+  let inString = false;
+  let escaped = false;
+  
+  for (let i = 0; i < result.length; i++) {
+    const ch = result[i];
+    
+    if (escaped) { escaped = false; continue; }
+    if (ch === '\\') { escaped = true; continue; }
+    if (ch === '"') { inString = !inString; continue; }
+    if (inString) continue;
+    if (ch === '{') braceDepth++;
+    else if (ch === '}') braceDepth--;
+    else if (ch === '[') bracketDepth++;
+    else if (ch === ']') bracketDepth--;
+  }
+
+  const closingBrackets = [];
+  for (let i = 0; i < bracketDepth; i++) closingBrackets.push(']');
+  for (let i = 0; i < braceDepth; i++) closingBrackets.push('}');
+  
+  if (closingBrackets.length > 0) {
+    const closed = result + closingBrackets.reverse().join('');
+    try { return JSON.parse(closed); } catch { /* still broken */ }
+  }
+
+  const lastOpen = Math.max(result.lastIndexOf('{'), result.lastIndexOf('['));
+  if (lastOpen >= 0) {
+    try { return JSON.parse(result.slice(lastOpen)); } catch { /* nothing works */ }
+  }
+
+  throw new SyntaxError("Model output could not be parsed as JSON: " + result.slice(0, 300) + "...");
+}
+
+/**
+ * Throw a tagged error that preserves captured diagnostics for failure
+ * artifact writing without any production code modification.
+ */
+class DiagnosticError extends Error {
+  constructor(message, cause) {
+    super(message, { cause });
+    this.name = "DiagnosticError";
+    this.focusedDiagnostics = null;
+  }
+}
+
+/**
+ * Detect whether /api/chat is available for a given baseUrl.
+ */
+async function detectChatSupport(baseUrl) {
+  if (DETECTION_CACHE.has(baseUrl)) return DETECTION_CACHE.get(baseUrl);
+
+  try {
+    const res = await fetch(`${baseUrl}/api/chat`, {
+      method: "POST",
+      headers: { "Content-Type": "application/json" },
+      body: JSON.stringify({
+        model: "dummy-check",
+        messages: [{ role: "user", content: "test" }],
+        stream: false,
+      }),
+    });
+
+    let chatSupported;
+    if (res.ok) { await res.body?.consume(); chatSupported = true; }
+    else if (res.status === 405 || res.status === 501) { await res.body?.consume(); chatSupported = false; }
+    else { await res.body?.consume(); chatSupported = false; }
+
+    DETECTION_CACHE.set(baseUrl, chatSupported);
+    return chatSupported;
+  } catch {
+    DETECTION_CACHE.set(baseUrl, false);
+    return false;
+  }
+}
+
+/**
+ * Make one focused request that captures all observable diagnostics
+ * before delegating recovery/parse back to the caller.
+ *
+ * @param {object} params
+ * @param {string} params.baseUrl
+ * @param {string} params.modelName
+ * @param {string} params.prompt
+ * @returns {{ diagnostics: object, error?: DiagnosticError | null, parsedResult: unknown }}
+ */
+export async function runFocusedDiagnostic({ baseUrl, modelName, prompt }) {
+  const diagnostics = {
+    rawResponseText: null,
+    rawResponseCharacterCount: null,
+    done: null,
+    doneReason: null,
+    promptEvalCount: null,
+    evalCount: null,
+    modelElapsedMs: null,
+    apiUsed: null,
+  };
+
+  const startedAt = Date.now();
+
+  let chatSupported = false;
+  try { chatSupported = await detectChatSupport(baseUrl); } catch { /* use default */ }
+
+  let rawResponse = null;
+  let fullResponseData = null;
+  let apiUsed = null;
+
+  // ---- Try /api/chat (same path as production) ----
+  if (chatSupported) {
+    try {
+      const controller = new AbortController();
+      const timeout = setTimeout(() => controller.abort(), 60000);
+
+      const res = await fetch(`${baseUrl}/api/chat`, {
+        method: "POST",
+        headers: { "Content-Type": "application/json" },
+        body: JSON.stringify({
+          model: modelName,
+          messages: [{ role: "user", content: prompt }],
+          stream: false,
+          format: "json",
+        }),
+        signal: controller.signal,
+      });
+
+      clearTimeout(timeout);
+
+      if (res.ok) {
+        fullResponseData = await res.json();
+        rawResponse = typeof fullResponseData.message?.content === "string"
+          ? fullResponseData.message.content
+          : JSON.stringify(fullResponseData.message?.content ?? null);
+        apiUsed = "/api/chat";
+      } else {
+        await res.body?.consume();
+      }
+    } catch (e) {
+      if (!e.message?.includes("abort")) { /* non-fatal */ }
+    }
+  }
+
+  // ---- Fallback to /api/generate (production-compatible path) ----
+  if (rawResponse == null || rawResponse === "") {
+    try {
+      const controller = new AbortController();
+      const timeout = setTimeout(() => controller.abort(), 300000);
+
+      apiUsed = "/api/generate";
+
+      const res = await fetch(`${baseUrl}/api/generate`, {
+        method: "POST",
+        headers: { "Content-Type": "application/json" },
+        body: JSON.stringify({
+          model: modelName,
+          prompt,
+          stream: false,
+        }),
+        signal: controller.signal,
+      });
+
+      clearTimeout(timeout);
+
+      if (!res.ok) {
+        const text = await res.text().catch(() => "");
+        throw new Error(`/api/generate returned ${res.status}: ${text.slice(0, 500)}`);
+      }
+
+      fullResponseData = await res.json();
+
+      rawResponse = typeof fullResponseData.response === "string"
+        ? fullResponseData.response
+        : JSON.stringify(fullResponseData);
+    } catch (e) {
+      // Preserve abort/timeout — these are legitimate signal-based failures
+      if (e.name === "AbortError" || e.message?.includes("aborted")) {
+        throw e;
+      }
+      if (apiUsed === "/api/generate") {
+        throw new Error(
+          `Ollama /api/generate request timed out after 5 minutes.\n\n` +
+          `This usually means:\n` +
+          `1. The model is loading into memory for the first time (cold start)\n` +
+          `2. Your hardware is slow for this model size\n` +
+          `3. Ollama server is overloaded\n\n` +
+          `Try:\n` +
+          `- Run the request again after ~1 minute (model may be cached now)\n` +
+          `- Use a smaller model (e.g., llama3.1 instead of llama3.1:70b)\n` +
+          `- Check Ollama logs: \`ollama serve\``
+        );
+      }
+      throw e;
+    }
+  }
+
+  diagnostics.rawResponseText = rawResponse;
+  diagnostics.rawResponseCharacterCount = rawResponse?.length ?? 0;
+  diagnostics.apiUsed = apiUsed || "none";
+  diagnostics.modelElapsedMs = Date.now() - startedAt;
+
+  // Completion metadata (available in fullResponseData for both /api/chat and /api/generate)
+  if (fullResponseData != null) {
+    diagnostics.done = fullResponseData.done ?? null;
+    diagnostics.doneReason = fullResponseData.done_reason ?? null;
+    diagnostics.promptEvalCount = fullResponseData.prompt_eval_count ?? null;
+    diagnostics.evalCount = fullResponseData.eval_count ?? null;
+  }
+
+  // ---- Error path: signal parse failure ----
+  if (rawResponse == null || rawResponse === "") {
+    let diagInfo = "";
+    if (fullResponseData) {
+      const keys = Object.keys(fullResponseData);
+      diagInfo += "Keys in response: " + keys.join(", ") + "\n";
+      for (const key of keys) {
+        const val = fullResponseData[key];
+        if (typeof val === "string") {
+          diagInfo += `  ${key}: "${val.slice(0, 200)}"\n`;
+        } else if (typeof val === "object" && val != null) {
+          try { diagInfo += `  ${key}: ${JSON.stringify(val).slice(0, 300)}\n`; } catch { diagInfo += `  ${key}: [object]\n`; }
+        } else {
+          diagInfo += `  ${key}: ${String(val)}\n`;
+        }
+      }
+    }
+
+    const err = new DiagnosticError(
+      "Model produced empty output.\n\n" +
+      "API used: " + (apiUsed || "none") + "\n" +
+      "/api/chat supported: " + chatSupported + "\n" +
+      "Full server response:\n" + (diagInfo || "(none)\n") +
+      "\nPossible causes:\n" +
+      "- Check 'ollama list' — make sure the model name matches exactly\n" +
+      "- The model may be corrupted. Try: ollama pull " + modelName + "\n" +
+      "- This Ollama version does not support format:json — relying on prompt instructions only\n" +
+      "- If your model is very small (e.g., tinyllama, phi), try a larger one like llama3.1"
+    );
+    err.focusedDiagnostics = structuredClone(diagnostics);
+    throw err;
+  }
+
+  // ---- Recovery / parse delegation to inline implementation ----
+  let parsedResult = null;
+  let recoveryError = null;
+  try {
+    parsedResult = recoverJson(rawResponse);
+  } catch (e) {
+    if (e instanceof SyntaxError) {
+      recoveryError = new DiagnosticError(
+        "Model returned output that could not be parsed as valid JSON.\n\n" +
+        "API used: " + (apiUsed || "none") + "\n" +
+        "/api/chat supported: " + chatSupported + "\n" +
+        "Raw model output:\n" + rawResponse.slice(0, 1000) + (rawResponse.length > 1000 ? "\n...(truncated)" : "") +
+        "\n\nPossible causes:\n" +
+        "- This Ollama version does not support format:json\n" +
+        "- Try a larger model (llama3.1, mistral-large) which follows JSON instructions better\n" +
+        "- Shorten your scenario to under 500 words\n" +
+        "- Consider upgrading Ollama: https://ollama.com/download"
+      );
+      recoveryError.focusedDiagnostics = structuredClone(diagnostics);
+    }
+    // Propagate non-SyntaxError without wrapping
+    if (!(e instanceof SyntaxError)) throw e;
+  }
+
+  return { diagnostics, parsedResult, error: recoveryError };
+}
+
+// ---- Named export for static analysis verification ----
+export function _getDetectionCache() { return DETECTION_CACHE; }
@@ -4,13 +4,17 @@ import dotenv from "dotenv";

 import fixture from "../../tests/fixtures/live-product-launch-update-response.json" with { type: "json" };
 import { buildGraphUpdatePrompt } from "../../lib/graph/prompt-builder.js";
-import { getProvider } from "../../lib/llm/provider.js";
 import { assertConfig } from "../../lib/config.js";

 import { createRequire } from "module";
 const require = createRequire(import.meta.url);
 const { runLiveExperiment } = require("../../tests/graph/live-update-experiment-helper.cjs");

+// Non-production diagnostics: an independent request captures raw-response
+// text and Ollama completion metadata (done, done_reason, prompt_eval_count,
+// eval_count) before delegating JSON recovery to the inline helper.
+import { runFocusedDiagnostic } from "./focus-diagnostics-helper.mjs";
+
 dotenv.config({ path: ".env.local" });

 const TARGET_NODE_ID = "nxmeiab";
@@ -135,29 +139,76 @@ function buildGlobalPlan() {
 }

 async function runFocused() {
-  const { modelName } = validateEnvironment();
-  const provider = getProvider();
+  const { baseUrl, modelName } = validateEnvironment();
  const plan = buildFocusedPlan();

-  const startedAt = Date.now();
-  const raw = await provider.generateReconstruction(plan.prompt, modelName);
-  const modelElapsedMs = Date.now() - startedAt;
+  // ---- non-production diagnostics wrapper ----
+  // Independent request captures raw response + completion metadata.
+  // The diagnostics helper mirrors the production JSON-recovery logic inline
+  // (since recoverJson is not exported) and delegates parse back to that
+  // implementation. The comparison runner only observes result/error objects.
+  const diagResult = await runFocusedDiagnostic({ baseUrl, modelName, prompt: plan.prompt });

-  const artifact = {
-    path: "focused",
-    targetNodeId: TARGET_NODE_ID,
-    modelName,
-    modelElapsedMs,
-    inputCharacterCount: plan.inputCharacterCount,
-    structuredResult: raw,
-  };
+  try {
+    if (diagResult.error) {
+      throw diagResult.error;
+    }
+    // Successful parse via production helper — proceed to standard artifact
+    const raw = diagResult.parsedResult;

-  const artifactPath = path.resolve(
-    "tests/experimental/artifacts/rto-focused-vs-global-focused.json",
-  );
-  await fs.mkdir(path.dirname(artifactPath), { recursive: true });
-  await fs.writeFile(artifactPath, JSON.stringify(artifact, null, 2));
-  console.log(JSON.stringify({ artifactPath, modelElapsedMs, inputCharacterCount: plan.inputCharacterCount }, null, 2));
+    const artifact = {
+      path: "focused",
+      targetNodeId: TARGET_NODE_ID,
+      modelName,
+      modelElapsedMs: diagResult.diagnostics.modelElapsedMs,
+      inputCharacterCount: plan.inputCharacterCount,
+      structuredResult: raw,
+    };
+
+    const artifactPath = path.resolve(
+      "tests/experimental/artifacts/rto-focused-vs-global-focused.json",
+    );
+    await fs.mkdir(path.dirname(artifactPath), { recursive: true });
+    await fs.writeFile(artifactPath, JSON.stringify(artifact, null, 2));
+    console.log(JSON.stringify({ artifactPath, modelElapsedMs: diagResult.diagnostics.modelElapsedMs, inputCharacterCount: plan.inputCharacterCount }, null, 2));
+    return;
+  } catch (err) {
+    const focusedDiagnostics = err.focusedDiagnostics ?? null;
+
+    if (!focusedDiagnostics) {
+      // Should not happen — every DiagnosticError carries diagnostics.
+      console.error("Unexpected: no diagnostics captured before parse failure.");
+      process.exit(1);
+    }
+
+    const errorArtifact = {
+      path: "focused",
+      modelName: focusedDiagnostics.apiUsed === "/api/chat" ? modelName : modelName,
+      inputCharacterCount: plan.inputCharacterCount,
+      rawResponseText: focusedDiagnostics.rawResponseText?.slice(0, 4096),
+      rawResponseCharacterCount: focusedDiagnostics.rawResponseCharacterCount,
+      done: focusedDiagnostics.done,
+      doneReason: focusedDiagnostics.doneReason,
+      promptEvalCount: focusedDiagnostics.promptEvalCount,
+      evalCount: focusedDiagnostics.evalCount,
+      errorType: err.name,
+      errorMessage: err.message.slice(0, 4096),
+    };
+
+    const artifactPath = path.resolve(
+      "tests/experimental/artifacts/rto-focused-vs-global-focused-failure.json",
+    );
+    await fs.mkdir(path.dirname(artifactPath), { recursive: true });
+    await fs.writeFile(artifactPath, JSON.stringify(errorArtifact, null, 2));
+
+    console.log(JSON.stringify({
+      artifactPath,
+      errorType: err.name,
+      rawResponseCharacterCount: focusedDiagnostics.rawResponseCharacterCount,
+      done: focusedDiagnostics.done,
+      doneReason: focusedDiagnostics.doneReason,
+    }, null, 2));
+  }
 }

 async function runGlobal() {
@@ -177,6 +228,8 @@ async function runGlobal() {
    targetNodeId: TARGET_NODE_ID,
    modelName,
    modelElapsedMs: result.modelElapsedMs,
+    providerGenerateCalls: result.providerGenerateCalls ?? 0,
+    providerTimingCaptured: typeof result.modelElapsedMs === "number",
    endToEndElapsedMs: result.endToEndElapsedMs ?? endToEndElapsedMs,
    inputCharacterCount: plan.inputCharacterCount,
    graphUpdateResultSummary: {
@@ -213,7 +266,7 @@ function printStaticValidation() {
    fixedQuestion: FIXED_QUESTION,
    fixedAnswer: FIXED_ANSWER,
    focused: {
-      resolvesTo: "scripts/experimental/rto-focused-answer-deconstruction.mjs-equivalent focused provider path",
+      resolvesTo: "scripts/experimental/rto-focused-vs-global-comparison-equivalent focused provider path",
      wholeGraphSupplied: false,
      inputCharacterCount: focused.inputCharacterCount,
      modelTimingBoundary: focused.modelTimingBoundary,
@@ -252,4 +305,4 @@ if (mode === "--focused") {
 } else {
  console.error(`Unknown mode: ${mode}`);
  process.exit(1);
-}
+}