From cbd038749006d70c9027d058f4059ca29595e748 Mon Sep 17 00:00:00 2001 From: Ludovic Vielle Date: Wed, 22 Jul 2026 15:50:09 +0200 Subject: [PATCH] Expose ACME cooldown end time and error details Operators could see that a rate-limit cooldown was active, but not when it ends, and failure logs omitted most of the CA problem document. Add a until-timestamp gauge and log the full acme.Error surface so cooldowns and ACME responses are diagnosable. Signed-off-by: Ludovic Vielle --- pkg/certmanager/acme.go | 8 ++-- pkg/certmanager/acme_errors.go | 67 ++++++++++++++++++++++------- pkg/certmanager/metrics.go | 26 ++++++++--- pkg/certmanager/provision_worker.go | 30 ++++++++++--- 4 files changed, 99 insertions(+), 32 deletions(-) diff --git a/pkg/certmanager/acme.go b/pkg/certmanager/acme.go index 72753ecc6..53a92435e 100644 --- a/pkg/certmanager/acme.go +++ b/pkg/certmanager/acme.go @@ -147,11 +147,9 @@ func (s *ACMEService) InCooldown() bool { s.cooldownMu.RLock() defer s.cooldownMu.RUnlock() - active := time.Now().Before(s.cooldownUntil) + s.metrics.setCooldown(s.cooldownUntil) - s.metrics.setCooldown(active) - - return active + return time.Now().Before(s.cooldownUntil) } func (s *ACMEService) CooldownUntil() time.Time { @@ -169,7 +167,7 @@ func (s *ACMEService) enterCooldown(until time.Time) { s.cooldownUntil = until } - s.metrics.setCooldown(time.Now().Before(s.cooldownUntil)) + s.metrics.setCooldown(s.cooldownUntil) } func (s *ACMEService) registerAccount(ctx context.Context) error { diff --git a/pkg/certmanager/acme_errors.go b/pkg/certmanager/acme_errors.go index 75feee026..376db2d1a 100644 --- a/pkg/certmanager/acme_errors.go +++ b/pkg/certmanager/acme_errors.go @@ -26,6 +26,7 @@ import ( "math" "net/http" "strconv" + "strings" "time" "golang.org/x/crypto/acme" @@ -42,18 +43,18 @@ var ( type ACMEError struct { op string err error + statusCode int problemType string detail string + instance string + header http.Header + subproblems string rateLimited bool retryAfter time.Duration retryAfterSet bool } func (e *ACMEError) Error() string { - if e == nil { - return "" - } - if e.err != nil { return fmt.Sprintf("%s: %v", e.op, e.err) } @@ -62,10 +63,6 @@ func (e *ACMEError) Error() string { } func (e *ACMEError) Unwrap() error { - if e == nil { - return nil - } - return e.err } @@ -74,7 +71,7 @@ func (e *ACMEError) Is(target error) bool { } func (e *ACMEError) RetryAfter() time.Duration { - if e == nil || !e.rateLimited { + if !e.rateLimited { return 0 } @@ -89,20 +86,32 @@ func (e *ACMEError) RetryAfter() time.Duration { return defaultCooldown } -func (e *ACMEError) ProblemType() string { - if e == nil { - return "" - } +func (e *ACMEError) StatusCode() int { + return e.statusCode +} +func (e *ACMEError) ProblemType() string { return e.problemType } func (e *ACMEError) Detail() string { - if e == nil { + return e.detail +} + +func (e *ACMEError) Instance() string { + return e.instance +} + +func (e *ACMEError) Link() string { + if e.header == nil { return "" } - return e.detail + return e.header.Get("Link") +} + +func (e *ACMEError) Subproblems() string { + return e.subproblems } func newACMEError(op string, err error) *ACMEError { @@ -121,8 +130,12 @@ func newACMEError(op string, err error) *ACMEError { return out } + out.statusCode = acmeErr.StatusCode out.problemType = acmeErr.ProblemType out.detail = acmeErr.Detail + out.instance = acmeErr.Instance + out.header = acmeErr.Header + out.subproblems = formatACMESubproblems(acmeErr.Subproblems) if _, ok := acme.RateLimit(acmeErr); ok { out.rateLimited = true @@ -136,6 +149,30 @@ func newACMEError(op string, err error) *ACMEError { return out } +func formatACMESubproblems(subproblems []acme.Subproblem) string { + if len(subproblems) == 0 { + return "" + } + + parts := make([]string, 0, len(subproblems)) + for _, subproblem := range subproblems { + parts = append(parts, formatACMESubproblem(subproblem)) + } + + return strings.Join(parts, "; ") +} + +// formatACMESubproblem mirrors acme.Subproblem.String but also includes +// Instance, which String omits. +func formatACMESubproblem(subproblem acme.Subproblem) string { + formatted := subproblem.String() + if subproblem.Instance == "" { + return formatted + } + + return formatted + " (instance: " + subproblem.Instance + ")" +} + // parseRetryAfter reports the Retry-After delay and whether the header was // present and parseable. It mirrors the delta-seconds and HTTP-date forms the // ACME client understands. An absent or unparseable value returns ok=false so diff --git a/pkg/certmanager/metrics.go b/pkg/certmanager/metrics.go index 0b78abe56..bc66a6f63 100644 --- a/pkg/certmanager/metrics.go +++ b/pkg/certmanager/metrics.go @@ -47,10 +47,11 @@ const ( ) type metrics struct { - provisionSteps *prometheus.CounterVec - acmeErrors *prometheus.CounterVec - acmeCooldown prometheus.Gauge - stepDuration *prometheus.HistogramVec + provisionSteps *prometheus.CounterVec + acmeErrors *prometheus.CounterVec + acmeCooldown prometheus.Gauge + acmeCooldownUntil prometheus.Gauge + stepDuration *prometheus.HistogramVec } func newMetrics(registerer prometheus.Registerer) *metrics { @@ -91,6 +92,16 @@ func newMetrics(registerer prometheus.Registerer) *metrics { }, ), ), + acmeCooldownUntil: registerCollector( + registerer, + prometheus.NewGauge( + prometheus.GaugeOpts{ + Subsystem: "certmanager", + Name: "certificate_acme_cooldown_until_timestamp_seconds", + Help: "Unix timestamp when the global ACME rate-limit cooldown ends; 0 when not cooling down.", + }, + ), + ), stepDuration: registerCollector( registerer, prometheus.NewHistogramVec( @@ -173,11 +184,14 @@ func normalizeProblemType(problemType string) string { return suffix } -func (m *metrics) setCooldown(active bool) { - if active { +func (m *metrics) setCooldown(until time.Time) { + if time.Now().Before(until) { m.acmeCooldown.Set(1) + m.acmeCooldownUntil.Set(float64(until.Unix())) + return } m.acmeCooldown.Set(0) + m.acmeCooldownUntil.Set(0) } diff --git a/pkg/certmanager/provision_worker.go b/pkg/certmanager/provision_worker.go index a0600f5eb..bc86e5f8e 100644 --- a/pkg/certmanager/provision_worker.go +++ b/pkg/certmanager/provision_worker.go @@ -693,12 +693,25 @@ func (h *provisionHandler) logACMEOutcome( errorCode string, ) { var ( + statusCode int problemType string detail string + instance string + link string + subproblems string + retryAfter time.Duration ) if acmeErr, ok := errors.AsType[*ACMEError](err); ok { + statusCode = acmeErr.StatusCode() problemType = acmeErr.ProblemType() detail = acmeErr.Detail() + instance = acmeErr.Instance() + link = acmeErr.Link() + + subproblems = acmeErr.Subproblems() + if errors.Is(acmeErr, ErrACMERateLimited) { + retryAfter = acmeErr.RetryAfter() + } } level := h.logger.WarnCtx @@ -710,14 +723,19 @@ func (h *provisionHandler) logACMEOutcome( level( ctx, "certificate provisioning step failed", - log.String("hostname", certificate.Hostname), - log.String("certificate_id", certificate.ID.String()), - log.String("phase", string(phase)), - log.String("error_code", errorCode), + log.String("acme_hostname", certificate.Hostname), + log.String("acme_certificate_id", certificate.ID.String()), + log.String("acme_phase", string(phase)), + log.String("acme_error_code", errorCode), + log.Int("acme_status_code", statusCode), log.String("acme_problem_type", problemType), log.String("acme_detail", detail), - log.Int("retry_count", certificate.SSLRetryCount), - log.Time("cool_down_until", h.acmeService.CooldownUntil()), + log.String("acme_instance", instance), + log.Duration("acme_retry_after", retryAfter), + log.String("acme_link", link), + log.String("acme_subproblems", subproblems), + log.Int("acme_retry_count", certificate.SSLRetryCount), + log.Time("acme_cooldown_until", h.acmeService.CooldownUntil()), log.Error(err), ) }