Achieving structured wide-event logging using Go Slog

透過 Go Slog 達成結構化寬事件 logging 最佳實踐

前言

最近有較多的時間思考開發上的最佳實踐,考慮到目前開發的一個後端項目基本就是拿 go 原生 log🔗 到處打印與儲存片面事件而已。

logger.Info("Some Error happened")

在閱讀以下文件與最佳實踐後,我想著手改善現有的 logging 體驗透過導入 Go 1.21 引入的原生 slog 庫。

最佳典範定義

為達成 logging 最佳範例會用到的定義概念
  • 結構化 log:儲存為 JSON 或類似格式的 log。
  • 寬事件:一種理念,將某事件(請求)對應一個包含所有上下文的 log。
  • 基數(Cardinality):log 數值的豐富可能性。
    • 高基數:如 user_id,獨特容易抓出問題所在但耗費成本紀錄。
    • 低基數:如 http_method (GET, POST, PUT, DELETE, etc.),常見且重複。

實際導入結構化寬事件 Log 到 Go Gin 專案

取一個待辦事項的 CRUD 專案為例,實際範例代碼可以參考:Logger PR🔗

internal/logger/
├── logger.go # 初始化 slog handler
├── middleware.go # 寬事件組合 middleware
└── context.go # 業務上下文累積工具

logger.go:初始化 Logger

首先建立 logger.go,根據執行環境選擇不同的 Handler🔗

logger/logger.go
var Log *slog.Logger
func InitLogger() {
var handler slog.Handler
if gin.Mode() == gin.DebugMode {
handler = tint.NewHandler(os.Stdout, &tint.Options{
Level: slog.LevelDebug,
TimeFormat: time.Kitchen,
})
} else {
handler = slog.NewJSONHandler(&lumberjack.Logger{
Filename: "logs/app.log",
MaxSize: 10,
MaxBackups: 5,
MaxAge: 30,
Compress: true,
}, &slog.HandlerOptions{Level: slog.LevelInfo})
}
Log = slog.New(handler.WithAttrs([]slog.Attr{
slog.String("service", "go-gin-testing-todos"),
}))
slog.SetDefault(Log)
}

開發環境使用 tint🔗 輸出帶顏色與美化日期的文字格式,生產環境則輸出 JSON 並透過 Gin 官方文件推薦的 lumberjack🔗 做 log rotation。

WithAttrs🔗 讓每一筆 log 都自動帶上 service 欄位,可以塞入一些全局低基數的常見資訊像是:地區、服務名稱、環境變數⋯⋯等。

middleware.go:組合寬事件

透過把一個請求中發生的事件對應一筆 log 組成一個上下文豐富的寬事件。實作上透過 gin middleware 在請求結束後統一發出:

logger/middleware.go
func WideEventMiddleware() gin.HandlerFunc {
return func(c *gin.Context) {
start := time.Now()
c.Next()
statusCode := c.Writer.Status()
requestID, _ := c.Get("requestId")
requestIDStr, _ := requestID.(string)
fields := []any{
slog.String("method", c.Request.Method),
slog.Int("status_code", statusCode),
slog.String("path", c.Request.URL.Path),
slog.String("query", c.Request.URL.RawQuery),
slog.Int64("duration_ms", time.Since(start).Milliseconds()),
slog.String("client_ip", c.ClientIP()),
slog.String("requestId", requestIDStr),
}
var msg string = "http_completed"
if bizCtx := GetBusinessContext[any](c); bizCtx != nil {
for k, v := range bizCtx {
fields = append(fields, slog.Any(k, v))
}
if resource, ok := bizCtx["resource"].(string); ok {
if action, ok := bizCtx["action"].(string); ok {
msg = resource + "_" + action
}
}
}
if len(c.Errors) > 0 {
fields = append(fields, slog.String("error_message", c.Errors.Last().Error()))
}
switch {
case statusCode >= 500:
Log.Error(msg, fields...)
case statusCode >= 400:
Log.Warn(msg, fields...)
default:
Log.Info(msg, fields...)
}
}
}

