From 2108c5186dae53a1e69947828aa2342a73c3fc62 Mon Sep 17 00:00:00 2001 From: Herman Slatman Date: Thu, 27 Mar 2025 11:09:45 +0100 Subject: [PATCH] Add `internal` property to ACME error response logs --- acme/challenge.go | 23 ++++++++- acme/challenge_test.go | 106 +++++++++++++++++++++++++++++++++++++++-- acme/errors.go | 24 ++++++++++ acme/errors_test.go | 57 ++++++++++++++++++++++ 4 files changed, 205 insertions(+), 5 deletions(-) diff --git a/acme/challenge.go b/acme/challenge.go index df81ecd2a..7bfbdba38 100644 --- a/acme/challenge.go +++ b/acme/challenge.go @@ -22,6 +22,7 @@ import ( "net" "net/url" "reflect" + "slices" "strconv" "strings" "time" @@ -29,12 +30,12 @@ import ( "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 } diff --git a/acme/challenge_test.go b/acme/challenge_test.go index f0c7ae28f..2ed523fef 100644 --- a/acme/challenge_test.go +++ b/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)) + }) +} diff --git a/acme/errors.go b/acme/errors.go index 3c5fdb8d1..cae354520 100644 --- a/acme/errors.go +++ b/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 +} diff --git a/acme/errors_test.go b/acme/errors_test.go index 8e586a127..680e718c8 100644 --- a/acme/errors_test.go +++ b/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)) + }) +}