caddytls: Sync distributed storage cleaning (#5940)

* caddytls: Log out remote addr to detect abuse

* caddytls: Sync distributed storage cleaning

* Handle errors

* Update certmagic to fix tiny bug

* Split off port when logging remote IP

* Upgrade CertMagic

3 files changed, 33 insertions, 16 deletions

diff --git a/modules/caddytls/acmeissuer.go b/modules/caddytls/acmeissuer.go
index 5e79c2d2e..a7dbd26ec 100644
--- a/modules/caddytls/acmeissuer.go
+++ b/modules/caddytls/acmeissuer.go
@@ -16,9 +16,11 @@ package caddytls
 
 import (
 	"context"
+	"crypto/tls"
 	"crypto/x509"
 	"errors"
 	"fmt"
+	"net"
 	"net/url"
 	"os"
 	"strconv"
@@ -496,7 +498,7 @@ func (iss *ACMEIssuer) UnmarshalCaddyfile(d *caddyfile.Dispenser) error {
 // to see if a certificate can be obtained for name.
 // The certificate request should be denied if this
 // returns an error.
-func onDemandAskRequest(logger *zap.Logger, ask string, name string) error {
+func onDemandAskRequest(ctx context.Context, logger *zap.Logger, ask string, name string) error {
 	askURL, err := url.Parse(ask)
 	if err != nil {
 		return fmt.Errorf("parsing ask URL: %v", err)
@@ -513,7 +515,17 @@ func onDemandAskRequest(logger *zap.Logger, ask string, name string) error {
 	}
 	resp.Body.Close()
 
+	// logging out the client IP can be useful for servers that want to count
+	// attempts from clients to detect patterns of abuse
+	var clientIP string
+	if hello, ok := ctx.Value(certmagic.ClientHelloInfoCtxKey).(*tls.ClientHelloInfo); ok && hello != nil {
+		if remote := hello.Conn.RemoteAddr(); remote != nil {
+			clientIP, _, _ = net.SplitHostPort(remote.String())
+		}
+	}
+
 	logger.Debug("response from ask endpoint",
+		zap.String("client_ip", clientIP),
 		zap.String("domain", name),
 		zap.String("url", askURLString),
 		zap.Int("status", resp.StatusCode))
diff --git a/modules/caddytls/automation.go b/modules/caddytls/automation.go
index e331cc701..6d085ee3f 100644
--- a/modules/caddytls/automation.go
+++ b/modules/caddytls/automation.go
@@ -256,7 +256,7 @@ func (ap *AutomationPolicy) Provision(tlsApp *TLS) error {
 				if tlsApp.Automation == nil || tlsApp.Automation.OnDemand == nil {
 					return nil
 				}
-				if err := onDemandAskRequest(tlsApp.logger, tlsApp.Automation.OnDemand.Ask, name); err != nil {
+				if err := onDemandAskRequest(ctx, tlsApp.logger, tlsApp.Automation.OnDemand.Ask, name); err != nil {
 					// distinguish true errors from denials, because it's important to elevate actual errors
 					if errors.Is(err, errAskDenied) {
 						tlsApp.logger.Debug("certificate issuance denied",
diff --git a/modules/caddytls/tls.go b/modules/caddytls/tls.go
index 02d5aae75..b66b09c4d 100644
--- a/modules/caddytls/tls.go
+++ b/modules/caddytls/tls.go
@@ -551,6 +551,10 @@ func (t *TLS) cleanStorageUnits() {
 	storageCleanMu.Lock()
 	defer storageCleanMu.Unlock()
 
+	// TODO: This check might not be needed anymore now that CertMagic syncs
+	// and throttles storage cleaning globally across the cluster.
+	// The original comment below might be outdated:
+	//
 	// If storage was cleaned recently, don't do it again for now. Although the ticker
 	// calling this function drops missed ticks for us, config reloads discard the old
 	// ticker and replace it with a new one, possibly invoking a cleaning to happen again
@@ -563,21 +567,26 @@ func (t *TLS) cleanStorageUnits() {
 		return
 	}
 
+	id, err := caddy.InstanceID()
+	if err != nil {
+		t.logger.Warn("unable to get instance ID; storage clean stamps will be incomplete", zap.Error(err))
+	}
 	options := certmagic.CleanStorageOptions{
+		Logger:                 t.logger,
+		InstanceID:             id.String(),
+		Interval:               t.storageCleanInterval(),
 		OCSPStaples:            true,
 		ExpiredCerts:           true,
 		ExpiredCertGracePeriod: 24 * time.Hour * 14,
 	}
 
-	// avoid cleaning same storage more than once per cleaning cycle
-	storagesCleaned := make(map[string]struct{})
-
 	// start with the default/global storage
-	storage := t.ctx.Storage()
-	storageStr := fmt.Sprintf("%v", storage)
-	t.logger.Info("cleaning storage unit", zap.String("description", storageStr))
-	certmagic.CleanStorage(t.ctx, storage, options)
-	storagesCleaned[storageStr] = struct{}{}
+	err = certmagic.CleanStorage(t.ctx, t.ctx.Storage(), options)
+	if err != nil {
+		// probably don't want to return early, since we should still
+		// see if any other storages can get cleaned up
+		t.logger.Error("could not clean default/global storage", zap.Error(err))
+	}
 
 	// then clean each storage defined in ACME automation policies
 	if t.Automation != nil {
@@ -585,13 +594,9 @@ func (t *TLS) cleanStorageUnits() {
 			if ap.storage == nil {
 				continue
 			}
-			storageStr := fmt.Sprintf("%v", ap.storage)
-			if _, ok := storagesCleaned[storageStr]; ok {
-				continue
+			if err := certmagic.CleanStorage(t.ctx, ap.storage, options); err != nil {
+				t.logger.Error("could not clean storage configured in automation policy", zap.Error(err))
 			}
-			t.logger.Info("cleaning storage unit", zap.String("description", storageStr))
-			certmagic.CleanStorage(t.ctx, ap.storage, options)
-			storagesCleaned[storageStr] = struct{}{}
 		}
 	}