diff --git a/docs/internal/pipeline.md b/docs/internal/pipeline.md index 4952e3f..2537706 100644 --- a/docs/internal/pipeline.md +++ b/docs/internal/pipeline.md @@ -90,8 +90,10 @@ 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 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, +`prompt-000N.json` and `response-000N.json` metadata files under the attempt +directory. LLM response bodies are written as sibling `response-content-000N.*` +files, using pretty-printed JSON when the content is valid JSON and raw text +otherwise. 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. diff --git a/docs/operations.md b/docs/operations.md index a62b30e..13f65eb 100644 --- a/docs/operations.md +++ b/docs/operations.md @@ -139,14 +139,16 @@ 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. 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. +write `prompt-000N.json`, `response-000N.json`, and +`response-content-000N.*` files under that attempt directory and are linked from +the attempt `llm_calls` array. Prompt content is written inline in the prompt +artifact. Response metadata is written to `response-000N.json`, while the +response body is written separately as pretty-printed JSON when possible or as +raw text otherwise. 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. ## Retention diff --git a/internal/cli/run_test.go b/internal/cli/run_test.go index f9ab586..e1ff8da 100644 --- a/internal/cli/run_test.go +++ b/internal/cli/run_test.go @@ -2247,6 +2247,7 @@ func TestRunPipelineWritesDebugWhenWorkspaceDebugEnabled(t *testing.T) { "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/chunk-000001/attempt-01/response-content-0001.json", "extract/spells/output.json", "merge/spells/input.json", "merge/spells/output.json", @@ -2260,12 +2261,16 @@ func TestRunPipelineWritesDebugWhenWorkspaceDebugEnabled(t *testing.T) { } } 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"`) { + if !strings.Contains(attemptDebug, `"llm_calls"`) || !strings.Contains(attemptDebug, `"prompt_path"`) || !strings.Contains(attemptDebug, `"response_path"`) || !strings.Contains(attemptDebug, `"response_content_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) + if !strings.Contains(responseDebug, `"content_path"`) || strings.Contains(responseDebug, `spell_casts`) { + t.Fatalf("response debug = %s, want metadata with content path and no inline response", responseDebug) + } + responseContent := string(readFile(t, filepath.Join(debugDir, "extract/spells/chunk-000001/attempt-01/response-content-0001.json"))) + if !strings.Contains(responseContent, `"spell_casts"`) || !strings.Contains(responseContent, "\n ") { + t.Fatalf("response content = %s, want pretty JSON response body", responseContent) } assertPathNotExist(t, filepath.Join(debugDir, "llm/call-0001.json")) assertPathNotExist(t, filepath.Join(debugDir, "extract/spells/chunk-000001-attempt-01/llm-call-0001.json")) @@ -3751,6 +3756,9 @@ func assertDebugTreeDoesNotContain(t *testing.T, root string, forbidden ...strin if entry.IsDir() { return nil } + if strings.HasPrefix(filepath.Base(path), "response-content-") { + return nil + } data, err := os.ReadFile(path) if err != nil { return err diff --git a/internal/framework/debug/recorder.go b/internal/framework/debug/recorder.go index 506cdb9..5b2aad2 100644 --- a/internal/framework/debug/recorder.go +++ b/internal/framework/debug/recorder.go @@ -32,3 +32,10 @@ func (r *WorkspaceRecorder) WriteJSON(name string, payload any) error { } return coreworkspace.WriteJSON(r.root, name, payload) } + +func (r *WorkspaceRecorder) WriteBytes(name string, data []byte) error { + if !r.Enabled() { + return nil + } + return coreworkspace.WriteBytes(r.root, name, data) +} diff --git a/internal/framework/pipeline/debug.go b/internal/framework/pipeline/debug.go index eee9cc2..e1c8b2e 100644 --- a/internal/framework/pipeline/debug.go +++ b/internal/framework/pipeline/debug.go @@ -1,10 +1,12 @@ package pipeline import ( + "bytes" "context" "crypto/sha256" "encoding/base64" "encoding/hex" + "encoding/json" "errors" "fmt" "path" @@ -22,14 +24,16 @@ import ( type DebugRecorder interface { Enabled() bool WriteJSON(name string, payload any) error + WriteBytes(name string, data []byte) error } type noopDebugRecorder struct{} func NoopDebugRecorder() DebugRecorder { return noopDebugRecorder{} } -func (noopDebugRecorder) Enabled() bool { return false } -func (noopDebugRecorder) WriteJSON(string, any) error { return nil } +func (noopDebugRecorder) Enabled() bool { return false } +func (noopDebugRecorder) WriteJSON(string, any) error { return nil } +func (noopDebugRecorder) WriteBytes(string, []byte) error { return nil } func debugPathComponent(value string) string { value = strings.TrimSpace(value) if value == "" { @@ -171,20 +175,22 @@ type debugLLMPromptArtifact struct { } type debugLLMResponseArtifact struct { - CallID string `json:"call_id"` - Response *contracts.LLMDebugResponse `json:"response,omitempty"` - Fallback *debugStructuredCompletionResponse `json:"fallback,omitempty"` - Error string `json:"error,omitempty"` + CallID string `json:"call_id"` + Response *contracts.LLMDebugResponse `json:"response,omitempty"` + Fallback *debugStructuredCompletionResponse `json:"fallback,omitempty"` + ContentPath string `json:"content_path,omitempty"` + Error string `json:"error,omitempty"` } type debugLLMCallReference struct { - 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"` + CallID string `json:"call_id"` + PromptPath string `json:"prompt_path,omitempty"` + ResponsePath string `json:"response_path"` + ResponseContentPath string `json:"response_content_path,omitempty"` + 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 { @@ -274,6 +280,10 @@ func (client *debugLLMClient) CompleteStructured(ctx context.Context, req contra })) } responsePath := path.Join(scopePrefix, "response-"+callID+".json") + responseMaterial := debugResponseMaterial(response) + fallbackMaterial := debugCompletionFallback(response) + responseContentPath, responseForArtifact, fallbackForArtifact, contentErr := writeDebugResponseContent(client.recorder, scopePrefix, callID, responseMaterial, fallbackMaterial) + writeErr = errors.Join(writeErr, contentErr) writeErr = errors.Join(writeErr, writeDebugTimed(client.recorder, responsePath, debugTimedEnvelope{ Stage: req.StageName, ModuleKey: req.StageName, @@ -281,21 +291,23 @@ func (client *debugLLMClient) CompleteStructured(ctx context.Context, req contra CompletedAt: completed, DurationMS: completed.Sub(started).Milliseconds(), Payload: debugLLMResponseArtifact{ - CallID: callID, - Response: debugResponseMaterial(response), - Fallback: debugCompletionFallback(response), - Error: errorText, + CallID: callID, + Response: responseForArtifact, + Fallback: fallbackForArtifact, + ContentPath: responseContentPath, + Error: errorText, }, Error: errorText, })) callRef := debugLLMCallReference{ - CallID: callID, - PromptPath: promptPath, - ResponsePath: responsePath, - PromptID: req.PromptID, - ProfileID: debugFirstNonEmptyString(response.ProfileID, req.ProfileID), - Model: debugFirstNonEmptyString(response.Model, debugResponseModel(response)), - Error: err != nil, + CallID: callID, + PromptPath: promptPath, + ResponsePath: responsePath, + ResponseContentPath: responseContentPath, + PromptID: req.PromptID, + ProfileID: debugFirstNonEmptyString(response.ProfileID, req.ProfileID), + Model: debugFirstNonEmptyString(response.Model, debugResponseModel(response)), + Error: err != nil, } if scope := debugLLMScopeFromContext(ctx); scope != nil { scope.record(callRef) @@ -593,6 +605,60 @@ func debugCompletionFallback(response contracts.StructuredCompletionResponse) *d return &fallback } +func writeDebugResponseContent(recorder DebugRecorder, scopePrefix string, callID string, response *contracts.LLMDebugResponse, fallback *debugStructuredCompletionResponse) (string, *contracts.LLMDebugResponse, *debugStructuredCompletionResponse, error) { + responseCopy := cloneDebugResponseWithoutContent(response) + fallbackCopy := cloneDebugFallbackWithoutContent(fallback) + content := "" + if response != nil { + content = response.Content + } + if content == "" && fallback != nil { + content = fallback.Content + } + if content == "" { + return "", responseCopy, fallbackCopy, nil + } + + contentPath, data := debugResponseContentFile(scopePrefix, callID, content) + if recorder == nil || !recorder.Enabled() { + return contentPath, responseCopy, fallbackCopy, nil + } + if err := recorder.WriteBytes(contentPath, data); err != nil { + return contentPath, responseCopy, fallbackCopy, err + } + return contentPath, responseCopy, fallbackCopy, nil +} + +func cloneDebugResponseWithoutContent(response *contracts.LLMDebugResponse) *contracts.LLMDebugResponse { + if response == nil { + return nil + } + clone := *response + clone.Content = "" + return &clone +} + +func cloneDebugFallbackWithoutContent(fallback *debugStructuredCompletionResponse) *debugStructuredCompletionResponse { + if fallback == nil { + return nil + } + clone := *fallback + clone.Content = "" + return &clone +} + +func debugResponseContentFile(scopePrefix string, callID string, content string) (string, []byte) { + raw := []byte(content) + if json.Valid(raw) { + var formatted bytes.Buffer + if err := json.Indent(&formatted, raw, "", " "); err == nil { + formatted.WriteByte('\n') + return path.Join(scopePrefix, "response-content-"+callID+".json"), formatted.Bytes() + } + } + return path.Join(scopePrefix, "response-content-"+callID+".txt"), raw +} + func debugResponseMaterial(response contracts.StructuredCompletionResponse) *contracts.LLMDebugResponse { if response.Debug == nil { return nil diff --git a/internal/framework/pipeline/runner_test.go b/internal/framework/pipeline/runner_test.go index 5884b5a..83e6c61 100644 --- a/internal/framework/pipeline/runner_test.go +++ b/internal/framework/pipeline/runner_test.go @@ -1310,7 +1310,7 @@ func TestRunDebugFailedChunkAttemptReferencesScopedLLMOutput(t *testing.T) { t.Fatalf("llm_calls = %#v, want one scoped call", attempt.LLMCalls) } call := attempt.LLMCalls[0] - if call.CallID != "0001" || call.PromptPath != "chunk/attempt-01/prompt-0001.json" || call.ResponsePath != "chunk/attempt-01/response-0001.json" { + if call.CallID != "0001" || call.PromptPath != "chunk/attempt-01/prompt-0001.json" || call.ResponsePath != "chunk/attempt-01/response-0001.json" || call.ResponseContentPath != "chunk/attempt-01/response-content-0001.json" { t.Fatalf("llm call reference = %#v, want prompt and response paths", call) } if call.PromptID != "runner.chunk" || call.ProfileID != "debug-profile" || call.Model != "debug-model" || call.Error { @@ -1331,8 +1331,14 @@ func TestRunDebugFailedChunkAttemptReferencesScopedLLMOutput(t *testing.T) { 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 responsePayload.ContentPath != call.ResponseContentPath { + t.Fatalf("response content path = %q, want %q", responsePayload.ContentPath, call.ResponseContentPath) + } + if responsePayload.Response == nil || responsePayload.Response.Content != "" { + t.Fatalf("response payload = %#v, want metadata without inline content", responsePayload) + } + if got := string(recorder.bytes[call.ResponseContentPath]); got != "{\n \"raw\": true\n}\n" { + t.Fatalf("response content file = %q, want pretty JSON", got) } if _, ok := recorder.payloads["llm/call-0001.json"]; ok { t.Fatalf("old canonical LLM debug artifact was written") @@ -1342,6 +1348,43 @@ func TestRunDebugFailedChunkAttemptReferencesScopedLLMOutput(t *testing.T) { } } +func TestRunDebugWritesNonJSONLLMResponseContentAsText(t *testing.T) { + modules := defaultRunnerModules() + modules.chunker.callLLM = true + modules.chunker.llmPromptID = "runner.chunk" + modules.chunker.err = errors.New("malformed structured output") + recorder := newMemoryDebugRecorder() + + _, err := New(newRunnerRegistries(t, modules)).Run(context.Background(), RunInput{ + Pipeline: resolvedPipeline(), + LLMClient: debugResponseLLMClient{content: []byte("plain text response"), profileID: "debug-profile"}, + Debug: recorder, + }) + if err == nil || !strings.Contains(err.Error(), "malformed structured output") { + t.Fatalf("Run() error = %v, want chunk failure", err) + } + + attempt := recorder.envelope(t, "chunk/attempt-01.json") + if len(attempt.LLMCalls) != 1 { + t.Fatalf("llm_calls = %#v, want one scoped call", attempt.LLMCalls) + } + call := attempt.LLMCalls[0] + if call.ResponseContentPath != "chunk/attempt-01/response-content-0001.txt" { + t.Fatalf("response content path = %q, want .txt file", call.ResponseContentPath) + } + if got := string(recorder.bytes[call.ResponseContentPath]); got != "plain text response" { + t.Fatalf("response text content = %q, want raw text", got) + } + 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 != "" { + t.Fatalf("response payload = %#v, want metadata without inline content", responsePayload) + } +} + func TestRunStopsRetryAfterConfiguredAttemptsAndRecordsAttemptCount(t *testing.T) { modules := defaultRunnerModules() validator := &runnerChainValidator{name: "chain-extract", approved: []bool{false}, reason: "bad_extract", message: "extract rejected"} @@ -2367,10 +2410,14 @@ func (client debugResponseLLMClient) CompleteStructured(ctx context.Context, req type memoryDebugRecorder struct { payloads map[string]any + bytes map[string][]byte } func newMemoryDebugRecorder() *memoryDebugRecorder { - return &memoryDebugRecorder{payloads: map[string]any{}} + return &memoryDebugRecorder{ + payloads: map[string]any{}, + bytes: map[string][]byte{}, + } } func (recorder *memoryDebugRecorder) Enabled() bool { return true } @@ -2380,6 +2427,11 @@ func (recorder *memoryDebugRecorder) WriteJSON(name string, payload any) error { return nil } +func (recorder *memoryDebugRecorder) WriteBytes(name string, data []byte) error { + recorder.bytes[name] = append([]byte(nil), data...) + return nil +} + func (recorder *memoryDebugRecorder) envelope(t *testing.T, name string) debugTimedEnvelope { t.Helper() payload, ok := recorder.payloads[name]