refactor: log to support sublog

.vscode/settings.json

@@ -18,6 +18,7 @@
         "pgdialect",
         "pgxpool",
         "realworld",
+        "requestid",
         "sslmode",
         "stdlib",
         "stretchr",

go.mod

@@ -19,6 +19,7 @@ require (
 	github.com/chenzhuoyu/iasm v0.9.0 // indirect
 	github.com/fsnotify/fsnotify v1.6.0 // indirect
 	github.com/gabriel-vasile/mimetype v1.4.2 // indirect
+	github.com/gin-contrib/requestid v0.0.6 // indirect
 	github.com/gin-contrib/sse v0.1.0 // indirect
 	github.com/go-playground/locales v0.14.1 // indirect
 	github.com/go-playground/universal-translator v0.18.1 // indirect

go.sum

@@ -92,6 +92,8 @@ github.com/gabriel-vasile/mimetype v1.4.2 h1:w5qFW6JKBz9Y393Y4q372O9A7cUSequkh1Q
 github.com/gabriel-vasile/mimetype v1.4.2/go.mod h1:zApsH/mKG4w07erKIaJPFiX0Tsq9BFQgN3qGY5GnNgA=
 github.com/gin-contrib/cors v1.4.0 h1:oJ6gwtUl3lqV0WEIwM/LxPF1QZ5qe2lGWdY2+bz7y0g=
 github.com/gin-contrib/cors v1.4.0/go.mod h1:bs9pNM0x/UsmHPBWT2xZz9ROh8xYjYkiURUfmBoMlcs=
+github.com/gin-contrib/requestid v0.0.6 h1:mGcxTnHQ45F6QU5HQRgQUDsAfHprD3P7g2uZ4cSZo9o=
+github.com/gin-contrib/requestid v0.0.6/go.mod h1:9i4vKATX/CdggbkY252dPVasgVucy/ggBeELXuQztm4=
 github.com/gin-contrib/sse v0.1.0 h1:Y/yl/+YNO8GZSjAhjMsSuLt29uWRFHdHYUb5lYOV9qE=
 github.com/gin-contrib/sse v0.1.0/go.mod h1:RHrZQHXnP2xjPF+u1gW/2HnVO7nvIa9PG3Gm+fLHvGI=
 github.com/gin-gonic/gin v1.8.1/go.mod h1:ji8BvRH1azfM+SYow9zQ6SZMvR8qOMZHmsCuWR9tTTk=
@@ -181,6 +183,7 @@ github.com/google/pprof v0.0.0-20201203190320-1bf35d6f28c2/go.mod h1:kpwsk12EmLe
 github.com/google/pprof v0.0.0-20201218002935-b9804c9f04c2/go.mod h1:kpwsk12EmLew5upagYY7GY0pfYCcupk39gWOCRROcvE=
 github.com/google/renameio v0.1.0/go.mod h1:KWCgfxg9yswjAJkECMjeO8J8rahYeXnNhOm40UhjYkI=
 github.com/google/uuid v1.1.2/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo=
+github.com/google/uuid v1.3.0/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo=
 github.com/google/uuid v1.3.1 h1:KjJaJ9iWZ3jOFZIf1Lqf4laDRCasjl0BCmnEGxkdLb4=
 github.com/google/uuid v1.3.1/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo=
 github.com/googleapis/gax-go/v2 v2.0.4/go.mod h1:0Wqv26UfaUD9n4G6kQubkQ+KchISgw+vpHVxEJEs9eg=

internal/adapter/handler/restful/logger.go

@@ -6,26 +6,40 @@ import (
 	"time"
 
 	"github.com/gin-gonic/gin"
+	"github.com/google/uuid"
+	"github.com/labasubagia/realworld-backend/internal/core/port"
 )
 
 func (s *Server) Logger() gin.HandlerFunc {
 	return func(c *gin.Context) {
+
+		// request id
+		reqID := c.GetHeader("x-request-id")
+		if reqID == "" {
+			reqID = uuid.NewString()
+		}
+
+		// make logger and sub-logger
+		logger := s.logger.Field("request_id", reqID).Logger()
+		c.Set(port.LoggerCtxKey, logger)
+
 		// process request
 		startTime := time.Now()
 		c.Next()
 		duration := time.Since(startTime)
 
 		// log
-		logger := s.logger.Info()
+		logEvent := s.logger.Info()
 		if c.Writer.Status() >= 500 {
-			logger = s.logger.Error()
+			logEvent = s.logger.Error()
 			if c.Request != nil && c.Request.Body != nil {
 				if body, err := io.ReadAll(c.Request.Body); err == nil {
-					logger.Field("body", body)
+					logEvent.Field("body", body)
 				}
 			}
 		}
-		logger.
+		logEvent.
+			Field("request_id", reqID).
 			Field("protocol", "http").
 			Field("method", c.Request.Method).
 			Field("path", c.Request.URL.Path).

internal/adapter/logger/zap.go

@@ -23,61 +23,82 @@ func NewZapLogger(config util.Config) port.Logger {
 	}
 }
 
-// Log Level
+func (l *zapLogger) Field(key string, value any) port.Logger {
+	l.fields[key] = value
+	return l
+}
 
-func (l *zapLogger) Info() port.Logger {
-	l.level = zap.InfoLevel
+func (l *zapLogger) Logger() port.Logger {
 	return l
 }
 
-func (l *zapLogger) Error() port.Logger {
+func (l *zapLogger) Info() port.LogEvent {
+	l.level = zap.InfoLevel
+	return newZapEvent(l)
+}
+
+func (l *zapLogger) Error() port.LogEvent {
 	l.level = zapcore.ErrorLevel
-	return l
+	return newZapEvent(l)
 }
 
-func (l *zapLogger) Fatal() port.Logger {
+func (l *zapLogger) Fatal() port.LogEvent {
 	l.level = zap.PanicLevel
-	return l
+	return newZapEvent(l)
 }
 
-// Set Attributes
+type zapEvent struct {
+	opt    *zapLogger
+	fields map[string]any
+}
 
-func (l *zapLogger) Field(key string, value any) port.Logger {
-	l.fields[key] = value
-	return l
+func newZapEvent(opt *zapLogger) port.LogEvent {
+	return &zapEvent{
+		opt:    opt,
+		fields: map[string]any{},
+	}
 }
 
-func (l *zapLogger) Err(err error) port.Logger {
+func (e *zapEvent) Err(err error) port.LogEvent {
 	if err != nil {
-		return l
+		return e
 	}
-	l.fields["error"] = err.Error()
-	return l
+	e.fields["error"] = err.Error()
+	return e
 }
 
-// Send
+func (e *zapEvent) Field(key string, value any) port.LogEvent {
+	e.fields[key] = value
+	return e
+}
 
-func (l *zapLogger) Msg(v ...any) {
+func (e *zapEvent) Msg(v ...any) {
 	msg := fmt.Sprintln(v...)
-	l.send(msg)
+	e.send(msg)
 }
 
-func (l *zapLogger) Msgf(format string, v ...any) {
+func (e *zapEvent) Msgf(format string, v ...any) {
 	msg := fmt.Sprintf(format, v...)
-	l.send(msg)
+	e.send(msg)
 }
 
-func (l *zapLogger) send(msg string) {
+func (e *zapEvent) send(msg string) {
 	config := zap.NewProductionConfig()
-	if !l.config.IsProduction() {
+	if !e.opt.config.IsProduction() {
 		config = zap.NewDevelopmentConfig()
 	}
-	config.InitialFields = l.fields
+
+	for k, v := range e.opt.fields {
+		e.fields[k] = v
+	}
+	e.opt.fields = map[string]any{}
+	config.InitialFields = e.fields
+
 	logger, _ := config.Build()
 	defer func() {
 		logger.Sync()
-		l.fields = map[string]any{}
+		e.fields = map[string]any{}
 	}()
-	stdLogger, _ := zap.NewStdLogAt(logger, l.level)
+	stdLogger, _ := zap.NewStdLogAt(logger, e.opt.level)
 	stdLogger.Println(msg)
 }

internal/adapter/logger/zerolog.go

@@ -11,8 +11,8 @@ import (
 )
 
 type zeroLogLogger struct {
-	log   zerolog.Logger
-	event *zerolog.Event
+	logger zerolog.Logger
+	fields map[string]any
 }
 
 func NewZeroLogLogger(config util.Config) port.Logger {
@@ -22,46 +22,57 @@ func NewZeroLogLogger(config util.Config) port.Logger {
 		logger = zerolog.New(output).With().Timestamp().Logger()
 	}
 	return &zeroLogLogger{
-		log:   logger,
-		event: logger.Info(),
+		logger: logger,
+		fields: map[string]any{},
 	}
 }
 
-// Log Level
-
-func (l *zeroLogLogger) Info() port.Logger {
-	l.event = l.log.Info()
+func (l *zeroLogLogger) Field(key string, value any) port.Logger {
+	l.fields[key] = value
 	return l
 }
 
-func (l *zeroLogLogger) Error() port.Logger {
-	l.event = l.log.Error()
+func (l *zeroLogLogger) Logger() port.Logger {
 	return l
 }
 
-func (l *zeroLogLogger) Fatal() port.Logger {
-	l.event = l.log.Fatal()
-	return l
+func (l *zeroLogLogger) Info() port.LogEvent {
+	return newZeroLogEvent(l.fields, l.logger.Info())
 }
 
-// Set Attributes
+func (l *zeroLogLogger) Error() port.LogEvent {
+	return newZeroLogEvent(l.fields, l.logger.Error())
+}
 
-func (l *zeroLogLogger) Err(err error) port.Logger {
-	l.event = l.event.Err(err)
-	return l
+func (l *zeroLogLogger) Fatal() port.LogEvent {
+	return newZeroLogEvent(l.fields, l.logger.Fatal())
 }
 
-func (l *zeroLogLogger) Field(key string, value any) port.Logger {
-	l.event = l.event.Any(key, value)
-	return l
+type zeroLogEvent struct {
+	event *zerolog.Event
+}
+
+func newZeroLogEvent(initialFields map[string]any, event *zerolog.Event) port.LogEvent {
+	event.Fields(initialFields)
+	return &zeroLogEvent{event: event}
 }
 
-// Send
+func (e *zeroLogEvent) Err(err error) port.LogEvent {
+	e.event.Err(err)
+	return e
+}
+
+func (e *zeroLogEvent) Field(key string, value any) port.LogEvent {
+	e.event.Any(key, value)
+	return e
+}
 
-func (l *zeroLogLogger) Msg(v ...any) {
-	l.event.Msg(fmt.Sprint(v...))
+func (e *zeroLogEvent) Msg(v ...any) {
+	msg := fmt.Sprintln(v...)
+	e.event.Msg(msg)
 }
 
-func (l *zeroLogLogger) Msgf(format string, v ...any) {
-	l.event.Msgf(format, v...)
+func (e *zeroLogEvent) Msgf(format string, v ...any) {
+	msg := fmt.Sprintf(format, v...)
+	e.event.Msg(msg)
 }

internal/adapter/repository/sql/db/logger.go

@@ -28,11 +28,12 @@ func (h *LoggerHook) AfterQuery(ctx context.Context, event *bun.QueryEvent) {
 	now := time.Now()
 	duration := now.Sub(event.StartTime)
 
-	logger := h.logger.Info()
+	subLogger, _ := ctx.Value(port.LoggerCtxKey).(port.Logger)
+	logEvent := subLogger.Info()
 	if event.Err != nil {
-		logger = h.logger.Error().Err(event.Err)
+		logEvent = subLogger.Error().Err(event.Err)
 	}
-	logger.
+	logEvent.
 		Field("duration", duration).
 		Field("query", event.Query).
 		Msgf("SQL %s", event.Operation())

internal/core/port/logger.go

@@ -1,17 +1,20 @@
 package port
 
-type Logger interface {
-	// Level
-	// ? just limit to 2
-	Info() Logger
-	Error() Logger
-	Fatal() Logger
-	Err(error) Logger
+const LoggerCtxKey = "logger_key"
 
-	// set attributes
+type Logger interface {
 	Field(string, any) Logger
+	Logger() Logger
+
+	Info() LogEvent
+	Error() LogEvent
+	Fatal() LogEvent
+}
+
+type LogEvent interface {
+	Field(string, any) LogEvent
+	Err(error) LogEvent
 
-	// send
 	Msgf(string, ...any)
 	Msg(...any)
 }

internal/core/service/user.go

@@ -39,6 +39,9 @@ func (s *userService) Register(ctx context.Context, req port.RegisterParams) (us
 }
 
 func (s *userService) Login(ctx context.Context, req port.LoginParams) (user domain.User, err error) {
+	subLogger, _ := ctx.Value(port.LoggerCtxKey).(port.Logger)
+	subLogger.Info().Msg("func login")
+
 	existing, err := s.property.repo.User().FilterUser(ctx, port.FilterUserPayload{Emails: []string{req.User.Email}})
 	if err != nil {
 		return domain.User{}, exception.Into(err)