From bbcf76e4af64ff2f1179862f646e3313234b6157 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Beykan=20=C5=9Een?= Date: Fri, 9 Sep 2022 17:10:27 +0300 Subject: [PATCH 1/2] Add level template field to logger. --- middleware/logger.go | 6 ++++++ middleware/logger_test.go | 42 +++++++++++++++++++++++++++++++++++++++ 2 files changed, 48 insertions(+) diff --git a/middleware/logger.go b/middleware/logger.go index a21df8f39..3588eb8c3 100644 --- a/middleware/logger.go +++ b/middleware/logger.go @@ -39,6 +39,7 @@ type ( // - referer // - user_agent // - status + // - level // - error // - latency (In nanoseconds) // - latency_human (Human readable) @@ -180,6 +181,11 @@ func LoggerWithConfig(config LoggerConfig) echo.MiddlewareFunc { s = config.colorer.Cyan(n) } return buf.WriteString(s) + case "level": + if err != nil { + return buf.WriteString("error") + } + return buf.WriteString("info") case "error": if err != nil { // Error may contain invalid JSON e.g. `"` diff --git a/middleware/logger_test.go b/middleware/logger_test.go index ab889bfda..d493bb890 100644 --- a/middleware/logger_test.go +++ b/middleware/logger_test.go @@ -291,3 +291,45 @@ func TestLoggerTemplateWithTimeUnixMicro(t *testing.T) { assert.NoError(t, err) assert.WithinDuration(t, time.Unix(unixMicros/1000000, 0), time.Now(), 3*time.Second) } + +func TestLoggerTemplateWithLevel_withError(t *testing.T) { + buf := new(bytes.Buffer) + + e := echo.New() + e.Use(LoggerWithConfig(LoggerConfig{ + Format: `${level}`, + Output: buf, + })) + + e.GET("/", func(c echo.Context) error { + return errors.New("error") + }) + + req := httptest.NewRequest(http.MethodGet, "/", nil) + + rec := httptest.NewRecorder() + e.ServeHTTP(rec, req) + + assert.Equal(t, "error", buf.String()) +} + +func TestLoggerTemplateWithLevel_withoutError(t *testing.T) { + buf := new(bytes.Buffer) + + e := echo.New() + e.Use(LoggerWithConfig(LoggerConfig{ + Format: `${level}`, + Output: buf, + })) + + e.GET("/", func(c echo.Context) error { + return c.String(http.StatusOK, "OK") + }) + + req := httptest.NewRequest(http.MethodGet, "/", nil) + + rec := httptest.NewRecorder() + e.ServeHTTP(rec, req) + + assert.Equal(t, "info", buf.String()) +} From f9baf149ce4186b55b2ec0776798033fd27485c2 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Beykan=20=C5=9Een?= Date: Fri, 9 Sep 2022 17:51:33 +0300 Subject: [PATCH 2/2] Add LevelSetterFunc to LoggerConfig for level customization based on echo.Context and error. --- middleware/logger.go | 14 ++-- middleware/logger_test.go | 116 ++++++++++++++++++++++++++++++++-- middleware/middleware.go | 11 ++++ middleware/middleware_test.go | 14 +++- 4 files changed, 145 insertions(+), 10 deletions(-) diff --git a/middleware/logger.go b/middleware/logger.go index 3588eb8c3..6426d6766 100644 --- a/middleware/logger.go +++ b/middleware/logger.go @@ -61,6 +61,10 @@ type ( // Optional. Default value os.Stdout. Output io.Writer + // LevelSetter is a logging level setting function. + // Optional. Default value is DefaultLoggingLevelSetter. + LevelSetter LoggingLevelSetterFunc + template *fasttemplate.Template colorer *color.Color pool *sync.Pool @@ -76,6 +80,7 @@ var ( `"status":${status},"error":"${error}","latency":${latency},"latency_human":"${latency_human}"` + `,"bytes_in":${bytes_in},"bytes_out":${bytes_out}}` + "\n", CustomTimeFormat: "2006-01-02 15:04:05.00000", + LevelSetter: DefaultLoggingLevelSetter, colorer: color.New(), } ) @@ -98,6 +103,9 @@ func LoggerWithConfig(config LoggerConfig) echo.MiddlewareFunc { if config.Output == nil { config.Output = DefaultLoggerConfig.Output } + if config.LevelSetter == nil { + config.LevelSetter = DefaultLoggerConfig.LevelSetter + } config.template = fasttemplate.New(config.Format, "${", "}") config.colorer = color.New() @@ -182,10 +190,8 @@ func LoggerWithConfig(config LoggerConfig) echo.MiddlewareFunc { } return buf.WriteString(s) case "level": - if err != nil { - return buf.WriteString("error") - } - return buf.WriteString("info") + level := config.LevelSetter(c, err) + return buf.WriteString(level) case "error": if err != nil { // Error may contain invalid JSON e.g. `"` diff --git a/middleware/logger_test.go b/middleware/logger_test.go index d493bb890..b43c3db99 100644 --- a/middleware/logger_test.go +++ b/middleware/logger_test.go @@ -94,7 +94,7 @@ func TestLoggerTemplate(t *testing.T) { `"method":"${method}","uri":"${uri}","status":${status}, "latency":${latency},` + `"latency_human":"${latency_human}","bytes_in":${bytes_in}, "path":"${path}", "referer":"${referer}",` + `"bytes_out":${bytes_out},"ch":"${header:X-Custom-Header}", "protocol":"${protocol}"` + - `"us":"${query:username}", "cf":"${form:username}", "session":"${cookie:session}"}` + "\n", + `"us":"${query:username}", "cf":"${form:username}", "session":"${cookie:session}"}, "level":"${level}"}` + "\n", Output: buf, })) @@ -135,6 +135,7 @@ func TestLoggerTemplate(t *testing.T) { "echo-tests-agent": true, "6ba7b810-9dad-11d1-80b4-00c04fd430c8": true, "ac08034cd216a647fc2eb62f2bcf7b810": true, + "info": true, } for token, present := range cases { @@ -292,6 +293,33 @@ func TestLoggerTemplateWithTimeUnixMicro(t *testing.T) { assert.WithinDuration(t, time.Unix(unixMicros/1000000, 0), time.Now(), 3*time.Second) } +func TestLoggerTemplateWithLevel_withNoError(t *testing.T) { + buf := new(bytes.Buffer) + + e := echo.New() + e.Use(LoggerWithConfig(LoggerConfig{ + Format: `${level}`, + Output: buf, + LevelSetter: func(_ echo.Context, err error) string { + if err != nil { + return "foo" + } + return "bar" + }, + })) + + e.GET("/", func(c echo.Context) error { + return c.String(http.StatusOK, "OK") + }) + + req := httptest.NewRequest(http.MethodGet, "/", nil) + + rec := httptest.NewRecorder() + e.ServeHTTP(rec, req) + + assert.Equal(t, "bar", buf.String()) +} + func TestLoggerTemplateWithLevel_withError(t *testing.T) { buf := new(bytes.Buffer) @@ -299,6 +327,12 @@ func TestLoggerTemplateWithLevel_withError(t *testing.T) { e.Use(LoggerWithConfig(LoggerConfig{ Format: `${level}`, Output: buf, + LevelSetter: func(_ echo.Context, err error) string { + if err != nil { + return "foo" + } + return "bar" + }, })) e.GET("/", func(c echo.Context) error { @@ -310,26 +344,98 @@ func TestLoggerTemplateWithLevel_withError(t *testing.T) { rec := httptest.NewRecorder() e.ServeHTTP(rec, req) - assert.Equal(t, "error", buf.String()) + assert.Equal(t, "foo", buf.String()) } -func TestLoggerTemplateWithLevel_withoutError(t *testing.T) { +func TestLoggerTemplateWithLevel_withStatusCodeOK(t *testing.T) { buf := new(bytes.Buffer) e := echo.New() e.Use(LoggerWithConfig(LoggerConfig{ Format: `${level}`, Output: buf, + LevelSetter: func(c echo.Context, err error) string { + res := c.Response().Status + switch { + case res >= 500: + return "error" + case res >= 400: + return "warn" + default: + return "info" + } + }, })) e.GET("/", func(c echo.Context) error { - return c.String(http.StatusOK, "OK") + return c.String(200, "foo") }) req := httptest.NewRequest(http.MethodGet, "/", nil) - rec := httptest.NewRecorder() e.ServeHTTP(rec, req) assert.Equal(t, "info", buf.String()) } + +func TestLoggerTemplateWithLevel_withStatusCodeBadRequest(t *testing.T) { + buf := new(bytes.Buffer) + + e := echo.New() + e.Use(LoggerWithConfig(LoggerConfig{ + Format: `${level}`, + Output: buf, + LevelSetter: func(c echo.Context, err error) string { + res := c.Response().Status + switch { + case res >= 500: + return "error" + case res >= 400: + return "warn" + default: + return "info" + } + }, + })) + + e.GET("/", func(c echo.Context) error { + return c.String(400, "foo") + }) + + req := httptest.NewRequest(http.MethodGet, "/", nil) + rec := httptest.NewRecorder() + e.ServeHTTP(rec, req) + + assert.Equal(t, "warn", buf.String()) +} + +func TestLoggerTemplateWithLevel_withStatusCodeInternalServerError(t *testing.T) { + buf := new(bytes.Buffer) + + e := echo.New() + e.Use(LoggerWithConfig(LoggerConfig{ + Format: `${level}`, + Output: buf, + LevelSetter: func(c echo.Context, err error) string { + res := c.Response().Status + switch { + case res >= 500: + return "error" + case res >= 400: + return "warn" + default: + return "info" + } + }, + })) + + e.GET("/", func(c echo.Context) error { + return c.String(500, "foo") + }) + + req := httptest.NewRequest(http.MethodGet, "/", nil) + rec := httptest.NewRecorder() + e.ServeHTTP(rec, req) + + assert.Equal(t, "error", buf.String()) +} diff --git a/middleware/middleware.go b/middleware/middleware.go index f250ca49a..f08f1a713 100644 --- a/middleware/middleware.go +++ b/middleware/middleware.go @@ -16,6 +16,9 @@ type ( // BeforeFunc defines a function which is executed just before the middleware. BeforeFunc func(c echo.Context) + + // LoggingLevelSetterFunc allow set login level based on context and error. + LoggingLevelSetterFunc func(c echo.Context, err error) string ) func captureTokens(pattern *regexp.Regexp, input string) *strings.Replacer { @@ -87,3 +90,11 @@ func rewriteURL(rewriteRegex map[*regexp.Regexp]string, req *http.Request) error func DefaultSkipper(echo.Context) bool { return false } + +// DefaultLoggingLevelSetter returns "error" when error is not nil and returns info when error is nil. +func DefaultLoggingLevelSetter(_ echo.Context, err error) string { + if err != nil { + return "error" + } + return "info" +} diff --git a/middleware/middleware_test.go b/middleware/middleware_test.go index 44f44142c..12a1c044f 100644 --- a/middleware/middleware_test.go +++ b/middleware/middleware_test.go @@ -1,11 +1,13 @@ package middleware import ( - "github.com/stretchr/testify/assert" + "errors" "net/http" "net/http/httptest" "regexp" "testing" + + "github.com/stretchr/testify/assert" ) func TestRewriteURL(t *testing.T) { @@ -90,3 +92,13 @@ func TestRewriteURL(t *testing.T) { }) } } + +func TestDefaultLoggingLevelSetter_withError(t *testing.T) { + level := DefaultLoggingLevelSetter(nil, errors.New("error")) + assert.Equal(t, "error", level) +} + +func TestDefaultLoggingLevelSetter_withoutError(t *testing.T) { + level := DefaultLoggingLevelSetter(nil, nil) + assert.Equal(t, "info", level) +}