c.Next() 讓所有請求工作先跑完,middleware 才在最後收集所有資訊一次性輸出。這樣就不會有「一個請求散落多筆 log」的問題。

context.go:業務上下文累積

Handler 執行過程中,透過 AddBusinessContext 把業務資訊寫入 gin context,等 middleware 結束時一起帶出:

logger/context.go
func AddBusinessContext[T any](c *gin.Context, key string, value T) {
ctxMap := make(map[string]interface{})
if existing, exists := c.Get(businessContextKey); exists {
ctxMap = existing.(map[string]interface{})
}
ctxMap[key] = value
c.Set(businessContextKey, ctxMap)
}
func AddResourceAction(c *gin.Context, resource string, action string) {
AddBusinessContext(c, "resource", resource)
AddBusinessContext(c, "action", action)
}
todo_controller.go
func (c *TodoController) Create(ctx *gin.Context) {
logger.AddResourceAction(ctx, "todo", "create")
var todo model.Todo
if err := ctx.ShouldBindJSON(&todo); err != nil {
ctx.Error(err)
ctx.JSON(http.StatusBadRequest, gin.H{"error": err.Error()})
return
}
logger.AddBusinessContext(ctx, "todo_title", todo.Title)
if err := c.service.Create(&todo); err != nil {
ctx.Error(err)
ctx.JSON(http.StatusInternalServerError, gin.H{"error": err.Error()})
return
}
logger.AddBusinessContext(ctx, "todo_id", todo.ID)
ctx.JSON(http.StatusCreated, todo)
}

注意 todo_id 是在 Create 成功後才加入,這展示了寬事件的彈性:上下文可以在請求生命週期中逐步累積,不需要在一開始就知道所有資訊。

直接 log

要直接拿 logger 實例來操作也是沒問題的,上面只是透過 gin context 儲存請求發生的狀態並透過 middleware 把重複的上下文給統一搜集起來處理而已。

todo_service.go
func (s *todoService) Create(todo *model.Todo) error {
logger.Log.Debug("todo_create",
slog.String("collection", "todos"),
slog.String("operation", "InsertOne"),
slog.Any("document", todo),
)
// ...
}

main.go:裝上 logger 系統

func main() {
logger.InitLogger()
r := gin.New() // 不用 gin.Default(),避免 gin 內建 logger 重複輸出
r.Use(gin.Recovery())
r.Use(logger.WideEventMiddleware())
// ...
}

使用 gin.New() 而非 gin.Default(),因為 gin.Default() 內建了自己的 logger middleware,會和我們的寬事件 middleware 重複輸出。

輸出結果

一個請求一筆 log,所有上下文都清晰的紀錄呈現

透過 slog.NewJSONHandler 生產環境(JSON)結果範例:

logs/app.log
{
"time": "2026-05-06T13:40:44.192568+08:00",
"level": "INFO",
"msg": "todo_read",
"service": "go-gin-testing-todos",
"method": "GET",
"status_code": 200,
"path": "/todos",
"query": "",
"duration_ms": 4,
"client_ip": "::1",
"requestId": "076f59e0-2ca3-40e1-8789-7c45708707d5",
"resource": "todo",
"action": "read",
"todos_count": 12
}

透過自製的 Handler 結果範例:

Terminal window
12:55PM DBG Get All Todos service=go-gin-testing-todos collection=todos operation=Find filter=map[]
12:56PM ERR todo_read service=go-gin-testing-todos method=GET status_code=500 path=/todos query="" duration_ms=30001 client_ip=::1 requestId=2d02fee1-6912-4799-bd91-e1718ee0ab7b resource=todo action=read error_message="server selection error: server selection timeout, current topology: { Type: Unknown, Servers: [{ Addr: localhost:27017, Type: Unknown, Last error: dial tcp [::1]:27017: connect: connection refused }, ] }"

總結

go slog 有極高的擴張能力,可以依照自己需求替換不同的 handler,像是 log/syslog🔗,串上其他服務。未來可以考慮 Tail-based Sampling、非同步更新 log 來解決不同延伸問題。