Kratos日志库的使用姿势

什么是日志

所谓日志(Log)是指系统所指定对象的某些操作和其操作结果按时间有序的集合。log文件就是日志文件,log文件记录了系统和系统的用户之间交互的信息,是自动捕获人与系统终端之间交互的类型、内容或时间的数据收集方法。

日志是用来记录,用户操作,系统状态,错误信息等等内容的文件,是一个软件系统的重要组成部分。一个良好的日志规范,对于系统运行状态的分析,以及线上问题的解决具有重大的意义。

日志规范

在开发软件打印日志时,需要注意一些问题,举例可能不全,可以自行百度相关文章或查看文章底部文献:

  • 重要功能日志尽可能的完善。
  • 不要随意打印无用的日志,过多无用的日志会增加分析日志的难度。
  • 日志要区分等级 如 debug,warn,info,error 等。
  • 捕获到未处理错误时最好打印错误堆栈信息

Go 语言常用的日志库

Go 语言标准库中就为我们提供了一个日志库 log,除了这个以外还有很多日志库,如 logrusgloglogxUberzap 等等,例如 zap 就有很多的优点:

  • 高性能

  • 配置项丰富

  • 多种日志级别

  • 支持Hook

  • 丰富的工具包

  • 提供了sugar log

  • 多种日志打印格式

  • 简单使用
 1package main
 2
 3import (
 4    "errors"
 5    "go.uber.org/zap"
 6)
 7
 8var logger *zap.Logger
 9
10func init() {
11    logger, _ = zap.NewProduction()
12}
13func main() {
14    logger.Error(
15        "My name is baobao",
16        zap.String("from", "Hulun Buir"),
17        zap.Error(errors.New("no good")))
18
19    logger.Info("Worked in the Ministry of national development of China!",
20        zap.String("key", "eat🍚"),
21        zap.String("key", "sleep😴"))
22    defer logger.Sync()
23}

Kratos 日志库原理解析

在私下与 Tony老师 沟通时关于日志库的实现理念时,Tony老师 说:由于目前日志库非常多并且好用,在 Kratos 的日志中,主要考虑以下几个问题:

  1. 统一日志接口设计
  2. 组织结构化日志
  3. 并且需要有友好的日志级别使用
  4. 支持多输出源对接需求,如log-agent 或者 3rd 日志库

kratos 的日志库,不强制具体实现方式,只提供适配器,用户可以自行实现日志功能,只需要实现kratos/logLogger interface 即可接入自己喜欢的日志系统。

kratos 的日志库,在设计阶段,参考了很多优秀的开源项目和大厂的日志系统实现,经历了多次改动后才呈现给大家。

log库的组成

kratoslog 库主要由以下几个文件组成

  • level.go 定义日志级别

  • log.go 日志核心

  • helper.go loghelper

  • value.go 实现动态值

    源码分析

    kratoslog 库中, 核心部分就是 log.go 代码非常简洁,符合 kratos 的设计理念。 log.go 中声明了 Logger interface,用户只需要实现接口,即可引入自己的日志实现,主要代码如下:

