Merge pull request #38 from oleksandrkhmil/feat/trace-generator

Feat/trace generator

Author: eugene-burenkov

cmd/service/main.go

@@ -14,8 +14,10 @@ import (
 	"github.com/nix-united/golang-echo-boilerplate/internal/db"
 	"github.com/nix-united/golang-echo-boilerplate/internal/server"
 	"github.com/nix-united/golang-echo-boilerplate/internal/server/routes"
+	"github.com/nix-united/golang-echo-boilerplate/internal/slogx"
 
 	"github.com/caarlos0/env/v11"
+	"github.com/google/uuid"
 	"github.com/joho/godotenv"
 	"github.com/labstack/echo/v4"
 )
@@ -54,14 +56,18 @@ func run() error {
 
 	docs.SwaggerInfo.Host = fmt.Sprintf("%s:%s", cfg.HTTP.Host, cfg.HTTP.Port)
 
+	if err := slogx.Init(cfg.Logger); err != nil {
+		return fmt.Errorf("init logger: %w", err)
+	}
+
 	gormDB, err := db.NewGormDB(cfg.DB)
 	if err != nil {
 		return fmt.Errorf("new db connection: %w", err)
 	}
 
 	app := server.NewServer(echo.New(), gormDB, &cfg)
 
-	routes.ConfigureRoutes(app)
+	routes.ConfigureRoutes(slogx.NewTraceStarter(uuid.NewV7), app)
 
 	go func() {
 		if err = app.Start(cfg.HTTP.Port); err != nil {

go.mod

@@ -7,6 +7,7 @@ require (
 	github.com/caarlos0/env/v11 v11.3.1
 	github.com/go-ozzo/ozzo-validation/v4 v4.3.0
 	github.com/golang-jwt/jwt/v5 v5.2.2
+	github.com/google/uuid v1.6.0
 	github.com/joho/godotenv v1.5.1
 	github.com/labstack/echo-jwt/v4 v4.3.1
 	github.com/labstack/echo/v4 v4.13.3
@@ -128,7 +129,6 @@ require (
 	github.com/golangci/revgrep v0.8.0 // indirect
 	github.com/golangci/unconvert v0.0.0-20240309020433-c5143eacb3ed // indirect
 	github.com/google/go-cmp v0.7.0 // indirect
-	github.com/google/uuid v1.6.0 // indirect
 	github.com/gordonklaus/ineffassign v0.1.0 // indirect
 	github.com/gostaticanalysis/analysisutil v0.7.1 // indirect
 	github.com/gostaticanalysis/comment v1.4.2 // indirect

internal/config/config.go

@@ -1,9 +1,12 @@
 package config
 
+import "github.com/nix-united/golang-echo-boilerplate/internal/slogx"
+
 type Config struct {
-	Auth AuthConfig
-	DB   DBConfig
-	HTTP HTTPConfig
+	Logger slogx.Config
+	Auth   AuthConfig
+	DB     DBConfig
+	HTTP   HTTPConfig
 }
 
 type DBConfig struct {

internal/server/middleware/request_debugger.go

@@ -0,0 +1,128 @@
+package middleware
+
+import (
+	"bytes"
+	"context"
+	"encoding/json"
+	"fmt"
+	"io"
+	"log/slog"
+	"net/http"
+	"strings"
+
+	"github.com/labstack/echo/v4"
+)
+
+// requestDebugger is a logging middleware that logs request and response bodies with DEBUG level logs.
+// Warning: Do not use this middleware with endpoints containing sensitive information.
+//
+// Based on the Content-Type, it determines how the body will be formatted.
+// If the content type is application/json, the body will be logged as JSON; otherwise, it will be logged as a string.
+type requestDebugger struct{}
+
+func NewRequestDebugger() echo.MiddlewareFunc {
+	debugger := requestDebugger{}
+	return debugger.handle
+}
+
+func (d requestDebugger) handle(next echo.HandlerFunc) echo.HandlerFunc {
+	if !slog.Default().Enabled(context.Background(), slog.LevelDebug) {
+		return next
+	}
+
+	return func(c echo.Context) error {
+		requestBody, err := d.getRequestBody(c)
+		if err != nil {
+			return fmt.Errorf("get request body for logging: %w", err)
+		}
+
+		responseBodyGetter := d.getResponseBodyGetter(c)
+
+		errNext := next(c)
+
+		var attrs []any
+		if requestBody != nil {
+			attrs = append(attrs, "request_body", requestBody)
+		}
+
+		responseBody := responseBodyGetter(c)
+		if responseBody != nil {
+			attrs = append(attrs, "response_body", responseBody)
+		}
+
+		message := "Request/response data"
+		if len(attrs) == 0 {
+			message = "Request/response withot any data"
+		}
+
+		slog.DebugContext(c.Request().Context(), message, attrs...)
+
+		if errNext != nil {
+			return fmt.Errorf("handle request with request debugger: %w", errNext)
+		}
+
+		return nil
+	}
+}
+
+func (d requestDebugger) getRequestBody(c echo.Context) (any, error) {
+	if c.Request().Body == nil {
+		return nil, nil
+	}
+
+	rawRequestBody, err := io.ReadAll(c.Request().Body)
+	if err != nil {
+		return nil, fmt.Errorf("read request body: %w", err)
+	}
+
+	request := c.Request()
+	request.Body = io.NopCloser(bytes.NewReader(rawRequestBody))
+	c.SetRequest(request)
+
+	if strings.HasPrefix(request.Header.Get(echo.HeaderContentType), "application/json") {
+		return json.RawMessage(rawRequestBody), nil
+	}
+
+	return string(rawRequestBody), nil
+}
+
+func (d requestDebugger) getResponseBodyGetter(c echo.Context) func(echo.Context) any {
+	response := c.Response()
+	storer := newResponseStorer(response.Writer)
+	response.Writer = storer
+	c.SetResponse(response)
+
+	return func(c echo.Context) any {
+		if storer.storedResponse == nil {
+			return nil
+		}
+
+		if strings.HasPrefix(c.Response().Header().Get(echo.HeaderContentType), "application/json") {
+			return json.RawMessage(storer.storedResponse)
+		}
+
+		return string(storer.storedResponse)
+	}
+}
+
+// responseStorer stores the written response by the handler into its field.
+// This is used to automate response logging.
+type responseStorer struct {
+	http.ResponseWriter
+	storedResponse []byte
+}
+
+func newResponseStorer(writer http.ResponseWriter) *responseStorer {
+	return &responseStorer{ResponseWriter: writer}
+}
+
+func (s *responseStorer) Write(response []byte) (int, error) {
+	s.storedResponse = response
+
+	n, err := s.ResponseWriter.Write(response)
+	if err != nil {
+		return n, fmt.Errorf("write response with storer: %w", err)
+	}
+
+	return n, nil
+}

internal/server/middleware/request_logger.go

@@ -0,0 +1,61 @@
+package middleware
+
+import (
+	"context"
+	"fmt"
+	"log/slog"
+	"net/http"
+
+	"github.com/labstack/echo/v4"
+)
+
+type tracer interface {
+	Start(ctx context.Context) (context.Context, error)
+}
+
+// requestLogger is a logging middleware that generated trace ID for each request.
+type requestLogger struct {
+	tracer tracer
+}
+
+func NewRequestLogger(tracer tracer) echo.MiddlewareFunc {
+	middleware := requestLogger{tracer: tracer}
+	return middleware.handle
+}
+
+// handle creates trace and logs request information.
+func (l requestLogger) handle(next echo.HandlerFunc) echo.HandlerFunc {
+	return func(c echo.Context) error {
+		ctx, err := l.tracer.Start(c.Request().Context())
+		if err != nil {
+			return fmt.Errorf("trace starter: %w", err)
+		}
+
+		c.SetRequest(c.Request().WithContext(ctx))
+
+		errNext := next(c)
+
+		level := slog.LevelInfo
+		if c.Response().Status >= http.StatusInternalServerError {
+			level = slog.LevelError
+		}
+
+		attrs := []any{
+			"method", c.Request().Method,
+			"status", c.Response().Status,
+			"path", c.Path(),
+		}
+
+		if errNext != nil {
+			attrs = append(attrs, "error", errNext.Error())
+		}
+
+		slog.Log(c.Request().Context(), level, "Request", slog.Group("http", attrs...))
+
+		if errNext != nil {
+			return fmt.Errorf("handle request with request logger: %w", errNext)
+		}
+
+		return nil
+	}
+}

internal/server/routes/routes.go

@@ -1,40 +1,38 @@
 package routes
 
 import (
-	"fmt"
-
 	"github.com/nix-united/golang-echo-boilerplate/internal/repositories"
 	s "github.com/nix-united/golang-echo-boilerplate/internal/server"
 	"github.com/nix-united/golang-echo-boilerplate/internal/server/handlers"
+	"github.com/nix-united/golang-echo-boilerplate/internal/server/middleware"
 	"github.com/nix-united/golang-echo-boilerplate/internal/services/post"
 	"github.com/nix-united/golang-echo-boilerplate/internal/services/token"
+	"github.com/nix-united/golang-echo-boilerplate/internal/slogx"
 
 	"github.com/golang-jwt/jwt/v5"
 	echojwt "github.com/labstack/echo-jwt/v4"
 	"github.com/labstack/echo/v4"
-	"github.com/labstack/echo/v4/middleware"
 	echoSwagger "github.com/swaggo/echo-swagger"
 )
 
-func ConfigureRoutes(server *s.Server) {
+func ConfigureRoutes(tracer slogx.TraceStarter, server *s.Server) {
 	postRepository := repositories.NewPostRepository(server.DB)
 	postService := post.NewPostService(postRepository)
 
 	postHandler := handlers.NewPostHandlers(postService)
 	authHandler := handlers.NewAuthHandler(server)
 	registerHandler := handlers.NewRegisterHandler(server)
 
-	server.Echo.Use(middleware.Logger())
+	server.Echo.Use(middleware.NewRequestLogger(tracer))
 
 	server.Echo.GET("/swagger/*", echoSwagger.WrapHandler)
 
 	server.Echo.POST("/login", authHandler.Login)
 	server.Echo.POST("/register", registerHandler.Register)
 	server.Echo.POST("/refresh", authHandler.RefreshToken)
 
-	fmt.Println(server.Config.Auth.AccessSecret)
+	r := server.Echo.Group("", middleware.NewRequestDebugger())
 
-	r := server.Echo.Group("")
 	// Configure middleware with the custom claims type
 	config := echojwt.Config{
 		NewClaimsFunc: func(_ echo.Context) jwt.Claims {

internal/slogx/init.go

@@ -0,0 +1,57 @@
+package slogx
+
+import (
+	"fmt"
+	"io"
+	"log/slog"
+	"os"
+)
+
+type Config struct {
+	Application string `env:"LOG_APPLICATION"`
+
+	// File represents path to file where store logs. Used [os.Stdout] if empty.
+	File string `env:"LOG_FILE"`
+
+	// One of: "DEBUG", "INFO", "WARN", "ERROR". Default: "DEBUG".
+	Level string `env:"LOG_LEVEL"`
+
+	// Add source code position to messages.
+	AddSource bool `env:"LOG_ADD_SOURCE"`
+}
+
+func Init(config Config) (err error) {
+	writer := io.Writer(os.Stdout)
+	if config.File != "" {
+		const permission = 0o644
+
+		writer, err = os.OpenFile(config.File, os.O_APPEND|os.O_CREATE|os.O_WRONLY, permission)
+		if err != nil {
+			return fmt.Errorf("open file %s: %w", config.File, err)
+		}
+	}
+
+	level := slog.LevelDebug
+	if config.Level != "" {
+		if err = level.UnmarshalText([]byte(config.Level)); err != nil {
+			return fmt.Errorf("parse log level %s: %w", config.Level, err)
+		}
+	}
+
+	hostname, err := os.Hostname()
+	if err != nil {
+		return fmt.Errorf("get hostname: %w", err)
+	}
+
+	jsonHandler := slog.NewJSONHandler(writer, &slog.HandlerOptions{AddSource: config.AddSource, Level: level})
+
+	traceHandler := newTraceHandler(jsonHandler)
+
+	logger := slog.New(traceHandler).
+		With("application", config.Application).
+		With("hostname", hostname)
+
+	slog.SetDefault(logger)
+
+	return nil
+}