Add internal property to ACME challenge error response logs

acme/challenge.go

@@ -22,19 +22,20 @@ import (
 	"net"
 	"net/url"
 	"reflect"
+	"slices"
 	"strconv"
 	"strings"
 	"time"
 
 	"github.com/coreos/go-oidc/v3/oidc"
 	"github.com/fxamacker/cbor/v2"
 	"github.com/google/go-tpm/legacy/tpm2"
+
 	"github.com/smallstep/go-attestation/attest"
 	"go.step.sm/crypto/jose"
 	"go.step.sm/crypto/keyutil"
 	"go.step.sm/crypto/pemutil"
 	"go.step.sm/crypto/x509util"
-	"golang.org/x/exp/slices"
 
 	"github.com/smallstep/certificates/acme/wire"
 	"github.com/smallstep/certificates/authority/provisioner"
@@ -95,10 +96,28 @@ type Challenge struct {
 
 // ToLog enables response logging.
 func (ch *Challenge) ToLog() (interface{}, error) {
-	b, err := json.Marshal(ch)
+	type Record struct {
+		Type        ChallengeType `json:"type"`
+		Status      Status        `json:"status"`
+		Token       string        `json:"token"`
+		ValidatedAt string        `json:"validated,omitempty"`
+		URL         string        `json:"url"`
+		Target      string        `json:"target,omitempty"`
+		Error       errorRecord   `json:"error,omitempty"`
+	}
+	b, err := json.Marshal(Record{
+		Type:        ch.Type,
+		Status:      ch.Status,
+		Token:       ch.Token,
+		ValidatedAt: ch.ValidatedAt,
+		URL:         ch.URL,
+		Target:      ch.Target,
+		Error:       newErrorRecord(ch.Error),
+	})
 	if err != nil {
 		return nil, WrapErrorISE(err, "error marshaling challenge for logging")
 	}
+
 	return string(b), nil
 }
 

acme/challenge_test.go

@@ -31,16 +31,18 @@ import (
 	"time"
 
 	"github.com/fxamacker/cbor/v2"
-	"github.com/smallstep/certificates/authority/config"
-	"github.com/smallstep/certificates/authority/provisioner"
-	wireprovisioner "github.com/smallstep/certificates/authority/provisioner/wire"
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
+
 	"go.step.sm/crypto/jose"
 	"go.step.sm/crypto/keyutil"
 	"go.step.sm/crypto/minica"
 	"go.step.sm/crypto/pemutil"
 	"go.step.sm/crypto/x509util"
+
+	"github.com/smallstep/certificates/authority/config"
+	"github.com/smallstep/certificates/authority/provisioner"
+	wireprovisioner "github.com/smallstep/certificates/authority/provisioner/wire"
 )
 
 type mockClient struct {
@@ -5158,3 +5160,101 @@ func Test_dns01ChallengeHost(t *testing.T) {
 		})
 	}
 }
+
+func TestChallengeLogsResponses(t *testing.T) {
+	t.Parallel()
+
+	t.Run("ok", func(t *testing.T) {
+		t.Parallel()
+
+		ch := &Challenge{
+			Type:        HTTP01,
+			Status:      StatusPending,
+			Token:       "token",
+			ValidatedAt: "",
+			URL:         "http://test.example.com/.well-known/acme-challenge/identifier",
+			Target:      "target",
+			Error:       newError(ErrorConnectionType, errors.New("timeout")),
+		}
+
+		v, err := ch.ToLog()
+		require.NoError(t, err)
+		require.NotNil(t, v)
+		require.IsType(t, "string", v)
+
+		m := map[string]any{
+			"type":   "http-01",
+			"status": "pending",
+			"url":    "http://test.example.com/.well-known/acme-challenge/identifier",
+			"target": "target",
+			"token":  "token",
+			"error": map[string]any{
+				"type":     "urn:ietf:params:acme:error:connection",
+				"detail":   "The server could not connect to validation target",
+				"internal": "timeout",
+			},
+		}
+
+		exp, err := json.Marshal(m)
+		require.NoError(t, err)
+
+		assert.JSONEq(t, string(exp), v.(string))
+	})
+
+	t.Run("subproblem", func(t *testing.T) {
+		t.Parallel()
+
+		e := newError(ErrorConnectionType, errors.New("timeout"))
+		s1 := NewSubproblem(ErrorConnectionType, "sub-timeout")
+		s1.Identifier = &Identifier{Type: DNS, Value: "test.example.com"}
+		s2 := NewSubproblem(ErrorMalformedType, "sub-malformed")
+		e.AddSubproblems(s1, s2)
+
+		ch := &Challenge{
+			Type:        HTTP01,
+			Status:      StatusPending,
+			Token:       "token",
+			ValidatedAt: "",
+			URL:         "http://test.example.com/.well-known/acme-challenge/identifier",
+			Target:      "target",
+			Error:       e,
+		}
+
+		v, err := ch.ToLog()
+		require.NoError(t, err)
+		require.NotNil(t, v)
+		require.IsType(t, "string", v)
+
+		m := map[string]any{
+			"type":   "http-01",
+			"status": "pending",
+			"url":    "http://test.example.com/.well-known/acme-challenge/identifier",
+			"target": "target",
+			"token":  "token",
+			"error": map[string]any{
+				"type":   "urn:ietf:params:acme:error:connection",
+				"detail": "The server could not connect to validation target",
+				"subproblems": []map[string]any{
+					map[string]any{
+						"detail": "sub-timeout",
+						"type":   "urn:ietf:params:acme:error:connection",
+						"identifier": map[string]any{
+							"type":  "dns",
+							"value": "test.example.com",
+						},
+					},
+					map[string]any{
+						"detail": "sub-malformed",
+						"type":   "urn:ietf:params:acme:error:malformed",
+					},
+				},
+				"internal": "timeout",
+			},
+		}
+
+		exp, err := json.Marshal(m)
+		require.NoError(t, err)
+
+		assert.JSONEq(t, string(exp), v.(string))
+	})
+}

