Skip to content

Commit

Permalink
add logger test
Browse files Browse the repository at this point in the history 
Signed-off-by: Pavel Okhlopkov <[email protected]>
  • Loading branch information
Pavel Okhlopkov committed Oct 21, 2024
1 parent 2137ba5 commit 1b8b06d
Show file tree
Hide file tree
Showing 3 changed files with 261 additions and 3 deletions.
5 changes: 4 additions & 1 deletion pkg/unilogger/logger.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@ import (
"path/filepath"
"runtime/debug"
"strings"
"time"

logContext "github.com/flant/shell-operator/pkg/unilogger/context"
)
Expand All @@ -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 {
Expand Down Expand Up @@ -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))

Expand Down
252 changes: 252 additions & 0 deletions pkg/unilogger/logger_test.go
View file
Original file line number Diff line number Diff line change
@@ -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)
}
})
}
}
7 changes: 5 additions & 2 deletions pkg/unilogger/slog.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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 {
Expand Down Expand Up @@ -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)
Expand Down Expand Up @@ -162,13 +164,14 @@ 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{
Handler: slog.NewJSONHandler(b, opts),
b: b,
m: &sync.Mutex{},
w: out,
timeFn: timeFn,
}
}

0 comments on commit 1b8b06d

Please sign in to comment.