Merge pull request #203 from pace/http-transport-dumps

add transport dumps to easily debug issues with external parties

http/transport/README.md

@@ -0,0 +1,16 @@
+# HTTP Transports
+
+HTTP Transport to be used with the http client from go.
+
+## Environment based configuration
+
+* `HTTP_TRANSPORT_DUMP` default: `""` (option values are comma separated)
+  * Can contain a list of logging options:
+    * `request` will log the complete request with headers human readable
+    * `response` will log the complete response with headers human readable
+    * `request-hex` will log the complete request with headers in HEX
+    * `response-hex` will log the complete response with headers in HEX
+    * `body` will enable logging of the body for hex and human readable outputs
+  * Simple request header logging may look like this `request,response`
+  * Full human readable logging may look like this `request,response,body`
+  * Complete logging may look like this `request,response,request-hex,response-hex,body`

http/transport/default_transport.go

@@ -7,6 +7,7 @@ package transport
 // If not explicitly finalized via `Final` it uses `http.DefaultTransport` as finalizer.
 func NewDefaultTransportChain() *RoundTripperChain {
 	return Chain(
+		NewDumpRoundTripperEnv(),
 		NewDefaultRetryRoundTripper(),
 		&JaegerRoundTripper{},
 		&LoggingRoundTripper{},

http/transport/dump_round_tripper.go

@@ -0,0 +1,133 @@
+// Copyright © 2020 by PACE Telematics GmbH. All rights reserved.
+// Created at 2020/05/20 by Vincent Landgraf
+
+package transport
+
+import (
+	"encoding/hex"
+	"net/http"
+	"net/http/httputil"
+
+	"github.com/caarlos0/env"
+	"github.com/pace/bricks/maintenance/log"
+)
+
+// DumpRoundTripper dumps requests and responses in one log event.
+// This is not part of te request logger to be able to filter dumps more easily
+type DumpRoundTripper struct {
+	transport http.RoundTripper
+
+	DumpRequest     bool
+	DumpResponse    bool
+	DumpRequestHEX  bool
+	DumpResponseHEX bool
+	DumpBody        bool
+}
+
+type DumpRoundTripperOption string
+
+const (
+	DumpRoundTripperOptionRequest     = "request"
+	DumpRoundTripperOptionResponse    = "response"
+	DumpRoundTripperOptionRequestHEX  = "request-hex"
+	DumpRoundTripperOptionResponseHEX = "response-hex"
+	DumpRoundTripperOptionBody        = "body"
+)
+
+// NewDumpRoundTripperEnv creates a new RoundTripper based on the configuration
+// that is passed via environment variables
+func NewDumpRoundTripperEnv() *DumpRoundTripper {
+	// parse config
+	var cfg struct {
+		Options []DumpRoundTripperOption `env:"HTTP_TRANSPORT_DUMP" envSeparator:"," envDefault:""`
+	}
+	err := env.Parse(&cfg)
+	if err != nil {
+		log.Fatalf("Failed to parse dump round tripper environment: %v", err)
+	}
+
+	// create and configure rt
+	return NewDumpRoundTripper(cfg.Options...)
+}
+
+// NewDumpRoundTripper return the roundtripper with configured options
+func NewDumpRoundTripper(options ...DumpRoundTripperOption) *DumpRoundTripper {
+	rt := &DumpRoundTripper{}
+	for _, option := range options {
+		switch option {
+		case DumpRoundTripperOptionRequest:
+			rt.DumpRequest = true
+		case DumpRoundTripperOptionResponse:
+			rt.DumpResponse = true
+		case DumpRoundTripperOptionRequestHEX:
+			rt.DumpRequestHEX = true
+		case DumpRoundTripperOptionResponseHEX:
+			rt.DumpResponseHEX = true
+		case DumpRoundTripperOptionBody:
+			rt.DumpBody = true
+		default:
+			log.Fatalf("Failed to parse dump round tripper options from env: %v", option)
+		}
+	}
+	return rt
+}
+
+// Transport returns the RoundTripper to make HTTP requests
+func (l *DumpRoundTripper) Transport() http.RoundTripper {
+	return l.transport
+}
+
+// SetTransport sets the RoundTripper to make HTTP requests
+func (l *DumpRoundTripper) SetTransport(rt http.RoundTripper) {
+	l.transport = rt
+}
+
+// AnyEnabled returns true if any logging is enabled
+func (l DumpRoundTripper) AnyEnabled() bool {
+	return l.DumpRequest || l.DumpResponse || l.DumpRequestHEX || l.DumpResponseHEX
+}
+
+// RoundTrip executes a single HTTP transaction via Transport()
+func (l *DumpRoundTripper) RoundTrip(req *http.Request) (*http.Response, error) {
+	// fast path if logging is disabled
+	if !l.AnyEnabled() {
+		return l.Transport().RoundTrip(req)
+	}
+
+	dl := log.Ctx(req.Context()).Debug()
+
+	// request logging
+	if l.DumpRequest || l.DumpRequestHEX {
+		reqDump, err := httputil.DumpRequest(req, l.DumpBody)
+		if err != nil {
+			reqDump = []byte(err.Error())
+		}
+		if l.DumpRequest {
+			dl = dl.Bytes(DumpRoundTripperOptionRequest, reqDump)
+		}
+		if l.DumpRequestHEX {
+			dl = dl.Str(DumpRoundTripperOptionRequestHEX, hex.EncodeToString(reqDump))
+		}
+	}
+
+	resp, err := l.Transport().RoundTrip(req)
+
+	// response logging
+	if l.DumpResponse || l.DumpResponseHEX {
+		respDump, err := httputil.DumpResponse(resp, l.DumpBody)
+		if err != nil {
+			respDump = []byte(err.Error())
+		}
+		if l.DumpResponse {
+			dl = dl.Bytes(DumpRoundTripperOptionResponse, respDump)
+		}
+		if l.DumpResponseHEX {
+			dl = dl.Str(DumpRoundTripperOptionResponseHEX, hex.EncodeToString(respDump))
+		}
+	}
+
+	// emit log
+	dl.Msg("HTTP Transport Dump")
+
+	return resp, err
+}

http/transport/dump_round_tripper_test.go

@@ -0,0 +1,80 @@
+// Copyright © 2020 by PACE Telematics GmbH. All rights reserved.
+// Created at 2020/05/20 by Vincent Landgraf
+
+package transport
+
+import (
+	"bytes"
+	"context"
+	"net/http/httptest"
+	"testing"
+
+	"github.com/pace/bricks/maintenance/log"
+	"github.com/stretchr/testify/assert"
+)
+
+func TestNewDumpRoundTripperEnv(t *testing.T) {
+	out := &bytes.Buffer{}
+	ctx := log.Output(out).WithContext(context.Background())
+
+	rt := NewDumpRoundTripperEnv()
+	assert.NotNil(t, rt)
+
+	req := httptest.NewRequest("GET", "/foo", nil)
+	req = req.WithContext(ctx)
+	rt.SetTransport(&transportWithResponse{})
+
+	_, err := rt.RoundTrip(req)
+	assert.NoError(t, err)
+
+	assert.Equal(t, "", out.String())
+}
+
+func TestNewDumpRoundTripper(t *testing.T) {
+	out := &bytes.Buffer{}
+	ctx := log.Output(out).WithContext(context.Background())
+
+	rt := NewDumpRoundTripper(
+		DumpRoundTripperOptionRequest,
+		DumpRoundTripperOptionRequestHEX,
+		DumpRoundTripperOptionResponse,
+		DumpRoundTripperOptionResponseHEX,
+		DumpRoundTripperOptionBody,
+	)
+
+	req := httptest.NewRequest("GET", "/foo", bytes.NewBufferString("Foo"))
+	req = req.WithContext(ctx)
+	rt.SetTransport(&transportWithResponse{})
+
+	_, err := rt.RoundTrip(req)
+	assert.NoError(t, err)
+
+	assert.Contains(t, out.String(), `"level":"debug"`)
+	assert.Contains(t, out.String(), `"request":"GET /foo HTTP/1.1\r\nHost: example.com\r\n\r\nFoo"`)
+	assert.Contains(t, out.String(), `"request-hex":"474554202f666f6f20485454502f312e310d0a486f73743a206578616d706c652e636f6d0d0a0d0a466f6f"`)
+	assert.Contains(t, out.String(), `"response":"HTTP/0.0 000 status code 0\r\nContent-Length: 0\r\n\r\n"`)
+	assert.Contains(t, out.String(), `"response-hex":"485454502f302e30203030302073746174757320636f646520300d0a436f6e74656e742d4c656e6774683a20300d0a0d0a"`)
+	assert.Contains(t, out.String(), `"message":"HTTP Transport Dump"`)
+}
+
+func TestNewDumpRoundTripperSimple(t *testing.T) {
+	out := &bytes.Buffer{}
+	ctx := log.Output(out).WithContext(context.Background())
+
+	rt := NewDumpRoundTripper(
+		DumpRoundTripperOptionRequest,
+		DumpRoundTripperOptionResponse,
+	)
+
+	req := httptest.NewRequest("GET", "/foo", bytes.NewBufferString("Foo"))
+	req = req.WithContext(ctx)
+	rt.SetTransport(&transportWithResponse{})
+
+	_, err := rt.RoundTrip(req)
+	assert.NoError(t, err)
+
+	assert.Contains(t, out.String(), `"level":"debug"`)
+	assert.Contains(t, out.String(), `"request":"GET /foo HTTP/1.1\r\nHost: example.com\r\n\r\n"`)
+	assert.Contains(t, out.String(), `"response":"HTTP/0.0 000 status code 0\r\nContent-Length: 0\r\n\r\n"`)
+	assert.Contains(t, out.String(), `"message":"HTTP Transport Dump"`)
+}