Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
@@ -0,0 +1,67 @@
# ADR-43410: Logs Summary — Backfill Precedence Rule and Lazy Cache Healing

**Date**: 2026-07-05
**Status**: Draft
**Deciders**: Unknown (automated fix by copilot-swe-agent, pelikhan)

---

### Context

The `logs` tool builds a summary for each workflow run that includes `total_turns` and `total_safe_items`. These values can come from two sources:

1. **Log-derived metrics** (`result.Metrics.Turns`) — extracted from `events.jsonl` or `.log` files when full log artifacts are downloaded.
2. **Backfilled values** (`applyUsageActivitySummaryToResult`) — read from `usage/activity/summary.json`, which is always present even when full log artifacts are not downloaded (usage-only mode).

Two bugs caused these summary fields to always report `0`:

- **Bug 1 (orchestrator)**: The orchestrator unconditionally assigned `run.Turns = result.Metrics.Turns`. For usage-only downloads (no `events.jsonl`/`.log` files), `result.Metrics.Turns` is always `0`, discarding the backfilled value.
- **Bug 2 (cache-hit path)**: The cache-hit path returned cached `run_summary.json` as-is. Cache entries written before the backfill feature was introduced (no schema invalidation exists) kept `Turns` and `SafeItemsCount` at `0` indefinitely.

### Decision

We will apply two complementary rules:

1. **Backfill-wins-when-metrics-is-zero**: In the orchestrator, only overwrite `run.Turns` with `result.Metrics.Turns` when that value is greater than zero. This preserves any backfilled value for usage-only artifact downloads while still preferring the more precise log-derived count when full logs are available.

2. **Lazy cache healing on zero**: In the cache-hit path, if either `Turns` or `SafeItemsCount` is zero in the cached result, re-apply `applyUsageActivitySummaryToResult` from the on-disk `usage/activity/summary.json`. Because `applyUsageActivitySummaryToResult` is a no-op when values are already non-zero, this is safe to call unconditionally and self-heals stale cache entries without requiring a re-download or explicit cache invalidation.

### Alternatives Considered

#### Alternative 1: Always Prefer Backfilled Values

Never overwrite `run.Turns` with `result.Metrics.Turns`; treat log-derived metrics as supplementary only. This would fix Bug 1 but would lose precision: for runs with full log artifacts, `events.jsonl` counts turns at a finer granularity than `session.turns` in the activity summary.

Not chosen because it degrades accuracy for the common case where full log artifacts are present.

#### Alternative 2: Version-Based Cache Invalidation

Embed a backfill schema version in `run_summary.json` and invalidate the cache whenever the version changes. This would fix Bug 2 cleanly and avoid the I/O cost of conditionally re-reading the activity summary.

Not chosen because it requires a versioning/invalidation infrastructure that does not currently exist in the cache layer, and would force re-downloads rather than self-healing existing entries.

#### Alternative 3: Backfill in `extractLogMetrics` Fallback

When `extractLogMetrics` returns `Turns == 0`, fall back to reading the activity summary within the metrics-extraction step so that `result.Metrics.Turns` is always non-zero.

Not chosen because it would couple the log-metrics extraction path to the usage-activity backfill, blurring the separation of concerns between log parsing and usage-summary reading. It also does not address Bug 2.

### Consequences

#### Positive
- `total_turns` and `total_safe_items` now correctly reflect non-zero values from `usage/activity/summary.json` for usage-only artifact downloads.
- Stale cache entries self-heal on the next `logs` invocation without requiring cache deletion or a full re-download.
- Log-derived turn counts retain priority over backfilled values when full log artifacts are present, preserving accuracy.
- Five new unit tests codify the precedence rule and cache-healing behavior as executable contracts.

#### Negative
- The cache-hit path now incurs a conditional file read (`loadUsageActivitySummary`) for any cache entry where `Turns` or `SafeItemsCount` is zero, adding a small I/O cost per affected run.
- If a run genuinely has zero turns and zero safe items (e.g., an aborted run with no activity), the guard condition fires on every cache hit, reading a summary that changes nothing — a small wasted I/O.

#### Neutral
- The backfill function `applyUsageActivitySummaryToResult` must remain idempotent (no-op for non-zero values) for the lazy-healing approach to be safe; this invariant is now load-bearing.
- No cache format or schema version change is introduced; old cache entries are healed in place rather than invalidated.

---

