Golang XORM搭配OpenTracing+Jaeger链路监控让SQL执行一览无遗（附源码）

go version go1.14.3 windows/amd64

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

go get xorm.io/xorm

go get github.com/uber/jaeger-client-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.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
}

// ---> 请注意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)
	}
}

// 下面还有一些比较简单的接口实现，有兴趣的可以看源码

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
}

// 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()
	}
}

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