Rewrite the debug path to provide raw LLM prompt and response artifacts

This commit is contained in:
2026-07-08 08:37:26 -05:00
parent 451f6c0bb9
commit 68ec69f2e4
9 changed files with 389 additions and 71 deletions

View File

@@ -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, current run ID. The runner writes framework-boundary inputs, outputs,
structured LLM calls, validator calls, timing, and retry attempt metadata structured LLM calls, validator calls, timing, and retry attempt metadata
through that interface. Each retry or validator attempt records any LLM calls 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 made within that attempt in an `llm_calls` array and writes paired
canonical LLM call artifacts under the attempt directory. Debug output is not `prompt-000N.json` and `response-000N.json` files under the attempt directory.
used for resume and can contain sensitive source, reference, prompt, and Debug output is not used for resume and can contain sensitive source,
model-output material. Concrete modules still do not receive workspace paths. reference, prompt, and model-output material. Concrete modules still do not
receive workspace paths.
## Registries And Module Specs ## Registries And Module Specs

View File

@@ -138,12 +138,12 @@ checkpointing does not write debug output.
Debug artifacts include framework-boundary inputs and outputs for source, Debug artifacts include framework-boundary inputs and outputs for source,
chunk, extract, merge, normalize, and output work, structured LLM request and chunk, extract, merge, normalize, and output work, structured LLM request and
response data from Notarius contracts, validator requests and results, timing, response data from Notarius contracts, validator requests and results, timing,
and retry attempt metadata. Canonical LLM call artifacts are written under and retry attempt metadata. LLM calls made inside a retry or validator attempt
`llm/call-000N.json`; LLM calls made inside a retry or validator attempt are write paired `prompt-000N.json` and `response-000N.json` files under that
also copied under that attempt directory and linked from the attempt attempt directory and are linked from the attempt `llm_calls` array. Prompt and
`llm_calls` array. LLM response content in those artifacts is written as raw response content in those artifacts is written as raw text for inspection.
text for inspection. Debug artifacts may contain source material, reference Debug artifacts may contain source material, reference material, prompt inputs,
material, prompt inputs, model outputs, and other sensitive data. Obvious model outputs, and other sensitive data. API keys are not written, and obvious
credential-shaped values and sensitive map keys are redacted in framework credential-shaped values and sensitive map keys are redacted in framework
envelopes, but debug directories should still be protected as sensitive local envelopes, but debug directories should still be protected as sensitive local
state. state.

View File

