all repos

onasty @ bcf505635318b83f2b5338c2274ea658a2a23758

a one-time notes service
10 files changed, 180 insertions(+), 53 deletions(-)
feat: request id (#18)

* feat(requestid): add helper package

* feat: log request id

* refactor(logger): log request_id from context

* refactor: use slog with context

* refactor: move out setting up logging into sep package

* fixup! feat(requestid): add helper package

* remove linting errs :D

* fixup! refactor: use slog with context

* refactor: make loging statement more readable

* refactor(reqid): renaming

* refactor(reqid): use gofrs/uuid

* test(reqid): add banch
Author: Smirnov Oleksandr ss2316544@gmail.com
Committed by: GitHub noreply@github.com
Committed at: 2024-09-20 22:48:36 +0300
Parent: b617b17
M cmd/server/main.go

@@ -1,4 +1,3 @@

-//nolint:err113 // all errors are shown to the user so it's ok for them to be dynamic package main import (

@@ -14,6 +13,7 @@ "github.com/gin-gonic/gin"

"github.com/olexsmir/onasty/internal/config" "github.com/olexsmir/onasty/internal/hasher" "github.com/olexsmir/onasty/internal/jwtutil" + "github.com/olexsmir/onasty/internal/logger" "github.com/olexsmir/onasty/internal/mailer" "github.com/olexsmir/onasty/internal/service/notesrv" "github.com/olexsmir/onasty/internal/service/usersrv"

@@ -33,25 +33,32 @@ os.Exit(1)

} } +//nolint:err113 func run(ctx context.Context) error { ctx, cancel := context.WithCancel(ctx) defer cancel() cfg := config.NewConfig() - if err := setupLogger(cfg); err != nil { + + // logger + logger, err := logger.NewCustomLogger(cfg.LogLevel, cfg.LogFormat, cfg.LogShowLine) + if err != nil { return err } + slog.SetDefault(logger) + + // semi dev mode if !cfg.IsDevMode() { gin.SetMode(gin.ReleaseMode) } + // app deps psqlDB, err := psqlutil.Connect(ctx, cfg.PostgresDSN) if err != nil { return err } - // app deps sha256Hasher := hasher.NewSHA256Hasher(cfg.PasswordSalt) jwtTokenizer := jwtutil.NewJWTUtil(cfg.JwtSigningKey, cfg.JwtAccessTokenTTL) mailGunMailer := mailer.NewMailgun(cfg.MailgunFrom, cfg.MailgunDomain, cfg.MailgunAPIKey)

@@ -101,36 +108,3 @@ }

return nil } - -func setupLogger(cfg *config.Config) error { - loggerLevels := map[string]slog.Level{ - "info": slog.LevelInfo, - "debug": slog.LevelDebug, - "error": slog.LevelError, - "warn": slog.LevelWarn, - } - - logLevel, ok := loggerLevels[cfg.LogLevel] - if !ok { - return errors.New("unknown log level") - } - - handlerOptions := &slog.HandlerOptions{ - Level: logLevel, - AddSource: cfg.LogShowLine, - } - - var slogHandler slog.Handler - switch cfg.LogFormat { - case "json": - slogHandler = slog.NewJSONHandler(os.Stdout, handlerOptions) - case "text": - slogHandler = slog.NewTextHandler(os.Stdout, handlerOptions) - default: - return errors.New("unknown log format") - } - - slog.SetDefault(slog.New(slogHandler)) - - return nil -}
M e2e/e2e_test.go

@@ -16,6 +16,7 @@ "github.com/jackc/pgx/v5/stdlib"

"github.com/olexsmir/onasty/internal/config" "github.com/olexsmir/onasty/internal/hasher" "github.com/olexsmir/onasty/internal/jwtutil" + "github.com/olexsmir/onasty/internal/logger" "github.com/olexsmir/onasty/internal/mailer" "github.com/olexsmir/onasty/internal/service/notesrv" "github.com/olexsmir/onasty/internal/service/usersrv"

@@ -76,7 +77,6 @@

e.postgresDB = db e.stopPostgres = stop - e.setupLogger() e.initDeps() }

@@ -88,6 +88,11 @@ // initDeps initializes the dependencies for the app

