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 <ludovic@probo.com>
This commit is contained in:
Ludovic Vielle
2026-07-22 15:50:09 +02:00
parent 6313278c0d
commit cbd0387490
4 changed files with 99 additions and 32 deletions

View File

@@ -147,11 +147,9 @@ func (s *ACMEService) InCooldown() bool {
s.cooldownMu.RLock() s.cooldownMu.RLock()
defer s.cooldownMu.RUnlock() defer s.cooldownMu.RUnlock()
active := time.Now().Before(s.cooldownUntil) s.metrics.setCooldown(s.cooldownUntil)
s.metrics.setCooldown(active) return time.Now().Before(s.cooldownUntil)
return active
} }
func (s *ACMEService) CooldownUntil() time.Time { func (s *ACMEService) CooldownUntil() time.Time {
@@ -169,7 +167,7 @@ func (s *ACMEService) enterCooldown(until time.Time) {
s.cooldownUntil = until s.cooldownUntil = until
} }
s.metrics.setCooldown(time.Now().Before(s.cooldownUntil)) s.metrics.setCooldown(s.cooldownUntil)
} }
func (s *ACMEService) registerAccount(ctx context.Context) error { func (s *ACMEService) registerAccount(ctx context.Context) error {

View File

@@ -26,6 +26,7 @@ import (
"math" "math"
"net/http" "net/http"
"strconv" "strconv"
"strings"
"time" "time"
"golang.org/x/crypto/acme" "golang.org/x/crypto/acme"
@@ -42,18 +43,18 @@ var (
type ACMEError struct { type ACMEError struct {
op string op string
err error err error
statusCode int
problemType string problemType string
detail string detail string
instance string
header http.Header
subproblems string
rateLimited bool rateLimited bool
retryAfter time.Duration retryAfter time.Duration
retryAfterSet bool retryAfterSet bool
} }
func (e *ACMEError) Error() string { func (e *ACMEError) Error() string {
if e == nil {
return ""
}
if e.err != nil { if e.err != nil {
return fmt.Sprintf("%s: %v", e.op, e.err) return fmt.Sprintf("%s: %v", e.op, e.err)
} }
@@ -62,10 +63,6 @@ func (e *ACMEError) Error() string {
} }
func (e *ACMEError) Unwrap() error { func (e *ACMEError) Unwrap() error {
if e == nil {
return nil
}
return e.err return e.err
} }
@@ -74,7 +71,7 @@ func (e *ACMEError) Is(target error) bool {
} }
func (e *ACMEError) RetryAfter() time.Duration { func (e *ACMEError) RetryAfter() time.Duration {
if e == nil || !e.rateLimited { if !e.rateLimited {
return 0 return 0
} }
@@ -89,20 +86,32 @@ func (e *ACMEError) RetryAfter() time.Duration {
return defaultCooldown return defaultCooldown
} }
func (e *ACMEError) ProblemType() string { func (e *ACMEError) StatusCode() int {
if e == nil { return e.statusCode
return "" }
}
func (e *ACMEError) ProblemType() string {
return e.problemType return e.problemType
} }
func (e *ACMEError) Detail() string { 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 ""
} }
return e.detail return e.header.Get("Link")
}
func (e *ACMEError) Subproblems() string {
return e.subproblems
} }
func newACMEError(op string, err error) *ACMEError { func newACMEError(op string, err error) *ACMEError {
@@ -121,8 +130,12 @@ func newACMEError(op string, err error) *ACMEError {
return out return out
} }
out.statusCode = acmeErr.StatusCode
out.problemType = acmeErr.ProblemType out.problemType = acmeErr.ProblemType
out.detail = acmeErr.Detail out.detail = acmeErr.Detail
out.instance = acmeErr.Instance
out.header = acmeErr.Header
out.subproblems = formatACMESubproblems(acmeErr.Subproblems)
if _, ok := acme.RateLimit(acmeErr); ok { if _, ok := acme.RateLimit(acmeErr); ok {
out.rateLimited = true out.rateLimited = true
@@ -136,6 +149,30 @@ func newACMEError(op string, err error) *ACMEError {
return out 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 // parseRetryAfter reports the Retry-After delay and whether the header was
// present and parseable. It mirrors the delta-seconds and HTTP-date forms the // 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 // ACME client understands. An absent or unparseable value returns ok=false so

View File

@@ -47,10 +47,11 @@ const (
) )
type metrics struct { type metrics struct {
provisionSteps *prometheus.CounterVec provisionSteps *prometheus.CounterVec
acmeErrors *prometheus.CounterVec acmeErrors *prometheus.CounterVec
acmeCooldown prometheus.Gauge acmeCooldown prometheus.Gauge
stepDuration *prometheus.HistogramVec acmeCooldownUntil prometheus.Gauge
stepDuration *prometheus.HistogramVec
} }
func newMetrics(registerer prometheus.Registerer) *metrics { 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( stepDuration: registerCollector(
registerer, registerer,
prometheus.NewHistogramVec( prometheus.NewHistogramVec(
@@ -173,11 +184,14 @@ func normalizeProblemType(problemType string) string {
return suffix return suffix
} }
func (m *metrics) setCooldown(active bool) { func (m *metrics) setCooldown(until time.Time) {
if active { if time.Now().Before(until) {
m.acmeCooldown.Set(1) m.acmeCooldown.Set(1)
m.acmeCooldownUntil.Set(float64(until.Unix()))
return return
} }
m.acmeCooldown.Set(0) m.acmeCooldown.Set(0)
m.acmeCooldownUntil.Set(0)
} }

View File

@@ -693,12 +693,25 @@ func (h *provisionHandler) logACMEOutcome(
errorCode string, errorCode string,
) { ) {
var ( var (
statusCode int
problemType string problemType string
detail string detail string
instance string
link string
subproblems string
retryAfter time.Duration
) )
if acmeErr, ok := errors.AsType[*ACMEError](err); ok { if acmeErr, ok := errors.AsType[*ACMEError](err); ok {
statusCode = acmeErr.StatusCode()
problemType = acmeErr.ProblemType() problemType = acmeErr.ProblemType()
detail = acmeErr.Detail() detail = acmeErr.Detail()
instance = acmeErr.Instance()
link = acmeErr.Link()
subproblems = acmeErr.Subproblems()
if errors.Is(acmeErr, ErrACMERateLimited) {
retryAfter = acmeErr.RetryAfter()
}
} }
level := h.logger.WarnCtx level := h.logger.WarnCtx
@@ -710,14 +723,19 @@ func (h *provisionHandler) logACMEOutcome(
level( level(
ctx, ctx,
"certificate provisioning step failed", "certificate provisioning step failed",
log.String("hostname", certificate.Hostname), log.String("acme_hostname", certificate.Hostname),
log.String("certificate_id", certificate.ID.String()), log.String("acme_certificate_id", certificate.ID.String()),
log.String("phase", string(phase)), log.String("acme_phase", string(phase)),
log.String("error_code", errorCode), log.String("acme_error_code", errorCode),
log.Int("acme_status_code", statusCode),
log.String("acme_problem_type", problemType), log.String("acme_problem_type", problemType),
log.String("acme_detail", detail), log.String("acme_detail", detail),
log.Int("retry_count", certificate.SSLRetryCount), log.String("acme_instance", instance),
log.Time("cool_down_until", h.acmeService.CooldownUntil()), 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), log.Error(err),
) )
} }