logs: track per-run download duration/size and render end-of-run stats summary

docs/adr/60951-track-gh-aw-logs-download-telemetry.md

@@ -0,0 +1,46 @@
+# ADR-60951: Track gh aw logs download telemetry
+
+**Date**: 2026-09-15
+**Status**: Draft
+**Deciders**: gh-aw maintainers
+
+---
+
+### Context
+
+This pull request changes the `gh aw logs` pipeline to capture artifact download duration and downloaded size for each workflow run, persist those values into cached JSONL/log schemas, and print an end-of-run download summary across single-target, multi-target, and stdin-driven entry points. The PR description explains that the command previously did not show how long artifact downloads took or how much data they transferred, which made slow runs and GitHub API usage harder to diagnose. The implementation also derives an approximate per-run GitHub API cost from existing rate-limit reports rather than introducing a separate telemetry source. The architectural question is whether `gh aw logs` should treat download-performance telemetry as first-class run metadata and surface it consistently through its reporting and cache formats.
+
+### Decision
+
+We will record per-run artifact download duration and artifact size inside the `gh aw logs` workflow-run model, propagate those fields into persisted `RunData`/schema outputs, and render an aggregate end-of-run summary for real downloads. We will measure download duration around the existing artifact-download path, compute size from the downloaded artifact directory, and exclude cache hits from the aggregate timing and size metrics so the summary reflects actual transfer work performed during the invocation. We will also estimate GitHub API cost per downloaded run from existing rate-limit snapshots instead of adding a new API accounting mechanism. We chose this because the PR evidence shows the main problem is lack of visibility into download cost, and extending the current logs/reporting pipeline solves that with minimal new architecture.
+
+### Alternatives Considered
+
+#### Alternative 1: Keep download telemetry out of the run model and rely on ad hoc debug logging
+
+The team could have added temporary or verbose-only log lines around artifact downloads without changing `WorkflowRun`, `RunData`, or the JSON schemas. This was considered because it would be a smaller code change and avoid widening cached output contracts. It was not chosen because the PR explicitly updates cached JSONL persistence and schemas, indicating the telemetry needs to survive beyond a single terminal session and be available for downstream analysis.
+
+#### Alternative 2: Report only aggregate command-level download timing
+
+Another option was to compute one total download duration and size for the full command without attaching telemetry to each run. This was considered because it would still improve operator visibility while avoiding new per-run fields. It was not chosen because the PR adds `DownloadDuration` and `DownloadSizeBytes` directly to `WorkflowRun` and `RunData`, showing the intended design is per-run observability that can be aggregated later and reused from cache.
+
+### Consequences
+
+#### Positive
+- `gh aw logs` gains concrete visibility into artifact transfer cost, making slow or heavy runs easier to diagnose.
+- The telemetry is available both in terminal summaries and persisted JSON/JSONL outputs, enabling later analysis and cache round-tripping.
+- Reusing existing rate-limit snapshots provides a lightweight API-cost estimate without introducing a separate tracking subsystem.
+
+#### Negative
+- The run/report model and published schemas gain additional fields that maintainers must preserve or evolve carefully.
+- Size measurement adds extra filesystem work after downloads and may produce partial observability when directory sizing fails.
+- The API cost figure is only an estimate and can understate true usage during rate-limit window resets.
+
+#### Neutral
+- Cache hits continue to produce zero download metrics and are intentionally excluded from aggregate download summaries.
+- The implementation factors artifact downloading into a helper function to isolate timing and sizing behavior from the rest of run processing.
+- All three logs entry points now call the same end-of-run summary renderer, increasing consistency across invocation modes.
+
+---
+
+*ADR created by [adr-writer agent]. Review and finalize before changing status from Draft to Accepted.*

pkg/cli/logs_models.go

@@ -97,6 +97,13 @@ type WorkflowRun struct {
 	EffectiveTokens     int           // Cost-normalized token count computed from per-model multipliers
 	AvgTimeBetweenTurns time.Duration // Average time between consecutive LLM API calls (from per-turn timestamps when available)
 	LogsPath            string
+	// DownloadDuration is the wall-clock time spent downloading this run's artifacts
+	// from GitHub. It is zero for runs served from the on-disk cache (no download
+	// was performed).
+	DownloadDuration time.Duration
+	// DownloadSizeBytes is the total on-disk size of the artifacts downloaded for
+	// this run, used to estimate average/maximum transfer volume across a batch.
+	DownloadSizeBytes int64
 }
 
 // LogMetrics represents extracted metrics from log files

pkg/cli/logs_multi.go

