diff --git a/logger/zerolog.go b/logger/zerolog.go new file mode 100644 index 0000000..4142453 --- /dev/null +++ b/logger/zerolog.go @@ -0,0 +1,115 @@ +package logger + +import ( + "github.com/9seconds/mtg/v2/mtglib" + "github.com/rs/zerolog" +) + +const loggerFieldName = "logger" + +type zeroLogContextVarType uint8 + +const ( + zeroLogContextVarTypeUnknown zeroLogContextVarType = iota + zeroLogContextVarTypeStr + zeroLogContextVarTypeInt +) + +type zeroLogContext struct { + name string + log *zerolog.Logger + + ctxVarType zeroLogContextVarType + ctxVarName string + ctxVarStr string + ctxVarInt int + + parent *zeroLogContext +} + +func (z *zeroLogContext) Named(name string) mtglib.Logger { + loggerName := z.name + if loggerName == "" { + loggerName = name + } else { + loggerName += "." + name + } + + return &zeroLogContext{ + name: loggerName, + log: z.log, + parent: z, + } +} + +func (z *zeroLogContext) BindInt(name string, value int) mtglib.Logger { + return &zeroLogContext{ + name: z.name, + log: z.log, + ctxVarType: zeroLogContextVarTypeInt, + ctxVarInt: value, + ctxVarName: name, + parent: z, + } +} + +func (z *zeroLogContext) BindStr(name, value string) mtglib.Logger { + return &zeroLogContext{ + name: z.name, + log: z.log, + ctxVarType: zeroLogContextVarTypeStr, + ctxVarStr: value, + ctxVarName: name, + parent: z, + } +} + +func (z *zeroLogContext) Info(msg string) { + z.InfoError(msg, nil) +} + +func (z *zeroLogContext) Warning(msg string) { + z.WarningError(msg, nil) +} + +func (z *zeroLogContext) Debug(msg string) { + z.DebugError(msg, nil) +} + +func (z *zeroLogContext) InfoError(msg string, err error) { + z.emitLog(z.log.Info(), msg, err) +} + +func (z *zeroLogContext) WarningError(msg string, err error) { + z.emitLog(z.log.Warn(), msg, err) +} + +func (z *zeroLogContext) DebugError(msg string, err error) { + z.emitLog(z.log.Debug(), msg, err) +} + +func (z *zeroLogContext) emitLog(evt *zerolog.Event, msg string, err error) { + z.attachCtx(evt) + + for current := z.parent; current != nil; current = current.parent { + current.attachCtx(evt) + } + + evt.Str(loggerFieldName, z.name).Err(err).Msg(msg) +} + +func (z *zeroLogContext) attachCtx(evt *zerolog.Event) { + switch z.ctxVarType { + case zeroLogContextVarTypeStr: + evt.Str(z.ctxVarName, z.ctxVarStr) + case zeroLogContextVarTypeInt: + evt.Int(z.ctxVarName, z.ctxVarInt) + case zeroLogContextVarTypeUnknown: + } +} + +func NewZeroLogger(log zerolog.Logger) mtglib.Logger { + return &zeroLogContext{ + log: &log, + } +} diff --git a/logger/zerolog_test.go b/logger/zerolog_test.go new file mode 100644 index 0000000..4b2308f --- /dev/null +++ b/logger/zerolog_test.go @@ -0,0 +1,116 @@ +package logger_test + +import ( + "bytes" + "encoding/json" + "io" + "strings" + "testing" + "time" + + "github.com/9seconds/mtg/v2/logger" + "github.com/9seconds/mtg/v2/mtglib" + "github.com/rs/zerolog" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/suite" +) + +type zeroLoggerLogMessage struct { + Timestamp int64 `json:"timestamp"` + Level string `json:"level"` + StrParam string `json:"strparam"` + IntParam int `json:"intparam"` + Logger string `json:"logger"` + Error string `json:"error"` + Message string `json:"message"` +} + +type ZeroLoggerTestSuite struct { + suite.Suite +} + +func (suite *ZeroLoggerTestSuite) SetupSuite() { + zerolog.SetGlobalLevel(zerolog.TraceLevel) + + zerolog.TimeFieldFormat = zerolog.TimeFormatUnixMs + zerolog.TimestampFieldName = "timestamp" + zerolog.LevelFieldName = "level" +} + +func (suite *ZeroLoggerTestSuite) TestLog() { + testData := map[string]func(mtglib.Logger){ + "info": func(l mtglib.Logger) { l.Info("hello") }, + "warn": func(l mtglib.Logger) { l.Warning("hello") }, + "debug": func(l mtglib.Logger) { l.Debug("hello") }, + "info-error": func(l mtglib.Logger) { l.InfoError("hello", io.EOF) }, + "warn-error": func(l mtglib.Logger) { l.WarningError("hello", io.EOF) }, + "debug-error": func(l mtglib.Logger) { l.DebugError("hello", io.EOF) }, + } + + for k, v := range testData { + name := k + callback := v + level := strings.TrimSuffix(name, "-error") + + suite.T().Run(name, func(t *testing.T) { + buf := &bytes.Buffer{} + log := logger.NewZeroLogger(zerolog.New(buf).With().Timestamp().Logger()) + + callback(log.Named("name").BindInt("intparam", 1).BindStr("strparam", name)) + + msg := &zeroLoggerLogMessage{} + assert.NoError(t, json.Unmarshal(buf.Bytes(), msg)) + + timestamp := time.Unix(msg.Timestamp/1000, (msg.Timestamp%1000)*1_000_000) + assert.WithinDuration(t, time.Now(), timestamp, 100*time.Millisecond) + + assert.Equal(t, level, msg.Level) + assert.Equal(t, name, msg.StrParam) + assert.EqualValues(t, 1, msg.IntParam) + assert.Equal(t, "name", msg.Logger) + assert.Equal(t, "hello", msg.Message) + + if level != name { + assert.Equal(t, io.EOF.Error(), msg.Error) + } else { + assert.Empty(t, msg.Error) + } + }) + } +} + +func (suite *ZeroLoggerTestSuite) TestIndependence() { + buf := &bytes.Buffer{} + log := logger.NewZeroLogger(zerolog.New(buf).With().Timestamp().Logger()) + + log1 := log.Named("1") + log2 := log.Named("2") + log12 := log1.Named("2") + + log1.BindInt("param", 1).Info("hello") + + log1Output := buf.String() + + buf.Reset() + + log2.BindInt("lalala", 2).Info("hello") + + log2Output := buf.String() + + buf.Reset() + + log12.BindStr("tttt", "qqq").Info("hello") + + log12Output := buf.String() + + suite.NotContains("lalala", log1Output) + suite.NotContains("tttt", log1Output) + suite.NotContains("param", log2Output) + suite.NotContains("tttt", log1Output) + suite.NotContains("param", log12Output) + suite.NotContains("lalala", log12Output) +} + +func TestZeroLogger(t *testing.T) { // nolint: paralleltest + suite.Run(t, &ZeroLoggerTestSuite{}) +}