Structured wide-event logging using Go Slog

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

@ Go

前言

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

logger.Info("Some Error happened")

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

最佳典範定義

  • 結構化 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      # 初始化全局 Logger
├── middleware.go  # 寬事件組合 middleware
└── context.go     # 業務上下文累積工具

logger.go：初始化 Logger

首先建立 logger.go，根據執行環境選擇不同的 Handler🔗，slog 的 Handler 其實就是一個介面處理「log 要怎麼被處理和輸出」：

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：

logger/middleware.go
package logger


import (
  "log/slog"
  "time"


  "github.com/gin-gonic/gin"
)


// Base on Structured Logging from gin doc
// https://gin-gonic.com/en/docs/logging/structured-logging/
// WideEventMiddleware intercepts requests and emits a single wide event upon completion.
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 := []slog.Attr{
      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),
    }


    // Add Error to log
    if len(c.Errors) > 0 {
      fields = append(fields, slog.String("error_message", c.Errors.Last().Error()))
    }


    msg := "request_completed"
    switch {
    case statusCode >= 500:
      Log.LogAttrs(c.Request.Context(), slog.LevelError, msg, fields...)
    case statusCode >= 400:
      Log.LogAttrs(c.Request.Context(), slog.LevelWarn, msg, fields...)
    default:
      Log.LogAttrs(c.Request.Context(), slog.LevelInfo, msg, fields...)
    }
  }
}

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

context.go：業務上下文累積

請求執行過程中，透過 AddContext 把業務資訊寫入 gin context，等 middleware 結束時一起帶出：

logger/context.go
package logger


import (
  "log/slog"


  "github.com/gin-gonic/gin"
)


const businessContextKey = "logger_context"


// AddContext appends typed slog attributes to the request's business context.
func AddContext(c *gin.Context, attrs ...slog.Attr) {
  if len(attrs) == 0 {
    return
  }


  ctxAttrs := make([]slog.Attr, 0, len(attrs))
  if existing, exists := c.Get(businessContextKey); exists {
    if existingAttrs, ok := existing.([]slog.Attr); ok {
      ctxAttrs = append(ctxAttrs, existingAttrs...)
    }
  }


  ctxAttrs = append(ctxAttrs, attrs...)
  c.Set(businessContextKey, ctxAttrs)
}


// GetContext retrieves the accumulated business context from the request.
// Returns a copy so callers cannot mutate the context state.
func GetContext(c *gin.Context) []slog.Attr {
  if existing, exists := c.Get(businessContextKey); exists {
    if attrs, ok := existing.([]slog.Attr); ok {
      return append([]slog.Attr(nil), attrs...)
    }
  }
  return nil
}
todo_controller.go
func (c *TodoController) Create(ctx *gin.Context) {
  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.AddContext(ctx, slog.String("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.AddContext(ctx, slog.String("todo_id", todo.ID.Hex()))
  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 }, ] }"

總結

Handlers

pkg/logger

Middleware

產生 ID

收集欄位

AddContext

RequestIDMiddleware

StructuredWideEvent

Structured Logger (slog)

Business Context

Console (tint)

File (lumberjack)

MongoDB Handler

Syslog Handler

考量到現成套件使用人數不多，像是：sloggin🔗、 gin-contrib/slog🔗、samber/slog-gin🔗，我自己在 slog 之上添加了輕量的抽象讓搜集請求 log 變得更容易。未來可以考慮 Tail-based Sampling、非同步更新 log 來解決不同延伸問題。