From 967237ff45a5b5a87414c392d4a6d5813d04d0a0 Mon Sep 17 00:00:00 2001 From: Tim Voronov Date: Tue, 14 Feb 2023 16:03:33 -0500 Subject: [PATCH] Fixed dobule call of error handler (#21) --- Makefile | 27 +++++++++++++++++ README.md | 14 +++++++++ context.go | 6 +++- go.mod | 25 ++++++++-------- go.sum | 30 +++++++++++++++++++ levels.go | 2 ++ middleware.go | 29 ++++++++++++------- middleware_test.go | 72 ++++++++++++++++++++++++++++++++++++++++++++++ options_test.go | 9 +++--- 9 files changed, 187 insertions(+), 27 deletions(-) create mode 100644 Makefile create mode 100644 middleware_test.go diff --git a/Makefile b/Makefile new file mode 100644 index 0000000..c746b18 --- /dev/null +++ b/Makefile @@ -0,0 +1,27 @@ +default: install build + +add: + go get -u -v ${PKG} + +install-tools: + go install honnef.co/go/tools/cmd/staticcheck@latest && \ + go install golang.org/x/tools/cmd/goimports@latest + + +install-deps: + go mod tidy + +install: install-tools install-deps + +build: lint test + +test: + go test -race ./... + +lint: + go vet ./... && \ + staticcheck -tests=false ./... + +fmt: + go fmt ./... && \ + goimports -w . \ No newline at end of file diff --git a/README.md b/README.md index 57dfe8d..b3d0dcf 100644 --- a/README.md +++ b/README.md @@ -128,6 +128,20 @@ e.Use(lecho.Middleware(lecho.Config{ // Output: {"level":"info","request":{"remote_ip":"5.6.7.8","method":"GET", ...}, ...} ``` +### Enricher + +Enricher allows you to add additional fields to the log entry. + +```go +e.Use(lecho.Middleware(lecho.Config{ + Logger: logger, + Enricher: func(c echo.Context, logger zerolog.Context) zerolog.Context { + return e.Str("user_id", c.Get("user_id")) + }, + })) + // Output: {"level":"info","user_id":"123", ...} +``` + ## Helpers ### Level converters diff --git a/context.go b/context.go index 3c5f5d1..14b4276 100644 --- a/context.go +++ b/context.go @@ -2,14 +2,18 @@ package lecho import ( "context" + "github.com/rs/zerolog" ) -func (l *Logger) WithContext(ctx context.Context) context.Context { +// WithContext returns a new context with the provided logger. +func (l Logger) WithContext(ctx context.Context) context.Context { zerologger := l.Unwrap() return zerologger.WithContext(ctx) } +// Ctx returns a logger from the provided context. +// If no logger is found in the context, a new one is created. func Ctx(ctx context.Context) *zerolog.Logger { return zerolog.Ctx(ctx) } diff --git a/go.mod b/go.mod index a73647c..c03f950 100644 --- a/go.mod +++ b/go.mod @@ -3,24 +3,25 @@ module github.com/ziflex/lecho/v3 go 1.17 require ( - github.com/labstack/echo/v4 v4.9.1 + github.com/labstack/echo/v4 v4.10.0 github.com/labstack/gommon v0.4.0 - github.com/rs/zerolog v1.28.0 - github.com/stretchr/testify v1.7.0 + github.com/rs/zerolog v1.29.0 ) require ( github.com/davecgh/go-spew v1.1.1 // indirect github.com/golang-jwt/jwt v3.2.2+incompatible // indirect - github.com/mattn/go-colorable v0.1.12 // indirect - github.com/mattn/go-isatty v0.0.14 // indirect + github.com/mattn/go-colorable v0.1.13 // indirect + github.com/mattn/go-isatty v0.0.16 // indirect github.com/pmezard/go-difflib v1.0.0 // indirect + github.com/stretchr/objx v0.5.0 // indirect + github.com/stretchr/testify v1.8.1 // indirect github.com/valyala/bytebufferpool v1.0.0 // indirect - github.com/valyala/fasttemplate v1.2.1 // indirect - golang.org/x/crypto v0.0.0-20210817164053-32db794688a5 // indirect - golang.org/x/net v0.0.0-20211015210444-4f30a5c0130f // indirect - golang.org/x/sys v0.0.0-20211103235746-7861aae1554b // indirect - golang.org/x/text v0.3.7 // indirect - golang.org/x/time v0.0.0-20201208040808-7e3f01d25324 // indirect - gopkg.in/yaml.v3 v3.0.0-20210107192922-496545a6307b // indirect + github.com/valyala/fasttemplate v1.2.2 // indirect + golang.org/x/crypto v0.2.0 // indirect + golang.org/x/net v0.4.0 // indirect + golang.org/x/sys v0.3.0 // indirect + golang.org/x/text v0.5.0 // indirect + golang.org/x/time v0.2.0 // indirect + gopkg.in/yaml.v3 v3.0.1 // indirect ) diff --git a/go.sum b/go.sum index 9ee39ee..c99f8d0 100644 --- a/go.sum +++ b/go.sum @@ -7,31 +7,52 @@ github.com/golang-jwt/jwt v3.2.2+incompatible h1:IfV12K8xAKAnZqdXVzCZ+TOjboZ2keL github.com/golang-jwt/jwt v3.2.2+incompatible/go.mod h1:8pz2t5EyA70fFQQSrl6XZXzqecmYZeUEB8OUGHkxJ+I= github.com/labstack/echo/v4 v4.9.1 h1:GliPYSpzGKlyOhqIbG8nmHBo3i1saKWFOgh41AN3b+Y= github.com/labstack/echo/v4 v4.9.1/go.mod h1:Pop5HLc+xoc4qhTZ1ip6C0RtP7Z+4VzRLWZZFKqbbjo= +github.com/labstack/echo/v4 v4.10.0 h1:5CiyngihEO4HXsz3vVsJn7f8xAlWwRr3aY6Ih280ZKA= +github.com/labstack/echo/v4 v4.10.0/go.mod h1:S/T/5fy/GigaXnHTkh0ZGe4LpkkQysvRjFMSUTkDRNQ= github.com/labstack/gommon v0.4.0 h1:y7cvthEAEbU0yHOf4axH8ZG2NH8knB9iNSoTO8dyIk8= github.com/labstack/gommon v0.4.0/go.mod h1:uW6kP17uPlLJsD3ijUYn3/M5bAxtlZhMI6m3MFxTMTM= github.com/mattn/go-colorable v0.1.11/go.mod h1:u5H1YNBxpqRaxsYJYSkiCWKzEfiAb1Gb520KVy5xxl4= github.com/mattn/go-colorable v0.1.12 h1:jF+Du6AlPIjs2BiUiQlKOX0rt3SujHxPnksPKZbaA40= github.com/mattn/go-colorable v0.1.12/go.mod h1:u5H1YNBxpqRaxsYJYSkiCWKzEfiAb1Gb520KVy5xxl4= +github.com/mattn/go-colorable v0.1.13 h1:fFA4WZxdEF4tXPZVKMLwD8oUnCTTo08duU7wxecdEvA= +github.com/mattn/go-colorable v0.1.13/go.mod h1:7S9/ev0klgBDR4GtXTXX8a3vIGJpMovkB8vQcUbaXHg= github.com/mattn/go-isatty v0.0.14 h1:yVuAays6BHfxijgZPzw+3Zlu5yQgKGP2/hcQbHb7S9Y= github.com/mattn/go-isatty v0.0.14/go.mod h1:7GGIvUiUoEMVVmxf/4nioHXj79iQHKdU27kJ6hsGG94= +github.com/mattn/go-isatty v0.0.16 h1:bq3VjFmv/sOjHtdEhmkEV4x1AJtvUvOJ2PFAZ5+peKQ= +github.com/mattn/go-isatty v0.0.16/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/yFXSvRLM= github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= github.com/rs/xid v1.4.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg= github.com/rs/zerolog v1.28.0 h1:MirSo27VyNi7RJYP3078AA1+Cyzd2GB66qy3aUHvsWY= github.com/rs/zerolog v1.28.0/go.mod h1:NILgTygv/Uej1ra5XxGf82ZFSLk58MFGAUS2o6usyD0= +github.com/rs/zerolog v1.29.0 h1:Zes4hju04hjbvkVkOhdl2HpZa+0PmVwigmo8XoORE5w= +github.com/rs/zerolog v1.29.0/go.mod h1:NILgTygv/Uej1ra5XxGf82ZFSLk58MFGAUS2o6usyD0= github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= +github.com/stretchr/objx v0.4.0/go.mod h1:YvHI0jy2hoMjB+UWwv71VJQ9isScKT/TqJzVSSt89Yw= +github.com/stretchr/objx v0.5.0 h1:1zr/of2m5FGMsad5YfcqgdqdWrIhu+EBEJRhR1U7z/c= +github.com/stretchr/objx v0.5.0/go.mod h1:Yh+to48EsGEfYuaHDzXPcE3xhTkx73EhmCGUpEOglKo= github.com/stretchr/testify v1.7.0 h1:nwc3DEeHmmLAfoZucVR881uASk0Mfjw8xYJ99tb5CcY= github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= +github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= +github.com/stretchr/testify v1.8.0/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU= +github.com/stretchr/testify v1.8.1 h1:w7B6lhMri9wdJUVmEZPGGhZzrYTPvgJArz7wNPgYKsk= +github.com/stretchr/testify v1.8.1/go.mod h1:w2LPCIKwWwSfY2zedu0+kehJoqGctiVI29o6fzry7u4= github.com/valyala/bytebufferpool v1.0.0 h1:GqA5TC/0021Y/b9FG4Oi9Mr3q7XYx6KllzawFIhcdPw= github.com/valyala/bytebufferpool v1.0.0/go.mod h1:6bBcMArwyJ5K/AmCkWv1jt77kVWyCJ6HpOuEn7z0Csc= github.com/valyala/fasttemplate v1.2.1 h1:TVEnxayobAdVkhQfrfes2IzOB6o+z4roRkPF52WA1u4= github.com/valyala/fasttemplate v1.2.1/go.mod h1:KHLXt3tVN2HBp8eijSv/kGJopbvo7S+qRAEEKiv+SiQ= +github.com/valyala/fasttemplate v1.2.2 h1:lxLXG0uE3Qnshl9QyaK6XJxMXlQZELvChBOCmQD0Loo= +github.com/valyala/fasttemplate v1.2.2/go.mod h1:KHLXt3tVN2HBp8eijSv/kGJopbvo7S+qRAEEKiv+SiQ= golang.org/x/crypto v0.0.0-20210817164053-32db794688a5 h1:HWj/xjIHfjYU5nVXpTM0s39J9CbLn7Cc5a7IC5rwsMQ= golang.org/x/crypto v0.0.0-20210817164053-32db794688a5/go.mod h1:GvvjBRRGRdwPK5ydBHafDWAxML/pGHZbMvKqRZ5+Abc= +golang.org/x/crypto v0.2.0 h1:BRXPfhNivWL5Yq0BGQ39a2sW6t44aODpfxkWjYdzewE= +golang.org/x/crypto v0.2.0/go.mod h1:hebNnKkNXi2UzZN1eVRvBB7co0a+JxK6XbPiWVs/3J4= golang.org/x/net v0.0.0-20210226172049-e18ecbb05110/go.mod h1:m0MpNAwzfU5UDzcl9v0D8zg8gWTRqZa9RBIspLL5mdg= golang.org/x/net v0.0.0-20211015210444-4f30a5c0130f h1:OfiFi4JbukWwe3lzw+xunroH1mnC1e2Gy5cxNJApiSY= golang.org/x/net v0.0.0-20211015210444-4f30a5c0130f/go.mod h1:9nx3DQGgdP8bBQD5qxJ1jj9UTztislL4KSBs9R2vV5Y= +golang.org/x/net v0.4.0 h1:Q5QPcMlvfxFTAPV0+07Xz/MpK9NTXu2VDUuy0FeMfaU= +golang.org/x/net v0.4.0/go.mod h1:MBQ8lrhLObU/6UmLb4fmbmk5OcyYmqtbGd/9yIeKjEE= golang.org/x/sys v0.0.0-20201119102817-f84b799fce68/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20210423082822-04245dca01da/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= @@ -39,16 +60,25 @@ golang.org/x/sys v0.0.0-20210630005230-0f9fa26af87c/go.mod h1:oPkhp1MJrh7nUepCBc golang.org/x/sys v0.0.0-20210927094055-39ccf1dd6fa6/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.0.0-20211103235746-7861aae1554b h1:1VkfZQv42XQlA/jchYumAnv1UPo6RgF9rJFkTgZIxO4= golang.org/x/sys v0.0.0-20211103235746-7861aae1554b/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.3.0 h1:w8ZOecv6NaNa/zC8944JTU3vz4u6Lagfk4RPQxv92NQ= +golang.org/x/sys v0.3.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo= golang.org/x/text v0.3.3/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ= golang.org/x/text v0.3.6/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ= golang.org/x/text v0.3.7 h1:olpwvP2KacW1ZWvsR7uQhoyTYvKAupfQrRGBFM352Gk= golang.org/x/text v0.3.7/go.mod h1:u+2+/6zg+i71rQMx5EYifcz6MCKuco9NR6JIITiCfzQ= +golang.org/x/text v0.5.0 h1:OLmvp0KP+FVG99Ct/qFiL/Fhk4zp4QQnZ7b2U+5piUM= +golang.org/x/text v0.5.0/go.mod h1:mrYo+phRRbMaCq/xk9113O4dZlRixOauAjOtrjsXDZ8= golang.org/x/time v0.0.0-20201208040808-7e3f01d25324 h1:Hir2P/De0WpUhtrKGGjvSb2YxUgyZ7EFOSLIcSSpiwE= golang.org/x/time v0.0.0-20201208040808-7e3f01d25324/go.mod h1:tRJNPiyCQ0inRvYxbN9jk5I+vvW/OXSQhTDSoE431IQ= +golang.org/x/time v0.2.0 h1:52I/1L54xyEQAYdtcSuxtiT84KGYTBGXwayxmIpNJhE= +golang.org/x/time v0.2.0/go.mod h1:tRJNPiyCQ0inRvYxbN9jk5I+vvW/OXSQhTDSoE431IQ= golang.org/x/tools v0.0.0-20180917221912-90fa682c2a6e/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= gopkg.in/yaml.v3 v3.0.0-20210107192922-496545a6307b h1:h8qDotaEPuJATrMmW04NCwg7v22aHH28wwpauUhK9Oo= gopkg.in/yaml.v3 v3.0.0-20210107192922-496545a6307b/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= +gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA= +gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= diff --git a/levels.go b/levels.go index b774af1..7787a81 100644 --- a/levels.go +++ b/levels.go @@ -24,6 +24,7 @@ var ( } ) +// MatchEchoLevel returns a zerolog level and echo level for a given echo level func MatchEchoLevel(level log.Lvl) (zerolog.Level, log.Lvl) { zlvl, found := echoLevels[level] @@ -34,6 +35,7 @@ func MatchEchoLevel(level log.Lvl) (zerolog.Level, log.Lvl) { return zerolog.NoLevel, log.OFF } +// MatchZeroLevel returns an echo level and zerolog level for a given zerolog level func MatchZeroLevel(level zerolog.Level) (log.Lvl, zerolog.Level) { elvl, found := zeroLevels[level] diff --git a/middleware.go b/middleware.go index 40452b1..01b6ca1 100644 --- a/middleware.go +++ b/middleware.go @@ -13,24 +13,35 @@ import ( ) type ( + // Config is the configuration for the middleware. Config struct { - Logger *Logger - Skipper middleware.Skipper - BeforeNext middleware.BeforeFunc - Enricher Enricher + // Logger is a custom instance of the logger to use. + Logger *Logger + // Skipper defines a function to skip middleware. + Skipper middleware.Skipper + // BeforeNext is a function that is executed before the next handler is called. + BeforeNext middleware.BeforeFunc + // Enricher is a function that can be used to enrich the logger with additional information. + Enricher Enricher + // RequestIDHeader is the header name to use for the request ID in a log record. RequestIDHeader string - RequestIDKey string - NestKey string + // RequestIDKey is the key name to use for the request ID in a log record. + RequestIDKey string + // NestKey is the key name to use for the nested logger in a log record. + NestKey string } + // Enricher is a function that can be used to enrich the logger with additional information. Enricher func(c echo.Context, logger zerolog.Context) zerolog.Context + // Context is a wrapper around echo.Context that provides a logger. Context struct { echo.Context logger *Logger } ) +// NewContext returns a new Context. func NewContext(ctx echo.Context, logger *Logger) *Context { return &Context{ctx, logger} } @@ -39,6 +50,7 @@ func (c *Context) Logger() echo.Logger { return c.logger } +// Middleware returns a middleware which logs HTTP requests. func Middleware(config Config) echo.MiddlewareFunc { if config.Skipper == nil { config.Skipper = middleware.DefaultSkipper @@ -105,10 +117,7 @@ func Middleware(config Config) echo.MiddlewareFunc { config.BeforeNext(c) } - if err = next(c); err != nil { - c.Error(err) - } - + err = next(c) stop := time.Now() var mainEvt *zerolog.Event diff --git a/middleware_test.go b/middleware_test.go new file mode 100644 index 0000000..64d8dd6 --- /dev/null +++ b/middleware_test.go @@ -0,0 +1,72 @@ +package lecho_test + +import ( + "bytes" + "errors" + "net/http" + "net/http/httptest" + "testing" + + "github.com/labstack/echo/v4" + "github.com/rs/zerolog" + "github.com/stretchr/testify/assert" + "github.com/ziflex/lecho/v3" +) + +func TestMiddleware(t *testing.T) { + t.Run("should not trigger error handler", func(t *testing.T) { + var called bool + e := echo.New() + e.HTTPErrorHandler = func(err error, c echo.Context) { + called = true + + c.JSON(http.StatusInternalServerError, err.Error()) + } + req := httptest.NewRequest(http.MethodGet, "/", nil) + req.Header.Set(echo.HeaderContentType, echo.MIMEApplicationJSON) + rec := httptest.NewRecorder() + c := e.NewContext(req, rec) + + m := lecho.Middleware(lecho.Config{}) + + next := func(c echo.Context) error { + return errors.New("error") + } + + handler := m(next) + err := handler(c) + + assert.Error(t, err, "should return error") + assert.False(t, called, "should not call error handler") + }) + + t.Run("should use enricher", 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) + m := lecho.Middleware(lecho.Config{ + Logger: l, + Enricher: func(c echo.Context, logger zerolog.Context) zerolog.Context { + return logger.Str("test", "test") + }, + }) + + next := func(c echo.Context) error { + return nil + } + + handler := m(next) + err := handler(c) + + assert.NoError(t, err, "should not return error") + + str := b.String() + assert.Contains(t, str, `"test":"test"`) + }) +} diff --git a/options_test.go b/options_test.go index cc4b83e..dc94f82 100644 --- a/options_test.go +++ b/options_test.go @@ -3,14 +3,15 @@ package lecho_test import ( "bytes" "encoding/json" - "github.com/labstack/gommon/log" - "github.com/rs/zerolog" - "github.com/stretchr/testify/assert" - "github.com/ziflex/lecho/v3" "path/filepath" "strings" "testing" "time" + + "github.com/labstack/gommon/log" + "github.com/rs/zerolog" + "github.com/stretchr/testify/assert" + "github.com/ziflex/lecho/v3" ) func TestWithCaller(t *testing.T) {