feat(client): add option to log requests and responses (#325)

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

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()

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))
 }