From 1ed775e3a8029258c6ab468a7d36f10a7cecce5a Mon Sep 17 00:00:00 2001 From: Michael Eischer Date: Sat, 16 Jul 2022 21:41:37 +0200 Subject: [PATCH] debug: support roundtripper logging also for release builds Different from debug builds do not use the eofDetectRoundTripper if logging is disabled. --- internal/debug/round_tripper.go | 116 ++++++++++++++++++ internal/debug/round_tripper_debug.go | 115 +---------------- internal/debug/round_tripper_release.go | 4 + ...er_debug_test.go => round_tripper_test.go} | 2 - 4 files changed, 121 insertions(+), 116 deletions(-) create mode 100644 internal/debug/round_tripper.go rename internal/debug/{round_tripper_debug_test.go => round_tripper_test.go} (98%) diff --git a/internal/debug/round_tripper.go b/internal/debug/round_tripper.go new file mode 100644 index 000000000..6795d43d0 --- /dev/null +++ b/internal/debug/round_tripper.go @@ -0,0 +1,116 @@ +package debug + +import ( + "fmt" + "io" + "io/ioutil" + "net/http" + "net/http/httputil" + "os" + + "github.com/restic/restic/internal/errors" +) + +type eofDetectRoundTripper struct { + http.RoundTripper +} + +type eofDetectReader struct { + eofSeen bool + rd io.ReadCloser +} + +func (rd *eofDetectReader) Read(p []byte) (n int, err error) { + n, err = rd.rd.Read(p) + if err == io.EOF { + rd.eofSeen = true + } + return n, err +} + +func (rd *eofDetectReader) Close() error { + if !rd.eofSeen { + buf, err := ioutil.ReadAll(rd) + msg := fmt.Sprintf("body not drained, %d bytes not read", len(buf)) + if err != nil { + msg += fmt.Sprintf(", error: %v", err) + } + + if len(buf) > 0 { + if len(buf) > 20 { + buf = append(buf[:20], []byte("...")...) + } + msg += fmt.Sprintf(", body: %q", buf) + } + + fmt.Fprintln(os.Stderr, msg) + Log("%s: %+v", msg, errors.New("Close()")) + } + return rd.rd.Close() +} + +func (tr eofDetectRoundTripper) RoundTrip(req *http.Request) (res *http.Response, err error) { + res, err = tr.RoundTripper.RoundTrip(req) + if res != nil && res.Body != nil { + res.Body = &eofDetectReader{rd: res.Body} + } + return res, err +} + +type loggingRoundTripper struct { + http.RoundTripper +} + +func redactHeader(header http.Header) map[string][]string { + removedHeaders := make(map[string][]string) + for _, hdr := range []string{ + "Authorization", + "X-Auth-Token", // Swift headers + "X-Auth-Key", + } { + origHeader, hasHeader := header[hdr] + if hasHeader { + removedHeaders[hdr] = origHeader + header[hdr] = []string{"**redacted**"} + } + } + return removedHeaders +} + +func restoreHeader(header http.Header, origHeaders map[string][]string) { + for hdr, val := range origHeaders { + header[hdr] = val + } +} + +func (tr loggingRoundTripper) RoundTrip(req *http.Request) (res *http.Response, err error) { + // save original auth and redact it + origHeaders := redactHeader(req.Header) + + trace, err := httputil.DumpRequestOut(req, false) + if err != nil { + Log("DumpRequestOut() error: %v\n", err) + } else { + Log("------------ HTTP REQUEST -----------\n%s", trace) + } + + restoreHeader(req.Header, origHeaders) + + res, err = tr.RoundTripper.RoundTrip(req) + if err != nil { + Log("RoundTrip() returned error: %v", err) + } + + if res != nil { + origHeaders := redactHeader(res.Header) + trace, err := httputil.DumpResponse(res, false) + restoreHeader(res.Header, origHeaders) + if err != nil { + Log("DumpResponse() error: %v\n", err) + } else { + Log("------------ HTTP RESPONSE ----------\n%s", trace) + } + } + + return res, err +} diff --git a/internal/debug/round_tripper_debug.go b/internal/debug/round_tripper_debug.go index 020e798f0..df207207b 100644 --- a/internal/debug/round_tripper_debug.go +++ b/internal/debug/round_tripper_debug.go @@ -3,66 +3,7 @@ package debug -import ( - "fmt" - "io" - "io/ioutil" - "net/http" - "net/http/httputil" - "os" - - "github.com/restic/restic/internal/errors" -) - -type eofDetectRoundTripper struct { - http.RoundTripper -} - -type eofDetectReader struct { - eofSeen bool - rd io.ReadCloser -} - -func (rd *eofDetectReader) Read(p []byte) (n int, err error) { - n, err = rd.rd.Read(p) - if err == io.EOF { - rd.eofSeen = true - } - return n, err -} - -func (rd *eofDetectReader) Close() error { - if !rd.eofSeen { - buf, err := ioutil.ReadAll(rd) - msg := fmt.Sprintf("body not drained, %d bytes not read", len(buf)) - if err != nil { - msg += fmt.Sprintf(", error: %v", err) - } - - if len(buf) > 0 { - if len(buf) > 20 { - buf = append(buf[:20], []byte("...")...) - } - msg += fmt.Sprintf(", body: %q", buf) - } - - fmt.Fprintln(os.Stderr, msg) - Log("%s: %+v", msg, errors.New("Close()")) - } - return rd.rd.Close() -} - -func (tr eofDetectRoundTripper) RoundTrip(req *http.Request) (res *http.Response, err error) { - res, err = tr.RoundTripper.RoundTrip(req) - if res != nil && res.Body != nil { - res.Body = &eofDetectReader{rd: res.Body} - } - return res, err -} - -type loggingRoundTripper struct { - http.RoundTripper -} +import "net/http" // RoundTripper returns a new http.RoundTripper which logs all requests (if // debug is enabled). When debug is not enabled, upstream is returned. @@ -74,57 +15,3 @@ func RoundTripper(upstream http.RoundTripper) http.RoundTripper { } return eofRoundTripper } - -func redactHeader(header http.Header) map[string][]string { - removedHeaders := make(map[string][]string) - for _, hdr := range []string{ - "Authorization", - "X-Auth-Token", // Swift headers - "X-Auth-Key", - } { - origHeader, hasHeader := header[hdr] - if hasHeader { - removedHeaders[hdr] = origHeader - header[hdr] = []string{"**redacted**"} - } - } - return removedHeaders -} - -func restoreHeader(header http.Header, origHeaders map[string][]string) { - for hdr, val := range origHeaders { - header[hdr] = val - } -} - -func (tr loggingRoundTripper) RoundTrip(req *http.Request) (res *http.Response, err error) { - // save original auth and redact it - origHeaders := redactHeader(req.Header) - - trace, err := httputil.DumpRequestOut(req, false) - if err != nil { - Log("DumpRequestOut() error: %v\n", err) - } else { - Log("------------ HTTP REQUEST -----------\n%s", trace) - } - - restoreHeader(req.Header, origHeaders) - - res, err = tr.RoundTripper.RoundTrip(req) - if err != nil { - Log("RoundTrip() returned error: %v", err) - } - - if res != nil { - origHeaders := redactHeader(res.Header) - trace, err := httputil.DumpResponse(res, false) - restoreHeader(res.Header, origHeaders) - if err != nil { - Log("DumpResponse() error: %v\n", err) - } else { - Log("------------ HTTP RESPONSE ----------\n%s", trace) - } - } - - return res, err -} diff --git a/internal/debug/round_tripper_release.go b/internal/debug/round_tripper_release.go index 924c5c61e..6edadb479 100644 --- a/internal/debug/round_tripper_release.go +++ b/internal/debug/round_tripper_release.go @@ -8,5 +8,9 @@ import "net/http" // RoundTripper returns a new http.RoundTripper which logs all requests (if // debug is enabled). When debug is not enabled, upstream is returned. func RoundTripper(upstream http.RoundTripper) http.RoundTripper { + if opts.isEnabled { + // only use loggingRoundTripper if the debug log is configured + return loggingRoundTripper{eofDetectRoundTripper{upstream}} + } return upstream } diff --git a/internal/debug/round_tripper_debug_test.go b/internal/debug/round_tripper_test.go similarity index 98% rename from internal/debug/round_tripper_debug_test.go rename to internal/debug/round_tripper_test.go index 2095bbc6e..cc42a87d1 100644 --- a/internal/debug/round_tripper_debug_test.go +++ b/internal/debug/round_tripper_test.go @@ -1,5 +1,3 @@ -// +build debug - package debug import (