caddytls: Log error if ask request fails

Errors returned from the DecisionFunc (whether to get a cert on-demand)
are used as a signal whether to allow a cert or not; *any* error
will forbid cert issuance.

We bubble up the error all the way to the caller, but that caller is the
Go standard library which might gobble it up.
Now we explicitly log connection errors so sysadmins can
ensure their ask endpoints are working.

Thanks to our sponsor AppCove for reporting this!

2 files changed, 37 insertions, 24 deletions

diff --git a/modules/caddytls/acmeissuer.go b/modules/caddytls/acmeissuer.go
index 9552d6f..2fe4004 100644
--- a/modules/caddytls/acmeissuer.go
+++ b/modules/caddytls/acmeissuer.go
@@ -17,6 +17,7 @@ package caddytls
 import (
 	"context"
 	"crypto/x509"
+	"errors"
 	"fmt"
 	"net/url"
 	"os"
@@ -250,28 +251,27 @@ func (iss *ACMEIssuer) GetACMEIssuer() *ACMEIssuer { return iss }
 
 // UnmarshalCaddyfile deserializes Caddyfile tokens into iss.
 //
-//     ... acme [<directory_url>] {
-//         dir <directory_url>
-//         test_dir <test_directory_url>
-//         email <email>
-//         timeout <duration>
-//         disable_http_challenge
-//         disable_tlsalpn_challenge
-//         alt_http_port    <port>
-//         alt_tlsalpn_port <port>
-//         eab <key_id> <mac_key>
-//         trusted_roots <pem_files...>
-//         dns <provider_name> [<options>]
-//         propagation_delay <duration>
-//         propagation_timeout <duration>
-//         resolvers <dns_servers...>
-//         dns_challenge_override_domain <domain>
-//         preferred_chains [smallest] {
-//             root_common_name <common_names...>
-//             any_common_name  <common_names...>
-//         }
-//     }
-//
+//	... acme [<directory_url>] {
+//	    dir <directory_url>
+//	    test_dir <test_directory_url>
+//	    email <email>
+//	    timeout <duration>
+//	    disable_http_challenge
+//	    disable_tlsalpn_challenge
+//	    alt_http_port    <port>
+//	    alt_tlsalpn_port <port>
+//	    eab <key_id> <mac_key>
+//	    trusted_roots <pem_files...>
+//	    dns <provider_name> [<options>]
+//	    propagation_delay <duration>
+//	    propagation_timeout <duration>
+//	    resolvers <dns_servers...>
+//	    dns_challenge_override_domain <domain>
+//	    preferred_chains [smallest] {
+//	        root_common_name <common_names...>
+//	        any_common_name  <common_names...>
+//	    }
+//	}
 func (iss *ACMEIssuer) UnmarshalCaddyfile(d *caddyfile.Dispenser) error {
 	for d.Next() {
 		if d.NextArg() {
@@ -494,8 +494,7 @@ func onDemandAskRequest(ask string, name string) error {
 	resp.Body.Close()
 
 	if resp.StatusCode < 200 || resp.StatusCode > 299 {
-		return fmt.Errorf("certificate for hostname '%s' not allowed; non-2xx status code %d returned from %v",
-			name, resp.StatusCode, ask)
+		return fmt.Errorf("%s: %w %s - non-2xx status code %d", name, errAskDenied, ask, resp.StatusCode)
 	}
 
 	return nil
@@ -568,6 +567,11 @@ type ChainPreference struct {
 	AnyCommonName []string `json:"any_common_name,omitempty"`
 }
 
+// errAskDenied is an error that should be wrapped or returned when the
+// configured "ask" endpoint does not allow a certificate to be issued,
+// to distinguish that from other errors such as connection failure.
+var errAskDenied = errors.New("certificate not allowed by ask endpoint")
+
 // Interface guards
 var (
 	_ certmagic.PreChecker  = (*ACMEIssuer)(nil)
diff --git a/modules/caddytls/automation.go b/modules/caddytls/automation.go
index ee168b4..0a732b8 100644
--- a/modules/caddytls/automation.go
+++ b/modules/caddytls/automation.go
@@ -16,6 +16,7 @@ package caddytls
 
 import (
 	"encoding/json"
+	"errors"
 	"fmt"
 	"net/http"
 	"time"
@@ -23,6 +24,7 @@ import (
 	"github.com/caddyserver/caddy/v2"
 	"github.com/caddyserver/certmagic"
 	"github.com/mholt/acmez"
+	"go.uber.org/zap"
 )
 
 // AutomationConfig governs the automated management of TLS certificates.
@@ -174,6 +176,13 @@ func (ap *AutomationPolicy) Provision(tlsApp *TLS) error {
 					tlsApp.Automation.OnDemand.Ask != "" {
 					err := onDemandAskRequest(tlsApp.Automation.OnDemand.Ask, name)
 					if err != nil {
+						// distinguish true errors from denials, because it's important to log actual errors
+						if !errors.Is(err, errAskDenied) {
+							tlsApp.logger.Error("request to 'ask' endpoint failed",
+								zap.Error(err),
+								zap.String("endpoint", tlsApp.Automation.OnDemand.Ask),
+								zap.String("domain", name))
+						}
 						return err
 					}
 				}