*ADR created by [adr-writer agent]. Review and finalize before changing status from Draft to Accepted.*
14 changes: 12 additions & 2 deletions pkg/cli/logs_orchestrator.go
Original file line number Diff line number Diff line change
Expand Up @@ -39,6 +39,16 @@ func isDeadlineExceeded(ctx context.Context) bool {
return errors.Is(ctx.Err(), context.DeadlineExceeded)
}

// applyMetricsTurnsToRun sets run.Turns from metrics when a log-derived count is
// available. It deliberately does NOT overwrite when metrics.Turns is zero so that
// a backfilled value from applyUsageActivitySummaryToResult (session.turns) is
// preserved for usage-only artifact downloads where events.jsonl/.log are absent.
func applyMetricsTurnsToRun(run *WorkflowRun, metrics LogMetrics) {
if metrics.Turns > 0 {
run.Turns = metrics.Turns
}
}

// noRunsMessage returns a human-readable explanation for why zero workflow runs
// were returned. It inspects the startDate filter and the timeoutReached flag
// so callers receive actionable guidance instead of a silent empty result.
Expand Down Expand Up @@ -578,7 +588,7 @@ outerLoop:
// Update run with metrics and path
run := result.Run
run.TokenUsage = result.Metrics.TokenUsage
run.Turns = result.Metrics.Turns
applyMetricsTurnsToRun(&run, result.Metrics)
run.AvgTimeBetweenTurns = result.Metrics.AvgTimeBetweenTurns
run.ErrorCount = 0
run.WarningCount = 0
Expand Down Expand Up @@ -1166,7 +1176,7 @@ func DownloadWorkflowLogsFromStdin(ctx context.Context, opts StdinLogsOptions) e