log.go

 1package log
 2
 3import (
 4    "context"
 5    "log"
 6)
 7
 8var (
 9    // DefaultLogger is default logger.
10    DefaultLogger Logger = NewStdLogger(log.Writer())
11)
12
13// Logger 接口, 后面实现自定义日志库的时候,就是要实现这个接口。
14type Logger interface {
15    Log(level Level, keyvals ...interface{}) error
16}
17
18type logger struct {
19    logs      []Logger // logger 数组
20    prefix    []interface{} // 一些默认打印的值,例如通过 With 绑定的 Valuer
21    hasValuer bool // 是否包含 Valuer 
22    ctx       context.Context // 上下文
23}
24
25func (c *logger) Log(level Level, keyvals ...interface{}) error {
26    kvs := make([]interface{}, 0, len(c.prefix)+len(keyvals))
27    kvs = append(kvs, c.prefix...)
28        // 判断是否存在 valuer
29    if c.hasValuer {
30                // 绑定 valuer
31        bindValues(c.ctx, kvs)
32    }
33    kvs = append(kvs, keyvals...)
34        // 遍历 logs,调用所有的 logger 进行日志打印。
35    for _, l := range c.logs {
36        if err := l.Log(level, kvs...); err != nil {
37            return err
38        }
39    }
40    return nil
41}
42
43// With with logger fields.
44func With(l Logger, kv ...interface{}) Logger {
45    // 判断是否能 把传入的 logger 断言成 *logger
46    if c, ok := l.(*logger); ok {
47        // 预分配内存,make了一个空间长度为 c.prefix + keyvals长度的 interface数组
48        kvs := make([]interface{}, 0, len(c.prefix)+len(kv))
49        // 处理打印的内容
50        kvs = append(kvs, kv...)
51        kvs = append(kvs, c.prefix...)
52        // containsValuer()用来判断 kvs 里面是否存在 valuer
53        return &logger{
54            logs:      c.logs,
55            prefix:    kvs,
56            hasValuer: containsValuer(kvs),
57            ctx:       c.ctx,
58        }
59    }
60    return &logger{logs: []Logger{l}, prefix: kv, hasValuer: containsValuer(kv)}
61}
62
63// WithContext 绑定 ctx,注意 ctx 必须非空
64func WithContext(ctx context.Context, l Logger) Logger {
65    if c, ok := l.(*logger); ok {
66        return &logger{
67            logs:      c.logs,
68            prefix:    c.prefix,
69            hasValuer: c.hasValuer,
70            ctx:       ctx,
71        }
72    }
73    return &logger{logs: []Logger{l}, ctx: ctx}
74}
75
76// MultiLogger 包装多个logger,简单说就是同时使用多个logger打印
77func MultiLogger(logs ...Logger) Logger {
78    return &logger{logs: logs}
79}

value.go

 1// 返回 valuer 函数.
 2func Value(ctx context.Context, v interface{}) interface{} {
 3    if v, ok := v.(Valuer); ok {
 4        return v(ctx)
 5    }
 6    return v
 7}
 8
 9// ...省略一些内置的 valuer 实现
10
11// 绑定 valuer
12func bindValues(ctx context.Context, keyvals []interface{}) {
13    for i := 1; i < len(keyvals); i += 2 {
14        if v, ok := keyvals[i].(Valuer); ok {
15            keyvals[i] = v(ctx)
16        }
17    }
18}
19
20// 是否包含 valuer
21func containsValuer(keyvals []interface{}) bool {
22    for i := 1; i < len(keyvals); i += 2 {
23        if _, ok := keyvals[i].(Valuer); ok {
24            return true
25        }
26    }
27    return false
28}

helper.go

 1package log
 2
 3import (
 4    "context"
 5    "fmt"
 6)
 7
 8// Helper is a logger helper.
 9type Helper struct {
10    logger Logger
11}
12
13// 创建一个 logger helper 实例
14func NewHelper(logger Logger) *Helper {
15    return &Helper{
16        logger: logger,
17    }
18}
19
20// 通过 WithContext() 返回包含 ctx 的一个日志的帮助类,包含一些定义好的按级别打印日志的方法
21func (h *Helper) WithContext(ctx context.Context) *Helper {
22    return &Helper{
23        logger: WithContext(ctx, h.logger),
24    }
25}
26
27func (h *Helper) Log(level Level, keyvals ...interface{}) {
28    h.logger.Log(level, keyvals...)
29}
30
31func (h *Helper) Debug(a ...interface{}) {
32    h.logger.Log(LevelDebug, "msg", fmt.Sprint(a...))
33}
34
35func (h *Helper) Debugf(format string, a ...interface{}) {
36    h.logger.Log(LevelDebug, "msg", fmt.Sprintf(format, a...))
37}
38
39// ...省略一些重复的方法

通过单元测试了解调用逻辑

