diff --git a/docs/internal/pipeline.md b/docs/internal/pipeline.md index 9fa3445..4952e3f 100644 --- a/docs/internal/pipeline.md +++ b/docs/internal/pipeline.md @@ -89,10 +89,11 @@ When workspace debug output is enabled, the CLI passes a debug recorder for the current run ID. The runner writes framework-boundary inputs, outputs, structured LLM calls, validator calls, timing, and retry attempt metadata through that interface. Each retry or validator attempt records any LLM calls -made within that attempt in an `llm_calls` array and writes scoped copies of the -canonical LLM call artifacts under the attempt directory. Debug output is not -used for resume and can contain sensitive source, reference, prompt, and -model-output material. Concrete modules still do not receive workspace paths. +made within that attempt in an `llm_calls` array and writes paired +`prompt-000N.json` and `response-000N.json` files under the attempt directory. +Debug output is not used for resume and can contain sensitive source, +reference, prompt, and model-output material. Concrete modules still do not +receive workspace paths. ## Registries And Module Specs diff --git a/docs/operations.md b/docs/operations.md index 3d9021a..a62b30e 100644 --- a/docs/operations.md +++ b/docs/operations.md @@ -138,12 +138,12 @@ checkpointing does not write debug output. Debug artifacts include framework-boundary inputs and outputs for source, chunk, extract, merge, normalize, and output work, structured LLM request and response data from Notarius contracts, validator requests and results, timing, -and retry attempt metadata. Canonical LLM call artifacts are written under -`llm/call-000N.json`; LLM calls made inside a retry or validator attempt are -also copied under that attempt directory and linked from the attempt -`llm_calls` array. LLM response content in those artifacts is written as raw -text for inspection. Debug artifacts may contain source material, reference -material, prompt inputs, model outputs, and other sensitive data. Obvious +and retry attempt metadata. LLM calls made inside a retry or validator attempt +write paired `prompt-000N.json` and `response-000N.json` files under that +attempt directory and are linked from the attempt `llm_calls` array. Prompt and +response content in those artifacts is written as raw text for inspection. +Debug artifacts may contain source material, reference material, prompt inputs, +model outputs, and other sensitive data. API keys are not written, and obvious credential-shaped values and sensitive map keys are redacted in framework envelopes, but debug directories should still be protected as sensitive local state. diff --git a/internal/cli/run_test.go b/internal/cli/run_test.go index efdc19c..f9ab586 100644 --- a/internal/cli/run_test.go +++ b/internal/cli/run_test.go @@ -2244,8 +2244,9 @@ func TestRunPipelineWritesDebugWhenWorkspaceDebugEnabled(t *testing.T) { "chunk/input.json", "chunk/output.json", "extract/spells/input.json", - "extract/spells/chunk-000001-attempt-01.json", - "extract/spells/chunk-000001-attempt-01/llm-call-0001.json", + "extract/spells/chunk-000001/attempt-01.json", + "extract/spells/chunk-000001/attempt-01/prompt-0001.json", + "extract/spells/chunk-000001/attempt-01/response-0001.json", "extract/spells/output.json", "merge/spells/input.json", "merge/spells/output.json", @@ -2253,15 +2254,23 @@ func TestRunPipelineWritesDebugWhenWorkspaceDebugEnabled(t *testing.T) { "normalize/spells/output.json", "output/input.json", "output/output.json", - "llm/call-0001.json", } { if _, err := os.Stat(filepath.Join(debugDir, name)); err != nil { t.Fatalf("expected debug artifact %q: %v", name, err) } } - attemptDebug := string(readFile(t, filepath.Join(debugDir, "extract/spells/chunk-000001-attempt-01.json"))) - if !strings.Contains(attemptDebug, `"llm_calls"`) || !strings.Contains(attemptDebug, `"scoped_path"`) { - t.Fatalf("extract attempt debug = %s, want scoped llm_calls", attemptDebug) + attemptDebug := string(readFile(t, filepath.Join(debugDir, "extract/spells/chunk-000001/attempt-01.json"))) + if !strings.Contains(attemptDebug, `"llm_calls"`) || !strings.Contains(attemptDebug, `"prompt_path"`) || !strings.Contains(attemptDebug, `"response_path"`) { + t.Fatalf("extract attempt debug = %s, want prompt/response llm_calls", attemptDebug) + } + responseDebug := string(readFile(t, filepath.Join(debugDir, "extract/spells/chunk-000001/attempt-01/response-0001.json"))) + if !strings.Contains(responseDebug, `"content"`) || !strings.Contains(responseDebug, `spell_casts`) { + t.Fatalf("response debug = %s, want raw response content", responseDebug) + } + assertPathNotExist(t, filepath.Join(debugDir, "llm/call-0001.json")) + assertPathNotExist(t, filepath.Join(debugDir, "extract/spells/chunk-000001-attempt-01/llm-call-0001.json")) + if _, err := os.Stat(filepath.Join(debugDir, "extract/spells/chunk-000001-attempt-01.json")); !os.IsNotExist(err) { + t.Fatalf("old extract attempt path still exists: %v", err) } assertPathNotExist(t, filepath.Join(workspaceDir, "checkpoints")) } @@ -3367,7 +3376,7 @@ func (client *fakeRunLLMClient) CompleteStructured(ctx context.Context, req cont if err := json.Unmarshal(encoded, out); err != nil { return contracts.StructuredCompletionResponse{}, err } - return contracts.StructuredCompletionResponse{Content: encoded}, nil + return fakeRunStructuredResponse(req, encoded), nil } startUnitID := 1 if client.invalidSourceRef { @@ -3400,7 +3409,37 @@ func (client *fakeRunLLMClient) CompleteStructured(ctx context.Context, req cont if err := json.Unmarshal(encoded, out); err != nil { return contracts.StructuredCompletionResponse{}, err } - return contracts.StructuredCompletionResponse{Content: encoded}, nil + return fakeRunStructuredResponse(req, encoded), nil +} + +func fakeRunStructuredResponse(req contracts.StructuredCompletionRequest, content []byte) contracts.StructuredCompletionResponse { + profileID := req.ProfileID + if profileID == "" { + profileID = "fake-profile" + } + return contracts.StructuredCompletionResponse{ + Content: content, + Model: "fake-model", + ProfileID: profileID, + Debug: &contracts.LLMDebugMaterial{ + Prompt: &contracts.LLMDebugPrompt{ + PromptID: req.PromptID, + PromptVersion: req.PromptVersion, + SelectedProfileID: profileID, + SessionID: req.SessionID, + Messages: []contracts.LLMDebugMessage{ + {Role: "user", Content: "fake rendered prompt for " + req.PromptID}, + }, + }, + Response: &contracts.LLMDebugResponse{ + Content: string(content), + PromptID: req.PromptID, + PromptVersion: req.PromptVersion, + SelectedProfileID: profileID, + ModelName: "fake-model", + }, + }, + } } func fakeLLMFactory(client contracts.StructuredLLMClient, err error) LLMClientFactory { diff --git a/internal/framework/contracts/contracts.go b/internal/framework/contracts/contracts.go index b1f19fc..26c5ec8 100644 --- a/internal/framework/contracts/contracts.go +++ b/internal/framework/contracts/contracts.go @@ -19,19 +19,69 @@ type StructuredCompletionRequest struct { } type StructuredCompletionResponse struct { - Content json.RawMessage `json:"content"` - Provider string `json:"provider,omitempty"` - Model string `json:"model,omitempty"` - ProfileID string `json:"profile_id,omitempty"` - PromptTokens int `json:"prompt_tokens,omitempty"` - CompletionTokens int `json:"completion_tokens,omitempty"` - TotalTokens int `json:"total_tokens,omitempty"` + Content json.RawMessage `json:"content"` + Provider string `json:"provider,omitempty"` + Model string `json:"model,omitempty"` + ProfileID string `json:"profile_id,omitempty"` + PromptTokens int `json:"prompt_tokens,omitempty"` + CompletionTokens int `json:"completion_tokens,omitempty"` + TotalTokens int `json:"total_tokens,omitempty"` + Debug *LLMDebugMaterial `json:"debug,omitempty"` } type StructuredLLMClient interface { CompleteStructured(ctx context.Context, req StructuredCompletionRequest, out any) (StructuredCompletionResponse, error) } +type LLMDebugMaterial struct { + Prompt *LLMDebugPrompt `json:"prompt,omitempty"` + Response *LLMDebugResponse `json:"response,omitempty"` +} + +type LLMDebugPrompt struct { + PromptID string `json:"prompt_id,omitempty"` + PromptVersion string `json:"prompt_version,omitempty"` + PromptHash string `json:"prompt_hash,omitempty"` + SelectedProfileID string `json:"selected_profile_id,omitempty"` + SessionID string `json:"session_id,omitempty"` + RenderedPromptHash string `json:"rendered_prompt_hash,omitempty"` + Messages []LLMDebugMessage `json:"messages,omitempty"` + EffectiveModelParams map[string]any `json:"effective_model_params,omitempty"` + OutputContract map[string]any `json:"output_contract,omitempty"` + StructuredOutput map[string]any `json:"structured_output,omitempty"` + InputHashes map[string]string `json:"input_hashes,omitempty"` +} + +type LLMDebugMessage struct { + Role string `json:"role"` + Content string `json:"content"` + CacheControl map[string]any `json:"cache_control,omitempty"` +} + +type LLMDebugResponse struct { + Content string `json:"content,omitempty"` + RunID string `json:"run_id,omitempty"` + PromptID string `json:"prompt_id,omitempty"` + PromptVersion string `json:"prompt_version,omitempty"` + PromptHash string `json:"prompt_hash,omitempty"` + RenderedPromptHash string `json:"rendered_prompt_hash,omitempty"` + SelectedProfileID string `json:"selected_profile_id,omitempty"` + ModelName string `json:"model_name,omitempty"` + Endpoint string `json:"endpoint,omitempty"` + EffectiveModelParams map[string]any `json:"effective_model_params,omitempty"` + InputHashes map[string]string `json:"input_hashes,omitempty"` + Validation map[string]any `json:"validation,omitempty"` + Usage LLMDebugUsage `json:"usage,omitempty"` +} + +type LLMDebugUsage struct { + PromptTokens int `json:"prompt_tokens,omitempty"` + CompletionTokens int `json:"completion_tokens,omitempty"` + TotalTokens int `json:"total_tokens,omitempty"` + CachedTokens int `json:"cached_tokens,omitempty"` + CacheWriteTokens int `json:"cache_write_tokens,omitempty"` +} + type LLMProfileManifestProvider interface { LLMProfileManifests() []artifacts.LLMProfileManifest } diff --git a/internal/framework/llm/scriptorium_client.go b/internal/framework/llm/scriptorium_client.go index 0f7e5c7..c5566e1 100644 --- a/internal/framework/llm/scriptorium_client.go +++ b/internal/framework/llm/scriptorium_client.go @@ -98,6 +98,13 @@ func (c *ScriptoriumClient) CompleteStructured(ctx context.Context, req contract Vars: scriptoriumVars(req), Metadata: scriptoriumMetadata(req), } + prepared, err := c.engine.Prepare(ctx, runReq) + if err != nil { + if ctxErr := ctx.Err(); ctxErr != nil { + return contracts.StructuredCompletionResponse{}, ctxErr + } + return contracts.StructuredCompletionResponse{}, fmt.Errorf("prepare Scriptorium prompt %q: %w", promptID, redactScriptoriumError(err)) + } result, err := c.engine.Run(ctx, runReq) if err != nil { if ctxErr := ctx.Err(); ctxErr != nil { @@ -108,7 +115,7 @@ func (c *ScriptoriumClient) CompleteStructured(ctx context.Context, req contract if result == nil { return contracts.StructuredCompletionResponse{}, fmt.Errorf("run Scriptorium prompt %q: empty result", promptID) } - response := c.responseFromResult(result) + response := c.responseFromResult(result, prepared) if result.Validation.Status == scriptorium.ValidationFailed || !result.Validation.IsValid { return response, fmt.Errorf("run Scriptorium prompt %q: validation failed: %s", promptID, strings.Join(result.Validation.Errors, "; ")) } @@ -121,7 +128,7 @@ func (c *ScriptoriumClient) CompleteStructured(ctx context.Context, req contract return response, nil } -func (c *ScriptoriumClient) responseFromResult(result *scriptorium.RunResult) contracts.StructuredCompletionResponse { +func (c *ScriptoriumClient) responseFromResult(result *scriptorium.RunResult, prepared *scriptorium.PreparedRun) contracts.StructuredCompletionResponse { content := result.Artifact.Body if len(content) == 0 { content = []byte(result.RawOutput) @@ -142,9 +149,111 @@ func (c *ScriptoriumClient) responseFromResult(result *scriptorium.RunResult) co PromptTokens: result.Usage.PromptTokens, CompletionTokens: result.Usage.CompletionTokens, TotalTokens: result.Usage.TotalTokens, + Debug: scriptoriumDebugMaterial(prepared, result), } } +func scriptoriumDebugMaterial(prepared *scriptorium.PreparedRun, result *scriptorium.RunResult) *contracts.LLMDebugMaterial { + material := &contracts.LLMDebugMaterial{} + if prepared != nil { + material.Prompt = scriptoriumDebugPrompt(prepared) + } + if result != nil { + material.Response = scriptoriumDebugResponse(result) + } + if material.Prompt == nil && material.Response == nil { + return nil + } + return material +} + +func scriptoriumDebugPrompt(prepared *scriptorium.PreparedRun) *contracts.LLMDebugPrompt { + if prepared == nil { + return nil + } + messages := make([]contracts.LLMDebugMessage, 0, len(prepared.Messages)) + for _, message := range prepared.Messages { + messages = append(messages, contracts.LLMDebugMessage{ + Role: message.Role, + Content: message.Content, + CacheControl: jsonObject(message.CacheControl), + }) + } + return &contracts.LLMDebugPrompt{ + PromptID: prepared.PromptID, + PromptVersion: prepared.PromptVersion, + PromptHash: prepared.PromptHash, + SelectedProfileID: prepared.SelectedProfileID, + SessionID: prepared.SessionID, + RenderedPromptHash: prepared.RenderedPromptHash, + Messages: messages, + EffectiveModelParams: jsonObject(prepared.EffectiveModelParams), + OutputContract: jsonObject(prepared.OutputContract), + StructuredOutput: jsonObject(prepared.StructuredOutput), + InputHashes: cloneStringMap(prepared.InputHashes), + } +} + +func scriptoriumDebugResponse(result *scriptorium.RunResult) *contracts.LLMDebugResponse { + if result == nil { + return nil + } + content := result.RawOutput + if content == "" { + content = string(result.Artifact.Body) + } + return &contracts.LLMDebugResponse{ + Content: content, + RunID: result.RunID, + PromptID: result.PromptID, + PromptVersion: result.PromptVersion, + PromptHash: result.PromptHash, + RenderedPromptHash: result.RenderedPromptHash, + SelectedProfileID: result.SelectedProfileID, + ModelName: result.ModelName, + Endpoint: result.Endpoint, + EffectiveModelParams: jsonObject(result.EffectiveModelParams), + InputHashes: cloneStringMap(result.InputHashes), + Validation: jsonObject(result.Validation), + Usage: contracts.LLMDebugUsage{ + PromptTokens: result.Usage.PromptTokens, + CompletionTokens: result.Usage.CompletionTokens, + TotalTokens: result.Usage.TotalTokens, + CachedTokens: result.Usage.CachedTokens, + CacheWriteTokens: result.Usage.CacheWriteTokens, + }, + } +} + +func jsonObject(value any) map[string]any { + if value == nil { + return nil + } + data, err := json.Marshal(value) + if err != nil || string(data) == "null" { + return nil + } + var out map[string]any + if err := json.Unmarshal(data, &out); err != nil { + return nil + } + if len(out) == 0 { + return nil + } + return out +} + +func cloneStringMap(values map[string]string) map[string]string { + if len(values) == 0 { + return nil + } + out := make(map[string]string, len(values)) + for key, value := range values { + out[key] = value + } + return out +} + func (c *ScriptoriumClient) LLMProfileManifests() []artifacts.LLMProfileManifest { if c == nil || c.recorder == nil { return nil diff --git a/internal/framework/llm/scriptorium_client_test.go b/internal/framework/llm/scriptorium_client_test.go index 248f5f4..4993eaa 100644 --- a/internal/framework/llm/scriptorium_client_test.go +++ b/internal/framework/llm/scriptorium_client_test.go @@ -45,6 +45,25 @@ func TestScriptoriumClientMapsPromptRequestAndUnmarshalsOutput(t *testing.T) { if resp.PromptTokens != 11 || resp.CompletionTokens != 7 || resp.TotalTokens != 18 { t.Fatalf("usage = %#v, want mapped token counts", resp) } + if resp.Debug == nil || resp.Debug.Prompt == nil { + t.Fatalf("debug prompt = nil, want prepared prompt material") + } + if resp.Debug.Prompt.PromptID != "adapter.test" || resp.Debug.Prompt.SelectedProfileID != "explicit-profile" { + t.Fatalf("debug prompt metadata = %#v, want prompt/profile", resp.Debug.Prompt) + } + if len(resp.Debug.Prompt.Messages) != 1 || !strings.Contains(resp.Debug.Prompt.Messages[0].Content, `{"source":true}`) { + t.Fatalf("debug prompt messages = %#v, want rendered input content", resp.Debug.Prompt.Messages) + } + if resp.Debug.Response == nil || resp.Debug.Response.Content != `{"ok":true}` { + t.Fatalf("debug response = %#v, want raw response content", resp.Debug.Response) + } + debugJSON, err := json.Marshal(resp.Debug) + if err != nil { + t.Fatalf("marshal debug material: %v", err) + } + if strings.Contains(string(debugJSON), "secret-token") || strings.Contains(string(debugJSON), "sk-") { + t.Fatalf("debug material contains secret material: %s", debugJSON) + } gotReq := fake.lastRequest() if gotReq.Prompt.SessionID != "session-123" { t.Fatalf("session id = %q, want session-123", gotReq.Prompt.SessionID) @@ -100,6 +119,12 @@ func TestScriptoriumClientValidationFailureReturnsError(t *testing.T) { if got := string(resp.Content); got != `{"bad":true}` { t.Fatalf("response content = %q, want raw failed output", got) } + if resp.Debug == nil || resp.Debug.Response == nil || resp.Debug.Response.Content != `{"bad":true}` { + t.Fatalf("debug response = %#v, want raw failed output", resp.Debug) + } + if resp.Debug.Prompt == nil || len(resp.Debug.Prompt.Messages) == 0 { + t.Fatalf("debug prompt = %#v, want prepared prompt material", resp.Debug.Prompt) + } } func TestScriptoriumClientDecodeFailureReturnsRawResponse(t *testing.T) { @@ -119,13 +144,16 @@ func TestScriptoriumClientDecodeFailureReturnsRawResponse(t *testing.T) { if got := string(resp.Content); got != `{"ok":true}` { t.Fatalf("response content = %q, want raw decode-failed output", got) } + if resp.Debug == nil || resp.Debug.Response == nil || resp.Debug.Response.Content != `{"ok":true}` { + t.Fatalf("debug response = %#v, want raw decode-failed output", resp.Debug) + } } func TestScriptoriumClientProviderFailureIncludesContextAndRedactsBearerToken(t *testing.T) { client := newTestScriptoriumClient(t, &fakeScriptoriumLLM{err: errors.New("provider failed with Bearer secret-token")}) var out map[string]any - _, err := client.CompleteStructured(context.Background(), contracts.StructuredCompletionRequest{ + resp, err := client.CompleteStructured(context.Background(), contracts.StructuredCompletionRequest{ PromptID: "adapter.test", SessionID: "session-123", Inputs: contracts.LLMInputSet{ @@ -141,6 +169,9 @@ func TestScriptoriumClientProviderFailureIncludesContextAndRedactsBearerToken(t if strings.Contains(err.Error(), "secret-token") || !strings.Contains(err.Error(), "Bearer [REDACTED]") { t.Fatalf("error = %q, want redacted bearer token", err.Error()) } + if resp.Debug != nil { + t.Fatalf("debug material = %#v, want none for provider failure without result", resp.Debug) + } } func TestScriptoriumClientContextCancellationIsRespected(t *testing.T) { diff --git a/internal/framework/pipeline/debug.go b/internal/framework/pipeline/debug.go index 94868e6..eee9cc2 100644 --- a/internal/framework/pipeline/debug.go +++ b/internal/framework/pipeline/debug.go @@ -165,19 +165,26 @@ type debugStructuredCompletionResponse struct { TotalTokens int `json:"total_tokens,omitempty"` } -type debugStructuredLLMCall struct { - Request debugStructuredCompletionRequest `json:"request"` - Response debugStructuredCompletionResponse `json:"response,omitempty"` - Error string `json:"error,omitempty"` +type debugLLMPromptArtifact struct { + CallID string `json:"call_id"` + Prompt *contracts.LLMDebugPrompt `json:"prompt,omitempty"` +} + +type debugLLMResponseArtifact struct { + CallID string `json:"call_id"` + Response *contracts.LLMDebugResponse `json:"response,omitempty"` + Fallback *debugStructuredCompletionResponse `json:"fallback,omitempty"` + Error string `json:"error,omitempty"` } type debugLLMCallReference struct { - CallID string `json:"call_id"` - CanonicalPath string `json:"canonical_path"` - ScopedPath string `json:"scoped_path,omitempty"` - PromptID string `json:"prompt_id,omitempty"` - ProfileID string `json:"profile_id,omitempty"` - Error bool `json:"error,omitempty"` + CallID string `json:"call_id"` + PromptPath string `json:"prompt_path,omitempty"` + ResponsePath string `json:"response_path"` + PromptID string `json:"prompt_id,omitempty"` + ProfileID string `json:"profile_id,omitempty"` + Model string `json:"model,omitempty"` + Error bool `json:"error,omitempty"` } type debugValidationRequest struct { @@ -232,44 +239,65 @@ func wrapDebugLLMClient(client contracts.StructuredLLMClient, recorder DebugReco func (client *debugLLMClient) CompleteStructured(ctx context.Context, req contracts.StructuredCompletionRequest, out any) (contracts.StructuredCompletionResponse, error) { client.mu.Lock() client.counter++ - callID := fmt.Sprintf("call-%04d", client.counter) + callID := fmt.Sprintf("%04d", client.counter) client.mu.Unlock() started := time.Now().UTC() response, err := client.inner.CompleteStructured(ctx, req, out) completed := time.Now().UTC() - payload := debugStructuredLLMCall{ - Request: debugCompletionRequest(req), - Response: debugCompletionResponse(response), - } + errorText := "" if err != nil { - payload.Error = err.Error() + errorText = err.Error() } - envelope := debugTimedEnvelope{ + + scopePrefix := cleanDebugPath(req.StageName) + if scopePrefix == "_" { + scopePrefix = "llm" + } + if scope := debugLLMScopeFromContext(ctx); scope != nil { + scopePrefix = scope.prefix + } + promptPath := "" + var writeErr error + if response.Debug != nil && response.Debug.Prompt != nil { + promptPath = path.Join(scopePrefix, "prompt-"+callID+".json") + writeErr = errors.Join(writeErr, writeDebugTimed(client.recorder, promptPath, debugTimedEnvelope{ + Stage: req.StageName, + ModuleKey: req.StageName, + StartedAt: started, + CompletedAt: completed, + DurationMS: completed.Sub(started).Milliseconds(), + Payload: debugLLMPromptArtifact{ + CallID: callID, + Prompt: response.Debug.Prompt, + }, + })) + } + responsePath := path.Join(scopePrefix, "response-"+callID+".json") + writeErr = errors.Join(writeErr, writeDebugTimed(client.recorder, responsePath, debugTimedEnvelope{ Stage: req.StageName, ModuleKey: req.StageName, StartedAt: started, CompletedAt: completed, DurationMS: completed.Sub(started).Milliseconds(), - Payload: payload, - Error: payload.Error, - } - canonicalPath := path.Join("llm", callID+".json") - writeErr := writeDebugTimed(client.recorder, canonicalPath, envelope) + Payload: debugLLMResponseArtifact{ + CallID: callID, + Response: debugResponseMaterial(response), + Fallback: debugCompletionFallback(response), + Error: errorText, + }, + Error: errorText, + })) callRef := debugLLMCallReference{ - CallID: callID, - CanonicalPath: canonicalPath, - PromptID: req.PromptID, - ProfileID: debugFirstNonEmptyString(response.ProfileID, req.ProfileID), - Error: err != nil, + CallID: callID, + PromptPath: promptPath, + ResponsePath: responsePath, + PromptID: req.PromptID, + ProfileID: debugFirstNonEmptyString(response.ProfileID, req.ProfileID), + Model: debugFirstNonEmptyString(response.Model, debugResponseModel(response)), + Error: err != nil, } if scope := debugLLMScopeFromContext(ctx); scope != nil { - scopedPath := path.Join(scope.prefix, "llm-"+callID+".json") - callRef.ScopedPath = scopedPath - scopedWriteErr := writeDebugTimed(client.recorder, scopedPath, envelope) - if scopedWriteErr != nil { - writeErr = errors.Join(writeErr, scopedWriteErr) - } scope.record(callRef) } if err != nil { @@ -548,6 +576,37 @@ func debugCompletionResponse(response contracts.StructuredCompletionResponse) de } } +func debugCompletionFallback(response contracts.StructuredCompletionResponse) *debugStructuredCompletionResponse { + if response.Debug != nil && response.Debug.Response != nil { + return nil + } + fallback := debugCompletionResponse(response) + if fallback.Content == "" && + fallback.Provider == "" && + fallback.Model == "" && + fallback.ProfileID == "" && + fallback.PromptTokens == 0 && + fallback.CompletionTokens == 0 && + fallback.TotalTokens == 0 { + return nil + } + return &fallback +} + +func debugResponseMaterial(response contracts.StructuredCompletionResponse) *contracts.LLMDebugResponse { + if response.Debug == nil { + return nil + } + return response.Debug.Response +} + +func debugResponseModel(response contracts.StructuredCompletionResponse) string { + if response.Debug == nil || response.Debug.Response == nil { + return "" + } + return response.Debug.Response.ModelName +} + func debugValidationRequestEnvelope(req contracts.ValidationRequest) debugValidationRequest { req.Schema.JSONSchema = nil out := debugValidationRequest{ diff --git a/internal/framework/pipeline/runner.go b/internal/framework/pipeline/runner.go index 545daf5..916b0b7 100644 --- a/internal/framework/pipeline/runner.go +++ b/internal/framework/pipeline/runner.go @@ -441,7 +441,7 @@ func (r *Runner) runLane(ctx context.Context, input RunInput, checkpoints Checkp var acceptedWarnings []contracts.Warning accepted, rejection, err := runWithRetry(ctx, lane.Extract.Retries, func(attempt int) (bool, *contracts.RejectedOutput, error) { attemptStarted := time.Now().UTC() - attemptPath := path.Join("extract", debugPathComponent(lane.ID), fmt.Sprintf("chunk-%06d-attempt-%02d", chunk.Index+1, attempt)) + attemptPath := path.Join("extract", debugPathComponent(lane.ID), fmt.Sprintf("chunk-%06d", chunk.Index+1), fmt.Sprintf("attempt-%02d", attempt)) attemptCtx, llmScope := withDebugLLMScope(ctx, attemptPath) result, err := extractor.Extract(attemptCtx, contracts.ExtractionRequest{ Source: doc, diff --git a/internal/framework/pipeline/runner_test.go b/internal/framework/pipeline/runner_test.go index a657987..5884b5a 100644 --- a/internal/framework/pipeline/runner_test.go +++ b/internal/framework/pipeline/runner_test.go @@ -1310,22 +1310,36 @@ func TestRunDebugFailedChunkAttemptReferencesScopedLLMOutput(t *testing.T) { t.Fatalf("llm_calls = %#v, want one scoped call", attempt.LLMCalls) } call := attempt.LLMCalls[0] - if call.CallID != "call-0001" || call.CanonicalPath != "llm/call-0001.json" || call.ScopedPath != "chunk/attempt-01/llm-call-0001.json" { - t.Fatalf("llm call reference = %#v, want canonical and scoped paths", call) + if call.CallID != "0001" || call.PromptPath != "chunk/attempt-01/prompt-0001.json" || call.ResponsePath != "chunk/attempt-01/response-0001.json" { + t.Fatalf("llm call reference = %#v, want prompt and response paths", call) } - if call.PromptID != "runner.chunk" || call.ProfileID != "debug-profile" || call.Error { + if call.PromptID != "runner.chunk" || call.ProfileID != "debug-profile" || call.Model != "debug-model" || call.Error { t.Fatalf("llm call metadata = %#v, want prompt/profile and no call error", call) } - scoped := recorder.envelope(t, call.ScopedPath) - scopedPayload, ok := scoped.Payload.(debugStructuredLLMCall) + prompt := recorder.envelope(t, call.PromptPath) + promptPayload, ok := prompt.Payload.(debugLLMPromptArtifact) if !ok { - t.Fatalf("scoped payload type = %T, want debugStructuredLLMCall", scoped.Payload) + t.Fatalf("prompt payload type = %T, want debugLLMPromptArtifact", prompt.Payload) } - if scopedPayload.Response.Content != `{"raw":true}` { - t.Fatalf("scoped response content = %q, want raw LLM response", scopedPayload.Response.Content) + if promptPayload.Prompt == nil || len(promptPayload.Prompt.Messages) != 1 || promptPayload.Prompt.Messages[0].Content != "raw prompt text" { + t.Fatalf("prompt payload = %#v, want raw prompt message", promptPayload) + } + + response := recorder.envelope(t, call.ResponsePath) + responsePayload, ok := response.Payload.(debugLLMResponseArtifact) + if !ok { + t.Fatalf("response payload type = %T, want debugLLMResponseArtifact", response.Payload) + } + if responsePayload.Response == nil || responsePayload.Response.Content != `{"raw":true}` { + t.Fatalf("response payload = %#v, want raw LLM response", responsePayload) + } + if _, ok := recorder.payloads["llm/call-0001.json"]; ok { + t.Fatalf("old canonical LLM debug artifact was written") + } + if _, ok := recorder.payloads["chunk/attempt-01/llm-call-0001.json"]; ok { + t.Fatalf("old scoped LLM debug artifact was written") } - _ = recorder.envelope(t, call.CanonicalPath) } func TestRunStopsRetryAfterConfiguredAttemptsAndRecordsAttemptCount(t *testing.T) { @@ -2332,7 +2346,22 @@ func (client debugResponseLLMClient) CompleteStructured(ctx context.Context, req } return contracts.StructuredCompletionResponse{ Content: append([]byte(nil), client.content...), + Model: "debug-model", ProfileID: profileID, + Debug: &contracts.LLMDebugMaterial{ + Prompt: &contracts.LLMDebugPrompt{ + PromptID: req.PromptID, + SelectedProfileID: profileID, + Messages: []contracts.LLMDebugMessage{ + {Role: "user", Content: "raw prompt text"}, + }, + }, + Response: &contracts.LLMDebugResponse{ + Content: string(client.content), + SelectedProfileID: profileID, + ModelName: "debug-model", + }, + }, }, client.err }