Go - 实现项目内链路追踪

为什么项目内需要链路追踪？当一个请求中，请求了多个服务单元，如果请求出现了错误或异常，很难去定位是哪个服务出了问题，这时就需要链路追踪。

从图中可以清晰的看出他们之间的调用关系，通过一个例子说明下链路的重要性，比如对方调我们一个接口，反馈在某个时间段这接口太慢了，在排查代码发现逻辑比较复杂，不光调用了多个三方接口、操作了数据库，还操作了缓存，怎么快速定位是哪块执行时间很长？

不卖关子，先说下本篇文章最终实现了什么，如果感兴趣再继续往下看。

实现了通过记录如下参数，来进行问题定位，关于每个参数的结构在下面都有介绍。

// 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 包。

支持设置失败时重试，可以自定义重试次数、重试前延迟等待时间、重试的满足条件；
支持设置失败时告警，可以自定义告警渠道（邮件/微信）、告警的满足条件；
支持设置调用链路；

调用示例代码：

// 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 信息。

调用示例代码：

// 原来查询这样写

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-gin-api

巴特西

Go - 实现项目内链路追踪

参数结构

链路 ID

请求信息

响应信息

调用三方接口信息

调试信息

SQL 信息

Redis 信息

请求结果

执行时长

如何收集参数？

无需关心的参数

调用第三方接口的信息

调试信息

SQL 信息

Redis 信息

核心原理是啥？

如何记录参数？

JSON 示例

zap 日志组件

总结

最新文章

热门文章