1func TestInfo(t *testing.T) {
2    logger := DefaultLogger
3    logger = With(logger, "ts", DefaultTimestamp, "caller", DefaultCaller)
4    logger.Log(LevelInfo, "key1", "value1")
5}
  1. 单测中首先声明了一个 logger ,用的默认的 DefaultLogger

  2. 调用 log.go 中的 With() 函数, 传入了 logger ,和两个动态值, DefaultTimestampDefaultCaller

  3. With方法被调用,判断是否能将参数 l 类型转换成 *logger

  4. 如果可以转换,将传入的KV,赋值给 logger.prefix 上,然后调用 value.go 中的 containsValuer() 判断传入的KV中是否存在 Valuer类型的值,将结果赋值给 context.hasValuer,最后返回 Logger 对象

  5. 否则则直接返回一个 &logger{logs: []Logger{l}, prefix: kv, hasValuer: containsValuer(kv)}

  6. 然后打印日志时,logger structLog 方法被调用

  7. Log() 方法首先预分配了 keyvals 的空间,然后判断 hasValuer,如果为 true,则调用 valuer.go 中的 bindValuer() 并传入了 ctx 然后获取 valuer 的值`if v, ok := v.(Valuer); ok {

     return v()
    

    }`

8.最后遍历 logger.logs 打印日志

使用方法

使用 Logger 打印日志

1logger := log.DefaultLogger
2logger.Log(LevelInfo, "key1", "value1")

使用 Helper 打印日志

1log := log.NewHelper(DefaultLogger)
2log.Debug("test debug")
3log.Info("test info")
4log.Warn("test warn")
5log.Error("test error")

使用 valuer

1logger := DefaultLogger
2logger = With(logger, "ts", DefaultTimestamp, "caller", DefaultCaller)
3logger.Log(LevelInfo, "msg", "helloworld")

同时打印多个 logger

1out := log.NewStdLogger(os.Stdout)
2err := log.NewStdLogger(os.Stderr)
3l := log.With(MultiLogger(out, err))
4l.Log(LevelInfo, "msg", "test")

使用 context

1logger := log.With(NewStdLogger(os.Stdout),
2    "trace", Trace(),
3)
4log := log.NewHelper(logger)
5ctx := context.WithValue(context.Background(), "trace_id", "2233")
6log.WithContext(ctx).Info("got trace!")

使用 filter 过滤日志

如果需要过滤日志中某些不应该被打印明文的字段如 password 等,可以通过 log.NewFilter() 来实现过滤功能。

通过 level 过滤日志

1l := log.NewHelper(log.NewFilter(log.DefaultLogger, log.FilterLevel(log.LevelWarn)))
2l.Log(LevelDebug, "msg1", "te1st debug")
3l.Debug("test debug")
4l.Debugf("test %s", "debug")
5l.Debugw("log", "test debug")
6l.Warn("warn log")

通过 key 过滤日志

1l := log.NewHelper(log.NewFilter(log.DefaultLogger, log.FilterKey("password")))
2l.Debugw("password", "123456")
通过 value 过滤日志
1l := log.NewHelper(log.NewFilter(log.DefaultLogger, log.FilterValue("kratos")))
2l.Debugw("name", "kratos")

通过 hook func 过滤日志

 1l := log.NewHelper(log.NewFilter(log.DefaultLogger, log.FilterFunc(testFilterFunc)))
 2l.Debug("debug level")
 3l.Infow("password", "123456")
 4func testFilterFunc(level Level, keyvals ...interface{}) bool {
 5    if level == LevelWarn {
 6        return true
 7    }
 8    for i := 0; i < len(keyvals); i++ {
 9        if keyvals[i] == "password" {
10            keyvals[i+1] = "***"
11        }
12    }
13    return false
14}

用 Zap 实现 kratos 的日志接口

实现的代码十分简单,仅有不到100 行代码,仅供大家参考。

