From c7f1a9774a5d8d5600c7e01a55b93df1a46c8623 Mon Sep 17 00:00:00 2001 From: Murad Biashimov Date: Thu, 22 Aug 2024 10:54:45 +0200 Subject: [PATCH] feat: improve logging --- client.go | 45 ++++++++++++------------ error.go | 59 ++++++++++++++++++++++++++------ error_test.go | 94 +++++++++++++++++++++++++++++++++++++++++++++++++++ go.mod | 1 + go.sum | 2 ++ 5 files changed, 167 insertions(+), 34 deletions(-) diff --git a/client.go b/client.go index f69c929..e6855fa 100644 --- a/client.go +++ b/client.go @@ -9,6 +9,7 @@ import ( "fmt" "io" "net/http" + "net/url" "os" "reflect" "strings" @@ -24,6 +25,11 @@ var errTokenIsRequired = errors.New( "token is required. See https://api.aiven.io/doc/#section/Get-started/Authentication", ) +// Doer aka http.Client +type Doer interface { + Do(req *http.Request) (*http.Response, error) +} + // NewClient creates a new Aiven client. func NewClient(opts ...Option) (Client, error) { d := new(aivenClient) @@ -95,10 +101,11 @@ func (d *aivenClient) Do(ctx context.Context, operationID, method, path string, } event.Ctx(ctx). - Stringer("took", end). + Stringer("duration", end). Str("operationID", operationID). Str("method", method). Str("path", path). + Str("query", fmtQuery(query...)). Send() }() } @@ -112,12 +119,7 @@ func (d *aivenClient) Do(ctx context.Context, operationID, method, path string, err = multierror.Append(rsp.Body.Close()).ErrorOrNil() }() - b, err := io.ReadAll(rsp.Body) - if err != nil || rsp.StatusCode < 200 || rsp.StatusCode >= 300 { - return nil, Error{Message: string(b), Status: rsp.StatusCode, MoreInfo: operationID} - } - - return b, err + return fromResponse(operationID, rsp) } func (d *aivenClient) do(ctx context.Context, method, path string, in any, query ...[2]string) (*http.Response, error) { @@ -140,30 +142,27 @@ func (d *aivenClient) do(ctx context.Context, method, path string, in any, query req.Header.Set("Content-Type", "application/json") req.Header.Set("User-Agent", d.UserAgent) req.Header.Set("Authorization", "aivenv1 "+d.Token) + req.URL.RawQuery = fmtQuery(query...) + return d.doer.Do(req) +} + +func isEmpty(a any) bool { + v := reflect.ValueOf(a) + return v.IsZero() || v.Kind() == reflect.Ptr && v.IsNil() +} - q := req.URL.Query() +func fmtQuery(query ...[2]string) string { + q := make(url.Values) for _, v := range query { - q.Set(v[0], v[1]) + q.Add(v[0], v[1]) } if !q.Has("limit") { // TODO: BAD hack to get around pagination in most cases // we should implement this properly at some point but for now // that should be its own issue - q.Set("limit", "999") + q.Add("limit", "999") } - req.URL.RawQuery = q.Encode() - return d.doer.Do(req) -} - -func isEmpty(a any) bool { - v := reflect.ValueOf(a) - - return v.IsZero() || v.Kind() == reflect.Ptr && v.IsNil() -} - -// Doer aka http.Client -type Doer interface { - Do(req *http.Request) (*http.Response, error) + return q.Encode() } diff --git a/error.go b/error.go index a201719..cd2c486 100644 --- a/error.go +++ b/error.go @@ -2,40 +2,77 @@ package aiven import ( + "encoding/json" "errors" "fmt" + "io" "net/http" "strings" ) // Error represents an Aiven API Error. type Error struct { - Message string `json:"message"` - MoreInfo string `json:"more_info"` - Status int `json:"status"` + // Aiven error response fields https://api.aiven.io/doc/#section/Responses/Failed-responses + Message string `json:"message"` + Errors any `json:"errors"` + + // Internal fields + OperationID string `json:"-"` + Status int `json:"-"` } -// Error concatenates the Status, Message and MoreInfo values. +// Error concatenates all the fields. func (e Error) Error() string { - return fmt.Sprintf("%d: %s - %s", e.Status, e.Message, e.MoreInfo) + var errMerged []byte + var err error + errMerged, err = json.Marshal(e.Errors) + if err != nil { + errMerged = []byte(err.Error()) + } + + // Must not use `%q` here which will escape every quote in the string. + // It might break external substring checks + return fmt.Sprintf(`[%d %s]: %s: %s`, e.Status, e.OperationID, e.Message, errMerged) } // IsNotFound returns true if the specified error has status 404 func IsNotFound(err error) bool { var e Error - return errors.As(err, &e) && e.Status == http.StatusNotFound } // IsAlreadyExists returns true if the error message and error code that indicates that entity already exists func IsAlreadyExists(err error) bool { var e Error - return errors.As(err, &e) && strings.Contains(e.Message, "already exists") && e.Status == http.StatusConflict } -// IsNilOrNotFound returns true for nil and 404 error. -// This check is quite often used for resource deletion when 404 is not an issue. -func IsNilOrNotFound(err error) bool { - return err == nil || IsNotFound(err) +func fromResponse(operationID string, rsp *http.Response) ([]byte, error) { + e := Error{OperationID: operationID, Status: rsp.StatusCode} + b, err := io.ReadAll(rsp.Body) + if err != nil { + e.Message = fmt.Sprintf("body read error: %s", err) + return nil, e + } + + if rsp.StatusCode < 200 || rsp.StatusCode >= 300 { + // According to the documentation, + // failed responses must have "errors" and "message" fields + // https://api.aiven.io/doc/#section/Responses/Failed-responses + err = json.Unmarshal(b, &e) + if err != nil { + // 1. The body might contain sensitive data + // 2. It might fail the unmarshalling into Error and still be a valid json + if json.Valid(b) { + e.Message = err.Error() + } else { + // If it is not valid json, it shouldn't contain sensitive data + // Returns the body, because clients might relay on the error message + e.Message = string(b) + } + } + return nil, e + } + + return b, nil } diff --git a/error_test.go b/error_test.go index dd154f9..feea77c 100644 --- a/error_test.go +++ b/error_test.go @@ -2,10 +2,14 @@ package aiven import ( + "bytes" "context" + "io" + "net/http" "os" "testing" + "github.com/google/go-cmp/cmp" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" ) @@ -103,3 +107,93 @@ func TestIsAlreadyExists(t *testing.T) { }) } } + +func TestFromResponse(t *testing.T) { + cases := []struct { + name string + operationID string + statusCode int + body []byte + expectErr error + expectStringer string + expectBytes []byte + }{ + { + name: "404", + operationID: "UserAuth", + statusCode: http.StatusNotFound, + body: []byte(`{ + "message": "Account does not exist", + "errors": [ + { + "error_code": "account_not_found", + "message": "Account does not exist", + "status": 404 + } + ] + }`), + expectStringer: `[404 UserAuth]: Account does not exist: [{"error_code":"account_not_found","message":"Account does not exist","status":404}]`, + expectBytes: nil, + expectErr: Error{ + Message: "Account does not exist", + Errors: []any{map[string]any{ + "error_code": "account_not_found", + "message": "Account does not exist", + "status": float64(404), + }}, + OperationID: "UserAuth", + Status: http.StatusNotFound, + }, + }, + { + name: "200", + operationID: "UserAuth", + statusCode: http.StatusOK, + body: []byte(`{"success": True}`), + expectBytes: []byte(`{"success": True}`), + expectErr: nil, + }, + { + name: "Invalid json", + operationID: "UserAuth", + statusCode: http.StatusInternalServerError, + body: []byte(`unknown error`), + expectBytes: nil, + expectStringer: `[500 UserAuth]: unknown error: null`, + expectErr: Error{ + OperationID: "UserAuth", + Message: "unknown error", + Status: http.StatusInternalServerError, + }, + }, + { + name: "Valid json, Error fields type mismatch", + operationID: "UserAuth", + statusCode: http.StatusBadRequest, + body: []byte(`{"message": {"key": "value"}}`), // message is not string + expectStringer: `[400 UserAuth]: json: cannot unmarshal object into Go struct field Error.message of type string: null`, + expectBytes: nil, + expectErr: Error{ + OperationID: "UserAuth", + Message: "json: cannot unmarshal object into Go struct field Error.message of type string", + Status: http.StatusBadRequest, + }, + }, + } + + for _, opt := range cases { + t.Run(opt.name, func(t *testing.T) { + rsp := &http.Response{ + StatusCode: opt.statusCode, + Body: io.NopCloser(bytes.NewReader(opt.body)), + } + + b, err := fromResponse(opt.operationID, rsp) + assert.Equal(t, opt.expectBytes, b) + assert.Empty(t, cmp.Diff(opt.expectErr, err)) + if err != nil { + assert.Equal(t, opt.expectStringer, err.Error()) + } + }) + } +} diff --git a/go.mod b/go.mod index 575b66a..808b25b 100644 --- a/go.mod +++ b/go.mod @@ -4,6 +4,7 @@ go 1.22 require ( github.com/dave/jennifer v1.7.0 + github.com/google/go-cmp v0.5.8 github.com/hashicorp/go-multierror v1.1.1 github.com/hashicorp/go-retryablehttp v0.7.7 github.com/iancoleman/strcase v0.3.0 diff --git a/go.sum b/go.sum index 15dea42..091da85 100644 --- a/go.sum +++ b/go.sum @@ -6,6 +6,8 @@ github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSs github.com/fatih/color v1.16.0 h1:zmkK9Ngbjj+K0yRhTVONQh1p/HknKYSlNT+vZCzyokM= github.com/fatih/color v1.16.0/go.mod h1:fL2Sau1YI5c0pdGEVCbKQbLXB6edEj1ZgiY4NijnWvE= github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA= +github.com/google/go-cmp v0.5.8 h1:e6P7q2lk1O+qJJb4BtCQXlK8vWEO8V1ZeuEdJNOqZyg= +github.com/google/go-cmp v0.5.8/go.mod h1:17dUlkBOakJ0+DkrSSNjCkIjxS6bF9zb3elmeNGIjoY= github.com/hashicorp/errwrap v1.0.0/go.mod h1:YH+1FKiLXxHSkmPseP+kNlulaMuP3n2brvKWEqk/Jc4= github.com/hashicorp/errwrap v1.1.0 h1:OxrOeh75EUXMY8TBjag2fzXGZ40LB6IKw45YeGUDY2I= github.com/hashicorp/errwrap v1.1.0/go.mod h1:YH+1FKiLXxHSkmPseP+kNlulaMuP3n2brvKWEqk/Jc4=