feat: implement request ID middleware and enhance recovery logging with structured logging
This commit is contained in:
@@ -1,7 +1,6 @@
|
||||
package middleware
|
||||
|
||||
import (
|
||||
"log"
|
||||
"net/http"
|
||||
"runtime/debug"
|
||||
|
||||
@@ -14,10 +13,16 @@ func Recovery(verbose bool) gin.HandlerFunc {
|
||||
return func(c *gin.Context) {
|
||||
defer func() {
|
||||
if r := recover(); r != nil {
|
||||
// Try to get a request-scoped logger; fall back to global logger
|
||||
entry := GetRequestLogger(c)
|
||||
if verbose {
|
||||
log.Printf("PANIC: %v\nRequest: %s %s\nHeaders: %v\nStacktrace:\n%s", r, c.Request.Method, c.Request.URL.String(), c.Request.Header, debug.Stack())
|
||||
entry.WithFields(map[string]interface{}{
|
||||
"method": c.Request.Method,
|
||||
"path": c.Request.URL.Path,
|
||||
"headers": c.Request.Header,
|
||||
}).Errorf("PANIC: %v\nStacktrace:\n%s", r, debug.Stack())
|
||||
} else {
|
||||
log.Printf("PANIC: %v", r)
|
||||
entry.Errorf("PANIC: %v", r)
|
||||
}
|
||||
c.AbortWithStatusJSON(http.StatusInternalServerError, gin.H{"error": "internal server error"})
|
||||
}
|
||||
|
||||
@@ -8,6 +8,7 @@ import (
|
||||
"strings"
|
||||
"testing"
|
||||
|
||||
"github.com/Wikid82/charon/backend/internal/logger"
|
||||
"github.com/gin-gonic/gin"
|
||||
)
|
||||
|
||||
@@ -16,8 +17,11 @@ func TestRecoveryLogsStacktraceVerbose(t *testing.T) {
|
||||
buf := &bytes.Buffer{}
|
||||
log.SetOutput(buf)
|
||||
defer log.SetOutput(old)
|
||||
// Ensure structured logger writes to the same buffer and enable debug
|
||||
logger.Init(true, buf)
|
||||
|
||||
router := gin.New()
|
||||
router.Use(RequestID())
|
||||
router.Use(Recovery(true))
|
||||
router.GET("/panic", func(c *gin.Context) {
|
||||
panic("test panic")
|
||||
@@ -38,6 +42,9 @@ func TestRecoveryLogsStacktraceVerbose(t *testing.T) {
|
||||
if !strings.Contains(out, "Stacktrace:") {
|
||||
t.Fatalf("verbose log did not include stack trace: %s", out)
|
||||
}
|
||||
if !strings.Contains(out, "request_id") {
|
||||
t.Fatalf("verbose log did not include request_id: %s", out)
|
||||
}
|
||||
}
|
||||
|
||||
func TestRecoveryLogsBriefWhenNotVerbose(t *testing.T) {
|
||||
@@ -46,7 +53,10 @@ func TestRecoveryLogsBriefWhenNotVerbose(t *testing.T) {
|
||||
log.SetOutput(buf)
|
||||
defer log.SetOutput(old)
|
||||
|
||||
// Ensure structured logger writes to the same buffer and keep debug off
|
||||
logger.Init(false, buf)
|
||||
router := gin.New()
|
||||
router.Use(RequestID())
|
||||
router.Use(Recovery(false))
|
||||
router.GET("/panic", func(c *gin.Context) {
|
||||
panic("brief panic")
|
||||
|
||||
35
backend/internal/api/middleware/request_id.go
Normal file
35
backend/internal/api/middleware/request_id.go
Normal file
@@ -0,0 +1,35 @@
|
||||
package middleware
|
||||
|
||||
import (
|
||||
"github.com/Wikid82/charon/backend/internal/logger"
|
||||
"github.com/gin-gonic/gin"
|
||||
"github.com/google/uuid"
|
||||
"github.com/sirupsen/logrus"
|
||||
)
|
||||
|
||||
const RequestIDKey = "requestID"
|
||||
const RequestIDHeader = "X-Request-ID"
|
||||
|
||||
// RequestID generates a uuid per request and places it in context and header.
|
||||
func RequestID() gin.HandlerFunc {
|
||||
return func(c *gin.Context) {
|
||||
rid := uuid.New().String()
|
||||
c.Set(RequestIDKey, rid)
|
||||
c.Writer.Header().Set(RequestIDHeader, rid)
|
||||
// Add to logger fields for this request
|
||||
entry := logger.WithFields(map[string]interface{}{"request_id": rid})
|
||||
c.Set("logger", entry)
|
||||
c.Next()
|
||||
}
|
||||
}
|
||||
|
||||
// GetRequestLogger retrieves the request-scoped logger from context or the global logger
|
||||
func GetRequestLogger(c *gin.Context) *logrus.Entry {
|
||||
if v, ok := c.Get("logger"); ok {
|
||||
if entry, ok := v.(*logrus.Entry); ok {
|
||||
return entry
|
||||
}
|
||||
}
|
||||
// fallback
|
||||
return logger.Log()
|
||||
}
|
||||
37
backend/internal/api/middleware/request_id_test.go
Normal file
37
backend/internal/api/middleware/request_id_test.go
Normal file
@@ -0,0 +1,37 @@
|
||||
package middleware
|
||||
|
||||
import (
|
||||
"bytes"
|
||||
"net/http"
|
||||
"net/http/httptest"
|
||||
"testing"
|
||||
|
||||
"github.com/Wikid82/charon/backend/internal/logger"
|
||||
"github.com/gin-gonic/gin"
|
||||
)
|
||||
|
||||
func TestRequestIDAddsHeaderAndLogger(t *testing.T) {
|
||||
buf := &bytes.Buffer{}
|
||||
logger.Init(true, buf)
|
||||
|
||||
router := gin.New()
|
||||
router.Use(RequestID())
|
||||
router.GET("/test", func(c *gin.Context) {
|
||||
// Ensure logger exists in context and header is present
|
||||
if _, ok := c.Get("logger"); !ok {
|
||||
t.Fatalf("expected request-scoped logger in context")
|
||||
}
|
||||
c.String(200, "ok")
|
||||
})
|
||||
|
||||
req := httptest.NewRequest(http.MethodGet, "/test", nil)
|
||||
w := httptest.NewRecorder()
|
||||
router.ServeHTTP(w, req)
|
||||
|
||||
if w.Code != http.StatusOK {
|
||||
t.Fatalf("expected status 200, got %d", w.Code)
|
||||
}
|
||||
if w.Header().Get(RequestIDHeader) == "" {
|
||||
t.Fatalf("expected response to include X-Request-ID header")
|
||||
}
|
||||
}
|
||||
24
backend/internal/api/middleware/request_logger.go
Normal file
24
backend/internal/api/middleware/request_logger.go
Normal file
@@ -0,0 +1,24 @@
|
||||
package middleware
|
||||
|
||||
import (
|
||||
"time"
|
||||
|
||||
"github.com/gin-gonic/gin"
|
||||
)
|
||||
|
||||
// RequestLogger logs basic request information along with the request_id.
|
||||
func RequestLogger() gin.HandlerFunc {
|
||||
return func(c *gin.Context) {
|
||||
start := time.Now()
|
||||
c.Next()
|
||||
latency := time.Since(start)
|
||||
entry := GetRequestLogger(c)
|
||||
entry.WithFields(map[string]interface{}{
|
||||
"status": c.Writer.Status(),
|
||||
"method": c.Request.Method,
|
||||
"path": c.Request.URL.Path,
|
||||
"latency": latency.String(),
|
||||
"client": c.ClientIP(),
|
||||
}).Info("handled request")
|
||||
}
|
||||
}
|
||||
36
backend/internal/api/middleware/request_logger_test.go
Normal file
36
backend/internal/api/middleware/request_logger_test.go
Normal file
@@ -0,0 +1,36 @@
|
||||
package middleware
|
||||
|
||||
import (
|
||||
"bytes"
|
||||
"net/http"
|
||||
"net/http/httptest"
|
||||
"strings"
|
||||
"testing"
|
||||
|
||||
"github.com/Wikid82/charon/backend/internal/logger"
|
||||
"github.com/gin-gonic/gin"
|
||||
)
|
||||
|
||||
func TestRequestLoggerIncludesRequestID(t *testing.T) {
|
||||
buf := &bytes.Buffer{}
|
||||
logger.Init(true, buf)
|
||||
|
||||
router := gin.New()
|
||||
router.Use(RequestID())
|
||||
router.Use(RequestLogger())
|
||||
router.GET("/ok", func(c *gin.Context) { c.String(200, "ok") })
|
||||
|
||||
req := httptest.NewRequest(http.MethodGet, "/ok", nil)
|
||||
w := httptest.NewRecorder()
|
||||
router.ServeHTTP(w, req)
|
||||
if w.Code != http.StatusOK {
|
||||
t.Fatalf("unexpected status code: %d", w.Code)
|
||||
}
|
||||
out := buf.String()
|
||||
if !strings.Contains(out, "request_id") {
|
||||
t.Fatalf("expected log output to include request_id: %s", out)
|
||||
}
|
||||
if !strings.Contains(out, "handled request") {
|
||||
t.Fatalf("expected log output to indicate handled request: %s", out)
|
||||
}
|
||||
}
|
||||
Reference in New Issue
Block a user