From 40631a6e97d5149047fbf39ba2fb9901468c6519 Mon Sep 17 00:00:00 2001
From: Adam Harwayne <harwayne@google.com>
Date: Wed, 21 Aug 2019 12:23:33 -0700
Subject: [PATCH] Retain the request body when logging HTTP. (#378)

* Retain the request body when logging HTTP.

* hack/build.sh -u

* Add a unit test.

* Unit test redacted headers.
---
 pkg/util/logging_http_transport.go      | 40 +++++++++++++++----------
 pkg/util/logging_http_transport_test.go | 30 +++++++++++++++++--
 vendor/modules.txt                      |  2 +-
 3 files changed, 53 insertions(+), 19 deletions(-)

diff --git a/pkg/util/logging_http_transport.go b/pkg/util/logging_http_transport.go
index 187e4422fa..ec50591300 100644
--- a/pkg/util/logging_http_transport.go
+++ b/pkg/util/logging_http_transport.go
@@ -21,6 +21,17 @@ import (
 	"net/http/httputil"
 	"os"
 	"strings"
+
+	"k8s.io/apimachinery/pkg/util/sets"
+)
+
+var (
+	// sensitiveRequestHeaders are headers that will be redacted when logging requests.
+	sensitiveRequestHeaders = sets.NewString(
+		"Authorization",
+		"WWW-Authenticate",
+		"Cookie",
+		"Proxy-Authorization")
 )
 
 type LoggingHttpTransport struct {
@@ -36,35 +47,34 @@ func NewLoggingTransportWithStream(transport http.RoundTripper, s io.Writer) htt
 	return &LoggingHttpTransport{transport, s}
 }
 
-var SENSITIVE_HEADERS = map[string]bool{
-	"Authorization":       true,
-	"WWW-Authenticate":    true,
-	"Cookie":              true,
-	"Proxy-Authorization": true,
-}
-
 func (t *LoggingHttpTransport) RoundTrip(r *http.Request) (*http.Response, error) {
 	stream := t.stream
 	if stream == nil {
 		stream = os.Stderr
 	}
-	reqCopy := *r
-	reqCopy.Header = make(http.Header, len(r.Header))
+	redacted := http.Header{}
 	for k, v := range r.Header {
-		sensitive := SENSITIVE_HEADERS[k]
-		if sensitive {
+		if sensitiveRequestHeaders.Has(k) {
+			redacted[k] = v
 			l := 0
 			for _, h := range v {
 				l += len(h)
 			}
-			reqCopy.Header.Set(k, strings.Repeat("*", l))
-		} else {
-			reqCopy.Header[k] = v
+			r.Header.Set(k, strings.Repeat("*", l))
 		}
 	}
-	reqBytes, _ := httputil.DumpRequestOut(&reqCopy, true)
+	reqBytes, err := httputil.DumpRequestOut(r, true)
+	if err != nil {
+		fmt.Fprintln(stream, "error dumping request:", err)
+		return nil, fmt.Errorf("dumping request: %v", err)
+	}
 	fmt.Fprintln(stream, "===== REQUEST =====")
 	fmt.Fprintln(stream, string(reqBytes))
+
+	for k, v := range redacted {
+		r.Header[k] = v
+	}
+
 	resp, err := t.transport.RoundTrip(r)
 	if err != nil {
 		fmt.Fprintln(stream, "===== ERROR =====")
diff --git a/pkg/util/logging_http_transport_test.go b/pkg/util/logging_http_transport_test.go
index 5e8993b112..a739253a34 100644
--- a/pkg/util/logging_http_transport_test.go
+++ b/pkg/util/logging_http_transport_test.go
@@ -17,17 +17,26 @@ package util
 import (
 	"bytes"
 	"errors"
+	"fmt"
 	"io/ioutil"
 	"net/http"
+	"net/http/httputil"
 	"strings"
 	"testing"
 
 	"gotest.tools/assert"
 )
 
-type dummyTransport struct{}
+type dummyTransport struct {
+	requestDump string
+}
 
 func (d *dummyTransport) RoundTrip(r *http.Request) (*http.Response, error) {
+	dump, err := httputil.DumpRequest(r, true)
+	if err != nil {
+		return nil, fmt.Errorf("dumping request: %v", err)
+	}
+	d.requestDump = string(dump)
 	return &http.Response{
 		Status:     "200 OK",
 		StatusCode: 200,
@@ -44,13 +53,28 @@ func (d *errorTransport) RoundTrip(r *http.Request) (*http.Response, error) {
 
 func TestWritesRequestResponse(t *testing.T) {
 	out := &bytes.Buffer{}
-	transport := NewLoggingTransportWithStream(&dummyTransport{}, out)
-	req, _ := http.NewRequest("GET", "http://example.com", nil)
+	dt := &dummyTransport{}
+	transport := NewLoggingTransportWithStream(dt, out)
+
+	body := "{this: is, the: body, of: [the, request]}"
+	req, _ := http.NewRequest("POST", "http://example.com", strings.NewReader(body))
+	nonRedacted := "this string will be logged"
+	redacted := "this string will be redacted"
+	req.Header.Add("non-redacted", nonRedacted)
+	req.Header.Add(sensitiveRequestHeaders.List()[0], redacted)
+
 	_, e := transport.RoundTrip(req)
 	assert.NilError(t, e)
 	s := out.String()
 	assert.Assert(t, strings.Contains(s, "REQUEST"))
 	assert.Assert(t, strings.Contains(s, "RESPONSE"))
+	assert.Assert(t, strings.Contains(s, body))
+	assert.Assert(t, strings.Contains(s, nonRedacted))
+	assert.Assert(t, !strings.Contains(s, redacted))
+
+	assert.Assert(t, strings.Contains(dt.requestDump, body))
+	assert.Assert(t, strings.Contains(dt.requestDump, nonRedacted))
+	assert.Assert(t, strings.Contains(dt.requestDump, redacted))
 }
 
 func TestElideAuthorizationHeader(t *testing.T) {
diff --git a/vendor/modules.txt b/vendor/modules.txt
index 3e2cc55952..14011651bb 100644
--- a/vendor/modules.txt
+++ b/vendor/modules.txt
@@ -191,6 +191,7 @@ k8s.io/apimachinery/pkg/util/runtime
 k8s.io/apimachinery/pkg/runtime/schema
 k8s.io/apimachinery/pkg/fields
 k8s.io/apimachinery/pkg/labels
+k8s.io/apimachinery/pkg/util/sets
 k8s.io/apimachinery/pkg/watch
 k8s.io/apimachinery/pkg/util/validation/field
 k8s.io/apimachinery/pkg/conversion
@@ -206,7 +207,6 @@ k8s.io/apimachinery/pkg/api/validation
 k8s.io/apimachinery/pkg/runtime/serializer
 k8s.io/apimachinery/pkg/conversion/queryparams
 k8s.io/apimachinery/pkg/util/naming
-k8s.io/apimachinery/pkg/util/sets
 k8s.io/apimachinery/pkg/util/net
 k8s.io/apimachinery/pkg/util/yaml
 k8s.io/apimachinery/third_party/forked/golang/reflect