diff --git a/README.md b/README.md index 4e1af59..5010f50 100644 --- a/README.md +++ b/README.md @@ -411,6 +411,10 @@ included in the new analysis is replaced with fresh judgments. If an analysis worker hits a fatal error, backpass stops handing out new transcripts and waits for every worker to stop before reporting the first fatal error. Calls already in flight finish, and their successful evidence is cached for reuse. Per-transcript failures, such as timeouts or unparseable output, still let the run continue; they are recorded, listed by `backpass status`, and retried on the next run. +A reply with no parseable JSON keeps a trace in its evidence record: `reply.class`, `reply.chars` (the reply's length), and its first and last 300 characters (`reply.head`, `reply.tail`), redacted before they are cut. +The class is judged from the reply text alone, since acpx reports no stop reason: `empty` (whitespace only), `truncated` (a code fence or `{` that never closes), `unparsed` (closed JSON-like text the extractor still rejected), or `prose` (no JSON shape at all). +After 3 unparseable replies in a row for the same transcript content, memory surface, analysis agent, model, effort, and analysis prompt, the transcript is skipped instead of retried: the run summary and `backpass status` say `skipped after 3 failures` (status reads each nested memory file's own evidence too and names the file), the last reply trace is kept, and it never counts as evidence. +Changing any of those inputs, or `--force`, analyzes it again; a timeout or exec failure resets the count and is always retried. ### 4. Aggregate gradients - and one judged consolidation call diff --git a/src/analyze.js b/src/analyze.js index 7bbcf78..1872305 100644 --- a/src/analyze.js +++ b/src/analyze.js @@ -4,13 +4,14 @@ import { randomUUID } from "node:crypto"; import { extractJson, runModelCall, usageRecord } from "./acpx.js"; import { distill } from "./distill.js"; +import { redact } from "./redact.js"; import { classifyInteraction } from "./interaction.js"; import { getAdapter, readTranscript } from "./discovery/index.js"; import { instructionUnits, renderInstructionIndex } from "./memory.js"; import { renderSkillIndexForAnalysis } from "./skills.js"; -import { renderPrompt } from "./prompts.js"; +import { loadPrompt, renderPrompt } from "./prompts.js"; import { renderOpenGapIndex } from "./gap-ledger.js"; -import { evidenceKey, isEvidenceFresh, safeFileName } from "./state.js"; +import { MAX_UNPARSED_REPLIES, evidenceKey, isEvidenceFresh, safeFileName, sha256 } from "./state.js"; import { emitProgress } from "./progress.js"; import { UserError, color, info, warn } from "./logger.js"; import { corroborationIdentityOf, transcriptIdentity } from "./transcript.js"; @@ -227,6 +228,93 @@ export function transcriptLabel(transcript) { return "(untitled)"; } +/** Characters kept from each end of an unparseable reply, after redaction. */ +export const REPLY_SNIPPET_CHARS = 300; + +/** + * Whether a reply opens a JSON object or a code fence and never closes it - the shape a + * reply cut off at an output-length limit leaves. An odd number of ``` fences is an + * unclosed fence. Otherwise the first `{` is scanned (string- and escape-aware) until + * its depth returns to zero: a closed first object means the reply was complete and + * failed to parse for some other reason. + */ +function opensUnclosed(text) { + if ((text.match(/```/g) || []).length % 2 === 1) return true; + const start = text.indexOf("{"); + if (start === -1) return false; + let depth = 0; + let inString = false; + let escaped = false; + for (const ch of text.slice(start)) { + if (inString) { + if (escaped) escaped = false; + else if (ch === "\\") escaped = true; + else if (ch === '"') inString = false; + } else if (ch === '"') { + inString = true; + } else if (ch === "{") { + depth += 1; + } else if (ch === "}") { + depth -= 1; + if (depth === 0) return false; + } + } + return true; +} + +/** + * Names why a reply had no parseable JSON, deterministically from the reply text alone. + * acpx's `--format quiet` output carries no harness stop reason, so none is read or + * guessed; truncation is judged from the reply's structure. Checked in order: + * + * - `empty`: whitespace only. + * - `truncated`: an opening fence or `{` that never closes (`opensUnclosed`). + * - `unparsed`: a `{` or a fence, all closed, that `extractJson` still could not parse. + * - `prose`: anything else - an answer with no JSON shape at all. + * + * @returns {"empty" | "truncated" | "unparsed" | "prose"} + */ +export function classifyUnparsedReply(text) { + const reply = String(text ?? ""); + if (!reply.trim()) return "empty"; + if (opensUnclosed(reply)) return "truncated"; + if (reply.includes("{") || reply.includes("```")) return "unparsed"; + return "prose"; +} + +/** + * The trace an unparseable reply leaves in its failed evidence record, so a later reader + * can tell its class apart without re-running the call: the class, the reply's length in + * characters, and its first and last `REPLY_SNIPPET_CHARS` characters. The whole reply is + * redacted before it is cut, so a secret is never split where a pattern would miss it; a + * reply no longer than both snippets together is kept whole in `head`, with no `tail`. + */ +export function unparsedReplyTrace(text) { + const reply = String(text ?? ""); + const chars = Array.from(redact(reply) || ""); + const trace = { + class: classifyUnparsedReply(reply), + chars: Array.from(reply).length, + head: chars.slice(0, REPLY_SNIPPET_CHARS).join(""), + }; + if (chars.length > REPLY_SNIPPET_CHARS * 2) trace.tail = chars.slice(-REPLY_SNIPPET_CHARS).join(""); + else if (chars.length > REPLY_SNIPPET_CHARS) trace.head = chars.join(""); + return trace; +} + +/** + * A reply arrived but held no parseable JSON. `reply` is what the evidence record keeps; + * `pick` is the agent, model, and effort that produced it. + */ +class UnparsedReplyError extends Error { + constructor(text, pick) { + const reply = unparsedReplyTrace(text); + super(`analysis returned no parseable JSON (${reply.class})`); + this.reply = reply; + this.pick = pick; + } +} + function promptPathFor(state, transcript) { return path.join(state.applyDir, "..", "prompts", `${safeFileName(transcriptIdentity(transcript))}.md`); } @@ -312,9 +400,10 @@ async function analyzeOne({ fs.mkdirSync(path.dirname(promptFile), { recursive: true }); fs.writeFileSync(promptFile, prompt); + /** @type {{ agent: string, model?: string | null, effort?: string | null } | null} */ let ranWith = null; const result = await config.agents.withFallthrough("analysis", async (pick) => { - ranWith = pick.agent; + ranWith = pick; const call = { agent: pick.agent, model: pick.model, @@ -332,14 +421,12 @@ async function analyzeOne({ for (const note of result.notes || []) noteOnce(note); const parsed = extractJson(result.text); - if (!parsed) { - throw new Error("analysis returned no parseable JSON"); - } + if (!parsed) throw new UnparsedReplyError(result.text, ranWith); return { status: "ok", evidence: sanitizeEvidence(parsed, memoryFile, distilled.trace), - usage: usageRecord(ranWith, result), + usage: usageRecord(ranWith?.agent, result), distilled, }; } finally { @@ -347,6 +434,43 @@ async function analyzeOne({ } } +/** + * What a streak of unparseable replies is counted against: the evidence key (transcript + * content, memory surface, analysis index) plus the call that answered - agent, model, + * effort, and the analysis prompt template. Changing any of them is a new question, so + * the streak starts over. + */ +export function replyFailureKey(key, pick) { + const template = sha256(loadPrompt("analysis")).slice(0, 16); + return [key, pick?.agent || "", pick?.model || "", pick?.effort || "", `prompt-${template}`].join("|"); +} + +/** + * Consecutive unparseable replies a failed record has seen at `failureKey`. A record from + * before the count existed, any other failure, or a different key counts zero. + */ +function unparsedRepliesBefore(existing, failureKey) { + if (existing?.status !== "failed" || existing.failureKey !== failureKey) return 0; + return Number.isInteger(existing.unparsedReplies) ? existing.unparsedReplies : 0; +} + +/** + * A transcript whose analysis came back unparseable `MAX_UNPARSED_REPLIES` times in a row + * for the same `replyFailureKey` is not called again: the record keeps its last reply + * trace and stays `failed`, so it never counts as evidence. Only unparseable replies + * count; a timeout or exec failure says nothing about the transcript, resets the streak, + * and is always retried. + */ +export function hasGivenUp(existing, transcript, memoryHash, pick) { + const failureKey = replyFailureKey(evidenceKey(transcript, memoryHash), pick); + return unparsedRepliesBefore(existing, failureKey) >= MAX_UNPARSED_REPLIES; +} + +/** The run-summary suffix for transcripts given up on; empty when there are none. */ +export function gaveUpNote(summary) { + return summary?.gaveUp ? ` · ${summary.gaveUp} skipped after ${MAX_UNPARSED_REPLIES} failures` : ""; +} + /** * Bounded-concurrency worker pool - the design's `--jobs N` fan-out. * The worker also receives its runner slot so the progress view can show one @@ -394,18 +518,21 @@ export async function analyzeTranscripts({ alsoLoaded = "", }) { const state = config.state; - const pending = []; + let pending = []; const summary = { total: transcripts.length, cached: 0, analyzed: 0, skipped: 0, failed: 0, + gaveUp: 0, usage: [], staleMemoryHash: 0, quotesNotInTrace: 0, }; const priorHashes = new Set(); + /** Prior failed records, read once here so a new failure can extend their streak. */ + const priorFailures = new Map(); const transcriptMetadata = (transcript) => ({ harness: transcript.harness, id: transcript.id, @@ -436,6 +563,7 @@ export async function analyzeTranscripts({ summary.cached += 1; continue; } + if (existing?.status === "failed") priorFailures.set(transcript, existing); // Distinguish "no prior evidence" from "prior evidence exists, but it was judged // against a memory surface that no longer matches" - a re-analysis here, not a miss. if (existing?.status === "ok" && existing.memoryHash && existing.memoryHash !== memoryHash) { @@ -445,6 +573,27 @@ export async function analyzeTranscripts({ pending.push(transcript); } + // A streak only holds for the agent that produced it, so a candidate for giving up costs + // the pick resolution here (cached for the fan-out below); a run with none skips it. + const streaks = force + ? [] + : pending.filter((transcript) => priorFailures.get(transcript)?.unparsedReplies >= MAX_UNPARSED_REPLIES); + if (streaks.length) { + const current = await config.agents.resolve("analysis"); + const givenUp = new Set( + streaks.filter((transcript) => hasGivenUp(priorFailures.get(transcript), transcript, memoryHash, current)), + ); + summary.gaveUp = givenUp.size; + pending = pending.filter((transcript) => !givenUp.has(transcript)); + } + if (summary.gaveUp) { + warn( + `${summary.gaveUp} transcript(s) skipped after ${MAX_UNPARSED_REPLIES} unparseable replies in a row; ` + + `\`backpass status\` lists them with their last reply, and a changed transcript, memory surface, ` + + `analysis model, or --force analyzes them again`, + ); + } + if (summary.staleMemoryHash) { info( `${color.yellow("·")} ${summary.staleMemoryHash} transcript(s) have evidence from a previous ` + @@ -545,10 +694,18 @@ export async function analyzeTranscripts({ } } catch (err) { if (err instanceof UserError) throw err; - // Per-transcript fail-soft: recorded, listed by `backpass status`, retried next run. + // Per-transcript fail-soft: recorded, listed by `backpass status`, retried next run - + // except after `MAX_UNPARSED_REPLIES` unparseable replies in a row (`hasGivenUp`). summary.failed += 1; warn(`${transcript.harness} ${transcriptLabel(transcript)}: ${err.message}`); - state.writeEvidence(transcript, { ...base, status: "failed", error: err.message }); + const record = { ...base, status: "failed", error: err.message }; + if (err instanceof UnparsedReplyError) { + const failureKey = replyFailureKey(base.key, err.pick); + const unparsedReplies = unparsedRepliesBefore(priorFailures.get(transcript), failureKey) + 1; + state.writeEvidence(transcript, { ...record, reply: err.reply, failureKey, unparsedReplies }); + } else { + state.writeEvidence(transcript, record); + } } finally { done += 1; emitProgress("analyze:tick", { diff --git a/src/cli.js b/src/cli.js index f588859..5c3d228 100644 --- a/src/cli.js +++ b/src/cli.js @@ -139,7 +139,8 @@ APPLY are checked together, and no edit may be decided twice --no-open print the review surface URL without opening a browser --dry-run show what would be written, write nothing - --force re-analyze transcripts that already have fresh evidence, + --force re-analyze transcripts that already have fresh evidence + or were skipped after repeated unparseable replies, and re-probe agents instead of trusting the probe cache OTHER diff --git a/src/commands/analyze.js b/src/commands/analyze.js index ca3cec1..4488553 100644 --- a/src/commands/analyze.js +++ b/src/commands/analyze.js @@ -1,15 +1,15 @@ -import { analyzeTranscripts, reclaimExpiredRawFiles } from "../analyze.js"; +import { analyzeTranscripts, gaveUpNote, reclaimExpiredRawFiles } from "../analyze.js"; import { userClaudeSkillsDir } from "../config.js"; import { UserError, color, info, json, out, warn } from "../logger.js"; import { memorySurfaceHash, resolveMemoryFiles, separateFileWarning } from "../memory.js"; import { attributeTranscripts, + layerNestedWeights, nestedContext, renderAlsoLoaded, reportNestedMemoryFiles, resolveNestedMemoryFiles, nestedReach, - nestedSurfaceHash, workedUnder, writeNestedReach, } from "../nested.js"; @@ -63,13 +63,7 @@ export function primaryMemoryFile(repo, config, scope = null) { // Nested memory files are weights of their own, named in `nestedMemoryFiles` - never a // separate root file to consolidate (`src/nested.js`). const named = reportNestedMemoryFiles(resolveNestedMemoryFiles(repo.root, config)); - const nested = named.map((weight) => { - const ancestors = named - .filter((candidate) => weight.dir.startsWith(`${candidate.dir}/`)) - .sort((a, b) => a.dir.length - b.dir.length); - const layered = { ...weight, ancestors }; - return { ...layered, hash: nestedSurfaceHash(resolved.primary, layered, skills) }; - }); + const nested = layerNestedWeights(resolved.primary, named, skills); return { file: resolved.primary, all: resolved.all, @@ -203,7 +197,7 @@ export async function cmdAnalyze(ctx) { out(`analyzed against ${file.path} (${file.units.length} instructions, ${file.tokens} tok)`); out( ` ${summary.analyzed} newly analyzed · ${summary.cached} cached · ` + - `${summary.skipped} skipped (too short) · ${summary.failed} failed`, + `${summary.skipped} skipped (too short) · ${summary.failed} failed${gaveUpNote(summary)}`, ); if (summary.failed) { out(color.dim(" failed transcripts are listed by `backpass status` and retried next run")); @@ -216,7 +210,7 @@ export async function cmdAnalyze(ctx) { if (nestedSummary) { out( ` ${nestedSummary.analyzed} newly analyzed · ${nestedSummary.cached} cached · ` + - `${nestedSummary.skipped} skipped (too short) · ${nestedSummary.failed} failed`, + `${nestedSummary.skipped} skipped (too short) · ${nestedSummary.failed} failed${gaveUpNote(nestedSummary)}`, ); } } diff --git a/src/commands/bootstrap.js b/src/commands/bootstrap.js index a8871b9..fbac15d 100644 --- a/src/commands/bootstrap.js +++ b/src/commands/bootstrap.js @@ -1,4 +1,4 @@ -import { analyzeTranscripts } from "../analyze.js"; +import { analyzeTranscripts, gaveUpNote } from "../analyze.js"; import { applyDecisions, writeBootstrapFiles } from "../apply/writer.js"; import { bootstrapTargets, renderPointer, starterMemoryFile } from "../bootstrap.js"; import { UserError, color, info, json, out, warn } from "../logger.js"; @@ -114,7 +114,7 @@ async function bootstrapRunCore(ctx, deps) { }); info( `${color.cyan("·")} evidence: ${result.summary.analyzed} new · ${result.summary.cached} cached · ` + - `${result.summary.skipped} too short · ${result.summary.failed} failed`, + `${result.summary.skipped} too short · ${result.summary.failed} failed${gaveUpNote(result.summary)}`, ); const folded = await fold(ctx, memoryFile, memoryHash, [], transcripts); diff --git a/src/commands/run.js b/src/commands/run.js index bbf2380..18a9f7f 100644 --- a/src/commands/run.js +++ b/src/commands/run.js @@ -1,6 +1,7 @@ import { UserError, color, info, json, out } from "../logger.js"; import { ProposalViolation } from "../proposal.js"; import { runAnalysis } from "./analyze.js"; +import { gaveUpNote } from "../analyze.js"; import { bootstrapJson, bootstrapRun, printBootstrap } from "./bootstrap.js"; import { printProposal, printSynthesisFailure, runProposal, synthesisFailureHint } from "./propose.js"; import { budgetBar, formatTokens } from "../tokens.js"; @@ -91,7 +92,7 @@ export async function cmdRun(ctx) { if (analysis.summary) { info( `${color.cyan("·")} evidence: ${analysis.summary.analyzed} new · ${analysis.summary.cached} cached · ` + - `${analysis.summary.skipped} too short · ${analysis.summary.failed} failed`, + `${analysis.summary.skipped} too short · ${analysis.summary.failed} failed${gaveUpNote(analysis.summary)}`, ); } for (const { weight, summary } of analysis.nested || []) { @@ -104,7 +105,7 @@ export async function cmdRun(ctx) { if (summary) { info( ` evidence: ${summary.analyzed} new · ${summary.cached} cached · ${summary.skipped} too short · ` + - `${summary.failed} failed`, + `${summary.failed} failed${gaveUpNote(summary)}`, ); } } diff --git a/src/commands/status.js b/src/commands/status.js index 851b0c4..3d619dd 100644 --- a/src/commands/status.js +++ b/src/commands/status.js @@ -3,8 +3,15 @@ import path from "node:path"; import { userClaudeSkillsDir } from "../config.js"; import { color, json, out } from "../logger.js"; -import { resolveMemoryFiles } from "../memory.js"; -import { nestedBudget, nestedReachWarning, readNestedReach, resolveNestedMemoryFiles } from "../nested.js"; +import { memorySurfaceHash, resolveMemoryFiles } from "../memory.js"; +import { + layerNestedWeights, + nestedBudget, + nestedReachWarning, + nestedStateDir, + readNestedReach, + resolveNestedMemoryFiles, +} from "../nested.js"; import { loadProjectSkills, resolveOverflowTarget, @@ -16,6 +23,7 @@ import { HostCache, pruneHostCache } from "../discovery/cache.js"; import { budgetBar, budgetStatus, formatTokens } from "../tokens.js"; import { table } from "./scan.js"; import { candidateKey, isProbeEntryFresh, resolvedEffort } from "../agents.js"; +import { MAX_UNPARSED_REPLIES, State } from "../state.js"; export async function cmdStatus(ctx) { const { repo, config, scope } = ctx; @@ -23,9 +31,6 @@ export async function cmdStatus(ctx) { const resolved = resolveMemoryFiles(repo.root, config.memoryFiles, { allowExternal: scope?.kind === "user" }); const files = resolved.all; - const evidence = state.listEvidence(); - const counts = { ok: 0, failed: 0, skipped: 0 }; - for (const e of evidence) counts[e.status] = (counts[e.status] || 0) + 1; const cache = state.readScanCache(); pruneHostCache(state.root); @@ -41,6 +46,34 @@ export async function cmdStatus(ctx) { const skillDirs = resolveProjectSkillDirs(repo.root, overflow.dir, config.skillsDirs || [], { exact: userScope }); const skills = loadProjectSkills(repo.root, overflow.dir, config.skillsDirs || [], { exact: userScope }); const descriptionTokens = skillDescriptionTokens(skills); + const nestedWeights = resolveNestedMemoryFiles(repo.root, config); + + // Each trained memory file keeps its own evidence store, keyed to its own surface hash. + const trained = nestedWeights.filter((weight) => weight.file && !weight.pointerTo); + const stores = [ + { path: resolved.primary?.path ?? null, state, memoryHash: memorySurfaceHash(resolved.hash, skills) }, + ...(resolved.primary ? layerNestedWeights(resolved.primary, trained, skills) : []).map((weight) => ({ + path: weight.path, + state: new State(repo.root, { stateDir: nestedStateDir(state, weight.path) }), + memoryHash: weight.hash, + })), + ]; + const counts = { ok: 0, failed: 0, skipped: 0 }; + const failed = []; + const evidenceByFile = stores.map((store) => { + const own = { path: store.path, ok: 0, failed: 0, skipped: 0, gaveUp: 0 }; + for (const e of store.state.listEvidence()) { + counts[e.status] = (counts[e.status] || 0) + 1; + own[e.status] = (own[e.status] || 0) + 1; + if (e.status !== "failed") continue; + const givenUp = isGivenUp(e, store.memoryHash); + if (givenUp) own.gaveUp += 1; + failed.push({ record: e, memory: store.path, givenUp }); + } + return own; + }); + const gaveUp = failed.filter((f) => f.givenUp).length; + const labelMemory = stores.length > 1; const duplicates = files .filter((file) => !resolved.pointers.includes(file)) @@ -60,7 +93,6 @@ export async function cmdStatus(ctx) { }; }); // Nested memory files are weights of their own, each under its own budget. - const nestedWeights = resolveNestedMemoryFiles(repo.root, config); for (const weight of nestedWeights) { budgets.push({ path: weight.path, @@ -103,7 +135,7 @@ export async function cmdStatus(ctx) { budgets, ...(nestedAttribution ? { nestedAttribution } : {}), crossSurfaceDuplicates: duplicates, - evidence: counts, + evidence: { ...counts, gaveUp, files: evidenceByFile }, scanCacheEntries: Object.keys(cache.entries).length, hosts: hostCache, summary: summary ? { analyzedSessions: summary.analyzedSessions, totals: summary.totals } : null, @@ -183,7 +215,8 @@ export async function cmdStatus(ctx) { out(color.dim("CACHE")); out(` scan cache ${Object.keys(cache.entries).length} file(s) fingerprinted`); out( - ` evidence ${counts.ok || 0} ok · ${counts.skipped || 0} skipped · ${color.red(String(counts.failed || 0))} failed`, + ` evidence ${counts.ok || 0} ok · ${counts.skipped || 0} skipped · ${color.red(String(counts.failed || 0))} failed` + + (gaveUp ? ` (${gaveUp} skipped after ${MAX_UNPARSED_REPLIES} failures)` : ""), ); if (summary) { const eligibleClusters = summary.totals.gapClusters; @@ -210,12 +243,29 @@ export async function cmdStatus(ctx) { } if (counts.failed) { - out(color.dim("FAILED TRANSCRIPTS (retried on the next run)")); - const rows = [["HARNESS", "SESSION", "ERROR"]]; - for (const e of evidence.filter((x) => x.status === "failed").slice(0, 10)) { - rows.push([e.transcript.harness, String(e.transcript.id).slice(-12), String(e.error).slice(0, 60)]); + out(color.dim("FAILED TRANSCRIPTS (retried on the next run unless skipped)")); + const rows = [[...(labelMemory ? ["MEMORY"] : []), "HARNESS", "SESSION", "REPLY", "NEXT RUN", "ERROR"]]; + for (const { record: e, memory, givenUp } of failed.slice(0, 10)) { + rows.push([ + ...(labelMemory ? [memory] : []), + e.transcript.harness, + String(e.transcript.id).slice(-12), + describeReply(e.reply), + givenUp ? `skipped after ${MAX_UNPARSED_REPLIES} failures` : "retry", + String(e.error).slice(0, 60), + ]); } out(table(rows)); + if (failed.some((f) => f.record.reply)) { + out( + color.dim( + labelMemory + ? " each unparseable reply's redacted head and tail are kept in its memory file's evidence/.json" + + " (.backpass/ for the root, .backpass/nested// for a nested file)" + : " each unparseable reply's redacted head and tail are kept in .backpass/evidence/.json", + ), + ); + } out(""); } @@ -261,6 +311,25 @@ function describeRole(config, role) { return color.dim(configured ? `${count} (effort ${configured})` : count); } +/** + * Whether the analysis stage gave up on a failed record at the current memory surface. + * `status` neither discovers transcripts nor resolves the analysis agent, so a changed + * transcript or agent still analyzes it again on the next run (`hasGivenUp` in src/analyze.js). + */ +function isGivenUp(record, memoryHash) { + return ( + record.memoryHash === memoryHash && + Number.isInteger(record.unparsedReplies) && + record.unparsedReplies >= MAX_UNPARSED_REPLIES + ); +} + +/** The class and size of an unparseable reply; "-" for any other failure or an older record. */ +function describeReply(reply) { + if (!reply || typeof reply.class !== "string") return "-"; + return Number.isInteger(reply.chars) ? `${reply.class} · ${reply.chars} chars` : reply.class; +} + function formatBytes(bytes) { if (bytes < 1024) return `${bytes} B`; if (bytes < 1024 * 1024) return `${Math.round(bytes / 1024)} KB`; diff --git a/src/nested.js b/src/nested.js index 4f88753..8c42aac 100644 --- a/src/nested.js +++ b/src/nested.js @@ -164,6 +164,20 @@ export function nestedSurfaceHash(rootFile, weight, skills) { ); } +/** + * Each nested file with the named files above it, shallowest first, and the surface hash + * its evidence is keyed to (`nestedSurfaceHash`). + */ +export function layerNestedWeights(rootFile, weights, skills) { + return weights.map((weight) => { + const ancestors = weights + .filter((candidate) => weight.dir.startsWith(`${candidate.dir}/`)) + .sort((a, b) => a.dir.length - b.dir.length); + const layered = { ...weight, ancestors }; + return { ...layered, hash: nestedSurfaceHash(rootFile, layered, skills) }; + }); +} + export function nestedStateDir(rootState, weightPath) { return path.join(rootState.root, "nested", `${safeFileName(weightPath)}-${sha256(weightPath).slice(0, 8)}`); } diff --git a/src/state.js b/src/state.js index 74ab4c9..5d564fe 100644 --- a/src/state.js +++ b/src/state.js @@ -250,6 +250,13 @@ function migrateEvidenceRecord(record, transcript, identity) { export const ANALYSIS_INDEX_VERSION = 4; +/** + * Consecutive unparseable analysis replies at one `replyFailureKey` after which the + * transcript is skipped rather than retried every run (`hasGivenUp` in `src/analyze.js`). + * A changed key (see `replyFailureKey`) or `--force` analyzes it again. + */ +export const MAX_UNPARSED_REPLIES = 3; + /** * Cache key for a transcript's analysis: its content signature, the memory-surface hash, * and the analysis index version. Changing any of them invalidates the evidence. @@ -263,6 +270,8 @@ export function evidenceKey(transcript, memoryHash) { * Only a successful analysis is worth caching. A `failed` entry is retried, and a * `skipped` entry is re-derived because the skip decision depends on configuration * (`minUserTurns`) rather than on the model - recomputing it costs one local file read. + * The one bound on retrying is `MAX_UNPARSED_REPLIES`, and a record given up on that way + * is still not fresh: it stays `failed` and never counts as evidence. */ export function isEvidenceFresh(evidence, transcript, memoryHash) { if (!evidence || evidence.status !== "ok") return false; diff --git a/test/analyze-failure-trace.test.js b/test/analyze-failure-trace.test.js new file mode 100644 index 0000000..b6a8e19 --- /dev/null +++ b/test/analyze-failure-trace.test.js @@ -0,0 +1,352 @@ +import test from "node:test"; +import assert from "node:assert/strict"; +import fs from "node:fs"; +import os from "node:os"; +import path from "node:path"; +import { fileURLToPath } from "node:url"; +import { spawnSync } from "node:child_process"; + +import { extractJson } from "../src/acpx.js"; +import { classifyUnparsedReply, hasGivenUp, replyFailureKey, unparsedReplyTrace } from "../src/analyze.js"; +import { MAX_UNPARSED_REPLIES, evidenceKey } from "../src/state.js"; + +/** + * An analysis reply with no parseable JSON (issue #193). The failed evidence record keeps + * a redacted trace of the reply and a class naming why it did not parse, and a transcript + * that answers unparseably `MAX_UNPARSED_REPLIES` times in a row for the same evidence key + * and analysis call is skipped - by name - instead of being retried every run. + */ + +const ROOT = path.resolve(path.dirname(fileURLToPath(import.meta.url)), ".."); +const CLI = path.join(ROOT, "bin", "backpass.js"); + +const binDir = fs.mkdtempSync(path.join(os.tmpdir(), "backpass-failtrace-bin-")); +const fakePi = path.join(binDir, "pi"); +const fakeAcpx = path.join(binDir, "acpx"); + +fs.writeFileSync(fakePi, `#!${process.execPath}\nprocess.exit(0);\n`); +fs.chmodSync(fakePi, 0o755); + +// Every prompt turn answers with the contents of FAKE_REPLY_FILE and appends one line to +// FAKE_CALL_LOG, so a test can change the reply between runs and count the model calls. +fs.writeFileSync( + fakeAcpx, + `#!${process.execPath} +const fs = require("node:fs"); +const argv = process.argv.slice(2); +if (argv.includes("config") && argv.includes("show")) { + process.stdout.write(JSON.stringify({ agents: {} }) + "\\n"); + process.exit(0); +} +if (argv.includes("--file")) { + fs.appendFileSync(process.env.FAKE_CALL_LOG, "call\\n"); + // A nested memory file's analysis answers from FAKE_NESTED_REPLY_FILE when it is set. + const prompt = fs.readFileSync(argv[argv.indexOf("--file") + 1], "utf8"); + const nested = process.env.FAKE_NESTED_REPLY_FILE && prompt.includes("## The memory file under audit: apps/"); + const reply = fs.readFileSync(nested ? process.env.FAKE_NESTED_REPLY_FILE : process.env.FAKE_REPLY_FILE, "utf8"); + // acpx's own timeout exit: a per-transcript failure with no reply to keep. + if (reply === "__TIMEOUT__") process.exit(3); + process.stdout.write(reply); + process.exit(0); +} +process.exit(0); +`, +); +fs.chmodSync(fakeAcpx, 0o755); + +const PROSE = "I reviewed the session and the agent followed the build instruction without trouble."; + +test("each unparseable reply is classed from its text alone", () => { + const cases = [ + ["", "empty"], + [" \n\t ", "empty"], + ['```json\n{"positive": [], "negative": []', "truncated"], + ['{"positive": [{"instruction": "AG-001", "quote": "a } brace in a string', "truncated"], + ['Here is the result:\n{"positive": [{"instruction": "AG-001"}', "truncated"], + ["{positive: [], negative: []}", "unparsed"], + ["```json\nnot json at all\n```", "unparsed"], + [PROSE, "prose"], + ]; + for (const [reply, expected] of cases) { + // Every case is a reply the extractor really rejects, so the class is never asked of + // a reply analysis would have accepted. + assert.equal(extractJson(reply), null, `extractJson must reject ${JSON.stringify(reply)}`); + assert.equal(classifyUnparsedReply(reply), expected, JSON.stringify(reply)); + } +}); + +test("the saved reply trace is redacted before it is cut, and measures the raw reply", () => { + const key = "sk-ant-abcdefghijklmnopqrstuvwxyz0123"; + const long = `export ANTHROPIC_API_KEY=${key}\n${"x".repeat(1000)}\nGITHUB_TOKEN=ghp_abcdefghijklmnopqrstuvwxyz`; + const trace = unparsedReplyTrace(long); + assert.equal(trace.class, "prose"); + assert.equal(trace.chars, long.length); + assert.equal(trace.head.length, 300); + assert.equal(trace.tail.length, 300); + assert.ok(!trace.head.includes(key) && !trace.tail.includes("ghp_"), "no secret survives into either snippet"); + assert.match(trace.head, /\[redacted/); + assert.match(trace.tail, /\[redacted/); + + const short = unparsedReplyTrace(PROSE); + assert.deepEqual(short, { class: "prose", chars: PROSE.length, head: PROSE }, "a short reply is kept whole"); + + const medium = "y".repeat(500); + assert.deepEqual(unparsedReplyTrace(medium), { class: "prose", chars: 500, head: medium }); +}); + +test("a streak gives up only for the same evidence key and the same analysis call", () => { + const transcript = { harness: "pi", id: "pi:s", nativeId: "s", contentSignature: "sig" }; + const pick = { agent: "pi", model: "m1", effort: "medium" }; + const key = evidenceKey(transcript, "sha256:a"); + const record = { + status: "failed", + key, + failureKey: replyFailureKey(key, pick), + unparsedReplies: MAX_UNPARSED_REPLIES, + }; + assert.equal(hasGivenUp(record, transcript, "sha256:a", pick), true); + assert.equal( + hasGivenUp({ ...record, unparsedReplies: MAX_UNPARSED_REPLIES - 1 }, transcript, "sha256:a", pick), + false, + ); + assert.equal(hasGivenUp(record, transcript, "sha256:b", pick), false, "a memory change starts over"); + assert.equal(hasGivenUp(record, { ...transcript, contentSignature: "grew" }, "sha256:a", pick), false); + assert.equal(hasGivenUp(record, transcript, "sha256:a", { ...pick, model: "m2" }), false, "a model change too"); + assert.equal(hasGivenUp(record, transcript, "sha256:a", { ...pick, effort: "high" }), false); + const legacy = { status: "failed", key, error: "analysis returned no parseable JSON" }; + assert.equal(hasGivenUp(legacy, transcript, "sha256:a", pick), false, "a record from before the count retries"); +}); + +function git(args, cwd) { + spawnSync("git", args, { cwd, stdio: "ignore" }); +} + +function initRepo(memory, nested) { + const dir = fs.realpathSync(fs.mkdtempSync(path.join(os.tmpdir(), "backpass-failtrace-repo-"))); + git(["init", "--quiet", "-b", "main"], dir); + git(["config", "user.email", "test@example.com"], dir); + git(["config", "user.name", "test"], dir); + fs.writeFileSync(path.join(dir, "AGENTS.md"), memory); + if (nested) { + fs.mkdirSync(path.join(dir, "apps", "api"), { recursive: true }); + fs.writeFileSync(path.join(dir, "apps", "api", "AGENTS.md"), "# API memory\n\n- Handlers live in src/routes.\n"); + fs.writeFileSync(path.join(dir, ".backpassrc.json"), JSON.stringify({ nestedMemoryFiles: ["apps/api/AGENTS.md"] })); + } + git(["add", "-A"], dir); + git(["commit", "-q", "-m", "memory"], dir); + return dir; +} + +function writeSession(home, id, cwd) { + const dir = path.join(home, ".pi", "agent", "sessions", id); + fs.mkdirSync(dir, { recursive: true }); + const entries = [ + { type: "session", version: 3, id, timestamp: new Date().toISOString(), cwd }, + { type: "message", message: { role: "user", content: "Please build the project." } }, + { type: "message", message: { role: "assistant", content: "Ran make build as instructed." } }, + { type: "message", message: { role: "user", content: "Now run the tests too." } }, + { type: "message", message: { role: "assistant", content: "Tests pass." } }, + ]; + fs.writeFileSync(path.join(dir, `1_${id}.jsonl`), `${entries.map((e) => JSON.stringify(e)).join("\n")}\n`); +} + +function harness({ nested = false } = {}) { + const home = fs.mkdtempSync(path.join(os.tmpdir(), "backpass-failtrace-home-")); + const dir = initRepo("# Agent instructions\n\n- Run `make build` before every push.\n", nested); + // A nested run's session works under apps/api, so both the root and the nested file analyze it. + writeSession(home, "session-a", nested ? path.join(dir, "apps", "api") : dir); + const replyFile = path.join(home, "reply.txt"); + const nestedReplyFile = path.join(home, "nested-reply.txt"); + const callLog = path.join(home, "calls.log"); + fs.writeFileSync(replyFile, PROSE); + fs.writeFileSync(nestedReplyFile, PROSE); + const env = { + ...process.env, + HOME: home, + USERPROFILE: home, + PATH: `${binDir}${path.delimiter}${process.env.PATH}`, + BACKPASS_ACPX_BIN: fakeAcpx, + FAKE_REPLY_FILE: replyFile, + FAKE_CALL_LOG: callLog, + ...(nested ? { FAKE_NESTED_REPLY_FILE: nestedReplyFile } : {}), + NO_COLOR: "1", + }; + const cli = (args) => { + const result = spawnSync(process.execPath, [CLI, ...args], { cwd: dir, env, encoding: "utf8", timeout: 20000 }); + return { ...result, output: `${result.stdout}${result.stderr}` }; + }; + const analyze = (extra = []) => { + const result = cli([ + "analyze", + "--harness", + "pi", + "--since", + "all", + "--analysis-agent", + "pi", + "--jobs", + "1", + ...extra, + ]); + assert.equal(result.status, 0, result.output); + return result; + }; + const analyzeJson = (extra = []) => { + const result = analyze(["--json", ...extra]); + return { ...result, summary: JSON.parse(result.stdout).summary }; + }; + const calls = () => + fs.existsSync(callLog) ? fs.readFileSync(callLog, "utf8").split("\n").filter(Boolean).length : 0; + const record = () => { + const evidenceDir = path.join(dir, ".backpass", "evidence"); + const [file] = fs.readdirSync(evidenceDir).filter((name) => name.endsWith(".json")); + return JSON.parse(fs.readFileSync(path.join(evidenceDir, file), "utf8")); + }; + return { dir, replyFile, cli, analyze, analyzeJson, calls, record }; +} + +test("a failed analysis keeps a redacted, classed trace of the reply", () => { + const h = harness(); + const reply = `Sorry, I cannot produce JSON. TOKEN=supersecretvalue123\n${"z".repeat(700)}\n{"positive": [`; + fs.writeFileSync(h.replyFile, reply); + + const run = h.analyzeJson(); + assert.equal(run.summary.failed, 1); + assert.match(run.stderr, /analysis returned no parseable JSON \(truncated\)/); + + const record = h.record(); + assert.equal(record.status, "failed"); + assert.equal(record.error, "analysis returned no parseable JSON (truncated)"); + assert.equal(record.reply.class, "truncated"); + assert.equal(record.reply.chars, reply.trim().length, "measured from the reply text, not reported by the model"); + assert.ok(!record.reply.head.includes("supersecretvalue123")); + assert.match(record.reply.head, /TOKEN=\[redacted\]/); + assert.ok(record.reply.tail.endsWith('{"positive": [')); + assert.equal(record.unparsedReplies, 1); + + const status = h.cli(["status"]); + assert.equal(status.status, 0, status.output); + assert.match(status.stdout, /REPLY\s+NEXT RUN\s+ERROR/); + assert.match(status.stdout, new RegExp(`truncated · ${record.reply.chars} chars\\s+retry`)); +}); + +test(`after ${MAX_UNPARSED_REPLIES} unparseable replies in a row a transcript is skipped by name until its key changes`, () => { + const h = harness(); + for (let n = 1; n <= MAX_UNPARSED_REPLIES; n += 1) { + const run = h.analyzeJson(); + assert.deepEqual([run.summary.failed, run.summary.gaveUp], [1, 0], `run ${n} still calls the model`); + assert.equal(h.record().unparsedReplies, n); + assert.equal(h.record().reply.class, "prose"); + } + assert.equal(h.calls(), MAX_UNPARSED_REPLIES); + + const skipped = h.analyze(); + assert.equal(h.calls(), MAX_UNPARSED_REPLIES, "no model call for a transcript given up on"); + assert.match(skipped.stdout, new RegExp(`0 failed · 1 skipped after ${MAX_UNPARSED_REPLIES} failures`)); + assert.match(skipped.stderr, /1 transcript\(s\) skipped after 3 unparseable replies in a row/); + assert.equal(h.record().reply.class, "prose", "the last failure trace is kept"); + assert.equal(h.record().status, "failed", "a skipped transcript never counts as evidence"); + + const status = h.cli(["status"]); + assert.match(status.stdout, /1 failed \(1 skipped after 3 failures\)/); + assert.match(status.stdout, new RegExp(`prose · ${PROSE.length} chars\\s+skipped after 3 failures`)); + const structured = JSON.parse(h.cli(["status", "--json"]).stdout); + assert.deepEqual([structured.evidence.failed, structured.evidence.gaveUp], [1, 1]); + + // --force asks again; one more unparseable reply keeps the streak. + assert.equal(h.analyzeJson(["--force"]).summary.failed, 1); + assert.equal(h.calls(), MAX_UNPARSED_REPLIES + 1); + + // A different analysis model is a new question, so the streak starts over. + assert.equal(h.analyzeJson(["--analysis-model", "other/model"]).summary.failed, 1); + assert.equal(h.record().unparsedReplies, 1); + assert.equal(h.analyzeJson(["--analysis-model", "other/model"]).summary.gaveUp, 0); + + // So is a memory-surface change, and a parseable answer then lands as evidence. + fs.writeFileSync(path.join(h.dir, "AGENTS.md"), "# Agent instructions\n\n- Always run lint.\n"); + fs.writeFileSync(h.replyFile, JSON.stringify({ positive: [], negative: [], gaps: [] })); + const recovered = h.analyzeJson(); + assert.deepEqual([recovered.summary.analyzed, recovered.summary.gaveUp], [1, 0]); + assert.equal(h.record().status, "ok"); +}); + +test("status names a give-up only while the memory surface it gave up at is current", () => { + const h = harness(); + for (let n = 1; n <= MAX_UNPARSED_REPLIES; n += 1) h.analyzeJson(); + assert.equal(JSON.parse(h.cli(["status", "--json"]).stdout).evidence.gaveUp, 1); + + fs.writeFileSync(path.join(h.dir, "AGENTS.md"), "# Agent instructions\n\n- Always run lint.\n"); + const status = h.cli(["status"]); + assert.match(status.stdout, new RegExp(`prose · ${PROSE.length} chars\\s+retry`)); + assert.doesNotMatch(status.stdout, /skipped after/); + assert.equal(JSON.parse(h.cli(["status", "--json"]).stdout).evidence.gaveUp, 0); + assert.equal(h.analyzeJson().summary.gaveUp, 0, "the next run does retry it"); +}); + +test("status reads a nested memory file's own evidence store and names its give-up", () => { + const h = harness({ nested: true }); + fs.writeFileSync(h.replyFile, JSON.stringify({ positive: [], negative: [], gaps: [] })); + for (let n = 1; n <= MAX_UNPARSED_REPLIES; n += 1) h.analyzeJson(); + assert.equal(h.calls(), 1 + MAX_UNPARSED_REPLIES, "the root answers once; the nested file asks every run"); + assert.equal(h.record().status, "ok", "the root analysis succeeded"); + + const status = h.cli(["status"]); + assert.equal(status.status, 0, status.output); + assert.match(status.stdout, /1 ok · 0 skipped · 1 failed \(1 skipped after 3 failures\)/); + assert.match(status.stdout, /MEMORY\s+HARNESS\s+SESSION\s+REPLY\s+NEXT RUN\s+ERROR/); + assert.match( + status.stdout, + new RegExp(`apps/api/AGENTS\\.md\\s+pi\\s+\\S+\\s+prose · ${PROSE.length} chars\\s+skipped after 3 failures`), + ); + const structured = JSON.parse(h.cli(["status", "--json"]).stdout).evidence; + assert.deepEqual([structured.ok, structured.failed, structured.gaveUp], [1, 1, 1]); + assert.deepEqual(structured.files, [ + { path: "AGENTS.md", ok: 1, failed: 0, skipped: 0, gaveUp: 0 }, + { path: "apps/api/AGENTS.md", ok: 0, failed: 1, skipped: 0, gaveUp: 1 }, + ]); + + // A change to the nested file is a new surface for its evidence: status shows a retry. + fs.appendFileSync(path.join(h.dir, "apps", "api", "AGENTS.md"), "- Run the contract tests.\n"); + const changed = JSON.parse(h.cli(["status", "--json"]).stdout).evidence; + assert.equal(changed.gaveUp, 0); + assert.match(h.cli(["status"]).stdout, new RegExp(`prose · ${PROSE.length} chars\\s+retry`)); +}); + +test("a timeout resets the streak and keeps no reply trace", () => { + const h = harness(); + h.analyzeJson(); + h.analyzeJson(); + assert.equal(h.record().unparsedReplies, 2); + + fs.writeFileSync(h.replyFile, "__TIMEOUT__"); + assert.equal(h.analyzeJson().summary.failed, 1); + const record = h.record(); + assert.match(record.error, /timeout/); + assert.equal(record.unparsedReplies, undefined); + assert.equal(record.reply, undefined); + + fs.writeFileSync(h.replyFile, PROSE); + h.analyzeJson(); + assert.equal(h.record().unparsedReplies, 1, "the streak counts only consecutive unparseable replies"); +}); + +test("status still lists an older failed record without the trace fields", () => { + const h = harness(); + h.analyzeJson(); + const evidenceDir = path.join(h.dir, ".backpass", "evidence"); + const [file] = fs.readdirSync(evidenceDir); + const legacy = h.record(); + delete legacy.reply; + delete legacy.failureKey; + delete legacy.unparsedReplies; + legacy.error = "analysis returned no parseable JSON"; + fs.writeFileSync(path.join(evidenceDir, file), JSON.stringify(legacy)); + + const status = h.cli(["status"]); + assert.equal(status.status, 0, status.output); + assert.match(status.stdout, /-\s+retry\s+analysis returned no parseable JSON/); + + const run = h.analyzeJson(); + assert.equal(run.summary.failed, 1, "a legacy failed record is retried"); + assert.equal(h.record().unparsedReplies, 1); +});