Retry failed GitHub release scans with backoff

A failed scan no longer advances last_synced_at; it schedules a retry from 60s with exponential backoff, honouring Retry-After/X-RateLimit-Reset.
2026-10-09 22:31:38 +11:00
parent 1837f6ef8c
commit 07e17791d1
18 changed files with 477 additions and 134 deletions
@@ -447,7 +447,7 @@ func (p *GitHubProvider) fetchReleases(ctx context.Context, remote models.Remote
 			return nil, "", false, err
 		}
 		if resp.StatusCode != http.StatusOK {
-			return nil, "", false, fmt.Errorf("github releases API %s: status %d", u, resp.StatusCode)
+			return nil, "", false, provider.NewUpstreamStatusError("github releases API "+u, resp)
 		}
 		if page == 1 {
 			newEtag = respEtag
@@ -78,6 +78,7 @@ type githubFixture struct {
 	notModHit   int               // releases-list requests answered 304
 	releaseAuth string            // Authorization header seen on the last releases request
 	assetAuth   string            // Authorization header seen on the last asset request
+	failStatus  int               // when set, the releases list answers this status (rate-limit style)
 	mu          sync.Mutex
 }

@@ -100,6 +101,14 @@ func newGitHubFixture(t *testing.T, withDigest bool) *githubFixture {
 		f.mu.Lock()
 		f.releasesHit++
 		f.releaseAuth = r.Header.Get("Authorization")
+		if f.failStatus != 0 {
+			status := f.failStatus
+			f.mu.Unlock()
+			w.Header().Set("X-RateLimit-Remaining", "0")
+			w.Header().Set("X-RateLimit-Reset", strconv.FormatInt(time.Now().Add(30*time.Second).Unix(), 10))
+			http.Error(w, "API rate limit exceeded", status)
+			return
+		}
 		etag := f.etag
 		if etag != "" && r.Header.Get("If-None-Match") == etag {
 			f.notModHit++
@@ -35,7 +35,7 @@ type SyncStore interface {
 	provider.RemoteMetadataStore
 	ListGitHubRPMRemotes(ctx context.Context) ([]models.Remote, error)
 	ClaimGitHubSyncLease(ctx context.Context, remoteName, owner string, freshness, lease time.Duration) (claimed bool, etag string, err error)
-	ReleaseGitHubSyncLease(ctx context.Context, remoteName, owner, etag string, syncedAt time.Time) error
+	ReleaseGitHubSyncLease(ctx context.Context, remoteName, owner string, res provider.SyncResult) error
 }

 // SyncConfig tunes the shared syncer. Zero values fall back to safe defaults.
@@ -205,10 +205,11 @@ func (s *Syncer) process(ctx context.Context, job syncJob) {
 		s.mu.Unlock()
 	}()

-	freshness := time.Duration(job.remote.MutableTTL) * time.Second
-	if freshness <= 0 {
-		freshness = defaultSyncFreshness
+	ttl := time.Duration(job.remote.MutableTTL) * time.Second
+	if ttl <= 0 {
+		ttl = defaultSyncFreshness
 	}
+	freshness := ttl
 	if job.prime {
 		freshness = 0 // prime ignores the recency gate but still respects a live lease
 	}
@@ -226,18 +227,15 @@ func (s *Syncer) process(ctx context.Context, job syncJob) {
 	defer cancel()

 	newEtag, changed, scanErr := s.prov.scanWithState(scanCtx, job.remote, s.store, etag)
-	releaseEtag := etag
-	if scanErr == nil {
-		releaseEtag = newEtag
-	} else {
+	if scanErr != nil {
 		slog.Error("github_rpm syncer: scan failed", "remote", job.remote.Name, "error", scanErr)
 	}

 	// Release on a detached context so a clean shutdown mid-scan still frees the
-	// lease and advances last_synced_at (otherwise it simply expires).
+	// lease and records the outcome (otherwise the lease simply expires).
 	relCtx, relCancel := context.WithTimeout(context.WithoutCancel(ctx), 10*time.Second)
 	defer relCancel()
-	if err := s.store.ReleaseGitHubSyncLease(relCtx, job.remote.Name, s.owner, releaseEtag, time.Now()); err != nil {
+	if err := s.store.ReleaseGitHubSyncLease(relCtx, job.remote.Name, s.owner, provider.NewSyncResult(newEtag, scanErr, ttl)); err != nil {
 		slog.Warn("github_rpm syncer: release lease", "remote", job.remote.Name, "error", err)
 	}

@@ -27,6 +27,8 @@ type fakeSyncStore struct {
 	leaseExp   map[string]time.Time
 	lastSynced map[string]time.Time
 	etags      map[string]string
+	retryAt    map[string]time.Time
+	lastResult provider.SyncResult
 }

 func newFakeSyncStore() *fakeSyncStore {
@@ -36,6 +38,7 @@ func newFakeSyncStore() *fakeSyncStore {
 		leaseExp:   map[string]time.Time{},
 		lastSynced: map[string]time.Time{},
 		etags:      map[string]string{},
+		retryAt:    map[string]time.Time{},
 	}
 }

@@ -52,6 +55,9 @@ func (f *fakeSyncStore) ClaimGitHubSyncLease(_ context.Context, name, owner stri
 	ls, hasLS := f.lastSynced[name]
 	exp, hasExp := f.leaseExp[name]
 	freshOK := !hasLS || now.Sub(ls) >= freshness
+	if ra, pending := f.retryAt[name]; pending {
+		freshOK = !now.Before(ra)
+	}
 	leaseOK := !hasExp || exp.Before(now)
 	if freshOK && leaseOK {
 		f.leaseOwner[name] = owner
@@ -61,14 +67,20 @@ func (f *fakeSyncStore) ClaimGitHubSyncLease(_ context.Context, name, owner stri
 	return false, "", nil
 }

-func (f *fakeSyncStore) ReleaseGitHubSyncLease(_ context.Context, name, owner, etag string, syncedAt time.Time) error {
+func (f *fakeSyncStore) ReleaseGitHubSyncLease(_ context.Context, name, owner string, res provider.SyncResult) error {
 	f.mu.Lock()
 	defer f.mu.Unlock()
 	if f.leaseOwner[name] != owner {
 		return nil
 	}
-	f.lastSynced[name] = syncedAt
-	f.etags[name] = etag
+	f.lastResult = res
+	if res.Failed {
+		f.retryAt[name] = time.Now().Add(res.Backoff)
+	} else {
+		f.lastSynced[name] = time.Now()
+		f.etags[name] = res.Etag
+		delete(f.retryAt, name)
+	}
 	delete(f.leaseOwner, name)
 	delete(f.leaseExp, name)
 	return nil
@@ -310,3 +322,80 @@ func TestSyncerPrimeBypassesRecencyPeriodicDoesNot(t *testing.T) {
 		t.Fatalf("periodic scan ran inside recency window: %d -> %d releases calls", releasesAfterPrime, fx.releasesHit)
 	}
 }
+
+// A rate-limited scan is not recorded as a sync: the last good repodata keeps
+// serving, the retry honours the upstream reset hint and backoff, and once the
+// upstream recovers the next poll after the backoff re-syncs without waiting
+// out mutable_ttl.
+func TestSyncerFailedScanRetriesAfterBackoff(t *testing.T) {
+	fx := newGitHubFixture(t, true)
+	fx.etag = `"v1"`
+	store := newFakeSyncStore()
+	p := newTestProvider()
+	s := newSyncer(store, p, testSyncConfig())
+	remote := fx.remote()
+	bg := context.Background()
+
+	s.process(bg, syncJob{remote: remote, prime: true})
+	if rows, _ := store.ListRPMMetadataEntries(bg, remote.Name); len(rows) != 1 {
+		t.Fatalf("prime did not derive: %d rows", len(rows))
+	}
+
+	// mutable_ttl elapses while GitHub is rate-limiting.
+	fx.mu.Lock()
+	fx.failStatus = http.StatusForbidden
+	fx.etag = `"v2"`
+	fx.mu.Unlock()
+	store.mu.Lock()
+	store.lastSynced[remote.Name] = time.Now().Add(-2 * time.Hour)
+	store.mu.Unlock()
+
+	s.process(bg, syncJob{remote: remote})
+	res := store.lastResult
+	if !res.Failed {
+		t.Fatal("403 scan was recorded as a successful sync")
+	}
+	if until := time.Until(res.RetryAt); until < 20*time.Second || until > 40*time.Second {
+		t.Fatalf("retry hint from X-RateLimit-Reset not carried: retry in %v", until)
+	}
+	if res.Backoff != time.Minute || res.MaxBackoff >= time.Duration(remote.MutableTTL)*time.Second {
+		t.Fatalf("backoff %v cap %v, want 1m first retry capped below mutable_ttl", res.Backoff, res.MaxBackoff)
+	}
+	if store.etags[remote.Name] != `"v1"` {
+		t.Fatalf("failed scan replaced the etag: %q", store.etags[remote.Name])
+	}
+
+	rec := httptest.NewRecorder()
+	req := httptest.NewRequest(http.MethodGet, "/api/v1/remote/acme-rpm/repodata/repomd.xml", nil)
+	p.ServeRemote(rec, req, remote, "repodata/repomd.xml", "https://x", store)
+	if rec.Code != http.StatusOK {
+		t.Fatalf("last good repodata not served during failure: %d %s", rec.Code, rec.Body.String())
+	}
+	if rows, _ := store.ListRPMMetadataEntries(bg, remote.Name); len(rows) != 1 {
+		t.Fatalf("failed scan dropped cached metadata: %d rows", len(rows))
+	}
+
+	// Inside the backoff nothing is retried.
+	hits := fx.releasesHit
+	s.process(bg, syncJob{remote: remote})
+	if fx.releasesHit != hits {
+		t.Fatal("scan retried inside the backoff window")
+	}
+
+	// Upstream recovers and the backoff elapses: the next poll re-syncs.
+	fx.mu.Lock()
+	fx.failStatus = 0
+	fx.rpmBytes["other-9-9.aarch64.rpm"] = testsupport.MinimalRPM("other", "9", "9", "aarch64")
+	fx.mu.Unlock()
+	store.mu.Lock()
+	store.retryAt[remote.Name] = time.Now().Add(-time.Second)
+	store.mu.Unlock()
+
+	s.process(bg, syncJob{remote: remote})
+	if store.lastResult.Failed || store.etags[remote.Name] != `"v2"` {
+		t.Fatalf("recovery scan not recorded: failed=%v etag=%q", store.lastResult.Failed, store.etags[remote.Name])
+	}
+	if rows, _ := store.ListRPMMetadataEntries(bg, remote.Name); len(rows) != 2 {
+		t.Fatalf("recovery did not refresh metadata: %d rows", len(rows))
+	}
+}