# Golang XORM搭配OpenTracing+Jaeger链路监控让SQL执行一览无遗（附源码）
> - [xorm 是一个简单而强大的Go语言ORM库. 通过它可以使数据库操作非常简便。](https://gitea.com/xorm/xorm)
> - [OpenTracing API 分布式追踪，也称为分布式请求追踪，是一种用于分析和监视应用程序的方法，特别是那些使用微服务体系结构构建的应用程序，IT和DevOps团队可以使用分布式追踪来监视应用程序](https://zhuanlan.zhihu.com/p/83654617)
系统环境
```
go version go1.14.3 windows/amd64
```
[⭐ 项目Gitee源码](https://gitee.com/avtion/xormWithTracing)
## 一、Docker运行JaegerTracing-All-In-One镜像
Docker命令
```bash
docker run -d --name jaeger -e COLLECTOR_ZIPKIN_HTTP_PORT=9411 -p 5775:5775/udp -p 6831:6831/udp -p 6832:6832/udp -p 5778:5778 -p 16686:16686 -p 14268:14268 -p 14250:14250 -p 9411:9411 jaegertracing/all-in-one:1.18
```
浏览器访问`localhost:16686`，可以看到`JaegerUI`界面，如下所示：
至此，以`内存`作为数据寄存方式的`OpenTracing+Jaeger`服务成功运行。
## 二、GoModule安装Xorm、OpenTracing和Jaeger
Xorm - 需要 `1.0` 版本及以上才能支持传递`Context上下文`
```bash
go get xorm.io/xorm
```
OpenTracing和Jaeger - 只需要安装`Jaeger-Client`就会依赖`Opentracing`
```bash
go get github.com/uber/jaeger-client-go
```
## 三、初始化Opentracing和Jaeger
```go
func initJaeger() (closer io.Closer, err error) {
// 根据配置初始化Tracer 返回Closer
tracer, closer, err := (&config.Configuration{
ServiceName: "xormWithTracing",
Disabled: false,
Sampler: &config.SamplerConfig{
Type: jaeger.SamplerTypeConst,
// param的值在0到1之间，设置为1则将所有的Operation输出到Reporter
Param: 1,
},
Reporter: &config.ReporterConfig{
LogSpans: true,
LocalAgentHostPort: "localhost:6831",
},
}).NewTracer()
if err != nil {
return
}
// 设置全局Tracer - 如果不设置将会导致上下文无法生成正确的Span
opentracing.SetGlobalTracer(tracer)
return
}
```
单元测试结果
## 四、通过日志模块将链路监控侵入到XORM执行逻辑中
1. `XORM`通过其中Log包里面的`ContextLogger`接口定义了它需要的日志实例是怎么样的，我们可以在外部实现该接口就可以将`链路监控`的逻辑侵入到`XORM`的执行过程
```go
// xorm.io\xorm@v1.0.2\log
// ContextLogger represents a logger interface with context
type ContextLogger interface {
SQLLogger
Debugf(format string, v ...interface{})
Errorf(format string, v ...interface{})
Infof(format string, v ...interface{})
Warnf(format string, v ...interface{})
Level() LogLevel
SetLevel(l LogLevel)
ShowSQL(show ...bool)
IsShowSQL() bool
}
```
2. 实现接口的代码比较长，这里只截取重要部分，如果有需要可以到源码中查看
```go
// ---> 请注意import
// 因为我们需要多个名为Log的包
// 所以我们需要手动重命名
import (
"fmt"
_ "github.com/go-sql-driver/mysql"
"github.com/opentracing/opentracing-go"
tracerLog "github.com/opentracing/opentracing-go/log"
"github.com/uber/jaeger-client-go"
"github.com/uber/jaeger-client-go/config"
"github.com/uber/jaeger-client-go/log/zap"
zap2 "go.uber.org/zap"
"io"
"xorm.io/xorm"
xormLog "xorm.io/xorm/log"
)
type CustomCtxLogger struct {
logger *zap.Logger
level xormLog.LogLevel
showSQL bool
// ---> 这里span是从上下文中创建的
// 我们不能将创建的span写回到上下文
// 所以只能在Logger中维护一个span
span opentracing.Span
}
// BeforeSQL implements ContextLogger
func (l *CustomCtxLogger) BeforeSQL(ctx xormLog.LogContext) {
// ----> 重头戏在这里，需要从Context上下文中创建一个新的Span来对SQL执行进行链路监控
l.span, _ = opentracing.StartSpanFromContext(ctx.Ctx, "XORM SQL Execute")
}
// AfterSQL implements ContextLogger
func (l *CustomCtxLogger) AfterSQL(ctx xormLog.LogContext) {
// defer结束掉span
defer l.span.Finish()
// 原本的SimpleLogger里面会获取一次SessionId
var sessionPart string
v := ctx.Ctx.Value("__xorm_session_id")
if key, ok := v.(string); ok {
sessionPart = fmt.Sprintf(" [%s]", key)
l.span.LogFields(tracerLog.String("session_id", sessionPart))
}
// 将Ctx中全部的信息写入到Span中
l.span.LogFields(tracerLog.String("SQL", ctx.SQL))
l.span.LogFields(tracerLog.Object("args", ctx.Args))
l.span.SetTag("execute_time", ctx.ExecuteTime)
if ctx.ExecuteTime > 0 {
l.logger.Infof("[SQL]%s %s %v - %v", sessionPart, ctx.SQL, ctx.Args, ctx.ExecuteTime)
} else {
l.logger.Infof("[SQL]%s %s %v", sessionPart, ctx.SQL, ctx.Args)
}
}
// 下面还有一些比较简单的接口实现，有兴趣的可以看源码
```
3. 重写XORM引擎创建方法
```go
func NewEngine() (engine *xorm.Engine, err error) {
// XORM创建引擎
engine, err = xorm.NewEngine("mysql", "test:test@/test?charset=utf8mb4")
if err != nil {
return
}
// 创建自定义的日志实例
_l, err := zap2.NewDevelopment()
if err != nil {
return
}
// 将日志实例设置到XORM的引擎中
engine.SetLogger(&CustomCtxLogger{
logger: zap.NewLogger(_l),
level: xormLog.LOG_DEBUG,
showSQL: true,
span: nil,
})
return
}
```
## 六、单元测试
单元测试代码
```go
// XORM技术文档范例
type User struct {
Id int64
Name string `xorm:"varchar(25) notnull unique 'usr_name' comment('姓名')"`
}
func TestNewEngine(t *testing.T) {
// 初始化XORM引擎
engine, err := NewEngine()
if err != nil {
t.Fatal(err)
}
// 初始化Tracer
closer, err := initJaeger()
if err != nil {
t.Fatal(err)
}
defer closer.Close()
// 生成新的Span - 注意将span结束掉，不然无法发送对应的结果
span := opentracing.StartSpan("xorm sync")
defer span.Finish()
// 把生成的Root Span写入到Context上下文，获取一个子Context
ctx := opentracing.ContextWithSpan(context.Background(), span)
// 将子上下文传入Session
session := engine.Context(ctx)
// Sync2同步表结构
if err := session.Sync2(&User{}); err != nil {
t.Fatal(err)
}
// 插入一条数据
if _, err := session.InsertOne(&User{Name: "test"}); err != nil {
t.Fatal()
}
}
```
最终执行结果如下
```bash
2020-06-15T23:49:12.888+0800 INFO zap/logger.go:38 [SQL] SELECT `TABLE_NAME`, `ENGINE`, `AUTO_INCREMENT`, `TABLE_COMMENT` from `INFORMATION_SCHEMA`.`TABLES` WHERE `TABLE_SCHEMA`=? AND (`ENGINE`='MyISAM' OR `ENGINE` = 'InnoDB' OR `ENGINE` = 'TokuDB') [test] - 7.0021ms
2020-06-15T23:49:13.633+0800 INFO zap/logger.go:38 [SQL] CREATE TABLE IF NOT EXISTS `user` (`id` BIGINT(20) PRIMARY KEY AUTO_INCREMENT NOT NULL, `usr_name` VARCHAR(25) NOT NULL COMMENT '姓名') DEFAULT CHARSET utf8mb4 [] - 730.5132ms
2020-06-15T23:49:14.252+0800 INFO zap/logger.go:38 [SQL] CREATE UNIQUE INDEX `UQE_user_usr_name` ON `user` (`usr_name`) [] - 619.0328ms
2020-06-15T23:49:14.367+0800 INFO zap/logger.go:38 [SQL] INSERT INTO `user` (`usr_name`) VALUES (?) [test] - 115.1608ms
```
使用`JaegerUI`查看链路追踪的结果，可以清晰的看到每一条SQL语句执行的顺序、时间、内容、参数以及在整个Session所占的比例，有效提高我们在企业项目中分析项目的短板
有疑问加站长微信联系（非本文作者）
