Kratos源码-Logging

提示：文章写完后，目录可以自动生成，如何生成可参考右边的帮助文档

---

前言

提示：这里可以添加本文要记录的大概内容：

例如：随着人工智能的不断发展，机器学习这门技术也越来越重要，很多人都开启了学习机器学习，本文就介绍了机器学习的基础内容。

---

提示：以下是本篇文章正文内容，下面案例可供参考

一、log初始化

上代码：

func main() {
	flag.Parse()
	logger := log.With(log.NewStdLogger(os.Stdout),
		"ts", log.DefaultTimestamp,
		"caller", log.DefaultCaller,
		"service.id", id,
		"service.name", Name,
		"service.version", Version,
		"trace.id", tracing.TraceID(),
		"span.id", tracing.SpanID(),
	)
	c := config.New(
		config.WithSource(
			file.NewSource(flagconf),
		),
	)
	defer c.Close()

	if err := c.Load(); err != nil {
		panic(err)
	}

	var bc conf.Bootstrap
	if err := c.Scan(&bc); err != nil {
		panic(err)
	}

	app, cleanup, err := wireApp(bc.Server, bc.Data, logger)
	if err != nil {
		panic(err)
	}
	defer cleanup()

	// start and wait for stop signal
	if err := app.Run(); err != nil {
		panic(err)
	}
}

这是利用Kratos自动生成的项目中的main方法。
这里我们追踪两个方法：With、NewStdLogger。

首先看一下接口和结构体：

// Logger is a logger interface.
type Logger interface {
	Log(level Level, keyvals ...interface{}) error
}

type logger struct {
	logger    Logger
	prefix    []interface{}
	hasValuer bool
	ctx       context.Context
}

Kratos的接口设计的原则是：越少暴露方法，后期适配具体框架需要改动的越少。
本质上就是低耦合的思想。

NewStdLogger创建了一个stdLogger的实例，stdLogger实现了Logger接口的Log方法，所以stdLogger的实例可以作为Logger接口的实现来返回。

type stdLogger struct {
	log  *log.Logger // 这是标准库中的Logger
	pool *sync.Pool
}

// NewStdLogger new a logger with writer.
func NewStdLogger(w io.Writer) Logger {
	return &stdLogger{
		log: log.New(w, "", 0),
		pool: &sync.Pool{
			New: func() interface{} {
				return new(bytes.Buffer)
			},
		},
	}
}

其中log.New是go标准库中的方法，如下。

// A Logger represents an active logging object that generates lines of
// output to an io.Writer. Each logging operation makes a single call to
// the Writer's Write method. A Logger can be used simultaneously from
// multiple goroutines; it guarantees to serialize access to the Writer.
type Logger struct {
	mu        sync.Mutex  // ensures atomic writes; protects the following fields
	prefix    string      // prefix on each line to identify the logger (but see Lmsgprefix)
	flag      int         // properties
	out       io.Writer   // destination for output
	buf       []byte      // for accumulating text to write
	isDiscard atomic.Bool // whether out == io.Discard
}
// New creates a new Logger. The out variable sets the
// destination to which log data will be written.
// The prefix appears at the beginning of each generated log line, or
// after the log header if the Lmsgprefix flag is provided.
// The flag argument defines the logging properties.
func New(out io.Writer, prefix string, flag int) *Logger {
	l := &Logger{out: out, prefix: prefix, flag: flag}
	if out == io.Discard {
		l.isDiscard.Store(true)
	}
	return l
}

With方法，接受一个Logger，经过封装，再返回一个Logger。

// With with logger fields.
func With(l Logger, kv ...interface{}) Logger {
	c, ok := l.(*logger)
	if !ok {
		return &logger{logger: l, prefix: kv, hasValuer: containsValuer(kv), ctx: context.Background()}
	}
	kvs := make([]interface{}, 0, len(c.prefix)+len(kv))
	kvs = append(kvs, c.prefix...)
	kvs = append(kvs, kv...)
	return &logger{
		logger:    c.logger,
		prefix:    kvs,
		hasValuer: containsValuer(kvs),
		ctx:       c.ctx,
	}
}

