HTTP请求ID与日志关联的实战

介绍

Hertz 作为一个高性能的 HTTP 框架，它提供了 requestid 中间件以及内置的 hlog 日志库与一些 hlog 日志组件的扩展，本文主要讲解如何将请求ID与日志关联方便用户查找日志。

实战

请求ID中间件介绍

Hertz 的 requestid 中间件是根据 Gin 框架的 requestid 修改并适配 Hertz 。它的主要作用是在请求的响应和 context 中添加 rquestid，用于唯一标识一次请求。

它的使用方式如下:

package main

import (
	"context"

	"github.com/cloudwego/hertz/pkg/app"
	"github.com/cloudwego/hertz/pkg/app/server"
	"github.com/cloudwego/hertz/pkg/common/utils"
	"github.com/cloudwego/hertz/pkg/protocol/consts"
	"github.com/hertz-contrib/requestid"
)

func main() {
	h := server.Default()

	h.Use(requestid.New())

	// Example ping request.
	h.GET("/ping", func(ctx context.Context, c *app.RequestContext) {
		c.JSON(consts.StatusOK, utils.H{"ping": "pong"})
	})

	h.Spin()
}

访问 127.0.0.1:8888/ping，我们会发现响应头中多出了一个 X-request-ID 字段。

Hlog 扩展

Hertz 同时提供了 hlog 用于打印框架内部的日志，用户可以在一些简单的日志打印场景中使用。

默认的 hlog 是基于 log 包实现并且性能是普通的，Hertz 提供了 logger 扩展，它提供了 zap 和 logrus 实现。

logrus 扩展的使用方式如下:

package main

import (
	"context"

	"github.com/cloudwego/hertz/pkg/common/hlog"
	hertzlogrus "github.com/hertz-contrib/logger/logrus"
)

func main() {
	logger := hertzlogrus.NewLogger()
	hlog.SetLogger(logger)
	hlog.CtxInfof(context.Background(), "hello %s", "hertz")
}

实战代码

通过使用 requestid 中间件与 logger 扩展我们将一次请求的日志关联起来。

自定义 Hook

logrus 支持用户自定义 Hook，通过实现一个自定义 Hook 可以在日志中打印 requestid。

// Custom Hook
type RequestIdHook struct{}

func (h *RequestIdHook) Levels() []logrus.Level {
return logrus.AllLevels
}

func (h *RequestIdHook) Fire(e *logrus.Entry) error {
ctx := e.Context
if ctx == nil {
return nil
}
value := ctx.Value("X-Request-ID")
if value != nil {
e.Data["log_id"] = value
}
return nil
}

完整代码

package main

import (
	"context"

	"github.com/cloudwego/hertz/pkg/app"
	"github.com/cloudwego/hertz/pkg/app/server"
	"github.com/cloudwego/hertz/pkg/common/hlog"
	"github.com/cloudwego/hertz/pkg/common/utils"
	"github.com/cloudwego/hertz/pkg/protocol/consts"
	hertzlogrus "github.com/hertz-contrib/logger/logrus"
	"github.com/hertz-contrib/requestid"
	"github.com/sirupsen/logrus"
)

type RequestIdHook struct{}

func (h *RequestIdHook) Levels() []logrus.Level {
	return logrus.AllLevels
}

func (h *RequestIdHook) Fire(e *logrus.Entry) error {
	ctx := e.Context
	if ctx == nil {
		return nil
	}
	value := ctx.Value("X-Request-ID")
	if value != nil {
		e.Data["log_id"] = value
	}
	return nil
}

func main() {
	h := server.Default()
	logger := hertzlogrus.NewLogger(hertzlogrus.WithHook(&RequestIdHook{}))
	hlog.SetLogger(logger)

	h.Use(requestid.New())

	// Example ping request.
	h.GET("/ping", func(ctx context.Context, c *app.RequestContext) {
		hlog.CtxInfof(ctx, "test log")
		c.JSON(consts.StatusOK, utils.H{"ping": "pong"})
	})
	h.Spin()
}

效果

{"level":"info","msg":"HERTZ: Using network library=netpoll","time":"2022-11-04T13:58:51+08:00"}
{"level":"info","msg":"HERTZ: HTTP server listening on address=[::]:8888","time":"2022-11-04T13:58:51+08:00"}
{"level":"info","log_id":"8f0012a3-f97b-49ca-b13b-1f009585b5d9","msg":"test log","time":"2022-11-04T13:59:11+08:00"}

通过这种方式我们将一次 HTTP 请求的日志通过 requstid 关联起来。其实 Hertz 提供了更加强大的能力，关于这一点我们将在下篇文章中介绍。大家如果感兴趣可以提前查看 obs-opentelemetry 。