為什麼專案內需要鏈路追蹤？當一個請求中，請求了多個服務單元，如果請求出現了錯誤或異常，很難去定位是哪個服務出了問題，這時就需要鏈路追蹤。  從圖中可以清晰的看出他們之間的呼叫關係，通過一個例子說明下鏈路的重要性，比如對方調我們一個介面，反饋在某個時間段這介面太慢了，在排查程式碼發現邏輯比較複雜，不光呼叫了多個三方介面、操作了資料庫，還操作了快取，怎麼快速定位是哪塊執行時間很長？ 不賣關子，先說下本篇文章最終實現了什麼，如果感興趣再繼續往下看。 實現了通過記錄如下引數，來進行問題定位，關於每個引數的結構在下面都有介紹。 ``` // Trace 記錄的引數 type Trace struct { mux sync.Mutex Identifier string `json:"trace_id"` // 鏈路 ID Request *Request `json:"request"` // 請求資訊 Response *Response `json:"response"` // 響應資訊 ThirdPartyRequests []*Dialog `json:"third_party_requests"` // 呼叫第三方介面的資訊 Debugs []*Debug `json:"debugs"` // 除錯資訊 SQLs []*SQL `json:"sqls"` // 執行的 SQL 資訊 Redis []*Redis `json:"redis"` // 執行的 Redis 資訊 Success bool `json:"success"` // 請求結果 true or false CostSeconds float64 `json:"cost_seconds"` // 執行時長(單位秒) } ``` ## 引數結構 ### 鏈路 ID `String` 例如：4b4f81f015a4f2a01b00。如果請求 Header 中存在 `TRACE-ID`，就使用它，反之，重新建立一個。將 `TRACE_ID` 放到介面返回值中，這樣就可以通過這個標示查到這一串的資訊。 ### 請求資訊 `Object`，結構如下： ``` type Request struct { TTL string `json:"ttl"` // 請求超時時間 Method string `json:"method"` // 請求方式 DecodedURL string `json:"decoded_url"` // 請求地址 Header interface{} `json:"header"` // 請求 Header 資訊 Body interface{} `json:"body"` // 請求 Body 資訊 } ``` ### 響應資訊 `Object`，結構如下： ``` type Response struct { Header interface{} `json:"header"` // Header 資訊 Body interface{} `json:"body"` // Body 資訊 BusinessCode int `json:"business_code,omitempty"` // 業務碼 BusinessCodeMsg string `json:"business_code_msg,omitempty"` // 提示資訊 HttpCode int `json:"http_code"` // HTTP 狀態碼 HttpCodeMsg string `json:"http_code_msg"` // HTTP 狀態碼資訊 CostSeconds float64 `json:"cost_seconds"` // 執行時間(單位秒) } ``` ### 呼叫三方介面資訊 `Object`，結構如下： ``` type Dialog struct { mux sync.Mutex Request *Request `json:"request"` // 請求資訊 Responses []*Response `json:"responses"` // 返回資訊 Success bool `json:"success"` // 是否成功，true 或 false CostSeconds float64 `json:"cost_seconds"` // 執行時長(單位秒) } ``` 這裡面的 `Request` 和 `Response` 結構與上面保持一致。 細節來了，為什麼 `Responses` 結構是 `[]*Response` ？ 是因為 HTTP 可以進行重試請求，比如當請求對方介面的時候，HTTP 狀態碼為 503 `http.StatusServiceUnavailable`，這時需要重試，我們也需要把重試的響應資訊記錄下來。 ### 除錯資訊 `Object` 結構如下： ``` type Debug struct { Key string `json:"key"` // 標示 Value interface{} `json:"value"` // 值 CostSeconds float64 `json:"cost_seconds"` // 執行時間(單位秒) } ``` ### SQL 資訊 `Object`，結構如下： ``` type SQL struct { Timestamp string `json:"timestamp"` // 時間，格式：2006-01-02 15:04:05 Stack string `json:"stack"` // 檔案地址和行號 SQL string `json:"sql"` // SQL 語句 Rows int64 `json:"rows_affected"` // 影響行數 CostSeconds float64 `json:"cost_seconds"` // 執行時長(單位秒) } ``` ### Redis 資訊 `Object`，結構如下： ``` type Redis struct { Timestamp string `json:"timestamp"` // 時間，格式：2006-01-02 15:04:05 Handle string `json:"handle"` // 操作，SET/GET 等 Key string `json:"key"` // Key Value string `json:"value,omitempty"` // Value TTL float64 `json:"ttl,omitempty"` // 超時時長(單位分) CostSeconds float64 `json:"cost_seconds"` // 執行時間(單位秒) } ``` ### 請求結果 `Bool`，這個和統一定義返回值有點關係，看下程式碼： ``` // 錯誤返回 c.AbortWithError(code.ErrParamBind.WithErr(err)) // 正確返回 c.Payload(code.OK.WithData(data)) ``` 當錯誤返回時 且 `ctx.Writer.Status() != http.StatusOK` 時，為 `false`，反之為 `true`。 ### 執行時長 `Float64`，例如：0.041746869，記錄的是從請求開始到請求結束所花費的時間。 ## 如何收集引數？ 這時有老鐵會說了：“規劃的稍微還行，使用的時候會不會很麻煩？” “No，No，使用起來一丟丟都不麻煩”，接著往下看。 ### 無需關心的引數 鏈路 ID、請求資訊、響應資訊、請求結果、執行時長，這 5 個引數，開發者無需關心，這些都在中介軟體封裝好了。 ### 呼叫第三方介面的資訊 只需多傳遞一個引數即可。 在這裡厚臉皮自薦下 [httpclient 包](https://mp.weixin.qq.com/s/IxvzNPI18OEYmCL5uH4jCA) 。 - 支援設定失敗時重試，可以自定義重試次數、重試前延遲等待時間、重試的滿足條件； - 支援設定失敗時告警，可以自定義告警渠道（郵件/微信）、告警的滿足條件； - 支援設定呼叫鏈路； 呼叫示例程式碼： ``` // httpclient 是專案中封裝的包 api := "http://127.0.0.1:9999/demo/post" params := url.Values{} params.Set("name", name) body, err := httpclient.PostForm(api, params, httpclient.WithTrace(ctx.Trace()), // 傳遞上下文 ) ``` ### 除錯資訊 只需多傳遞一個引數即可。 呼叫示例程式碼： ``` // p 是專案中封裝的包 p.Println("key", "value", p.WithTrace(ctx.Trace()), // 傳遞上下文 ) ``` ### SQL 資訊 稍微複雜一丟丟，需要多傳遞一個引數，然後再寫一個 `GORM` 外掛。 使用的 `GORM V2` 自帶的 `Callbacks` 和 `Context` 知識點，細節不多說，可以看下這篇文章：[基於 GORM 獲取當前請求所執行的 SQL 資訊](https://mp.weixin.qq.com/s/zDXEkO9AQK5INf0JcNQITg)。 呼叫示例程式碼： ``` // 原來查詢這樣寫 err := u.db.GetDbR(). First(data, id). Where("is_deleted = ?", -1). Error // 現在只需這樣寫 err := u.db.GetDbR(). WithContext(ctx.RequestContext()). First(data, id). Where("is_deleted = ?", -1). Error // .WithContext 是 GORM V2 自帶的。 // 外掛的程式碼就不貼了，去上面的文章檢視即可。 ``` ### Redis 資訊 只需多傳遞一個引數即可。 呼叫示例程式碼： ``` // cache 是基於 go-redis 封裝的包 d.cache.Get("name", cache.WithTrace(c.Trace()), ) ``` ## 核心原理是啥？ 在這沒關子可賣，看到這相信老鐵們都知道了，就兩個：一個是 攔截器，另一個是 `Context`。  ## 如何記錄引數？ 將以上資料轉為 `JSON` 結構記錄到日誌中。 ### JSON 示例 ``` { "level":"info", "time":"2021-01-30 22:32:48", "caller":"core/core.go:444", "msg":"core-interceptor", "domain":"go-gin-api[fat]", "method":"GET", "path":"/demo/trace", "http_code":200, "business_code":1, "success":true, "cost_seconds":0.054025302, "trace_id":"2cdb2f96934f573af391", "trace_info":{ "trace_id":"2cdb2f96934f573af391", "request":{ "ttl":"un-limit", "method":"GET", "decoded_url":"/demo/trace", "header":{ "Accept":[ "application/json" ], "Accept-Encoding":[ "gzip, deflate, br" ], "Accept-Language":[ "zh-CN,zh;q=0.9,en;q=0.8" ], "Authorization":[ "eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJVc2VySUQiOjEsIlVzZXJOYW1lIjoieGlubGlhbmdub3RlIiwiZXhwIjoxNjEyMTAzNTQwLCJpYXQiOjE2MTIwMTcxNDAsIm5iZiI6MTYxMjAxNzE0MH0.2yHDdP7cNT5uL5xA0-j_NgTK4GrW-HGn0KUxcbZfpKg" ], "Connection":[ "keep-alive" ], "Referer":[ "http://127.0.0.1:9999/swagger/index.html" ], "Sec-Fetch-Dest":[ "empty" ], "Sec-Fetch-Mode":[ "cors" ], "Sec-Fetch-Site":[ "same-origin" ], "User-Agent":[ "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/88.0.4324.96 Safari/537.36" ] }, "body":"" }, "response":{ "header":{ "Content-Type":[ "application/json; charset=utf-8" ], "Trace-Id":[ "2cdb2f96934f573af391" ], "Vary":[ "Origin" ] }, "body":{ "code":1, "msg":"OK", "data":[ { "name":"Tom", "job":"Student" }, { "name":"Jack", "job":"Teacher" } ], "id":"2cdb2f96934f573af391" }, "business_code":1, "business_code_msg":"OK", "http_code":200, "http_code_msg":"OK", "cost_seconds":0.054024874 }, "third_party_requests":[ { "request":{ "ttl":"5s", "method":"GET", "decoded_url":"http://127.0.0.1:9999/demo/get/Tom", "header":{ "Authorization":[ "eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJVc2VySUQiOjEsIlVzZXJOYW1lIjoieGlubGlhbmdub3RlIiwiZXhwIjoxNjEyMTAzNTQwLCJpYXQiOjE2MTIwMTcxNDAsIm5iZiI6MTYxMjAxNzE0MH0.2yHDdP7cNT5uL5xA0-j_NgTK4GrW-HGn0KUxcbZfpKg" ], "Content-Type":[ "application/x-www-form-urlencoded; charset=utf-8" ], "TRACE-ID":[ "2cdb2f96934f573af391" ] }, "body":null }, "responses":[ { "header":{ "Content-Length":[ "87" ], "Content-Type":[ "application/json; charset=utf-8" ], "Date":[ "Sat, 30 Jan 2021 14:32:48 GMT" ], "Trace-Id":[ "2cdb2f96934f573af391" ], "Vary":[ "Origin" ] }, "body":"{"code":1,"msg":"OK","data":{"name":"Tom","job":"Student"},"id":"2cdb2f96934f573af391"}", "http_code":200, "http_code_msg":"200 OK", "cost_seconds":0.000555089 } ], "success":true, "cost_seconds":0.000580202 }, { "request":{ "ttl":"5s", "method":"POST", "decoded_url":"http://127.0.0.1:9999/demo/post", "header":{ "Authorization":[ "eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJVc2VySUQiOjEsIlVzZXJOYW1lIjoieGlubGlhbmdub3RlIiwiZXhwIjoxNjEyMTAzNTQwLCJpYXQiOjE2MTIwMTcxNDAsIm5iZiI6MTYxMjAxNzE0MH0.2yHDdP7cNT5uL5xA0-j_NgTK4GrW-HGn0KUxcbZfpKg" ], "Content-Type":[ "application/x-www-form-urlencoded; charset=utf-8" ], "TRACE-ID":[ "2cdb2f96934f573af391" ] }, "body":"name=Jack" }, "responses":[ { "header":{ "Content-Length":[ "88" ], "Content-Type":[ "application/json; charset=utf-8" ], "Date":[ "Sat, 30 Jan 2021 14:32:48 GMT" ], "Trace-Id":[ "2cdb2f96934f573af391" ], "Vary":[ "Origin" ] }, "body":"{"code":1,"msg":"OK","data":{"name":"Jack","job":"Teacher"},"id":"2cdb2f96934f573af391"}", "http_code":200, "http_code_msg":"200 OK", "cost_seconds":0.000450153 } ], "success":true, "cost_seconds":0.000468387 } ], "debugs":[ { "key":"res1.Data.Name", "value":"Tom", "cost_seconds":0.000005193 }, { "key":"res2.Data.Name", "value":"Jack", "cost_seconds":0.000003907 }, { "key":"redis-name", "value":"tom", "cost_seconds":0.000009816 } ], "sqls":[ { "timestamp":"2021-01-30 22:32:48", "stack":"/Users/xinliang/github/go-gin-api/internal/api/repository/db_repo/user_demo_repo/user_demo.go:76", "sql":"SELECT `id`,`user_name`,`nick_name`,`mobile` FROM `user_demo` WHERE user_name = 'test_user' and is_deleted = -1 ORDER BY `user_demo`.`id` LIMIT 1", "rows_affected":1, "cost_seconds":0.031969072 } ], "redis":[ { "timestamp":"2021-01-30 22:32:48", "handle":"set", "key":"name", "value":"tom", "ttl":10, "cost_seconds":0.009982091 }, { "timestamp":"2021-01-30 22:32:48", "handle":"get", "key":"name", "cost_seconds":0.010681579 } ], "success":true, "cost_seconds":0.054025302 } } ``` ### zap 日誌元件 有對日誌收集感興趣的老鐵們可以往下看，`trace_info` 只是日誌的一個引數，具體日誌引數包括： | 引數 | 資料型別 | 說明 | | ------------- | -------- | -------------------------------------------- | | level | String | 日誌級別，例如：info,warn,error,debug | | time | String | 時間，例如：2021-01-30 16:05:44 | | caller | String | 呼叫位置，檔案+行號，例如：core/core.go:443 | | msg | String | 日誌資訊，例如：xx 錯誤 | | domain | String | 域名或服務名，例如：go-gin-api[fat] | | method | String | 請求方式，例如：POST | | path | String | 請求路徑，例如：/user/create | | http_code | Int | HTTP 狀態碼，例如：200 | | business_code | Int | 業務狀態碼，例如：10101 | | success | Bool | 狀態，true or false | | cost_seconds | Float64 | 花費時間，單位：秒，例如：0.01 | | trace_id | String | 鏈路ID，例如：ec3c868c8dcccfe515ab | | trace_info | Object | 鏈路資訊，結構化資料。 | | error | String | 錯誤資訊，當出現錯誤時才有這欄位。 | | errorVerbose | String | 詳細的錯誤堆疊資訊，當出現錯誤時才有這欄位。 | 日誌記錄可以使用 `zap`，`logrus` ，這次我使用的 `zap`，簡單封裝一下即可，比如： - 支援設定日誌級別； - 支援設定日誌輸出到控制檯； - 支援設定日誌輸出到檔案； - 支援設定日誌輸出到檔案(可自動分割)； ## 總結 這個功能比較常用，使用起來也很爽，比如呼叫方發現接口出問題時，只需要提供 `TRACE-ID` 即可，我們就可以查到關於它整個鏈路的所有資訊。 > 以上程式碼的實現都在 go-gin-api 專案中，地址：https://github.com/xinliangnote/go-