到这一步，我们可以把logger理解成一个大logger套小logger的俄罗斯套娃，那么我们再回来看看，接口中的唯一一个方法怎么实现的。

func (c *logger) Log(level Level, keyvals ...interface{}) error {
	kvs := make([]interface{}, 0, len(c.prefix)+len(keyvals))
	kvs = append(kvs, c.prefix...)
	if c.hasValuer {
		bindValues(c.ctx, kvs)
	}
	kvs = append(kvs, keyvals...)
	return c.logger.Log(level, kvs...)
}

logger经过一些预处理，调用子logger的Log，所以如开头的代码所示，最终会调用到stdLogger的Log实现，上代码：

// Log print the kv pairs log.
func (l *stdLogger) Log(level Level, keyvals ...interface{}) error {
	if len(keyvals) == 0 {
		return nil
	}
	if (len(keyvals) & 1) == 1 {
		keyvals = append(keyvals, "KEYVALS UNPAIRED")
	}
	buf := l.pool.Get().(*bytes.Buffer)
	buf.WriteString(level.String())
	for i := 0; i < len(keyvals); i += 2 {
		_, _ = fmt.Fprintf(buf, " %s=%v", keyvals[i], keyvals[i+1])
	}
	_ = l.log.Output(4, buf.String()) //nolint:gomnd
	buf.Reset()
	l.pool.Put(buf)
	return nil
}

到这里就好理解了，经过层层调用，进入了go标准库的go/src/log/log.go的Output方法。

_ = l.log.Output(4, buf.String()) //nolint:gomnd 不要做魔法数检查，4表示调用深度

二、log的调用

1.logger注入

上一节有一行代码：

app, cleanup, err := wireApp(bc.Server, bc.Data, logger)

这行代码完成了app的初始化，并将之前生成的logger注入其中。这里用了wire实现了依赖注入，如果是Java转过来，可能更容易理解，但是不管是否理解依赖注入，反正，我们知道，后续的logger是上一步生成的就可以了。

2.引入Helper

// GreeterUsecase is a Greeter usecase.
type GreeterUsecase struct {
	repo GreeterRepo
	log  *log.Helper
}

// NewGreeterUsecase new a Greeter usecase.
func NewGreeterUsecase(repo GreeterRepo, logger log.Logger) *GreeterUsecase {
	return &GreeterUsecase{repo: repo, log: log.NewHelper(logger)}
}

// CreateGreeter creates a Greeter, and returns the new Greeter.
func (uc *GreeterUsecase) CreateGreeter(ctx context.Context, g *Greeter) (*Greeter, error) {
	uc.log.WithContext(ctx).Infof("CreateGreeter: %v", g.Hello)
	return uc.repo.Save(ctx, g)
}

经过连续的注入，这一步进入了HTTP的handler中，首先看到NewGreeterUsecase方法通过NewHelper方法，将logger转成了log.Helper。

// Helper is a logger helper.
type Helper struct {
	logger  Logger
	msgKey  string
	sprint  func(...interface{}) string
	sprintf func(format string, a ...interface{}) string
}

进一步，CreateGreeter方法在打印日志时，调用Helper的WithContext方法，获取了一个带有Context的Helper。
代码如下：

// WithContext returns a shallow copy of h with its context changed
// to ctx. The provided ctx must be non-nil.
func (h *Helper) WithContext(ctx context.Context) *Helper {
	return &Helper{
		msgKey:  h.msgKey,
		logger:  WithContext(ctx, h.logger),
		sprint:  h.sprint,
		sprintf: h.sprintf,
	}
}

Infof方法，也是Helper结构体的方法，由于Helper还实现了Log方法，所以Helper也是Logger接口的一个实现，所以h.logger.Log会经过一系列调用最终变成调用go标准库的go/src/log/log.go的Output方法。注意，这里所说的是在这个示例程序，由于开始的时候调用NewStdLogger创建了标准logger，很容易想到，如果我们最初的log.With中传入的是三方库的接口，那么这里是不是就是别的实现了。

现在我们思考一个问题，Kratos源码-Java中的日志框架一文中我们看过Java的两种主流日志门面，那么Kratos的日志更接近哪一种呢？下一节我们继续分析。

