基于Zap Context实现日志服务链路追踪

由于在Golang severs中，每个request都是在单个goroutine中完成，并且在这个goroutine中还会有启动新goroutine执行其它任务的应用场景，即一个request中通常包含多个goroutine，这些goroutine之间通常会有交互。

如果我们想对每个请求的调用链路进行跟踪时，就需要借助golang的context包来实现，再配合uber/zap,那么构建ELK将会变得很轻松便捷。

为了保证代码简明易读，文章开始会以gin+zap实现， 结尾会附上net/http+zap的实现代码

1. 初始化zap服务并定义日志上下文方法

package zlog

import (
	"github.com/gin-gonic/gin"
	"go.uber.org/zap"
	"go.uber.org/zap/zapcore"
	"strconv"
)

const loggerKey = iota

var Logger *zap.Logger

// 初始化日志配置

func init() {
	level := zap.DebugLevel
	core := zapcore.NewCore(
		zapcore.NewJSONEncoder(zap.NewProductionEncoderConfig()), // json格式日志（ELK渲染收集）
		zapcore.NewMultiWriteSyncer(zapcore.AddSync(os.Stdout)),  // 打印到控制台和文件
		level,                                                    // 日志级别
	)

	// 开启文件及行号
	development := zap.Development()
	Logger = zap.New(core,
		zap.AddCaller(),
		zap.AddStacktrace(zap.ErrorLevel),	// error级别日志，打印堆栈
		development)
}

// 给指定的context添加字段（关键方法）
func NewContext(ctx *gin.Context, fields ...zapcore.Field) {
	ctx.Set(strconv.Itoa(loggerKey), WithContext(ctx).With(fields...))
}

// 从指定的context返回一个zap实例（关键方法）
func WithContext(ctx *gin.Context) *zap.Logger {
	if ctx == nil {
		return Logger
	}
	l, _ := ctx.Get(strconv.Itoa(loggerKey))
	ctxLogger, ok := l.(*zap.Logger)
	if ok {
		return ctxLogger
	}
	return Logger
}

2. 定义gin中间件，添加关键日志字段

通过中间件，我们可以方便的为每个request添加日志上下文关键字段，我这儿只添加了traceId和一些请求信息字段，我们还可以根据应用场景添加其它自定义字段。

func traceLoggerMiddleware() gin.HandlerFunc {
	return func(ctx *gin.Context) {
	    // 每个请求生成的请求traceId具有全局唯一性
		u1, _ := uuid.NewV4()
		traceId := u1.String()
		zlog.NewContext(ctx, zap.String("traceId", traceId))
		
		// 为日志添加请求的地址以及请求参数等信息
		zlog.NewContext(ctx, zap.String("request.method", ctx.Request.Method))
		headers, _ := json.Marshal(ctx.Request.Header)
		zlog.NewContext(ctx, zap.String("request.headers", string(headers)))
		zlog.NewContext(ctx, zap.String("request.url", ctx.Request.URL.String()))
		
		// 将请求参数json序列化后添加进日志上下文
		if ctx.Request.Form == nil {
			ctx.Request.ParseMultipartForm(32 << 20)
		}
		form, _ := json.Marshal(ctx.Request.Form)
		zlog.NewContext(ctx, zap.String("request.params", string(form)))
		
		ctx.Next()
	}
}

3. 测试日志输出

package test

import (
    "zlog"
	"github.com/gin-gonic/gin"
	"go.uber.org/zap"
)

type Test struct {
}

func (t Test) Test1(ctx *gin.Context) {
	name := ctx.Query("name")
	// 注意打印日志都需要通过WithContext(ctx)来获得zapLogger
	
	zlog.WithContext(ctx).Debug("测试日志", zap.String("name", name))
}

最后输出日志如下，由于输出的是json编码日志，直接阅读会感觉很乱，但搭配ELK后味道很赞

{"level":"debug","ts":1557482212.408422,"caller":"test/test.go:17","msg":"测试日志","trace":"9fd2d1ce6fbd345c17f6b09f5dd3e750","request.method":"GET","request.headers":"{\"Accept\":[\"text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3\"],\"Accept-Encoding\":[\"gzip, deflate, br\"],\"Accept-Language\":[\"zh-CN,zh;q=0.9\"],\"Cache-Control\":[\"max-age=0\"],\"Connection\":[\"keep-alive\"],\"Upgrade-Insecure-Requests\":[\"1\"],\"User-Agent\":[\"Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/73.0.3683.86 Safari/537.36\"]}","request.url":"/t","request.params":"{}","name":""}

附：http原生包+zap实现代码

package zlog

import (
	"context"
	"go.uber.org/zap"
	"go.uber.org/zap/zapcore"
)

const loggerKey = iota

var Logger *zap.Logger

func init() {
	config := zap.NewProductionConfig()
	l, err := config.Build(
		zap.AddCaller(),
		zap.AddStacktrace(zap.ErrorLevel),
	)
	if err != nil {
		panic(err)
	}
	Logger = l
}

// 给指定的context添加字段
func NewContext(ctx context.Context, fields ...zapcore.Field) context.Context {
	return context.WithValue(ctx, loggerKey, WithContext(ctx).With(fields...))
}

// 从指定的context返回一个zap实例
func WithContext(ctx context.Context) *zap.Logger {
	if ctx == nil {
		return Logger
	}
	if ctxLogger, ok := ctx.Value(loggerKey).(*zap.Logger); ok {
		return ctxLogger
	}
	return Logger
}

结语：

本文的实现方法主要是context的WithValue()配合zap的自定义追加字段特性来处理的，大家同样可以使用自己喜欢的log库来实现。文章的末尾，再附带提一下context包使用的一些最佳实践建议：

• 不要把context存储在结构体中，而是要显式地进行传递 把context作为第一个参数，并且一般都把变量命名为ctx 就算是程序允许，也不要传入一个nil的context，如果不知道是否要用context的话，用context.TODO()来替代。

• context.WithValue()只用来传递请求范围的值，不要用它来传递可选参数 就算是被多个不同的goroutine使用，context也是安全的。

• context.Background 只应用在最高等级，作为所有派生 context 的根。

• context 取消是建议性的，这些函数可能需要一些时间来清理和退出。

• context.Value应该很少使用，它不应该被用来传递可选参数。这使得 API 隐式的并且可以引起错误。取而代之的是，这些值应该作为参数传递。

• Context 结构没有取消方法，因为只有派生 context 的函数才应该取消 context。