包包baobaolin.com
date
entry
015
topic
delivery
rev

你的 access log 回答不了「為什麼」

從 log 裡撈出那筆 500,整行只有 method、path、狀態碼、耗時。真正的錯誤訊息在它前面幾行——而你沒有辦法確定是哪幾行,因為同一秒還有其他二十個請求也在寫 log。

典型的 access log 一行長這樣:

[GIN] 2026/09/07 - 21:03:11 | 500 |  142.7ms |  10.0.1.24 | POST /api/v1/orders

它告訴你:有這個請求、失敗了、花了 142 毫秒。它沒告訴你的是唯一你想知道的事——為什麼

原因在於這行是誰寫的。access log 由 middleware 在 handler 跑完之後產生,它拿得到的是 response:狀態碼、大小、耗時。handler 裡那個 err 的內容,在 return 的那一刻就結束了生命,除非有人另外把它寫出來。

兩種日誌,各自正確,互相對不上

多數服務其實兩種都有。錯誤訊息通常確實被印出來了,就在 access log 那行的前面幾行:

ERROR: pq: duplicate key value violates unique constraint "orders_trade_no_key"
[GIN] 2026/09/07 - 21:03:11 | 500 |  142.7ms |  10.0.1.24 | POST /api/v1/orders

在低流量的環境,這樣就夠了——靠時間順序把它們配起來。問題是這個方法在有負載的時候就失效:同一秒裡有二十個請求交錯寫入,「前面幾行」變成一個猜測。

兩堆各自正確、卻無法對應的日誌,合起來的價值接近零。

request id:一條線穿過去

修法不是多記東西,是給每個請求一個識別碼,然後讓每一行都帶著它。

入口的 middleware 產生(或沿用上游傳來的)id,塞進 context:

func RequestID() gin.HandlerFunc {
    return func(c *gin.Context) {
        id := c.GetHeader("X-Request-ID")
        if id == "" { id = uuid.NewString() }
        c.Set("request_id", id)
        c.Header("X-Request-ID", id)   // 回給客戶端
        c.Next()
    }
}

之後所有的 log——錯誤、警告、access line——都帶這個欄位:

{"level":"error","request_id":"7f3a…","msg":"insert order failed",
 "err":"duplicate key value violates unique constraint"}
{"level":"info","request_id":"7f3a…","status":500,"method":"POST",
 "path":"/api/v1/orders","latency_ms":142.7}

現在調查一筆 500 是一個查詢,不是一次考古:拿 request id 過濾,得到的就是那一次請求的完整故事。

把 id 回給客戶端這一步不要省。它讓「客戶回報問題」從一段模糊的描述變成一個可以直接查的鍵——對方附上 X-Request-ID,你就不需要問「大概幾點、用哪個帳號、試了幾次」。這跟在回應裡帶上 build sha 是同一個習慣:把診斷需要的資訊,放進使用者本來就會複製給你的東西裡。

沿用上游的 id

注意上面那段先讀 X-Request-ID header 才決定要不要生新的。這一步讓 id 可以跨服務:前端產生、後端沿用、後端呼叫另一個服務時再傳下去。

沒有這個的話,一個請求穿過三個服務就會有三個不相干的 id,你只能再一次用時間戳去猜。這在跨層系統偵錯裡差別特別大——那篇講的「請求走到第幾節」,有共用 id 的話就是一個查詢的事。

結構化,因為你要查它不是讀它

純文字 log 對 grep 友善,對「找出過去一小時所有 status ≥ 500 且 path 開頭是 /api/v1/orders 的請求」不友善。輸出 JSON、讓欄位可以被過濾,這件事在 log 量還小的時候做很便宜,等到需要的時候再改就很貴。

最少要有的欄位:

  • request_idtimestamplevel
  • methodpathstatuslatency_ms
  • 錯誤那行的 err(原始訊息,不要只寫「操作失敗」)
  • 身分(user_id 之類的內部識別碼,不是 email)

不要寫進去的東西

日誌的存取控制通常比資料庫鬆,所以有些東西進去了就等於外流:

  • token、密碼、API key——包含「為了 debug 暫時印一下」的那次。出現過就算洩漏的判準在這裡一樣適用
  • 整包 request body——它遲早會包含個資或信用卡欄位。要記的話要有白名單,不是黑名單
  • 個資——email、電話、地址、身分證號。記內部 id,需要時再去資料庫查

這件事的麻煩在於它不可逆:寫進去的 log 已經散到 CloudWatch、備份、和某個人下載的 .log 檔裡。事後刪不乾淨。

順帶一提保留期。CloudWatch log group 預設是永久保留,而它按儲存量收費。導入時順手設一個保留天數(多數服務三十到九十天就夠),否則兩年後你會看到一筆莫名其妙的帳單,而那些 log 從來沒有人查過。

如果只記得一件事

日誌的價值不在於寫了多少,在於能不能從一個症狀走到一個原因。 判斷標準只有一個:拿到使用者回報的一筆失敗,你能不能在一個查詢之內看到那次請求發生的全部事情。答不出來的話,記再多行也只是佔硬碟。

修訂紀錄

  1. 首次發布