From 2777847629d4eaf2698e27a7a69c1f30855748ba Mon Sep 17 00:00:00 2001 From: Roman Suvorov Date: Fri, 11 Dec 2020 17:18:36 +0300 Subject: [PATCH 1/4] LogRoundTrip request nil pointer defreference --- estransport/logger.go | 42 +++++++++++++++++++++++++++++++++++++----- 1 file changed, 37 insertions(+), 5 deletions(-) diff --git a/estransport/logger.go b/estransport/logger.go index 4f0af98a3a..ca23ff832f 100644 --- a/estransport/logger.go +++ b/estransport/logger.go @@ -8,6 +8,7 @@ import ( "bufio" "bytes" "encoding/json" + "errors" "fmt" "io" "io/ioutil" @@ -80,6 +81,12 @@ type debuggingLogger struct { // LogRoundTrip prints the information about request and response. // func (l *TextLogger) LogRoundTrip(req *http.Request, res *http.Response, err error, start time.Time, dur time.Duration) error { + if req == nil { + return errors.New("request is empty") + } + if req.URL == nil { + return errors.New("request URL is empty") + } fmt.Fprintf(l.Output, "%s %s %s [status:%d request:%s]\n", start.Format(time.RFC3339), req.Method, @@ -87,7 +94,7 @@ func (l *TextLogger) LogRoundTrip(req *http.Request, res *http.Response, err err resStatusCode(res), dur.Truncate(time.Millisecond), ) - if l.RequestBodyEnabled() && req != nil && req.Body != nil && req.Body != http.NoBody { + if l.RequestBodyEnabled() && req.Body != nil && req.Body != http.NoBody { var buf bytes.Buffer if req.GetBody != nil { b, _ := req.GetBody() @@ -118,6 +125,16 @@ func (l *TextLogger) ResponseBodyEnabled() bool { return l.EnableResponseBody } // LogRoundTrip prints the information about request and response. // func (l *ColorLogger) LogRoundTrip(req *http.Request, res *http.Response, err error, start time.Time, dur time.Duration) error { + if req == nil { + return errors.New("request is empty") + } + if req.URL == nil { + return errors.New("request URL is empty") + } + if res == nil { + return errors.New("response is empty") + } + query, _ := url.QueryUnescape(req.URL.RawQuery) if query != "" { query = "?" + query @@ -152,7 +169,7 @@ func (l *ColorLogger) LogRoundTrip(req *http.Request, res *http.Response, err er dur.Truncate(time.Millisecond), ) - if l.RequestBodyEnabled() && req != nil && req.Body != nil && req.Body != http.NoBody { + if l.RequestBodyEnabled() && req.Body != nil && req.Body != http.NoBody { var buf bytes.Buffer if req.GetBody != nil { b, _ := req.GetBody() @@ -165,7 +182,7 @@ func (l *ColorLogger) LogRoundTrip(req *http.Request, res *http.Response, err er fmt.Fprint(l.Output, "\x1b[0m") } - if l.ResponseBodyEnabled() && res != nil && res.Body != nil && res.Body != http.NoBody { + if l.ResponseBodyEnabled() && res.Body != nil && res.Body != http.NoBody { defer res.Body.Close() var buf bytes.Buffer buf.ReadFrom(res.Body) @@ -193,6 +210,13 @@ func (l *ColorLogger) ResponseBodyEnabled() bool { return l.EnableResponseBody } // LogRoundTrip prints the information about request and response. // func (l *CurlLogger) LogRoundTrip(req *http.Request, res *http.Response, err error, start time.Time, dur time.Duration) error { + if req == nil { + return errors.New("request is empty") + } + if req.URL == nil { + return errors.New("request URL is empty") + } + var b bytes.Buffer var query string @@ -252,7 +276,9 @@ func (l *CurlLogger) LogRoundTrip(req *http.Request, res *http.Response, err err b.WriteRune('\n') var status string - status = res.Status + if res != nil { + status = res.Status + } fmt.Fprintf(&b, "# => %s [%s] %s\n", start.UTC().Format(time.RFC3339), status, dur.Truncate(time.Millisecond)) if l.ResponseBodyEnabled() && res != nil && res.Body != nil && res.Body != http.NoBody { @@ -286,6 +312,12 @@ func (l *JSONLogger) LogRoundTrip(req *http.Request, res *http.Response, err err // https://github.com/elastic/ecs/blob/master/schemas/http.yml // // TODO(karmi): Research performance optimization of using sync.Pool + if req == nil { + return errors.New("request is empty") + } + if req.URL == nil { + return errors.New("request URL is empty") + } bsize := 200 var b = bytes.NewBuffer(make([]byte, 0, bsize)) @@ -342,7 +374,7 @@ func (l *JSONLogger) LogRoundTrip(req *http.Request, res *http.Response, err err b.WriteString(`{"request":{`) b.WriteString(`"method":`) appendQuote(req.Method) - if l.RequestBodyEnabled() && req != nil && req.Body != nil && req.Body != http.NoBody { + if l.RequestBodyEnabled() && req.Body != nil && req.Body != http.NoBody { var buf bytes.Buffer if req.GetBody != nil { b, _ := req.GetBody() From b88b45a57f59b56993f102f55247bb3b9773e77b Mon Sep 17 00:00:00 2001 From: Roman Suvorov Date: Mon, 14 Dec 2020 12:17:23 +0300 Subject: [PATCH 2/4] reqURL to var --- estransport/logger.go | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/estransport/logger.go b/estransport/logger.go index ca23ff832f..5abf393a00 100644 --- a/estransport/logger.go +++ b/estransport/logger.go @@ -216,12 +216,13 @@ func (l *CurlLogger) LogRoundTrip(req *http.Request, res *http.Response, err err if req.URL == nil { return errors.New("request URL is empty") } + reqURL := req.URL var b bytes.Buffer var query string qvalues := url.Values{} - for k, v := range req.URL.Query() { + for k, v := range reqURL.Query() { if k == "pretty" { continue } @@ -251,7 +252,7 @@ func (l *CurlLogger) LogRoundTrip(req *http.Request, res *http.Response, err err } b.WriteString(" 'http://localhost:9200") - b.WriteString(req.URL.Path) + b.WriteString(reqURL.Path) b.WriteString("?pretty") if query != "" { fmt.Fprintf(&b, "&%s", query) From 5d38c976dbe2c165c6c7e652f6f1f373a487a29e Mon Sep 17 00:00:00 2001 From: Roman Suvorov Date: Mon, 14 Dec 2020 14:33:15 +0300 Subject: [PATCH 3/4] tests for LogRoundTrip --- estransport/logger.go | 25 +++++--- estransport/logger_internal_test.go | 98 +++++++++++++++++++++++++++++ 2 files changed, 113 insertions(+), 10 deletions(-) diff --git a/estransport/logger.go b/estransport/logger.go index 5abf393a00..624aac99e9 100644 --- a/estransport/logger.go +++ b/estransport/logger.go @@ -19,7 +19,12 @@ import ( "time" ) -var debugLogger DebuggingLogger +var ( + debugLogger DebuggingLogger + errRequestEmpty = errors.New("request is empty") + errRequestURLEmpty = errors.New("request URL is empty") + errResponseEmpty = errors.New("response is empty") +) // Logger defines an interface for logging request and response. // @@ -82,10 +87,10 @@ type debuggingLogger struct { // func (l *TextLogger) LogRoundTrip(req *http.Request, res *http.Response, err error, start time.Time, dur time.Duration) error { if req == nil { - return errors.New("request is empty") + return errRequestEmpty } if req.URL == nil { - return errors.New("request URL is empty") + return errRequestURLEmpty } fmt.Fprintf(l.Output, "%s %s %s [status:%d request:%s]\n", start.Format(time.RFC3339), @@ -126,13 +131,13 @@ func (l *TextLogger) ResponseBodyEnabled() bool { return l.EnableResponseBody } // func (l *ColorLogger) LogRoundTrip(req *http.Request, res *http.Response, err error, start time.Time, dur time.Duration) error { if req == nil { - return errors.New("request is empty") + return errRequestEmpty } if req.URL == nil { - return errors.New("request URL is empty") + return errRequestURLEmpty } if res == nil { - return errors.New("response is empty") + return errResponseEmpty } query, _ := url.QueryUnescape(req.URL.RawQuery) @@ -211,10 +216,10 @@ func (l *ColorLogger) ResponseBodyEnabled() bool { return l.EnableResponseBody } // func (l *CurlLogger) LogRoundTrip(req *http.Request, res *http.Response, err error, start time.Time, dur time.Duration) error { if req == nil { - return errors.New("request is empty") + return errRequestEmpty } if req.URL == nil { - return errors.New("request URL is empty") + return errRequestURLEmpty } reqURL := req.URL @@ -314,10 +319,10 @@ func (l *JSONLogger) LogRoundTrip(req *http.Request, res *http.Response, err err // // TODO(karmi): Research performance optimization of using sync.Pool if req == nil { - return errors.New("request is empty") + return errRequestEmpty } if req.URL == nil { - return errors.New("request URL is empty") + return errRequestURLEmpty } bsize := 200 diff --git a/estransport/logger_internal_test.go b/estransport/logger_internal_test.go index cd60cfa7e0..0f020f8ad6 100644 --- a/estransport/logger_internal_test.go +++ b/estransport/logger_internal_test.go @@ -7,6 +7,7 @@ package estransport import ( + "bytes" "encoding/json" "errors" "fmt" @@ -430,6 +431,103 @@ func TestTransportLogger(t *testing.T) { }) } +func TestLoggers(t *testing.T) { + start := time.Now() + dur := time.Second + t.Run("TextLogger req == nil", func(t *testing.T) { + var buff bytes.Buffer + logger := TextLogger{Output: &buff} + err := logger.LogRoundTrip(nil, nil, nil, start, dur) + if !errors.Is(err, errRequestEmpty) { + t.Errorf("Expected error `%s`, got `%v`", errRequestEmpty, err) + } + }) + t.Run("TextLogger req.URL == nil", func(t *testing.T) { + var buff bytes.Buffer + logger := TextLogger{Output: &buff} + req := http.Request{ + Method: http.MethodGet, + } + + err := logger.LogRoundTrip(&req, nil, nil, start, dur) + if !errors.Is(err, errRequestURLEmpty) { + t.Errorf("Expected error `%s`, got `%v`", errRequestURLEmpty, err) + } + }) + t.Run("ColorLogger req == nil", func(t *testing.T) { + var buff bytes.Buffer + logger := ColorLogger{Output: &buff} + err := logger.LogRoundTrip(nil, nil, nil, start, dur) + if !errors.Is(err, errRequestEmpty) { + t.Errorf("Expected error `%s`, got `%v`", errRequestEmpty, err) + } + }) + t.Run("ColorLogger req.URL == nil", func(t *testing.T) { + var buff bytes.Buffer + logger := ColorLogger{Output: &buff} + req := http.Request{ + Method: http.MethodGet, + } + + err := logger.LogRoundTrip(&req, nil, nil, start, dur) + if !errors.Is(err, errRequestURLEmpty) { + t.Errorf("Expected error `%s`, got `%v`", errRequestURLEmpty, err) + } + }) + t.Run("ColorLogger res == nil", func(t *testing.T) { + var buff bytes.Buffer + logger := ColorLogger{Output: &buff} + req, err := http.NewRequest(http.MethodGet, "http:example.com", nil) + if err != nil { + t.Errorf("Unexpected error: %s", err) + } + err = logger.LogRoundTrip(req, nil, nil, start, dur) + if !errors.Is(err, errResponseEmpty) { + t.Errorf("Expected error `%s`, got `%v`", errResponseEmpty, err) + } + }) + t.Run("CurlLogger req == nil", func(t *testing.T) { + var buff bytes.Buffer + logger := CurlLogger{Output: &buff} + err := logger.LogRoundTrip(nil, nil, nil, start, dur) + if !errors.Is(err, errRequestEmpty) { + t.Errorf("Expected error `%s`, got `%v`", errRequestEmpty, err) + } + }) + t.Run("CurlLogger req.URL == nil", func(t *testing.T) { + var buff bytes.Buffer + logger := CurlLogger{Output: &buff} + req := http.Request{ + Method: http.MethodGet, + } + + err := logger.LogRoundTrip(&req, nil, nil, start, dur) + if !errors.Is(err, errRequestURLEmpty) { + t.Errorf("Expected error `%s`, got `%v`", errRequestURLEmpty, err) + } + }) + t.Run("JSONLogger req == nil", func(t *testing.T) { + var buff bytes.Buffer + logger := JSONLogger{Output: &buff} + err := logger.LogRoundTrip(nil, nil, nil, start, dur) + if !errors.Is(err, errRequestEmpty) { + t.Errorf("Expected error `%s`, got `%v`", errRequestEmpty, err) + } + }) + t.Run("JSONLogger req.URL == nil", func(t *testing.T) { + var buff bytes.Buffer + logger := JSONLogger{Output: &buff} + req := http.Request{ + Method: http.MethodGet, + } + + err := logger.LogRoundTrip(&req, nil, nil, start, dur) + if !errors.Is(err, errRequestURLEmpty) { + t.Errorf("Expected error `%s`, got `%v`", errRequestURLEmpty, err) + } + }) +} + func TestDebuggingLogger(t *testing.T) { logger := &debuggingLogger{Output: ioutil.Discard} From 738825680442d63c333b75fb6fc997597aad146d Mon Sep 17 00:00:00 2001 From: Roman Suvorov Date: Tue, 15 Dec 2020 10:42:32 +0300 Subject: [PATCH 4/4] move req check closer to useage --- estransport/logger.go | 19 +++++++++---------- 1 file changed, 9 insertions(+), 10 deletions(-) diff --git a/estransport/logger.go b/estransport/logger.go index 624aac99e9..fac880e5f0 100644 --- a/estransport/logger.go +++ b/estransport/logger.go @@ -136,10 +136,6 @@ func (l *ColorLogger) LogRoundTrip(req *http.Request, res *http.Response, err er if req.URL == nil { return errRequestURLEmpty } - if res == nil { - return errResponseEmpty - } - query, _ := url.QueryUnescape(req.URL.RawQuery) if query != "" { query = "?" + query @@ -150,6 +146,9 @@ func (l *ColorLogger) LogRoundTrip(req *http.Request, res *http.Response, err er color string ) + if res == nil { + return errResponseEmpty + } status = res.Status switch { case res.StatusCode > 0 && res.StatusCode < 300: @@ -318,12 +317,6 @@ func (l *JSONLogger) LogRoundTrip(req *http.Request, res *http.Response, err err // https://github.com/elastic/ecs/blob/master/schemas/http.yml // // TODO(karmi): Research performance optimization of using sync.Pool - if req == nil { - return errRequestEmpty - } - if req.URL == nil { - return errRequestURLEmpty - } bsize := 200 var b = bytes.NewBuffer(make([]byte, 0, bsize)) @@ -347,6 +340,12 @@ func (l *JSONLogger) LogRoundTrip(req *http.Request, res *http.Response, err err b.Write(v) } + if req == nil { + return errRequestEmpty + } + if req.URL == nil { + return errRequestURLEmpty + } port := req.URL.Port() b.WriteRune('{')