move attributes tot nested group - first commit of the year

README.md

@@ -81,7 +81,7 @@ router.GET("/pong", func(c *gin.Context) {
 router.Run(":1234")
 
 // output:
-// time=2023-04-10T14:00:0.000000Z level=INFO msg="Incoming request" status=200 method=GET path=/pong route=/pong ip=127.0.0.1 latency=25.5µs user-agent=curl/7.77.0 time=2023-04-10T14:00:00.000Z
+// time=2023-10-15T20:32:58.926+02:00 level=INFO msg="Incoming request" env=production request.time=2023-10-15T20:32:58.626+02:00 request.method=GET request.path=/ request.route="" request.ip=127.0.0.1:63932 request.length=0 response.time=2023-10-15T20:32:58.926+02:00 response.latency=100ms response.status=200 response.length=7 id=""
 ```
 
 ### OTEL
@@ -200,7 +200,7 @@ router.GET("/pong", func(c *gin.Context) {
 router.Run(":1234")
 
 // output:
-// time="2023-04-10 14:00:00" level=INFO msg="Incoming request" status=200 method=GET path=/pong route=/pong ip=127.0.0.1 latency=25.5µs user-agent=curl/7.77.0 time="2023-04-10 14:00:00"
+// time=2023-10-15T20:32:58.926+02:00 level=INFO msg="Incoming request" env=production request.time=2023-10-15T20:32:58Z request.method=GET request.path=/ request.route="" request.ip=127.0.0.1:63932 request.length=0 response.time=2023-10-15T20:32:58Z response.latency=100ms response.status=200 response.length=7 id=""
 ```
 
 ### Using custom logger sub-group
@@ -223,7 +223,7 @@ router.GET("/pong", func(c *gin.Context) {
 router.Run(":1234")
 
 // output:
-// time=2023-04-10T14:00:0.000000+02:00 level=INFO msg="Incoming request" http.status=200 http.method=GET http.path=/pong http.route=/pong http.ip=127.0.0.1 http.latency=20.125µs http.user-agent=curl/7.77.0 time=2023-04-10T14:00:00.000+02:00
+// time=2023-10-15T20:32:58.926+02:00 level=INFO msg="Incoming request" env=production http.request.time=2023-10-15T20:32:58.626+02:00 http.request.method=GET http.request.path=/ http.request.route="" http.request.ip=127.0.0.1:63932 http.request.length=0 http.response.time=2023-10-15T20:32:58.926+02:00 http.response.latency=100ms http.response.status=200 http.response.length=7 http.id=""
 ```
 
 ### Add logger to a single route
@@ -241,9 +241,6 @@ router.GET("/pong", sloggin.New(logger), func(c *gin.Context) {
 })
 
 router.Run(":1234")
-
-// output:
-// time="2023-04-10 14:00:00" level=INFO msg="Incoming request" status=200 method=GET path=/pong route=/pong ip=127.0.0.1 latency=25.5µs user-agent=curl/7.77.0 time="2023-04-10 14:00:00"
 ```
 
 ### Adding custom attributes
@@ -272,7 +269,7 @@ router.GET("/pong", func(c *gin.Context) {
 router.Run(":1234")
 
 // output:
-// time=2023-04-10T14:00:0.000000+02:00 level=INFO msg="Incoming request" environment=production server=gin/1.9.0 gin_mode=release server_start_time=2023-04-10T10:00:00.000+02:00 status=200 method=GET path=/pong route=/pong ip=127.0.0.1 latency=25.5µs user-agent=curl/7.77.0 time=2023-04-10T14:00:00.000+02:00 foo=bar
+// time=2023-10-15T20:32:58.926+02:00 level=INFO msg="Incoming request" environment=production server=gin/1.9.0 gin_mode=release request.time=2023-10-15T20:32:58.626+02:00 request.method=GET request.path=/ request.route="" request.ip=127.0.0.1:63932 request.length=0 response.time=2023-10-15T20:32:58.926+02:00 response.latency=100ms response.status=200 response.length=7 id="" foo=bar
 ```
 
 ### JSON output
@@ -295,7 +292,7 @@ router.GET("/pong", func(c *gin.Context) {
 router.Run(":1234")
 
 // output:
-// {"time":"2023-04-10T14:00:0.000000+02:00","level":"INFO","msg":"Incoming request","gin_mode":"GIN_MODE","status":200,"method":"GET","path":"/pong","ip":"127.0.0.1","latency":15542,"user-agent":"curl/7.77.0","time":"2023-04-10T14:00:0.000000+02:00"}
+// {"time":"2023-10-15T20:32:58.926+02:00","level":"INFO","msg":"Incoming request","gin_mode":"GIN_MODE","env":"production","http":{"request":{"time":"2023-10-15T20:32:58.626+02:00","method":"GET","path":"/","route":"","ip":"127.0.0.1:55296","length":0},"response":{"time":"2023-10-15T20:32:58.926+02:00","latency":100000,"status":200,"length":7},"id":""}}
 ```
 
 ## 🤝 Contributing

dump.go

@@ -2,6 +2,7 @@ package sloggin
 
 import (
 	"bytes"
+	"io"
 
 	"github.com/gin-gonic/gin"
 )
@@ -10,22 +11,65 @@ type bodyWriter struct {
 	gin.ResponseWriter
 	body    *bytes.Buffer
 	maxSize int
+	bytes   int
 }
 
 // implements gin.ResponseWriter
 func (w bodyWriter) Write(b []byte) (int, error) {
-	if w.body.Len()+len(b) > w.maxSize {
+	if w.body != nil {
-		w.body.Write(b[:w.maxSize-w.body.Len()])
+		if w.body.Len()+len(b) > w.maxSize {
-	} else {
+			w.body.Write(b[:w.maxSize-w.body.Len()])
-		w.body.Write(b)
+		} else {
+			w.body.Write(b)
+		}
 	}
+	w.bytes += len(b)
 	return w.ResponseWriter.Write(b)
 }
 
-func newBodyWriter(writer gin.ResponseWriter, maxSize int) *bodyWriter {
+func newBodyWriter(writer gin.ResponseWriter, maxSize int, recordBody bool) *bodyWriter {
+	var body *bytes.Buffer
+	if recordBody {
+		body = bytes.NewBufferString("")
+	}
+
 	return &bodyWriter{
-		body:           bytes.NewBufferString(""),
 		ResponseWriter: writer,
+		body:           body,
 		maxSize:        maxSize,
 	}
 }
+
+type bodyReader struct {
+	io.ReadCloser
+	body    *bytes.Buffer
+	maxSize int
+	bytes   int
+}
+
+// implements io.Reader
+func (r *bodyReader) Read(b []byte) (int, error) {
+	n, err := r.ReadCloser.Read(b)
+	if r.body != nil {
+		if r.body.Len()+n > r.maxSize {
+			r.body.Write(b[:r.maxSize-r.body.Len()])
+		} else {
+			r.body.Write(b)
+		}
+	}
+	r.bytes += n
+	return n, err
+}
+
+func newBodyReader(reader io.ReadCloser, maxSize int, recordBody bool) *bodyReader {
+	var body *bytes.Buffer
+	if recordBody {
+		body = bytes.NewBufferString("")
+	}
+
+	return &bodyReader{
+		ReadCloser: reader,
+		body:       body,
+		maxSize:    maxSize,
+	}
+}

middleware.go

@@ -1,8 +1,6 @@
 package sloggin
 
 import (
-	"bytes"
-	"io"
 	"net/http"
 	"strings"
 	"time"
@@ -71,7 +69,8 @@ func New(logger *slog.Logger) gin.HandlerFunc {
 		WithResponseHeader: false,
 		WithSpanID:         false,
 		WithTraceID:        false,
-		Filters:            []Filter{},
+
+		Filters: []Filter{},
 	})
 }
 
@@ -111,86 +110,107 @@ func NewWithConfig(logger *slog.Logger, config Config) gin.HandlerFunc {
 		}
 
 		// dump request body
-		var reqBody []byte
+		br := newBodyReader(c.Request.Body, RequestBodyMaxSize, config.WithRequestBody)
-		if config.WithRequestBody {
+		c.Request.Body = br
-			buf, err := io.ReadAll(c.Request.Body)
-			if err == nil {
-				c.Request.Body = io.NopCloser(bytes.NewBuffer(buf))
-				if len(buf) > RequestBodyMaxSize {
-					reqBody = buf[:RequestBodyMaxSize]
-				} else {
-					reqBody = buf
-				}
-			}
-		}
 
 		// dump response body
-		if config.WithResponseBody {
+		bw := newBodyWriter(c.Writer, ResponseBodyMaxSize, config.WithResponseBody)
-			c.Writer = newBodyWriter(c.Writer, ResponseBodyMaxSize)
+		c.Writer = bw
-		}
 
 		c.Next()
 
+		status := c.Writer.Status()
+		method := c.Request.Method
+		host := c.Request.Host
+		route := c.FullPath()
 		end := time.Now()
 		latency := end.Sub(start)
-		status := c.Writer.Status()
+		userAgent := c.Request.UserAgent()
+		ip := c.ClientIP()
+		referer := c.Request.Referer()
 
-		attributes := []slog.Attr{
+		baseAttributes := []slog.Attr{}
-			slog.Int("status", status),
+
-			slog.String("method", c.Request.Method),
+		requestAttributes := []slog.Attr{
+			slog.Time("time", start),
+			slog.String("method", method),
+			slog.String("host", host),
 			slog.String("path", path),
-			slog.String("route", c.FullPath()),
+			slog.String("route", route),
-			slog.String("ip", c.ClientIP()),
+			slog.String("ip", ip),
-			slog.Duration("latency", latency),
+			slog.String("referer", referer),
-			slog.Time("time", end),
 		}
 
-		if config.WithUserAgent {
+		responseAttributes := []slog.Attr{
-			attributes = append(attributes, slog.String("user-agent", c.Request.UserAgent()))
+			slog.Time("time", end),
+			slog.Duration("latency", latency),
+			slog.Int("status", status),
 		}
 
 		if config.WithRequestID {
-			attributes = append(attributes, slog.String("request-id", requestID))
+			baseAttributes = append(baseAttributes, slog.String("id", requestID))
 		}
 
+		// otel
 		if config.WithTraceID {
 			traceID := trace.SpanFromContext(c.Request.Context()).SpanContext().TraceID().String()
-			attributes = append(attributes, slog.String("trace-id", traceID))
+			baseAttributes = append(baseAttributes, slog.String("trace-id", traceID))
 		}
-
 		if config.WithSpanID {
 			spanID := trace.SpanFromContext(c.Request.Context()).SpanContext().SpanID().String()
-			attributes = append(attributes, slog.String("span-id", spanID))
+			baseAttributes = append(baseAttributes, slog.String("span-id", spanID))
 		}
 
-		// request
+		// request body
+		requestAttributes = append(requestAttributes, slog.Int("length", br.bytes))
 		if config.WithRequestBody {
-			attributes = append(attributes, slog.Group("request", slog.String("body", string(reqBody))))
+			requestAttributes = append(requestAttributes, slog.String("body", br.body.String()))
 		}
+
+		// request headers
 		if config.WithRequestHeader {
 			for k, v := range c.Request.Header {
 				if _, found := HiddenRequestHeaders[strings.ToLower(k)]; found {
 					continue
 				}
-				attributes = append(attributes, slog.Group("request", slog.Group("header", slog.Any(k, v))))
+				requestAttributes = append(requestAttributes, slog.Group("header", slog.Any(k, v)))
 			}
 		}
 
-		// response
+		if config.WithUserAgent {
-		if config.WithResponseBody {
+			requestAttributes = append(requestAttributes, slog.String("user-agent", userAgent))
-			if w, ok := c.Writer.(*bodyWriter); ok {
-				attributes = append(attributes, slog.Group("response", slog.String("body", w.body.String())))
-			}
 		}
+
+		// response body
+		responseAttributes = append(responseAttributes, slog.Int("length", bw.bytes))
+		if config.WithResponseBody {
+			responseAttributes = append(responseAttributes, slog.String("body", bw.body.String()))
+		}
+
+		// response headers
 		if config.WithResponseHeader {
 			for k, v := range c.Writer.Header() {
 				if _, found := HiddenResponseHeaders[strings.ToLower(k)]; found {
 					continue
 				}
-				attributes = append(attributes, slog.Group("response", slog.Group("header", slog.Any(k, v))))
+				responseAttributes = append(responseAttributes, slog.Group("header", slog.Any(k, v)))
 			}
 		}
 
+		attributes := append(
+			[]slog.Attr{
+				{
+					Key:   "request",
+					Value: slog.GroupValue(requestAttributes...),
+				},
+				{
+					Key:   "response",
+					Value: slog.GroupValue(responseAttributes...),
+				},
+			},
+			baseAttributes...,
+		)
+
 		// custom context values
 		if v, ok := c.Get(customAttributesCtxKey); ok {
 			switch attrs := v.(type) {