@@ -164,6 +164,9 @@ func DownloadWorkflowLogsForTargets( //nolint:largefunc // Keeps shared collecti
 	if err := prepareCachedLogsJSONL(&opts); err != nil {
 		return err
 	}
+	if opts.collectionStats == nil {
+		opts.collectionStats = &logsCollectionStats{}
+	}
 	defer func() {
 		err = errors.Join(err, finalizeCachedLogsJSONL(opts.cachedJSONLWriter, opts.cachedJSONLSourcePaths, opts.cachedJSONLWildcard, opts.StartDate, opts.EndDate))
 	}()
@@ -180,6 +183,7 @@ func DownloadWorkflowLogsForTargets( //nolint:largefunc // Keeps shared collecti
 	finishGitHubAPIRateLimitReports(activeCtx, allAPIRateLimits, opts.JSONOutput)
 	cacheGitHubAPIRateLimitReports(opts.cachedJSONLWriter, allAPIRateLimits...)
 	apiRateLimit, apiRateLimits := partitionGitHubAPIRateLimitReports(allAPIRateLimits)
+	renderLogsDownloadStatsSummary(opts.collectionStats, allAPIRateLimits...)
 	if len(processedRuns) == 0 {
 		if len(allErrors) > 0 {
 			return errors.Join(allErrors...)

pkg/cli/logs_orchestrator.go

@@ -304,6 +304,9 @@ func DownloadWorkflowLogs(ctx context.Context, opts LogsDownloadOptions) (err er
 	if err := prepareCachedLogsJSONL(&opts); err != nil {
 		return err
 	}
+	if opts.collectionStats == nil {
+		opts.collectionStats = &logsCollectionStats{}
+	}
 	defer func() {
 		err = errors.Join(err, finalizeCachedLogsJSONL(opts.cachedJSONLWriter, opts.cachedJSONLSourcePaths, opts.cachedJSONLWildcard, opts.StartDate, opts.EndDate))
 	}()
@@ -314,6 +317,7 @@ func DownloadWorkflowLogs(ctx context.Context, opts LogsDownloadOptions) (err er
 	}
 	renderLogsCollectionStats(opts.collectionStats)
 	finishGitHubAPIRateLimitReport(ctx, apiRateLimit, opts.JSONOutput)
+	renderLogsDownloadStatsSummary(opts.collectionStats, apiRateLimit)
 	cacheGitHubAPIRateLimitReports(opts.cachedJSONLWriter, apiRateLimit)
 	if handled, err := handleEmptyProcessedRuns(result.processedRuns, opts, result.timeoutReached, result.storageLimitReached, result.continuation, nil, apiRateLimit, nil); handled || err != nil {
 		logsOrchestratorLog.Printf("No processed runs to render (timeoutReached=%v, err=%v)", result.timeoutReached, err)

pkg/cli/logs_orchestrator_download.go

@@ -39,6 +39,15 @@ type logsCollectionStats struct {
 	discoveredRuns    atomic.Int64
 	downloadedReports atomic.Int64
 	cachedReports     atomic.Int64
+	// downloadCount, totalDownloadNanos, maxDownloadNanos, totalDownloadBytes, and
+	// maxDownloadBytes track artifact-download timing and size across runs that were
+	// actually downloaded this invocation (not served from the on-disk cache), so an
+	// avg/max summary can be rendered at the end of the run.
+	downloadCount      atomic.Int64
+	totalDownloadNanos atomic.Int64
+	maxDownloadNanos   atomic.Int64
+	totalDownloadBytes atomic.Int64
+	maxDownloadBytes   atomic.Int64
 }
 
 func (s *logsCollectionStats) recordDiscovered(count int) {
@@ -57,6 +66,36 @@ func (s *logsCollectionStats) recordResult(result DownloadResult) {
 	}
 	if !result.Skipped && result.Error == nil {
 		s.downloadedReports.Add(1)
+		if result.Run.DownloadDuration > 0 {
+			s.recordDownloadStats(result.Run.DownloadDuration, result.Run.DownloadSizeBytes)
+		}
+	}
+}
+
+// recordDownloadStats accumulates per-run download duration and size so that
+// renderLogsDownloadStatsSummary can report avg/max values at the end of the run.
+func (s *logsCollectionStats) recordDownloadStats(duration time.Duration, sizeBytes int64) {
+	if s == nil {
+		return
+	}
+	s.downloadCount.Add(1)
+	s.totalDownloadNanos.Add(duration.Nanoseconds())
+	s.totalDownloadBytes.Add(sizeBytes)
+	atomicMaxInt64(&s.maxDownloadNanos, duration.Nanoseconds())
+	atomicMaxInt64(&s.maxDownloadBytes, sizeBytes)
+}
+
+// atomicMaxInt64 atomically sets *addr to value if value is greater than the
+// current contents, using a compare-and-swap retry loop.
+func atomicMaxInt64(addr *atomic.Int64, value int64) {
+	for {
+		current := addr.Load()
+		if value <= current {
+			return
+		}
+		if addr.CompareAndSwap(current, value) {
+			return
+		}
 	}
 }
 
@@ -70,6 +109,73 @@ func renderLogsCollectionStats(stats *logsCollectionStats) {
 	)))
 }
 
+// gitHubAPIRateLimitCostEstimate sums the core GitHub API requests consumed
+// across one or more rate-limit reports (Start/End snapshots taken around the
+// logs command). Returns ok=false when no populated report is available.
+func gitHubAPIRateLimitCostEstimate(reports []*GitHubAPIRateLimitReport) (int, bool) {
+	var total int
+	var found bool
+	for _, report := range reports {
+		if report == nil || report.Start == nil || report.End == nil {
+			continue
+		}
+		diff := report.End.Used - report.Start.Used
+		if diff < 0 || report.End.Reset != report.Start.Reset {
+			// The rate-limit window reset mid-run (Used wrapped back down, or the
+			// reset timestamp itself moved even though Used happened to still be
+			// >= Start.Used); fall back to the ending value as a lower-bound
+			// approximation rather than mixing counters from different windows.
+			diff = report.End.Used
+		}
+		total += diff
+		found = true
+	}
+	return total, found
+}
+
+// formatDownloadByteSize renders a byte count in a compact human-readable form
+// (B, KB, MB, GB) for the end-of-run download stats summary.
+func formatDownloadByteSize(bytes int64) string {
+	const unit = 1024
+	if bytes < unit {
+		return fmt.Sprintf("%dB", bytes)
+	}
+	div, exp := int64(unit), 0
+	for n := bytes / unit; n >= unit; n /= unit {
+		div *= unit
+		exp++
+	}
+	return fmt.Sprintf("%.1f%ciB", float64(bytes)/float64(div), "KMGTPE"[exp])
+}
+
+// renderLogsDownloadStatsSummary prints an end-of-run informational line
+// summarizing per-run artifact download duration and size (avg/max across runs
+// actually downloaded this invocation), plus an estimated GitHub API rate-limit
+// cost per run derived from the provided rate-limit reports. It is a no-op when
+// no runs were downloaded or stats were not tracked.
+func renderLogsDownloadStatsSummary(stats *logsCollectionStats, reports ...*GitHubAPIRateLimitReport) {
+	if stats == nil {
+		return
+	}
+	count := stats.downloadCount.Load()
+	if count == 0 {
+		return
+	}
+	avgDuration := time.Duration(stats.totalDownloadNanos.Load() / count)
+	maxDuration := time.Duration(stats.maxDownloadNanos.Load())
+	avgSize := stats.totalDownloadBytes.Load() / count
+	maxSize := stats.maxDownloadBytes.Load()
+	msg := fmt.Sprintf(
+		"Download stats: avg %s (max %s) per run; avg size %s (max %s) per run",
+		avgDuration.Round(time.Millisecond), maxDuration.Round(time.Millisecond),
+		formatDownloadByteSize(avgSize), formatDownloadByteSize(maxSize),
+	)
+	if calls, ok := gitHubAPIRateLimitCostEstimate(reports); ok {
+		msg += fmt.Sprintf("; GitHub API cost estimate: ~%.1f requests/run", float64(calls)/float64(count))
+	}
+	fmt.Fprintln(os.Stderr, console.FormatInfoMessage(msg))
+}
+
 type processWorkflowRunBatchOptions struct {
 	count                  int
 	outputDir              string

pkg/cli/logs_orchestrator_stdin.go

@@ -280,6 +280,7 @@ func DownloadWorkflowLogsFromStdin(ctx context.Context, opts StdinLogsOptions) (
 		finishGitHubAPIRateLimitReports(ctx, allAPIRateLimits, opts.JSONOutput)
 		cacheGitHubAPIRateLimitReports(cachedJSONLWriter, allAPIRateLimits...)
 		apiRateLimit, apiRateLimits := partitionGitHubAPIRateLimitReports(allAPIRateLimits)
+		renderLogsDownloadStatsSummary(collectionStats, allAPIRateLimits...)
 		if opts.JSONOutput {
 			logsData := buildLogsData([]ProcessedRun{}, opts.OutputDir, nil)
 			logsData.GitHubAPIRateLimit = populatedGitHubAPIRateLimitReport(apiRateLimit)
@@ -307,6 +308,7 @@ func DownloadWorkflowLogsFromStdin(ctx context.Context, opts StdinLogsOptions) (
 	finishGitHubAPIRateLimitReports(ctx, allAPIRateLimits, opts.JSONOutput)
 	cacheGitHubAPIRateLimitReports(cachedJSONLWriter, allAPIRateLimits...)
 	apiRateLimit, apiRateLimits := partitionGitHubAPIRateLimitReports(allAPIRateLimits)
+	renderLogsDownloadStatsSummary(collectionStats, allAPIRateLimits...)
 	return renderLogsOutput(processedRuns, renderLogsOutputOptions{
 		outputDir:         opts.OutputDir,
 		summaryFile:       opts.SummaryFile,