// and sets up the router for tests func (e *AppTestSuite) initDeps() { cfg := e.getConfig() + + logger, err := logger.NewCustomLogger(cfg.LogLevel, cfg.LogFormat, cfg.LogShowLine) + e.require.NoError(err) + + slog.SetDefault(logger) e.hasher = hasher.NewSHA256Hasher(cfg.PasswordSalt) e.jwtTokenizer = jwtutil.NewJWTUtil(cfg.JwtSigningKey, time.Hour)

@@ -168,13 +173,6 @@

return db, stop, driver.Close() } -func (e *AppTestSuite) setupLogger() { - slog.SetDefault(slog.New(slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{ - Level: slog.LevelDebug, - AddSource: os.Getenv("LOG_SHOW_LINE") == "true", - }))) -} - func (e *AppTestSuite) getConfig() *config.Config { return &config.Config{ //nolint:exhaustruct AppEnv: "testing",

@@ -185,5 +183,8 @@ JwtSigningKey: "jwt-key",

JwtAccessTokenTTL: time.Hour, JwtRefreshTokenTTL: 24 * time.Hour, VerficationTokenTTL: 24 * time.Hour, + LogShowLine: os.Getenv("LOG_SHOW_LINE") == "true", + LogFormat: "text", + LogLevel: "debug", } }
A internal/logger/logger.go

@@ -0,0 +1,52 @@

+package logger + +import ( + "context" + "errors" + "log/slog" + "os" + + "github.com/olexsmir/onasty/internal/transport/http/reqid" +) + +type CustomLogger struct{ slog.Handler } + +//nolint:err113 +func NewCustomLogger(lvl, format string, showLine bool) (*slog.Logger, error) { + loggerLevels := map[string]slog.Level{ + "info": slog.LevelInfo, + "debug": slog.LevelDebug, + "error": slog.LevelError, + "warn": slog.LevelWarn, + } + + logLevel, ok := loggerLevels[lvl] + if !ok { + return nil, errors.New("unknown log level") + } + + handlerOptions := &slog.HandlerOptions{ + Level: logLevel, + AddSource: showLine, + } + + var slogHandler slog.Handler + switch format { + case "json": + slogHandler = slog.NewJSONHandler(os.Stdout, handlerOptions) + case "text": + slogHandler = slog.NewTextHandler(os.Stdout, handlerOptions) + default: + return nil, errors.New("unknown log format") + } + + return slog.New(&CustomLogger{Handler: slogHandler}), nil +} + +func (l *CustomLogger) Handle(ctx context.Context, r slog.Record) error { + if requestID := reqid.GetContext(ctx); requestID != "" { + r.AddAttrs(slog.String("request_id", requestID)) + } + + return l.Handler.Handle(ctx, r) +}
M internal/mailer/mailgun.go

@@ -29,8 +29,8 @@ msg.SetHtml(content)

_, _, err := m.mg.Send(ctx, msg) - slog.Info("email sent", "to", to) - slog.Debug("email sent", "subject", subject, "content", content, "err", err) + slog.InfoContext(ctx, "email sent", "to", to) + slog.DebugContext(ctx, "email sent", "subject", subject, "content", content, "err", err) return err }
M internal/service/usersrv/email.go

