diff --git a/README.md b/README.md index d0fe206..f5599e4 100644 --- a/README.md +++ b/README.md @@ -116,8 +116,19 @@ func main() { return c.String(http.StatusOK, "Hello, World!") }) } + +``` + +### Escalate log level for slow requests: +```go +e.Use(lecho.Middleware(lecho.Config{ + Logger: logger, + RequestLatencyLevel: zerolog.WarnLevel, + RequestLatencyLimit: 500 * time.Millisecond, +})) ``` + ### Nesting under a sub dictionary ```go diff --git a/middleware.go b/middleware.go index 2969f54..55d8b96 100644 --- a/middleware.go +++ b/middleware.go @@ -31,6 +31,10 @@ type ( NestKey string // HandleError indicates whether to propagate errors up the middleware chain, so the global error handler can decide appropriate status code. HandleError bool + // For long-running requests that take longer than this limit, log at a different level. Ignored by default + RequestLatencyLimit time.Duration + // The level to log at if RequestLatencyLimit is exceeded + RequestLatencyLevel zerolog.Level } // Enricher is a function that can be used to enrich the logger with additional information. @@ -126,10 +130,12 @@ func Middleware(config Config) echo.MiddlewareFunc { } stop := time.Now() - + latency := stop.Sub(start) var mainEvt *zerolog.Event if err != nil { mainEvt = logger.log.Err(err) + } else if config.RequestLatencyLimit != 0 && latency > config.RequestLatencyLimit { + mainEvt = logger.log.WithLevel(config.RequestLatencyLevel) } else { mainEvt = logger.log.WithLevel(logger.log.GetLevel()) } @@ -148,8 +154,8 @@ func Middleware(config Config) echo.MiddlewareFunc { evt.Str("user_agent", req.UserAgent()) evt.Int("status", res.Status) evt.Str("referer", req.Referer()) - evt.Dur("latency", stop.Sub(start)) - evt.Str("latency_human", stop.Sub(start).String()) + evt.Dur("latency", latency) + evt.Str("latency_human", latency.String()) cl := req.Header.Get(echo.HeaderContentLength) if cl == "" { diff --git a/middleware_test.go b/middleware_test.go index 02c3e23..14bc7e3 100644 --- a/middleware_test.go +++ b/middleware_test.go @@ -6,8 +6,10 @@ import ( "net/http" "net/http/httptest" "testing" + "time" "github.com/labstack/echo/v4" + "github.com/labstack/gommon/log" "github.com/rs/zerolog" "github.com/stretchr/testify/assert" "github.com/ziflex/lecho/v3" @@ -97,4 +99,66 @@ func TestMiddleware(t *testing.T) { str := b.String() assert.Contains(t, str, `"test":"test"`) }) + + t.Run("should escalate log level for slow requests", func(t *testing.T) { + e := echo.New() + req := httptest.NewRequest(http.MethodGet, "/", nil) + req.Header.Set(echo.HeaderContentType, echo.MIMEApplicationJSON) + rec := httptest.NewRecorder() + c := e.NewContext(req, rec) + + b := &bytes.Buffer{} + l := lecho.New(b) + l.SetLevel(log.INFO) + m := lecho.Middleware(lecho.Config{ + Logger: l, + RequestLatencyLimit: 5 * time.Millisecond, + RequestLatencyLevel: zerolog.WarnLevel, + }) + + // Slow request should be logged at the escalated level + next := func(c echo.Context) error { + time.Sleep(5 * time.Millisecond) + return nil + } + handler := m(next) + err := handler(c) + assert.NoError(t, err, "should not return error") + + str := b.String() + assert.Contains(t, str, `"level":"warn"`) + assert.NotContains(t, str, `"level":"info"`) + }) + + t.Run("shouldn't escalate log level for fast requests", func(t *testing.T) { + e := echo.New() + req := httptest.NewRequest(http.MethodGet, "/", nil) + req.Header.Set(echo.HeaderContentType, echo.MIMEApplicationJSON) + rec := httptest.NewRecorder() + c := e.NewContext(req, rec) + + b := &bytes.Buffer{} + l := lecho.New(b) + l.SetLevel(log.INFO) + m := lecho.Middleware(lecho.Config{ + Logger: l, + RequestLatencyLimit: 5 * time.Millisecond, + RequestLatencyLevel: zerolog.WarnLevel, + }) + + // Fast request should be logged at the default level + next := func(c echo.Context) error { + time.Sleep(1 * time.Millisecond) + return nil + } + + handler := m(next) + err := handler(c) + + assert.NoError(t, err, "should not return error") + + str := b.String() + assert.Contains(t, str, `"level":"info"`) + assert.NotContains(t, str, `"level":"warn"`) + }) }