实现

 1// kratos/examples/log/zap.go
 2package logger
 3
 4import (
 5    "fmt"
 6        "os"
 7
 8    "github.com/go-kratos/kratos/v2/log"
 9    "go.uber.org/zap"
10    "go.uber.org/zap/zapcore"
11    "gopkg.in/natefinch/lumberjack.v2"
12)
13
14var _ log.Logger = (*ZapLogger)(nil)
15
16// Zap 结构体
17type ZapLogger struct {
18    log  *zap.Logger
19    Sync func() error
20}
21
22// 创建一个 ZapLogger 实例
23func NewZapLogger(encoder zapcore.EncoderConfig, level zap.AtomicLevel, opts ...zap.Option) *ZapLogger {
24    writeSyncer := getLogWriter()
25    // 设置 zapcore
26    core := zapcore.NewCore(
27        zapcore.NewConsoleEncoder(encoder),
28        zapcore.NewMultiWriteSyncer(
29            zapcore.AddSync(os.Stdout),
30        ), level)
31    //  new 一个 *zap.Logger
32    zapLogger := zap.New(core, opts...)
33    return &ZapLogger{log: zapLogger, Sync: zapLogger.Sync}
34}
35
36// Log 方法实现了 kratos/log/log.go 中的 Logger interface
37func (l *ZapLogger) Log(level log.Level, keyvals ...interface{}) error {
38    if len(keyvals) == 0 || len(keyvals)%2 != 0{
39            l.log.Warn(fmt.Sprint("Keyvalues must appear in pairs: ", keyvals))
40        return nil
41    }
42    // 按照 KV 传入的时候,使用的 zap.Field
43    var data []zap.Field
44    for i := 0; i < len(keyvals); i += 2 {
45        data = append(data, zap.Any(fmt.Sprint(keyvals[i]), fmt.Sprint(keyvals[i+1])))
46    }
47    switch level {
48    case log.LevelDebug:
49        l.log.Debug("", data...)
50    case log.LevelInfo:
51        l.log.Info("", data...)
52    case log.LevelWarn:
53        l.log.Warn("", data...)
54    case log.LevelError:
55        l.log.Error("", data...)
56    }
57    return nil
58}
59
60// 日志自动切割,采用 lumberjack 实现的
61func getLogWriter() zapcore.WriteSyncer {
62    lumberJackLogger := &lumberjack.Logger{
63        Filename:   "./test.log",
64        MaxSize:    10,
65        MaxBackups: 5,
66        MaxAge:     30,
67        Compress:   false,
68    }
69    return zapcore.AddSync(lumberJackLogger)
70}

使用方法

 1// kratos/examples/log/zap_test.go
 2package logger
 3
 4import (
 5    "testing"
 6
 7    "github.com/go-kratos/kratos/v2/log"
 8    "go.uber.org/zap"
 9    "go.uber.org/zap/zapcore"
10)
11
12func TestZapLogger(t *testing.T) {
13    encoder := zapcore.EncoderConfig{
14        TimeKey:        "t",
15        LevelKey:       "level",
16        NameKey:        "logger",
17        CallerKey:      "caller",
18        MessageKey:     "msg",
19        StacktraceKey:  "stack",
20        EncodeTime:     zapcore.ISO8601TimeEncoder,
21        LineEnding:     zapcore.DefaultLineEnding,
22        EncodeLevel:    zapcore.LowercaseLevelEncoder,
23        EncodeDuration: zapcore.SecondsDurationEncoder,
24        EncodeCaller:   zapcore.FullCallerEncoder,
25    }
26    logger := NewZapLogger(
27        encoder,
28        zap.NewAtomicLevelAt(zapcore.DebugLevel),
29        zap.AddStacktrace(
30            zap.NewAtomicLevelAt(zapcore.ErrorLevel)),
31        zap.AddCallerSkip(2),
32        zap.Development(),
33    )
34    zlog := log.NewHelper(logger)
35    zlog.Infow("name","go 语言进阶")
36    defer logger.Sync()
37}

参考文献