@@ -27,7 +27,7 @@ url string,

) error { select { case <-ctx.Done(): - slog.Error("failed to send verfication email", "err", ctx.Err()) + slog.ErrorContext(ctx, "failed to send verfication email", "err", ctx.Err()) return ErrFailedToSendVerifcationEmail default: if err := u.mailer.Send(

@@ -39,8 +39,6 @@ ); err != nil {

return errors.Join(ErrFailedToSendVerifcationEmail, err) } cancel() - - slog.Debug("email sent") } return nil
M internal/transport/http/apiv1/response.go

@@ -52,17 +52,17 @@ newInternalError(c, err)

} func newError(c *gin.Context, status int, msg string) { - slog.Error(msg, "status", status) + slog.ErrorContext(c.Request.Context(), msg, "status", status) c.AbortWithStatusJSON(status, response{msg}) } func newErrorStatus(c *gin.Context, status int, msg string) { - slog.Error(msg, "status", status) + slog.ErrorContext(c.Request.Context(), msg, "status", status) c.AbortWithStatus(status) } func newInternalError(c *gin.Context, err error, msg ...string) { - slog.With("status", "internal error").Error(err.Error()) + slog.ErrorContext(c.Request.Context(), err.Error(), "status", "internal error") if len(msg) != 0 { c.AbortWithStatusJSON(http.StatusInternalServerError, response{
M internal/transport/http/http.go

@@ -7,6 +7,7 @@ "github.com/gin-gonic/gin"

"github.com/olexsmir/onasty/internal/service/notesrv" "github.com/olexsmir/onasty/internal/service/usersrv" "github.com/olexsmir/onasty/internal/transport/http/apiv1" + "github.com/olexsmir/onasty/internal/transport/http/reqid" ) type Transport struct {

@@ -28,6 +29,7 @@ func (t *Transport) Handler() http.Handler {

r := gin.New() r.Use( gin.Recovery(), + reqid.Middleware(), t.logger(), )
M internal/transport/http/middlewares.go

@@ -5,9 +5,9 @@ "log/slog"

"time" "github.com/gin-gonic/gin" + "github.com/olexsmir/onasty/internal/transport/http/reqid" ) -// TODO: include requiest id func (t *Transport) logger() gin.HandlerFunc { return func(c *gin.Context) { start := time.Now()

@@ -30,6 +30,7 @@ slog.LogAttrs(

c.Request.Context(), lvl, c.Errors.ByType(gin.ErrorTypePrivate).String(), + slog.String("request_id", reqid.Get(c)), slog.String("latency", latency.String()), slog.String("method", c.Request.Method), slog.Int("status_code", c.Writer.Status()),
A internal/transport/http/reqid/reqid.go

@@ -0,0 +1,50 @@

+// reqid provides gin-gonic/gin middleware to generate a requestid for each request +package reqid + +import ( + "context" + + "github.com/gin-gonic/gin" + "github.com/gofrs/uuid/v5" +) + +type requestIDKey string + +const ( + RequestID requestIDKey = "request_id" + + headerRequestID = "X-Request-ID" +) + +// Middleware initializes the request ID +func Middleware() gin.HandlerFunc { + return func(c *gin.Context) { + rid := c.GetHeader(headerRequestID) + if rid == "" { + rid = uuid.Must(uuid.NewV4()).String() + c.Request.Header.Add(headerRequestID, rid) + } + + // set reqeust ID request context + ctx := context.WithValue(c.Request.Context(), RequestID, rid) + c.Request = c.Request.WithContext(ctx) + + // ensures that the request ID is in the response + c.Header(headerRequestID, rid) + c.Next() + } +} + +// Get returns the request ID +func Get(c *gin.Context) string { + return c.GetHeader(headerRequestID) +} + +// GetContext returns the request ID from context +func GetContext(ctx context.Context) string { + rid, ok := ctx.Value(RequestID).(string) + if !ok { + return "" + } + return rid +}
A internal/transport/http/reqid/reqid_test.go

@@ -0,0 +1,49 @@

+package reqid + +import ( + "net/http" + "net/http/httptest" + "testing" + + "github.com/gin-gonic/gin" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +//nolint:gochecknoinits +func init() { + gin.SetMode(gin.TestMode) +} + +func testHandler(c *gin.Context) { + c.Status(http.StatusOK) +} + +func TestMiddleware(t *testing.T) { + r := gin.New() + r.Use(Middleware()) + r.GET("/", testHandler) + + w := httptest.NewRecorder() + req, err := http.NewRequest(http.MethodGet, "/", nil) + require.NoError(t, err) + + r.ServeHTTP(w, req) + + assert.Equal(t, http.StatusOK, w.Code) + assert.NotEmpty(t, w.Header().Get(headerRequestID)) +} + +func BenchmarkMiddleware(b *testing.B) { + r := gin.New() + r.Use(Middleware()) + r.GET("/", testHandler) + + w := httptest.NewRecorder() + req, err := http.NewRequest(http.MethodGet, "/", nil) + require.NoError(b, err) + + for i := 0; i < b.N; i++ { + r.ServeHTTP(w, req) + } +}