Write workspace debug artifacts during runs

This commit is contained in:
2026-07-08 03:14:59 +00:00
parent ae9c2e1d5e
commit a5bbfea9b9
10 changed files with 1134 additions and 6 deletions

View File

@@ -50,6 +50,7 @@ type RunInput struct {
Warnings []contracts.Warning
Checkpoints CheckpointRecorder
Checkpoint CheckpointLoader
Debug DebugRecorder
}
type RunOutput struct {
@@ -81,10 +82,27 @@ func (r *Runner) Run(ctx context.Context, input RunInput) (output RunOutput, err
if checkpointLoader == nil {
checkpointLoader = NoopCheckpointLoader()
}
debugRecorder := input.Debug
if debugRecorder == nil {
debugRecorder = NoopDebugRecorder()
}
input.Debug = debugRecorder
input.LLMClient = wrapDebugLLMClient(input.LLMClient, debugRecorder)
defer func() {
output.Manifest.LLMProfiles = mergeLLMProfileManifests(input.LLMProfiles, llmProfileManifests(input.LLMClient))
}()
output.Warnings = append(output.Warnings, cloneWarnings(input.Warnings)...)
if err := writeDebugTimed(debugRecorder, "run.json", debugTimedEnvelope{
Stage: "run",
StartedAt: startedTime(input.StartedAt),
Payload: map[string]any{
"pipeline_id": input.Pipeline.ID,
"pipeline_digest": input.Pipeline.Digest,
"run_id": output.Manifest.RunID,
},
}); err != nil {
return failOutput(output), fmt.Errorf("write debug run artifact: %w", err)
}
adapter, err := r.registries.Inputs.Build(input.Pipeline.Input.Module)
if err != nil {
@@ -94,6 +112,21 @@ func (r *Runner) Run(ctx context.Context, input RunInput) (output RunOutput, err
sourceCheckpoint, sourceDecision := checkpointLoader.Source(adapter.Key())
recordCheckpointEvent(&output, checkpointLoader, "source", "", adapter.Key(), sourceDecision)
doc := sourceCheckpoint.Document
sourceStarted := time.Now().UTC()
if err := writeDebugTimed(debugRecorder, "source/input.json", debugTimedEnvelope{
Stage: "source",
ModuleKey: adapter.Key(),
StartedAt: sourceStarted,
Payload: debugSourceInput{
SourceID: input.SourceID,
Path: input.Path,
Raw: debugContentEnvelope(input.RawInput, sourceInputMediaType(input.Path), nil, nil),
Options: redactSensitiveMap(input.Pipeline.Input.Options),
Metadata: redactSensitiveMap(input.Metadata),
},
}); err != nil {
return failOutput(output), fmt.Errorf("write source debug artifact: %w", err)
}
if !sourceDecision.Reused {
if err := checkpoints.SourceRunning(adapter.Key()); err != nil {
return failOutput(output), fmt.Errorf("write source checkpoint: %w", err)
@@ -118,6 +151,18 @@ func (r *Runner) Run(ctx context.Context, input RunInput) (output RunOutput, err
return failOutput(output), fmt.Errorf("write source checkpoint: %w", err)
}
}
if err := writeDebugTimed(debugRecorder, "source/output.json", debugTimedEnvelope{
Stage: "source",
ModuleKey: adapter.Key(),
StartedAt: sourceStarted,
Payload: map[string]any{
"reused": sourceDecision.Reused,
"decision": sourceDecision,
"document": debugSourceDocumentEnvelope(doc),
},
}); err != nil {
return failOutput(output), fmt.Errorf("write source debug artifact: %w", err)
}
sourceInput := sourceInputMaterial(input.Path, input.RawInput)
sessionID := resolvedSessionID(input.SessionID, doc.ID)
output.Manifest.Metadata = manifestMetadataWithSessionID(output.Manifest.Metadata, sessionID)
@@ -132,6 +177,22 @@ func (r *Runner) Run(ctx context.Context, input RunInput) (output RunOutput, err
var chunkWarnings []contracts.Warning
chunkCheckpoint, chunkDecision := checkpointLoader.Chunk(chunker.Key(), doc.Digest)
recordCheckpointEvent(&output, checkpointLoader, string(StageChunk), "", chunker.Key(), chunkDecision)
chunkStarted := time.Now().UTC()
if err := writeDebugTimed(debugRecorder, "chunk/input.json", debugTimedEnvelope{
Stage: string(StageChunk),
ModuleKey: chunker.Key(),
StartedAt: chunkStarted,
Payload: map[string]any{
"reused": chunkDecision.Reused,
"decision": chunkDecision,
"source": debugSourceDocumentEnvelope(doc),
"source_input": debugContentEnvelope(sourceInput.Content, sourceInput.MediaType, nil, nil),
"options": redactSensitiveMap(input.Pipeline.Chunk.Options),
"metadata": redactSensitiveMap(input.Metadata),
},
}); err != nil {
return failOutput(output), fmt.Errorf("write chunk debug artifact: %w", err)
}
chunksAccepted := chunkDecision.Reused
var chunkRejection *contracts.RejectedOutput
if chunkDecision.Reused {
@@ -143,6 +204,7 @@ func (r *Runner) Run(ctx context.Context, input RunInput) (output RunOutput, err
return failOutput(output), fmt.Errorf("write chunk checkpoint: %w", err)
}
chunksAccepted, chunkRejection, err = runWithRetry(ctx, input.Pipeline.Chunk.Retries, func(attempt int) (bool, *contracts.RejectedOutput, error) {
attemptStarted := time.Now().UTC()
chunkResult, err := chunker.Chunk(ctx, contracts.ChunkRequest{
Source: doc,
SourceInput: sourceInput.Clone(),
@@ -154,6 +216,13 @@ func (r *Runner) Run(ctx context.Context, input RunInput) (output RunOutput, err
Metadata: input.Metadata,
})
if err != nil {
_ = writeDebugTimed(debugRecorder, path.Join("chunk", fmt.Sprintf("attempt-%02d.json", attempt)), debugTimedEnvelope{
Stage: string(StageChunk),
ModuleKey: chunker.Key(),
Attempt: attempt,
StartedAt: attemptStarted,
Error: err.Error(),
})
return false, nil, fmt.Errorf("chunk source with chunker %q: %w", chunker.Key(), err)
}
if len(chunkResult.Chunks) == 0 {
@@ -163,12 +232,35 @@ func (r *Runner) Run(ctx context.Context, input RunInput) (output RunOutput, err
if err != nil {
return false, nil, fmt.Errorf("validate chunks from chunker %q: %w", chunker.Key(), err)
}
validationWarnings, rejection, err := r.validateChunksRaw(ctx, doc, chunker.Key(), chunks, sourceInput, sessionID, input.Pipeline.ChunkReferences.ReferenceSet, input.LLMClient, input.Metadata, input.Pipeline.ValidatorChains, attempt)
validationWarnings, rejection, err := r.validateChunksRaw(ctx, doc, chunker.Key(), chunks, sourceInput, sessionID, input.Pipeline.ChunkReferences.ReferenceSet, input.LLMClient, input.Metadata, input.Pipeline.ValidatorChains, attempt, input.Debug)
if err != nil || rejection != nil {
_ = writeDebugTimed(debugRecorder, path.Join("chunk", fmt.Sprintf("attempt-%02d.json", attempt)), debugTimedEnvelope{
Stage: string(StageChunk),
ModuleKey: chunker.Key(),
Attempt: attempt,
StartedAt: attemptStarted,
Payload: map[string]any{
"chunks": debugSourceChunkEnvelopes(chunks),
"warnings": append(cloneWarnings(chunkResult.Warnings), validationWarnings...),
"rejection": debugRejectedOutputPtr(rejection),
},
})
return false, rejection, err
}
canonicalChunks = chunks
chunkWarnings = append(cloneWarnings(chunkResult.Warnings), validationWarnings...)
if err := writeDebugTimed(debugRecorder, path.Join("chunk", fmt.Sprintf("attempt-%02d.json", attempt)), debugTimedEnvelope{
Stage: string(StageChunk),
ModuleKey: chunker.Key(),
Attempt: attempt,
StartedAt: attemptStarted,
Payload: map[string]any{
"chunks": debugSourceChunkEnvelopes(chunks),
"warnings": chunkWarnings,
},
}); err != nil {
return false, nil, err
}
return true, nil, nil
})
if err != nil {
@@ -187,6 +279,23 @@ func (r *Runner) Run(ctx context.Context, input RunInput) (output RunOutput, err
}
}
}
chunkDebugPayload := map[string]any{
"reused": chunkDecision.Reused,
"accepted": chunksAccepted,
"chunks": debugSourceChunkEnvelopes(canonicalChunks),
"warnings": chunkWarnings,
}
if chunkRejection != nil {
chunkDebugPayload["rejection"] = debugRejectedOutputEnvelope(*chunkRejection)
}
if err := writeDebugTimed(debugRecorder, "chunk/output.json", debugTimedEnvelope{
Stage: string(StageChunk),
ModuleKey: chunker.Key(),
StartedAt: chunkStarted,
Payload: chunkDebugPayload,
}); err != nil {
return failOutput(output), fmt.Errorf("write chunk debug artifact: %w", err)
}
if chunksAccepted {
for _, lane := range input.Pipeline.ArtifactLanes {
@@ -209,6 +318,22 @@ func (r *Runner) Run(ctx context.Context, input RunInput) (output RunOutput, err
return failOutput(output), fmt.Errorf("build output encoder %q: %w", input.Pipeline.Output.Module, err)
}
attachModuleManifestMetadata(&output, "output", encoder)
outputStarted := time.Now().UTC()
if err := writeDebugTimed(debugRecorder, "output/input.json", debugTimedEnvelope{
Stage: string(StageOutput),
ModuleKey: encoder.Key(),
StartedAt: outputStarted,
Payload: map[string]any{
"manifest": output.Manifest,
"normalize_outputs": debugNormalizeOutputEnvelopes(output.NormalizeOutputs),
"rejected": debugRejectedOutputEnvelopes(output.Rejected),
"warnings": output.Warnings,
"options": redactSensitiveMap(input.Pipeline.Output.Options),
"metadata": redactSensitiveMap(input.Metadata),
},
}); err != nil {
return failOutput(output), fmt.Errorf("write output debug artifact: %w", err)
}
encoded, err := encoder.Encode(ctx, contracts.OutputRequest{
Manifest: output.Manifest,
NormalizeOutputs: cloneNormalizeOutputs(output.NormalizeOutputs),
@@ -227,6 +352,17 @@ func (r *Runner) Run(ctx context.Context, input RunInput) (output RunOutput, err
return failOutput(output), fmt.Errorf("validate output files from encoder %q: %w", encoder.Key(), err)
}
output.OutputFiles = files
if err := writeDebugTimed(debugRecorder, "output/output.json", debugTimedEnvelope{
Stage: string(StageOutput),
ModuleKey: encoder.Key(),
StartedAt: outputStarted,
Payload: map[string]any{
"files": debugOutputFiles(files),
"warnings": encoded.Warnings,
},
}); err != nil {
return failOutput(output), fmt.Errorf("write output debug artifact: %w", err)
}
return output, nil
}
@@ -252,6 +388,23 @@ func (r *Runner) runLane(ctx context.Context, input RunInput, checkpoints Checkp
extractDependencies := digestFingerprints("chunks", joinedChunkDigest(chunks))
extractCheckpoint, extractDecision := checkpointLoader.Extract(lane.ID, extractor.Key(), extractDependencies)
recordCheckpointEvent(output, checkpointLoader, string(StageExtract), lane.ID, extractor.Key(), extractDecision)
extractStarted := time.Now().UTC()
if err := writeDebugTimed(input.Debug, path.Join("extract", debugPathComponent(lane.ID), "input.json"), debugTimedEnvelope{
Stage: string(StageExtract),
LaneID: lane.ID,
ModuleKey: extractor.Key(),
StartedAt: extractStarted,
Payload: map[string]any{
"reused": extractDecision.Reused,
"decision": extractDecision,
"source": debugSourceDocumentEnvelope(doc),
"chunks": debugSourceChunkEnvelopes(chunks),
"options": redactSensitiveMap(lane.Extract.Options),
"metadata": redactSensitiveMap(input.Metadata),
},
}); err != nil {
return fmt.Errorf("write extract debug artifact for lane %q: %w", lane.ID, err)
}
if extractDecision.Reused {
extractOutputs = cloneExtractOutputs(extractCheckpoint.Outputs)
extractWarnings = cloneWarnings(extractCheckpoint.Warnings)
@@ -305,6 +458,7 @@ func (r *Runner) runLane(ctx context.Context, input RunInput, checkpoints Checkp
metadata: input.Metadata,
chains: input.Pipeline.ValidatorChains,
attempt: attempt,
debug: input.Debug,
})
if err != nil || rejection != nil {
return false, rejection, err
@@ -330,6 +484,20 @@ func (r *Runner) runLane(ctx context.Context, input RunInput, checkpoints Checkp
return fmt.Errorf("write extract checkpoint for lane %q: %w", lane.ID, err)
}
}
if err := writeDebugTimed(input.Debug, path.Join("extract", debugPathComponent(lane.ID), "output.json"), debugTimedEnvelope{
Stage: string(StageExtract),
LaneID: lane.ID,
ModuleKey: extractor.Key(),
StartedAt: extractStarted,
Payload: map[string]any{
"reused": extractDecision.Reused,
"outputs": debugExtractOutputEnvelopes(extractOutputs),
"rejected": debugRejectedOutputEnvelopes(output.Rejected[extractRejectedStart:]),
"warnings": extractWarnings,
},
}); err != nil {
return fmt.Errorf("write extract debug artifact for lane %q: %w", lane.ID, err)
}
if len(extractOutputs) == 0 {
return nil
@@ -340,6 +508,23 @@ func (r *Runner) runLane(ctx context.Context, input RunInput, checkpoints Checkp
mergeDependencies := rawOutputDigests(extractPayloads(extractOutputs))
mergeCheckpoint, mergeDecision := checkpointLoader.Merge(lane.ID, merger.Key(), mergeDependencies)
recordCheckpointEvent(output, checkpointLoader, string(StageMerge), lane.ID, merger.Key(), mergeDecision)
mergeStarted := time.Now().UTC()
if err := writeDebugTimed(input.Debug, path.Join("merge", debugPathComponent(lane.ID), "input.json"), debugTimedEnvelope{
Stage: string(StageMerge),
LaneID: lane.ID,
ModuleKey: merger.Key(),
StartedAt: mergeStarted,
Payload: map[string]any{
"reused": mergeDecision.Reused,
"decision": mergeDecision,
"source": debugSourceDocumentEnvelope(doc),
"extract_outputs": debugExtractOutputEnvelopes(extractOutputs),
"options": redactSensitiveMap(lane.Merge.Options),
"metadata": redactSensitiveMap(input.Metadata),
},
}); err != nil {
return fmt.Errorf("write merge debug artifact for lane %q: %w", lane.ID, err)
}
if mergeDecision.Reused {
acceptedMerge = cloneMergeOutput(mergeCheckpoint.Output)
mergeWarnings = cloneWarnings(mergeCheckpoint.Warnings)
@@ -385,6 +570,7 @@ func (r *Runner) runLane(ctx context.Context, input RunInput, checkpoints Checkp
metadata: input.Metadata,
chains: input.Pipeline.ValidatorChains,
attempt: attempt,
debug: input.Debug,
})
if err != nil || rejection != nil {
return false, rejection, err
@@ -402,6 +588,19 @@ func (r *Runner) runLane(ctx context.Context, input RunInput, checkpoints Checkp
if err := checkpoints.MergeRejected(lane.ID, merger.Key(), mergeDependencies, *mergeRejection); err != nil {
return fmt.Errorf("write merge checkpoint for lane %q: %w", lane.ID, err)
}
if err := writeDebugTimed(input.Debug, path.Join("merge", debugPathComponent(lane.ID), "output.json"), debugTimedEnvelope{
Stage: string(StageMerge),
LaneID: lane.ID,
ModuleKey: merger.Key(),
StartedAt: mergeStarted,
Payload: map[string]any{
"accepted": false,
"rejection": debugRejectedOutputEnvelope(*mergeRejection),
"warnings": mergeWarnings,
},
}); err != nil {
return fmt.Errorf("write merge debug artifact for lane %q: %w", lane.ID, err)
}
return nil
}
output.Warnings = append(output.Warnings, mergeWarnings...)
@@ -409,12 +608,43 @@ func (r *Runner) runLane(ctx context.Context, input RunInput, checkpoints Checkp
return fmt.Errorf("write merge checkpoint for lane %q: %w", lane.ID, err)
}
}
if err := writeDebugTimed(input.Debug, path.Join("merge", debugPathComponent(lane.ID), "output.json"), debugTimedEnvelope{
Stage: string(StageMerge),
LaneID: lane.ID,
ModuleKey: merger.Key(),
StartedAt: mergeStarted,
Payload: map[string]any{
"reused": mergeDecision.Reused,
"accepted": true,
"output": debugMergeOutputEnvelope(acceptedMerge),
"warnings": mergeWarnings,
},
}); err != nil {
return fmt.Errorf("write merge debug artifact for lane %q: %w", lane.ID, err)
}
var acceptedNormalize contracts.NormalizeOutput
var normalizeWarnings []contracts.Warning
normalizeDependencies := rawOutputDigests([]contracts.RawPayload{acceptedMerge.Payload})
normalizeCheckpoint, normalizeDecision := checkpointLoader.Normalize(lane.ID, normalizer.Key(), normalizeDependencies)
recordCheckpointEvent(output, checkpointLoader, string(StageNormalize), lane.ID, normalizer.Key(), normalizeDecision)
normalizeStarted := time.Now().UTC()
if err := writeDebugTimed(input.Debug, path.Join("normalize", debugPathComponent(lane.ID), "input.json"), debugTimedEnvelope{
Stage: string(StageNormalize),
LaneID: lane.ID,
ModuleKey: normalizer.Key(),
StartedAt: normalizeStarted,
Payload: map[string]any{
"reused": normalizeDecision.Reused,
"decision": normalizeDecision,
"source": debugSourceDocumentEnvelope(doc),
"merge_output": debugMergeOutputEnvelope(acceptedMerge),
"options": redactSensitiveMap(lane.Normalize.Options),
"metadata": redactSensitiveMap(input.Metadata),
},
}); err != nil {
return fmt.Errorf("write normalize debug artifact for lane %q: %w", lane.ID, err)
}
if normalizeDecision.Reused {
acceptedNormalize = cloneNormalizeOutput(normalizeCheckpoint.Output)
normalizeWarnings = cloneWarnings(normalizeCheckpoint.Warnings)
@@ -460,6 +690,7 @@ func (r *Runner) runLane(ctx context.Context, input RunInput, checkpoints Checkp
metadata: input.Metadata,
chains: input.Pipeline.ValidatorChains,
attempt: attempt,
debug: input.Debug,
})
if err != nil || rejection != nil {
return false, rejection, err
@@ -477,6 +708,19 @@ func (r *Runner) runLane(ctx context.Context, input RunInput, checkpoints Checkp
if err := checkpoints.NormalizeRejected(lane.ID, normalizer.Key(), normalizeDependencies, *normalizeRejection); err != nil {
return fmt.Errorf("write normalize checkpoint for lane %q: %w", lane.ID, err)
}
if err := writeDebugTimed(input.Debug, path.Join("normalize", debugPathComponent(lane.ID), "output.json"), debugTimedEnvelope{
Stage: string(StageNormalize),
LaneID: lane.ID,
ModuleKey: normalizer.Key(),
StartedAt: normalizeStarted,
Payload: map[string]any{
"accepted": false,
"rejection": debugRejectedOutputEnvelope(*normalizeRejection),
"warnings": normalizeWarnings,
},
}); err != nil {
return fmt.Errorf("write normalize debug artifact for lane %q: %w", lane.ID, err)
}
return nil
}
output.Warnings = append(output.Warnings, normalizeWarnings...)
@@ -484,6 +728,20 @@ func (r *Runner) runLane(ctx context.Context, input RunInput, checkpoints Checkp
return fmt.Errorf("write normalize checkpoint for lane %q: %w", lane.ID, err)
}
}
if err := writeDebugTimed(input.Debug, path.Join("normalize", debugPathComponent(lane.ID), "output.json"), debugTimedEnvelope{
Stage: string(StageNormalize),
LaneID: lane.ID,
ModuleKey: normalizer.Key(),
StartedAt: normalizeStarted,
Payload: map[string]any{
"reused": normalizeDecision.Reused,
"accepted": true,
"output": debugNormalizeOutputEnvelope(acceptedNormalize),
"warnings": normalizeWarnings,
},
}); err != nil {
return fmt.Errorf("write normalize debug artifact for lane %q: %w", lane.ID, err)
}
output.NormalizeOutputs = append(output.NormalizeOutputs, acceptedNormalize)
return nil
}
@@ -509,6 +767,7 @@ type rawValidationTarget struct {
metadata map[string]any
chains []ResolvedValidatorChain
attempt int
debug DebugRecorder
}
func runWithRetry(ctx context.Context, retries int, run func(attempt int) (bool, *contracts.RejectedOutput, error)) (bool, *contracts.RejectedOutput, error) {
@@ -558,7 +817,7 @@ func runWithRetry(ctx context.Context, retries int, run func(attempt int) (bool,
return false, lastRejection, nil
}
func (r *Runner) validateChunksRaw(ctx context.Context, doc *source.SourceDocument, moduleKey string, chunks []contracts.SourceChunk, sourceInput contracts.LLMInputMaterial, sessionID string, references contracts.ReferenceSet, llmClient contracts.StructuredLLMClient, metadata map[string]any, chains []ResolvedValidatorChain, attempt int) ([]contracts.Warning, *contracts.RejectedOutput, error) {
func (r *Runner) validateChunksRaw(ctx context.Context, doc *source.SourceDocument, moduleKey string, chunks []contracts.SourceChunk, sourceInput contracts.LLMInputMaterial, sessionID string, references contracts.ReferenceSet, llmClient contracts.StructuredLLMClient, metadata map[string]any, chains []ResolvedValidatorChain, attempt int, debug DebugRecorder) ([]contracts.Warning, *contracts.RejectedOutput, error) {
return r.validateRaw(ctx, rawValidationTarget{
stage: StageChunk,
moduleKey: moduleKey,
@@ -572,6 +831,7 @@ func (r *Runner) validateChunksRaw(ctx context.Context, doc *source.SourceDocume
metadata: metadata,
chains: chains,
attempt: attempt,
debug: debug,
})
}
@@ -591,7 +851,27 @@ func (r *Runner) validateRaw(ctx context.Context, target rawValidationTarget) ([
return nil, nil, fmt.Errorf("build validator %q: %w", validatorBinding.Binding.Module, err)
}
request := target.validationRequest(validatorBinding.Binding)
started := time.Now().UTC()
result, err := validator.Validate(ctx, request)
debugPayload := debugValidationCall{
ValidatorName: validator.Name(),
Request: debugValidationRequestEnvelope(request),
Result: debugValidationResultEnvelope(result),
}
if err != nil {
debugPayload.Error = err.Error()
}
if debugErr := writeDebugTimed(target.debug, path.Join("validate", debugPathComponent(string(target.stage)), debugPathComponent(target.laneID), debugPathComponent(target.moduleKey), fmt.Sprintf("%02d-%s-attempt-%02d.json", len(warnings)+1, debugPathComponent(validator.Name()), target.attempt)), debugTimedEnvelope{
Stage: string(target.stage),
LaneID: target.laneID,
ModuleKey: target.moduleKey,
Attempt: target.attempt,
StartedAt: started,
Payload: debugPayload,
Error: debugPayload.Error,
}); debugErr != nil {
return nil, nil, fmt.Errorf("write validation debug artifact: %w", debugErr)
}
if err != nil {
return nil, nil, fmt.Errorf("validate raw %s output with validator %q: %w", target.stage, validator.Name(), err)
}
@@ -733,6 +1013,13 @@ func validateRunInput(input RunInput) error {
return nil
}
func startedTime(t time.Time) time.Time {
if t.IsZero() {
return time.Now().UTC()
}
return t.UTC()
}
func manifestFromPipeline(input RunInput) artifacts.RunManifest {
startedAt := input.StartedAt
if startedAt.IsZero() {