diff --git a/pkg/unilogger/logger.go b/pkg/unilogger/logger.go index a7c78043..0aa9b45e 100644 --- a/pkg/unilogger/logger.go +++ b/pkg/unilogger/logger.go @@ -10,6 +10,7 @@ import ( "path/filepath" "runtime/debug" "strings" + "time" logContext "github.com/flant/shell-operator/pkg/unilogger/context" ) @@ -33,6 +34,8 @@ type Options struct { AddSource bool Level slog.Level Output io.Writer + + TimeFunc func(t time.Time) time.Time } func NewNop() *Logger { @@ -84,7 +87,7 @@ func NewLogger(opts Options) *Logger { }, } - l.slogHandler = NewHandler(opts.Output, handlerOpts) + l.slogHandler = NewHandler(opts.Output, handlerOpts, opts.TimeFunc) l.logger = slog.New(l.slogHandler.WithAttrs(nil)) diff --git a/pkg/unilogger/logger_test.go b/pkg/unilogger/logger_test.go new file mode 100644 index 00000000..4647802b --- /dev/null +++ b/pkg/unilogger/logger_test.go @@ -0,0 +1,252 @@ +package unilogger_test + +import ( + "bytes" + "context" + "log/slog" + "testing" + "time" + + "github.com/flant/shell-operator/pkg/unilogger" + + "github.com/stretchr/testify/assert" +) + +func Test_Logger(t *testing.T) { + t.Parallel() + + defaultLogFn := func(logger *unilogger.Logger) { + logger.Trace("stub msg", slog.String("stub_arg", "arg")) + logger.Debug("stub msg", slog.String("stub_arg", "arg")) + logger.Info("stub msg", slog.String("stub_arg", "arg")) + logger.Warn("stub msg", slog.String("stub_arg", "arg")) + logger.Error("stub msg", slog.String("stub_arg", "arg")) + //test fatal + logger.Log(context.Background(), unilogger.LevelFatal.Level(), "stub msg", slog.String("stub_arg", "arg")) + } + + type meta struct { + name string + enabled bool + } + + type fields struct { + logfn func(logger *unilogger.Logger) *unilogger.Logger + } + + type args struct { + addSource bool + level unilogger.Level + } + + type wants struct { + shouldContains []string + shouldNotContains []string + } + + tests := []struct { + meta meta + fields fields + args args + wants wants + }{ + { + meta: meta{ + name: "logger default options is level info and add source false", + enabled: true, + }, + fields: fields{ + logfn: func(logger *unilogger.Logger) *unilogger.Logger { return logger }, + }, + args: args{}, + wants: wants{ + shouldContains: []string{ + `{"level":"info","msg":"stub msg","stub_arg":"arg","time":"2006-01-02T15:04:05Z"}`, + `{"level":"warn","msg":"stub msg","stub_arg":"arg","time":"2006-01-02T15:04:05Z"}`, + `{"level":"error","msg":"stub msg","stub_arg":"arg","time":"2006-01-02T15:04:05Z"}`, + `{"level":"fatal","msg":"stub msg","stub_arg":"arg","time":"2006-01-02T15:04:05Z"}`, + }, + shouldNotContains: []string{ + `"level":"debug"`, + `"level":"trace"`, + }, + }, + }, + { + meta: meta{ + name: "logger change to debug level should contains addsource and debug level", + enabled: true, + }, + fields: fields{ + logfn: func(logger *unilogger.Logger) *unilogger.Logger { + logger.SetLevel(unilogger.LevelDebug) + + return logger + }, + }, + args: args{ + addSource: false, + level: unilogger.LevelInfo, + }, + wants: wants{ + shouldContains: []string{ + `{"level":"debug","msg":"stub msg","source":"unilogger/logger_test.go:20","stub_arg":"arg","time":"2006-01-02T15:04:05Z"}`, + `{"level":"info","msg":"stub msg","source":"unilogger/logger_test.go:21","stub_arg":"arg","time":"2006-01-02T15:04:05Z"}`, + `{"level":"warn","msg":"stub msg","source":"unilogger/logger_test.go:22","stub_arg":"arg","time":"2006-01-02T15:04:05Z"}`, + `{"level":"error","msg":"stub msg","source":"unilogger/logger_test.go:23","stub_arg":"arg","time":"2006-01-02T15:04:05Z"}`, + `{"level":"fatal","msg":"stub msg","source":"unilogger/logger_test.go:25","stub_arg":"arg","time":"2006-01-02T15:04:05Z"}`, + }, + shouldNotContains: []string{ + `"level":"trace"`, + }, + }, + }, + { + meta: meta{ + name: "logger with name should have field logger", + enabled: true, + }, + fields: fields{ + logfn: func(logger *unilogger.Logger) *unilogger.Logger { + return logger.Named("first") + }, + }, + args: args{ + addSource: false, + level: unilogger.LevelInfo, + }, + wants: wants{ + shouldContains: []string{ + `{"level":"info","logger":"first","msg":"stub msg","stub_arg":"arg","time":"2006-01-02T15:04:05Z"}`, + `{"level":"warn","logger":"first","msg":"stub msg","stub_arg":"arg","time":"2006-01-02T15:04:05Z"}`, + `{"level":"error","logger":"first","msg":"stub msg","stub_arg":"arg","time":"2006-01-02T15:04:05Z"}`, + `{"level":"fatal","logger":"first","msg":"stub msg","stub_arg":"arg","time":"2006-01-02T15:04:05Z"}`}, + shouldNotContains: []string{ + `"level":"debug"`, + `"level":"trace"`, + }, + }, + }, + { + meta: meta{ + name: "logger names shoud separate by dot", + enabled: true, + }, + fields: fields{ + logfn: func(logger *unilogger.Logger) *unilogger.Logger { + logger = logger.Named("first") + logger = logger.Named("second") + return logger.Named("third") + }, + }, + args: args{ + addSource: false, + level: unilogger.LevelInfo, + }, + wants: wants{ + shouldContains: []string{ + `{"level":"info","logger":"first.second.third","msg":"stub msg","stub_arg":"arg","time":"2006-01-02T15:04:05Z"}`, + `{"level":"warn","logger":"first.second.third","msg":"stub msg","stub_arg":"arg","time":"2006-01-02T15:04:05Z"}`, + `{"level":"error","logger":"first.second.third","msg":"stub msg","stub_arg":"arg","time":"2006-01-02T15:04:05Z"}`, + `{"level":"fatal","logger":"first.second.third","msg":"stub msg","stub_arg":"arg","time":"2006-01-02T15:04:05Z"}`, + }, + shouldNotContains: []string{ + `"level":"debug"`, + `"level":"trace"`, + }, + }, + }, + { + meta: meta{ + name: "with group should wrap args", + enabled: true, + }, + fields: fields{ + logfn: func(logger *unilogger.Logger) *unilogger.Logger { + return logger.WithGroup("module") + }, + }, + args: args{ + addSource: false, + level: unilogger.LevelInfo, + }, + wants: wants{ + shouldContains: []string{ + `{"level":"info","msg":"stub msg","module":{"stub_arg":"arg"},"time":"2006-01-02T15:04:05Z"}`, + `{"level":"warn","msg":"stub msg","module":{"stub_arg":"arg"},"time":"2006-01-02T15:04:05Z"}`, + `{"level":"error","msg":"stub msg","module":{"stub_arg":"arg"},"time":"2006-01-02T15:04:05Z"}`, + `{"level":"fatal","msg":"stub msg","module":{"stub_arg":"arg"},"time":"2006-01-02T15:04:05Z"}`, + }, + shouldNotContains: []string{ + `"level":"debug"`, + `"level":"trace"`, + }, + }, + }, + { + meta: meta{ + name: "default logger level change must affect logger which set default", + enabled: true, + }, + fields: fields{ + logfn: func(logger *unilogger.Logger) *unilogger.Logger { + unilogger.SetDefault(logger) + unilogger.SetDefaultLevel(unilogger.LevelError) + return logger + }, + }, + args: args{ + addSource: false, + level: unilogger.LevelInfo, + }, + wants: wants{ + shouldContains: []string{ + `{"level":"error","msg":"stub msg","stub_arg":"arg","time":"2006-01-02T15:04:05Z"}`, + `{"level":"fatal","msg":"stub msg","stub_arg":"arg","time":"2006-01-02T15:04:05Z"}`, + }, + shouldNotContains: []string{ + `"level":"info"`, + `"level":"warn"`, + `"level":"debug"`, + `"level":"trace"`, + }, + }, + }, + } + + for _, tt := range tests { + if !tt.meta.enabled { + continue + } + + t.Run(tt.meta.name, func(t *testing.T) { + buf := bytes.NewBuffer([]byte{}) + + logger := unilogger.NewLogger(unilogger.Options{ + AddSource: tt.args.addSource, + Level: tt.args.level.Level(), + Output: buf, + TimeFunc: func(_ time.Time) time.Time { + t, err := time.Parse(time.DateTime, "2006-01-02 15:04:05") + if err != nil { + panic(err) + } + + return t + }, + }) + + logger = tt.fields.logfn(logger) + + defaultLogFn(logger) + + for _, v := range tt.wants.shouldContains { + assert.Contains(t, buf.String(), v) + } + + for _, v := range tt.wants.shouldNotContains { + assert.NotContains(t, buf.String(), v) + } + }) + } +} diff --git a/pkg/unilogger/slog.go b/pkg/unilogger/slog.go index 2cb6b3d3..cef32b2d 100644 --- a/pkg/unilogger/slog.go +++ b/pkg/unilogger/slog.go @@ -36,6 +36,8 @@ type SlogHandler struct { w io.Writer b *bytes.Buffer m *sync.Mutex + + timeFn func(t time.Time) time.Time } func NewSlogHandler(handler slog.Handler) *SlogHandler { @@ -81,7 +83,7 @@ func (h *SlogHandler) Handle(ctx context.Context, r slog.Record) error { // HEAD start var headLogFields []string lvl := fmt.Sprintf(`"level":"%s"`, strings.ToLower(Level(r.Level).String())) - time := fmt.Sprintf(`"time":"%s"`, r.Time.Format(time.RFC3339)) + time := fmt.Sprintf(`"time":"%s"`, h.timeFn(r.Time).Format(time.RFC3339)) msg := fmt.Sprintf(`"msg":"%s"`, r.Message) headLogFields = append(headLogFields, lvl) @@ -162,7 +164,7 @@ func (h *SlogHandler) WithGroup(name string) slog.Handler { return &h2 } -func NewHandler(out io.Writer, opts *slog.HandlerOptions) *SlogHandler { +func NewHandler(out io.Writer, opts *slog.HandlerOptions, timeFn func(t time.Time) time.Time) *SlogHandler { b := new(bytes.Buffer) return &SlogHandler{ @@ -170,5 +172,6 @@ func NewHandler(out io.Writer, opts *slog.HandlerOptions) *SlogHandler { b: b, m: &sync.Mutex{}, w: out, + timeFn: timeFn, } }