From 9ee91f22d8f41ba2302d7a3f1fdfbd44de4ae29b Mon Sep 17 00:00:00 2001 From: Alex Kombo Date: Wed, 23 Sep 2026 19:36:16 +0300 Subject: [PATCH 01/10] feat: trace research/dev runs and record code-gen model, usage and cost - Trace research and development supervisor runs with per-step observations - Emit code-gen generations (CLI plan/execute/relaxed, API plan/file/continuation) under generate-code via observeActiveGeneration, with real model, usage and cost - Parse the CLI JSON array transcript (shared cli-envelope) and report the costliest model and summed usage from modelUsage - Carry modelUsed, tokensUsed and costUsd from the code-gen module through CodeGenerationAgent into the generate-code output and console summary --- docs/observability.md | 58 ++++- src/agents/code-generation-agent.ts | 10 + src/cli/dev.ts | 18 +- src/cli/display-helpers.ts | 1 + src/cli/full.ts | 19 +- src/cli/research.ts | 11 +- src/layers/code-gen/interface.ts | 1 + .../code-gen/modules/claude-api/index.ts | 18 +- .../modules/claude-code-cli/cli-driver.ts | 34 +-- .../code-gen/modules/claude-code-cli/index.ts | 87 ++++--- src/llm/cli-envelope.ts | 104 +++++++++ src/llm/providers/anthropic.ts | 8 +- src/llm/providers/claude-cli.ts | 89 ++++---- src/llm/structured-cli.ts | 4 +- src/observability/index.ts | 139 ++++++++++-- src/supervisors/development-supervisor.ts | 59 ++++- src/supervisors/research-supervisor.ts | 36 ++- src/types/index.ts | 3 + test/agents/code-generation-agent.spec.ts | 9 + .../claude-code-cli/cli-driver.spec.ts | 32 +++ .../modules/claude-code-cli/index.spec.ts | 43 ++++ test/llm/providers/anthropic.spec.ts | 11 + test/llm/providers/claude-cli.spec.ts | 41 ++++ test/llm/structured-cli.spec.ts | 11 +- test/observability/index.spec.ts | 214 +++++++++++++++++- 25 files changed, 896 insertions(+), 164 deletions(-) create mode 100644 src/llm/cli-envelope.ts diff --git a/docs/observability.md b/docs/observability.md index 79864d9b..ce29530e 100644 --- a/docs/observability.md +++ b/docs/observability.md @@ -81,6 +81,37 @@ each time rather than mutating an earlier run's session. The PR identity lives i All traces from a single `run-pipeline` invocation share one **session ID** (a UUID generated at the start of `runPipeline`), visible in the Sessions view. +### Research and development CLIs + +`npm run research`, `npm run dev:run`, and `npm run full` each produce **one trace per CLI run** +(`cht-agent-research` / `cht-agent-dev` / `cht-agent-full`). The supervisors add their own +observations under whatever observation is active, so a full run with human-feedback iterations shows +every research and development pass in one tree: + +``` +cht-agent-full (root span — input: { ticket }) +├── agent: research (input: { title, domain, additionalContext? }) +│ ├── retriever: documentation-search +│ ├── retriever: code-context-search +│ ├── retriever: context-analysis +│ └── chain: generate-plan +│ └── generation: orchestration-plan +└── agent: development (input: { title, previewMode, additionalContext? }) + ├── agent: generate-code (input: { iteration }; output: files, confidence, cross-file issues, model, tokens, cost) + │ └── generation: code-gen-plan, code-gen-execute, code-gen-execute-relaxed (claude-code-cli) + │ or code-gen-plan, code-gen-file, code-gen-continuation (claude-api) + ├── evaluator: validate-implementation (output: { score }) + │ └── generation: implementation-validation + └── … repeats per refinement iteration +``` + +Graph nodes report failures through the state's `errors` array rather than throwing, so a node span +is marked `level: 'ERROR'` whenever its update carries errors. Any ERROR observation (a failed node, a failed or +empty generation) also marks the **root** ERROR with that message, so failed runs are filterable at +the trace level even when the workflow recovered. The root output is a run summary (phase and errors +for research; approvals, iterations, score, and files written for dev/full). Node outputs are summaries (phase, +the node's status message, counts); full prompts and completions live only on the generations. + --- ## Naming Conventions @@ -125,7 +156,7 @@ Follow these when adding instrumentation to new workflows: started before it are not retroactively updated. 3. Wrap each model call in `observeGeneration`. It records the prompt, the parsed output, - `usageDetails` (API path) or `costDetails` (Claude CLI path), and ends the generation with + `usageDetails`, `costDetails` when the path reports cost (Claude CLI), and ends the generation with `level: 'ERROR'` on failure. Build the chain with `createLangChainStructuredChain` (API) or `createStructuredCliChain` (CLI) so `invoke` returns a `GenerationResult` (`{ parsed, model?, usage?, costUsd? }`): @@ -134,26 +165,39 @@ Follow these when adding instrumentation to new workflows: () => chain.invoke(prompt)); ``` -4. Use `root.startObservation()` for non-LangChain operations: +4. Code with no step handle (the code-gen modules) uses `observeActiveGeneration(opts, invoke)`, + which nests under the active observation and records nothing outside a trace. Both helpers take + `output` to map what is recorded and `failure` for a result that did not throw but still failed + (for example a CLI `is_error`). + +5. For nested steps that don't have the root in scope, use `observeStep` (or `observeNode` for a + LangGraph node). Both nest under the **active** observation, so they need no parent argument, and + the callback receives the step to pass to `observeGeneration`: + ```typescript + .addNode('generatePlan', observeNode({ name: 'generate-plan', asType: 'chain' }, this.generatePlanNode.bind(this))) + ``` + Until a `withTrace` has run in the process they are no-ops, so supervisor unit tests need no stubbing. + + Use `root.startObservation()` for non-LangChain operations: ```typescript const span = root.startObservation('my-operation', { input: { key: value } }); // ... do work ... span.update({ output: { result } }).end(); ``` -5. Score terminal outcomes and set the root output: +6. Score terminal outcomes and set the root output: ```typescript scoreTrace(root, { name: 'my-outcome', value: success ? 1 : 0 }); root.update({ output: { result } }); ``` -6. Shut Langfuse down **once** at the end of the whole run, not per item. It flushes buffered spans, +7. Shut Langfuse down **once** at the end of the whole run, not per item. It flushes buffered spans, then queued scores, and awaits in-flight requests: ```typescript await shutdownLangfuse(); ``` -7. In tests, stub the observability module with proxyquire. Record calls so the spec can assert the +8. In tests, stub the observability module with proxyquire. Record calls so the spec can assert the root was actually passed to each stage (see `test/scripts/run-pipeline.spec.ts` for a full recording spy): ```typescript @@ -187,7 +231,7 @@ Every generation records the model, prompt, completion, latency, and errors. Cos | Path | What is sent | How Langfuse prices it | |---|---|---| | API (OpenRouter / Anthropic) | `usageDetails` from LangChain `usage_metadata` (input/output/total tokens) and the provider's reported model name | Inferred from the model definition in Langfuse | -| Claude CLI (`claude -p`) | `costDetails.total` from the CLI's `total_cost_usd` and the configured model name; the CLI reports no token counts | Ingested USD directly | +| Claude CLI (`claude -p`) | `costDetails.total` from the CLI's `total_cost_usd`, `usageDetails` summed from its `modelUsage` (input includes cache reads/writes), and the model the CLI reports it ran (the highest-cost `modelUsage` entry), not the configured label | Ingested USD directly | ## Delivery Semantics @@ -217,4 +261,4 @@ warning when Langfuse is unreachable, so tracing never changes a run's exit code - **Dashboards**: cost per PR, filter decision distribution, distill success rate, latency by stage. - **Alerting**: notify when `flag-for-human` rate or schema validation failures spike. - **Evaluation datasets**: curate representative PR inputs from the trace store for automated quality evaluation. -- **Agent instrumentation**: apply the same pattern to `ResearchSupervisor` and individual agents once the memory pipeline PoC is validated. +- **Agent internals**: MCP/Kapa and DeepWiki calls inside the research retrievers are not yet separate `tool` observations. diff --git a/src/agents/code-generation-agent.ts b/src/agents/code-generation-agent.ts index dadc73d2..01b4c50f 100644 --- a/src/agents/code-generation-agent.ts +++ b/src/agents/code-generation-agent.ts @@ -355,10 +355,14 @@ export class CodeGenerationAgent { crossFileIssues: crossFileIssues.length > 0 ? crossFileIssues : undefined, compileGateSkipped: llmResult.compileGateSkipped, compileGateSkipReason: llmResult.compileGateSkipReason, + tokensUsed: llmResult.tokensUsed, + modelUsed: llmResult.modelUsed, + costUsd: llmResult.costUsd, }; console.log(`[Code Generation Agent] Generated ${result.files.length} files`); console.log(`[Code Generation Agent] Confidence: ${(result.confidence * 100).toFixed(0)}%`); + console.log(`[Code Generation Agent] Model: ${result.modelUsed ?? 'unknown'}, tokens: ${result.tokensUsed ?? 'n/a'}, cost: ${result.costUsd === undefined ? 'n/a' : `$${result.costUsd.toFixed(4)}`}`); this.todos.printSummary(); return result; } @@ -692,6 +696,9 @@ export class CodeGenerationAgent { moduleCrossFileIssues?: import('../types').CrossFileIssue[]; compileGateSkipped?: boolean; compileGateSkipReason?: string; + tokensUsed?: number; + modelUsed?: string; + costUsd?: number; }> { const moduleInput = this.buildModuleInput(input, context); const session = await this.initBeadsSession(input); @@ -711,6 +718,9 @@ export class CodeGenerationAgent { moduleCrossFileIssues: moduleOutput.crossFileIssues, compileGateSkipped: moduleOutput.compileGateSkipped, compileGateSkipReason: moduleOutput.compileGateSkipReason, + tokensUsed: moduleOutput.tokensUsed, + modelUsed: moduleOutput.modelUsed, + costUsd: moduleOutput.costUsd, }; } diff --git a/src/cli/dev.ts b/src/cli/dev.ts index 75d6bc75..b21f0bc0 100644 --- a/src/cli/dev.ts +++ b/src/cli/dev.ts @@ -27,6 +27,7 @@ import * as dotenv from 'dotenv'; import * as path from 'node:path'; +import { withTrace, shutdownLangfuse, type TraceRoot } from '../observability'; import { DevelopmentSupervisor } from '../supervisors/development-supervisor'; import { parseTicketFile } from '../utils/ticket-parser'; import { displayIssueDetails } from '../workflows/research-workflow'; @@ -167,7 +168,7 @@ function ensureTicketPath(): string { return path.resolve(process.argv[2]); } -const main = async (): Promise => { +const main = async (root: TraceRoot): Promise => { console.log('╔════════════════════════════════════════════════════════════════╗'); console.log('║ CHT Multi-Agent System - Development Only CLI ║'); console.log('║ (Research phase skipped — using synthesized stubs) ║'); @@ -217,6 +218,12 @@ const main = async (): Promise => { // Display completion displayDevelopmentCompletion(workflowResult, developmentInput.options); + root.update({ output: { + approved: workflowResult.approved, + iterations: workflowResult.iterationCount, + score: workflowResult.result?.validationResult?.overallScore, + filesWritten: workflowResult.filesWritten, + } }); } catch (error) { console.error('\n❌ Error running development:', error); @@ -224,9 +231,14 @@ const main = async (): Promise => { console.error('Message:', error.message); console.error('Stack:', error.stack); } - process.exit(1); + throw error; } }; // Run the CLI -main(); +withTrace({ name: 'cht-agent-dev', tags: ['cht-agent', 'dev'], input: { ticket: process.argv[2] } }, main) + .then(shutdownLangfuse) + .catch(async () => { + await shutdownLangfuse(); + process.exit(1); + }); diff --git a/src/cli/display-helpers.ts b/src/cli/display-helpers.ts index 554bedd0..44085820 100644 --- a/src/cli/display-helpers.ts +++ b/src/cli/display-helpers.ts @@ -296,6 +296,7 @@ export const runResearchWorkflow = async ( const duration = ((Date.now() - startTime) / 1000).toFixed(2); displayResults(result, duration); + return result; }; export const displayResults = (result: ResearchState, duration: string) => { diff --git a/src/cli/full.ts b/src/cli/full.ts index 85b41a1f..f1308bad 100644 --- a/src/cli/full.ts +++ b/src/cli/full.ts @@ -32,6 +32,7 @@ import * as dotenv from 'dotenv'; import * as path from 'node:path'; +import { withTrace, shutdownLangfuse, type TraceRoot } from '../observability'; import { ResearchSupervisor } from '../supervisors/research-supervisor'; import { DevelopmentSupervisor } from '../supervisors/development-supervisor'; import { parseTicketFile } from '../utils/ticket-parser'; @@ -86,7 +87,7 @@ function ensureTicketPath(): string { return path.resolve(process.argv[2]); } -const main = async (): Promise => { +const main = async (root: TraceRoot): Promise => { console.log('╔════════════════════════════════════════════════════════════════╗'); console.log('║ CHT Multi-Agent System - Full Workflow CLI ║'); console.log('╚════════════════════════════════════════════════════════════════╝\n'); @@ -117,15 +118,27 @@ const main = async (): Promise => { developmentOptions ); displayFullWorkflowSummary(workflowResult); + root.update({ output: { + researchApproved: workflowResult.research.approved, + researchIterations: workflowResult.research.iterationCount, + developmentApproved: workflowResult.development?.approved, + developmentIterations: workflowResult.development?.iterationCount, + filesWritten: workflowResult.development?.filesWritten, + } }); } catch (error) { console.error('\n❌ Error running workflow:', error); if (error instanceof Error) { console.error('Message:', error.message); console.error('Stack:', error.stack); } - process.exit(1); + throw error; } }; // Run the CLI -main(); +withTrace({ name: 'cht-agent-full', tags: ['cht-agent', 'full'], input: { ticket: process.argv[2] } }, main) + .then(shutdownLangfuse) + .catch(async () => { + await shutdownLangfuse(); + process.exit(1); + }); diff --git a/src/cli/research.ts b/src/cli/research.ts index 32ffb7f6..e178b6d4 100644 --- a/src/cli/research.ts +++ b/src/cli/research.ts @@ -13,6 +13,7 @@ import * as dotenv from 'dotenv'; import * as path from 'node:path'; import { runResearchWorkflow } from './display-helpers'; +import { withTrace, shutdownLangfuse } from '../observability'; dotenv.config(); @@ -37,15 +38,15 @@ const HELP_HINTS = [ 'Content goes in markdown body with ## sections', ]; -runResearchWorkflow( - 'CHT Multi-Agent System - Research CLI', - getTicketPath, - HELP_HINTS, -).catch(error => { +withTrace({ name: 'cht-agent-research', tags: ['cht-agent', 'research'], input: { ticket: process.argv[2] } }, async root => { + const result = await runResearchWorkflow('CHT Multi-Agent System - Research CLI', getTicketPath, HELP_HINTS); + root.update({ output: { phase: result.currentPhase, planGenerated: result.orchestrationPlan !== undefined, errors: result.errors } }); +}).then(shutdownLangfuse).catch(async error => { console.error('\n❌ Error running research workflow:', error); if (error instanceof Error) { console.error('Message:', error.message); console.error('Stack:', error.stack); } + await shutdownLangfuse(); process.exit(1); }); diff --git a/src/layers/code-gen/interface.ts b/src/layers/code-gen/interface.ts index c7738c5b..422a3cd6 100644 --- a/src/layers/code-gen/interface.ts +++ b/src/layers/code-gen/interface.ts @@ -51,6 +51,7 @@ export interface CodeGenModuleOutput { explanation: string; tokensUsed?: number; modelUsed?: string; + costUsd?: number; /** * True when the module knows its output is incomplete (e.g., CLI hit * is_error or saturated max-turns). The agent surfaces this as a diff --git a/src/layers/code-gen/modules/claude-api/index.ts b/src/layers/code-gen/modules/claude-api/index.ts index f782223e..98e69a4b 100644 --- a/src/layers/code-gen/modules/claude-api/index.ts +++ b/src/layers/code-gen/modules/claude-api/index.ts @@ -5,9 +5,10 @@ import { ContextFile, GeneratedFile, } from '../../interface'; -import { LLMProvider, LLMToolDefinition, ToolHandler, createAnthropicProvider, getAPIConfigFromEnv } from '../../../../llm'; +import { InvokeOptions, LLMProvider, LLMResponse, LLMToolDefinition, ToolHandler, createAnthropicProvider, getAPIConfigFromEnv } from '../../../../llm'; import { readEnv } from '../../../../utils/env'; import { isShutdownRequested } from '../../../../utils/shutdown'; +import { fromLLMResponse, observeActiveGeneration } from '../../../../observability'; import { runApiCompileGate } from './compile-gate'; import { CompileValidationResult } from '../../../../agents/compile-validator'; import { @@ -403,10 +404,9 @@ export class ClaudeApiCodeGenModule implements CodeGenModule { input: CodeGenModuleInput, manifest: FileManifest ): Promise<{ plan: PlanItem[]; tokensUsed: number }> { - const llm = this.getProvider(); const prompt = this.buildPlanPrompt(input, manifest); - const response = await llm.invoke(prompt, { maxTokens: 8192 }); + const response = await this.tracedInvoke('code-gen-plan', prompt, { maxTokens: 8192 }); const tokensUsed = (response.usage?.inputTokens ?? 0) + (response.usage?.outputTokens ?? 0); const plan = this.parsePlan(response.content); @@ -678,13 +678,21 @@ export class ClaudeApiCodeGenModule implements CodeGenModule { }; } + private tracedInvoke(name: string, prompt: string, options: InvokeOptions): Promise { + const llm = this.getProvider(); + return observeActiveGeneration({ name, model: llm.modelName, input: prompt, output: (r) => r.content }, async () => { + const response = await llm.invoke(prompt, options); + return fromLLMResponse(response, response); + }); + } + private async invokeLLM( prompt: string, codeGenTools: { tools: LLMToolDefinition[]; toolHandler: ToolHandler } | undefined, filePath: string, ): Promise> | null> { try { - return await this.getProvider().invoke(prompt, { + return await this.tracedInvoke('code-gen-file', prompt, { maxTokens: 65536, ...(codeGenTools ? { tools: codeGenTools.tools, toolHandler: codeGenTools.toolHandler } : {}), }); @@ -838,7 +846,7 @@ export class ClaudeApiCodeGenModule implements CodeGenModule { const prompt = this.buildContinuationPrompt(lastLines, planItem, input); let response; try { - response = await this.getProvider().invoke(prompt, { maxTokens: 65536 }); + response = await this.tracedInvoke('code-gen-continuation', prompt, { maxTokens: 65536 }); } catch (error) { console.error(`[Code Gen Module] Continuation call ${iteration + 1} failed:`, error); return false; diff --git a/src/layers/code-gen/modules/claude-code-cli/cli-driver.ts b/src/layers/code-gen/modules/claude-code-cli/cli-driver.ts index 5ac02c6d..ecf48d5e 100644 --- a/src/layers/code-gen/modules/claude-code-cli/cli-driver.ts +++ b/src/layers/code-gen/modules/claude-code-cli/cli-driver.ts @@ -10,6 +10,7 @@ import { spawn, ChildProcess } from 'node:child_process'; import { readEnv } from '../../../../utils/env'; +import { findResultEnvelope, isJson, parsePlainObject, summarizeModelUsage, type CliModelUsageEntry } from '../../../../llm/cli-envelope'; export enum ClaudeCliPhase { Plan = 'plan', @@ -172,6 +173,8 @@ export interface ClaudeCliResult { numTurns: number; sessionId?: string; cost?: number; + model?: string; + usage?: { inputTokens: number; outputTokens: number }; } type RawCliJson = Partial<{ @@ -180,6 +183,7 @@ type RawCliJson = Partial<{ num_turns: number; session_id: string; total_cost_usd: number; + modelUsage: Record; }>; function toClaudeCliResult(parsed: RawCliJson): ClaudeCliResult { @@ -189,42 +193,22 @@ function toClaudeCliResult(parsed: RawCliJson): ClaudeCliResult { numTurns: parsed.num_turns ?? 0, sessionId: parsed.session_id, cost: parsed.total_cost_usd, + ...summarizeModelUsage(parsed.modelUsage), }; } -function tryParseResultObject(stdout: string): ClaudeCliResult | null { - const jsonMatch = /\{[\s\S]*"type"\s*:\s*"result"[\s\S]*\}/.exec(stdout); - if (!jsonMatch) return null; - try { - return toClaudeCliResult(JSON.parse(jsonMatch[0]) as RawCliJson); - } catch { - return null; - } -} - -function tryParseWholeStdout(stdout: string): ClaudeCliResult | null { - try { - return toClaudeCliResult(JSON.parse(stdout) as RawCliJson); - } catch { - return null; - } -} - /** * Parse the CLI's JSON output into a typed result. Empty stdout is treated as * an error case (isError=true) so callers can surface partial completions. - * Unparseable stdout falls back to the raw text with isError=false. + * JSON with no result message is an error; non-JSON stdout falls back to the raw text with isError=false. */ export function parseCliResult(stdout: string): ClaudeCliResult { if (!stdout || stdout.trim() === '') { return { result: '', isError: true, numTurns: 0 }; } - // Look for the result-shaped JSON object first (matches the existing claude-cli.ts pattern). - const fromResultBlock = tryParseResultObject(stdout); - if (fromResultBlock) return fromResultBlock; - // Fall back to treating the whole stdout as the result. - const fromWhole = tryParseWholeStdout(stdout); - if (fromWhole) return fromWhole; + const envelope = findResultEnvelope(stdout) ?? parsePlainObject(stdout); + if (envelope) return toClaudeCliResult(envelope); + if (isJson(stdout)) return { result: 'CLI output contained no result message', isError: true, numTurns: 0 }; return { result: stdout.trim(), isError: false, numTurns: 0 }; } diff --git a/src/layers/code-gen/modules/claude-code-cli/index.ts b/src/layers/code-gen/modules/claude-code-cli/index.ts index b6da1e74..3825a4fc 100644 --- a/src/layers/code-gen/modules/claude-code-cli/index.ts +++ b/src/layers/code-gen/modules/claude-code-cli/index.ts @@ -31,7 +31,7 @@ import { PlanItem, parsePlan } from '../../lib/plan'; import { buildPlanPrompt } from '../../lib/prompts'; import { buildFileManifest } from '../../lib/file-manifest'; import { buildExecutePrompt, buildRelaxedExecutePrompt } from './prompts'; -import { spawnClaudeCli, parseCliResult, ClaudeCliPhase, DEFAULT_MAX_TURNS } from './cli-driver'; +import { spawnClaudeCli, parseCliResult, ClaudeCliPhase, ClaudeCliResult, DEFAULT_MAX_TURNS } from './cli-driver'; import { snapshotChtCore, captureChtCoreDiff, @@ -42,6 +42,7 @@ import { import { validateClaudeCLI } from '../../../../llm'; import { readEnv } from '../../../../utils/env'; import { isShutdownRequested } from '../../../../utils/shutdown'; +import { fromLLMResponse, observeActiveGeneration } from '../../../../observability'; const PLAN_PHASE_TOOLS = ['Read', 'Grep', 'Glob']; const EXECUTE_PHASE_TOOLS = ['Read', 'Write', 'Edit', 'Grep', 'Glob']; @@ -116,17 +117,18 @@ export class ClaudeCodeCLICodeGenModule implements CodeGenModule { chtCorePath: string, ): Promise { if (isShutdownRequested()) return emptyResult(input, 'shutdown requested before plan'); - const plan = await this.runPlanPhase(input, chtCorePath); + const calls: ClaudeCliResult[] = []; + const plan = await this.runPlanPhase(input, chtCorePath, calls); if (plan.length === 0) { console.warn('[claude-code-cli] Plan phase produced no items; skipping execute'); - return emptyResult(input, 'empty plan'); + return emptyResult(input, 'empty plan', calls); } await this.surfacePlan(input, plan); - if (isShutdownRequested()) return emptyResult(input, 'shutdown requested before execute'); - const executeResult = await this.runExecutePhase(input, plan, chtCorePath); + if (isShutdownRequested()) return emptyResult(input, 'shutdown requested before execute', calls); + const executeResult = await this.runExecutePhase(input, plan, chtCorePath, calls); const captureResult = await this.captureWithRelaxedRetry({ - input, plan, executeResult, snapshotSha: snapshot.headSha, chtCorePath, + input, plan, executeResult, snapshotSha: snapshot.headSha, chtCorePath, calls, }); const compileResult = await runCompileGate(chtCorePath); const moduleIssues = collectModuleIssues({ @@ -139,7 +141,7 @@ export class ClaudeCodeCLICodeGenModule implements CodeGenModule { return { files: captureResult.files, explanation: `Generated ${captureResult.files.length} file(s) via Claude Code CLI tool use for "${input.ticket.issue.title}".`, - modelUsed: 'claude-cli', + ...summarizeSpend(calls), partialGeneration: executeResult.partialCompletion, partialGenerationReason: executeResult.reason, crossFileIssues: moduleIssues.length > 0 ? moduleIssues : undefined, @@ -170,9 +172,10 @@ export class ClaudeCodeCLICodeGenModule implements CodeGenModule { executeResult: { partialCompletion: boolean; reason?: string; resultText: string }; snapshotSha: string; chtCorePath: string; + calls: ClaudeCliResult[]; }, ): Promise<{ files: Awaited>; executeNoOp: boolean }> { - const { input, plan, executeResult, snapshotSha, chtCorePath } = opts; + const { input, plan, executeResult, snapshotSha, chtCorePath, calls } = opts; let files = await captureChtCoreDiff(chtCorePath, snapshotSha); console.log(`[claude-code-cli] Captured ${files.length} file change(s) from CLI session`); @@ -186,7 +189,7 @@ export class ClaudeCodeCLICodeGenModule implements CodeGenModule { console.warn( '[claude-code-cli] Zero files captured on STRICT execute; attempting relaxed retry (R17)' ); - await this.runExecutePhase(input, plan, chtCorePath, buildRelaxedExecutePrompt); + await this.runExecutePhase(input, plan, chtCorePath, calls, buildRelaxedExecutePrompt, 'code-gen-execute-relaxed'); files = await captureChtCoreDiff(chtCorePath, snapshotSha); console.log( `[claude-code-cli] After relaxed retry: ${files.length} file change(s) captured` @@ -200,16 +203,11 @@ export class ClaudeCodeCLICodeGenModule implements CodeGenModule { return { files, executeNoOp: false }; } - private async runPlanPhase(input: CodeGenModuleInput, cwd: string): Promise { + private async runPlanPhase(input: CodeGenModuleInput, cwd: string, calls: ClaudeCliResult[]): Promise { const manifest = buildFileManifest(input.contextFiles); const prompt = buildPlanPrompt(input, manifest); - const stdout = await spawnClaudeCli(prompt, { - cwd, - allowedTools: PLAN_PHASE_TOOLS, - permissionMode: 'acceptEdits', - phase: ClaudeCliPhase.Plan, - }); - const parsed = parseCliResult(stdout); + const parsed = await runTracedCliPhase('code-gen-plan', prompt, cwd, PLAN_PHASE_TOOLS, ClaudeCliPhase.Plan); + calls.push(parsed); if (parsed.isError) { console.warn( `[claude-code-cli] Plan phase reported is_error=true: ` + @@ -224,17 +222,13 @@ export class ClaudeCodeCLICodeGenModule implements CodeGenModule { input: CodeGenModuleInput, plan: PlanItem[], cwd: string, + calls: ClaudeCliResult[], promptBuilder: (input: CodeGenModuleInput, plan: PlanItem[]) => string = buildExecutePrompt, + generationName = 'code-gen-execute', ): Promise<{ partialCompletion: boolean; reason?: string; resultText: string }> { const prompt = promptBuilder(input, plan); - const stdout = await spawnClaudeCli(prompt, { - cwd, - allowedTools: EXECUTE_PHASE_TOOLS, - permissionMode: 'acceptEdits', - phase: ClaudeCliPhase.Execute, - }); - - const parsed = parseCliResult(stdout); + const parsed = await runTracedCliPhase(generationName, prompt, cwd, EXECUTE_PHASE_TOOLS, ClaudeCliPhase.Execute); + calls.push(parsed); if (parsed.isError) { const reason = `is_error=true from CLI: ${parsed.result.substring(0, 200)}`; console.warn(`[claude-code-cli] Execute phase: ${reason}`); @@ -249,6 +243,25 @@ export class ClaudeCodeCLICodeGenModule implements CodeGenModule { } } +function runTracedCliPhase( + name: string, + prompt: string, + cwd: string, + allowedTools: string[], + phase: ClaudeCliPhase, +): Promise { + return observeActiveGeneration({ + name, + model: 'claude-cli', + input: prompt, + output: (r) => ({ result: r.result, numTurns: r.numTurns }), + failure: (r) => (r.isError ? r.result || 'CLI reported is_error' : undefined), + }, async () => { + const parsed = parseCliResult(await spawnClaudeCli(prompt, { cwd, allowedTools, permissionMode: 'acceptEdits', phase })); + return fromLLMResponse({ model: parsed.model ?? 'claude-cli', usage: parsed.usage, costUsd: parsed.cost }, parsed); + }); +} + async function fireCallback( label: string, callback: ((...args: Args) => void | Promise) | undefined, @@ -306,11 +319,31 @@ function logModuleIssues(args: { } } -function emptyResult(input: CodeGenModuleInput, reason: string): CodeGenModuleOutput { +function emptyResult(input: CodeGenModuleInput, reason: string, calls: ReadonlyArray = []): CodeGenModuleOutput { return { files: [], explanation: `Generation aborted (${reason}) for "${input.ticket.issue.title}".`, - modelUsed: 'claude-cli', + ...summarizeSpend(calls), + }; +} + +/** + * Total tokens and cost across every CLI call in one generation, attributed to + * the model of the costliest call. + * + * @example + * summarizeSpend([{ result: '', isError: false, numTurns: 1, model: 'claude-opus-5-5', cost: 0.5, usage: { inputTokens: 90, outputTokens: 10 } }]); + * // { modelUsed: 'claude-opus-5-5', tokensUsed: 100, costUsd: 0.5 } + */ +export function summarizeSpend(calls: ReadonlyArray): Pick { + const costliest = calls + .filter((c) => c.model) + .reduce((top, c) => ((c.cost ?? 0) > (top?.cost ?? -1) ? c : top), undefined); + const costs = calls.flatMap((c) => (c.cost === undefined ? [] : [c.cost])); + return { + modelUsed: costliest?.model ?? 'claude-cli', + tokensUsed: calls.reduce((sum, c) => sum + (c.usage?.inputTokens ?? 0) + (c.usage?.outputTokens ?? 0), 0), + costUsd: costs.length > 0 ? costs.reduce((sum, c) => sum + c, 0) : undefined, }; } diff --git a/src/llm/cli-envelope.ts b/src/llm/cli-envelope.ts new file mode 100644 index 00000000..2bd676a2 --- /dev/null +++ b/src/llm/cli-envelope.ts @@ -0,0 +1,104 @@ +/** + * Parsing helpers for `claude -p --output-format json` stdout, shared by the + * text-only provider and the code-gen CLI driver. + */ + +export interface CliModelUsageEntry { + inputTokens?: number; + outputTokens?: number; + cacheReadInputTokens?: number; + cacheCreationInputTokens?: number; + costUSD?: number; +} + +function isResultMessage(value: unknown): value is Record { + return typeof value === 'object' && value !== null && (value as { type?: unknown }).type === 'result'; +} + +function resultFrom(value: unknown): Record | null { + if (Array.isArray(value)) return value.find(isResultMessage) ?? null; + return isResultMessage(value) ? value : null; +} + +function tryParse(text: string): unknown { + try { + return JSON.parse(text); + } catch { + return undefined; + } +} + +/** + * Parse stdout as a single JSON object (not an array or scalar), for CLI output + * that has the result fields but no `type` marker. + * + * @example + * parsePlainObject('{"result":"ok"}'); // { result: 'ok' } + * parsePlainObject('[{"type":"system"}]'); // null + */ +export function parsePlainObject>(stdout: string): T | null { + const value = tryParse(stdout); + return typeof value === 'object' && value !== null && !Array.isArray(value) ? (value as T) : null; +} + +/** + * True when stdout is valid JSON of any shape. + * + * @example + * isJson('[1]'); // true + * isJson('rate limited'); // false + */ +export function isJson(stdout: string): boolean { + return tryParse(stdout) !== undefined; +} + +function span(text: string, open: string, close: string): string | null { + const start = text.indexOf(open); + const end = text.lastIndexOf(close); + return start === -1 || end <= start ? null : text.slice(start, end + 1); +} + +/** + * Find the `type: "result"` message in CLI stdout. Newer CLI versions print a JSON + * array of every message (init, assistant, result); older ones print the result + * object alone. Either may be preceded or followed by non-JSON noise. + * + * @example + * findResultEnvelope('[{"type":"system"},{"type":"result","result":"ok"}]'); // { type: 'result', result: 'ok' } + * findResultEnvelope('warn\n{"type":"result","result":"ok"}'); // { type: 'result', result: 'ok' } + */ +export function findResultEnvelope>(stdout: string): T | null { + const candidates = [stdout.trim(), span(stdout, '[', ']'), span(stdout, '{', '}')]; + for (const candidate of candidates) { + if (!candidate) continue; + const found = resultFrom(tryParse(candidate)); + if (found) return found as T; + } + return null; +} + +function promptTokens(entry: CliModelUsageEntry): number { + return (entry.inputTokens ?? 0) + (entry.cacheReadInputTokens ?? 0) + (entry.cacheCreationInputTokens ?? 0); +} + +/** + * Derive the model that actually served the call (the highest-cost `modelUsage` + * entry, since the CLI may add cheap helper-model calls) and the token usage + * summed across every model. Prompt tokens include cache reads and writes. + * + * @example + * summarizeModelUsage({ 'claude-opus-5-5': { inputTokens: 2, cacheReadInputTokens: 8, outputTokens: 4, costUSD: 0.5 } }); + * // { model: 'claude-opus-5-5', usage: { inputTokens: 10, outputTokens: 4 } } + */ +export function summarizeModelUsage( + modelUsage: Record | undefined +): { model?: string; usage?: { inputTokens: number; outputTokens: number } } { + const entries = Object.entries(modelUsage ?? {}); + if (entries.length === 0) return {}; + const [model] = entries.reduce((top, e) => ((e[1].costUSD ?? 0) > (top[1].costUSD ?? 0) ? e : top)); + const usage = entries.reduce( + (sum, [, e]) => ({ inputTokens: sum.inputTokens + promptTokens(e), outputTokens: sum.outputTokens + (e.outputTokens ?? 0) }), + { inputTokens: 0, outputTokens: 0 } + ); + return { model, usage }; +} diff --git a/src/llm/providers/anthropic.ts b/src/llm/providers/anthropic.ts index 222e1637..c3c2fc60 100644 --- a/src/llm/providers/anthropic.ts +++ b/src/llm/providers/anthropic.ts @@ -243,7 +243,7 @@ export const createAnthropicProvider = (config: APIProviderConfig): LLMProvider }; }; - const invokeForJSON = async (prompt: string, options?: InvokeOptions): Promise => { + const invokeForJSONWithResponse = async (prompt: string, options?: InvokeOptions): Promise<{ parsed: T; response: LLMResponse }> => { // Increase maxTokens for JSON responses to avoid truncation const jsonOptions = { ...options, @@ -271,7 +271,7 @@ export const createAnthropicProvider = (config: APIProviderConfig): LLMProvider jsonStr = jsonStr.replace(/,(\s*[}\]])/g, '$1'); try { - return JSON.parse(jsonStr) as T; + return { parsed: JSON.parse(jsonStr) as T, response }; } catch (error) { // Log a snippet of the problematic JSON for debugging const snippet = jsonStr.substring(0, 500); @@ -281,6 +281,9 @@ export const createAnthropicProvider = (config: APIProviderConfig): LLMProvider } }; + const invokeForJSON = async (prompt: string, options?: InvokeOptions): Promise => + (await invokeForJSONWithResponse(prompt, options)).parsed; + return { providerType: 'anthropic', modelName: config.model, @@ -288,5 +291,6 @@ export const createAnthropicProvider = (config: APIProviderConfig): LLMProvider invoke, invokeWithMessages, invokeForJSON, + invokeForJSONWithResponse, }; }; diff --git a/src/llm/providers/claude-cli.ts b/src/llm/providers/claude-cli.ts index f806ad92..76609380 100644 --- a/src/llm/providers/claude-cli.ts +++ b/src/llm/providers/claude-cli.ts @@ -12,6 +12,7 @@ import { spawn, ChildProcess } from 'node:child_process'; import { extractJsonObject } from '../json-extract'; +import { findResultEnvelope, isJson, parsePlainObject, summarizeModelUsage, type CliModelUsageEntry } from '../cli-envelope'; import { isBatchFatalError } from '../rate-limit'; import { LLMProvider, @@ -32,7 +33,7 @@ export interface ClaudeCLIConfig { timeout?: number; /** Max agentic turns - set to 1 for simple completions (default: 1) */ maxTurns?: number; - /** Model to use (passed via prompt context, CLI uses account default) */ + /** Fallback model label; the CLI picks its model from ANTHROPIC_MODEL or account settings and the model it reports wins */ model?: string; /** Default max tokens */ maxTokens?: number; @@ -64,6 +65,7 @@ interface CLIResponse { duration_ms: number; num_turns: number; is_error: boolean; + modelUsage?: Record; } /* istanbul ignore next -- only invoked from the 60s progress interval below */ @@ -73,24 +75,6 @@ function totalLength(chunks: string[]): number { return total; } -/** - * Extract the CLI's JSON result envelope from stdout (which may have leading - * non-JSON noise). Returns null if no result envelope is found. Linear scan. - */ -function extractResultEnvelope(stdout: string): CLIResponse | null { - const start = stdout.indexOf('{'); - const end = stdout.lastIndexOf('}'); - if (start === -1 || end <= start) return null; - const candidate = stdout.slice(start, end + 1); - if (!/"type"\s*:\s*"result"/.test(candidate)) return null; - try { - return JSON.parse(candidate) as CLIResponse; - } catch (e) { - console.error('[Claude CLI] Failed to parse matched JSON:', e); - return null; - } -} - /** * Create a Claude CLI LLM provider * @@ -264,43 +248,51 @@ export const createClaudeCLIProvider = (config: ClaudeCLIConfig = {}): LLMProvid } // Claude CLI can include non-JSON content before the result object. - const envelope = extractResultEnvelope(stdout); + const envelope = findResultEnvelope(stdout) ?? parsePlainObject(stdout); if (envelope) return envelope; - // Try parsing the entire output as JSON - try { - return JSON.parse(stdout); - } catch { - // No JSON envelope. A plain-text usage/rate-limit or auth notice (the CLI - // can emit these without a result envelope) must NOT be mistaken for a - // successful result — classify it as an error so the batch stops instead - // of silently flagging a PR. See isBatchFatalError / run-pipeline. - if (isBatchFatalError(stdout)) { - console.error(`[Claude CLI] Limit/auth notice in plain-text output: ${stdout.substring(0, 200)}`); - return { - type: 'result', - subtype: 'error', - result: stdout.trim(), - session_id: '', - total_cost_usd: 0, - duration_ms: 0, - num_turns: 0, - is_error: true, - }; - } - // Otherwise treat stdout as the result. Log first 200 chars for debugging. - console.warn(`[Claude CLI] Non-JSON response (first 200 chars): ${stdout.substring(0, 200)}`); + if (isJson(stdout)) { + return { + type: 'result', + subtype: 'error', + result: 'CLI output contained no result message', + session_id: '', + total_cost_usd: 0, + duration_ms: 0, + num_turns: 0, + is_error: true, + }; + } + + // No JSON envelope. A plain-text usage/rate-limit or auth notice (the CLI + // can emit these without a result envelope) must NOT be mistaken for a + // successful result — classify it as an error so the batch stops instead + // of silently flagging a PR. See isBatchFatalError / run-pipeline. + if (isBatchFatalError(stdout)) { + console.error(`[Claude CLI] Limit/auth notice in plain-text output: ${stdout.substring(0, 200)}`); return { type: 'result', - subtype: 'success', + subtype: 'error', result: stdout.trim(), session_id: '', total_cost_usd: 0, duration_ms: 0, - num_turns: 1, - is_error: false, + num_turns: 0, + is_error: true, }; } + // Otherwise treat stdout as the result. Log first 200 chars for debugging. + console.warn(`[Claude CLI] Non-JSON response (first 200 chars): ${stdout.substring(0, 200)}`); + return { + type: 'result', + subtype: 'success', + result: stdout.trim(), + session_id: '', + total_cost_usd: 0, + duration_ms: 0, + num_turns: 1, + is_error: false, + }; }; /** @@ -320,10 +312,11 @@ export const createClaudeCLIProvider = (config: ClaudeCLIConfig = {}): LLMProvid console.warn('[Claude CLI] Warning: CLI returned empty result'); } + const reported = summarizeModelUsage(parsed.modelUsage); return { content: result, - model: modelName, - usage: undefined, // CLI doesn't provide token usage + model: reported.model ?? modelName, + usage: reported.usage, stopReason: parsed.subtype === 'success' ? 'end_turn' : 'error', costUsd: parsed.total_cost_usd, }; diff --git a/src/llm/structured-cli.ts b/src/llm/structured-cli.ts index 13f853f2..6276bf4c 100644 --- a/src/llm/structured-cli.ts +++ b/src/llm/structured-cli.ts @@ -16,7 +16,7 @@ import { z } from 'zod'; import { createLLMProviderFromEnv } from './factory'; -import { fromLangChain, type GenerationResult } from '../observability'; +import { fromLangChain, fromLLMResponse, type GenerationResult } from '../observability'; export { isUsingCLIProvider } from './factory'; @@ -77,7 +77,7 @@ ${shape}`; return { parsed: schema.parse(await provider.invokeForJSON(jsonPrompt, options)) }; } const { parsed, response } = await provider.invokeForJSONWithResponse(jsonPrompt, options); - return { parsed: schema.parse(parsed), model: response.model, costUsd: response.costUsd }; + return fromLLMResponse(response, schema.parse(parsed)); }, }; }; diff --git a/src/observability/index.ts b/src/observability/index.ts index 7e007989..92ae7b43 100644 --- a/src/observability/index.ts +++ b/src/observability/index.ts @@ -1,8 +1,9 @@ /** Langfuse v5 (OpenTelemetry) tracing; everything no-ops when LANGFUSE_ENABLED=false or a Langfuse key is unset. */ +import { AsyncLocalStorage } from 'node:async_hooks'; import { LangfuseClient } from '@langfuse/client'; import { LangfuseSpanProcessor } from '@langfuse/otel'; -import { propagateAttributes, startObservation, type LangfuseSpan } from '@langfuse/tracing'; +import { propagateAttributes, startActiveObservation, startObservation, type LangfuseGeneration, type LangfuseSpan } from '@langfuse/tracing'; import { context, propagation, trace } from '@opentelemetry/api'; import { NodeTracerProvider } from '@opentelemetry/sdk-trace-node'; @@ -16,10 +17,18 @@ interface LangfuseRuntime { let runtime: LangfuseRuntime | undefined; +const traceFailures = new AsyncLocalStorage(); + function errorMessage(err: unknown): string { return err instanceof Error ? err.message : String(err); } +/** Marks the observation ERROR and records it so the enclosing withTrace root is marked too. */ +function markFailed(observation: { update(attrs: { level: 'ERROR'; statusMessage: string }): unknown }, message: string): void { + observation.update({ level: 'ERROR', statusMessage: message }); + traceFailures.getStore()?.push(message); +} + function getRuntime(): LangfuseRuntime | undefined { if (process.env.LANGFUSE_ENABLED === 'false' || !process.env.LANGFUSE_PUBLIC_KEY || !process.env.LANGFUSE_SECRET_KEY) return undefined; if (runtime === undefined) { @@ -67,18 +76,70 @@ export interface TraceOptions { export function withTrace(opts: TraceOptions, fn: (root: TraceRoot) => Promise): Promise { getRuntime(); const { name, input, ...propagated } = opts; - return propagateAttributes({ traceName: name, ...propagated }, async () => { - const root = startObservation(name, { input }); + const failures: string[] = []; + return traceFailures.run(failures, () => propagateAttributes({ traceName: name, ...propagated }, () => + observeStep({ name, input, output: () => undefined, failure: () => summarizeFailures(failures) }, fn))); +} + +function summarizeFailures(failures: string[]): string | undefined { + if (failures.length === 0) return undefined; + return failures.length === 1 ? failures[0] : `${failures.length} observations failed; first: ${failures[0]}`; +} + +export type StepType = 'span' | 'agent' | 'tool' | 'chain' | 'retriever' | 'evaluator'; + +export interface StepOptions { + name: string; + asType?: StepType; + input?: unknown; + /** Maps the result to the recorded output; defaults to the result itself, `undefined` records nothing. */ + output?: (result: T) => unknown; + /** Returns an error message when a result that did not throw still represents a failure. */ + failure?: (result: T) => string | undefined; +} + +/** Child of the active observation (so nested steps nest automatically); a no-op span before any withTrace. */ +export async function observeStep(opts: StepOptions, fn: (step: TraceRoot) => Promise): Promise { + const run = async (step: TraceRoot): Promise => { + if (opts.input !== undefined) step.update({ input: opts.input }); try { - return await fn(root); + const result = await fn(step); + const output = opts.output ? opts.output(result) : result; + if (output !== undefined) step.update({ output }); + const failed = opts.failure?.(result); + if (failed) markFailed(step, failed); + return result; } catch (err) { const message = errorMessage(err); - root.update({ output: { error: message }, level: 'ERROR', statusMessage: message }); + step.update({ output: { error: message } }); + markFailed(step, message); throw err; - } finally { - root.end(); } - }); + }; + return startActiveObservation(opts.name, run, { asType: (opts.asType ?? 'span') as 'span' }); +} + +interface NodeUpdate { + errors?: string[]; + currentPhase?: string; + messages?: Array<{ content: string }>; +} + +/** Wraps a LangGraph node: nodes report failure through `errors` rather than throwing. */ +export function observeNode( + opts: { name: string; asType?: StepType; input?: (state: NoInfer) => unknown; output?: (result: NoInfer) => Record }, + node: (state: S, step: TraceRoot) => Promise +): (state: S) => Promise { + return (state) => observeStep({ + name: opts.name, + asType: opts.asType, + input: opts.input?.(state), + output: (r) => { + const update = r as NodeUpdate; + return { phase: update.currentPhase, summary: update.messages?.[0]?.content, errors: update.errors, ...opts.output?.(r) }; + }, + failure: (r) => (r as NodeUpdate).errors?.join('; ') || undefined, + }, (step) => node(state, step)); } export function scoreTrace(root: TraceRoot, score: { name: string; value: number; comment?: string }): void { @@ -107,24 +168,72 @@ export function fromLangChain(res: { return { parsed: res.parsed, model: meta?.model_name ?? meta?.model, usage }; } -export async function observeGeneration( - root: TraceRoot | undefined, - opts: { name: string; model: string; input: string }, +export function fromLLMResponse( + response: { model: string; usage?: { inputTokens: number; outputTokens: number }; costUsd?: number }, + parsed: T +): GenerationResult { + const u = response.usage; + const usage = u && { input: u.inputTokens, output: u.outputTokens, total: u.inputTokens + u.outputTokens }; + return { parsed, model: response.model, usage, costUsd: response.costUsd }; +} + +function isEmptyOutput(parsed: unknown): boolean { + return parsed === null || parsed === undefined || (typeof parsed === 'string' && parsed.trim() === ''); +} + +export interface GenerationOptions { + name: string; + model: string; + input: string; + /** Maps the parsed result to the recorded output; defaults to the parsed result itself. */ + output?: (parsed: T) => unknown; + /** Returns an error message when a result that did not throw still represents a failure. */ + failure?: (parsed: T) => string | undefined; +} + +async function recordGeneration( + generation: LangfuseGeneration | undefined, + opts: GenerationOptions, invoke: () => Promise> ): Promise { - const generation = root?.startObservation(opts.name, { model: opts.model, input: opts.input }, { asType: 'generation' }); try { const result = await invoke(); + const output = opts.output ? opts.output(result.parsed) : result.parsed; generation?.update({ - output: result.parsed, + output, model: result.model ?? opts.model, usageDetails: result.usage, costDetails: result.costUsd === undefined ? undefined : { total: result.costUsd }, - }).end(); + }); + const failed = opts.failure?.(result.parsed) ?? (isEmptyOutput(output) ? 'model returned empty output' : undefined); + if (generation && failed) markFailed(generation, failed); + generation?.end(); return result.parsed; } catch (err) { const message = errorMessage(err); - generation?.update({ output: { error: message }, level: 'ERROR', statusMessage: message }).end(); + if (generation) { + generation.update({ output: { error: message } }); + markFailed(generation, message); + generation.end(); + } throw err; } } + +export async function observeGeneration( + root: TraceRoot | undefined, + opts: GenerationOptions, + invoke: () => Promise> +): Promise { + const generation = root?.startObservation(opts.name, { model: opts.model, input: opts.input }, { asType: 'generation' }); + return recordGeneration(generation, opts, invoke); +} + +/** Generation under the active observation, for code that has no root handle; records nothing outside a trace. */ +export async function observeActiveGeneration( + opts: GenerationOptions, + invoke: () => Promise> +): Promise { + const active = trace.getActiveSpan() === undefined ? undefined : startObservation(opts.name, { model: opts.model, input: opts.input }, { asType: 'generation' }); + return recordGeneration(active, opts, invoke); +} diff --git a/src/supervisors/development-supervisor.ts b/src/supervisors/development-supervisor.ts index 2f8435eb..78b2bd9b 100644 --- a/src/supervisors/development-supervisor.ts +++ b/src/supervisors/development-supervisor.ts @@ -31,6 +31,7 @@ import { import { CodeGenerationAgent } from '../agents/code-generation-agent'; import { CodeGenModuleRegistry } from '../layers/code-gen/registry'; import { LLMProvider, createLLMProviderFromEnv } from '../llm'; +import { observeStep, observeNode, observeGeneration, fromLLMResponse, type GenerationResult, type TraceRoot } from '../observability'; import { createStagingDirectory, writeToStaging, @@ -194,6 +195,21 @@ const DevelopmentStateAnnotation = Annotation.Root({ }), }); +type DevelopmentGraphState = typeof DevelopmentStateAnnotation.State; + +function summarizeCodeGeneration(codeGen: CodeGenerationResult | undefined): Record { + if (!codeGen) return {}; + return { + files: codeGen.files.map((f) => `${f.action} ${f.relativePath}`), + confidence: codeGen.confidence, + compileGateSkipped: codeGen.compileGateSkipped, + crossFileIssues: codeGen.crossFileIssues?.length, + modelUsed: codeGen.modelUsed, + tokensUsed: codeGen.tokensUsed, + costUsd: codeGen.costUsd, + }; +} + export class DevelopmentSupervisor { private readonly graph: ReturnType; private readonly codeGenAgent: CodeGenerationAgent; @@ -219,8 +235,18 @@ export class DevelopmentSupervisor { private buildGraph() { const workflow = new StateGraph(DevelopmentStateAnnotation) // Define nodes - .addNode('generateCode', this.codeGenerationNode.bind(this)) - .addNode('validateImpl', this.validationNode.bind(this)) + .addNode('generateCode', observeNode({ + name: 'generate-code', + asType: 'agent', + input: (s) => ({ iteration: (s.iterationCount ?? 0) + 1 }), + output: (r) => summarizeCodeGeneration(r.codeGeneration), + }, (state: DevelopmentGraphState) => this.codeGenerationNode(state))) + .addNode('validateImpl', observeNode({ + name: 'validate-implementation', + asType: 'evaluator', + input: (s) => ({ iteration: s.iterationCount }), + output: (r) => ({ score: (r.validationResult as ImplementationValidation | undefined)?.overallScore }), + }, (state: DevelopmentGraphState, step: TraceRoot) => this.validationNode(state, step))) // Define edges with conditional routing from validation .addEdge(START, 'generateCode') @@ -321,7 +347,7 @@ export class DevelopmentSupervisor { /** * Node: Validation */ - private async validationNode(state: typeof DevelopmentStateAnnotation.State) { + private async validationNode(state: typeof DevelopmentStateAnnotation.State, step?: TraceRoot) { if (isShutdownRequested()) { console.log('[Development Supervisor] Shutdown requested; skipping validation node'); return { currentPhase: 'complete' as const }; @@ -338,7 +364,7 @@ export class DevelopmentSupervisor { if (codeGeneration.files.length === 0) { return this.skipValidationForEmptyFiles({ issue, codeGeneration, todoId }); } - return await this.runValidationWithTodo({ issue, codeGeneration, todoId }); + return await this.runValidationWithTodo({ issue, codeGeneration, todoId, step }); } private skipValidationForEmptyFiles(opts: { @@ -359,11 +385,13 @@ export class DevelopmentSupervisor { issue: IssueTemplate; codeGeneration: CodeGenerationResult; todoId: string; + step?: TraceRoot; }) { try { const validation = await this.validateImplementation( opts.issue, - opts.codeGeneration + opts.codeGeneration, + opts.step ); this.todos.complete(opts.todoId); this.todos.printSummary(); @@ -494,6 +522,7 @@ export class DevelopmentSupervisor { private async validateImplementation( issue: IssueTemplate, codeGen: CodeGenerationResult, + step?: TraceRoot, ): Promise { console.log('[Development Supervisor] Validating implementation...'); @@ -557,14 +586,22 @@ Respond with a JSON object: }`; try { - const result = await this.llm.invokeForJSON(prompt); - return result; + return await observeGeneration(step, { name: 'implementation-validation', model: this.llm.modelName, input: prompt }, + () => this.invokeValidation(prompt)); } catch { // Fallback validation based on heuristics return this.heuristicValidation(issue, codeGen); } } + private async invokeValidation(prompt: string): Promise> { + if (!this.llm.invokeForJSONWithResponse) { + return { parsed: await this.llm.invokeForJSON(prompt) }; + } + const { parsed, response } = await this.llm.invokeForJSONWithResponse(prompt); + return fromLLMResponse(response, parsed); + } + /** * Build a token-efficient code section for validation. * @@ -747,7 +784,13 @@ Respond with a JSON object: perFileFeedback: undefined, }; - const result = await this.graph.invoke(initialState); + const result = await observeStep({ + name: 'development', + asType: 'agent', + input: { title: input.issue.issue.title, previewMode: input.options.previewMode, additionalContext: input.additionalContext }, + output: (r) => ({ phase: r.currentPhase, iterations: r.iterationCount, score: r.validationResult?.overallScore, errors: r.errors }), + failure: (r) => r.errors.join('; ') || undefined, + }, () => this.graph.invoke(initialState)); console.log('\n========================================'); console.log('DEVELOPMENT SUPERVISOR - Development Phase Complete'); diff --git a/src/supervisors/research-supervisor.ts b/src/supervisors/research-supervisor.ts index 653982c6..53fe7edd 100644 --- a/src/supervisors/research-supervisor.ts +++ b/src/supervisors/research-supervisor.ts @@ -21,6 +21,7 @@ import { DocumentationSearchAgent } from '../agents/documentation-search-agent'; import { CodeContextAgent } from '../agents/code-context-agent'; import { ContextAnalysisAgent } from '../agents/context-analysis-agent'; import { LLMProvider, createLLMProviderFromEnv } from '../llm'; +import { observeStep, observeNode, observeGeneration, fromLLMResponse, type TraceRoot } from '../observability'; import { TodoTracker, createSupervisorTodoTracker } from '../utils/todo-tracker'; // Define the state annotation for type safety @@ -200,6 +201,13 @@ function collectBulletText(section: string): string[] { .filter(line => line.length > 0); } +type ResearchGraphState = typeof ResearchStateAnnotation.State; + +function retrieverInput(state: ResearchGraphState): Record | undefined { + const issue = state.issue?.issue; + return issue && { title: issue.title, domain: issue.technical_context.domain, components: issue.technical_context.components }; +} + /** The inputs the plan-generation methods share, bundled into one object. */ interface PlanContext { issue: IssueTemplate; @@ -246,10 +254,10 @@ export class ResearchSupervisor { private buildGraph() { const workflow = new StateGraph(ResearchStateAnnotation) // Define nodes - .addNode('documentationSearch', this.documentationSearchNode.bind(this)) - .addNode('codeContextSearch', this.codeContextSearchNode.bind(this)) - .addNode('analyzeContext', this.contextAnalysisNode.bind(this)) - .addNode('generatePlan', this.generatePlanNode.bind(this)) + .addNode('documentationSearch', observeNode({ name: 'documentation-search', asType: 'retriever', input: retrieverInput }, (state: ResearchGraphState) => this.documentationSearchNode(state))) + .addNode('codeContextSearch', observeNode({ name: 'code-context-search', asType: 'retriever', input: retrieverInput }, (state: ResearchGraphState) => this.codeContextSearchNode(state))) + .addNode('analyzeContext', observeNode({ name: 'context-analysis', asType: 'retriever', input: retrieverInput }, (state: ResearchGraphState) => this.contextAnalysisNode(state))) + .addNode('generatePlan', observeNode({ name: 'generate-plan', asType: 'chain' }, this.generatePlanNode.bind(this))) // Define edges .addEdge(START, 'documentationSearch') @@ -390,7 +398,7 @@ export class ResearchSupervisor { /** * Node: Generate Orchestration Plan */ - private async generatePlanNode(state: typeof ResearchStateAnnotation.State) { + private async generatePlanNode(state: typeof ResearchStateAnnotation.State, step?: TraceRoot) { console.log('\n=== GENERATE PLAN NODE ==='); const todoId = 'research-4'; this.todos.start(todoId); @@ -413,7 +421,7 @@ export class ResearchSupervisor { analysis: state.contextAnalysis, codeContext, codeContextFindings: state.codeContextFindings, - }); + }, step); this.todos.complete(todoId); this.todos.printSummary(); return { @@ -442,13 +450,15 @@ export class ResearchSupervisor { /** * Generate orchestration plan using Claude */ - private async generateOrchestrationPlan(ctx: PlanContext): Promise { + private async generateOrchestrationPlan(ctx: PlanContext, step?: TraceRoot): Promise { console.log('[Research Supervisor] Generating orchestration plan...'); const prompt = this.buildPlanPrompt(ctx); - const response = await this.llm.invoke(prompt); - const content = response.content; + const content = await observeGeneration(step, { name: 'orchestration-plan', model: this.llm.modelName, input: prompt }, async () => { + const response = await this.llm.invoke(prompt); + return fromLLMResponse(response, response.content); + }); // Parse the response into structured plan const plan = this.parsePlanResponse(content, ctx); @@ -862,7 +872,13 @@ Format your response with clear section headers (### IMPLEMENTATION APPROACH, ## let result: typeof ResearchStateAnnotation.State; try { - result = await this.graph.invoke(initialState); + result = await observeStep({ + name: 'research', + asType: 'agent', + input: { title: issue.issue.title, domain: issue.issue.technical_context.domain, additionalContext }, + output: (r) => ({ phase: r.currentPhase, errors: r.errors }), + failure: (r) => r.errors.join('; ') || undefined, + }, () => this.graph.invoke(initialState)); } catch (error) { return handleResearchError(error, initialState); } diff --git a/src/types/index.ts b/src/types/index.ts index 48e903d2..d9e3744f 100644 --- a/src/types/index.ts +++ b/src/types/index.ts @@ -539,6 +539,9 @@ export interface CodeGenerationResult { compileGateSkipped?: boolean; /** Human-readable reason associated with {@link compileGateSkipped}. */ compileGateSkipReason?: string; + tokensUsed?: number; + modelUsed?: string; + costUsd?: number; } /** diff --git a/test/agents/code-generation-agent.spec.ts b/test/agents/code-generation-agent.spec.ts index 6b124bdf..7c23586a 100644 --- a/test/agents/code-generation-agent.spec.ts +++ b/test/agents/code-generation-agent.spec.ts @@ -148,6 +148,15 @@ describe('CodeGenerationAgent', () => { expect(moduleInput).to.have.property('targetDirectory', '/tmp/cht-core'); }); + it('forwards the module model, tokens and cost onto the result', async () => { + generateStub.resolves({ files: [], explanation: '', modelUsed: 'claude-opus-5-5', tokensUsed: 3000, costUsd: 0.5 }); + const agent = new CodeGenerationAgent({ llmProvider: mockProvider, codeGenRegistry: mockRegistry }); + + const result = await agent.generate(createInput()); + + expect(result).to.include({ modelUsed: 'claude-opus-5-5', tokensUsed: 3000, costUsd: 0.5 }); + }); + it('should map layer GeneratedFile to agent GeneratedFile with inferred metadata', async () => { const moduleOutput: CodeGenModuleOutput = { files: [ diff --git a/test/layers/code-gen/modules/claude-code-cli/cli-driver.spec.ts b/test/layers/code-gen/modules/claude-code-cli/cli-driver.spec.ts index 6c6bd363..67c54617 100644 --- a/test/layers/code-gen/modules/claude-code-cli/cli-driver.spec.ts +++ b/test/layers/code-gen/modules/claude-code-cli/cli-driver.spec.ts @@ -149,6 +149,38 @@ describe('cli-driver (A.2a)', () => { expect(parsed.isError).to.equal(false); }); + it('reads the result message from an array transcript', () => { + const driver = loadDriver(); + const stdout = JSON.stringify([ + { type: 'system', subtype: 'init' }, + { type: 'result', result: 'done', is_error: false, num_turns: 7, total_cost_usd: 1.5 }, + ]); + const parsed = driver.parseCliResult(stdout); + expect(parsed.result).to.equal('done'); + expect(parsed.numTurns).to.equal(7); + expect(parsed.cost).to.equal(1.5); + }); + + it('reports the costliest model and summed usage from modelUsage', () => { + const driver = loadDriver(); + const stdout = JSON.stringify([ + { type: 'system', subtype: 'init', model: 'claude-opus-5-5' }, + { type: 'result', result: 'done', num_turns: 3, total_cost_usd: 2.1, modelUsage: { + 'claude-haiku-4-5-20251001': { inputTokens: 100, outputTokens: 10, costUSD: 0.1 }, + 'claude-opus-5-5': { inputTokens: 5, cacheReadInputTokens: 900, cacheCreationInputTokens: 95, outputTokens: 40, costUSD: 2 }, + } }, + ]); + const parsed = driver.parseCliResult(stdout); + expect(parsed.model).to.equal('claude-opus-5-5'); + expect(parsed.usage).to.deep.equal({ inputTokens: 1100, outputTokens: 50 }); + }); + + it('returns isError=true for an array transcript with no result message', () => { + const driver = loadDriver(); + const parsed = driver.parseCliResult(JSON.stringify([{ type: 'system', subtype: 'init' }])); + expect(parsed.isError).to.equal(true); + }); + it('handles plain non-result JSON via the fallback parser', () => { const driver = loadDriver(); const json = JSON.stringify({ result: 'plain', is_error: false, num_turns: 2 }); diff --git a/test/layers/code-gen/modules/claude-code-cli/index.spec.ts b/test/layers/code-gen/modules/claude-code-cli/index.spec.ts index 57186748..94ff7337 100644 --- a/test/layers/code-gen/modules/claude-code-cli/index.spec.ts +++ b/test/layers/code-gen/modules/claude-code-cli/index.spec.ts @@ -85,6 +85,49 @@ describe('ClaudeCodeCLICodeGenModule (A.2d orchestrator)', () => { expect(result.files[0].path).to.equal('src/a.ts'); }); + it('reports summed tokens and cost across CLI calls, attributed to the costliest model', async () => { + const spawnStub = sinon.stub() + .onFirstCall().resolves(planResultText) + .onSecondCall().resolves('execute ok'); + const parse = (s: string) => (s === planResultText + ? { result: s, isError: false, numTurns: 1, model: 'claude-sonnet-5', cost: 0.1, usage: { inputTokens: 900, outputTokens: 100 } } + : { result: s, isError: false, numTurns: 3, model: 'claude-opus-5-5', cost: 0.4, usage: { inputTokens: 1800, outputTokens: 200 } }); + const { ClaudeCodeCLICodeGenModule } = proxyquire('../../../../../src/layers/code-gen/modules/claude-code-cli/index', { + './cli-driver': { spawnClaudeCli: spawnStub, parseCliResult: parse, ClaudeCliPhase: { Plan: 'plan', Execute: 'execute' } }, + './workspace': { + snapshotChtCore: sinon.stub().resolves({ headSha: 'abc1234', stashRef: null }), + captureChtCoreDiff: sinon.stub().resolves([{ path: 'src/a.ts', content: 'x', purpose: 'p' }]), + rollbackChtCore: sinon.stub().resolves({ reset: 'ok', clean: 'ok', stashPop: 'skipped', errors: [] }), + }, + }); + + const result = await new ClaudeCodeCLICodeGenModule().generate(baseInput()); + + expect(result.modelUsed).to.equal('claude-opus-5-5'); + expect(result.tokensUsed).to.equal(3000); + expect(result.costUsd).to.be.closeTo(0.5, 1e-9); + }); + + it('still reports the plan call spend when the plan is empty', async () => { + const emptyPlan = '=== PLAN ===\n=== END PLAN ===\n'; + const { ClaudeCodeCLICodeGenModule } = proxyquire('../../../../../src/layers/code-gen/modules/claude-code-cli/index', { + './cli-driver': { + spawnClaudeCli: sinon.stub().resolves(emptyPlan), + parseCliResult: (s: string) => ({ result: s, isError: false, numTurns: 1, model: 'claude-opus-5-5', cost: 0.2, usage: { inputTokens: 40, outputTokens: 2 } }), + ClaudeCliPhase: { Plan: 'plan', Execute: 'execute' }, + }, + './workspace': { + snapshotChtCore: sinon.stub().resolves({ headSha: 'abc1234', stashRef: null }), + captureChtCoreDiff: sinon.stub(), + rollbackChtCore: sinon.stub().resolves({ reset: 'ok', clean: 'ok', stashPop: 'skipped', errors: [] }), + }, + }); + + const result = await new ClaudeCodeCLICodeGenModule().generate(baseInput()); + + expect(result).to.include({ modelUsed: 'claude-opus-5-5', tokensUsed: 42, costUsd: 0.2 }); + }); + it('returns empty result and rolls back when shutdown is requested after snapshot but before plan', async () => { const spawnStub = sinon.stub(); const snapshotStub = sinon.stub().resolves({ headSha: 'abc1234', stashRef: null }); diff --git a/test/llm/providers/anthropic.spec.ts b/test/llm/providers/anthropic.spec.ts index a04660ab..69a062f5 100644 --- a/test/llm/providers/anthropic.spec.ts +++ b/test/llm/providers/anthropic.spec.ts @@ -254,6 +254,17 @@ describe('createAnthropicProvider invokeForJSON', () => { expect(caught).to.not.be.null; expect(caught!.message).to.match(/Failed to parse LLM response as JSON/); }); + it('invokeForJSONWithResponse returns the parsed JSON with the token usage the model reported', async () => { + const stub = buildChatAnthropicStub(); + stub.invokeStub.resolves({ + content: '{"score": 80}', + usage_metadata: { input_tokens: 120, output_tokens: 30 }, + } as ChatResponseShape); + const provider = loadProviderTyped(stub, baseConfig); + const { parsed, response } = await provider.invokeForJSONWithResponse!<{ score: number }>('p'); + expect(parsed).to.deep.equal({ score: 80 }); + expect(response.usage).to.deep.equal({ inputTokens: 120, outputTokens: 30 }); + }); }); describe('createAnthropicProvider tool-use loop', () => { diff --git a/test/llm/providers/claude-cli.spec.ts b/test/llm/providers/claude-cli.spec.ts index 42575113..88bd20c4 100644 --- a/test/llm/providers/claude-cli.spec.ts +++ b/test/llm/providers/claude-cli.spec.ts @@ -315,6 +315,47 @@ describe('createClaudeCLIProvider (v9a.7) — invokeWithMessages / invokeForJSON }); }); +describe('createClaudeCLIProvider — array transcript output', () => { + const transcript = (result?: Record): string => + JSON.stringify([ + { type: 'system', subtype: 'init', model: 'claude-opus-5-5' }, + { type: 'assistant', message: { content: [{ type: 'text', text: '{"a":1}' }] } }, + ...(result ? [result] : []), + ]); + + it('reads the result message, the model that ran, and its token usage', async () => { + const { provider } = loadProvider([ + { + stdout: transcript(JSON.parse(cliResultJson({ + result: '{"a":1}', + total_cost_usd: 0.6, + modelUsage: { + 'claude-opus-5-5': { inputTokens: 2, cacheReadInputTokens: 100, cacheCreationInputTokens: 50, outputTokens: 4, costUSD: 0.59 }, + 'claude-haiku-4-5-20251001': { inputTokens: 10, outputTokens: 1, costUSD: 0.01 }, + }, + }))), + closeCode: 0, + }, + ]); + const { parsed, response } = await provider.invokeForJSONWithResponse!<{ a: number }>('p'); + expect(parsed.a).to.equal(1); + expect(response.model).to.equal('claude-opus-5-5'); + expect(response.usage).to.deep.equal({ inputTokens: 162, outputTokens: 5 }); + expect(response.costUsd).to.equal(0.6); + }); + + it('throws instead of returning empty content when the transcript has no result message', async () => { + const { provider } = loadProvider([{ stdout: transcript(), closeCode: 1 }]); + let caught: Error | undefined; + try { + await provider.invoke('p'); + } catch (e) { + caught = e as Error; + } + expect(caught?.message).to.equal('Claude CLI error: CLI output contained no result message'); + }); +}); + describe('validateClaudeCLI (v9a.7)', () => { /** validateClaudeCLI uses spawn directly; can't reuse the loader. */ const loadValidate = ( diff --git a/test/llm/structured-cli.spec.ts b/test/llm/structured-cli.spec.ts index 6c3b3b92..6651a9e4 100644 --- a/test/llm/structured-cli.spec.ts +++ b/test/llm/structured-cli.spec.ts @@ -68,12 +68,12 @@ describe('createStructuredCliChain', () => { expect(calls[0].options?.maxTurns).to.equal(1); }); - it('should carry model and cost from invokeForJSONWithResponse when the provider offers it', async () => { + it('should carry model, usage and cost from invokeForJSONWithResponse when the provider offers it', async () => { const fakeProvider = { invokeForJSON: async () => { throw new Error('should not be called'); }, invokeForJSONWithResponse: async () => ({ parsed: { decision: 'skip', reason: 'trivial' }, - response: { content: '{}', model: 'claude-sonnet-4-5', costUsd: 0.0123 }, + response: { content: '{}', model: 'claude-sonnet-4-5', costUsd: 0.0123, usage: { inputTokens: 30, outputTokens: 7 } }, }), }; const { createStructuredCliChain } = proxyquire('../../src/llm/structured-cli', { @@ -82,7 +82,12 @@ describe('createStructuredCliChain', () => { const result = await createStructuredCliChain(schema, SHAPE).invoke('Classify this PR.'); - expect(result).to.deep.equal({ parsed: { decision: 'skip', reason: 'trivial' }, model: 'claude-sonnet-4-5', costUsd: 0.0123 }); + expect(result).to.deep.equal({ + parsed: { decision: 'skip', reason: 'trivial' }, + model: 'claude-sonnet-4-5', + costUsd: 0.0123, + usage: { input: 30, output: 7, total: 37 }, + }); }); it('should throw when the response does not satisfy the schema', async () => { diff --git a/test/observability/index.spec.ts b/test/observability/index.spec.ts index d5da853f..3e502e24 100644 --- a/test/observability/index.spec.ts +++ b/test/observability/index.spec.ts @@ -3,6 +3,9 @@ import { expect } from 'chai'; import { LangfuseSpanProcessor, type LangfuseSpanProcessorParams } from '@langfuse/otel'; import { InMemorySpanExporter, type ReadableSpan } from '@opentelemetry/sdk-trace-base'; import type * as Observability from '../../src/observability'; +import { ResearchSupervisor } from '../../src/supervisors/research-supervisor'; +import type { LLMProvider } from '../../src/llm'; +import type { IssueTemplate } from '../../src/types'; const proxyquire = require('proxyquire'); @@ -15,6 +18,7 @@ describe('observability', () => { let processorParams: LangfuseSpanProcessorParams[]; let scores: Array<{ otelSpan: unknown; data: Record }>; let clientShutdowns: number; + let clientShutdownError: Error | undefined; function loadWithInMemoryExporter(): typeof Observability { class RecordingProcessor extends LangfuseSpanProcessor { @@ -26,7 +30,7 @@ describe('observability', () => { } class FakeClient { score = { trace: (obs: { otelSpan: unknown }, data: Record) => { scores.push({ otelSpan: obs.otelSpan, data }); } }; - shutdown = async () => { clientShutdowns++; }; + shutdown = async () => { clientShutdowns++; if (clientShutdownError) throw clientShutdownError; }; } return proxyquire('../../src/observability', { '@langfuse/otel': { LangfuseSpanProcessor: RecordingProcessor }, @@ -41,6 +45,7 @@ describe('observability', () => { processorParams = []; scores = []; clientShutdowns = 0; + clientShutdownError = undefined; mod = loadWithInMemoryExporter(); }); @@ -156,6 +161,42 @@ describe('observability', () => { expect(attr(cli, 'langfuse.observation.cost_details')).to.equal(JSON.stringify({ total: 0.042 })); }); + it('nests observeActiveGeneration under the active step and records model, usage, and cost', async () => { + await mod.withTrace({ name: 'dev-run' }, () => + mod.observeStep({ name: 'generate-code', asType: 'agent' }, () => + mod.observeActiveGeneration({ name: 'code-gen-plan', model: 'claude-cli', input: 'p', output: (r: { text: string }) => r.text }, + async () => ({ parsed: { text: 'plan' }, model: 'claude-opus-5-5', usage: { input: 900, output: 40, total: 940 }, costUsd: 0.6 })))); + const spans = await exportedSpans(); + const step = spans.find((s) => s.name === 'generate-code')!; + const generation = spans.find((s) => s.name === 'code-gen-plan')!; + expect(generation.parentSpanContext?.spanId).to.equal(step.spanContext().spanId); + expect(attr(generation, 'langfuse.observation.type')).to.equal('generation'); + expect(attr(generation, 'langfuse.observation.model.name')).to.equal('claude-opus-5-5'); + expect(attr(generation, 'langfuse.observation.usage_details')).to.equal(JSON.stringify({ input: 900, output: 40, total: 940 })); + expect(attr(generation, 'langfuse.observation.cost_details')).to.equal(JSON.stringify({ total: 0.6 })); + expect(attr(generation, 'langfuse.observation.output')).to.equal('plan'); + }); + + it('marks an observeActiveGeneration ERROR when failure() reports one, and fails the root', async () => { + const result = await mod.withTrace({ name: 'dev-run' }, () => + mod.observeActiveGeneration({ name: 'code-gen-execute', model: 'claude-cli', input: 'p', failure: (r: { isError: boolean }) => (r.isError ? 'max turns' : undefined) }, + async () => ({ parsed: { isError: true } }))); + const spans = await exportedSpans(); + const generation = spans.find((s) => s.name === 'code-gen-execute')!; + const root = spans.find((s) => s.name === 'dev-run')!; + expect(result).to.deep.equal({ isError: true }); + expect(attr(generation, 'langfuse.observation.level')).to.equal('ERROR'); + expect(attr(generation, 'langfuse.observation.status_message')).to.equal('max turns'); + expect(attr(root, 'langfuse.observation.level')).to.equal('ERROR'); + }); + + it('records nothing from observeActiveGeneration outside a trace', async () => { + await mod.withTrace({ name: 'warm-up' }, async () => {}); + const result = await mod.observeActiveGeneration({ name: 'orphan', model: 'm', input: 'p' }, async () => ({ parsed: 7 })); + expect(result).to.equal(7); + expect((await exportedSpans()).map((s) => s.name)).to.deep.equal(['warm-up']); + }); + it('ends a failed generation with level ERROR and rethrows', async () => { let thrown: unknown; await mod.withTrace({ name: 't' }, async (root) => { @@ -211,11 +252,182 @@ describe('observability', () => { expect(warnings.join('\n')).to.include('Unauthorized'); }); + it('nests observeStep spans under the active observation across a LangGraph run', async () => { + const { StateGraph, Annotation, START, END } = require('@langchain/langgraph'); + const State = Annotation.Root({ n: Annotation({ reducer: (_: number, u: number) => u, default: () => 0 }) }); + const graph = new StateGraph(State) + .addNode('plan', (state: { n: number }) => mod.observeStep({ name: 'plan', asType: 'chain' }, async (step) => { + await mod.observeGeneration(step, { name: 'plan-llm', model: 'm', input: 'p' }, async () => ({ parsed: 1 })); + return { n: state.n + 1 }; + })) + .addEdge(START, 'plan') + .addEdge('plan', END) + .compile(); + + await mod.withTrace({ name: 'research-run' }, () => + mod.observeStep({ name: 'research', asType: 'agent' }, () => graph.invoke({ n: 0 }))); + + const spans = await exportedSpans(); + const byName = (name: string) => spans.find((s) => s.name === name)!; + const chain = ['research-run', 'research', 'plan', 'plan-llm'].map(byName); + for (let i = 1; i < chain.length; i++) { + expect(chain[i].parentSpanContext?.spanId, chain[i].name).to.equal(chain[i - 1].spanContext().spanId); + expect(chain[i].spanContext().traceId).to.equal(chain[0].spanContext().traceId); + } + expect(attr(byName('research'), 'langfuse.observation.type')).to.equal('agent'); + expect(attr(byName('plan'), 'langfuse.observation.output')).to.equal(JSON.stringify({ n: 1 })); + }); + + it('marks a step ERROR when failure() reports one without the step throwing', async () => { + await mod.withTrace({ name: 't' }, () => + mod.observeStep({ name: 'node', output: () => undefined, failure: () => 'docs search failed' }, async () => ({}))); + const node = (await exportedSpans()).find((s) => s.name === 'node')!; + expect(attr(node, 'langfuse.observation.level')).to.equal('ERROR'); + expect(attr(node, 'langfuse.observation.status_message')).to.equal('docs search failed'); + expect(attr(node, 'langfuse.observation.output')).to.equal(undefined); + }); + + it('observeNode summarizes the node update and marks ERROR when it carries errors', async () => { + const node = mod.observeNode({ name: 'documentation-search', asType: 'retriever', output: () => ({ refs: 0 }) }, + async (state: { q: string }) => ({ currentPhase: 'doc-search', errors: [`search failed for ${state.q}`], messages: [{ content: 'nothing found' }] })); + await mod.withTrace({ name: 't' }, () => node({ q: 'forms' })); + const span = (await exportedSpans()).find((s) => s.name === 'documentation-search')!; + expect(attr(span, 'langfuse.observation.type')).to.equal('retriever'); + expect(attr(span, 'langfuse.observation.level')).to.equal('ERROR'); + expect(attr(span, 'langfuse.observation.status_message')).to.equal('search failed for forms'); + expect(JSON.parse(attr(span, 'langfuse.observation.output') as string)).to.deep.equal( + { phase: 'doc-search', summary: 'nothing found', errors: ['search failed for forms'], refs: 0 }); + }); + + describe('supervisor instrumentation', () => { + const issue: IssueTemplate = { + issue: { + title: 'Add filters', type: 'feature', priority: 'medium', description: 'Add contact filters', + technical_context: { domain: 'contacts', components: [] }, + requirements: ['r1'], acceptance_criteria: ['a1'], constraints: [], + }, + }; + const llm = (overrides: Partial): LLMProvider => ({ + providerType: 'anthropic', honorsCustomTools: false, modelName: 'test-model', + invoke: async () => ({ content: '', model: 'test-model' }), + invokeWithMessages: async () => ({ content: '', model: 'test-model' }), + invokeForJSON: async (): Promise => { throw new Error('invokeForJSONWithResponse should be preferred'); }, + ...overrides, + }); + const spanTree = async () => { + const spans = await exportedSpans(); + const byName = (name: string) => spans.find((s) => s.name === name)!; + const parentOf = (name: string) => spans.find((s) => s.spanContext().spanId === byName(name).parentSpanContext?.spanId)?.name; + return { byName, parentOf }; + }; + + it('traces the development graph down to the validation generation with its token usage', async () => { + class FakeCodeGenAgent { + generate = async () => ({ + files: [{ relativePath: 'src/a.ts', content: 'export const a = 1;', language: 'typescript', type: 'source', description: '', action: 'create' }], + summary: 's', implementedRequirements: [], pendingRequirements: [], notes: [], confidence: 0.9, + }); + } + const { DevelopmentSupervisor } = proxyquire('../../src/supervisors/development-supervisor', { + '../agents/code-generation-agent': { CodeGenerationAgent: FakeCodeGenAgent }, + }); + const validation = { requirementsMet: [], acceptanceCriteriaPassed: [], overallScore: 90, recommendations: [] }; + const supervisor = new DevelopmentSupervisor({ llmProvider: llm({ + invokeForJSONWithResponse: async () => ({ parsed: validation as T, response: { content: '', model: 'test-model', usage: { inputTokens: 10, outputTokens: 5 } } }), + }) }); + + await mod.withTrace({ name: 't' }, () => supervisor.develop({ + issue, + orchestrationPlan: { summary: '', keyFindings: [], recommendedApproach: '', estimatedComplexity: 'medium', phases: [], riskFactors: [], estimatedEffort: '' }, + researchFindings: { documentationReferences: [], relevantExamples: [], suggestedApproaches: [], relatedDomains: [], confidence: 0.5, source: 'local-docs' }, + contextAnalysis: { similarContexts: [], reusablePatterns: [], relevantDesignDecisions: [], recommendations: [], historicalSuccessRate: null, relatedDomains: [], codeContext: null }, + options: { chtCorePath: '/tmp/cht-core', previewMode: true }, + })); + + const { byName, parentOf } = await spanTree(); + expect(parentOf('development')).to.equal('t'); + expect(parentOf('generate-code')).to.equal('development'); + expect(parentOf('validate-implementation')).to.equal('development'); + expect(parentOf('implementation-validation')).to.equal('validate-implementation'); + expect(attr(byName('generate-code'), 'langfuse.observation.input')).to.equal(JSON.stringify({ iteration: 1 })); + expect(JSON.parse(attr(byName('generate-code'), 'langfuse.observation.output') as string).files).to.deep.equal(['create src/a.ts']); + expect(JSON.parse(attr(byName('validate-implementation'), 'langfuse.observation.output') as string).score).to.equal(90); + expect(attr(byName('implementation-validation'), 'langfuse.observation.usage_details')).to.equal(JSON.stringify({ input: 10, output: 5, total: 15 })); + }); + + it('traces the research graph down to the plan generation with its token usage', async () => { + const supervisor = new ResearchSupervisor({ useMockMCP: true, llmProvider: llm({ + invoke: async () => ({ content: '### IMPLEMENTATION APPROACH\nDo it.', model: 'test-model', usage: { inputTokens: 40, outputTokens: 8 } }), + }) }); + + await mod.withTrace({ name: 't' }, () => supervisor.research(issue)); + + const { byName, parentOf } = await spanTree(); + expect(parentOf('research')).to.equal('t'); + for (const node of ['documentation-search', 'code-context-search', 'context-analysis', 'generate-plan']) { + expect(parentOf(node), node).to.equal('research'); + } + expect(parentOf('orchestration-plan')).to.equal('generate-plan'); + expect(attr(byName('orchestration-plan'), 'langfuse.observation.usage_details')).to.equal(JSON.stringify({ input: 40, output: 8, total: 48 })); + expect(attr(byName('research'), 'langfuse.observation.level')).to.not.equal('ERROR'); + expect(attr(byName('t'), 'langfuse.observation.level')).to.not.equal('ERROR'); + expect(attr(byName('documentation-search'), 'langfuse.observation.input')).to.equal( + JSON.stringify({ title: 'Add filters', domain: 'contacts', components: [] })); + }); + }); + + it('resolves shutdown when Langfuse is unreachable so tracing never fails the run', async () => { + await mod.withTrace({ name: 't' }, async () => {}); + clientShutdownError = new Error('connect ECONNREFUSED 127.0.0.1:9'); + await mod.shutdownLangfuse(); + expect(clientShutdowns).to.equal(1); + }); + + it('marks the root ERROR when a nested step reports failure without throwing', async () => { + await mod.withTrace({ name: 'root' }, () => + mod.observeStep({ name: 'node', output: () => undefined, failure: () => 'docs search failed' }, async () => ({}))); + const root = (await exportedSpans()).find((s) => s.name === 'root')!; + expect(attr(root, 'langfuse.observation.level')).to.equal('ERROR'); + expect(attr(root, 'langfuse.observation.status_message')).to.equal('docs search failed'); + }); + + it('leaves the root DEFAULT when every step succeeds, and scopes failures to their own trace', async () => { + await mod.withTrace({ name: 'failing-run' }, () => + mod.observeStep({ name: 'bad', output: () => undefined, failure: () => 'x' }, async () => ({}))); + await mod.withTrace({ name: 'clean-run' }, () => mod.observeStep({ name: 'ok' }, async () => ({ fine: true }))); + const clean = (await exportedSpans()).find((s) => s.name === 'clean-run')!; + expect(attr(clean, 'langfuse.observation.level')).to.equal(undefined); + }); + + it('marks an empty generation ERROR and its root too, but still returns the output unchanged', async () => { + let returned: unknown; + await mod.withTrace({ name: 'root' }, async (root) => { + returned = await mod.observeGeneration(root, { name: 'plan', model: 'claude-cli', input: 'p' }, async () => ({ parsed: ' ' })); + }); + const spans = await exportedSpans(); + const plan = spans.find((s) => s.name === 'plan')!; + expect(returned).to.equal(' '); + expect(attr(plan, 'langfuse.observation.level')).to.equal('ERROR'); + expect(attr(plan, 'langfuse.observation.status_message')).to.equal('model returned empty output'); + expect(attr(spans.find((s) => s.name === 'root')!, 'langfuse.observation.level')).to.equal('ERROR'); + }); + it('returns parsed output and skips Langfuse when no root is given', async () => { expect(await mod.observeGeneration(undefined, { name: 'g', model: 'm', input: 'p' }, async () => ({ parsed: 7 }))).to.equal(7); }); }); + describe('fromLLMResponse', () => { + it('maps provider usage to Langfuse usage keys with a computed total and keeps cost', () => { + expect(mod.fromLLMResponse({ model: 'claude-x', usage: { inputTokens: 100, outputTokens: 20 }, costUsd: 0.01 }, 'plan')).to.deep.equal( + { parsed: 'plan', model: 'claude-x', usage: { input: 100, output: 20, total: 120 }, costUsd: 0.01 }); + }); + + it('leaves usage undefined when the provider reported none', () => { + expect(mod.fromLLMResponse({ model: 'claude-cli' }, 1).usage).to.equal(undefined); + }); + }); + describe('fromLangChain', () => { it('maps usage_metadata and response_metadata.model_name', () => { expect(mod.fromLangChain({ From d50fcd9436c498e8a97a452cd1753c2f889e9577 Mon Sep 17 00:00:00 2001 From: Alex Kombo Date: Wed, 23 Sep 2026 19:38:59 +0300 Subject: [PATCH 02/10] fix: find CLI result envelope when surrounding noise contains brackets --- src/llm/cli-envelope.ts | 26 ++++++++++++++++++++++---- test/llm/cli-envelope.spec.ts | 18 ++++++++++++++++++ 2 files changed, 40 insertions(+), 4 deletions(-) create mode 100644 test/llm/cli-envelope.spec.ts diff --git a/src/llm/cli-envelope.ts b/src/llm/cli-envelope.ts index 2bd676a2..c2d44fe6 100644 --- a/src/llm/cli-envelope.ts +++ b/src/llm/cli-envelope.ts @@ -58,18 +58,36 @@ function span(text: string, open: string, close: string): string | null { return start === -1 || end <= start ? null : text.slice(start, end + 1); } +function* lineBlocks(text: string): Generator { + const lines = text.split('\n'); + const starts = lines.flatMap((line, i) => (line.startsWith('[') || line.startsWith('{') ? [i] : [])); + const ends = lines.flatMap((line, i) => (/[\]}]\s*$/.test(line) && !/^\s/.test(line) ? [i] : [])).reverse(); + for (const start of starts) { + for (const end of ends) { + if (end >= start) yield lines.slice(start, end + 1).join('\n'); + } + } +} + +function* candidatesFrom(stdout: string): Generator { + yield stdout.trim(); + yield span(stdout, '[', ']'); + yield span(stdout, '{', '}'); + yield* lineBlocks(stdout); +} + /** * Find the `type: "result"` message in CLI stdout. Newer CLI versions print a JSON * array of every message (init, assistant, result); older ones print the result - * object alone. Either may be preceded or followed by non-JSON noise. + * object alone. Either may be preceded or followed by non-JSON noise, including + * noise with brackets, as long as the JSON starts and ends at column 0 of a line. * * @example * findResultEnvelope('[{"type":"system"},{"type":"result","result":"ok"}]'); // { type: 'result', result: 'ok' } - * findResultEnvelope('warn\n{"type":"result","result":"ok"}'); // { type: 'result', result: 'ok' } + * findResultEnvelope('warn [cli]\n[{"type":"result","result":"ok"}]'); // { type: 'result', result: 'ok' } */ export function findResultEnvelope>(stdout: string): T | null { - const candidates = [stdout.trim(), span(stdout, '[', ']'), span(stdout, '{', '}')]; - for (const candidate of candidates) { + for (const candidate of candidatesFrom(stdout)) { if (!candidate) continue; const found = resultFrom(tryParse(candidate)); if (found) return found as T; diff --git a/test/llm/cli-envelope.spec.ts b/test/llm/cli-envelope.spec.ts new file mode 100644 index 00000000..53f08513 --- /dev/null +++ b/test/llm/cli-envelope.spec.ts @@ -0,0 +1,18 @@ +import { expect } from 'chai'; +import { findResultEnvelope } from '../../src/llm/cli-envelope'; + +describe('findResultEnvelope', () => { + const transcript = '[{"type":"system","subtype":"init"},{"type":"result","result":"ok","total_cost_usd":0.1}]'; + + it('finds the result in an array transcript preceded by bracketed noise', () => { + expect(findResultEnvelope(`warning [cli]: retrying\n${transcript}`)).to.include({ type: 'result', result: 'ok' }); + }); + + it('finds the result when bracketed noise surrounds the transcript on both sides', () => { + expect(findResultEnvelope(`warn [a]\n${transcript}\nhook [done] {x}`)).to.include({ result: 'ok' }); + }); + + it('returns null when no line block holds a result message', () => { + expect(findResultEnvelope('warn [a]\n[{"type":"system"}]\n')).to.equal(null); + }); +}); From b4327c0b3a260e74f2472029168e050b55f3a4ab Mon Sep 17 00:00:00 2001 From: Alex Kombo Date: Wed, 23 Sep 2026 21:29:51 +0300 Subject: [PATCH 03/10] refactor: clear SonarCloud findings on tracing changes --- src/agents/code-generation-agent.ts | 3 +- .../code-gen/modules/claude-code-cli/index.ts | 12 +++---- src/llm/cli-envelope.ts | 12 ++++--- src/observability/index.ts | 33 ++++++++++--------- test/llm/cli-envelope.spec.ts | 2 +- test/observability/index.spec.ts | 6 ++-- 6 files changed, 36 insertions(+), 32 deletions(-) diff --git a/src/agents/code-generation-agent.ts b/src/agents/code-generation-agent.ts index 01b4c50f..642b6f55 100644 --- a/src/agents/code-generation-agent.ts +++ b/src/agents/code-generation-agent.ts @@ -362,7 +362,8 @@ export class CodeGenerationAgent { console.log(`[Code Generation Agent] Generated ${result.files.length} files`); console.log(`[Code Generation Agent] Confidence: ${(result.confidence * 100).toFixed(0)}%`); - console.log(`[Code Generation Agent] Model: ${result.modelUsed ?? 'unknown'}, tokens: ${result.tokensUsed ?? 'n/a'}, cost: ${result.costUsd === undefined ? 'n/a' : `$${result.costUsd.toFixed(4)}`}`); + const cost = result.costUsd === undefined ? 'n/a' : '$' + result.costUsd.toFixed(4); + console.log(`[Code Generation Agent] Model: ${result.modelUsed ?? 'unknown'}, tokens: ${result.tokensUsed ?? 'n/a'}, cost: ${cost}`); this.todos.printSummary(); return result; } diff --git a/src/layers/code-gen/modules/claude-code-cli/index.ts b/src/layers/code-gen/modules/claude-code-cli/index.ts index 3825a4fc..a6e59750 100644 --- a/src/layers/code-gen/modules/claude-code-cli/index.ts +++ b/src/layers/code-gen/modules/claude-code-cli/index.ts @@ -31,7 +31,7 @@ import { PlanItem, parsePlan } from '../../lib/plan'; import { buildPlanPrompt } from '../../lib/prompts'; import { buildFileManifest } from '../../lib/file-manifest'; import { buildExecutePrompt, buildRelaxedExecutePrompt } from './prompts'; -import { spawnClaudeCli, parseCliResult, ClaudeCliPhase, ClaudeCliResult, DEFAULT_MAX_TURNS } from './cli-driver'; +import { spawnClaudeCli, parseCliResult, ClaudeCliPhase, ClaudeCliResult, DEFAULT_MAX_TURNS, SpawnOptions } from './cli-driver'; import { snapshotChtCore, captureChtCoreDiff, @@ -206,7 +206,7 @@ export class ClaudeCodeCLICodeGenModule implements CodeGenModule { private async runPlanPhase(input: CodeGenModuleInput, cwd: string, calls: ClaudeCliResult[]): Promise { const manifest = buildFileManifest(input.contextFiles); const prompt = buildPlanPrompt(input, manifest); - const parsed = await runTracedCliPhase('code-gen-plan', prompt, cwd, PLAN_PHASE_TOOLS, ClaudeCliPhase.Plan); + const parsed = await runTracedCliPhase('code-gen-plan', prompt, { cwd, allowedTools: PLAN_PHASE_TOOLS, phase: ClaudeCliPhase.Plan }); calls.push(parsed); if (parsed.isError) { console.warn( @@ -227,7 +227,7 @@ export class ClaudeCodeCLICodeGenModule implements CodeGenModule { generationName = 'code-gen-execute', ): Promise<{ partialCompletion: boolean; reason?: string; resultText: string }> { const prompt = promptBuilder(input, plan); - const parsed = await runTracedCliPhase(generationName, prompt, cwd, EXECUTE_PHASE_TOOLS, ClaudeCliPhase.Execute); + const parsed = await runTracedCliPhase(generationName, prompt, { cwd, allowedTools: EXECUTE_PHASE_TOOLS, phase: ClaudeCliPhase.Execute }); calls.push(parsed); if (parsed.isError) { const reason = `is_error=true from CLI: ${parsed.result.substring(0, 200)}`; @@ -246,9 +246,7 @@ export class ClaudeCodeCLICodeGenModule implements CodeGenModule { function runTracedCliPhase( name: string, prompt: string, - cwd: string, - allowedTools: string[], - phase: ClaudeCliPhase, + spawnOpts: Pick, ): Promise { return observeActiveGeneration({ name, @@ -257,7 +255,7 @@ function runTracedCliPhase( output: (r) => ({ result: r.result, numTurns: r.numTurns }), failure: (r) => (r.isError ? r.result || 'CLI reported is_error' : undefined), }, async () => { - const parsed = parseCliResult(await spawnClaudeCli(prompt, { cwd, allowedTools, permissionMode: 'acceptEdits', phase })); + const parsed = parseCliResult(await spawnClaudeCli(prompt, { ...spawnOpts, permissionMode: 'acceptEdits' })); return fromLLMResponse({ model: parsed.model ?? 'claude-cli', usage: parsed.usage, costUsd: parsed.cost }, parsed); }); } diff --git a/src/llm/cli-envelope.ts b/src/llm/cli-envelope.ts index c2d44fe6..099d5396 100644 --- a/src/llm/cli-envelope.ts +++ b/src/llm/cli-envelope.ts @@ -62,10 +62,12 @@ function* lineBlocks(text: string): Generator { const lines = text.split('\n'); const starts = lines.flatMap((line, i) => (line.startsWith('[') || line.startsWith('{') ? [i] : [])); const ends = lines.flatMap((line, i) => (/[\]}]\s*$/.test(line) && !/^\s/.test(line) ? [i] : [])).reverse(); - for (const start of starts) { - for (const end of ends) { - if (end >= start) yield lines.slice(start, end + 1).join('\n'); - } + for (const start of starts) yield* blocksFrom(lines, start, ends); +} + +function* blocksFrom(lines: string[], start: number, ends: number[]): Generator { + for (const end of ends) { + if (end >= start) yield lines.slice(start, end + 1).join('\n'); } } @@ -113,7 +115,7 @@ export function summarizeModelUsage( ): { model?: string; usage?: { inputTokens: number; outputTokens: number } } { const entries = Object.entries(modelUsage ?? {}); if (entries.length === 0) return {}; - const [model] = entries.reduce((top, e) => ((e[1].costUSD ?? 0) > (top[1].costUSD ?? 0) ? e : top)); + const [model] = entries.reduce((top, e) => ((e[1].costUSD ?? 0) > (top[1].costUSD ?? 0) ? e : top), entries[0]); const usage = entries.reduce( (sum, [, e]) => ({ inputTokens: sum.inputTokens + promptTokens(e), outputTokens: sum.outputTokens + (e.outputTokens ?? 0) }), { inputTokens: 0, outputTokens: 0 } diff --git a/src/observability/index.ts b/src/observability/index.ts index 92ae7b43..c3f932d9 100644 --- a/src/observability/index.ts +++ b/src/observability/index.ts @@ -191,31 +191,34 @@ export interface GenerationOptions { failure?: (parsed: T) => string | undefined; } +function completeGeneration(generation: LangfuseGeneration, opts: GenerationOptions, result: GenerationResult): void { + const output = opts.output ? opts.output(result.parsed) : result.parsed; + generation.update({ + output, + model: result.model ?? opts.model, + usageDetails: result.usage, + costDetails: result.costUsd === undefined ? undefined : { total: result.costUsd }, + }); + const failed = opts.failure?.(result.parsed) ?? (isEmptyOutput(output) ? 'model returned empty output' : undefined); + if (failed) markFailed(generation, failed); + generation.end(); +} + async function recordGeneration( generation: LangfuseGeneration | undefined, opts: GenerationOptions, invoke: () => Promise> ): Promise { + if (!generation) return (await invoke()).parsed; try { const result = await invoke(); - const output = opts.output ? opts.output(result.parsed) : result.parsed; - generation?.update({ - output, - model: result.model ?? opts.model, - usageDetails: result.usage, - costDetails: result.costUsd === undefined ? undefined : { total: result.costUsd }, - }); - const failed = opts.failure?.(result.parsed) ?? (isEmptyOutput(output) ? 'model returned empty output' : undefined); - if (generation && failed) markFailed(generation, failed); - generation?.end(); + completeGeneration(generation, opts, result); return result.parsed; } catch (err) { const message = errorMessage(err); - if (generation) { - generation.update({ output: { error: message } }); - markFailed(generation, message); - generation.end(); - } + generation.update({ output: { error: message } }); + markFailed(generation, message); + generation.end(); throw err; } } diff --git a/test/llm/cli-envelope.spec.ts b/test/llm/cli-envelope.spec.ts index 53f08513..f0e14f70 100644 --- a/test/llm/cli-envelope.spec.ts +++ b/test/llm/cli-envelope.spec.ts @@ -13,6 +13,6 @@ describe('findResultEnvelope', () => { }); it('returns null when no line block holds a result message', () => { - expect(findResultEnvelope('warn [a]\n[{"type":"system"}]\n')).to.equal(null); + expect(findResultEnvelope('warn [a]\n[{"type":"system"}]\n')).to.be.null; }); }); diff --git a/test/observability/index.spec.ts b/test/observability/index.spec.ts index 3e502e24..ad279e46 100644 --- a/test/observability/index.spec.ts +++ b/test/observability/index.spec.ts @@ -284,7 +284,7 @@ describe('observability', () => { const node = (await exportedSpans()).find((s) => s.name === 'node')!; expect(attr(node, 'langfuse.observation.level')).to.equal('ERROR'); expect(attr(node, 'langfuse.observation.status_message')).to.equal('docs search failed'); - expect(attr(node, 'langfuse.observation.output')).to.equal(undefined); + expect(attr(node, 'langfuse.observation.output')).to.be.undefined; }); it('observeNode summarizes the node update and marks ERROR when it carries errors', async () => { @@ -396,7 +396,7 @@ describe('observability', () => { mod.observeStep({ name: 'bad', output: () => undefined, failure: () => 'x' }, async () => ({}))); await mod.withTrace({ name: 'clean-run' }, () => mod.observeStep({ name: 'ok' }, async () => ({ fine: true }))); const clean = (await exportedSpans()).find((s) => s.name === 'clean-run')!; - expect(attr(clean, 'langfuse.observation.level')).to.equal(undefined); + expect(attr(clean, 'langfuse.observation.level')).to.be.undefined; }); it('marks an empty generation ERROR and its root too, but still returns the output unchanged', async () => { @@ -424,7 +424,7 @@ describe('observability', () => { }); it('leaves usage undefined when the provider reported none', () => { - expect(mod.fromLLMResponse({ model: 'claude-cli' }, 1).usage).to.equal(undefined); + expect(mod.fromLLMResponse({ model: 'claude-cli' }, 1).usage).to.be.undefined; }); }); From a3fd23b2c7fe6d58d838a97da58d0e11c76e266c Mon Sep 17 00:00:00 2001 From: Alex Kombo Date: Thu, 24 Sep 2026 13:34:05 +0300 Subject: [PATCH 04/10] fix: take the last CLI result, surface error text, and bound noise parsing Select the latest result message and map an error result's errors list into result. Only lines that open JSON count as block starts, so long bracketed logs parse fast. --- src/llm/cli-envelope.ts | 20 +++++++++++++------- test/llm/cli-envelope.spec.ts | 20 ++++++++++++++++++++ 2 files changed, 33 insertions(+), 7 deletions(-) diff --git a/src/llm/cli-envelope.ts b/src/llm/cli-envelope.ts index 099d5396..8497c95c 100644 --- a/src/llm/cli-envelope.ts +++ b/src/llm/cli-envelope.ts @@ -16,7 +16,7 @@ function isResultMessage(value: unknown): value is Record { } function resultFrom(value: unknown): Record | null { - if (Array.isArray(value)) return value.find(isResultMessage) ?? null; + if (Array.isArray(value)) return value.findLast(isResultMessage) ?? null; return isResultMessage(value) ? value : null; } @@ -60,7 +60,7 @@ function span(text: string, open: string, close: string): string | null { function* lineBlocks(text: string): Generator { const lines = text.split('\n'); - const starts = lines.flatMap((line, i) => (line.startsWith('[') || line.startsWith('{') ? [i] : [])); + const starts = lines.flatMap((line, i) => (/^(?:[[{]\s*$|\[\s*\{|\{\s*")/.test(line) ? [i] : [])); const ends = lines.flatMap((line, i) => (/[\]}]\s*$/.test(line) && !/^\s/.test(line) ? [i] : [])).reverse(); for (const start of starts) yield* blocksFrom(lines, start, ends); } @@ -79,10 +79,12 @@ function* candidatesFrom(stdout: string): Generator { } /** - * Find the `type: "result"` message in CLI stdout. Newer CLI versions print a JSON - * array of every message (init, assistant, result); older ones print the result - * object alone. Either may be preceded or followed by non-JSON noise, including - * noise with brackets, as long as the JSON starts and ends at column 0 of a line. + * Find the last `type: "result"` message in CLI stdout. With `--verbose` (or the + * `verbose` setting) the CLI prints a JSON array of every message (init, + * assistant, result). Otherwise it prints the result object alone. Either may be + * preceded or followed by non-JSON noise, including noise with brackets, as long + * as the JSON starts and ends at column 0 of a line. Error results carry + * `errors: string[]` and no `result`, so the joined errors become the `result`. * * @example * findResultEnvelope('[{"type":"system"},{"type":"result","result":"ok"}]'); // { type: 'result', result: 'ok' } @@ -92,11 +94,15 @@ export function findResultEnvelope>(stdout: string): for (const candidate of candidatesFrom(stdout)) { if (!candidate) continue; const found = resultFrom(tryParse(candidate)); - if (found) return found as T; + if (found) return withErrorText(found) as T; } return null; } +function withErrorText(message: Record): Record { + return message.result === undefined && Array.isArray(message.errors) ? { ...message, result: message.errors.join('; ') } : message; +} + function promptTokens(entry: CliModelUsageEntry): number { return (entry.inputTokens ?? 0) + (entry.cacheReadInputTokens ?? 0) + (entry.cacheCreationInputTokens ?? 0); } diff --git a/test/llm/cli-envelope.spec.ts b/test/llm/cli-envelope.spec.ts index f0e14f70..00bda520 100644 --- a/test/llm/cli-envelope.spec.ts +++ b/test/llm/cli-envelope.spec.ts @@ -15,4 +15,24 @@ describe('findResultEnvelope', () => { it('returns null when no line block holds a result message', () => { expect(findResultEnvelope('warn [a]\n[{"type":"system"}]\n')).to.be.null; }); + + it('takes the last result when the transcript holds more than one', () => { + const two = '[{"type":"result","result":"first"},{"type":"result","result":"second"}]'; + expect(findResultEnvelope(two)).to.include({ result: 'second' }); + }); + + it('uses the errors list as the result text for error results', () => { + const maxTurns = '{"type":"result","subtype":"error_max_turns","is_error":true,"errors":["Reached maximum number of turns (150)"]}'; + expect(findResultEnvelope(maxTurns)).to.include({ result: 'Reached maximum number of turns (150)' }); + }); + + it('stays fast on long bracketed noise with no JSON', function () { + this.timeout(1000); + const noise = Array.from({ length: 2000 }, (_, i) => `[warn] line ${i} [x]`).join('\n'); + expect(findResultEnvelope(noise)).to.be.null; + }); + + it('finds a pretty-printed result object after bracketed noise', () => { + expect(findResultEnvelope('[warn] x\n{\n "type": "result",\n "result": "ok"\n}\n')).to.include({ result: 'ok' }); + }); }); From db254c2c6235e2b3f930d08fc29e4db8fd59419c Mon Sep 17 00:00:00 2001 From: Alex Kombo Date: Thu, 24 Sep 2026 13:34:39 +0300 Subject: [PATCH 05/10] fix: record model, usage and cost on failed CLI provider generations The provider now throws LLMCallError carrying the reported response, and traced generations copy its spend. Adds tracing tests for both code-gen modules. --- src/llm/providers/claude-cli.ts | 22 +++++++------ src/llm/types.ts | 13 ++++++++ src/observability/index.ts | 9 +++++- test/helpers/generation-recorder.ts | 32 +++++++++++++++++++ .../layers/code-gen/claude-api-module.spec.ts | 26 +++++++++++++++ .../modules/claude-code-cli/index.spec.ts | 27 ++++++++++++++++ test/llm/providers/claude-cli.spec.ts | 22 +++++++++++++ test/observability/index.spec.ts | 15 +++++++++ 8 files changed, 155 insertions(+), 11 deletions(-) create mode 100644 test/helpers/generation-recorder.ts diff --git a/src/llm/providers/claude-cli.ts b/src/llm/providers/claude-cli.ts index 76609380..0ad3b9a1 100644 --- a/src/llm/providers/claude-cli.ts +++ b/src/llm/providers/claude-cli.ts @@ -19,6 +19,7 @@ import { LLMMessage, LLMResponse, InvokeOptions, + LLMCallError, } from '../types'; /** @@ -302,24 +303,25 @@ export const createClaudeCLIProvider = (config: ClaudeCLIConfig = {}): LLMProvid const stdout = await executeCLI(prompt, options); const parsed = parseResponse(stdout); - if (parsed.is_error) { - throw new Error(`Claude CLI error: ${parsed.result}`); - } - - // Ensure result is always a string const result = parsed.result ?? ''; - if (!result && !parsed.is_error) { - console.warn('[Claude CLI] Warning: CLI returned empty result'); - } - const reported = summarizeModelUsage(parsed.modelUsage); - return { + const response: LLMResponse = { content: result, model: reported.model ?? modelName, usage: reported.usage, stopReason: parsed.subtype === 'success' ? 'end_turn' : 'error', costUsd: parsed.total_cost_usd, }; + + if (parsed.is_error) { + throw new LLMCallError(`Claude CLI error: ${parsed.result}`, response); + } + + if (!result) { + console.warn('[Claude CLI] Warning: CLI returned empty result'); + } + + return response; }; /** diff --git a/src/llm/types.ts b/src/llm/types.ts index 247d9431..728cfd13 100644 --- a/src/llm/types.ts +++ b/src/llm/types.ts @@ -109,6 +109,19 @@ export interface LLMResponse { costUsd?: number; } +/** + * A failed call that still reported what it spent, so tracing can record the + * model, usage and cost of the failure. + * + * @example + * throw new LLMCallError('Claude CLI error: max turns', { content: '', model: 'claude-opus-5-5', costUsd: 0.4 }); + */ +export class LLMCallError extends Error { + constructor(message: string, readonly response: LLMResponse) { + super(message); + } +} + /** * LLM Provider Interface * diff --git a/src/observability/index.ts b/src/observability/index.ts index c3f932d9..3d82172f 100644 --- a/src/observability/index.ts +++ b/src/observability/index.ts @@ -6,6 +6,7 @@ import { LangfuseSpanProcessor } from '@langfuse/otel'; import { propagateAttributes, startActiveObservation, startObservation, type LangfuseGeneration, type LangfuseSpan } from '@langfuse/tracing'; import { context, propagation, trace } from '@opentelemetry/api'; import { NodeTracerProvider } from '@opentelemetry/sdk-trace-node'; +import { LLMCallError } from '../llm/types'; // Bounds span export only; the OTLP exporter retries internally. const REQUEST_TIMEOUT_SECONDS = 3; @@ -204,6 +205,12 @@ function completeGeneration(generation: LangfuseGeneration, opts: GenerationO generation.end(); } +function spendOf(err: unknown): { model?: string; usageDetails?: Record; costDetails?: { total: number } } { + if (!(err instanceof LLMCallError)) return {}; + const spent = fromLLMResponse(err.response, undefined); + return { model: spent.model, usageDetails: spent.usage, costDetails: spent.costUsd === undefined ? undefined : { total: spent.costUsd } }; +} + async function recordGeneration( generation: LangfuseGeneration | undefined, opts: GenerationOptions, @@ -216,7 +223,7 @@ async function recordGeneration( return result.parsed; } catch (err) { const message = errorMessage(err); - generation.update({ output: { error: message } }); + generation.update({ output: { error: message }, ...spendOf(err) }); markFailed(generation, message); generation.end(); throw err; diff --git a/test/helpers/generation-recorder.ts b/test/helpers/generation-recorder.ts new file mode 100644 index 00000000..e2fd3c25 --- /dev/null +++ b/test/helpers/generation-recorder.ts @@ -0,0 +1,32 @@ +import { fromLLMResponse, type GenerationOptions, type GenerationResult } from '../../src/observability'; + +export interface RecordedGeneration { + name: string; + model?: string; + costUsd?: number; + failure?: string; + error?: string; +} + +/** + * Stand-in for the observability module that records each generation a caller opens. + * + * @example + * const { records, observability } = generationRecorder(); + * proxyquire(modulePath, { '../../../../observability': observability }); + * // after the run: records[0] => { name: 'code-gen-plan', model: 'claude-opus-5-5', costUsd: 0.1 } + */ +export function generationRecorder() { + const records: RecordedGeneration[] = []; + const observeActiveGeneration = async (opts: GenerationOptions, invoke: () => Promise>): Promise => { + try { + const result = await invoke(); + records.push({ name: opts.name, model: result.model, costUsd: result.costUsd, failure: opts.failure?.(result.parsed) }); + return result.parsed; + } catch (err) { + records.push({ name: opts.name, error: (err as Error).message }); + throw err; + } + }; + return { records, observability: { fromLLMResponse, observeActiveGeneration } }; +} diff --git a/test/layers/code-gen/claude-api-module.spec.ts b/test/layers/code-gen/claude-api-module.spec.ts index 7c7bdcba..3bf37c89 100644 --- a/test/layers/code-gen/claude-api-module.spec.ts +++ b/test/layers/code-gen/claude-api-module.spec.ts @@ -7,6 +7,7 @@ import { ContextFile, } from '../../../src/layers/code-gen/interface'; import { LLMProvider, LLMResponse, LLMMessage, InvokeOptions } from '../../../src/llm'; +import { generationRecorder } from '../../helpers/generation-recorder'; // Load the module with the compile gate stubbed to a benign pass, so these // generate() calls never invoke the real snapshot/tsc/rollback gate (which would @@ -1553,4 +1554,29 @@ describe('ClaudeApiCodeGenModule', () => { expect(module.version).to.equal('0.6.0'); }); }); + + describe('generation tracing', () => { + it('opens one generation per LLM call with the reported model and cost, and records a failed call', async () => { + const { records, observability } = generationRecorder(); + const { ClaudeApiCodeGenModule: TracedModule } = proxyquire(MODULE_PATH, { + './compile-gate': { runApiCompileGate: async () => ({ passed: true, issues: [] }) }, + '../../../../utils/shutdown': { isShutdownRequested: () => false }, + '../../../../observability': observability, + }) as typeof import('../../../src/layers/code-gen/modules/claude-api/index'); + invokeStub.onCall(0).resolves({ ...makePlanResponse([ + { action: 'CREATE', path: 'src/a.ts', rationale: 'File A with feature implementation' }, + { action: 'CREATE', path: 'src/b.ts', rationale: 'File B with feature implementation' }, + ]), model: 'claude-opus-5-5', costUsd: 0.2 }); + invokeStub.onCall(1).resolves({ ...makeSingleFileResponse('export const a = 1;\nexport function run() { return a; }'), costUsd: 0.3 }); + invokeStub.rejects(new Error('overloaded')); + + await new TracedModule(mockProvider).generate(baseInput); + + expect(records.slice(0, 3)).to.deep.equal([ + { name: 'code-gen-plan', model: 'claude-opus-5-5', costUsd: 0.2, failure: undefined }, + { name: 'code-gen-file', model: 'test-model', costUsd: 0.3, failure: undefined }, + { name: 'code-gen-file', error: 'overloaded' }, + ]); + }); + }); }); diff --git a/test/layers/code-gen/modules/claude-code-cli/index.spec.ts b/test/layers/code-gen/modules/claude-code-cli/index.spec.ts index 94ff7337..fbd8cac3 100644 --- a/test/layers/code-gen/modules/claude-code-cli/index.spec.ts +++ b/test/layers/code-gen/modules/claude-code-cli/index.spec.ts @@ -5,6 +5,7 @@ import { __resetShutdownForTests } from '../../../../../src/utils/shutdown'; import { CodeGenModuleInput } from '../../../../../src/layers/code-gen/interface'; import { CrossFileIssue } from '../../../../../src/types'; import { extractLlmDiscoveryIssues } from '../../../../../src/layers/code-gen/modules/claude-code-cli/index'; +import { generationRecorder } from '../../../../helpers/generation-recorder'; // Helper: proxyquire the orchestrator with cli-driver + workspace stubbed. const proxyquire = require('proxyquire').noCallThru(); @@ -108,6 +109,32 @@ describe('ClaudeCodeCLICodeGenModule (A.2d orchestrator)', () => { expect(result.costUsd).to.be.closeTo(0.5, 1e-9); }); + it('traces plan and execute generations with model and cost, and marks a CLI is_error as a failure', async () => { + const { records, observability } = generationRecorder(); + const spawnStub = sinon.stub() + .onFirstCall().resolves(planResultText) + .onSecondCall().resolves('max turns'); + const parse = (s: string) => (s === planResultText + ? { result: s, isError: false, numTurns: 1, model: 'claude-sonnet-5', cost: 0.1 } + : { result: 'Reached maximum number of turns (150)', isError: true, numTurns: 150, model: 'claude-opus-5-5', cost: 0.4 }); + const { ClaudeCodeCLICodeGenModule } = proxyquire('../../../../../src/layers/code-gen/modules/claude-code-cli/index', { + './cli-driver': { spawnClaudeCli: spawnStub, parseCliResult: parse, ClaudeCliPhase: { Plan: 'plan', Execute: 'execute' } }, + './workspace': { + snapshotChtCore: sinon.stub().resolves({ headSha: 'abc1234', stashRef: null }), + captureChtCoreDiff: sinon.stub().resolves([{ path: 'src/a.ts', content: 'x', purpose: 'p' }]), + rollbackChtCore: sinon.stub().resolves({ reset: 'ok', clean: 'ok', stashPop: 'skipped', errors: [] }), + }, + '../../../../observability': observability, + }); + + await new ClaudeCodeCLICodeGenModule().generate(baseInput()); + + expect(records).to.deep.equal([ + { name: 'code-gen-plan', model: 'claude-sonnet-5', costUsd: 0.1, failure: undefined }, + { name: 'code-gen-execute', model: 'claude-opus-5-5', costUsd: 0.4, failure: 'Reached maximum number of turns (150)' }, + ]); + }); + it('still reports the plan call spend when the plan is empty', async () => { const emptyPlan = '=== PLAN ===\n=== END PLAN ===\n'; const { ClaudeCodeCLICodeGenModule } = proxyquire('../../../../../src/layers/code-gen/modules/claude-code-cli/index', { diff --git a/test/llm/providers/claude-cli.spec.ts b/test/llm/providers/claude-cli.spec.ts index 88bd20c4..013e930c 100644 --- a/test/llm/providers/claude-cli.spec.ts +++ b/test/llm/providers/claude-cli.spec.ts @@ -181,6 +181,28 @@ describe('createClaudeCLIProvider (v9a.7) — response handling', () => { expect(caught!.message).to.match(/Claude CLI error: auth failed/); }); + it('attaches the reported model, usage, cost and errors text to an is_error failure', async () => { + const { provider } = loadProvider([ + { + stdout: cliResultJson({ + result: undefined, + subtype: 'error_max_turns', + is_error: true, + errors: ['Reached maximum number of turns (1)'], + total_cost_usd: 0.3, + modelUsage: { 'claude-opus-5-5': { inputTokens: 5, outputTokens: 2, costUSD: 0.3 } }, + }), + closeCode: 0, + }, + ]); + const caught = await provider.invoke('p').then( + () => expect.fail('expected invoke to throw'), + (e: { message: string; response?: unknown }) => e, + ); + expect(caught.message).to.equal('Claude CLI error: Reached maximum number of turns (1)'); + expect(caught.response).to.deep.include({ model: 'claude-opus-5-5', usage: { inputTokens: 5, outputTokens: 2 }, costUsd: 0.3 }); + }); + it('falls back to treating non-JSON stdout as the result content', async () => { const { provider } = loadProvider([{ stdout: 'plain text completion', closeCode: 0 }]); const result = await provider.invoke('p'); diff --git a/test/observability/index.spec.ts b/test/observability/index.spec.ts index ad279e46..a8b6ca16 100644 --- a/test/observability/index.spec.ts +++ b/test/observability/index.spec.ts @@ -5,6 +5,7 @@ import { InMemorySpanExporter, type ReadableSpan } from '@opentelemetry/sdk-trac import type * as Observability from '../../src/observability'; import { ResearchSupervisor } from '../../src/supervisors/research-supervisor'; import type { LLMProvider } from '../../src/llm'; +import { LLMCallError } from '../../src/llm/types'; import type { IssueTemplate } from '../../src/types'; const proxyquire = require('proxyquire'); @@ -211,6 +212,20 @@ describe('observability', () => { expect(attr(generation, 'langfuse.observation.output')).to.equal(JSON.stringify({ error: 'model down' })); }); + it('keeps the reported model, usage and cost when the call throws an LLMCallError', async () => { + const failure = new LLMCallError('Claude CLI error: max turns', { + content: '', model: 'claude-opus-5-5', usage: { inputTokens: 900, outputTokens: 40 }, costUsd: 0.6, + }); + await mod.withTrace({ name: 't' }, async (root) => { + await mod.observeGeneration(root, { name: 'g', model: 'claude-cli', input: 'p' }, async () => { throw failure; }).catch(() => undefined); + }); + const generation = (await exportedSpans()).find((s) => s.name === 'g')!; + expect(attr(generation, 'langfuse.observation.level')).to.equal('ERROR'); + expect(attr(generation, 'langfuse.observation.model.name')).to.equal('claude-opus-5-5'); + expect(attr(generation, 'langfuse.observation.usage_details')).to.equal(JSON.stringify({ input: 900, output: 40, total: 940 })); + expect(attr(generation, 'langfuse.observation.cost_details')).to.equal(JSON.stringify({ total: 0.6 })); + }); + it('records a thrown error on the root observation, still ends it, and rethrows', async () => { let thrown: unknown; try { From d37c442fcc792556c188d7ea360e8aa64cd4c1d6 Mon Sep 17 00:00:00 2001 From: Alex Kombo Date: Thu, 1 Oct 2026 00:16:58 +0300 Subject: [PATCH 06/10] fix: keep CLI spend when JSON parsing or schema validation fails --- src/llm/providers/claude-cli.ts | 6 +++++- src/llm/structured-cli.ts | 5 ++++- test/llm/providers/claude-cli.spec.ts | 16 +++++++++++++++- test/llm/structured-cli.spec.ts | 21 ++++++++++++++++++++- 4 files changed, 44 insertions(+), 4 deletions(-) diff --git a/src/llm/providers/claude-cli.ts b/src/llm/providers/claude-cli.ts index 0ad3b9a1..11aebf5f 100644 --- a/src/llm/providers/claude-cli.ts +++ b/src/llm/providers/claude-cli.ts @@ -364,7 +364,11 @@ export const createClaudeCLIProvider = (config: ClaudeCLIConfig = {}): LLMProvid IMPORTANT: Respond with valid JSON only. Do not include any text before or after the JSON object.`; const response = await invoke(jsonPrompt, options); - return { parsed: parseJsonContent(response.content), response }; + try { + return { parsed: parseJsonContent(response.content), response }; + } catch (err) { + throw new LLMCallError((err as Error).message, response); + } }; const invokeForJSON = async (prompt: string, options?: InvokeOptions): Promise => diff --git a/src/llm/structured-cli.ts b/src/llm/structured-cli.ts index 6276bf4c..49560a47 100644 --- a/src/llm/structured-cli.ts +++ b/src/llm/structured-cli.ts @@ -16,6 +16,7 @@ import { z } from 'zod'; import { createLLMProviderFromEnv } from './factory'; +import { LLMCallError } from './types'; import { fromLangChain, fromLLMResponse, type GenerationResult } from '../observability'; export { isUsingCLIProvider } from './factory'; @@ -77,7 +78,9 @@ ${shape}`; return { parsed: schema.parse(await provider.invokeForJSON(jsonPrompt, options)) }; } const { parsed, response } = await provider.invokeForJSONWithResponse(jsonPrompt, options); - return fromLLMResponse(response, schema.parse(parsed)); + const checked = schema.safeParse(parsed); + if (!checked.success) throw new LLMCallError(checked.error.message, response); + return fromLLMResponse(response, checked.data); }, }; }; diff --git a/test/llm/providers/claude-cli.spec.ts b/test/llm/providers/claude-cli.spec.ts index 013e930c..cae191f8 100644 --- a/test/llm/providers/claude-cli.spec.ts +++ b/test/llm/providers/claude-cli.spec.ts @@ -2,7 +2,7 @@ import { expect } from 'chai'; import sinon from 'sinon'; import { EventEmitter } from 'events'; -import { LLMProvider } from '../../../src/llm/types'; +import { LLMCallError, LLMProvider } from '../../../src/llm/types'; import { DISALLOWED_TOOLS } from '../../../src/llm/providers/claude-cli'; import { isBatchFatalError } from '../../../src/llm/rate-limit'; @@ -199,6 +199,7 @@ describe('createClaudeCLIProvider (v9a.7) — response handling', () => { () => expect.fail('expected invoke to throw'), (e: { message: string; response?: unknown }) => e, ); + expect(caught).to.be.instanceOf(LLMCallError); expect(caught.message).to.equal('Claude CLI error: Reached maximum number of turns (1)'); expect(caught.response).to.deep.include({ model: 'claude-opus-5-5', usage: { inputTokens: 5, outputTokens: 2 }, costUsd: 0.3 }); }); @@ -318,6 +319,19 @@ describe('createClaudeCLIProvider (v9a.7) — invokeWithMessages / invokeForJSON expect(caught!.message).to.match(/did not contain valid JSON/); }); + it('invokeForJSONWithResponse keeps the paid response on a JSON parse failure', async () => { + const { provider } = loadProvider([ + { stdout: cliResultJson({ result: 'just plain prose', total_cost_usd: 0.02 }), closeCode: 0 }, + ]); + const caught = await provider.invokeForJSONWithResponse!('p').then( + () => expect.fail('expected invokeForJSONWithResponse to throw'), + (e: LLMCallError) => e, + ); + expect(caught).to.be.instanceOf(LLMCallError); + expect(caught.message).to.match(/did not contain valid JSON/); + expect(caught.response).to.include({ content: 'just plain prose', costUsd: 0.02 }); + }); + it('invokeForJSON strips trailing commas before parsing', async () => { const { provider } = loadProvider([ { stdout: cliResultJson({ result: '{"a":1, "b":[1,2,],}' }), closeCode: 0 }, diff --git a/test/llm/structured-cli.spec.ts b/test/llm/structured-cli.spec.ts index 6651a9e4..8d7b3ff8 100644 --- a/test/llm/structured-cli.spec.ts +++ b/test/llm/structured-cli.spec.ts @@ -1,6 +1,6 @@ import { expect } from 'chai'; import { z } from 'zod'; -import type { InvokeOptions } from '../../src/llm/types'; +import { LLMCallError, type InvokeOptions } from '../../src/llm/types'; const proxyquire = require('proxyquire').noCallThru(); @@ -102,4 +102,23 @@ describe('createStructuredCliChain', () => { expect(calls).to.have.length(1); } }); + + it('should keep the paid response on the error when the response does not satisfy the schema', async () => { + const response = { content: '{}', model: 'claude-sonnet-4-5', costUsd: 0.0123, usage: { inputTokens: 30, outputTokens: 7 } }; + const fakeProvider = { + invokeForJSON: async () => { throw new Error('should not be called'); }, + invokeForJSONWithResponse: async () => ({ parsed: { decision: 'maybe', reason: '' }, response }), + }; + const { createStructuredCliChain } = proxyquire('../../src/llm/structured-cli', { + './factory': { createLLMProviderFromEnv: () => fakeProvider, isUsingCLIProvider: () => true }, + }); + + const caught = await createStructuredCliChain(schema, SHAPE).invoke('Classify this PR.').then( + () => expect.fail('expected a schema validation error'), + (e: LLMCallError) => e, + ); + + expect(caught).to.be.instanceOf(LLMCallError); + expect(caught.response).to.equal(response); + }); }); From bcc0622d3a25c9469739c9b36b6ffb324cfabe30 Mon Sep 17 00:00:00 2001 From: Alex Kombo Date: Thu, 1 Oct 2026 00:16:59 +0300 Subject: [PATCH 07/10] refactor: drop redundant async from observeStep --- src/observability/index.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/observability/index.ts b/src/observability/index.ts index 3d82172f..13b25438 100644 --- a/src/observability/index.ts +++ b/src/observability/index.ts @@ -100,7 +100,7 @@ export interface StepOptions { } /** Child of the active observation (so nested steps nest automatically); a no-op span before any withTrace. */ -export async function observeStep(opts: StepOptions, fn: (step: TraceRoot) => Promise): Promise { +export function observeStep(opts: StepOptions, fn: (step: TraceRoot) => Promise): Promise { const run = async (step: TraceRoot): Promise => { if (opts.input !== undefined) step.update({ input: opts.input }); try { From cdc5ca4d454e77bdc4bda692873d78be44392a46 Mon Sep 17 00:00:00 2001 From: Alex Kombo Date: Thu, 1 Oct 2026 00:17:00 +0300 Subject: [PATCH 08/10] docs: restore flush-failed warning wording in delivery semantics --- docs/observability.md | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/docs/observability.md b/docs/observability.md index ce29530e..769ef249 100644 --- a/docs/observability.md +++ b/docs/observability.md @@ -238,8 +238,9 @@ Every generation records the model, prompt, completion, latency, and errors. Cos Spans are exported over OTLP/HTTP by a batching span processor with a 3-second request timeout. The OTLP exporter applies its own retry/backoff on transient failures within that time. Scores go through the client's queue, which uses the SDK default timeout of 60 seconds (`@langfuse/client` 5.11.1 ignores -its `timeout` option). `shutdownLangfuse()` flushes both queues before `process.exit` and only logs a -warning when Langfuse is unreachable, so tracing never changes a run's exit code. +its `timeout` option). `shutdownLangfuse()` flushes both queues before `process.exit`; if Langfuse is +unreachable it logs a `[Langfuse] … flush failed` warning and resolves, so tracing never changes a +run's exit code. --- From 7a7bb79eae9dd35c47a38e02423723d74a094646 Mon Sep 17 00:00:00 2001 From: Alex Kombo Date: Thu, 1 Oct 2026 20:07:24 +0300 Subject: [PATCH 09/10] fix: keep API spend when the JSON response cannot be parsed --- src/llm/providers/anthropic.ts | 5 +++-- test/llm/providers/anthropic.spec.ts | 24 +++++++++++++++++++++++- 2 files changed, 26 insertions(+), 3 deletions(-) diff --git a/src/llm/providers/anthropic.ts b/src/llm/providers/anthropic.ts index c3c2fc60..d082c8b5 100644 --- a/src/llm/providers/anthropic.ts +++ b/src/llm/providers/anthropic.ts @@ -16,6 +16,7 @@ import { InvokeOptions, LLMToolDefinition, DEFAULT_CONFIG, + LLMCallError, capMaxTokens, } from '../types'; @@ -261,7 +262,7 @@ export const createAnthropicProvider = (config: APIProviderConfig): LLMProvider // Strip any ```json fence and extract the outermost JSON object. const extracted = extractJsonObject(content); if (!extracted) { - throw new Error('LLM response did not contain valid JSON object'); + throw new LLMCallError('LLM response did not contain valid JSON object', response); } let jsonStr = extracted; @@ -277,7 +278,7 @@ export const createAnthropicProvider = (config: APIProviderConfig): LLMProvider const snippet = jsonStr.substring(0, 500); console.error(`[LLM] JSON parse error. First 500 chars: ${snippet}...`); console.error(`[LLM] Stop reason: ${response.stopReason}`); - throw new Error(`Failed to parse LLM response as JSON: ${error}`); + throw new LLMCallError(`Failed to parse LLM response as JSON: ${error}`, response); } }; diff --git a/test/llm/providers/anthropic.spec.ts b/test/llm/providers/anthropic.spec.ts index 69a062f5..ed32e204 100644 --- a/test/llm/providers/anthropic.spec.ts +++ b/test/llm/providers/anthropic.spec.ts @@ -1,7 +1,7 @@ /* eslint-disable @typescript-eslint/no-var-requires */ import { expect } from 'chai'; import sinon from 'sinon'; -import { APIProviderConfig, LLMProvider } from '../../../src/llm/types'; +import { APIProviderConfig, LLMCallError, LLMProvider } from '../../../src/llm/types'; const proxyquire = require('proxyquire').noCallThru(); @@ -254,6 +254,28 @@ describe('createAnthropicProvider invokeForJSON', () => { expect(caught).to.not.be.null; expect(caught!.message).to.match(/Failed to parse LLM response as JSON/); }); + + for (const [label, content, message] of [ + ['is truncated mid-JSON', '{"score": 8', /did not contain valid JSON/], + ['holds malformed JSON', '{this is: not json}', /Failed to parse LLM response as JSON/], + ] as const) { + it(`keeps the paid usage on the error when the response ${label}`, async () => { + const stub = buildChatAnthropicStub(); + stub.invokeStub.resolves({ + content, + usage_metadata: { input_tokens: 120, output_tokens: 30 }, + response_metadata: { stop_reason: 'max_tokens' }, + } as ChatResponseShape); + const provider = loadProviderTyped(stub, baseConfig); + const caught = await provider.invokeForJSONWithResponse!('p').then( + () => expect.fail('expected invokeForJSONWithResponse to throw'), + (e: LLMCallError) => e, + ); + expect(caught).to.be.instanceOf(LLMCallError); + expect(caught.message).to.match(message); + expect(caught.response).to.deep.include({ model: 'claude-opus-4-6', usage: { inputTokens: 120, outputTokens: 30 } }); + }); + } it('invokeForJSONWithResponse returns the parsed JSON with the token usage the model reported', async () => { const stub = buildChatAnthropicStub(); stub.invokeStub.resolves({ From ef73c67d967e6dd9f191605d14074d82ac6ea91d Mon Sep 17 00:00:00 2001 From: Alex Kombo Date: Thu, 1 Oct 2026 20:25:38 +0300 Subject: [PATCH 10/10] chore: leave Langfuse keys empty in .env.example so tracing stays off by default --- .env.example | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/.env.example b/.env.example index 6de4d09f..a35aa4f3 100644 --- a/.env.example +++ b/.env.example @@ -63,7 +63,7 @@ CHT_CORE_PATH=/path/to/cht-core # Langfuse LLM observability (https://cloud.langfuse.com) # Set LANGFUSE_ENABLED=false to disable tracing locally (default: enabled; the SDK # disables itself when credentials are missing). -LANGFUSE_PUBLIC_KEY=pk-lf-... -LANGFUSE_SECRET_KEY=sk-lf-... +# LANGFUSE_PUBLIC_KEY=pk-lf-... +# LANGFUSE_SECRET_KEY=sk-lf-... LANGFUSE_BASE_URL=https://cloud.langfuse.com # LANGFUSE_ENABLED=false # uncomment to disable tracing