feat(git): instrument readiness-gate prewarm with metrics

Adds per-repo duration histogram (cachew.git.prewarm_repo_duration_seconds,
labelled by path=fetch|restore and status=success|error), total-pass duration
histogram (cachew.git.prewarm_pass_duration_seconds), and pass-completion
counter (cachew.git.prewarm_passes_total), both labelled by outcome
(complete|empty_histogram|no_store).

Lets us see prewarm tail latency per deploy and distinguish 'no top-N'
configs from genuinely-warm pods on the dashboard.

Amp-Thread-ID: https://ampcode.com/threads/T-019e4193-0c35-732e-96f0-b9c97aed2fae
Co-authored-by: Amp <amp@ampcode.com>

Author: worstell

internal/strategy/git/git.go

@@ -227,6 +227,7 @@ func (s *Strategy) SetMetadataStore(store *metadatadb.Store) {
 		if s.config.PrewarmMostClonedRepos > 0 {
 			logger.WarnContext(s.ctx, "prewarm-most-cloned-repos is set but no metadata store was provided; "+
 				"reporting ready without prewarm (misconfiguration)")
+			s.metrics.recordPrewarmPass(s.ctx, "no_store", 0)
 			s.prewarmComplete.Store(true)
 		}
 		return
@@ -261,6 +262,7 @@ func (s *Strategy) SetMetadataStore(store *metadatadb.Store) {
 // against cold upstreams can extend startup considerably.
 func (s *Strategy) prewarmMostCloned(ctx context.Context) {
 	logger := logging.FromContext(ctx)
+	passStart := time.Now()
 	select {
 	case <-ctx.Done():
 		return
@@ -269,6 +271,7 @@ func (s *Strategy) prewarmMostCloned(ctx context.Context) {
 	top := s.repoCounts.TopRepos(prewarmPopularityWindowDays, s.config.PrewarmMostClonedRepos)
 	if len(top) == 0 {
 		logger.WarnContext(ctx, "prewarm-most-cloned-repos is set but the clone histogram is empty; reporting ready")
+		s.metrics.recordPrewarmPass(ctx, "empty_histogram", time.Since(passStart))
 		return
 	}
 	logger.InfoContext(ctx, "Prewarming most-cloned repositories for readiness gate", "count", len(top))
@@ -277,34 +280,41 @@ func (s *Strategy) prewarmMostCloned(ctx context.Context) {
 			return
 		}
 		start := time.Now()
-		if err := s.prewarmRepo(ctx, rc.Repo); err != nil {
+		path, err := s.prewarmRepo(ctx, rc.Repo)
+		dur := time.Since(start)
+		status := "success"
+		if err != nil {
+			status = "error"
 			logger.ErrorContext(ctx, "Failed to prewarm repo for readiness gate",
-				"upstream", rc.Repo, "clone_count", rc.Count, "duration", time.Since(start), "error", err)
-			continue
+				"upstream", rc.Repo, "clone_count", rc.Count, "path", path, "duration", dur, "error", err)
+		} else {
+			logger.InfoContext(ctx, "Prewarmed repo for readiness gate",
+				"upstream", rc.Repo, "clone_count", rc.Count, "path", path, "duration", dur)
 		}
-		logger.InfoContext(ctx, "Prewarmed repo for readiness gate",
-			"upstream", rc.Repo, "clone_count", rc.Count, "duration", time.Since(start))
+		s.metrics.recordPrewarmRepo(ctx, path, status, dur)
 	}
+	s.metrics.recordPrewarmPass(ctx, "complete", time.Since(passStart))
 }
 
 // prewarmRepo ensures the mirror for upstreamURL exists and has been freshened
 // once. Uses FetchTimeout (not CloneTimeout) on the fetch path so a slow
 // upstream on an already-cloned mirror cannot extend startup by an hour.
-func (s *Strategy) prewarmRepo(ctx context.Context, upstreamURL string) error {
+// Returns the path taken ("fetch" or "restore") for metrics labelling.
+func (s *Strategy) prewarmRepo(ctx context.Context, upstreamURL string) (string, error) {
 	repo, err := s.cloneManager.GetOrCreate(ctx, upstreamURL)
 	if err != nil {
-		return errors.Wrapf(err, "resolve clone for %s", upstreamURL)
+		return "restore", errors.Wrapf(err, "resolve clone for %s", upstreamURL)
 	}
 	if repo.State() != gitclone.StateReady {
 		if err := s.ensureCloneReady(ctx, repo); err != nil {
-			return errors.Wrapf(err, "clone %s", upstreamURL)
+			return "restore", errors.Wrapf(err, "clone %s", upstreamURL)
 		}
-		return nil
+		return "restore", nil
 	}
 	if err := repo.FetchLenient(ctx, s.cloneManager.Config().FetchTimeout); err != nil {
-		return errors.Wrapf(err, "fetch %s", upstreamURL)
+		return "fetch", errors.Wrapf(err, "fetch %s", upstreamURL)
 	}
-	return nil
+	return "fetch", nil
 }
 
 func (s *Strategy) warmExistingRepos(ctx context.Context) error {

internal/strategy/git/metrics.go

@@ -12,21 +12,27 @@ import (
 )
 
 type gitMetrics struct {
-	operationDuration  metric.Float64Histogram
-	operationTotal     metric.Int64Counter
-	requestTotal       metric.Int64Counter
-	snapshotServeTotal metric.Int64Counter
-	snapshotServeSize  metric.Float64Histogram
+	operationDuration   metric.Float64Histogram
+	operationTotal      metric.Int64Counter
+	requestTotal        metric.Int64Counter
+	snapshotServeTotal  metric.Int64Counter
+	snapshotServeSize   metric.Float64Histogram
+	prewarmRepoDuration metric.Float64Histogram
+	prewarmPassDuration metric.Float64Histogram
+	prewarmPassTotal    metric.Int64Counter
 }
 
 func newGitMetrics() *gitMetrics {
 	meter := otel.Meter("cachew.git")
 	return &gitMetrics{
-		operationDuration:  metrics.NewMetric[metric.Float64Histogram](meter, "cachew.git.operation_duration_seconds", "s", "Duration of git operations (clone, fetch, repack, snapshot)"),
-		operationTotal:     metrics.NewMetric[metric.Int64Counter](meter, "cachew.git.operations_total", "{operations}", "Total number of git operations"),
-		requestTotal:       metrics.NewMetric[metric.Int64Counter](meter, "cachew.git.requests_total", "{requests}", "Total number of git HTTP requests by type"),
-		snapshotServeTotal: metrics.NewMetric[metric.Int64Counter](meter, "cachew.git.snapshot_serves_total", "{serves}", "Snapshot serve events by source (cache, spool, cold_cache) and repository"),
-		snapshotServeSize:  metrics.NewMetric[metric.Float64Histogram](meter, "cachew.git.snapshot_serve_bytes", "By", "Size of served snapshots in bytes"),
+		operationDuration:   metrics.NewMetric[metric.Float64Histogram](meter, "cachew.git.operation_duration_seconds", "s", "Duration of git operations (clone, fetch, repack, snapshot)"),
+		operationTotal:      metrics.NewMetric[metric.Int64Counter](meter, "cachew.git.operations_total", "{operations}", "Total number of git operations"),
+		requestTotal:        metrics.NewMetric[metric.Int64Counter](meter, "cachew.git.requests_total", "{requests}", "Total number of git HTTP requests by type"),
+		snapshotServeTotal:  metrics.NewMetric[metric.Int64Counter](meter, "cachew.git.snapshot_serves_total", "{serves}", "Snapshot serve events by source (cache, spool, cold_cache) and repository"),
+		snapshotServeSize:   metrics.NewMetric[metric.Float64Histogram](meter, "cachew.git.snapshot_serve_bytes", "By", "Size of served snapshots in bytes"),
+		prewarmRepoDuration: metrics.NewMetric[metric.Float64Histogram](meter, "cachew.git.prewarm_repo_duration_seconds", "s", "Duration of per-repo prewarm during readiness gate, by entry state and status"),
+		prewarmPassDuration: metrics.NewMetric[metric.Float64Histogram](meter, "cachew.git.prewarm_pass_duration_seconds", "s", "Total duration of the readiness-gate prewarm pass, by outcome"),
+		prewarmPassTotal:    metrics.NewMetric[metric.Int64Counter](meter, "cachew.git.prewarm_passes_total", "{passes}", "Total readiness-gate prewarm passes completed, by outcome"),
 	}
 }
 
@@ -56,3 +62,21 @@ func (m *gitMetrics) recordSnapshotServe(ctx context.Context, source, repo strin
 		m.snapshotServeSize.Record(ctx, float64(sizeBytes), attrs)
 	}
 }
+
+// recordPrewarmRepo records the wall-clock cost of warming a single repo during
+// the readiness gate. path is "fetch" (mirror already on disk) or "restore"
+// (mirror snapshot pulled from S3 or full clone). status is "success" or "error".
+func (m *gitMetrics) recordPrewarmRepo(ctx context.Context, path, status string, duration time.Duration) {
+	m.prewarmRepoDuration.Record(ctx, duration.Seconds(), metric.WithAttributes(
+		attribute.String("path", path),
+		attribute.String("status", status),
+	))
+}
+
+// recordPrewarmPass records the total prewarm-pass wall time and completion
+// outcome. outcome is one of: "complete", "empty_histogram", "no_store".
+func (m *gitMetrics) recordPrewarmPass(ctx context.Context, outcome string, duration time.Duration) {
+	attrs := metric.WithAttributes(attribute.String("outcome", outcome))
+	m.prewarmPassTotal.Add(ctx, 1, attrs)
+	m.prewarmPassDuration.Record(ctx, duration.Seconds(), attrs)
+}