From 6631e0fa995f0dd8ff8f716d8b83310577cddfc4 Mon Sep 17 00:00:00 2001 From: Bryan Frimin Date: Tue, 14 Oct 2025 14:47:32 +0200 Subject: [PATCH] Fix failed ACME block the queue Signed-off-by: Bryan Frimin --- pkg/certmanager/provisioner.go | 142 +++++++++++++++---- pkg/certmanager/renewer.go | 63 +++++++- pkg/coredata/custom_domain.go | 85 +++++++++++ pkg/coredata/migrations/20251014T120000Z.sql | 8 ++ 4 files changed, 269 insertions(+), 29 deletions(-) create mode 100644 pkg/coredata/migrations/20251014T120000Z.sql diff --git a/pkg/certmanager/provisioner.go b/pkg/certmanager/provisioner.go index 4b0e949bd..aecfef3d6 100644 --- a/pkg/certmanager/provisioner.go +++ b/pkg/certmanager/provisioner.go @@ -17,7 +17,6 @@ package certmanager import ( "context" "fmt" - "strings" "time" "github.com/getprobo/probo/pkg/coredata" @@ -79,6 +78,10 @@ func (p *Provisioner) checkPendingDomains(ctx context.Context) error { return p.pg.WithConn( ctx, func(conn pg.Conn) error { + if err := p.handleStaleProvisioningAttempts(ctx, conn); err != nil { + p.logger.ErrorCtx(ctx, "cannot handle stale provisioning attempts", log.Error(err)) + } + var domains coredata.CustomDomains if err := domains.ListDomainsWithPendingHTTPChallenges(ctx, conn, coredata.NewNoScope()); err != nil { return fmt.Errorf("cannot load domains with pending challenges: %w", err) @@ -112,39 +115,72 @@ func (p *Provisioner) checkPendingDomains(ctx context.Context) error { ) } -func isChallengeFailedError(err error) bool { - if err == nil { - return false +func (p *Provisioner) handleStaleProvisioningAttempts(ctx context.Context, conn pg.Conn) error { + var domains coredata.CustomDomains + if err := domains.ListStaleProvisioningDomains(ctx, conn, coredata.NewNoScope()); err != nil { + return fmt.Errorf("cannot load stale provisioning domains: %w", err) } - errStr := strings.ToLower(err.Error()) + if len(domains) == 0 { + return nil + } - // These errors indicate the challenge/order is no longer valid - return strings.Contains(errStr, "authorization must be pending") || - strings.Contains(errStr, "order") && strings.Contains(errStr, "invalid") || - strings.Contains(errStr, "authorization") && strings.Contains(errStr, "invalid") || - strings.Contains(errStr, "challenge") && strings.Contains(errStr, "invalid") + p.logger.InfoCtx(ctx, "found stale provisioning attempts to reset", log.Int("count", len(domains))) + + for _, domain := range domains { + if err := p.resetStaleDomain(ctx, conn, domain); err != nil { + p.logger.ErrorCtx( + ctx, + "cannot reset stale domain", + log.String("domain", domain.Domain), + log.Error(err), + ) + } + } + + return nil } -func (p *Provisioner) resetDomainToRetry( +func (p *Provisioner) resetStaleDomain( ctx context.Context, conn pg.Conn, domain *coredata.CustomDomain, ) error { fullDomain := &coredata.CustomDomain{} if err := fullDomain.LoadByIDForUpdate(ctx, conn, coredata.NewNoScope(), p.encryptionKey, domain.ID); err != nil { - return fmt.Errorf("cannot load domain for update: %w", err) + return fmt.Errorf("cannot load stale domain for update: %w", err) } + staleDuration := time.Since(fullDomain.UpdatedAt) + + p.logger.InfoCtx( + ctx, + "resetting stale domain", + log.String("domain", fullDomain.Domain), + log.String("status", string(fullDomain.SSLStatus)), + log.Duration("stale_duration", staleDuration), + log.Int("retry_count", fullDomain.SSLRetryCount), + ) + fullDomain.HTTPChallengeToken = nil fullDomain.HTTPChallengeKeyAuth = nil fullDomain.HTTPChallengeURL = nil fullDomain.HTTPOrderURL = nil - fullDomain.SSLStatus = coredata.CustomDomainSSLStatusPending + if fullDomain.SSLLastAttemptAt != nil && time.Since(*fullDomain.SSLLastAttemptAt) > 24*time.Hour { + p.logger.InfoCtx( + ctx, + "resetting retry count due to old last attempt", + log.String("domain", fullDomain.Domain), + log.Time("last_attempt", *fullDomain.SSLLastAttemptAt), + ) + fullDomain.SSLRetryCount = 0 + fullDomain.SSLLastAttemptAt = nil + } + if err := fullDomain.Update(ctx, conn, coredata.NewNoScope(), p.encryptionKey); err != nil { - return fmt.Errorf("cannot update domain: %w", err) + return fmt.Errorf("cannot update stale domain: %w", err) } return nil @@ -208,35 +244,82 @@ func (p *Provisioner) provisionDomainCertificate( ctx, "cannot complete HTTP challenge", log.String("domain", domain.Domain), + log.Int("retry_count", domain.SSLRetryCount), log.Error(err), ) - // Check if the error indicates the challenge/order has failed - // and needs to be reset for a fresh attempt - if isChallengeFailedError(err) { - p.logger.InfoCtx( + fullDomain := &coredata.CustomDomain{} + if loadErr := fullDomain.LoadByIDForUpdate(ctx, conn, coredata.NewNoScope(), p.encryptionKey, domain.ID); loadErr != nil { + p.logger.ErrorCtx( ctx, - "challenge or order is no longer valid, resetting domain to retry with fresh challenge", + "cannot load domain for retry tracking", log.String("domain", domain.Domain), + log.Error(loadErr), + ) + return loadErr + } + + fullDomain.SSLRetryCount++ + now := time.Now() + fullDomain.SSLLastAttemptAt = &now + + const maxRetries = 3 + if fullDomain.SSLRetryCount >= maxRetries { + p.logger.ErrorCtx( + ctx, + "domain has exceeded max retry attempts, marking as failed", + log.String("domain", domain.Domain), + log.Int("retry_count", fullDomain.SSLRetryCount), ) - if resetErr := p.resetDomainToRetry(ctx, conn, domain); resetErr != nil { + fullDomain.SSLStatus = coredata.CustomDomainSSLStatusFailed + fullDomain.HTTPChallengeToken = nil + fullDomain.HTTPChallengeKeyAuth = nil + fullDomain.HTTPChallengeURL = nil + fullDomain.HTTPOrderURL = nil + + if updateErr := fullDomain.Update(ctx, conn, coredata.NewNoScope(), p.encryptionKey); updateErr != nil { p.logger.ErrorCtx( ctx, - "cannot reset domain for retry", + "cannot mark domain as failed", log.String("domain", domain.Domain), - log.Error(resetErr), + log.Error(updateErr), ) - return resetErr + return updateErr } - p.logger.InfoCtx( - ctx, - "domain reset to pending, will retry with new challenge on next cycle", - log.String("domain", domain.Domain), - ) + return nil } + p.logger.InfoCtx( + ctx, + "resetting domain to retry with fresh challenge", + log.String("domain", domain.Domain), + log.Int("retry_count", fullDomain.SSLRetryCount), + ) + + fullDomain.HTTPChallengeToken = nil + fullDomain.HTTPChallengeKeyAuth = nil + fullDomain.HTTPChallengeURL = nil + fullDomain.HTTPOrderURL = nil + fullDomain.SSLStatus = coredata.CustomDomainSSLStatusPending + + if updateErr := fullDomain.Update(ctx, conn, coredata.NewNoScope(), p.encryptionKey); updateErr != nil { + p.logger.ErrorCtx( + ctx, + "cannot reset domain for retry", + log.String("domain", domain.Domain), + log.Error(updateErr), + ) + return updateErr + } + + p.logger.InfoCtx( + ctx, + "domain reset to pending, will retry with new challenge on next cycle", + log.String("domain", domain.Domain), + ) + return nil } @@ -261,6 +344,9 @@ func (p *Provisioner) provisionDomainCertificate( fullDomain.SSLExpiresAt = &cert.ExpiresAt fullDomain.SSLStatus = coredata.CustomDomainSSLStatusActive + fullDomain.SSLRetryCount = 0 + fullDomain.SSLLastAttemptAt = nil + fullDomain.HTTPChallengeToken = nil fullDomain.HTTPChallengeKeyAuth = nil fullDomain.HTTPChallengeURL = nil diff --git a/pkg/certmanager/renewer.go b/pkg/certmanager/renewer.go index 8916ef97c..50c535f51 100644 --- a/pkg/certmanager/renewer.go +++ b/pkg/certmanager/renewer.go @@ -171,7 +171,65 @@ func (r *Renewer) renewDomain(ctx context.Context, conn pg.Conn, domain *coredat return nil } - return fmt.Errorf("cannot renew certificate: %w", err) + r.logger.WarnCtx( + ctx, + "cannot renew certificate", + log.String("domain", lockedDomain.Domain), + log.Int("retry_count", lockedDomain.SSLRetryCount), + log.Error(err), + ) + + lockedDomain.SSLRetryCount++ + now := time.Now() + lockedDomain.SSLLastAttemptAt = &now + + const maxRetries = 3 + if lockedDomain.SSLRetryCount >= maxRetries { + r.logger.ErrorCtx( + ctx, + "domain has exceeded max renewal retry attempts, marking as failed", + log.String("domain", lockedDomain.Domain), + log.Int("retry_count", lockedDomain.SSLRetryCount), + ) + + lockedDomain.SSLStatus = coredata.CustomDomainSSLStatusFailed + lockedDomain.HTTPChallengeToken = nil + lockedDomain.HTTPChallengeKeyAuth = nil + lockedDomain.HTTPChallengeURL = nil + lockedDomain.HTTPOrderURL = nil + + if updateErr := lockedDomain.Update(ctx, conn, coredata.NewNoScope(), r.encryptionKey); updateErr != nil { + r.logger.ErrorCtx( + ctx, + "cannot mark domain as failed", + log.String("domain", lockedDomain.Domain), + log.Error(updateErr), + ) + return updateErr + } + + return nil + } + + // Update retry tracking but keep domain ACTIVE for next renewal cycle + if updateErr := lockedDomain.Update(ctx, conn, coredata.NewNoScope(), r.encryptionKey); updateErr != nil { + r.logger.ErrorCtx( + ctx, + "cannot update domain retry tracking", + log.String("domain", lockedDomain.Domain), + log.Error(updateErr), + ) + return updateErr + } + + r.logger.InfoCtx( + ctx, + "domain will retry renewal on next cycle", + log.String("domain", lockedDomain.Domain), + log.Int("retry_count", lockedDomain.SSLRetryCount), + ) + + return nil } r.logger.InfoCtx( @@ -190,6 +248,9 @@ func (r *Renewer) renewDomain(ctx context.Context, conn pg.Conn, domain *coredat lockedDomain.SSLExpiresAt = &cert.ExpiresAt lockedDomain.SSLStatus = coredata.CustomDomainSSLStatusActive + lockedDomain.SSLRetryCount = 0 + lockedDomain.SSLLastAttemptAt = nil + lockedDomain.HTTPChallengeToken = nil lockedDomain.HTTPChallengeKeyAuth = nil lockedDomain.HTTPChallengeURL = nil diff --git a/pkg/coredata/custom_domain.go b/pkg/coredata/custom_domain.go index 3b2659855..9aed48866 100644 --- a/pkg/coredata/custom_domain.go +++ b/pkg/coredata/custom_domain.go @@ -42,6 +42,8 @@ type ( SSLCertificateChain *string `db:"ssl_certificate_chain"` SSLStatus CustomDomainSSLStatus `db:"ssl_status"` SSLExpiresAt *time.Time `db:"ssl_expires_at"` + SSLRetryCount int `db:"ssl_retry_count"` + SSLLastAttemptAt *time.Time `db:"ssl_last_attempt_at"` CreatedAt time.Time `db:"created_at"` UpdatedAt time.Time `db:"updated_at"` } @@ -149,6 +151,8 @@ SELECT ssl_certificate_chain, ssl_status, ssl_expires_at, + ssl_retry_count, + ssl_last_attempt_at, created_at, updated_at FROM @@ -199,6 +203,8 @@ SELECT ssl_certificate_chain, ssl_status, ssl_expires_at, + ssl_retry_count, + ssl_last_attempt_at, created_at, updated_at FROM @@ -249,6 +255,8 @@ SELECT ssl_certificate_chain, ssl_status, ssl_expires_at, + ssl_retry_count, + ssl_last_attempt_at, created_at, updated_at FROM @@ -304,6 +312,8 @@ INSERT INTO custom_domains ( ssl_certificate_chain, ssl_status, ssl_expires_at, + ssl_retry_count, + ssl_last_attempt_at, created_at, updated_at ) VALUES ( @@ -319,6 +329,8 @@ INSERT INTO custom_domains ( @ssl_certificate_chain, @ssl_status, @ssl_expires_at, + @ssl_retry_count, + @ssl_last_attempt_at, @created_at, @updated_at ) @@ -337,6 +349,8 @@ INSERT INTO custom_domains ( "ssl_certificate_chain": cd.SSLCertificateChain, "ssl_status": cd.SSLStatus, "ssl_expires_at": cd.SSLExpiresAt, + "ssl_retry_count": cd.SSLRetryCount, + "ssl_last_attempt_at": cd.SSLLastAttemptAt, "created_at": cd.CreatedAt, "updated_at": cd.UpdatedAt, } @@ -375,6 +389,8 @@ SET ssl_certificate_chain = @ssl_certificate_chain, ssl_status = @ssl_status, ssl_expires_at = @ssl_expires_at, + ssl_retry_count = @ssl_retry_count, + ssl_last_attempt_at = @ssl_last_attempt_at, updated_at = @updated_at WHERE %s @@ -394,6 +410,8 @@ WHERE "ssl_certificate_chain": cd.SSLCertificateChain, "ssl_status": cd.SSLStatus, "ssl_expires_at": cd.SSLExpiresAt, + "ssl_retry_count": cd.SSLRetryCount, + "ssl_last_attempt_at": cd.SSLLastAttemptAt, "updated_at": time.Now(), } maps.Copy(args, scope.SQLArguments()) @@ -453,6 +471,8 @@ SELECT ssl_certificate_chain, ssl_status, ssl_expires_at, + ssl_retry_count, + ssl_last_attempt_at, created_at, updated_at FROM @@ -501,6 +521,8 @@ SELECT ssl_certificate_chain, ssl_status, ssl_expires_at, + ssl_retry_count, + ssl_last_attempt_at, created_at, updated_at FROM @@ -551,6 +573,8 @@ SELECT ssl_certificate_chain, ssl_status, ssl_expires_at, + ssl_retry_count, + ssl_last_attempt_at, created_at, updated_at FROM @@ -604,6 +628,8 @@ SELECT ssl_certificate_chain, ssl_status, ssl_expires_at, + ssl_retry_count, + ssl_last_attempt_at, created_at, updated_at FROM @@ -632,3 +658,62 @@ WHERE *domains = result return nil } + +func (domains *CustomDomains) ListStaleProvisioningDomains( + ctx context.Context, + conn pg.Conn, + scope Scoper, +) error { + q := ` +SELECT + id, + domain, + http_challenge_token, + http_challenge_key_auth, + http_challenge_url, + http_order_url, + ssl_certificate, + encrypted_ssl_private_key, + ssl_certificate_chain, + ssl_status, + ssl_expires_at, + ssl_retry_count, + ssl_last_attempt_at, + created_at, + updated_at +FROM + custom_domains +WHERE + %s + AND ( + (ssl_status IN (@provisioning_status, @renewing_status) AND updated_at < CURRENT_TIMESTAMP - INTERVAL '4 hours') + OR + (ssl_retry_count > 0 AND ssl_last_attempt_at < CURRENT_TIMESTAMP - INTERVAL '24 hours') + ) + AND ssl_status != @failed_status + AND ssl_status != @active_status +` + + q = fmt.Sprintf(q, scope.SQLFragment()) + + args := pgx.NamedArgs{ + "provisioning_status": string(CustomDomainSSLStatusProvisioning), + "renewing_status": string(CustomDomainSSLStatusRenewing), + "failed_status": string(CustomDomainSSLStatusFailed), + "active_status": string(CustomDomainSSLStatusActive), + } + maps.Copy(args, scope.SQLArguments()) + + rows, err := conn.Query(ctx, q, args) + if err != nil { + return fmt.Errorf("cannot query stale provisioning domains: %w", err) + } + + result, err := pgx.CollectRows(rows, pgx.RowToAddrOfStructByName[CustomDomain]) + if err != nil { + return fmt.Errorf("cannot collect stale provisioning domains: %w", err) + } + + *domains = result + return nil +} diff --git a/pkg/coredata/migrations/20251014T120000Z.sql b/pkg/coredata/migrations/20251014T120000Z.sql new file mode 100644 index 000000000..f5fa07c7c --- /dev/null +++ b/pkg/coredata/migrations/20251014T120000Z.sql @@ -0,0 +1,8 @@ +-- Add retry tracking fields for SSL certificate provisioning +ALTER TABLE custom_domains ADD COLUMN ssl_retry_count INTEGER NOT NULL DEFAULT 0; +ALTER TABLE custom_domains ADD COLUMN ssl_last_attempt_at TIMESTAMP; + +-- Add index to efficiently find stale provisioning attempts +CREATE INDEX idx_custom_domains_ssl_last_attempt + ON custom_domains(ssl_last_attempt_at, ssl_status) + WHERE ssl_status IN ('PENDING', 'PROVISIONING', 'RENEWING');