run := result.Run
run.TokenUsage = result.Metrics.TokenUsage
run.Turns = result.Metrics.Turns
applyMetricsTurnsToRun(&run, result.Metrics)
run.AvgTimeBetweenTurns = result.Metrics.AvgTimeBetweenTurns
run.ErrorCount = 0
run.WarningCount = 0
Expand Down
19 changes: 19 additions & 0 deletions pkg/cli/logs_run_processor.go
Original file line number Diff line number Diff line change
Expand Up @@ -134,6 +134,8 @@ func downloadRunArtifactsConcurrent(ctx context.Context, runs []WorkflowRun, out
LogsPath: runOutputDir,
Cached: true, // Mark as cached
}
// Re-apply the usage activity backfill to heal stale cache entries.
backfillCacheHitIfNeeded(&result, runOutputDir, verbose)
// Update progress counter
completed := completedCount.Add(1)
if progressBar != nil {
Expand Down Expand Up @@ -460,6 +462,23 @@ func downloadRunArtifactsConcurrent(ctx context.Context, runs []WorkflowRun, out
return results
}

// backfillCacheHitIfNeeded re-applies the usage activity summary backfill to heal
// stale cache entries that were saved before safe-outputs or turn backfill was
// introduced. It is a no-op when both Run.Turns and Run.SafeItemsCount are already
// non-zero. Errors loading the summary are logged when verbose is true; a missing
// summary file is silent (no summary = nothing to backfill).
func backfillCacheHitIfNeeded(result *DownloadResult, runOutputDir string, verbose bool) {
if result.Run.Turns == 0 || result.Run.SafeItemsCount == 0 {
usageActivitySummary, err := loadUsageActivitySummary(runOutputDir)
if err != nil && verbose {
logsOrchestratorLog.Printf("Warning: failed to load usage activity summary for cache-hit backfill (run %d): %v", result.Run.DatabaseID, err)
}
if usageActivitySummary != nil {
applyUsageActivitySummaryToResult(usageActivitySummary, result, true)
}
}
}

// runContainsSafeOutputType checks if a run's agent_output.json contains a specific safe output type
func runContainsSafeOutputType(runDir string, safeOutputType string, verbose bool) (bool, error) {
logsOrchestratorLog.Printf("Checking run for safe output type: dir=%s, type=%s", runDir, safeOutputType)
Expand Down
157 changes: 157 additions & 0 deletions pkg/cli/logs_usage_activity_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -337,3 +337,160 @@ func TestExtractThenApplyProcessorOrderingBackfillsSafeItemsCount(t *testing.T)

assert.Equal(t, 5, result.Run.SafeItemsCount, "SafeItemsCount should be backfilled from summary when no manifest is present")
}

// TestCacheHitBackfillsStaleZeroSafeItemsCount verifies that backfillCacheHitIfNeeded
// re-applies the usage activity backfill when SafeItemsCount is zero in the cached
// run_summary.json. This covers stale cache entries that were saved before the
// safe-outputs backfill was introduced.
func TestCacheHitBackfillsStaleZeroSafeItemsCount(t *testing.T) {
t.Parallel()

runDir := t.TempDir()

// Write an activity summary with safe_outputs populated.
summaryPath := filepath.Join(runDir, "usage", "activity", "summary.json")
require.NoError(t, os.MkdirAll(filepath.Dir(summaryPath), 0o755))
require.NoError(t, os.WriteFile(summaryPath, []byte(`{
"schema":"`+usageActivitySummarySchema+`",
"safe_outputs":{"total_items":4,"items_by_type":{"create_issue":4}}
}`), 0o644))

// Simulate a stale cache: SafeItemsCount is 0 (saved before backfill existed).
result := DownloadResult{Run: WorkflowRun{SafeItemsCount: 0}}

backfillCacheHitIfNeeded(&result, runDir, false)

assert.Equal(t, 4, result.Run.SafeItemsCount, "cache-hit backfill should heal stale SafeItemsCount=0 from activity summary")
}

// TestCacheHitBackfillsStaleZeroTurns verifies that backfillCacheHitIfNeeded correctly
// re-applies the usage activity backfill when Turns is zero in the cached
// run_summary.json. This covers stale cache entries where the session.turns
// backfill had not yet run.
func TestCacheHitBackfillsStaleZeroTurns(t *testing.T) {
t.Parallel()

runDir := t.TempDir()

// Write an activity summary with a session turns count.
summaryPath := filepath.Join(runDir, "usage", "activity", "summary.json")
require.NoError(t, os.MkdirAll(filepath.Dir(summaryPath), 0o755))
require.NoError(t, os.WriteFile(summaryPath, []byte(`{
"schema":"`+usageActivitySummarySchema+`",
"session":{"turns":34}
}`), 0o644))

// Simulate a stale cache: Turns is 0 (saved before turns backfill existed).
result := DownloadResult{Run: WorkflowRun{Turns: 0}}

backfillCacheHitIfNeeded(&result, runDir, false)

assert.Equal(t, 34, result.Run.Turns, "cache-hit backfill should heal stale Turns=0 from activity summary")
}

// TestCacheHitDoesNotOverwriteNonZeroValues verifies that backfillCacheHitIfNeeded
// is a no-op when both Run.Turns and Run.SafeItemsCount are already non-zero.
func TestCacheHitDoesNotOverwriteNonZeroValues(t *testing.T) {
t.Parallel()

runDir := t.TempDir()

// Write an activity summary with different values than what is in the cache.
summaryPath := filepath.Join(runDir, "usage", "activity", "summary.json")
require.NoError(t, os.MkdirAll(filepath.Dir(summaryPath), 0o755))
require.NoError(t, os.WriteFile(summaryPath, []byte(`{
"schema":"`+usageActivitySummarySchema+`",
"session":{"turns":99},
"safe_outputs":{"total_items":99}
}`), 0o644))

// Cache has non-zero values — the backfill guard should be a no-op.
result := DownloadResult{Run: WorkflowRun{Turns: 14, SafeItemsCount: 5}}

backfillCacheHitIfNeeded(&result, runDir, false)

// Guard condition is false (both >0), so neither value should change.
assert.Equal(t, 14, result.Run.Turns, "non-zero cached Turns must not be overwritten by the cache-hit backfill guard")

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[/tdd] TestCacheHitDoesNotOverwriteNonZeroValues doesn't exercise the case where only one of the two fields is zero — the guard uses ||, so this partial-zero scenario is the critical path.\n\n

\n💡 Missing test case\n\nAdd two sub-cases:\n\n1. Turns=0, SafeItemsCount=5 — guard triggers; only Turns gets backfilled, SafeItemsCount stays 5\n2. Turns=14, SafeItemsCount=0 — guard triggers; only SafeItemsCount gets backfilled, Turns stays 14\n\nThese cover the || semantics and would catch a regression if the guard were changed to &&.\n\n
\n\n@copilot please address this.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Added TestCacheHitBackfillsPartialZeroTurns and TestCacheHitBackfillsPartialZeroSafeItemsCount in the latest commit to cover both partial-zero branches of the || guard. Each test verifies that only the zero field gets backfilled while the non-zero field remains unchanged.

assert.Equal(t, 5, result.Run.SafeItemsCount, "non-zero cached SafeItemsCount must not be overwritten by the cache-hit backfill guard")
}

// TestCacheHitBackfillsPartialZeroTurns verifies that backfillCacheHitIfNeeded
// triggers on the || condition when only Turns is zero, backfills Turns from the
// activity summary, and leaves the non-zero SafeItemsCount untouched.
func TestCacheHitBackfillsPartialZeroTurns(t *testing.T) {
t.Parallel()

runDir := t.TempDir()

summaryPath := filepath.Join(runDir, "usage", "activity", "summary.json")
require.NoError(t, os.MkdirAll(filepath.Dir(summaryPath), 0o755))
require.NoError(t, os.WriteFile(summaryPath, []byte(`{
"schema":"`+usageActivitySummarySchema+`",
"session":{"turns":34},
"safe_outputs":{"total_items":99}
}`), 0o644))

// Turns=0 triggers the guard; SafeItemsCount=5 is already non-zero.
result := DownloadResult{Run: WorkflowRun{Turns: 0, SafeItemsCount: 5}}

backfillCacheHitIfNeeded(&result, runDir, false)

assert.Equal(t, 34, result.Run.Turns, "stale Turns=0 must be backfilled when SafeItemsCount is non-zero")
assert.Equal(t, 5, result.Run.SafeItemsCount, "non-zero SafeItemsCount must not be overwritten when only Turns triggers the guard")
}

// TestCacheHitBackfillsPartialZeroSafeItemsCount verifies that backfillCacheHitIfNeeded
// triggers on the || condition when only SafeItemsCount is zero, backfills SafeItemsCount
// from the activity summary, and leaves the non-zero Turns untouched.
func TestCacheHitBackfillsPartialZeroSafeItemsCount(t *testing.T) {
t.Parallel()

runDir := t.TempDir()

summaryPath := filepath.Join(runDir, "usage", "activity", "summary.json")
require.NoError(t, os.MkdirAll(filepath.Dir(summaryPath), 0o755))
require.NoError(t, os.WriteFile(summaryPath, []byte(`{
"schema":"`+usageActivitySummarySchema+`",
"session":{"turns":99},
"safe_outputs":{"total_items":4}
}`), 0o644))

// SafeItemsCount=0 triggers the guard; Turns=14 is already non-zero.
result := DownloadResult{Run: WorkflowRun{Turns: 14, SafeItemsCount: 0}}

backfillCacheHitIfNeeded(&result, runDir, false)

assert.Equal(t, 14, result.Run.Turns, "non-zero Turns must not be overwritten when only SafeItemsCount triggers the guard")
assert.Equal(t, 4, result.Run.SafeItemsCount, "stale SafeItemsCount=0 must be backfilled when Turns is non-zero")
}

// TestMetricsTurnsZeroDoesNotOverwriteBackfilledTurns verifies that
// applyMetricsTurnsToRun preserves backfilled run.Turns when metrics.Turns is 0.
// This is the case for usage-only artifact downloads where no events.jsonl/.log
// files exist, so extractLogMetrics returns Turns=0.
func TestMetricsTurnsZeroDoesNotOverwriteBackfilledTurns(t *testing.T) {
t.Parallel()

// Simulate a result where the backfill set Run.Turns=34 but Metrics.Turns=0
// because only the usage artifact was downloaded (no log files).
run := WorkflowRun{Turns: 34}
metrics := LogMetrics{Turns: 0}

applyMetricsTurnsToRun(&run, metrics)

assert.Equal(t, 34, run.Turns, "backfilled Turns must be preserved when Metrics.Turns is 0 (usage-only download)")
}

// TestMetricsTurnsNonZeroOverridesBackfilledTurns verifies that when full log
// artifacts are present (Metrics.Turns > 0), applyMetricsTurnsToRun uses the more
// precise log-derived count over the backfilled session.turns value.
func TestMetricsTurnsNonZeroOverridesBackfilledTurns(t *testing.T) {
t.Parallel()

run := WorkflowRun{Turns: 34} // backfilled from session.turns
metrics := LogMetrics{Turns: 36} // from events.jsonl (more precise)

applyMetricsTurnsToRun(&run, metrics)

assert.Equal(t, 36, run.Turns, "log-derived Metrics.Turns must override backfilled value when non-zero")
}
Loading