acme/errors.go

@@ -6,6 +6,7 @@ import (
 	"net/http"
 
 	"github.com/pkg/errors"
+
 	"github.com/smallstep/certificates/api/render"
 )
 
@@ -428,3 +429,26 @@ func (e *Error) Render(w http.ResponseWriter, r *http.Request) {
 	w.Header().Set("Content-Type", "application/problem+json")
 	render.JSONStatus(w, r, e, e.StatusCode())
 }
+
+type errorRecord = map[string]any
+
+func newErrorRecord(e *Error) errorRecord {
+	if e == nil {
+		return nil
+	}
+
+	m := errorRecord{
+		"type":   e.Type,
+		"detail": e.Detail,
+	}
+
+	if len(e.Subproblems) > 0 { // replicate omitempty
+		m["subproblems"] = e.Subproblems
+	}
+
+	if e.Err != nil { // replicate omitempty
+		m["internal"] = e.Err.Error()
+	}
+
+	return m
+}

acme/errors_test.go

@@ -2,6 +2,7 @@ package acme
 
 import (
 	"encoding/json"
+	"errors"
 	"testing"
 
 	"github.com/stretchr/testify/assert"
@@ -52,3 +53,59 @@ func TestError_WithAdditionalErrorDetail(t *testing.T) {
 		})
 	}
 }
+
+func Test_newErrorRecordCreatesErrorRecords(t *testing.T) {
+	t.Parallel()
+
+	t.Run("nil", func(t *testing.T) {
+		t.Parallel()
+
+		got := newErrorRecord(nil)
+		assert.Nil(t, got)
+	})
+
+	t.Run("ok", func(t *testing.T) {
+		t.Parallel()
+
+		exp := map[string]any{
+			"type":     "urn:ietf:params:acme:error:malformed",
+			"detail":   "The request message was malformed",
+			"internal": "fail",
+		}
+		expBytes, err := json.Marshal(exp)
+		require.NoError(t, err)
+
+		got := newErrorRecord(newError(ErrorMalformedType, errors.New("fail")))
+
+		gotBytes, err := json.Marshal(got)
+		require.NoError(t, err)
+
+		assert.JSONEq(t, string(expBytes), string(gotBytes))
+	})
+
+	t.Run("subproblems", func(t *testing.T) {
+		t.Parallel()
+
+		s1 := NewSubproblem(ErrorMalformedType, "first-subproblem-msg")
+		s1.Identifier = &Identifier{Type: DNS, Value: "test.example.com"}
+		s2 := NewSubproblem(ErrorMalformedType, "second-subproblem-msg")
+		e := newError(ErrorMalformedType, errors.New("fail"))
+		e.AddSubproblems(s1, s2)
+
+		exp := map[string]any{
+			"type":        "urn:ietf:params:acme:error:malformed",
+			"detail":      "The request message was malformed",
+			"subproblems": []Subproblem{s1, s2},
+			"internal":    "fail",
+		}
+		expBytes, err := json.Marshal(exp)
+		require.NoError(t, err)
+
+		got := newErrorRecord(e)
+
+		gotBytes, err := json.Marshal(got)
+		require.NoError(t, err)
+
+		assert.JSONEq(t, string(expBytes), string(gotBytes))
+	})
+}