Logrus打印trace

本文最后更新于：2022年7月29日 下午

看完 Go每周一库之Logrus 由感而发 ，是旭文博客的补充，强烈建议先看旭文的博客

Logrus打印trace

Logrus 前置知识点

旭文提到 Logrus 的两个重要结构体：Logger Entry，但是对于这两者并没有做详细的介绍，但是这些知识点对于本文下文有重要的意义。

Logger

Logger 是一个非常有趣的结构，我们先来看一下它的内部结构，没有写出所有的结构

1
2
3
4
5
6
7
8
9
10
type Logger struct {
	Out io.Writer // 封装流，所有的日志都会调用 Write 方法写.
	Hooks LevelHooks // 钩子. 在写日志的之前会调用
	Formatter Formatter // 结构化方法,是一个函数.所有的日志都会调用Format方法把Entry结构化成[]byte数组
	
    Level Level // 日志等级
	mu MutexWrap // 锁.非常重要.
	// Reusable empty entry
	entryPool sync.Pool // entry池。用来保证不会多次分配内存
}

可以看到 Logger 结构体没有依赖其余的组件，都是通过接口的方式暴露出功能，在我们实现插件的时候只需要关注自己需要实现的接口，而完全不需要去修改 logrus 的代码。

Level、Out、Formatter、Hooks这些功能旭文的博客已经写的很明白，此处就不多赘述。

Entry

Entry 对应每条日志的实体，他的内部结构如下：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
type Entry struct {
	Logger *Logger
	// Contains all the fields set by the user.
	Data Fields
	// Time at which the log entry was created
	Time time.Time
	// Level the log entry was logged at: Trace, Debug, Info, Warn, Error, Fatal or Panic
	// This field will be set on entry firing and the value will be equal to the one in Logger struct field.
	Level Level
	// Calling method, with package name
	Caller *runtime.Frame
	// Message passed to Trace, Debug, Info, Warn, Error, Fatal or Panic
	Message string
	// When formatter is called in entry.log(), a Buffer may be set to entry
	Buffer *bytes.Buffer
	Context context.Context
	err string
}

Entry内部包括了Logger结构体指针，这是一个非常常见的编程手法，我们知道Entry都是通过Logger生成的，那么这些Entry就必须要知道是哪个Logger生成了ta，并且Entry会高度依赖Logger(Logger掌握了输出信息)，但是需要注意: Entry没有使用 Logger 的 EnterPool.

Entry最为重要的字段就是Data了，它保存了日志除内容之外的结构化信息，Fields本身就是一个map，没有什么神奇的东西。

Entry也可以生成Entry，主要通过 Data 复制来实现。

Logrus实现trace

trace_id应该是一个微服务的刚需。它由Gateway产生，并在微服务各个节点之中流转，一个trace_id就可以标记出一条完整的链路。

想想有没有这种需求：我需要打印一次请求的完整日志、快速定位服务A请求服务B的日志。需要实现这个功能就需要我们把trace_id给加入到结构化日志中，这可以使用logrus完美实现。

通过刚刚的前置知识点可以知道

  1. 每条日志的信息都是由 Entry 保存的
  2. Entry 内部由 Data、Ctx字段
  3. Entry 知道 Logger 指针
  4. Logger 在每次输出Entry日志的时候会调用 Hooks

接下来我们就可以通过这些来实现我们的功能了。首先书写 Gin 中间件，获取请求头的TraceID信息写入到 gin.Request.Context 中。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
// GinTraceIdMiddleware 生成trade_id
func GinTraceIdMiddleware(ginCtx *gin.Context) {
	reqCtx := ginCtx.Request.Context()
	header := ginCtx.GetHeader(HeaderTraceIdKey)
	if header != "" {
		reqCtx = ContextWithTraceId(reqCtx, header)
	} else {
		reqCtx = ContextWithRandomTraceId(reqCtx)
	}
	ginCtx.Request = ginCtx.Request.WithContext(reqCtx)
}

// ContextWithRandomTraceId 为Context生成随机的trace_id
func ContextWithRandomTraceId(ctx context.Context) (newCtx context.Context) {
	traceId := UUID()
	ContextWithTraceId(ctx, traceId)
	return
}

// ContextWithTraceId 为Context设置trace_id. 如果ID已存在则不设置
func ContextWithTraceId(ctx context.Context, traceId string) (newCtx context.Context) {
	oldTraceId, ok := ctx.Value(TraceIdKey).(string)
	if ok && oldTraceId != "" {
		return
	}
	
	newCtx = context.WithValue(ctx, TraceIdKey, traceId)
	return
}