@@ -2244,8 +2244,9 @@ func TestRunPipelineWritesDebugWhenWorkspaceDebugEnabled(t *testing.T) {
"chunk/input.json", "chunk/input.json",
"chunk/output.json", "chunk/output.json",
"extract/spells/input.json", "extract/spells/input.json",
"extract/spells/chunk-000001-attempt-01.json", "extract/spells/chunk-000001/attempt-01.json",
"extract/spells/chunk-000001-attempt-01/llm-call-0001.json", "extract/spells/chunk-000001/attempt-01/prompt-0001.json",
"extract/spells/chunk-000001/attempt-01/response-0001.json",
"extract/spells/output.json", "extract/spells/output.json",
"merge/spells/input.json", "merge/spells/input.json",
"merge/spells/output.json", "merge/spells/output.json",
@@ -2253,15 +2254,23 @@ func TestRunPipelineWritesDebugWhenWorkspaceDebugEnabled(t *testing.T) {
"normalize/spells/output.json", "normalize/spells/output.json",
"output/input.json", "output/input.json",
"output/output.json", "output/output.json",
"llm/call-0001.json",
} { } {
if _, err := os.Stat(filepath.Join(debugDir, name)); err != nil { if _, err := os.Stat(filepath.Join(debugDir, name)); err != nil {
t.Fatalf("expected debug artifact %q: %v", name, err) t.Fatalf("expected debug artifact %q: %v", name, err)
} }
} }
attemptDebug := string(readFile(t, filepath.Join(debugDir, "extract/spells/chunk-000001-attempt-01.json"))) 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"`) { if !strings.Contains(attemptDebug, `"llm_calls"`) || !strings.Contains(attemptDebug, `"prompt_path"`) || !strings.Contains(attemptDebug, `"response_path"`) {
t.Fatalf("extract attempt debug = %s, want scoped llm_calls", attemptDebug) 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")) 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 { if err := json.Unmarshal(encoded, out); err != nil {
return contracts.StructuredCompletionResponse{}, err return contracts.StructuredCompletionResponse{}, err
} }
return contracts.StructuredCompletionResponse{Content: encoded}, nil return fakeRunStructuredResponse(req, encoded), nil
} }
startUnitID := 1 startUnitID := 1
if client.invalidSourceRef { if client.invalidSourceRef {
@@ -3400,7 +3409,37 @@ func (client *fakeRunLLMClient) CompleteStructured(ctx context.Context, req cont
if err := json.Unmarshal(encoded, out); err != nil { if err := json.Unmarshal(encoded, out); err != nil {
return contracts.StructuredCompletionResponse{}, err 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 { func fakeLLMFactory(client contracts.StructuredLLMClient, err error) LLMClientFactory {

View File

@@ -19,19 +19,69 @@ type StructuredCompletionRequest struct {
} }
type StructuredCompletionResponse struct { type StructuredCompletionResponse struct {
Content json.RawMessage `json:"content"` Content json.RawMessage `json:"content"`
Provider string `json:"provider,omitempty"` Provider string `json:"provider,omitempty"`
Model string `json:"model,omitempty"` Model string `json:"model,omitempty"`
ProfileID string `json:"profile_id,omitempty"` ProfileID string `json:"profile_id,omitempty"`
PromptTokens int `json:"prompt_tokens,omitempty"` PromptTokens int `json:"prompt_tokens,omitempty"`
CompletionTokens int `json:"completion_tokens,omitempty"` CompletionTokens int `json:"completion_tokens,omitempty"`
TotalTokens int `json:"total_tokens,omitempty"` TotalTokens int `json:"total_tokens,omitempty"`
Debug *LLMDebugMaterial `json:"debug,omitempty"`
} }
type StructuredLLMClient interface { type StructuredLLMClient interface {
CompleteStructured(ctx context.Context, req StructuredCompletionRequest, out any) (StructuredCompletionResponse, error) 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 { type LLMProfileManifestProvider interface {
LLMProfileManifests() []artifacts.LLMProfileManifest LLMProfileManifests() []artifacts.LLMProfileManifest
} }

View File

@@ -98,6 +98,13 @@ func (c *ScriptoriumClient) CompleteStructured(ctx context.Context, req contract
Vars: scriptoriumVars(req), Vars: scriptoriumVars(req),
Metadata: scriptoriumMetadata(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) result, err := c.engine.Run(ctx, runReq)
if err != nil { if err != nil {
if ctxErr := ctx.Err(); ctxErr != nil { if ctxErr := ctx.Err(); ctxErr != nil {
@@ -108,7 +115,7 @@ func (c *ScriptoriumClient) CompleteStructured(ctx context.Context, req contract
if result == nil { if result == nil {
return contracts.StructuredCompletionResponse{}, fmt.Errorf("run Scriptorium prompt %q: empty result", promptID) 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 { 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, "; ")) 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 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 content := result.Artifact.Body
if len(content) == 0 { if len(content) == 0 {
content = []byte(result.RawOutput) content = []byte(result.RawOutput)
@@ -142,9 +149,111 @@ func (c *ScriptoriumClient) responseFromResult(result *scriptorium.RunResult) co
PromptTokens: result.Usage.PromptTokens, PromptTokens: result.Usage.PromptTokens,
CompletionTokens: result.Usage.CompletionTokens, CompletionTokens: result.Usage.CompletionTokens,
TotalTokens: result.Usage.TotalTokens, 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 { func (c *ScriptoriumClient) LLMProfileManifests() []artifacts.LLMProfileManifest {
if c == nil || c.recorder == nil { if c == nil || c.recorder == nil {
return nil return nil

View File

@@ -45,6 +45,25 @@ func TestScriptoriumClientMapsPromptRequestAndUnmarshalsOutput(t *testing.T) {
if resp.PromptTokens != 11 || resp.CompletionTokens != 7 || resp.TotalTokens != 18 { if resp.PromptTokens != 11 || resp.CompletionTokens != 7 || resp.TotalTokens != 18 {
t.Fatalf("usage = %#v, want mapped token counts", resp) 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() gotReq := fake.lastRequest()
if gotReq.Prompt.SessionID != "session-123" { if gotReq.Prompt.SessionID != "session-123" {
t.Fatalf("session id = %q, want session-123", gotReq.Prompt.SessionID) 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}` { if got := string(resp.Content); got != `{"bad":true}` {
t.Fatalf("response content = %q, want raw failed output", got) 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) { func TestScriptoriumClientDecodeFailureReturnsRawResponse(t *testing.T) {
@@ -119,13 +144,16 @@ func TestScriptoriumClientDecodeFailureReturnsRawResponse(t *testing.T) {
if got := string(resp.Content); got != `{"ok":true}` { if got := string(resp.Content); got != `{"ok":true}` {
t.Fatalf("response content = %q, want raw decode-failed output", got) 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) { func TestScriptoriumClientProviderFailureIncludesContextAndRedactsBearerToken(t *testing.T) {
client := newTestScriptoriumClient(t, &fakeScriptoriumLLM{err: errors.New("provider failed with Bearer secret-token")}) client := newTestScriptoriumClient(t, &fakeScriptoriumLLM{err: errors.New("provider failed with Bearer secret-token")})
var out map[string]any var out map[string]any
_, err := client.CompleteStructured(context.Background(), contracts.StructuredCompletionRequest{ resp, err := client.CompleteStructured(context.Background(), contracts.StructuredCompletionRequest{
PromptID: "adapter.test", PromptID: "adapter.test",
SessionID: "session-123", SessionID: "session-123",
Inputs: contracts.LLMInputSet{ Inputs: contracts.LLMInputSet{
@@ -141,6 +169,9 @@ func TestScriptoriumClientProviderFailureIncludesContextAndRedactsBearerToken(t
if strings.Contains(err.Error(), "secret-token") || !strings.Contains(err.Error(), "Bearer [REDACTED]") { if strings.Contains(err.Error(), "secret-token") || !strings.Contains(err.Error(), "Bearer [REDACTED]") {
t.Fatalf("error = %q, want redacted bearer token", err.Error()) 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) { func TestScriptoriumClientContextCancellationIsRespected(t *testing.T) {

View File

@@ -165,19 +165,26 @@ type debugStructuredCompletionResponse struct {
TotalTokens int `json:"total_tokens,omitempty"` TotalTokens int `json:"total_tokens,omitempty"`
} }
type debugStructuredLLMCall struct { type debugLLMPromptArtifact struct {
Request debugStructuredCompletionRequest `json:"request"` CallID string `json:"call_id"`
Response debugStructuredCompletionResponse `json:"response,omitempty"` Prompt *contracts.LLMDebugPrompt `json:"prompt,omitempty"`
Error string `json:"error,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 { type debugLLMCallReference struct {
CallID string `json:"call_id"` CallID string `json:"call_id"`
CanonicalPath string `json:"canonical_path"` PromptPath string `json:"prompt_path,omitempty"`
ScopedPath string `json:"scoped_path,omitempty"` ResponsePath string `json:"response_path"`
PromptID string `json:"prompt_id,omitempty"` PromptID string `json:"prompt_id,omitempty"`
ProfileID string `json:"profile_id,omitempty"` ProfileID string `json:"profile_id,omitempty"`
Error bool `json:"error,omitempty"` Model string `json:"model,omitempty"`
Error bool `json:"error,omitempty"`
} }
type debugValidationRequest struct { 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) { func (client *debugLLMClient) CompleteStructured(ctx context.Context, req contracts.StructuredCompletionRequest, out any) (contracts.StructuredCompletionResponse, error) {
client.mu.Lock() client.mu.Lock()
client.counter++ client.counter++
callID := fmt.Sprintf("call-%04d", client.counter) callID := fmt.Sprintf("%04d", client.counter)
client.mu.Unlock() client.mu.Unlock()
started := time.Now().UTC() started := time.Now().UTC()
response, err := client.inner.CompleteStructured(ctx, req, out) response, err := client.inner.CompleteStructured(ctx, req, out)
completed := time.Now().UTC() completed := time.Now().UTC()
payload := debugStructuredLLMCall{ errorText := ""
Request: debugCompletionRequest(req),
Response: debugCompletionResponse(response),
}
if err != nil { 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, Stage: req.StageName,
ModuleKey: req.StageName, ModuleKey: req.StageName,
StartedAt: started, StartedAt: started,
CompletedAt: completed, CompletedAt: completed,
DurationMS: completed.Sub(started).Milliseconds(), DurationMS: completed.Sub(started).Milliseconds(),
Payload: payload, Payload: debugLLMResponseArtifact{
Error: payload.Error, CallID: callID,
} Response: debugResponseMaterial(response),
canonicalPath := path.Join("llm", callID+".json") Fallback: debugCompletionFallback(response),
writeErr := writeDebugTimed(client.recorder, canonicalPath, envelope) Error: errorText,
},
Error: errorText,
}))
callRef := debugLLMCallReference{ callRef := debugLLMCallReference{
CallID: callID, CallID: callID,
CanonicalPath: canonicalPath, PromptPath: promptPath,
PromptID: req.PromptID, ResponsePath: responsePath,
ProfileID: debugFirstNonEmptyString(response.ProfileID, req.ProfileID), PromptID: req.PromptID,
Error: err != nil, ProfileID: debugFirstNonEmptyString(response.ProfileID, req.ProfileID),
Model: debugFirstNonEmptyString(response.Model, debugResponseModel(response)),
Error: err != nil,
} }
if scope := debugLLMScopeFromContext(ctx); scope != 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) scope.record(callRef)
} }
if err != nil { 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 { func debugValidationRequestEnvelope(req contracts.ValidationRequest) debugValidationRequest {
req.Schema.JSONSchema = nil req.Schema.JSONSchema = nil
out := debugValidationRequest{ out := debugValidationRequest{

View File

@@ -441,7 +441,7 @@ func (r *Runner) runLane(ctx context.Context, input RunInput, checkpoints Checkp
var acceptedWarnings []contracts.Warning var acceptedWarnings []contracts.Warning
accepted, rejection, err := runWithRetry(ctx, lane.Extract.Retries, func(attempt int) (bool, *contracts.RejectedOutput, error) { accepted, rejection, err := runWithRetry(ctx, lane.Extract.Retries, func(attempt int) (bool, *contracts.RejectedOutput, error) {
attemptStarted := time.Now().UTC() 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) attemptCtx, llmScope := withDebugLLMScope(ctx, attemptPath)
result, err := extractor.Extract(attemptCtx, contracts.ExtractionRequest{ result, err := extractor.Extract(attemptCtx, contracts.ExtractionRequest{
Source: doc, Source: doc,

View File

@@ -1310,22 +1310,36 @@ func TestRunDebugFailedChunkAttemptReferencesScopedLLMOutput(t *testing.T) {
t.Fatalf("llm_calls = %#v, want one scoped call", attempt.LLMCalls) t.Fatalf("llm_calls = %#v, want one scoped call", attempt.LLMCalls)
} }
call := attempt.LLMCalls[0] call := attempt.LLMCalls[0]
if call.CallID != "call-0001" || call.CanonicalPath != "llm/call-0001.json" || call.ScopedPath != "chunk/attempt-01/llm-call-0001.json" { 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 canonical and scoped paths", call) 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) t.Fatalf("llm call metadata = %#v, want prompt/profile and no call error", call)
} }
scoped := recorder.envelope(t, call.ScopedPath) prompt := recorder.envelope(t, call.PromptPath)
scopedPayload, ok := scoped.Payload.(debugStructuredLLMCall) promptPayload, ok := prompt.Payload.(debugLLMPromptArtifact)
if !ok { 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}` { if promptPayload.Prompt == nil || len(promptPayload.Prompt.Messages) != 1 || promptPayload.Prompt.Messages[0].Content != "raw prompt text" {
t.Fatalf("scoped response content = %q, want raw LLM response", scopedPayload.Response.Content) 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) { func TestRunStopsRetryAfterConfiguredAttemptsAndRecordsAttemptCount(t *testing.T) {
@@ -2332,7 +2346,22 @@ func (client debugResponseLLMClient) CompleteStructured(ctx context.Context, req
} }
return contracts.StructuredCompletionResponse{ return contracts.StructuredCompletionResponse{
Content: append([]byte(nil), client.content...), Content: append([]byte(nil), client.content...),
Model: "debug-model",
ProfileID: profileID, 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 }, client.err
} }