diff --git a/src/logger/bufio_wrapper.go b/src/logger/bufio_wrapper.go index ecab168..2f3353e 100644 --- a/src/logger/bufio_wrapper.go +++ b/src/logger/bufio_wrapper.go @@ -5,21 +5,25 @@ import ( "sync" ) -type BufioWrapper struct { +type bufioWrapper struct { *bufio.Writer m *sync.RWMutex } -func (b *BufioWrapper) Write(p []byte) (nn int, err error) { +func (b *bufioWrapper) Write(p []byte) (nn int, err error) { b.m.RLock() defer b.m.RUnlock() return b.Writer.Write(p) } -func (b *BufioWrapper) Flush() error { +func (b *bufioWrapper) Flush() error { b.m.Lock() defer b.m.Unlock() return b.Writer.Flush() } + +func (b *bufioWrapper) Close() error { + return b.Flush() +} diff --git a/src/logger/logger.go b/src/logger/logger.go index 97e9c5a..fb78003 100644 --- a/src/logger/logger.go +++ b/src/logger/logger.go @@ -1,12 +1,14 @@ package logger import ( - "backend/src/request_context" "context" + "github.com/gin-gonic/gin" "github.com/rs/zerolog" ) +const RequestIdKey = "logger_request_id" + type Logger interface { Log() Event Warning() Event @@ -14,11 +16,14 @@ type Logger interface { Fatal() Event Printf(format string, v ...any) + + WithContext(ctx context.Context) Logger + WithPrefix(prefix string) Logger } type logger struct { prefix string - requestCtx request_context.RequestContext + requestId string zeroLogger *zerolog.Logger } @@ -45,33 +50,38 @@ func (l logger) Printf(format string, v ...any) { func (l logger) wrapEvent(zerologEvent *zerolog.Event) Event { var e Event = event{zerologEvent} - if l.requestCtx != nil { - e = e.Str("requestId", l.requestCtx.RequestId()) - e = e.Str("userId", l.requestCtx.UserId()) - if l.prefix != "" { - e = e.Str("prefix", l.prefix) - } + if l.requestId != "" { + e = e.Str("requestId", l.requestId) + } + if l.prefix != "" { + e = e.Str("prefix", l.prefix) } return e } func (l logger) WithContext(ctx context.Context) Logger { - if rctx, ok := ctx.(request_context.RequestContext); ok { - return logger{ - prefix: l.prefix, - requestCtx: rctx, - zeroLogger: l.zeroLogger, - } + requestIdVal := ctx.Value(RequestIdKey) + requestId, ok := requestIdVal.(string) + if !ok || requestId == "" { + return l } - return l + return logger{ + prefix: l.prefix, + requestId: requestId, + zeroLogger: l.zeroLogger, + } } func (l logger) WithPrefix(prefix string) Logger { return logger{ prefix: prefix, - requestCtx: l.requestCtx, + requestId: l.requestId, zeroLogger: l.zeroLogger, } } + +func SetCtxRequestId(ginCtx *gin.Context, requestId string) { + ginCtx.Set(RequestIdKey, requestId) +} diff --git a/src/logger/new.go b/src/logger/new.go index 70ccab8..d3179aa 100644 --- a/src/logger/new.go +++ b/src/logger/new.go @@ -42,8 +42,8 @@ func New(opts NewLoggerOpts) (Logger, error) { level = zerolog.DebugLevel } - writer := bufio.NewWriterSize(io.MultiWriter(writers...), 32*1024) - wrapper := &BufioWrapper{writer, &sync.RWMutex{}} + writer := bufio.NewWriterSize(io.MultiWriter(writers...), 8*1024) + wrapper := &bufioWrapper{writer, &sync.RWMutex{}} go func() { tmr := time.NewTicker(500 * time.Millisecond) defer tmr.Stop() @@ -53,6 +53,7 @@ func New(opts NewLoggerOpts) (Logger, error) { select { case <-context.Background().Done(): + wrapper.Flush() return case <-tmr.C: } diff --git a/src/request_context/ctx.go b/src/request_context/ctx.go deleted file mode 100644 index 2436250..0000000 --- a/src/request_context/ctx.go +++ /dev/null @@ -1,59 +0,0 @@ -package request_context - -import ( - "context" - "time" -) - -type RequestContext interface { - context.Context - - RequestId() string - UserId() string -} - -type Opts struct { - RequestId string - UserId string -} - -func New(opts Opts) RequestContext { - return reqCtx{ - requestId: opts.RequestId, - userId: opts.UserId, - } -} - -type reqCtx struct { - ctx context.Context - requestId string - userId string -} - -func (r reqCtx) Deadline() (deadline time.Time, ok bool) { - return r.ctx.Deadline() -} - -func (r reqCtx) Done() <-chan struct{} { - return r.ctx.Done() -} - -func (r reqCtx) Err() error { - return r.ctx.Err() -} - -func (r reqCtx) Value(key any) any { - return r.ctx.Value(key) -} - -func (r reqCtx) String() string { - return r.ctx.Err().Error() -} - -func (r reqCtx) RequestId() string { - return r.requestId -} - -func (r reqCtx) UserId() string { - return r.userId -} diff --git a/src/server/handlers/long_pooling_handler.go b/src/server/handlers/long_pooling_handler.go index 332436e..840a254 100644 --- a/src/server/handlers/long_pooling_handler.go +++ b/src/server/handlers/long_pooling_handler.go @@ -2,12 +2,13 @@ package handlers import ( "backend/src/client_notifier" + "backend/src/logger" "backend/src/server/utils" "github.com/gin-gonic/gin" ) -func NewLongPoolingHandler(notifier client_notifier.ClientNotifier) gin.HandlerFunc { +func NewLongPoolingHandler(logger logger.Logger, notifier client_notifier.ClientNotifier) gin.HandlerFunc { return func(c *gin.Context) { user := utils.GetUserFromRequest(c) if user == nil { diff --git a/src/server/handlers/user_create_handler.go b/src/server/handlers/user_create_handler.go index 9591a13..98f3e34 100644 --- a/src/server/handlers/user_create_handler.go +++ b/src/server/handlers/user_create_handler.go @@ -2,6 +2,7 @@ package handlers import ( "backend/src/core/services" + "backend/src/logger" "encoding/json" "github.com/gin-gonic/gin" @@ -19,38 +20,54 @@ type createUserOutput struct { Name string `json:"name"` } -func NewUserCreateHandler(userService services.UserService) gin.HandlerFunc { - return func(ctx *gin.Context) { +func NewUserCreateHandler(logger logger.Logger, userService services.UserService) gin.HandlerFunc { + return func(c *gin.Context) { + ctxLogger := logger.WithContext(c) + params := createUserInput{} - if err := ctx.ShouldBindJSON(¶ms); err != nil { - ctx.AbortWithError(400, err) + if err := c.ShouldBindJSON(¶ms); err != nil { + ctxLogger.Error().Err(err).Msg("bad input body model") + c.Data(400, "plain/text", []byte(err.Error())) return } - dto, err := userService.CreateUser(ctx, services.UserCreateParams{ - Email: params.Email, - Password: params.Password, - Name: params.Name, - }) - if err == services.ErrUserExists || err == services.ErrUserBadPassword { - ctx.Data(400, "plain/text", []byte(err.Error())) + dto, err := userService.CreateUser( + c, + services.UserCreateParams{ + Email: params.Email, + Password: params.Password, + Name: params.Name, + }, + ) + if err == services.ErrUserExists { + ctxLogger.Error().Err(err).Msg("user already exists") + c.Data(400, "plain/text", []byte(err.Error())) + return + } + if err == services.ErrUserBadPassword { + ctxLogger.Error().Err(err).Msg("password does not satisfy requirements") + c.Data(400, "plain/text", []byte(err.Error())) return } if err != nil { - ctx.Data(500, "plain/text", []byte(err.Error())) + ctxLogger.Error().Err(err).Msg("create user error") + c.Data(500, "plain/text", []byte(err.Error())) return } - resultBody, err := json.Marshal(createUserOutput{ - Id: dto.Id, - Email: dto.Email, - Name: dto.Name, - }) + resultBody, err := json.Marshal( + createUserOutput{ + Id: dto.Id, + Email: dto.Email, + Name: dto.Name, + }, + ) if err != nil { - ctx.AbortWithError(500, err) + ctxLogger.Error().Err(err).Msg("marshal user model error") + c.Data(500, "plain/text", []byte(err.Error())) return } - ctx.Data(200, "application/json", resultBody) + c.Data(200, "application/json", resultBody) } } diff --git a/src/server/handlers/user_login_handler.go b/src/server/handlers/user_login_handler.go index 4250728..e48552c 100644 --- a/src/server/handlers/user_login_handler.go +++ b/src/server/handlers/user_login_handler.go @@ -2,6 +2,7 @@ package handlers import ( "backend/src/core/services" + "backend/src/logger" "encoding/json" "github.com/gin-gonic/gin" @@ -16,21 +17,31 @@ type loginUserOutput struct { Token string `json:"token"` } -func NewUserLoginHandler(userService services.UserService) gin.HandlerFunc { - return func(ctx *gin.Context) { +func NewUserLoginHandler(logger logger.Logger, userService services.UserService) gin.HandlerFunc { + return func(c *gin.Context) { + ctxLogger := logger.WithContext(c).WithPrefix("NewUserLoginHandler") + params := loginUserInput{} - if err := ctx.ShouldBindJSON(¶ms); err != nil { - ctx.AbortWithError(400, err) + if err := c.ShouldBindJSON(¶ms); err != nil { + ctxLogger.Error().Err(err).Msg("bad input body model") + c.AbortWithError(400, err) return } - token, err := userService.AuthenticateUser(ctx, params.Login, params.Password) - if err == services.ErrUserNotExists || err == services.ErrUserWrongPassword { - ctx.AbortWithError(400, err) + token, err := userService.AuthenticateUser(c, params.Login, params.Password) + if err == services.ErrUserNotExists { + ctxLogger.Error().Err(err).Msg("user does not exist") + c.AbortWithError(400, err) + return + } + if err == services.ErrUserWrongPassword { + ctxLogger.Error().Err(err).Msg("wrong password") + c.AbortWithError(400, err) return } if err != nil { - ctx.AbortWithError(500, err) + ctxLogger.Error().Err(err).Msg("AuthenticateUser internal error") + c.AbortWithError(500, err) return } @@ -38,10 +49,11 @@ func NewUserLoginHandler(userService services.UserService) gin.HandlerFunc { Token: token, }) if err != nil { - ctx.AbortWithError(500, err) + ctxLogger.Error().Err(err).Msg("marshal json internal error") + c.AbortWithError(500, err) return } - ctx.Data(200, "application/json", resultBody) + c.Data(200, "application/json", resultBody) } } diff --git a/src/server/middleware/request_log.go b/src/server/middleware/request_log.go index 889d75f..691bc33 100644 --- a/src/server/middleware/request_log.go +++ b/src/server/middleware/request_log.go @@ -1,20 +1,22 @@ package middleware import ( - "backend/src/logger" + log "backend/src/logger" "time" "github.com/gin-gonic/gin" "github.com/google/uuid" ) -func NewRequestLogMiddleware(logger logger.Logger) gin.HandlerFunc { +func NewRequestLogMiddleware(logger log.Logger) gin.HandlerFunc { return func(c *gin.Context) { requestId := c.GetHeader("X-Request-Id") if requestId == "" { requestId = uuid.New().String() } + log.SetCtxRequestId(c, requestId) + path := c.Request.URL.Path if c.Request.URL.RawQuery != "" { path = path + "?" + c.Request.URL.RawQuery @@ -28,9 +30,10 @@ func NewRequestLogMiddleware(logger logger.Logger) gin.HandlerFunc { statusCode := c.Writer.Status() clientIP := c.ClientIP() - e := logger.Log() - e.Str("id", requestId) + ctxLogger := logger.WithContext(c) + + e := ctxLogger.Log() e.Str("ip", clientIP) - e.Msgf("[REQUEST] %s %s %d %v", method, path, statusCode, latency) + e.Msgf("Request %s %s %d %v", method, path, statusCode, latency) } } diff --git a/src/server/server.go b/src/server/server.go index cfd5eaf..3d0ad53 100644 --- a/src/server/server.go +++ b/src/server/server.go @@ -32,20 +32,21 @@ func New(opts NewServerOpts) *Server { } r := gin.New() + r.Static("/webapp", "./webapp") + r.GET("/health", handlers.NewDummyHandler()) + r.Use(middleware.NewRequestLogMiddleware(opts.Logger)) r.Use(middleware.NewRecoveryMiddleware(opts.Logger, opts.DebugMode)) - r.Static("/webapp", "./webapp") - - r.GET("/pooling", handlers.NewLongPoolingHandler(opts.Notifier)) + r.GET("/pooling", handlers.NewLongPoolingHandler(opts.Logger, opts.Notifier)) linkGroup := r.Group("/s") linkGroup.POST("/new", handlers.NewShortlinkCreateHandler(opts.ShortlinkService)) linkGroup.GET("/:linkId", handlers.NewShortlinkResolveHandler(opts.ShortlinkService)) userGroup := r.Group("/user") - userGroup.POST("/create", handlers.NewUserCreateHandler(opts.UserService)) - userGroup.POST("/login", handlers.NewUserLoginHandler(opts.UserService)) + userGroup.POST("/create", handlers.NewUserCreateHandler(opts.Logger, opts.UserService)) + userGroup.POST("/login", handlers.NewUserLoginHandler(opts.Logger, opts.UserService)) dummyGroup := r.Group("/dummy") {