这样我们可以直接书写 router.Use(GinTraceIdMiddleware) 使得每次的请求的ctx都携带 __trace_id ，这样我们只需要让这个ctx在程序各个地方流转即可。

接下来是第二步：让每次打印都携带流转的Ctx。通过上文可以知道每个 Entry 都会携带一个 Ctx 信息。这样Entry也可以设置成这个Ctx。然后在打印日志的时候把Ctx的TraceId信息加入到 Entry 的 Data 中即可。这一步我们可以使用Hook来实现。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
// TraceIdHook 使用该结构体在日志中打印TraceID信息
type TraceIdHook struct {}

// Levels 所有等级, 可以书写成可配置的
func (m *TraceIdHook) Levels() []logrus.Level {
	return logrus.AllLevels
}

const (
	TraceIdKey       = "__trace_id"
	HeaderTraceIdKey = "__trace_id"
)

// Fire implements logrus.Hook.Fire
func (m *TraceIdHook) Fire(entry *logrus.Entry) (err error) {
	var tradeId string
	if entry.Context != nil {
		var ok bool
		tradeId, ok = entry.Context.Value(TraceIdKey).(string) // 判断 entry 中的ctx字段是否存在 traceId 信息
		if !ok {
			return
		}
	}

	if tradeId == "" {
		return
	}

	entry.Data["trace_id"] = tradeId // 把 trace_id 信息加入到携带信息中，这样就可以打印出来了

	return
}

使用方法

主函数

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
func main() {
	engine := gin.Default()
	logrus.AddHook(&log.TraceIdHook{})

	engine.Use(log.GinTraceIdMiddleware)

	engine.POST(`/`, func(c *gin.Context) {
		logrus.WithContext(c.Request.Context()).
			WithField(`func`, `index`).
			Info("hello")

		c.String(200, "OK!!!")
	})

	_ = engine.Run(":8080")
}

log包

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
package log

import (
	"context"
	"github.com/gin-gonic/gin"
	"github.com/google/uuid"
	"github.com/sirupsen/logrus"
	"strings"
)

func InitLog() {
	logrus.AddHook(&TraceIdHook{})
}

type TraceIdHook struct {
}

func (m *TraceIdHook) Levels() []logrus.Level {
	return logrus.AllLevels
}

const (
	TraceIdKey       = "__trace_id"
	HeaderTraceIdKey = "__trace_id"
)

// Fire implements logrus.Hook.Fire
func (m *TraceIdHook) Fire(entry *logrus.Entry) (err error) {
	var tradeId string
	if entry.Context != nil {
		var ok bool
		tradeId, ok = entry.Context.Value(TraceIdKey).(string)
		if !ok {
			return
		}
	}

	if tradeId == "" {
		return
	}

	entry.Data["trace_id"] = tradeId

	return
}

// GinTraceIdMiddleware 生成trade_id
func GinTraceIdMiddleware(ginCtx *gin.Context) {
	reqCtx := ginCtx.Request.Context()
	header := ginCtx.GetHeader(HeaderTraceIdKey)
	if header != "" {
		reqCtx = ContextWithTraceId(reqCtx, header)
	} else {
		reqCtx = ContextWithRandomTraceId(reqCtx)
	}
	ginCtx.Request = ginCtx.Request.WithContext(reqCtx)
}

// ContextWithRandomTraceId 为Context生成随机的trace_id
func ContextWithRandomTraceId(ctx context.Context) (newCtx context.Context) {
	traceId := UUID()
	newCtx = ContextWithTraceId(ctx, traceId)
	return
}

// ContextWithTraceId 为Context设置trace_id. 如果ID已存在则不设置
func ContextWithTraceId(ctx context.Context, traceId string) (newCtx context.Context) {
	oldTraceId, ok := ctx.Value(TraceIdKey).(string)
	if ok && oldTraceId != "" {
		return
	}

	newCtx = context.WithValue(ctx, TraceIdKey, traceId)
	return
}

func UUID() string {
	value := uuid.New()

	return strings.ToLower(
		strings.Replace(value.String(), "-", "", -1),
	)
}

func BgContextWithCancel() (ctx context.Context, cancel context.CancelFunc) {
	ctx, cancel = context.WithCancel(context.Background())
	ctx = ContextWithRandomTraceId(ctx)
	return
}

func GetTraceId(ctx context.Context) (traceId string) {
	traceId, _ = ctx.Value(TraceIdKey).(string)
	return
}

这样当我们每打一次日志的时候都可以记录到trace_id

写在最后

也不知道想写点什么东西在最后，就这样吧

Golang
go

本博客所有文章除特别声明外，均采用 CC BY-SA 4.0 协议 ，转载请注明出处！