From 1a800f3b2057a38252bbb911442af4e3697823ac Mon Sep 17 00:00:00 2001 From: Socialpranker <273312799+Socialpranker@users.noreply.github.com> Date: Fri, 10 Jul 2026 10:52:41 +0200 Subject: [PATCH] fix: pace certificate renewal retries instead of blocking on one long job A certificate that fails to renew (e.g. because DNS is temporarily broken) used to get stuck: queueRenewalTask submitted a single job to the jobManager that internally retried for up to 30 days with a growing backoff. While that job was in flight, every subsequent maintenance tick tried to queue the same job again, but jobManager's dedup-by-name silently dropped it. So once the backoff grew to hours, a fixed DNS record wouldn't get picked up until the sleeping job woke up on its own schedule, sometimes many hours later, even though the logs made it look like a new attempt was queued every 10 minutes. This moves the backoff schedule out of the job and into queueRenewalTask itself. Each job now makes a single renewal attempt and returns right away, so it never occupies the dedup slot for more than one attempt. The periodic maintenance tick is now what actually paces retries, gated by the same retryIntervals schedule doWithRetry already used. RenewCertSync/RenewCertAsync are unchanged and still used by manageOne, on-demand handshakes, and forceRenew. --- async.go | 82 ++++++++++++++++++++++++ async_test.go | 81 ++++++++++++++++++++++++ config.go | 28 +++++++-- maintain.go | 43 ++++++++++--- maintain_test.go | 160 +++++++++++++++++++++++++++++++++++++++++++++++ 5 files changed, 380 insertions(+), 14 deletions(-) create mode 100644 maintain_test.go diff --git a/async.go b/async.go index a2391803..15cfe710 100644 --- a/async.go +++ b/async.go @@ -95,6 +95,88 @@ func (jm *jobManager) worker() { } } +// renewalBackoff tracks, per certificate name, when the next renewal +// attempt driven by the periodic maintenance loop is allowed to run. It +// exists so that queueRenewalTask can make a single renewal attempt per +// call (via renewCertOnce) instead of submitting a job to jm that loops +// internally through retryIntervals for up to maxRetryDuration -- which +// would otherwise occupy jm's dedup slot for that name and cause +// subsequent maintenance ticks to silently no-op via jm.Submit until the +// long-lived job's own internal sleep happens to wake up (up to 6 hours +// later). By moving the schedule here, the periodic maintenance tick +// (which already runs every RenewCheckInterval and only proceeds if the +// certificate still needs renewal) becomes the actual retry driver, while +// still following the same backoff schedule as doWithRetry. +type renewalBackoff struct { + mu sync.Mutex + state map[string]*renewalBackoffState +} + +type renewalBackoffState struct { + nextAttempt time.Time + intervalIdx int // -1 until the first failed attempt + firstAttempt time.Time +} + +var renewalRetrySchedule = &renewalBackoff{} + +// readyFor reports whether name is currently allowed to attempt a renewal. +// It is always true for a name with no recorded failure. +func (rb *renewalBackoff) readyFor(name string) bool { + return rb.readyForAsOf(name, time.Now()) +} + +// readyForAsOf is like readyFor but evaluates readiness as of the given +// time instead of time.Now(); it exists so tests can exercise the backoff +// schedule without sleeping for real minutes/hours/days. +func (rb *renewalBackoff) readyForAsOf(name string, asOf time.Time) bool { + rb.mu.Lock() + defer rb.mu.Unlock() + st, ok := rb.state[name] + if !ok { + return true + } + return !asOf.Before(st.nextAttempt) +} + +// recordFailure schedules the next allowed attempt for name using the same +// retryIntervals/maxRetryDuration schedule as doWithRetry. It reports +// whether the overall retry budget (maxRetryDuration since the first +// recorded failure in this cycle) has been exhausted. If exhausted, the +// backoff cycle for name is reset (mirroring doWithRetry's own behavior of +// giving up and returning), so the next maintenance tick will attempt +// immediately rather than being throttled forever; if the certificate still +// needs renewal by then, a fresh backoff cycle begins. +func (rb *renewalBackoff) recordFailure(name string, now time.Time) (exhausted bool) { + rb.mu.Lock() + defer rb.mu.Unlock() + if rb.state == nil { + rb.state = make(map[string]*renewalBackoffState) + } + st, ok := rb.state[name] + if !ok { + st = &renewalBackoffState{intervalIdx: -1, firstAttempt: now} + rb.state[name] = st + } + if now.Sub(st.firstAttempt) >= maxRetryDuration { + delete(rb.state, name) + return true + } + if st.intervalIdx < len(retryIntervals)-1 { + st.intervalIdx++ + } + st.nextAttempt = now.Add(retryIntervals[st.intervalIdx]) + return false +} + +// clear forgets any recorded backoff state for name, e.g. after a +// successful renewal or once the certificate no longer needs renewing. +func (rb *renewalBackoff) clear(name string) { + rb.mu.Lock() + defer rb.mu.Unlock() + delete(rb.state, name) +} + func doWithRetry(ctx context.Context, log *zap.Logger, f func(context.Context) error) error { var attempts int ctx = context.WithValue(ctx, AttemptsCtxKey, &attempts) diff --git a/async_test.go b/async_test.go index a118733e..71c10c42 100644 --- a/async_test.go +++ b/async_test.go @@ -69,3 +69,84 @@ func waitUntil(timeout time.Duration, cond func() bool) bool { } return cond() } + +// TestRenewalBackoffSchedule verifies the scheduling primitive that lets +// queueRenewalTask pace retries itself instead of relying on a single +// long-lived jm job sleeping between attempts (see caddyserver/caddy#7843: +// after a transient DNS outage cleared, renewal did not happen again until +// the process was restarted, because the in-flight job's own multi-hour +// internal sleep -- not the periodic maintenance tick -- was governing +// retries, and jm.Submit silently dropped every duplicate submission from +// the maintenance tick in the meantime). +// +// It uses a fresh *renewalBackoff (not the shared package-level +// renewalRetrySchedule) and a synthetic clock so it doesn't need to sleep +// for real minutes/hours/days. +func TestRenewalBackoffSchedule(t *testing.T) { + rb := &renewalBackoff{} + const name = "renew_example.com" + now := time.Date(2026, 1, 1, 0, 0, 0, 0, time.UTC) + + // No recorded failures yet: always ready. + if !rb.readyFor(name) { + t.Fatal("expected a name with no recorded failure to be ready immediately") + } + + // First failure: schedules the first retry interval out. + if exhausted := rb.recordFailure(name, now); exhausted { + t.Fatal("did not expect the retry budget to be exhausted after a single failure") + } + if rb.readyForAsOf(name, now) { + t.Fatal("expected name to not be ready for a retry immediately after recording a failure") + } + + // Not ready right up until (but not including) the first retry interval. + almostThere := now.Add(retryIntervals[0] - time.Millisecond) + if rb.readyForAsOf(name, almostThere) { + t.Fatal("expected name to still not be ready just before its scheduled retry time") + } + + // Ready once the first retry interval has elapsed. + dueTime := now.Add(retryIntervals[0]) + if !rb.readyForAsOf(name, dueTime) { + t.Fatal("expected name to be ready once its scheduled retry time has passed") + } + + // A second consecutive failure advances to the next (longer) interval, + // counted from when this second attempt happened. + if exhausted := rb.recordFailure(name, dueTime); exhausted { + t.Fatal("did not expect the retry budget to be exhausted after a second failure") + } + secondDue := dueTime.Add(retryIntervals[1]) + if rb.readyForAsOf(name, secondDue.Add(-time.Millisecond)) { + t.Fatal("expected name to still be backing off before the second scheduled retry time") + } + if !rb.readyForAsOf(name, secondDue) { + t.Fatal("expected name to be ready once the second scheduled retry time has passed") + } + + // clear() makes the name immediately ready again, as happens after a + // successful renewal. + rb.recordFailure(name, secondDue) + if rb.readyForAsOf(name, secondDue) { + t.Fatal("expected name to be backing off before calling clear") + } + rb.clear(name) + if !rb.readyForAsOf(name, secondDue) { + t.Fatal("expected name to be immediately ready after clear") + } + + // Once the cumulative failure window reaches maxRetryDuration, the + // caller is told the budget is exhausted and the schedule resets, so a + // fresh maintenance tick is not throttled indefinitely (mirroring + // doWithRetry's own give-up-and-return behavior). + start := now + rb.recordFailure(name, start) + exhausted := rb.recordFailure(name, start.Add(maxRetryDuration)) + if !exhausted { + t.Fatal("expected the retry budget to be reported exhausted once maxRetryDuration has elapsed") + } + if !rb.readyForAsOf(name, start.Add(maxRetryDuration)) { + t.Fatal("expected name to be immediately ready again after the retry budget was exhausted") + } +} diff --git a/config.go b/config.go index 27c39cd8..9c637655 100644 --- a/config.go +++ b/config.go @@ -807,16 +807,32 @@ func (cfg *Config) storageHasCertResourcesAnyIssuer(ctx context.Context, name st // cache with the new certificate. The certificate will not be renewed if it // is not close to expiring unless force is true. func (cfg *Config) RenewCertSync(ctx context.Context, name string, force bool) error { - return cfg.renewCert(ctx, name, force, true) + return cfg.renewCert(ctx, name, force, false, true) } // RenewCertAsync is the same as RenewCertSync(), except it runs in the // background; i.e. non-interactively, and with retries if it fails. func (cfg *Config) RenewCertAsync(ctx context.Context, name string, force bool) error { - return cfg.renewCert(ctx, name, force, false) + return cfg.renewCert(ctx, name, force, true, false) } -func (cfg *Config) renewCert(ctx context.Context, name string, force, interactive bool) error { +// renewCertOnce makes a single, non-interactive renewal attempt for name and +// returns whatever error results, without looping through the retryIntervals +// schedule internally. Unlike RenewCertSync, it never prompts on stdin +// (interactive is always false for PreCheck/setEmail purposes), so it is safe +// to call from a background goroutine. It still acquires/releases the same +// storage lock as RenewCertSync/RenewCertAsync around the single attempt, so +// cross-instance coordination is preserved. +// +// This exists for callers, such as the periodic maintenance loop, that +// already have their own outer retry/backoff driver and therefore don't want +// a single renewal job to camp on the jobManager dedup slot for its name for +// up to maxRetryDuration; see queueRenewalTask. +func (cfg *Config) renewCertOnce(ctx context.Context, name string, force bool) error { + return cfg.renewCert(ctx, name, force, false, false) +} + +func (cfg *Config) renewCert(ctx context.Context, name string, force, retry, interactive bool) error { if len(cfg.Issuers) == 0 { return fmt.Errorf("no issuers configured; impossible to renew or check existing certificate in storage") } @@ -1034,10 +1050,10 @@ func (cfg *Config) renewCert(ctx context.Context, name string, force, interactiv return nil } - if interactive { - err = f(ctx) - } else { + if retry { err = doWithRetry(ctx, log, f) + } else { + err = f(ctx) } return err diff --git a/maintain.go b/maintain.go index bda4a93f..6c9a68e8 100644 --- a/maintain.go +++ b/maintain.go @@ -229,25 +229,46 @@ func (certCache *Cache) RenewManagedCertificates(ctx context.Context) error { func (certCache *Cache) queueRenewalTask(ctx context.Context, oldCert Certificate, cfg *Config) error { log := certCache.logger.Named("maintenance") - timeLeft := expiresAt(oldCert.Leaf).Sub(time.Now().UTC()) - log.Info("certificate expires soon; queuing for renewal", - zap.Strings("identifiers", oldCert.Names), - zap.Duration("remaining", timeLeft)) - // Get the name which we should use to renew this certificate; // we only support managing certificates with one name per cert, // so this should be easy. renewName := oldCert.Names[0] + jobName := "renew_" + renewName + + // If a previous attempt for this name failed, don't try again until the + // backoff schedule (the same retryIntervals used by doWithRetry) says + // we're allowed to. This is what actually paces retries now: each + // renewal job below makes just ONE attempt and returns, so it never + // occupies jm's dedup slot for longer than a single attempt takes. + // Without this check, a certificate that keeps needing renewal (e.g. + // because the underlying cause, like a DNS outage, hasn't cleared yet) + // would cause a new attempt on every single maintenance tick, which is + // exactly the hammering that retryIntervals exists to avoid. + if !renewalRetrySchedule.readyFor(jobName) { + log.Debug("certificate expires soon, but renewal already failed recently; waiting for backoff before retrying", + zap.Strings("identifiers", oldCert.Names)) + return nil + } - // queue up this renewal job (is a no-op if already active or queued) - jm.Submit(cfg.Logger, "renew_"+renewName, func() error { + timeLeft := expiresAt(oldCert.Leaf).Sub(time.Now().UTC()) + log.Info("certificate expires soon; queuing for renewal", + zap.Strings("identifiers", oldCert.Names), + zap.Duration("remaining", timeLeft)) + + // Queue up this renewal job (is a no-op if already active or queued, + // e.g. because this same certificate was independently queued for + // renewal elsewhere, such as manageOne or an on-demand handshake). + // Since this job makes only a single attempt (renewCertOnce) instead of + // looping internally for up to maxRetryDuration, it will not block + // future maintenance ticks from making progress once it returns. + jm.Submit(cfg.Logger, jobName, func() error { timeLeft := expiresAt(oldCert.Leaf).Sub(time.Now().UTC()) log.Info("attempting certificate renewal", zap.Strings("identifiers", oldCert.Names), zap.Duration("remaining", timeLeft)) // perform renewal - crucially, this happens OUTSIDE a lock on certCache - err := cfg.RenewCertAsync(ctx, renewName, false) + err := cfg.renewCertOnce(ctx, renewName, false) if err != nil { if cfg.OnDemand != nil { // loaded dynamically, remove dynamically @@ -255,8 +276,14 @@ func (certCache *Cache) queueRenewalTask(ctx context.Context, oldCert Certificat certCache.removeCertificate(oldCert) certCache.mu.Unlock() } + if exhausted := renewalRetrySchedule.recordFailure(jobName, time.Now()); exhausted { + log.Error("final attempt; giving up until next scheduled renewal check finds the certificate still needs renewal", + zap.Strings("identifiers", oldCert.Names), + zap.Error(err)) + } return fmt.Errorf("%v %v", oldCert.Names, err) } + renewalRetrySchedule.clear(jobName) // successful renewal, so update in-memory cache by loading // renewed certificate so it will be used with handshakes diff --git a/maintain_test.go b/maintain_test.go new file mode 100644 index 00000000..36c38487 --- /dev/null +++ b/maintain_test.go @@ -0,0 +1,160 @@ +package certmagic + +import ( + "context" + "crypto/x509" + "crypto/x509/pkix" + "fmt" + "math/big" + "sync/atomic" + "testing" + "time" +) + +// failingIssuer is a fake Issuer that always fails, simulating a CA +// challenge validation failure (e.g. because DNS is broken, as in +// caddyserver/caddy#7843). It counts how many times Issue was called so +// tests can assert on attempt cadence. +type failingIssuer struct { + calls atomic.Int32 + err error +} + +func (fi *failingIssuer) Issue(ctx context.Context, csr *x509.CertificateRequest) (*IssuedCertificate, error) { + fi.calls.Add(1) + return nil, fi.err +} + +func (fi *failingIssuer) IssuerKey() string { return "failing_test_issuer" } + +// TestQueueRenewalTaskPacesRetriesItself is a regression test for +// caddyserver/caddy#7843: after a transient failure (e.g. a DNS outage) +// prevented renewal, the certificate did not get renewed again even after +// the underlying problem cleared, until the process was restarted. +// +// Root cause: queueRenewalTask used to submit a job to the package-level +// jm that internally looped through doWithRetry's retryIntervals schedule +// for up to maxRetryDuration (30 days) without returning. Because jm.Submit +// silently drops duplicate submissions for a name that is already +// in-flight, every subsequent periodic maintenance tick's call to +// queueRenewalTask for the same certificate was a silent no-op: the only +// thing actually driving retries was the single long-lived job's own +// internal sleep, which could be up to 6 hours between attempts, and, +// depending on scheduling, could appear to simply stop making progress. +// +// This test simulates two consecutive maintenance ticks in quick +// succession for a certificate whose issuer always fails, and asserts: +// 1. The first tick makes exactly one renewal attempt. +// 2. A second tick immediately afterward makes NO additional attempt, +// because we are intentionally backing off (this is desired -- we +// don't want to hammer the CA every RenewCheckInterval). +// 3. Once the backoff interval has elapsed, a third tick DOES make +// another attempt -- proving that renewal attempts are paced by an +// externally observable, bounded schedule (retryIntervals[0], on the +// order of a minute) rather than being silently stuck behind a +// multi-hour-or-longer sleep inside a single dedup-protected job. +func TestQueueRenewalTaskPacesRetriesItself(t *testing.T) { + const domain = "example.com" + issuer := &failingIssuer{err: fmt.Errorf("simulated DNS-01 challenge failure")} + + certCache := &Cache{ + cache: make(map[string]Certificate), + cacheIndex: make(map[string][]string), + logger: defaultTestLogger, + } + cfg := &Config{ + Issuers: []Issuer{issuer}, + Storage: &FileStorage{Path: t.TempDir()}, + Logger: defaultTestLogger, + DisableARI: true, // keep the renewal-needed check to plain expiration logic + ReusePrivateKeys: true, // avoid needing a KeySource for a fresh key + certCache: certCache, + } + cfg.OCSP.DisableStapling = true + + // Build an already-expired self-signed leaf certificate and stash it in + // storage as the "current" cert resource, so loadCertResourceAnyIssuer + // finds something to renew. + tmpl := &x509.Certificate{ + SerialNumber: big.NewInt(1), + Subject: pkix.Name{CommonName: domain}, + DNSNames: []string{domain}, + NotBefore: time.Now().Add(-60 * 24 * time.Hour), + NotAfter: time.Now().Add(-1 * time.Hour), // already expired + } + leaf, priv, certPEM := mustIssueTestCertificate(t, tmpl, nil, nil) + + privPEM, err := PEMEncodePrivateKey(priv) + if err != nil { + t.Fatalf("encoding private key: %v", err) + } + + certRes := CertificateResource{ + SANs: []string{domain}, + CertificatePEM: certPEM, + PrivateKeyPEM: privPEM, + issuerKey: issuer.IssuerKey(), + } + ctx := context.Background() + if err := cfg.saveCertResource(ctx, issuer, certRes); err != nil { + t.Fatalf("seeding cert resource in storage: %v", err) + } + + oldCert := Certificate{ + Names: []string{domain}, + managed: true, + issuerKey: issuer.IssuerKey(), + } + oldCert.Leaf = leaf + + jobName := "renew_" + domain + // Make sure we start from a clean slate in the shared package-level + // schedule, in case another test left state behind. + renewalRetrySchedule.clear(jobName) + t.Cleanup(func() { renewalRetrySchedule.clear(jobName) }) + + // --- Tick 1: should make exactly one attempt, then back off. --- + if err := certCache.queueRenewalTask(ctx, oldCert, cfg); err != nil { + t.Fatalf("queueRenewalTask (tick 1): %v", err) + } + if !waitUntil(time.Second, func() bool { return issuer.calls.Load() == 1 }) { + t.Fatalf("expected exactly 1 issuance attempt after tick 1, got %d", issuer.calls.Load()) + } + // Give the job's error-handling path (which calls + // renewalRetrySchedule.recordFailure) a moment to run after Issue + // returns, since it happens in the jobManager worker goroutine. + if !waitUntil(time.Second, func() bool { return !renewalRetrySchedule.readyFor(jobName) }) { + t.Fatal("expected renewal name to be backing off after a failed attempt") + } + + // --- Tick 2: fires immediately after tick 1; must NOT attempt again, + // because we are still within the first backoff interval. This is the + // crux of the fix: previously it was jm's dedup (silent, unbounded) + // doing this job; now it's an explicit, bounded backoff check. --- + if err := certCache.queueRenewalTask(ctx, oldCert, cfg); err != nil { + t.Fatalf("queueRenewalTask (tick 2): %v", err) + } + time.Sleep(50 * time.Millisecond) // give any (unwanted) job a chance to run + if got := issuer.calls.Load(); got != 1 { + t.Fatalf("expected still only 1 issuance attempt immediately after tick 2 (should be backing off), got %d", got) + } + + // --- Simulate the backoff interval elapsing by directly rewinding the + // recorded schedule (equivalent to waiting retryIntervals[0], which we + // don't want this test to actually spend real time on). --- + renewalRetrySchedule.mu.Lock() + if st, ok := renewalRetrySchedule.state[jobName]; ok { + st.nextAttempt = time.Now().Add(-time.Millisecond) + } else { + t.Fatal("expected backoff state to be recorded for job name") + } + renewalRetrySchedule.mu.Unlock() + + // --- Tick 3: backoff has elapsed, so this tick must retry. --- + if err := certCache.queueRenewalTask(ctx, oldCert, cfg); err != nil { + t.Fatalf("queueRenewalTask (tick 3): %v", err) + } + if !waitUntil(time.Second, func() bool { return issuer.calls.Load() == 2 }) { + t.Fatalf("expected a second issuance attempt once the backoff interval elapsed, got %d", issuer.calls.Load()) + } +}