Merge pull request #1644 from repl-david-winiarski/IncreaseHttpDebugL…

…ogging

Increase http debug logging

go.mod

@@ -46,7 +46,7 @@ require (
 	github.com/mattn/go-isatty v0.0.4
 	github.com/mccutchen/go-httpbin v1.1.2-0.20190116014521-c5cb2f4802fa
 	github.com/mitchellh/mapstructure v0.0.0-20180220230111-00c29f56e238
-	github.com/nu7hatch/gouuid v0.0.0-20131221200532-179d4d0c4d8d // indirect
+	github.com/nu7hatch/gouuid v0.0.0-20131221200532-179d4d0c4d8d
 	github.com/onsi/ginkgo v1.14.0 // indirect
 	github.com/oxtoacart/bpool v0.0.0-20150712133111-4e1c5567d7c2
 	github.com/pierrec/lz4 v1.0.2-0.20171218195038-2fcda4cb7018 // indirect

lib/netext/httpext/httpdebug_transport.go

@@ -25,6 +25,7 @@ import (
 	"net/http"
 	"net/http/httputil"
 
+	uuid "github.com/nu7hatch/gouuid"
 	"github.com/sirupsen/logrus"
 )
 
@@ -41,26 +42,29 @@ type httpDebugTransport struct {
 //  - https://github.com/loadimpact/k6/issues/1042
 //  - https://github.com/loadimpact/k6/issues/774
 func (t httpDebugTransport) RoundTrip(req *http.Request) (*http.Response, error) {
-	t.debugRequest(req)
+	id, _ := uuid.NewV4()
+	t.debugRequest(req, id.String())
 	resp, err := t.originalTransport.RoundTrip(req)
-	t.debugResponse(resp)
+	t.debugResponse(resp, id.String())
 	return resp, err
 }
 
-func (t httpDebugTransport) debugRequest(req *http.Request) {
+func (t httpDebugTransport) debugRequest(req *http.Request, requestID string) {
 	dump, err := httputil.DumpRequestOut(req, t.httpDebugOption == "full")
 	if err != nil {
 		t.logger.Error(err)
 	}
-	t.logger.Infof("Request:\n%s\n", bytes.ReplaceAll(dump, []byte("\r\n"), []byte{'\n'}))
+	t.logger.WithField("request_id", requestID).Infof("Request:\n%s\n",
+		bytes.ReplaceAll(dump, []byte("\r\n"), []byte{'\n'}))
 }
 
-func (t httpDebugTransport) debugResponse(res *http.Response) {
+func (t httpDebugTransport) debugResponse(res *http.Response, requestID string) {
 	if res != nil {
 		dump, err := httputil.DumpResponse(res, t.httpDebugOption == "full")
 		if err != nil {
 			t.logger.Error(err)
 		}
-		t.logger.Infof("Response:\n%s\n", bytes.ReplaceAll(dump, []byte("\r\n"), []byte{'\n'}))
+		t.logger.WithField("request_id", requestID).Infof("Response:\n%s\n",
+			bytes.ReplaceAll(dump, []byte("\r\n"), []byte{'\n'}))
 	}
 }

lib/netext/httpext/request.go

@@ -252,11 +252,19 @@ func MakeRequest(ctx context.Context, preq *ParsedHTTPRequest) (*Response, error
 	tracerTransport := newTransport(ctx, state, tags)
 	var transport http.RoundTripper = tracerTransport
 
+	// Combine tags with common log fields
+	combinedLogFields := map[string]interface{}{"source": "http-debug", "vu": state.Vu, "iter": state.Iteration}
+	for k, v := range tags {
+		if _, present := combinedLogFields[k]; !present {
+			combinedLogFields[k] = v
+		}
+	}
+
 	if state.Options.HTTPDebug.String != "" {
 		transport = httpDebugTransport{
 			originalTransport: transport,
 			httpDebugOption:   state.Options.HTTPDebug.String,
-			logger:            state.Logger.WithField("source", "http-debug"),
+			logger:            state.Logger.WithFields(combinedLogFields),
 		}
 	}