diff --git a/log/README.md b/log/README.md index 80758192e..eefa9b78b 100644 --- a/log/README.md +++ b/log/README.md @@ -5,11 +5,13 @@ ### Structured logging ``` -logger := stdlog.NewLogger(stdlog.Writer(os.Stdout)) -log := log.NewHelper("module_name", logger) +logger := log.NewLogger(os.Stdout) +logger = With(logger, "key", "value") + +log := log.NewHelper("github.com/project/foo", logger) // Levels -log.Info("some log") -log.Infof("format %s", "some log") -log.Infow("field_name", "some log") +log.Info("hello") +log.Infof("hello %s", "kratos") +log.Infow("key", "value") ``` diff --git a/log/helper.go b/log/helper.go index 3049d515f..ee7e867b4 100644 --- a/log/helper.go +++ b/log/helper.go @@ -34,8 +34,8 @@ func (h *Helper) Debugf(format string, a ...interface{}) { } // Debugw logs a message at debug level. -func (h *Helper) Debugw(kvpair ...interface{}) { - h.debug.Print(kvpair...) +func (h *Helper) Debugw(pairs ...interface{}) { + h.debug.Print(pairs...) } // Info logs a message at info level. @@ -49,8 +49,8 @@ func (h *Helper) Infof(format string, a ...interface{}) { } // Infow logs a message at info level. -func (h *Helper) Infow(kvpair ...interface{}) { - h.info.Print(kvpair...) +func (h *Helper) Infow(pairs ...interface{}) { + h.info.Print(pairs...) } // Warn logs a message at warn level. @@ -64,8 +64,8 @@ func (h *Helper) Warnf(format string, a ...interface{}) { } // Warnw logs a message at warnf level. -func (h *Helper) Warnw(kvpair ...interface{}) { - h.warn.Print(kvpair...) +func (h *Helper) Warnw(pairs ...interface{}) { + h.warn.Print(pairs...) } // Error logs a message at error level. @@ -79,6 +79,6 @@ func (h *Helper) Errorf(format string, a ...interface{}) { } // Errorw logs a message at error level. -func (h *Helper) Errorw(kvpair ...interface{}) { - h.err.Print(kvpair...) +func (h *Helper) Errorw(pairs ...interface{}) { + h.err.Print(pairs...) } diff --git a/log/helper_test.go b/log/helper_test.go index 51c45ad41..4e12bb5e8 100644 --- a/log/helper_test.go +++ b/log/helper_test.go @@ -1,11 +1,14 @@ package log import ( + "io/ioutil" "testing" ) func TestHelper(t *testing.T) { - log := NewHelper("test", DefaultLogger) + logger := With(DefaultLogger, "caller", Caller(5)) + log := NewHelper("test", logger) + log.Debug("test debug") log.Debugf("test %s", "debug") log.Debugw("log", "test debug") @@ -18,3 +21,24 @@ func TestHelperLevel(t *testing.T) { log.Warn("test warn") log.Error("test error") } + +func BenchmarkHelperPrint(b *testing.B) { + log := NewHelper("test", NewStdLogger(ioutil.Discard)) + for i := 0; i < b.N; i++ { + log.Debug("test") + } +} + +func BenchmarkHelperPrintf(b *testing.B) { + log := NewHelper("test", NewStdLogger(ioutil.Discard)) + for i := 0; i < b.N; i++ { + log.Debugf("%s", "test") + } +} + +func BenchmarkHelperPrintw(b *testing.B) { + log := NewHelper("test", NewStdLogger(ioutil.Discard)) + for i := 0; i < b.N; i++ { + log.Debugw("key", "value") + } +} diff --git a/log/level.go b/log/level.go index dcd26fef9..94b32e632 100644 --- a/log/level.go +++ b/log/level.go @@ -3,6 +3,9 @@ package log // Level is a logger level. type Level int8 +// LevelKey is logger level key. +const LevelKey = "level" + const ( // LevelDebug is logger debug level. LevelDebug Level = iota @@ -14,11 +17,6 @@ const ( LevelError ) -const ( - // LevelKey is logger level key. - LevelKey = "level" -) - // Enabled compare whether the logging level is enabled. func (l Level) Enabled(lv Level) bool { return lv >= l diff --git a/log/log.go b/log/log.go index 8a89c7e6f..1cebf5abb 100644 --- a/log/log.go +++ b/log/log.go @@ -1,10 +1,12 @@ package log -import "os" +import ( + "log" +) var ( // DefaultLogger is default logger. - DefaultLogger Logger = NewStdLogger(os.Stderr) + DefaultLogger Logger = NewStdLogger(log.Writer()) ) // Logger is a logger interface. @@ -12,21 +14,37 @@ type Logger interface { Print(pairs ...interface{}) } -type logger struct { - log Logger - pairs []interface{} +type context struct { + logs []Logger + prefix []interface{} } -func (l *logger) Print(pairs ...interface{}) { - l.log.Print(append(pairs, l.pairs...)...) -} - -// With with logger kv pairs. -func With(log Logger, pairs ...interface{}) Logger { - if len(pairs) == 0 { - return log +func (c *context) Print(a ...interface{}) { + kvs := make([]interface{}, 0, len(c.prefix)+len(a)) + kvs = append(kvs, c.prefix...) + kvs = append(kvs, a...) + for _, log := range c.logs { + log.Print(kvs...) } - return &logger{log: log, pairs: pairs} +} + +// With with logger fields. +func With(l Logger, a ...interface{}) Logger { + if c, ok := l.(*context); ok { + kvs := make([]interface{}, 0, len(c.prefix)+len(a)) + kvs = append(kvs, a...) + kvs = append(kvs, c.prefix...) + return &context{ + logs: c.logs, + prefix: kvs, + } + } + return &context{logs: []Logger{l}, prefix: a} +} + +// Wrap wraps multi logger. +func Wrap(logs ...Logger) Logger { + return &context{logs: logs} } // Debug returns a debug logger. diff --git a/log/log_test.go b/log/log_test.go index 48cc60840..8885a861e 100644 --- a/log/log_test.go +++ b/log/log_test.go @@ -1,6 +1,7 @@ package log import ( + "os" "testing" ) @@ -11,3 +12,11 @@ func TestLogger(t *testing.T) { Warn(logger).Print("log", "test warn") Error(logger).Print("log", "test error") } + +func TestWrapper(t *testing.T) { + out := NewStdLogger(os.Stdout) + err := NewStdLogger(os.Stderr) + + l := Wrap(out, err) + l.Print("message", "test") +} diff --git a/log/std.go b/log/std.go index 6f742092b..38f2b0715 100644 --- a/log/std.go +++ b/log/std.go @@ -28,18 +28,18 @@ func NewStdLogger(w io.Writer) Logger { } // Print print the kv pairs log. -func (s *stdLogger) Print(kvpair ...interface{}) { - if len(kvpair) == 0 { +func (l *stdLogger) Print(pairs ...interface{}) { + if len(pairs) == 0 { return } - if len(kvpair)%2 != 0 { - kvpair = append(kvpair, "") + if len(pairs)%2 != 0 { + pairs = append(pairs, "") } - buf := s.pool.Get().(*bytes.Buffer) - for i := 0; i < len(kvpair); i += 2 { - fmt.Fprintf(buf, "%s=%v ", kvpair[i], kvpair[i+1]) + buf := l.pool.Get().(*bytes.Buffer) + for i := 0; i < len(pairs); i += 2 { + fmt.Fprintf(buf, "%s=%v ", pairs[i], Value(pairs[i+1])) } - s.log.Println(buf.String()) + l.log.Output(4, buf.String()) buf.Reset() - s.pool.Put(buf) + l.pool.Put(buf) } diff --git a/log/std_test.go b/log/std_test.go index 2cca13941..e76259b5a 100644 --- a/log/std_test.go +++ b/log/std_test.go @@ -2,7 +2,7 @@ package log import "testing" -func TestFmtLogger(t *testing.T) { +func TestStdLogger(t *testing.T) { logger := DefaultLogger Debug(logger).Print("log", "test debug") diff --git a/log/value.go b/log/value.go new file mode 100644 index 000000000..b43f6347e --- /dev/null +++ b/log/value.go @@ -0,0 +1,30 @@ +package log + +import ( + "runtime" + "strconv" + "strings" +) + +// Valuer is returns a log value. +type Valuer func() interface{} + +// Value return the function value. +func Value(v interface{}) interface{} { + if v, ok := v.(Valuer); ok { + return v() + } + return v +} + +// Caller returns returns a Valuer that returns a pkg/file:line description of the caller. +func Caller(depth int) Valuer { + return func() interface{} { + _, file, line, ok := runtime.Caller(depth) + if !ok { + return nil + } + idx := strings.LastIndexByte(file, '/') + return file[idx+1:] + ":" + strconv.Itoa(line) + } +} diff --git a/log/value_test.go b/log/value_test.go new file mode 100644 index 000000000..ed00bfcef --- /dev/null +++ b/log/value_test.go @@ -0,0 +1,8 @@ +package log + +import "testing" + +func TestValue(t *testing.T) { + logger := With(DefaultLogger, "caller", Caller(4)) + logger.Print("message", "helloworld") +} diff --git a/log/wrapper.go b/log/wrapper.go deleted file mode 100644 index 0330a853d..000000000 --- a/log/wrapper.go +++ /dev/null @@ -1,14 +0,0 @@ -package log - -type wrapper []Logger - -func (w wrapper) Print(pairs ...interface{}) { - for _, p := range w { - p.Print(pairs...) - } -} - -// Wrap wraps multi logger. -func Wrap(l ...Logger) Logger { - return wrapper(l) -} diff --git a/log/wrapper_test.go b/log/wrapper_test.go deleted file mode 100644 index e3652eb8a..000000000 --- a/log/wrapper_test.go +++ /dev/null @@ -1,14 +0,0 @@ -package log - -import ( - "os" - "testing" -) - -func TestWrapper(t *testing.T) { - out := NewStdLogger(os.Stdout) - err := NewStdLogger(os.Stderr) - - l := Wrap(out, err) - l.Print("message", "test") -}