From 9561e80efbccb5c1eef820858fb898e11c4b8d71 Mon Sep 17 00:00:00 2001 From: Eric Rakestraw Date: Thu, 24 Sep 2026 02:31:37 +0000 Subject: [PATCH] Add version two LLM reports and safe execution diagnostics --- docs/integrations/output-files.md | 45 ++--- docs/internal/diagnostics-reporting.md | 13 +- docs/operations.md | 7 +- docs/roadmap/implementation.md | 10 +- internal/cli/run.go | 49 ++++- internal/core/diagnostics/artifacts.go | 7 +- internal/core/diagnostics/run_dir.go | 8 + internal/core/reporting/llm.go | 58 ++++++ internal/core/reporting/report.go | 5 +- internal/framework/llm/adapter.go | 4 +- internal/framework/llm/observations.go | 3 +- internal/framework/processreport/llm.go | 183 +++++++++++++++++++ internal/framework/processreport/llm_test.go | 56 ++++++ internal/framework/processreport/report.go | 6 + internal/framework/runner/runner.go | 13 +- internal/framework/structuredoutput/call.go | 1 + 16 files changed, 428 insertions(+), 40 deletions(-) create mode 100644 internal/core/reporting/llm.go create mode 100644 internal/framework/processreport/llm.go create mode 100644 internal/framework/processreport/llm_test.go diff --git a/docs/integrations/output-files.md b/docs/integrations/output-files.md index 06495a7..dc4cb65 100644 --- a/docs/integrations/output-files.md +++ b/docs/integrations/output-files.md @@ -39,7 +39,7 @@ from the transcript output envelope: | Metadata field | Type / current value | | --- | --- | | `report_schema_name` | String: `audita-process-report` | -| `report_schema_version` | String: `v1` | +| `report_schema_version` | String: `v2` | | `output_schema` | String identifying the selected transcript encoder | | `config_version` | Optional integer, present when file configuration was loaded | @@ -60,6 +60,7 @@ The remaining top-level fields are: | `normalization_skipped` | Object of optional integer counters: `different_speakers`, `gap_too_large`, `duration_exceeded`, `token_limit_exceeded`; can be empty | | `chunking` | Optional section summary described below | | `diagnostics` | Optional artifact-path metadata described below | +| `llm_summary` | Optional logical LLM execution summary, present when observations were initialized | | `modules_summary` | Optional aggregate module outcome | | `module_results` | Optional array of module outcomes | @@ -88,7 +89,7 @@ human-readable, not structured fields to parse for control flow. - `directory_path` - `source_transcript_path`, `parsed_source_transcript_path`, `normalized_transcript_path` - `normalization_summary_path`, `chunking_summary_path` -- `utilization_summary_path`, `correction_ledger_path` +- `utilization_summary_path`, `llm_execution_path`, `selected_profiles_path`, `correction_ledger_path` - `invocation_metadata_path`, `redacted_effective_config_path`, `error_log_path` The [operations guide](../operations.md#diagnostics-directory) defines the physical @@ -163,24 +164,26 @@ or resume protocol. ## Utilization Diagnostics -This unversioned JSON object describes observations from the runtime, not service -limits or performance guarantees: +`llm_summary` contains integer `logical_calls`, `provider_attempts`, +`transient_retries`, and `structural_repairs`. Its `usage` contains `prompt`, +`completion`, `total`, `cached`, and `cache_write`, each with integer `value` +and boolean `known` and `complete`. A call counts once even if preparation fails. +If no call dispatches, usage is known-zero and complete. Missing `llm_summary` +means observations were unavailable. -- `effective_concurrency`: integer `total_llm`, `proposal_llm`, `validation_llm`. -- `run_timing`: millisecond integers `run_wall_time_ms`, `scheduler_queue_wait_ms`, - `llm_execution_time_ms`, `deterministic_validation_time_ms`; integer - `max_in_flight_llm_calls` and `average_in_flight_llm_calls`. -- `llm_calls`: integer `total_proposal_calls` and `total_validation_calls`. -- Optional `modules`: records with `module_key`, `module_instance`, integer - `proposal_llm_calls` and `validation_llm_calls`, and millisecond integer - `scheduler_queue_wait_ms`, `llm_execution_time_ms`, - `deterministic_validation_time_ms`, and `module_wall_time_ms`. -- Optional `validators`: records with `module_key`, `module_instance`, - `validator_key`, boolean `llm_backed`, integer `calls`, and millisecond integer - `elapsed_ms`. +The unversioned utilization JSON contains `backends`, keyed by backend ID. Each +entry has configured `concurrency` and `queue_capacity`, the same execution +summary fields, and integer `capacity_wait_ms`, `generation_ms`, +`retry_delay_ms`, and `logical_wall_ms`. It also has `run_wall_time_ms` and +optional `modules` and `validators` arrays. Module records contain the module +identity, logical proposal/validation call counts, and `module_wall_time_ms`. +Validator records contain module/validator identity, `llm_backed`, `calls`, and +`elapsed_ms`. Timings can overlap; they do not decompose total wall time. -Aggregated execution/wait durations can overlap in concurrent work; they need -not sum to wall time. The observed average concurrency is serialized as an integer. -Other source snapshots, prompt payloads, and diagnostic files are debugging -material; their placement is documented in operations without defining a separate -public schema for every file. +`llm-execution.json` has `calls` and `events` arrays joined by `call_id`. Calls +include logical attribution, final classification, summary, elapsed milliseconds, +and available prompt/profile/model metadata. Events contain safe execution +metadata, including attempt and terminal records, with millisecond durations. +Preparation failures have a call and no fabricated events. This artifact has no +provider messages, endpoints, credentials, or transcript content. Other request +and response artifacts can contain redacted prompt and transcript content. diff --git a/docs/internal/diagnostics-reporting.md b/docs/internal/diagnostics-reporting.md index 6da24ae..1458c23 100644 --- a/docs/internal/diagnostics-reporting.md +++ b/docs/internal/diagnostics-reporting.md @@ -40,8 +40,12 @@ ledger entries. It associates validator records by proposal index within each module, separates execution classes through validator metadata, and sorts entries by module instance, proposal index, and disposition. -Runner instrumentation collects utilization; CLI orchestration writes it when -run output is available. Report assembly does not independently measure calls. +Runner instrumentation and PromptKit observations collect utilization; CLI +orchestration writes the backend summary and safe call/event artifact when run +output is available. Report assembly maps the same observations to `llm_summary` +without independently measuring calls. A selected backend remains attributable +when preparation fails before dispatch. Domain module/validator timing stays +separate from provider timing, and those durations can overlap. For the serialized forms see [ledger](../integrations/output-files.md#correction-ledger) and [utilization](../integrations/output-files.md#utilization-diagnostics). @@ -59,8 +63,9 @@ artifacts and process exit status must be assessed together. ## Redaction -Effective configuration uses config redaction. LLM diagnostic and error paths -use `llm.ConfiguredSecrets` and the runtime's redaction helpers. Keep these separate +Effective configuration uses ConfigKit redaction. LLM diagnostic and error paths +use `llm.ConfiguredSecrets` and the runtime's redaction helpers. The CLI also +redacts every resolved backend secret from both report copies. Keep these separate mechanisms aligned with the [architecture requirement](../policy/architecture.md#errors-and-secret-handling). Operational handling of transcript-bearing artifacts belongs to [operations](../operations.md#artifact-handling). diff --git a/docs/operations.md b/docs/operations.md index 20c4adf..3712190 100644 --- a/docs/operations.md +++ b/docs/operations.md @@ -51,10 +51,13 @@ resolve them using the invocation's working directory. | `normalization-summary.json` | Normalization counters | | `chunking-summary.json` | Section/token summary | | `invocation.json` | Invocation metadata | -| `effective-config.json` | Redacted configuration snapshot | +| `effective-config.redacted.yaml` | Redacted ConfigKit configuration snapshot | +| `config-origins.yaml` | Safe configuration origin and resolution metadata | +| `selected-profiles.yaml` | Safe selected role profiles and model controls | | `report.json` | Run's [process report](integrations/output-files.md#process-report) | | `correction-ledger.json` | [Correction dispositions](integrations/output-files.md#correction-ledger) | -| `utilization-diagnostics.json` | [Concurrency and timing observations](integrations/output-files.md#utilization-diagnostics) | +| `utilization-diagnostics.json` | [Backend execution and domain timing observations](integrations/output-files.md#utilization-diagnostics) | +| `llm-execution.json` | Safe logical-call and execution event records | | `error.log` | Failure details when written | LLM request, response, and error diagnostics are also written within the run diff --git a/docs/roadmap/implementation.md b/docs/roadmap/implementation.md index 8ecb14f..9073878 100644 --- a/docs/roadmap/implementation.md +++ b/docs/roadmap/implementation.md @@ -473,7 +473,15 @@ No raw provider messages, URLs, keys, prompts, or payloads enter observation rec ## Stage 10: Update Reports and Diagnostic Artifacts -**Status:** Pending. **Depends on:** Stage 9. +**Status:** Complete. Process reports use v2 LLM summaries; retained diagnostics +include backend utilization, safe call/event records, selected profiles, config +origins, and the redacted ConfigKit snapshot. Focused reporting, diagnostics, +runtime, and runner tests and a binary build passed. A controlled provider 500 +response echoing a synthetic secret produced a partial failure report and retained +artifacts without the secret in stdout, stderr, reports, or artifacts. The assembled +CLI test suite remains scheduled for Stage 12. + +**Depends on:** Stage 9. **Owns:** `internal/core/reporting`, `internal/core/diagnostics`, `internal/framework/processreport`, runtime diagnostic writers, and CLI artifact wiring. diff --git a/internal/cli/run.go b/internal/cli/run.go index 45e4610..f07b2a6 100644 --- a/internal/cli/run.go +++ b/internal/cli/run.go @@ -3,6 +3,7 @@ package cli import ( "bytes" "context" + "encoding/json" "fmt" "io" "strings" @@ -34,6 +35,7 @@ type processInvocation struct { LLMRuntime *llm.Runtime ConfigPath string ConfigSource string + Overlay string ConfigVersion *int ExplicitModules bool } @@ -52,7 +54,7 @@ var processRunner = func(inv processInvocation, stdout io.Writer) (*normalizatio } fail := func(phase string, err error, runOutput *runner.RunOutput) (*normalization.NormalizationSummary, *chunking.Summary, *runner.RunOutput, *diagnostics.RunDirectory, error) { - _ = runDir.WriteErrorLog(fmt.Sprintf("%s: %v", phase, err)) + _ = runDir.WriteErrorLog(fmt.Sprintf("%s: %s", phase, llm.RedactError(err, inv.Config))) return nil, nil, runOutput, runDir, fmt.Errorf("%s: %w", phase, err) } @@ -64,6 +66,7 @@ var processRunner = func(inv processInvocation, stdout io.Writer) (*normalizatio ReportJSONPath: inv.ReportJSONPath, ConfigPath: inv.ConfigPath, ConfigSource: inv.ConfigSource, + Overlay: inv.Overlay, ConfigVersion: inv.ConfigVersion, TranscriptDescription: inv.Config.Context.Description, Modules: append([]string(nil), inv.Config.Pipeline.Modules...), @@ -78,6 +81,14 @@ var processRunner = func(inv processInvocation, stdout io.Writer) (*normalizatio if err != nil { _ = runDir.WriteErrorLog(fmt.Sprintf("effective_config: %v", err)) } + if origins, err := llm.ExplanationYAML(inv.ConfigResult); err == nil { + _ = runDir.WriteArtifact(diagnostics.ArtifactConfigOrigins, origins) + } + } + if inv.LLMRuntime != nil { + if profiles, err := inv.LLMRuntime.SelectedProfilesYAML(); err == nil { + _ = runDir.WriteArtifact(diagnostics.ArtifactSelectedProfiles, profiles) + } } transcriptBytes, err := coreio.ReadRequiredFile(inv.TranscriptPath, "transcript") @@ -194,6 +205,7 @@ var processRunner = func(inv processInvocation, stdout io.Writer) (*normalizatio ValidationDiagnosticsDir: runDir.Path(), }) runnerResult.Observations = observations.Snapshot() + runnerResult.ObservationsAvailable = true runnerResult.LLMSummary = llm.Summarize(runnerResult.Observations) runOutput = &runnerResult if runErr != nil { @@ -320,6 +332,7 @@ func runProcess(args []string, stdout, stderr io.Writer) int { LLMRuntime: llmRuntime, ConfigPath: selected.Path, ConfigSource: selected.Source, + Overlay: input.Overlay, ConfigVersion: &version, ExplicitModules: explicitModules, } @@ -329,6 +342,7 @@ func runProcess(args []string, stdout, stderr io.Writer) int { if runErr != nil { if runDir != nil && runOutput != nil { + writeExecutionArtifacts(runDir, runOutput, inv.Config) _ = runDir.WriteJSONArtifact(diagnostics.ArtifactCorrectionLedger, processreport.BuildCorrectionLedger(processreport.CorrectionLedgerInput{ RunDirectoryPath: runDir.Path(), @@ -336,7 +350,9 @@ func runProcess(args []string, stdout, stderr io.Writer) int { })) } errorPhase, errorMessage := extractErrorPhase(runErr) + errorMessage = llm.RedactError(fmt.Errorf("%s", errorMessage), inv.Config) report := processreport.Build(processReportInput("failed", inv, runDir, startedAt, completedAt, errorMessage, errorPhase, nil, nil, runOutput)) + report = redactProcessReport(report, inv.Config) if strings.TrimSpace(inv.ReportJSONPath) != "" { if err := reporting.WriteProcessReport(inv.ReportJSONPath, report); err != nil { @@ -351,7 +367,7 @@ func runProcess(args []string, stdout, stderr io.Writer) int { }) } - fmt.Fprintf(stderr, "audita process: %v\n", runErr) + fmt.Fprintf(stderr, "audita process: %s\n", llm.RedactError(runErr, inv.Config)) if runDir != nil { fmt.Fprintf(stderr, "audita process: diagnostics: %s\n", runDir.Path()) } @@ -359,6 +375,7 @@ func runProcess(args []string, stdout, stderr io.Writer) int { } if runDir != nil && runOutput != nil { + writeExecutionArtifacts(runDir, runOutput, inv.Config) _ = runDir.WriteJSONArtifact(diagnostics.ArtifactCorrectionLedger, processreport.BuildCorrectionLedger(processreport.CorrectionLedgerInput{ RunDirectoryPath: runDir.Path(), @@ -367,6 +384,7 @@ func runProcess(args []string, stdout, stderr io.Writer) int { } report := processreport.Build(processReportInput("success", inv, runDir, startedAt, completedAt, "", "", normSummary, chunkSummary, runOutput)) + report = redactProcessReport(report, inv.Config) if strings.TrimSpace(inv.ReportJSONPath) != "" { if err := reporting.WriteProcessReport(inv.ReportJSONPath, report); err != nil { @@ -395,6 +413,32 @@ func runProcess(args []string, stdout, stderr io.Writer) int { return 0 } +func writeExecutionArtifacts(runDir *diagnostics.RunDirectory, output *runner.RunOutput, cfg config.Config) { + if !output.ObservationsAvailable { + return + } + _ = runDir.WriteJSONArtifact(diagnostics.ArtifactLLMExecution, processreport.BuildLLMExecution(output.Observations)) + _ = runDir.WriteJSONArtifact(diagnostics.ArtifactUtilizationSummary, processreport.BuildUtilization(output, cfg.Backends)) +} + +func redactProcessReport(report reporting.ProcessReport, cfg config.Config) reporting.ProcessReport { + raw, err := json.Marshal(report) + if err != nil { + return report + } + content := string(raw) + for _, secret := range llm.ConfiguredSecrets(&cfg) { + content = strings.ReplaceAll(content, secret, "[REDACTED]") + encoded, _ := json.Marshal(secret) + content = strings.ReplaceAll(content, string(encoded[1:len(encoded)-1]), "[REDACTED]") + } + var safe reporting.ProcessReport + if json.Unmarshal([]byte(content), &safe) != nil { + return report + } + return safe +} + func runConfig(args []string, stdout, stderr io.Writer) int { if len(args) == 0 || isHelpCommand(args) || args[0] == "--help" || args[0] == "-h" { writeConfigUsage(stdout) @@ -514,6 +558,7 @@ func processReportInput(status string, inv processInvocation, runDir *diagnostic NormalizationSummary: normalizationSummary, ChunkingSummary: chunkingSummary, RunOutput: runOutput, + Backends: inv.Config.Backends, } } diff --git a/internal/core/diagnostics/artifacts.go b/internal/core/diagnostics/artifacts.go index 4946e8a..6b30bd9 100644 --- a/internal/core/diagnostics/artifacts.go +++ b/internal/core/diagnostics/artifacts.go @@ -13,9 +13,12 @@ const ( ArtifactNormalizationSummary = "normalization-summary.json" ArtifactChunkingSummary = "chunking-summary.json" ArtifactUtilizationSummary = "utilization-diagnostics.json" + ArtifactLLMExecution = "llm-execution.json" + ArtifactSelectedProfiles = "selected-profiles.yaml" + ArtifactConfigOrigins = "config-origins.yaml" ArtifactCorrectionLedger = "correction-ledger.json" ArtifactInvocationMetadata = "invocation.json" - ArtifactEffectiveConfig = "effective-config.yaml" + ArtifactEffectiveConfig = "effective-config.redacted.yaml" ArtifactReport = "report.json" ArtifactErrorLog = "error.log" ) @@ -29,6 +32,8 @@ func BuildDiagnosticsMetadata(runDirectoryPath string, runSucceeded bool) report NormalizationSummaryPath: filepath.Join(runDirectoryPath, ArtifactNormalizationSummary), ChunkingSummaryPath: filepath.Join(runDirectoryPath, ArtifactChunkingSummary), UtilizationSummaryPath: filepath.Join(runDirectoryPath, ArtifactUtilizationSummary), + LLMExecutionPath: filepath.Join(runDirectoryPath, ArtifactLLMExecution), + SelectedProfilesPath: filepath.Join(runDirectoryPath, ArtifactSelectedProfiles), CorrectionLedgerPath: filepath.Join(runDirectoryPath, ArtifactCorrectionLedger), InvocationMetadataPath: filepath.Join(runDirectoryPath, ArtifactInvocationMetadata), RedactedEffectiveConfigPath: filepath.Join(runDirectoryPath, ArtifactEffectiveConfig), diff --git a/internal/core/diagnostics/run_dir.go b/internal/core/diagnostics/run_dir.go index 34affed..73e6ff6 100644 --- a/internal/core/diagnostics/run_dir.go +++ b/internal/core/diagnostics/run_dir.go @@ -54,6 +54,7 @@ type InvocationMetadata struct { ReportJSONPath string `json:"report_json_path,omitempty"` ConfigPath string `json:"config_path,omitempty"` ConfigSource string `json:"config_source,omitempty"` + Overlay string `json:"overlay,omitempty"` ConfigVersion *int `json:"config_version,omitempty"` TranscriptDescription string `json:"transcript_description,omitempty"` Modules []string `json:"modules"` @@ -222,6 +223,13 @@ func (r *RunDirectory) WriteJSONArtifact(name string, payload any) error { return nil } +func (r *RunDirectory) WriteArtifact(name string, payload []byte) error { + if err := os.WriteFile(filepath.Join(r.path, name), payload, 0o644); err != nil { + return fmt.Errorf("failed to write %s: %w", name, err) + } + return nil +} + func (r *RunDirectory) ApplyRetention(input RetentionDecisionInput) error { decision := input if decision.RetentionMode == "" { diff --git a/internal/core/reporting/llm.go b/internal/core/reporting/llm.go new file mode 100644 index 0000000..9547518 --- /dev/null +++ b/internal/core/reporting/llm.go @@ -0,0 +1,58 @@ +package reporting + +// TokenMetric distinguishes measured zero from unavailable provider usage. +type TokenMetric struct { + Value int `json:"value"` + Known bool `json:"known"` + Complete bool `json:"complete"` +} + +type LLMUsage struct { + Prompt TokenMetric `json:"prompt"` + Completion TokenMetric `json:"completion"` + Total TokenMetric `json:"total"` + Cached TokenMetric `json:"cached"` + CacheWrite TokenMetric `json:"cache_write"` +} + +type LLMSummary struct { + LogicalCalls uint64 `json:"logical_calls"` + ProviderAttempts uint64 `json:"provider_attempts"` + TransientRetries uint64 `json:"transient_retries"` + StructuralRepairs uint64 `json:"structural_repairs"` + Usage LLMUsage `json:"usage"` +} + +type BackendUtilization struct { + Concurrency int `json:"concurrency"` + QueueCapacity int `json:"queue_capacity"` + LLMSummary + CapacityWaitMS int64 `json:"capacity_wait_ms"` + GenerationMS int64 `json:"generation_ms"` + RetryDelayMS int64 `json:"retry_delay_ms"` + LogicalWallMS int64 `json:"logical_wall_ms"` +} + +type UtilizationDiagnostics struct { + Backends map[string]BackendUtilization `json:"backends"` + RunWallTimeMS int64 `json:"run_wall_time_ms"` + Modules []ModuleUtilization `json:"modules,omitempty"` + Validators []ValidatorUtilization `json:"validators,omitempty"` +} + +type ModuleUtilization struct { + ModuleKey string `json:"module_key"` + ModuleInstance string `json:"module_instance"` + ProposalLLMCalls uint64 `json:"proposal_llm_calls"` + ValidationLLMCalls uint64 `json:"validation_llm_calls"` + ModuleWallTimeMS int64 `json:"module_wall_time_ms"` +} + +type ValidatorUtilization struct { + ModuleKey string `json:"module_key"` + ModuleInstance string `json:"module_instance"` + ValidatorKey string `json:"validator_key"` + LLMBacked bool `json:"llm_backed"` + Calls int `json:"calls"` + ElapsedMS int64 `json:"elapsed_ms"` +} diff --git a/internal/core/reporting/report.go b/internal/core/reporting/report.go index 86f1cd4..70d4199 100644 --- a/internal/core/reporting/report.go +++ b/internal/core/reporting/report.go @@ -30,13 +30,14 @@ type ProcessReport struct { NormalizationSkipped NormalizationSkipped `json:"normalization_skipped,omitempty"` Chunking *ChunkingSummary `json:"chunking,omitempty"` Diagnostics *DiagnosticsMetadata `json:"diagnostics,omitempty"` + LLMSummary *LLMSummary `json:"llm_summary,omitempty"` ModulesSummary *ModulesSummary `json:"modules_summary,omitempty"` ModuleResults []ModuleReport `json:"module_results,omitempty"` } const ( DefaultProcessReportSchemaName = "audita-process-report" - DefaultProcessReportSchemaVersion = "v1" + DefaultProcessReportSchemaVersion = "v2" ) type ReportMetadata struct { @@ -98,6 +99,8 @@ type DiagnosticsMetadata struct { NormalizationSummaryPath string `json:"normalization_summary_path,omitempty"` ChunkingSummaryPath string `json:"chunking_summary_path,omitempty"` UtilizationSummaryPath string `json:"utilization_summary_path,omitempty"` + LLMExecutionPath string `json:"llm_execution_path,omitempty"` + SelectedProfilesPath string `json:"selected_profiles_path,omitempty"` CorrectionLedgerPath string `json:"correction_ledger_path,omitempty"` InvocationMetadataPath string `json:"invocation_metadata_path,omitempty"` RedactedEffectiveConfigPath string `json:"redacted_effective_config_path,omitempty"` diff --git a/internal/framework/llm/adapter.go b/internal/framework/llm/adapter.go index dcba3f3..ddd0a51 100644 --- a/internal/framework/llm/adapter.go +++ b/internal/framework/llm/adapter.go @@ -41,6 +41,8 @@ func (c *RoleClient) CompleteStructured(parent context.Context, req structuredou defer cancel() record := structuredoutput.CallRecord{CallID: c.runtime.nextCallID.Add(1), Context: copyContext(req.Context), Started: time.Now().UTC()} record.Context.Role = c.role + profile := c.runtime.Profiles[c.role] + record.Prompt = structuredoutput.PromptMetadata{PromptID: req.PromptID, PromptVersion: req.PromptVersion, ProfileID: profile.ProfileID, BackendID: profile.EffectiveModelParams.BackendID, Model: profile.EffectiveModelParams.Model} if c.hooks.OnCall != nil { c.hooks.OnCall(record) } @@ -64,7 +66,6 @@ func (c *RoleClient) CompleteStructured(parent context.Context, req structuredou if !ok { return response, &structuredoutput.Failure{Kind: structuredoutput.FailureRuntime, Message: "unknown structured response schema", Cause: fmt.Errorf("schema %q", req.Schema)} } - profile := c.runtime.Profiles[c.role] backend := c.runtime.Config.Backends[profile.EffectiveModelParams.BackendID] vars := make(map[string]string, len(req.Variables)+1) for key, value := range req.Variables { @@ -94,6 +95,7 @@ func (c *RoleClient) CompleteStructured(parent context.Context, req structuredou defer handle.Discard() details := handle.Details() response.Prompt = promptMetadata(details) + record.Prompt = response.Prompt response.Model = details.EffectiveModelParams.Model response.Prepared = preparedSnapshot(details) record.Prepared = response.Prepared diff --git a/internal/framework/llm/observations.go b/internal/framework/llm/observations.go index f24ea3a..e9ebaa4 100644 --- a/internal/framework/llm/observations.go +++ b/internal/framework/llm/observations.go @@ -55,6 +55,7 @@ type ExecutionObservation struct { type LogicalCall struct { CallID uint64 `json:"call_id"` Context structuredoutput.DiagnosticContext `json:"context"` + Prompt structuredoutput.PromptMetadata `json:"prompt"` Started time.Time `json:"started"` Finished time.Time `json:"finished,omitempty"` WallDuration time.Duration `json:"wall_duration_ns"` @@ -108,7 +109,7 @@ func (c *ObservationCollector) recordCall(record structuredoutput.CallRecord) { } c.mu.Lock() defer c.mu.Unlock() - call := LogicalCall{CallID: record.CallID, Context: copyContext(record.Context), Started: record.Started, Finished: record.Finished, Failure: record.Failure} + call := LogicalCall{CallID: record.CallID, Context: copyContext(record.Context), Prompt: record.Prompt, Started: record.Started, Finished: record.Finished, Failure: record.Failure} if !record.Finished.IsZero() { call.WallDuration = record.Finished.Sub(record.Started) } diff --git a/internal/framework/processreport/llm.go b/internal/framework/processreport/llm.go new file mode 100644 index 0000000..746e1b8 --- /dev/null +++ b/internal/framework/processreport/llm.go @@ -0,0 +1,183 @@ +package processreport + +import ( + "time" + + "gitea.maximumdirect.net/eric/audita/internal/core/config" + "gitea.maximumdirect.net/eric/audita/internal/core/reporting" + "gitea.maximumdirect.net/eric/audita/internal/framework/llm" + "gitea.maximumdirect.net/eric/audita/internal/framework/runner" + "gitea.maximumdirect.net/eric/audita/internal/framework/structuredoutput" + pk "gitea.maximumdirect.net/eric/promptkit" +) + +func mapLLMSummary(source llm.ExecutionSummary) reporting.LLMSummary { + metric := func(value llm.TokenCount) reporting.TokenMetric { + return reporting.TokenMetric{Value: value.Value, Known: value.Known, Complete: value.Complete} + } + return reporting.LLMSummary{ + LogicalCalls: source.LogicalCalls, ProviderAttempts: source.ProviderAttempts, + TransientRetries: source.TransientRetries, StructuralRepairs: source.StructuralRepairs, + Usage: reporting.LLMUsage{Prompt: metric(source.Usage.Prompt), Completion: metric(source.Usage.Completion), Total: metric(source.Usage.Total), Cached: metric(source.Usage.Cached), CacheWrite: metric(source.Usage.CacheWrite)}, + } +} + +// BuildUtilization groups complete logical calls by their selected backend. +func BuildUtilization(output *runner.RunOutput, backends map[string]config.Backend) reporting.UtilizationDiagnostics { + result := reporting.UtilizationDiagnostics{Backends: make(map[string]reporting.BackendUtilization, len(backends))} + if output == nil { + return result + } + result.RunWallTimeMS = output.RunWallTimeMS + for id, backend := range backends { + group := llm.ObservationSnapshot{} + for _, call := range output.Observations.Calls { + if call.Prompt.BackendID == id { + group.Calls = append(group.Calls, call) + addModuleCall(&result, call) + } + } + var wait, generation, retry, wall time.Duration + for _, call := range group.Calls { + wall += call.WallDuration + } + for _, event := range output.Observations.Events { + if hasCall(group.Calls, event.CallID) { + group.Events = append(group.Events, event) + if event.Kind == string(pk.ExecutionFinished) { + wait += event.CapacityWait + generation += event.GenerationDuration + retry += event.RetryDelay + } + } + } + result.Backends[id] = reporting.BackendUtilization{ + Concurrency: backend.Concurrency, QueueCapacity: backend.QueueCapacity, + LLMSummary: mapLLMSummary(llm.Summarize(group)), + CapacityWaitMS: wait.Milliseconds(), GenerationMS: generation.Milliseconds(), + RetryDelayMS: retry.Milliseconds(), LogicalWallMS: wall.Milliseconds(), + } + } + for _, module := range output.ModuleResults { + found := false + for i := range result.Modules { + if result.Modules[i].ModuleInstance == module.ModuleInstance { + result.Modules[i].ModuleWallTimeMS = module.CompletedAt.Sub(module.StartedAt).Milliseconds() + found = true + break + } + } + if !found { + result.Modules = append(result.Modules, reporting.ModuleUtilization{ModuleKey: module.ModuleKey, ModuleInstance: module.ModuleInstance, ModuleWallTimeMS: module.CompletedAt.Sub(module.StartedAt).Milliseconds()}) + } + } + for _, timing := range output.ValidatorTimings { + result.Validators = append(result.Validators, reporting.ValidatorUtilization{ModuleKey: timing.ModuleKey, ModuleInstance: timing.ModuleInstance, ValidatorKey: timing.ValidatorName, LLMBacked: timing.LLMBacked, Calls: timing.Calls, ElapsedMS: timing.ElapsedMS}) + } + return result +} + +func hasCall(calls []llm.LogicalCall, id uint64) bool { + for _, call := range calls { + if call.CallID == id { + return true + } + } + return false +} + +func addModuleCall(result *reporting.UtilizationDiagnostics, call llm.LogicalCall) { + if call.Context.ModuleInstance == "" { + return + } + for i := range result.Modules { + if result.Modules[i].ModuleInstance == call.Context.ModuleInstance { + if call.Context.Role == "proposal" { + result.Modules[i].ProposalLLMCalls++ + } else if call.Context.Role == "validation" { + result.Modules[i].ValidationLLMCalls++ + } + return + } + } + module := reporting.ModuleUtilization{ModuleKey: call.Context.ModuleKey, ModuleInstance: call.Context.ModuleInstance} + if call.Context.Role == "proposal" { + module.ProposalLLMCalls++ + } else if call.Context.Role == "validation" { + module.ValidationLLMCalls++ + } + result.Modules = append(result.Modules, module) +} + +type executionCall struct { + CallID uint64 `json:"call_id"` + Context structuredoutput.DiagnosticContext `json:"context"` + Prompt structuredoutput.PromptMetadata `json:"prompt"` + Started time.Time `json:"started"` + Finished *time.Time `json:"finished,omitempty"` + ElapsedMS int64 `json:"elapsed_ms"` + Failure structuredoutput.FailureKind `json:"failure,omitempty"` + Summary reporting.LLMSummary `json:"summary"` +} + +type executionEvent struct { + CallID uint64 `json:"call_id"` + Context structuredoutput.DiagnosticContext `json:"context"` + Kind string `json:"kind"` + RunID string `json:"run_id,omitempty"` + Time time.Time `json:"time"` + BackendID string `json:"backend_id,omitempty"` + ProfileID string `json:"profile_id,omitempty"` + Model string `json:"model,omitempty"` + Generation *uint64 `json:"generation,omitempty"` + Attempt *uint64 `json:"attempt,omitempty"` + Dispatched bool `json:"dispatched"` + CapacityWaitMS int64 `json:"capacity_wait_ms"` + GenerationMS int64 `json:"generation_ms"` + RetryDelayMS int64 `json:"retry_delay_ms"` + DurationMS int64 `json:"duration_ms"` + Outcome string `json:"outcome,omitempty"` + Failure string `json:"failure,omitempty"` + StatusCode int `json:"status_code,omitempty"` + RetriesExhausted bool `json:"retries_exhausted,omitempty"` + Attempts uint64 `json:"attempts"` + TransientRetries uint64 `json:"transient_retries"` + StructuralRepairs uint64 `json:"structural_repairs"` + Usage reporting.LLMUsage `json:"usage"` +} + +// BuildLLMExecution serializes only safe observation fields and millisecond durations. +func BuildLLMExecution(snapshot llm.ObservationSnapshot) any { + calls := make([]executionCall, 0, len(snapshot.Calls)) + events := make([]executionEvent, 0, len(snapshot.Events)) + for _, call := range snapshot.Calls { + group := llm.ObservationSnapshot{Calls: []llm.LogicalCall{call}} + for _, event := range snapshot.Events { + if event.CallID == call.CallID { + group.Events = append(group.Events, event) + } + } + var finished *time.Time + if !call.Finished.IsZero() { + value := call.Finished + finished = &value + } + calls = append(calls, executionCall{CallID: call.CallID, Context: call.Context, Prompt: call.Prompt, Started: call.Started, Finished: finished, ElapsedMS: call.WallDuration.Milliseconds(), Failure: call.Failure, Summary: mapLLMSummary(llm.Summarize(group))}) + } + for _, event := range snapshot.Events { + var generation, attempt *uint64 + if event.Generation != 0 { + value := event.Generation + generation = &value + } + if event.Attempt != 0 { + value := event.Attempt + attempt = &value + } + events = append(events, executionEvent{CallID: event.CallID, Context: event.Context, Kind: event.Kind, RunID: event.RunID, Time: event.Time, BackendID: event.BackendID, ProfileID: event.ProfileID, Model: event.Model, Generation: generation, Attempt: attempt, Dispatched: event.Dispatched, CapacityWaitMS: event.CapacityWait.Milliseconds(), GenerationMS: event.GenerationDuration.Milliseconds(), RetryDelayMS: event.RetryDelay.Milliseconds(), DurationMS: event.Duration.Milliseconds(), Outcome: event.Outcome, Failure: event.Failure, StatusCode: event.StatusCode, RetriesExhausted: event.RetriesExhausted, Attempts: event.Attempts, TransientRetries: event.TransientRetries, StructuralRepairs: event.StructuralRepairs, Usage: mapLLMSummary(llm.ExecutionSummary{Usage: event.Usage}).Usage}) + } + return struct { + Calls []executionCall `json:"calls"` + Events []executionEvent `json:"events"` + }{calls, events} +} diff --git a/internal/framework/processreport/llm_test.go b/internal/framework/processreport/llm_test.go new file mode 100644 index 0000000..c710d74 --- /dev/null +++ b/internal/framework/processreport/llm_test.go @@ -0,0 +1,56 @@ +package processreport + +import ( + "encoding/json" + "strings" + "testing" + "time" + + "gitea.maximumdirect.net/eric/audita/internal/core/config" + "gitea.maximumdirect.net/eric/audita/internal/framework/llm" + "gitea.maximumdirect.net/eric/audita/internal/framework/runner" + "gitea.maximumdirect.net/eric/audita/internal/framework/structuredoutput" + pk "gitea.maximumdirect.net/eric/promptkit" +) + +func TestExecutionReportingGroupsPredispatchFailureAndKeepsSafeMilliseconds(t *testing.T) { + start := time.Now().UTC() + snapshot := llm.ObservationSnapshot{ + Calls: []llm.LogicalCall{ + {CallID: 1, Context: structuredoutput.DiagnosticContext{Role: "proposal", ModuleInstance: "grammar-1"}, Prompt: structuredoutput.PromptMetadata{BackendID: "primary", ProfileID: "draft", Model: "m"}, Started: start, Finished: start.Add(1500 * time.Millisecond), WallDuration: 1500 * time.Millisecond}, + {CallID: 2, Context: structuredoutput.DiagnosticContext{Role: "validation"}, Prompt: structuredoutput.PromptMetadata{BackendID: "secondary"}, Started: start, Finished: start.Add(5 * time.Millisecond), WallDuration: 5 * time.Millisecond, Failure: structuredoutput.FailureRuntime}, + }, + Events: []llm.ExecutionObservation{{CallID: 1, Kind: string(pk.ExecutionFinished), BackendID: "primary", Attempts: 2, TransientRetries: 1, CapacityWait: 20 * time.Millisecond, GenerationDuration: 500 * time.Millisecond, RetryDelay: 100 * time.Millisecond}}, + } + output := &runner.RunOutput{Observations: snapshot, ObservationsAvailable: true, LLMSummary: llm.Summarize(snapshot)} + utilization := BuildUtilization(output, map[string]config.Backend{"primary": {Concurrency: 2, QueueCapacity: 3}, "secondary": {Concurrency: 1}}) + if utilization.Backends["primary"].LogicalCalls != 1 || utilization.Backends["primary"].ProviderAttempts != 2 || utilization.Backends["primary"].CapacityWaitMS != 20 || utilization.Backends["primary"].LogicalWallMS != 1500 { + t.Fatalf("primary backend: %+v", utilization.Backends["primary"]) + } + if utilization.Backends["secondary"].LogicalCalls != 1 || utilization.Backends["secondary"].ProviderAttempts != 0 || !utilization.Backends["secondary"].Usage.Total.Known { + t.Fatalf("predispatch backend: %+v", utilization.Backends["secondary"]) + } + raw, err := json.Marshal(BuildLLMExecution(snapshot)) + if err != nil { + t.Fatal(err) + } + serialized := string(raw) + if !strings.Contains(serialized, `"elapsed_ms":1500`) || !strings.Contains(serialized, `"generation_ms":500`) || strings.Contains(serialized, "_ns") || strings.Contains(serialized, `"attempt":0`) || strings.Contains(serialized, `"section_index":0`) { + t.Fatalf("execution serialization: %s", serialized) + } + if !strings.Contains(serialized, `"calls"`) || !strings.Contains(serialized, `"events"`) { + t.Fatal(serialized) + } +} + +func TestReportSummaryAvailability(t *testing.T) { + input := BuildInput{Status: "failed", StartedAt: time.Now(), CompletedAt: time.Now()} + if got := Build(input).LLMSummary; got != nil { + t.Fatalf("unavailable summary: %+v", got) + } + input.RunOutput = &runner.RunOutput{ObservationsAvailable: true, LLMSummary: llm.Summarize(llm.ObservationSnapshot{})} + got := Build(input).LLMSummary + if got == nil || got.LogicalCalls != 0 || !got.Usage.Total.Known || !got.Usage.Total.Complete { + t.Fatalf("initialized empty summary: %+v", got) + } +} diff --git a/internal/framework/processreport/report.go b/internal/framework/processreport/report.go index 44fbef5..aed4511 100644 --- a/internal/framework/processreport/report.go +++ b/internal/framework/processreport/report.go @@ -4,6 +4,7 @@ import ( "time" "gitea.maximumdirect.net/eric/audita/internal/core/chunking" + "gitea.maximumdirect.net/eric/audita/internal/core/config" "gitea.maximumdirect.net/eric/audita/internal/core/diagnostics" "gitea.maximumdirect.net/eric/audita/internal/core/normalization" "gitea.maximumdirect.net/eric/audita/internal/core/reporting" @@ -28,6 +29,7 @@ type BuildInput struct { NormalizationSummary *normalization.NormalizationSummary ChunkingSummary *chunking.Summary RunOutput *runner.RunOutput + Backends map[string]config.Backend } // Build creates the public process report without owning command parsing or config loading. @@ -80,6 +82,10 @@ func Build(input BuildInput) reporting.ProcessReport { } } report.ModulesSummary, report.ModuleResults = buildModuleReporting(input.RunOutput) + if input.RunOutput != nil && input.RunOutput.ObservationsAvailable { + summary := mapLLMSummary(input.RunOutput.LLMSummary) + report.LLMSummary = &summary + } return report } diff --git a/internal/framework/runner/runner.go b/internal/framework/runner/runner.go index 4bcbd3e..7308f17 100644 --- a/internal/framework/runner/runner.go +++ b/internal/framework/runner/runner.go @@ -87,12 +87,13 @@ type RunInput struct { // RunOutput is the deterministic runner output. type RunOutput struct { - FinalTranscript *schema.Transcript `json:"-"` - ModuleResults []ModuleResult `json:"module_results"` - Observations llm.ObservationSnapshot `json:"-"` - LLMSummary llm.ExecutionSummary `json:"-"` - RunWallTimeMS int64 `json:"-"` - ValidatorTimings []ValidatorTiming `json:"-"` + FinalTranscript *schema.Transcript `json:"-"` + ModuleResults []ModuleResult `json:"module_results"` + Observations llm.ObservationSnapshot `json:"-"` + ObservationsAvailable bool `json:"-"` + LLMSummary llm.ExecutionSummary `json:"-"` + RunWallTimeMS int64 `json:"-"` + ValidatorTimings []ValidatorTiming `json:"-"` } func New(factory ModuleFactory) *Runner { diff --git a/internal/framework/structuredoutput/call.go b/internal/framework/structuredoutput/call.go index c6dfbc1..f1ad3ef 100644 --- a/internal/framework/structuredoutput/call.go +++ b/internal/framework/structuredoutput/call.go @@ -68,6 +68,7 @@ type Message struct { type CallRecord struct { CallID uint64 `json:"call_id"` Context DiagnosticContext `json:"context"` + Prompt PromptMetadata `json:"prompt"` Started time.Time `json:"started"` Finished time.Time `json:"finished,omitempty"` Prepared *PreparedSnapshot `json:"prepared,omitempty"`