From 1fac5f73bea9fe9c2548e67de76e175d7dc3c535 Mon Sep 17 00:00:00 2001 From: Inhere Date: Fri, 14 Apr 2023 22:28:47 +0800 Subject: [PATCH] :necktie: up: update some code logic and add more unit tests --- handler/buffer_test.go | 3 +++ handler/buffer_wrapper.go | 1 - logger.go | 38 +++++++++++++++++++------------------- logger_test.go | 12 ++++++++++++ processor.go | 27 ++++++++++++++++++--------- processor_test.go | 22 +++++++++++++++++++--- record.go | 7 +++++-- record_test.go | 8 ++++++-- rotatefile/clean_files.go | 22 ++++++++++------------ rotatefile/util.go | 16 ---------------- rotatefile/writer.go | 1 - rotatefile/writer_test.go | 4 ++++ util.go | 2 +- util_test.go | 29 +++++++++++++++++++++++++++++ write.go | 4 +++- 15 files changed, 129 insertions(+), 67 deletions(-) diff --git a/handler/buffer_test.go b/handler/buffer_test.go index f92a89b..06c5d7e 100644 --- a/handler/buffer_test.go +++ b/handler/buffer_test.go @@ -127,6 +127,9 @@ func TestLineBuffWriter(t *testing.T) { h := handler.LineBuffWriter(file, 12, slog.AllLevels) assert.NoErr(t, err) assert.True(t, fsutil.IsFile(logfile)) + assert.Panics(t, func() { + handler.LineBuffWriter(nil, 12, slog.AllLevels) + }) r := newLogRecord("Test LineBuffWriter") err = h.Handle(r) diff --git a/handler/buffer_wrapper.go b/handler/buffer_wrapper.go index 196c9ea..566ff7f 100644 --- a/handler/buffer_wrapper.go +++ b/handler/buffer_wrapper.go @@ -40,7 +40,6 @@ func (w *bufferWrapper) Flush() error { if err := w.buffer.Flush(); err != nil { return err } - return w.handler.Flush() } diff --git a/logger.go b/logger.go index b9a04c0..430d668 100644 --- a/logger.go +++ b/logger.go @@ -2,7 +2,6 @@ package slog import ( "context" - "os" "sync" "time" @@ -78,7 +77,7 @@ func NewWithName(name string, fns ...LoggerFn) *Logger { logger := &Logger{ name: name, // exit handle - ExitFunc: os.Exit, + // ExitFunc: os.Exit, PanicFunc: DefaultPanicFn, exitHandlers: []func(){}, // options @@ -124,7 +123,9 @@ func (l *Logger) Config(fns ...LoggerFn) *Logger { return l } -// Configure current logger +// Configure current logger. +// +// Deprecated: use Config() func (l *Logger) Configure(fn LoggerFn) *Logger { return l.Config(fn) } // FlushDaemon run flush handle on daemon @@ -134,18 +135,21 @@ func (l *Logger) Configure(fn LoggerFn) *Logger { return l.Config(fn) } // go slog.FlushDaemon() func (l *Logger) FlushDaemon() { for range time.NewTicker(flushInterval).C { - err := l.lockAndFlushAll() - printlnStderr("slog: daemon flush logs error: ", err) + if err := l.lockAndFlushAll(); err != nil { + printlnStderr("slog.FlushDaemon: daemon flush logs error: ", err) + } } } // FlushTimeout flush logs on limit time. +// // refer from glog package func (l *Logger) FlushTimeout(timeout time.Duration) { done := make(chan bool, 1) go func() { - err := l.lockAndFlushAll() - printlnStderr("slog: flush logs error: ", err) + if err := l.lockAndFlushAll(); err != nil { + printlnStderr("slog.FlushTimeout: flush logs error: ", err) + } done <- true }() @@ -153,7 +157,7 @@ func (l *Logger) FlushTimeout(timeout time.Duration) { select { case <-done: case <-time.After(timeout): - printlnStderr("slog: flush took longer than timeout:", timeout) + printlnStderr("slog.FlushTimeout: flush took longer than timeout:", timeout) } } @@ -168,8 +172,7 @@ func (l *Logger) Flush() error { return l.lockAndFlushAll() } // MustFlush flush logs. will panic on error func (l *Logger) MustFlush() { - err := l.lockAndFlushAll() - if err != nil { + if err := l.lockAndFlushAll(); err != nil { panic(err) } } @@ -190,10 +193,9 @@ func (l *Logger) lockAndFlushAll() error { // flush all without lock func (l *Logger) flushAll() { - // Flush from fatal down, in case there's trouble flushing. + // flush from fatal down, in case there's trouble flushing. _ = l.VisitAll(func(handler Handler) error { - err := handler.Flush() - if err != nil { + if err := handler.Flush(); err != nil { l.err = err printlnStderr("slog: call handler.Flush() error:", err) } @@ -204,9 +206,8 @@ func (l *Logger) flushAll() { // Close the logger func (l *Logger) Close() error { _ = l.VisitAll(func(handler Handler) error { - // Flush logs and then close - err := handler.Close() - if err != nil { + // flush logs and then close + if err := handler.Close(); err != nil { l.err = err printlnStderr("slog: call handler.Close() error:", err) } @@ -250,10 +251,9 @@ func (l *Logger) Exit(code int) { // global exit handlers runExitHandlers() - if l.ExitFunc == nil { - l.ExitFunc = os.Exit + if l.ExitFunc != nil { + l.ExitFunc(code) } - l.ExitFunc(code) } // SetName for logger diff --git a/logger_test.go b/logger_test.go index 71678a2..3323a12 100644 --- a/logger_test.go +++ b/logger_test.go @@ -177,6 +177,18 @@ func TestLogger_logf_allLevel(t *testing.T) { printfAllLevelLogs(l, "this a log %s", "message") } +func TestLogger_write_error(t *testing.T) { + h := newTestHandler() + h.errOnHandle = true + + l := slog.NewWithHandlers(h) + l.Info("a message") + + err := l.LastErr() + assert.Err(t, err) + assert.Eq(t, "handle error", err.Error()) +} + func newLogger() *slog.Logger { return slog.NewWithConfig(func(l *slog.Logger) { l.ReportCaller = true diff --git a/processor.go b/processor.go index 8434ece..0aac825 100644 --- a/processor.go +++ b/processor.go @@ -29,9 +29,9 @@ func (fn ProcessorFunc) Process(record *Record) { // ProcessableHandler interface type ProcessableHandler interface { - // AddProcessor add an processor + // AddProcessor add a processor AddProcessor(Processor) - // ProcessRecord handle an record + // ProcessRecord handle a record ProcessRecord(record *Record) } @@ -60,7 +60,6 @@ func (p *Processable) ProcessRecord(r *Record) { // AddHostname to record func AddHostname() Processor { hostname, _ := os.Hostname() - return ProcessorFunc(func(record *Record) { record.AddField("hostname", hostname) }) @@ -71,12 +70,7 @@ func AddUniqueID(fieldName string) Processor { hs := md5.New() return ProcessorFunc(func(record *Record) { - rb, err := strutil.RandomBytes(32) - if err != nil { - record.WithError(err) - return - } - + rb, _ := strutil.RandomBytes(32) hs.Write(rb) randomID := hex.EncodeToString(hs.Sum(nil)) hs.Reset() @@ -91,3 +85,18 @@ var MemoryUsage ProcessorFunc = func(record *Record) { runtime.ReadMemStats(stat) record.SetExtraValue("memoryUsage", stat.Alloc) } + +// AppendCtxKeys append context keys to record.Fields +func AppendCtxKeys(keys ...string) Processor { + return ProcessorFunc(func(record *Record) { + if record.Ctx == nil { + return + } + + for _, key := range keys { + if val := record.Ctx.Value(key); val != nil { + record.AddField(key, record.Ctx.Value(key)) + } + } + }) +} diff --git a/processor_test.go b/processor_test.go index 83f946b..d34366b 100644 --- a/processor_test.go +++ b/processor_test.go @@ -1,17 +1,18 @@ package slog_test import ( - "bytes" + "context" "fmt" "os" "testing" + "github.com/gookit/goutil/byteutil" "github.com/gookit/goutil/testutil/assert" "github.com/gookit/slog" ) func TestLogger_AddProcessor(t *testing.T) { - buf := new(bytes.Buffer) + buf := new(byteutil.Buffer) l := slog.NewJSONSugared(buf, slog.InfoLevel) l.AddProcessor(slog.AddHostname()) @@ -43,7 +44,22 @@ func TestLogger_AddProcessor(t *testing.T) { buf.Reset() assert.Contains(t, str, `"message":"message3"`) assert.Contains(t, str, `"requestId":`) - fmt.Println(str) + fmt.Print(str) + + l.ResetProcessors() + l.AddProcessors(slog.AppendCtxKeys("traceId", "userId")) + l.Info("message4") + str = buf.ResetAndGet() + fmt.Print(str) + assert.Contains(t, str, `"message":"message4"`) + assert.NotContains(t, str, `"traceId"`) + + ctx := context.WithValue(context.Background(), "traceId", "traceId123abc456") + l.WithCtx(ctx).Info("message5") + str = buf.ResetAndGet() + fmt.Print(str) + assert.Contains(t, str, `"message":"message5"`) + assert.Contains(t, str, `"traceId":"traceId123abc456"`) } func TestProcessable_AddProcessor(t *testing.T) { diff --git a/record.go b/record.go index f4e8d87..32fdb7f 100644 --- a/record.go +++ b/record.go @@ -79,6 +79,9 @@ func (r *Record) WithTime(t time.Time) *Record { return nr } +// WithCtx on record +func (r *Record) WithCtx(ctx context.Context) *Record { return r.WithContext(ctx) } + // WithContext on record func (r *Record) WithContext(ctx context.Context) *Record { nr := r.Copy() @@ -294,8 +297,8 @@ func (r *Record) SetFields(fields M) *Record { func (r *Record) log(level Level, args []any) { r.Level = level - // will reduce memory allocation once - // r.Message = strutil.Byte2str(formatArgsWithSpaces(args)) + + // r.Message = strutil.Byte2str(formatArgsWithSpaces(args)) // will reduce memory allocation once r.Message = formatArgsWithSpaces(args) // r.logWrite(level) r.logger.writeRecord(level, r) diff --git a/record_test.go b/record_test.go index d674783..6d14722 100644 --- a/record_test.go +++ b/record_test.go @@ -87,6 +87,7 @@ func TestRecord_SetContext(t *testing.T) { w := newBuffer() l := slog.NewWithConfig(func(l *slog.Logger) { l.DoNothingOnPanicFatal() + }).Config(func(l *slog.Logger) { l.CallerFlag = slog.CallerFlagPkg }) l.SetHandlers([]slog.Handler{ @@ -94,8 +95,9 @@ func TestRecord_SetContext(t *testing.T) { }) r := l.Record() - r.SetContext(context.Background()).Info("info message") - r.WithContext(context.Background()).Debug("debug message") + r.SetCtx(context.Background()).Info("info message") + r.WithCtx(context.Background()).Debug("debug message") + s := w.StringReset() fmt.Print(s) assert.Contains(t, s, "github.com/gookit/slog_test") @@ -154,8 +156,10 @@ func TestRecord_AddFields(t *testing.T) { func TestRecord_SetFields(t *testing.T) { r := newLogRecord("AddFields") + r.SetTime(timex.Now().Yesterday().T()) r.SetFields(slog.M{"f1": "hi", "env": "prod"}) assert.NotEmpty(t, r.Fields) + assert.NotEmpty(t, r.Time) } func TestRecord_allLevel(t *testing.T) { diff --git a/rotatefile/clean_files.go b/rotatefile/clean_files.go index 5e45e67..6cdcacb 100644 --- a/rotatefile/clean_files.go +++ b/rotatefile/clean_files.go @@ -3,6 +3,8 @@ package rotatefile import ( "os" "time" + + "github.com/gookit/goutil/fsutil" ) // CConfig struct for clean files @@ -83,16 +85,15 @@ func (r *FilesClear) WithConfigFn(fn func(c *CConfig)) *FilesClear { const flushInterval = 60 * time.Second -// DaemonClean daemon clean old files by config -func (r *FilesClear) DaemonClean() { +// CleanDaemon daemon clean old files by config +func (r *FilesClear) CleanDaemon() { if r.cfg.BackupNum == 0 && r.cfg.BackupTime == 0 { return } for range time.NewTicker(flushInterval).C { - err := r.Clean() - if err != nil { - printErrln("files-clear: clean files error:", err) + if err := r.Clean(); err != nil { + printErrln("files-clear: clean old files error:", err) } } } @@ -129,16 +130,13 @@ func (r *FilesClear) Clean() (err error) { bckNum := int(r.cfg.BackupNum) for _, fileDir := range r.filepathDirs { pattern := fileDir + r.namePattern - - err = r.cleanByBackupNum(pattern, bckNum) - if err != nil { + if err = r.cleanByBackupNum(pattern, bckNum); err != nil { return err } } for _, pattern := range r.filePatterns { - err = r.cleanByBackupNum(pattern, bckNum) - if err != nil { + if err = r.cleanByBackupNum(pattern, bckNum); err != nil { break } } @@ -147,7 +145,7 @@ func (r *FilesClear) Clean() (err error) { func (r *FilesClear) cleanByBackupNum(filePattern string, bckNum int) (err error) { keepNum := 0 - err = globWithFunc(filePattern, func(oldFile string) error { + err = fsutil.GlobWithFunc(filePattern, func(oldFile string) error { stat, err := os.Stat(oldFile) if err != nil { return err @@ -172,7 +170,7 @@ func (r *FilesClear) cleanByBackupTime(filePattern string, cutTime time.Time) (e oldFiles := make([]string, 0, 8) // match all old rotate files. eg: /tmp/error.log.* - err = globWithFunc(filePattern, func(filePath string) error { + err = fsutil.GlobWithFunc(filePattern, func(filePath string) error { stat, err := os.Stat(filePath) if err != nil { return err diff --git a/rotatefile/util.go b/rotatefile/util.go index 9760d87..ff021f6 100644 --- a/rotatefile/util.go +++ b/rotatefile/util.go @@ -4,7 +4,6 @@ import ( "compress/gzip" "io" "os" - "path/filepath" "github.com/gookit/goutil/fsutil" ) @@ -42,21 +41,6 @@ func compressFile(srcPath, dstPath string) error { return zw.Close() } -func globWithFunc(pattern string, fn func(filePath string) error) (err error) { - files, err := filepath.Glob(pattern) - if err != nil { - return err - } - - for _, filePath := range files { - err = fn(filePath) - if err != nil { - break - } - } - return -} - type filterFunc func(fPath string, fi os.FileInfo) bool type handleFunc func(fPath string, fi os.FileInfo) error diff --git a/rotatefile/writer.go b/rotatefile/writer.go index 6c470c3..703f202 100644 --- a/rotatefile/writer.go +++ b/rotatefile/writer.go @@ -218,7 +218,6 @@ func (d *Writer) ReopenFile() error { if d.file != nil { d.file.Close() } - return d.openFile() } diff --git a/rotatefile/writer_test.go b/rotatefile/writer_test.go index 4c4326d..d645649 100644 --- a/rotatefile/writer_test.go +++ b/rotatefile/writer_test.go @@ -38,6 +38,10 @@ func TestNewWriter(t *testing.T) { assert.NoErr(t, w.Sync()) assert.NoErr(t, w.Flush()) assert.NoErr(t, w.Close()) + + w, err = rotatefile.NewWriterWith(rotatefile.WithFilepath(testFile)) + assert.NoErr(t, err) + assert.Eq(t, w.Config().Filepath, testFile) } func TestWriter_Clean(t *testing.T) { diff --git a/util.go b/util.go index 6fb1d9f..d363e06 100644 --- a/util.go +++ b/util.go @@ -108,7 +108,7 @@ func formatArgsWithSpaces(vs []any) string { // TODO replace to byteutil.AppendAny() func appendAny(dst []byte, v any) []byte { if v == nil { - return dst + return append(dst, ""...) } switch val := v.(type) { diff --git a/util_test.go b/util_test.go index f574838..01ad396 100644 --- a/util_test.go +++ b/util_test.go @@ -4,7 +4,9 @@ import ( "strings" "testing" + "github.com/gookit/goutil/errorx" "github.com/gookit/goutil/testutil/assert" + "github.com/gookit/goutil/timex" ) func revertTemplateString(ss []string) string { @@ -41,3 +43,30 @@ func TestInner_parseTemplateToFields(t *testing.T) { assert.Eq(t, testTemplate, str) // dump.P(ss, str) } + +func TestUtil_formatArgsWithSpaces(t *testing.T) { + // tests for formatArgsWithSpaces + tests := []struct { + args []any + want string + }{ + {nil, ""}, + {[]any{"a", "b", "c"}, "a b c"}, + {[]any{"a", "b", "c", 1, 2, 3}, "a b c 1 2 3"}, + {[]any{"a", 1, nil}, "a 1 "}, + {[]any{12, int8(12), int16(12), int32(12), int64(12)}, "12 12 12 12 12"}, + {[]any{uint(12), uint8(12), uint16(12), uint32(12), uint64(12)}, "12 12 12 12 12"}, + {[]any{float32(12.12), 12.12}, "12.12 12.12"}, + {[]any{true, false}, "true false"}, + {[]any{[]byte("abc"), []byte("123")}, "abc 123"}, + {[]any{timex.OneHour}, "1h0m0s"}, + {[]any{errorx.Raw("a error message")}, "a error message"}, + {[]any{[]int{1, 2, 3}}, "[1 2 3]"}, + } + + for _, tt := range tests { + assert.Eq(t, tt.want, formatArgsWithSpaces(tt.args)) + } + + assert.NotEmpty(t, formatArgsWithSpaces([]any{timex.Now()})) +} diff --git a/write.go b/write.go index 8466fd2..6225cc2 100644 --- a/write.go +++ b/write.go @@ -64,13 +64,15 @@ func (l *Logger) writeRecord(level Level, r *Record) { for _, handler := range l.handlers { if handler.IsHandling(level) { if !inited { + // init, call processors r.Init(l.LowerLevelName) r.beforeHandle(l) inited = true } if err := handler.Handle(r); err != nil { - printlnStderr("slog: failed to handle log, error: ", err) + l.err = err + printlnStderr("slog: failed to handle log, error:", err) } } }