feat(core): move request logging from client to a transport (#1482)

Author: Codelax

internal/auth/token.go

@@ -25,12 +25,18 @@ func (t *Token) Headers() http.Header {
 	return headers
 }
 
+func AnonymizeTokenHeaders(headers http.Header) http.Header {
+	key := headers.Get(XAuthTokenHeader)
+	if key != "" {
+		headers.Set(XAuthTokenHeader, HideSecretKey(key))
+	}
+	return headers
+}
+
 // AnonymizedHeaders returns an anonymized version of Headers()
 // This method could be use for logging purpose.
 func (t *Token) AnonymizedHeaders() http.Header {
-	headers := http.Header{}
-	headers.Set(XAuthTokenHeader, HideSecretKey(t.SecretKey))
-	return headers
+	return AnonymizeTokenHeaders(t.Headers())
 }
 
 func HideSecretKey(k string) string {

scw/client.go

@@ -8,12 +8,10 @@ import (
 	"math"
 	"net"
 	"net/http"
-	"net/http/httputil"
 	"reflect"
 	"strconv"
 	"strings"
 	"sync"
-	"sync/atomic"
 	"time"
 
 	"github.com/scaleway/scaleway-sdk-go/internal/auth"
@@ -73,6 +71,11 @@ func NewClient(opts ...ClientOption) (*Client, error) {
 		setInsecureMode(s.httpClient)
 	}
 
+	if logger.ShouldLog(logger.LogLevelDebug) {
+		logger.Debugf("client: using request logger")
+		setRequestLogging(s.httpClient)
+	}
+
 	logger.Debugf("client: using sdk version " + version)
 
 	return &Client{
@@ -182,13 +185,8 @@ func (c *Client) Do(req *ScalewayRequest, res interface{}, opts ...RequestOption
 	return c.do(req, res)
 }
 
-// requestNumber auto increments on each do().
-// This allows easy distinguishing of concurrently performed requests in log.
-var requestNumber uint32
-
 // do performs a single HTTP request based on the ScalewayRequest object.
 func (c *Client) do(req *ScalewayRequest, res interface{}) (sdkErr error) {
-	currentRequestNumber := atomic.AddUint32(&requestNumber, 1)
 
 	if req == nil {
 		return errors.New("request must be non-nil")
@@ -213,29 +211,6 @@ func (c *Client) do(req *ScalewayRequest, res interface{}) (sdkErr error) {
 		httpRequest = httpRequest.WithContext(req.ctx)
 	}
 
-	if logger.ShouldLog(logger.LogLevelDebug) {
-		// Keep original headers (before anonymization)
-		originalHeaders := httpRequest.Header
-
-		// Get anonymized headers
-		httpRequest.Header = req.getAllHeaders(req.auth, c.userAgent, true)
-
-		dump, err := httputil.DumpRequestOut(httpRequest, true)
-		if err != nil {
-			logger.Warningf("cannot dump outgoing request: %s", err)
-		} else {
-			var logString string
-			logString += "\n--------------- Scaleway SDK REQUEST %d : ---------------\n"
-			logString += "%s\n"
-			logString += "---------------------------------------------------------"
-
-			logger.Debugf(logString, currentRequestNumber, dump)
-		}
-
-		// Restore original headers before sending the request
-		httpRequest.Header = originalHeaders
-	}
-
 	// execute request
 	httpResponse, err := c.httpClient.Do(httpRequest)
 	if err != nil {
@@ -248,19 +223,6 @@ func (c *Client) do(req *ScalewayRequest, res interface{}) (sdkErr error) {
 			sdkErr = errors.Wrap(closeErr, "could not close http response")
 		}
 	}()
-	if logger.ShouldLog(logger.LogLevelDebug) {
-		dump, err := httputil.DumpResponse(httpResponse, true)
-		if err != nil {
-			logger.Warningf("cannot dump ingoing response: %s", err)
-		} else {
-			var logString string
-			logString += "\n--------------- Scaleway SDK RESPONSE %d : ---------------\n"
-			logString += "%s\n"
-			logString += "----------------------------------------------------------"
-
-			logger.Debugf(logString, currentRequestNumber, dump)
-		}
-	}
 
 	sdkErr = hasResponseError(httpResponse)
 	if sdkErr != nil {
@@ -561,3 +523,12 @@ func setInsecureMode(c httpClient) {
 	}
 	transportClient.TLSClientConfig.InsecureSkipVerify = true
 }
+
+func setRequestLogging(c httpClient) {
+	standardHTTPClient, ok := c.(*http.Client)
+	if !ok {
+		logger.Warningf("client: cannot use request logger with HTTP client of type %T", c)
+		return
+	}
+	standardHTTPClient.Transport = &requestLoggerTransport{rt: standardHTTPClient.Transport}
+}

scw/client_test.go

@@ -124,6 +124,9 @@ func TestNewClientWithOptions(t *testing.T) {
 		testhelpers.Equals(t, testAPIURL, client.apiURL)
 
 		clientTransport, ok := client.httpClient.(*http.Client).Transport.(*http.Transport)
+		if loggerTransport, isLogger := client.httpClient.(*http.Client).Transport.(*requestLoggerTransport); !ok && isLogger {
+			clientTransport, ok = loggerTransport.rt.(*http.Transport)
+		}
 		testhelpers.Assert(t, ok, "clientTransport must be not nil")
 		testhelpers.Assert(t, clientTransport.TLSClientConfig != nil, "TLSClientConfig must be not nil")
 		testhelpers.Equals(t, testInsecure, clientTransport.TLSClientConfig.InsecureSkipVerify)

scw/transport.go

@@ -0,0 +1,62 @@
+package scw
+
+import (
+	"net/http"
+	"net/http/httputil"
+	"sync/atomic"
+
+	"github.com/scaleway/scaleway-sdk-go/internal/auth"
+	"github.com/scaleway/scaleway-sdk-go/logger"
+)
+
+type requestLoggerTransport struct {
+	rt http.RoundTripper
+	// requestNumber auto increments on each do().
+	// This allows easy distinguishing of concurrently performed requests in log.
+	requestNumber uint32
+}
+
+func (l *requestLoggerTransport) RoundTrip(request *http.Request) (*http.Response, error) {
+	currentRequestNumber := atomic.AddUint32(&l.requestNumber, 1)
+	// Keep original headers (before anonymization)
+	originalHeaders := request.Header
+
+	// Get anonymized headers
+	request.Header = auth.AnonymizeTokenHeaders(request.Header.Clone())
+
+	dump, err := httputil.DumpRequestOut(request, true)
+	if err != nil {
+		logger.Warningf("cannot dump outgoing request: %s", err)
+	} else {
+		var logString string
+		logString += "\n--------------- Scaleway SDK REQUEST %d : ---------------\n"
+		logString += "%s\n"
+		logString += "---------------------------------------------------------"
+
+		logger.Debugf(logString, currentRequestNumber, dump)
+	}
+
+	// Restore original headers before sending the request
+	request.Header = originalHeaders
+	response, requestError := l.rt.RoundTrip(request)
+	if requestError != nil {
+		_, isSdkError := requestError.(SdkError)
+		if !isSdkError {
+			return response, err
+		}
+	}
+
+	dump, err = httputil.DumpResponse(response, true)
+	if err != nil {
+		logger.Warningf("cannot dump ingoing response: %s", err)
+	} else {
+		var logString string
+		logString += "\n--------------- Scaleway SDK RESPONSE %d : ---------------\n"
+		logString += "%s\n"
+		logString += "----------------------------------------------------------"
+
+		logger.Debugf(logString, currentRequestNumber, dump)
+	}
+
+	return response, requestError
+}