HTTP request ID association with logs
Tags: webdev, beginners, go, tutorial
Published: 2022-11-04 16:06:41

## Introduction

[Hertz](https://github.com/cloudwego/hertz) is an ultra-large-scale enterprise-level microservice HTTP framework, featuring high ease of use, easy expansion, and low latency etc.

Hertz uses the self-developed high-performance network library [Netpoll](https://github.com/cloudwego/netpoll) by default. In some special scenarios, Hertz has certain advantages in QPS and latency compared to go net. For performance data, please refer to the echo data below.

![](https://picture.lanlance.cn/i/2022/10/27/635a832c5a574.png)

In internal practice, for some typical services, such as services with a high proportion of frameworks, gateways and other services, after migrating Hertz, compared to the Gin framework, the resource usage is significantly reduced. For more information, see [hertz-benchmark](https://github.com/cloudwego/hertz-benchmark).


[Hertz](https://github.com/cloudwego/hertz) provides requestid middleware、built-in hlog log library and some [hlog log component extensions](https://github.com/hertz-contrib/logger), this article focuses on how to associate request IDs with logs to make it easier for users to find logs.


## Hands-on


### Introduction to the Request ID middleware

The requestid middleware for Hertz is based on the [Gin](https://github.com/gin-gonic/gin) framework's requestid and adapted to Hertz. Its main purpose is to add `rquestid` to the HTTP response and `context` of a request to uniquely identify a HTTP request.

It is used in the following way:

```go
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()
}
```

Accessing `127.0.0.1:8888/ping`, we will see an extra `X-request-ID` field in the HTTP response header.

### Hlog extensions


Hertz also provides hlog for printing the framework's internal logs. Users can use this in simple log printing scenarios.

The default [hlog](https://github.com/cloudwego/hertz/tree/develop/pkg/common/hlog) is based on the `log` package implementation and has normal performance, while Hertz  provides the [logger](https://github.com/hertz-contrib/logger) extension, which provides `zap` and `logrus` implementations.

The logrus extension is used in the following way:

```go
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")
}
```

### Practical code


Associate the log of a request by using the requestid middleware with the [logger](https://github.com/hertz-contrib/logger) extension.

#### Custom Hooks

Logrus supports a user-defined Hook that can print `requestid` in the log by implementing a custom Hook.
```go
// 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
}
```

#### Full code
```go
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()
}
```

#### Effect

```go
{"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"}

```


In this way we associate the log of an HTTP request with `requstid`. In fact Hertz provides more powerful capabilities, which we will cover in the next article. You can check out [obs-opentelemetry](https://github.com/hertz-contrib/obs-opentelemetry) in advance if you are interested.

## Reference

- https://github.com/cloudwego/hertz/
- https://github.com/hertz-contrib/requestid/issues/6
- https://github.com/hertz-contrib/logger