// Log Print log by level and keyvals.
func (h *Helper) Log(level Level, keyvals ...interface{}) {
	_ = h.logger.Log(level, keyvals...)
}
// Infof logs a message at info level.
func (h *Helper) Infof(format string, a ...interface{}) {
	_ = h.logger.Log(LevelInfo, h.msgKey, h.sprintf(format, a...))
}

三、集成三方框架

适配实现 我们已经在contrib/log实现好了一些插件，用于适配目前常用的日志库，您也可以参考它们的代码来实现自己需要的日志库的适配：

std 标准输出，Kratos内置 fluent 输出到fluentd zap 适配了uber的zap日志库 aliyun 输出到阿里云日志

下面我们分析一下zap的实现吧。
先看使用：

func TestLogger(t *testing.T) {
	syncer := &testWriteSyncer{}
	encoderCfg := zapcore.EncoderConfig{
		MessageKey:     "msg",
		LevelKey:       "level",
		NameKey:        "logger",
		EncodeLevel:    zapcore.LowercaseLevelEncoder,
		EncodeTime:     zapcore.ISO8601TimeEncoder,
		EncodeDuration: zapcore.StringDurationEncoder,
	}
	core := zapcore.NewCore(zapcore.NewJSONEncoder(encoderCfg), syncer, zap.DebugLevel)
	zlogger := zap.New(core).WithOptions()
	logger := NewLogger(zlogger)

	defer func() { _ = logger.Close() }()

	zlog := log.NewHelper(logger)

	zlog.Debugw("log", "debug")
	zlog.Infow("log", "info")
	zlog.Warnw("log", "warn")
	zlog.Errorw("log", "error")
	zlog.Errorw("log", "error", "except warn")

	except := []string{
		"{\"level\":\"debug\",\"msg\":\"\",\"log\":\"debug\"}\n",
		"{\"level\":\"info\",\"msg\":\"\",\"log\":\"info\"}\n",
		"{\"level\":\"warn\",\"msg\":\"\",\"log\":\"warn\"}\n",
		"{\"level\":\"error\",\"msg\":\"\",\"log\":\"error\"}\n",
		"{\"level\":\"warn\",\"msg\":\"Keyvalues must appear in pairs: [log error except warn]\"}\n",
	}
	for i, s := range except {
		if s != syncer.output[i] {
			t.Logf("except=%s, got=%s", s, syncer.output[i])
			t.Fail()
		}
	}
}

其中可以看到熟悉的影子，NewLogger生成logger，NewHelper把logger封装成Helper。
马上我们可以想到，如果zap.Logger必然实现了Logger接口中的Log方法，上代码：

func (l *Logger) Log(level log.Level, keyvals ...interface{}) error {
	keylen := len(keyvals)
	if keylen == 0 || keylen%2 != 0 {
		l.log.Warn(fmt.Sprint("Keyvalues must appear in pairs: ", keyvals))
		return nil
	}

	data := make([]zap.Field, 0, (keylen/2)+1)
	for i := 0; i < keylen; i += 2 {
		data = append(data, zap.Any(fmt.Sprint(keyvals[i]), keyvals[i+1]))
	}

	switch level {
	case log.LevelDebug:
		l.log.Debug("", data...)
	case log.LevelInfo:
		l.log.Info("", data...)
	case log.LevelWarn:
		l.log.Warn("", data...)
	case log.LevelError:
		l.log.Error("", data...)
	case log.LevelFatal:
		l.log.Fatal("", data...)
	}
	return nil
}

到这里就清楚了，Log方法通过level决定了走zap.log的具体分支，也就是Debug、Info、Warn、Error、Fatal。

---

总结

到此，Kratos源码的Logging部分就分析完了。最后，插个题外话吧。打印日志应该遵循什么原则。

三要：

• HTTP、RPC的入参和返回值
• 程序异常原因
• 特殊条件分支

五不要

• 避免大量数据
• 避免循环
• 避免无意义
• 避免什么也说明不了
• 避免私密

好的日志包括什么：
级别-内容-时间-进程名称-类方法名-行号-异常堆栈