diff --git a/internal/server/observability.go b/internal/server/observability.go new file mode 100644 index 0000000..a281540 --- /dev/null +++ b/internal/server/observability.go @@ -0,0 +1,37 @@ +package server + +import ( + "log" + "strconv" + "time" + + "github.com/gin-gonic/gin" +) + +func RequestLogger() gin.HandlerFunc { + return func(c *gin.Context) { + start := time.Now() + path := c.Request.URL.Path + query := c.Request.URL.RawQuery + + c.Next() + + route := c.FullPath() + if route == "" { + route = path + } + + log.Printf( + "http_request method=%s route=%s path=%s query=%s status=%d duration_ms=%.2f bytes=%d client_ip=%s errors=%s", + c.Request.Method, + strconv.Quote(route), + strconv.Quote(path), + strconv.Quote(query), + c.Writer.Status(), + float64(time.Since(start).Microseconds())/1000, + c.Writer.Size(), + strconv.Quote(c.ClientIP()), + strconv.Quote(c.Errors.ByType(gin.ErrorTypePrivate).String()), + ) + } +} diff --git a/internal/server/server.go b/internal/server/server.go index 341a9ff..c708fae 100644 --- a/internal/server/server.go +++ b/internal/server/server.go @@ -22,7 +22,7 @@ func ProvideRouter(htmlRender render.HTMLRender) *gin.Engine { gin.SetMode(gin.ReleaseMode) } r := gin.New() - r.Use(CORSMiddleware(), gin.Logger(), gin.Recovery()) + r.Use(CORSMiddleware(), RequestLogger(), gin.Recovery()) r.Static("/static", "./static") r.Static("/dist", "./dist") r.HTMLRender = htmlRender diff --git a/internal/server/server_test.go b/internal/server/server_test.go index 9edd7ec..4317e2f 100644 --- a/internal/server/server_test.go +++ b/internal/server/server_test.go @@ -1,9 +1,16 @@ package server import ( + "bytes" + "io" + "log" "net/http" + "net/http/httptest" + "strings" "testing" "time" + + "github.com/gin-gonic/gin" ) func TestNewHTTPServer_TimeoutsAndAddr(t *testing.T) { @@ -25,3 +32,35 @@ func TestNewHTTPServer_TimeoutsAndAddr(t *testing.T) { t.Fatalf("IdleTimeout: got %s want %s", srv.IdleTimeout, 2*time.Minute) } } + +func TestRequestLoggerUsesMatchedRoute(t *testing.T) { + gin.SetMode(gin.TestMode) + + var logs bytes.Buffer + previousOutput := log.Writer() + log.SetOutput(&logs) + defer log.SetOutput(previousOutput) + + router := gin.New() + router.Use(RequestLogger()) + router.GET("/anime/:id", func(c *gin.Context) { + c.String(http.StatusOK, "ok") + }) + + req := httptest.NewRequest(http.MethodGet, "/anime/1?section=characters", nil) + rec := httptest.NewRecorder() + router.ServeHTTP(rec, req) + + output, err := io.ReadAll(&logs) + if err != nil { + t.Fatalf("read logs: %v", err) + } + + logLine := string(output) + if !strings.Contains(logLine, `route="/anime/:id"`) { + t.Fatalf("log line missing route: %s", logLine) + } + if !strings.Contains(logLine, `status=200`) { + t.Fatalf("log line missing status: %s", logLine) + } +}