Improve problem logging

Also fix panic in rare circumstances: caddyserver/certmagic#152

acme/certificate.go

@@ -111,7 +111,7 @@ func (c *Client) GetCertificateChain(ctx context.Context, account Account, certU
 	// heuristics to decide which is optimal." §7.4.2
 	alternates := extractLinks(resp, "alternate")
 	for _, altURL := range alternates {
-		resp, err = addChain(altURL)
+		_, err = addChain(altURL)
 		if err != nil {
 			return nil, fmt.Errorf("retrieving alternate certificate chain at %s: %w", altURL, err)
 		}

acme/problem.go

@@ -14,7 +14,11 @@
 
 package acme
 
-import "fmt"
+import (
+	"fmt"
+
+	"go.uber.org/zap/zapcore"
+)
 
 // Problem carries the details of an error from HTTP APIs as
 // defined in RFC 7807: https://tools.ietf.org/html/rfc7807
@@ -77,6 +81,9 @@ func (p Problem) Error() string {
 	if len(p.Subproblems) > 0 {
 		for _, v := range p.Subproblems {
 			s += fmt.Sprintf(", problem %q: %s", v.Type, v.Detail)
+			if v.Identifier.Type != "" || v.Identifier.Value != "" {
+				s += fmt.Sprintf(" (%s_identifier=%s)", v.Identifier.Type, v.Identifier.Value)
+			}
 		}
 	}
 	if p.Instance != "" {
@@ -85,6 +92,17 @@ func (p Problem) Error() string {
 	return s
 }
 
+// MarshalLogObject satisfies the zapcore.ObjectMarshaler interface.
+// This allows problems to be serialized by the zap logger.
+func (p Problem) MarshalLogObject(enc zapcore.ObjectEncoder) error {
+	enc.AddString("type", p.Type)
+	enc.AddString("title", p.Title)
+	enc.AddString("detail", p.Detail)
+	enc.AddString("instance", p.Instance)
+	enc.AddArray("subproblems", loggableSubproblems(p.Subproblems))
+	return nil
+}
+
 // Subproblem describes a more specific error in a problem according to
 // RFC 8555 §6.7.1: "An ACME problem document MAY contain the
 // 'subproblems' field, containing a JSON array of problem documents,
@@ -97,6 +115,26 @@ type Subproblem struct {
 	Identifier Identifier `json:"identifier,omitempty"`
 }
 
+// MarshalLogObject satisfies the zapcore.ObjectMarshaler interface.
+// This allows subproblems to be serialized by the zap logger.
+func (sp Subproblem) MarshalLogObject(enc zapcore.ObjectEncoder) error {
+	enc.AddString("identifier_type", sp.Identifier.Type)
+	enc.AddString("identifier", sp.Identifier.Value)
+	enc.AddObject("subproblem", sp.Problem)
+	return nil
+}
+
+type loggableSubproblems []Subproblem
+
+// MarshalLogArray satisfies the zapcore.ArrayMarshaler interface.
+// This allows a list of subproblems to be serialized by the zap logger.
+func (ls loggableSubproblems) MarshalLogArray(enc zapcore.ArrayEncoder) error {
+	for _, sp := range ls {
+		enc.AppendObject(sp)
+	}
+	return nil
+}
+
 // Standard token values for the "type" field of problems, as defined
 // in RFC 8555 §6.7: https://tools.ietf.org/html/rfc8555#section-6.7
 //

client.go

@@ -134,16 +134,23 @@ func (c *Client) ObtainCertificateUsingCSR(ctx context.Context, account acme.Acc
 		// for some errors, we can retry with different challenge types
 		var problem acme.Problem
 		if errors.As(err, &problem) {
-			authz := problem.Resource.(acme.Authorization)
+			authz, haveAuthz := problem.Resource.(acme.Authorization)
 			if c.Logger != nil {
-				c.Logger.Error("validating authorization",
-					zap.String("identifier", authz.IdentifierValue()),
-					zap.Error(err),
+				l := c.Logger
+				if haveAuthz {
+					l = l.With(zap.String("identifier", authz.IdentifierValue()))
+				}
+				l.Error("validating authorization",
+					zap.Object("problem", problem),
 					zap.String("order", order.Location),
 					zap.Int("attempt", attempt),
 					zap.Int("max_attempts", maxAttempts))
 			}
-			err = fmt.Errorf("solving challenge: %s: %w", authz.IdentifierValue(), err)
+			errStr := "solving challenge"
+			if haveAuthz {
+				errStr += ": " + authz.IdentifierValue()
+			}
+			err = fmt.Errorf("%s: %w", errStr, err)
 			if errors.As(err, &retryableErr{}) {
 				continue
 			}
@@ -505,9 +512,7 @@ func (c *Client) pollAuthorization(ctx context.Context, account acme.Account, au
 				c.Logger.Error("challenge failed",
 					zap.String("identifier", authz.IdentifierValue()),
 					zap.String("challenge_type", authz.currentChallenge.Type),
-					zap.Int("status_code", problem.Status),
-					zap.String("problem_type", problem.Type),
-					zap.String("error", problem.Detail))
+					zap.Object("problem", problem))
 			}
 
 			failedChallengeTypes.rememberFailedChallenge(authz)