fix(leak): don't mutate logger, just make events from it

logger.go

@@ -76,8 +76,9 @@ func SetLogger(opts ...Option) gin.HandlerFunc {
  Timestamp().
  Logger()
  return func(c *gin.Context) {
+ rl := l
  if cfg.logger != nil {
- l = cfg.logger(c, l)
+ rl = cfg.logger(c, l)
  }
 
  start := time.Now()
@@ -112,43 +113,33 @@ func SetLogger(opts ...Option) gin.HandlerFunc {
  }
  latency := end.Sub(start)
 
- l = l.With().
- Int("status", c.Writer.Status()).
- Str("method", c.Request.Method).
- Str("path", path).
- Str("ip", c.ClientIP()).
- Dur("latency", latency).
- Str("user_agent", c.Request.UserAgent()).
- Int("body_size", c.Writer.Size()).
- Logger()
-
  msg := "Request"
  if len(c.Errors) > 0 {
  msg = c.Errors.String()
  }
 
+ var evt *zerolog.Event
  level, hasLevel := cfg.pathLevels[path]
 
  switch {
  case c.Writer.Status() >= http.StatusBadRequest && c.Writer.Status() < http.StatusInternalServerError:
- {
- l.WithLevel(cfg.clientErrorLevel).
- Msg(msg)
- }
+ evt = rl.WithLevel(cfg.clientErrorLevel)
  case c.Writer.Status() >= http.StatusInternalServerError:
- {
- l.WithLevel(cfg.serverErrorLevel).
- Msg(msg)
- }
+ evt = rl.WithLevel(cfg.serverErrorLevel)
  case hasLevel:
- {
- l.WithLevel(level).
- Msg(msg)
- }
+ evt = rl.WithLevel(level)
  default:
- l.WithLevel(cfg.defaultLevel).
- Msg(msg)
+ evt = rl.WithLevel(cfg.defaultLevel)
  }
+ evt.
+ Int("status", c.Writer.Status()).
+ Str("method", c.Request.Method).
+ Str("path", path).
+ Str("ip", c.ClientIP()).
+ Dur("latency", latency).
+ Str("user_agent", c.Request.UserAgent()).
+ Int("body_size", c.Writer.Size()).
+ Msg(msg)
  }
  }
 }

logger_test.go

@@ -3,9 +3,12 @@ package logger
 import (
  "bytes"
  "context"
+ "fmt"
  "net/http"
  "net/http/httptest"
  "regexp"
+ "strings"
+ "sync"
  "testing"
 
  "github.com/gin-gonic/gin"
@@ -151,6 +154,52 @@ func TestLoggerWithLevels(t *testing.T) {
  assert.Contains(t, buffer.String(), "FTL")
 }
 
+type concurrentBuffer struct {
+ mu sync.Mutex
+ b bytes.Buffer
+}
+
+func (b *concurrentBuffer) Write(p []byte) (n int, err error) {
+ b.mu.Lock()
+ defer b.mu.Unlock()
+ return b.b.Write(p)
+}
+
+func TestCustomLoggerIssue68(t *testing.T) {
+ buffer := new(concurrentBuffer)
+ gin.SetMode(gin.ReleaseMode)
+ r := gin.New()
+ l := zerolog.New(buffer)
+ r.Use(SetLogger(
+ WithLogger(func(*gin.Context, zerolog.Logger) zerolog.Logger { return l }),
+ WithDefaultLevel(zerolog.DebugLevel),
+ WithClientErrorLevel(zerolog.ErrorLevel),
+ WithServerErrorLevel(zerolog.FatalLevel),
+ ))
+ r.GET("/example", func(c *gin.Context) {})
+
+ // concurrent requests should only have their info logged once
+ var wg sync.WaitGroup
+ for i := 0; i < 10; i++ {
+ wg.Add(1)
+ req := fmt.Sprintf("/example?a=%d", i)
+ go func() {
+ defer wg.Done()
+ performRequest(r, "GET", req)
+ }()
+ }
+ wg.Wait()
+
+ bs := buffer.b.String()
+ for i := 0; i < 10; i++ {
+ // should contain each request log exactly once
+ msg := fmt.Sprintf("/example?a=%d", i)
+ if assert.Contains(t, bs, msg) {
+ assert.Equal(t, strings.Index(bs, msg), strings.LastIndex(bs, msg))
+ }
+ }
+}
+
 func TestLoggerParseLevel(t *testing.T) {
  type args struct {
  levelStr string