From 59b1e8b0bc1f14832a721b9177dbd3884e47d0b4 Mon Sep 17 00:00:00 2001 From: Carter Date: Wed, 10 Aug 2016 10:04:57 -0400 Subject: [PATCH 1/6] Now logging the request body Logging the request body if the Content-Type is application/json or application/xml --- caddyhttp/httpserver/replacer.go | 35 ++++++++++++++++++++++++++++++-- 1 file changed, 33 insertions(+), 2 deletions(-) diff --git a/caddyhttp/httpserver/replacer.go b/caddyhttp/httpserver/replacer.go index 407c43df..ee4dc202 100644 --- a/caddyhttp/httpserver/replacer.go +++ b/caddyhttp/httpserver/replacer.go @@ -1,6 +1,8 @@ package httpserver import ( + "io/ioutil" + "log" "net" "net/http" "net/http/httputil" @@ -119,6 +121,19 @@ func NewReplacer(r *http.Request, rr *ResponseRecorder, emptyValue string) Repla return requestReplacer.Replace(string(dump)) }, + "{request_body}": func() string { + if !canLogRequest(r) { + return "" + } + + body, err := ioutil.ReadAll(r.Body) + if err != nil { + log.Printf("[WARNING] Cannot read request body %v", err) + return "" + } + + return string(body) + }, }, emptyValue: emptyValue, } @@ -132,6 +147,19 @@ func NewReplacer(r *http.Request, rr *ResponseRecorder, emptyValue string) Repla return rep } +func canLogRequest(r *http.Request) (canLog bool) { + if r.Method == "POST" || r.Method == "PUT" { + for _, cType := range r.Header[headerContentType] { + // the cType could have charset and other info + if strings.Index(cType, contentTypeJSON) > -1 || strings.Index(cType, contentTypeXML) > -1 { + canLog = true + break + } + } + } + return +} + // Replace performs a replacement of values on s and returns // the string with the replaced values. func (r *replacer) Replace(s string) string { @@ -226,6 +254,9 @@ func (r *replacer) Set(key, value string) { } const ( - timeFormat = "02/Jan/2006:15:04:05 -0700" - headerReplacer = "{>" + timeFormat = "02/Jan/2006:15:04:05 -0700" + headerReplacer = "{>" + headerContentType = "Content-Type" + contentTypeJSON = "application/json" + contentTypeXML = "application/xml" ) From d06c15cae6a9d431b107435f9bee92088899b217 Mon Sep 17 00:00:00 2001 From: Carter Date: Wed, 10 Aug 2016 10:36:16 -0400 Subject: [PATCH 2/6] Set the request body to a new ReadCloser --- caddyhttp/httpserver/replacer.go | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/caddyhttp/httpserver/replacer.go b/caddyhttp/httpserver/replacer.go index ee4dc202..cf7dfccc 100644 --- a/caddyhttp/httpserver/replacer.go +++ b/caddyhttp/httpserver/replacer.go @@ -1,6 +1,7 @@ package httpserver import ( + "bytes" "io/ioutil" "log" "net" @@ -127,6 +128,9 @@ func NewReplacer(r *http.Request, rr *ResponseRecorder, emptyValue string) Repla } body, err := ioutil.ReadAll(r.Body) + // Create a new ReadCloser to keep the body from being drained. + r.Body = ioutil.NopCloser(bytes.NewBuffer(body)) + if err != nil { log.Printf("[WARNING] Cannot read request body %v", err) return "" From 3fd8218f67053bc0cda129326a074570885e580c Mon Sep 17 00:00:00 2001 From: Carter Date: Wed, 10 Aug 2016 11:04:37 -0400 Subject: [PATCH 3/6] refactor and added test --- caddyhttp/httpserver/replacer.go | 19 ++++++++++++++----- caddyhttp/httpserver/replacer_test.go | 23 +++++++++++++++++++++++ 2 files changed, 37 insertions(+), 5 deletions(-) diff --git a/caddyhttp/httpserver/replacer.go b/caddyhttp/httpserver/replacer.go index cf7dfccc..958758da 100644 --- a/caddyhttp/httpserver/replacer.go +++ b/caddyhttp/httpserver/replacer.go @@ -127,12 +127,9 @@ func NewReplacer(r *http.Request, rr *ResponseRecorder, emptyValue string) Repla return "" } - body, err := ioutil.ReadAll(r.Body) - // Create a new ReadCloser to keep the body from being drained. - r.Body = ioutil.NopCloser(bytes.NewBuffer(body)) - + body, err := readRequestBody(r) if err != nil { - log.Printf("[WARNING] Cannot read request body %v", err) + log.Printf("[WARNING] Cannot copy request body %v", err) return "" } @@ -164,6 +161,18 @@ func canLogRequest(r *http.Request) (canLog bool) { return } +// readRequestBody reads the request body and sets a +// new io.ReadCloser that has not yet been read. +func readRequestBody(r *http.Request) ([]byte, error) { + body, err := ioutil.ReadAll(r.Body) + if err != nil { + return nil, err + } + // Create a new ReadCloser to keep the body from being drained. + r.Body = ioutil.NopCloser(bytes.NewBuffer(body)) + return body, nil +} + // Replace performs a replacement of values on s and returns // the string with the replaced values. func (r *replacer) Replace(s string) string { diff --git a/caddyhttp/httpserver/replacer_test.go b/caddyhttp/httpserver/replacer_test.go index 158e819e..be87d582 100644 --- a/caddyhttp/httpserver/replacer_test.go +++ b/caddyhttp/httpserver/replacer_test.go @@ -1,6 +1,7 @@ package httpserver import ( + "bytes" "net/http" "net/http/httptest" "os" @@ -161,3 +162,25 @@ func TestRound(t *testing.T) { } } } + +func TestReadRequestBody(t *testing.T) { + r, err := http.NewRequest("POST", "/", strings.NewReader(`null`)) + if err != nil { + t.Error(err) + } + defer r.Body.Close() + + body, err := readRequestBody(r) + if err != nil { + t.Error("readRequestBody failed", err) + } + + var data = make([]byte, len(body)) + _, err = r.Body.Read(data) + + if err != nil { + t.Error(err) + } else if !bytes.Equal(body, data) { + t.Error("Expceted equal bytes.") + } +} From d56ac28beccd811fac3d871240e500da1d2b2cde Mon Sep 17 00:00:00 2001 From: Carter Date: Wed, 10 Aug 2016 22:43:26 -0400 Subject: [PATCH 4/6] Using a LimitReader and fixed test and log format. --- caddyhttp/httpserver/replacer.go | 21 +++++++++++++-------- caddyhttp/httpserver/replacer_test.go | 20 ++++++++++++-------- 2 files changed, 25 insertions(+), 16 deletions(-) diff --git a/caddyhttp/httpserver/replacer.go b/caddyhttp/httpserver/replacer.go index 958758da..f07c25cc 100644 --- a/caddyhttp/httpserver/replacer.go +++ b/caddyhttp/httpserver/replacer.go @@ -2,8 +2,8 @@ package httpserver import ( "bytes" + "io" "io/ioutil" - "log" "net" "net/http" "net/http/httputil" @@ -127,13 +127,12 @@ func NewReplacer(r *http.Request, rr *ResponseRecorder, emptyValue string) Repla return "" } - body, err := readRequestBody(r) + body, err := readRequestBody(r, maxLogBodySize) if err != nil { - log.Printf("[WARNING] Cannot copy request body %v", err) return "" } - return string(body) + return requestReplacer.Replace(string(body)) }, }, emptyValue: emptyValue, @@ -163,13 +162,18 @@ func canLogRequest(r *http.Request) (canLog bool) { // readRequestBody reads the request body and sets a // new io.ReadCloser that has not yet been read. -func readRequestBody(r *http.Request) ([]byte, error) { - body, err := ioutil.ReadAll(r.Body) +func readRequestBody(r *http.Request, n int64) ([]byte, error) { + body, err := ioutil.ReadAll(io.LimitReader(r.Body, n)) if err != nil { return nil, err } - // Create a new ReadCloser to keep the body from being drained. - r.Body = ioutil.NopCloser(bytes.NewBuffer(body)) + + mr := io.MultiReader( + bytes.NewBuffer(body), + r.Body, + ) + + r.Body = ioutil.NopCloser(mr) return body, nil } @@ -272,4 +276,5 @@ const ( headerContentType = "Content-Type" contentTypeJSON = "application/json" contentTypeXML = "application/xml" + maxLogBodySize = 100 * 1000 ) diff --git a/caddyhttp/httpserver/replacer_test.go b/caddyhttp/httpserver/replacer_test.go index be87d582..e07d2932 100644 --- a/caddyhttp/httpserver/replacer_test.go +++ b/caddyhttp/httpserver/replacer_test.go @@ -2,6 +2,7 @@ package httpserver import ( "bytes" + "io/ioutil" "net/http" "net/http/httptest" "os" @@ -164,23 +165,26 @@ func TestRound(t *testing.T) { } func TestReadRequestBody(t *testing.T) { - r, err := http.NewRequest("POST", "/", strings.NewReader(`null`)) + payload := []byte(`{ "foo": "bar" }`) + var readSize int64 = 5 + r, err := http.NewRequest("POST", "/", bytes.NewReader(payload)) if err != nil { t.Error(err) } defer r.Body.Close() - body, err := readRequestBody(r) + logBody, err := readRequestBody(r, readSize) if err != nil { t.Error("readRequestBody failed", err) + } else if !bytes.EqualFold(payload[0:readSize], logBody) { + t.Error("Expected log comparison failed") } - var data = make([]byte, len(body)) - _, err = r.Body.Read(data) - + // Ensure the Request body is the same as the original. + reqBody, err := ioutil.ReadAll(r.Body) if err != nil { - t.Error(err) - } else if !bytes.Equal(body, data) { - t.Error("Expceted equal bytes.") + t.Error("Unable to read request body", err) + } else if !bytes.EqualFold(payload, reqBody) { + t.Error("Expected request body comparison failed") } } From 532ab661c7d35ea5534f19c843ce2898ecca5d2e Mon Sep 17 00:00:00 2001 From: Carter Date: Thu, 11 Aug 2016 07:03:14 -0400 Subject: [PATCH 5/6] Fully read and close the request body --- caddyhttp/httpserver/replacer.go | 14 +++++++++----- 1 file changed, 9 insertions(+), 5 deletions(-) diff --git a/caddyhttp/httpserver/replacer.go b/caddyhttp/httpserver/replacer.go index f07c25cc..5b84c88e 100644 --- a/caddyhttp/httpserver/replacer.go +++ b/caddyhttp/httpserver/replacer.go @@ -163,17 +163,21 @@ func canLogRequest(r *http.Request) (canLog bool) { // readRequestBody reads the request body and sets a // new io.ReadCloser that has not yet been read. func readRequestBody(r *http.Request, n int64) ([]byte, error) { + defer r.Body.Close() + body, err := ioutil.ReadAll(io.LimitReader(r.Body, n)) if err != nil { return nil, err } - mr := io.MultiReader( - bytes.NewBuffer(body), - r.Body, - ) + // Read the remaining bytes + remaining, err := ioutil.ReadAll(r.Body) + if err != nil { + return nil, err + } - r.Body = ioutil.NopCloser(mr) + buf := bytes.NewBuffer(append(body, remaining...)) + r.Body = ioutil.NopCloser(buf) return body, nil } From 676202a31e22cd2f45cdd3ae1a14497181db0348 Mon Sep 17 00:00:00 2001 From: Carter Date: Thu, 11 Aug 2016 19:08:49 -0400 Subject: [PATCH 6/6] Fixed styling and byte count --- caddyhttp/httpserver/replacer.go | 9 ++++----- 1 file changed, 4 insertions(+), 5 deletions(-) diff --git a/caddyhttp/httpserver/replacer.go b/caddyhttp/httpserver/replacer.go index 5b84c88e..9dc8f3dd 100644 --- a/caddyhttp/httpserver/replacer.go +++ b/caddyhttp/httpserver/replacer.go @@ -147,17 +147,16 @@ func NewReplacer(r *http.Request, rr *ResponseRecorder, emptyValue string) Repla return rep } -func canLogRequest(r *http.Request) (canLog bool) { +func canLogRequest(r *http.Request) bool { if r.Method == "POST" || r.Method == "PUT" { for _, cType := range r.Header[headerContentType] { // the cType could have charset and other info if strings.Index(cType, contentTypeJSON) > -1 || strings.Index(cType, contentTypeXML) > -1 { - canLog = true - break + return true } } } - return + return false } // readRequestBody reads the request body and sets a @@ -280,5 +279,5 @@ const ( headerContentType = "Content-Type" contentTypeJSON = "application/json" contentTypeXML = "application/xml" - maxLogBodySize = 100 * 1000 + maxLogBodySize = 100 * 1024 )