From 8650d7ff026d98c4011c3cf61b21634b7823e081 Mon Sep 17 00:00:00 2001 From: Toni Kangas Date: Fri, 11 Oct 2024 17:09:45 +0300 Subject: [PATCH] feat(client): add option to log requests and responses (#325) --- CHANGELOG.md | 3 + upcloud/client/client.go | 107 ++++++++++++++++++++++++++-------- upcloud/client/client_test.go | 40 +++++++++++++ 3 files changed, 126 insertions(+), 24 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index dec7456d..619a8d1c 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,9 @@ See updating [Changelog example here](https://keepachangelog.com/en/1.0.0/) ## [Unreleased] +### Added +- client: add option to configure logger for logging requests and responses + ## [8.9.0] ### Added diff --git a/upcloud/client/client.go b/upcloud/client/client.go index c7fd8d4b..a9685f59 100644 --- a/upcloud/client/client.go +++ b/upcloud/client/client.go @@ -4,6 +4,7 @@ import ( "bytes" "context" "crypto/tls" + "encoding/json" "fmt" "io" "net" @@ -23,11 +24,15 @@ const ( EnvDebugSkipCertificateVerify string = "UPCLOUD_DEBUG_SKIP_CERTIFICATE_VERIFY" ) +// LogFn is a function that logs a message with context and optional key-value pairs, e.g., slog.DebugContext +type LogFn func(context.Context, string, ...any) + type config struct { username string password string baseURL string httpClient *http.Client + logger LogFn } // Client represents an API client @@ -83,13 +88,12 @@ func (c *Client) Delete(ctx context.Context, path string) ([]byte, error) { // Do performs HTTP request and returns the response body. func (c *Client) Do(r *http.Request) ([]byte, error) { - c.addDefaultHeaders(r) response, err := c.config.httpClient.Do(r) if err != nil { return nil, err } - return handleResponse(response) + return c.handleResponse(response) } func (c *Client) createRequest(ctx context.Context, method, path string, body []byte) (*http.Request, error) { @@ -102,9 +106,35 @@ func (c *Client) createRequest(ctx context.Context, method, path string, body [] if err != nil { return nil, err } + c.addDefaultHeaders(req) + c.logRequest(req, body) return req, err } +// Parses the response and returns either the response body or an error +func (c *Client) handleResponse(response *http.Response) ([]byte, error) { + defer response.Body.Close() + + // Return an error on unsuccessful requests + if response.StatusCode < 200 || response.StatusCode > 299 { + errorBody, _ := io.ReadAll(response.Body) + var errorType ErrorType + switch response.Header.Get("Content-Type") { + case "application/problem+json": + errorType = ErrorTypeProblem + default: + errorType = ErrorTypeError + } + c.logResponse(response, errorBody) + return nil, &Error{response.StatusCode, response.Status, errorBody, errorType} + } + + responseBody, err := io.ReadAll(response.Body) + c.logResponse(response, responseBody) + + return responseBody, err +} + func (c *Client) addDefaultHeaders(r *http.Request) { const ( accept string = "Accept" @@ -139,6 +169,50 @@ func (c *Client) getBaseURL() string { return fmt.Sprintf("%s/%s", c.config.baseURL, APIVersion) } +// Pretty prints given JSON bytes. If the JSON is not valid, returns the original bytes as string. +func prettyJSON(i []byte) string { + var o bytes.Buffer + if err := json.Indent(&o, i, "", " "); err != nil { + return string(i) + } + return o.String() +} + +func (c *Client) logRequest(r *http.Request, body []byte) { + const authorization string = "Authorization" + + if c.config.logger != nil { + headers := r.Header.Clone() + if _, ok := headers[authorization]; ok { + auth := strings.Split(headers.Get(authorization), " ") + // Redact the token part of the Authorization header or the whole value if there is no space to separate scheme from parameters. + if len(auth) > 1 { + headers.Set(authorization, fmt.Sprintf("%s [REDACTED]", auth[0])) + } else { + headers.Set(authorization, "[REDACTED]") + } + } + + c.config.logger(r.Context(), "Sending request to UpCloud API", + "url", r.URL.Redacted(), + "method", r.Method, + "headers", headers, + "body", prettyJSON(body), + ) + } +} + +func (c *Client) logResponse(r *http.Response, body []byte) { + if c.config.logger != nil { + c.config.logger(r.Request.Context(), "Received response from UpCloud API", + "url", r.Request.URL.Redacted(), + "status", r.Status, + "headers", r.Header, + "body", prettyJSON(body), + ) + } +} + type ConfigFn func(o *config) // WithBaseURL modifies the client baseURL @@ -181,6 +255,13 @@ func WithTimeout(timeout time.Duration) ConfigFn { } } +// WithLogger configures logging function that logs requests and responses +func WithLogger(logger LogFn) ConfigFn { + return func(c *config) { + c.logger = logger + } +} + // New creates and returns a new client configured with the specified user and password and optional // config functions. func New(username, password string, c ...ConfigFn) *Client { @@ -221,28 +302,6 @@ func clientBaseURL(URL string) string { return URL } -// Parses the response and returns either the response body or an error -func handleResponse(response *http.Response) ([]byte, error) { - defer response.Body.Close() - - // Return an error on unsuccessful requests - if response.StatusCode < 200 || response.StatusCode > 299 { - errorBody, _ := io.ReadAll(response.Body) - var errorType ErrorType - switch response.Header.Get("Content-Type") { - case "application/problem+json": - errorType = ErrorTypeProblem - default: - errorType = ErrorTypeError - } - return nil, &Error{response.StatusCode, response.Status, errorBody, errorType} - } - - responseBody, err := io.ReadAll(response.Body) - - return responseBody, err -} - // NewDefaultHTTPClient returns new default http.Client. func NewDefaultHTTPClient() *http.Client { transport := NewDefaultHTTPTransport() diff --git a/upcloud/client/client_test.go b/upcloud/client/client_test.go index 32eb56c3..16a1906e 100644 --- a/upcloud/client/client_test.go +++ b/upcloud/client/client_test.go @@ -5,9 +5,12 @@ import ( "errors" "fmt" "io" + "log/slog" "net/http" "net/http/httptest" "os" + "regexp" + "strings" "testing" "time" @@ -216,6 +219,43 @@ func TestClientGetContextDeadline(t *testing.T) { require.True(t, errors.Is(err, context.DeadlineExceeded)) } +func TestClientWithLogger(t *testing.T) { + t.Parallel() + + var output strings.Builder + logger := slog.New(slog.NewJSONHandler(&output, &slog.HandlerOptions{ + Level: slog.LevelDebug, + ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr { + // Replace time with a static value + if a.Key == slog.TimeKey { + a.Value = slog.StringValue("2 Minutes to Midnight") + } + + // Replace URL with a static value as port is random + if a.Key == "url" { + re := regexp.MustCompile(`127\.0\.0\.1:\d+`) + a.Value = slog.StringValue(re.ReplaceAllString(a.Value.String(), "server")) + } + return a + }, + })) + + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.Header().Set("Date", "Fri, 11 Oct 2024 23:58:00 GMT") + fmt.Fprintf(w, `{"method": "%s", "path": "%s"}`, r.Method, r.URL.Path) + })) + defer srv.Close() + + c := New("username", "password", WithBaseURL(srv.URL), WithLogger(logger.DebugContext)) + _, err := c.Get(context.TODO(), "/test") + require.NoError(t, err) + + expected := `{"time":"2 Minutes to Midnight","level":"DEBUG","msg":"Sending request to UpCloud API","url":"http://server/1.3/test","method":"GET","headers":{"Accept":["application/json"],"Authorization":["Basic [REDACTED]"],"Content-Type":["application/json"],"User-Agent":["upcloud-go-api/8.9.0"]},"body":""} +{"time":"2 Minutes to Midnight","level":"DEBUG","msg":"Received response from UpCloud API","url":"http://server/1.3/test","status":"200 OK","headers":{"Content-Length":["38"],"Content-Type":["text/plain; charset=utf-8"],"Date":["Fri, 11 Oct 2024 23:58:00 GMT"]},"body":"{\n \"method\": \"GET\",\n \"path\": \"/1.3/test\"\n}"} +` + assert.Equal(t, expected, output.String()) +} + func ExampleWithTimeout() { New(os.Getenv("UPCLOUD_USERNAME"), os.Getenv("UPCLOUD_PASSWORD"), WithTimeout(10*time.Second)) }