使用XORMOpentracing,让你彻彻底底摆脱繁琐的CRUD的阴影,将工作重心转移至业务逻辑

image

使用XORMOpentracing,让你彻彻底底摆脱繁琐的CRUD的阴影,将工作重心转移至业务逻辑

系统环境
go version go1.14.3 windows/amd64
xorm.io/xorm 1.0.3

一、 ⚠️提醒

二、过程

1. 使用Docker启动Opentracing + jaeger服务

使用的镜像:jaegertracing/all-in-one:1.18

Docker命令

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界面,如下所示:

image

至此,以内存作为数据寄存方式的OpenTracing+Jaeger服务成功运行。

这里不详细讲解 Opentracing 的使用,有兴趣的同学可以查看官方技术文档
同时这里搭配的 jaeger 进行使用,方便我们调试和线上小规模部署

2. 安装Xorm、OpenTracing和Jaeger

Xorm - 需要 1.0.2 版本及以上才能支持Hook钩子函数

go get xorm.io/xorm

OpenTracing和Jaeger - 只需要安装Jaeger-Client就会依赖Opentracing

go get github.com/uber/jaeger-client-go

3. 初始化Opentracing –> 通常由服务统一初始化

main.go

package main

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没开启就一定没有结果
			LogSpans:           true,
            // 请一定要注意,LocalAgentHostPort填错了就一定没有结果
			LocalAgentHostPort: "localhost:6831",
		},
	}).NewTracer()
	if err != nil {
		return
	}

	// 设置全局Tracer - 如果不设置将会导致上下文无法生成正确的Span
	opentracing.SetGlobalTracer(tracer)
	return
}

3. 定义Hook钩子结构体

custom_hook.go

package main

type TracingHook struct {
	// 注意Hook伴随DB实例的生命周期,所以我们不能在Hook里面寄存span变量
	// 否则就会发生并发问题
	before func(c *contexts.ContextHook) (context.Context, error)
	after  func(c *contexts.ContextHook) error
}

// xorm的hook接口需要满足BeforeProcess和AfterProcess函数
func (h *TracingHook) BeforeProcess(c *contexts.ContextHook) (context.Context, error) {
	return h.before(c)
}

func (h *TracingHook) AfterProcess(c *contexts.ContextHook) error {
	return h.after(c)
}

// 让编译器知道这个是xorm的Hook,防止编译器无法检查到异常
var _ contexts.Hook = &TracingHook{}

4. 实现钩子函数

custom_hook.go

// 使用新定义类型
// context.WithValue方法中注释写到
// 提供的键需要可比性,而且不能是字符串或者任意内建类型,避免不同包之间
// 调用到相同的上下文Key发生碰撞,context的key具体类型通常为struct{},
// 或者作为外部静态变量(即开头字母为大写),类型应该是一个指针或者interface类型
type xormHookSpan struct{}

var xormHookSpanKey = &xormHookSpan{}

func before(c *contexts.ContextHook) (context.Context, error) {
	// 这里一定要注意,不要拿第二个返回值作为上下文进行替换,而是用自己的key
	span, _ := opentracing.StartSpanFromContext(c.Ctx, "xorm sql execute")
	c.Ctx = context.WithValue(c.Ctx, xormHookSpanKey, span)
	return c.Ctx, nil
}

func after(c *contexts.ContextHook) error {
	// 自己实现opentracing的SpanFromContext方法,断言将interface{}转换成opentracing的span
	sp, ok := c.Ctx.Value(xormHookSpanKey).(opentracing.Span)
	if !ok {
		// 没有则说明没有span
		return nil
	}
	defer sp.Finish()

	// 记录我们需要的内容
	if c.Err != nil {
		sp.LogFields(tracerLog.Object("err", c.Err))
	}

	// 使用xorm的builder将查询语句和参数结合,方便后期调试
	sql, _ := builder.ConvertToBoundSQL(c.SQL, c.Args)

    // 记录
	sp.LogFields(tracerLog.String("SQL", sql))
	sp.LogFields(tracerLog.Object("args", c.Args))
	sp.SetTag("execute_time", c.ExecuteTime)

	return nil
}

5. 把钩子函数挂载在钩子Hook上

custom_hook.go

func NewTracingHook() *TracingHook {
	return &TracingHook{
		before: before,
		after:  after,
	}
}

6. 在xorm引擎初始化时挂载自定义的Hook

main.go

func NewEngineForHook() (engine *xorm.Engine, err error) {
	// XORM创建引擎
	engine, err = xorm.NewEngine("mysql", "root:root@(localhost:3306)/test?charset=utf8mb4")
	if err != nil {
		return
	}

	// 使用我们的钩子函数 <---- 重要
	engine.AddHook(NewTracingHook())
	return
}

四、 单元测试 —> 不会如何使用的请认真看一下

main_test.go

// XORM技术文档范例
type User struct {
	Id   int64
	Name string `xorm:"varchar(25) notnull unique 'usr_name' comment('姓名')"`
}

// 新方式进行上下文注入,要求 xorm 1.0.2版本
func TestNewEngineForHook(t *testing.T) {
	rand.Seed(time.Now().UnixNano())
	// 初始化XORM引擎
	engine, err := NewEngineForHook()
	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: fmt.Sprintf("test-%d", rand.Intn(1<<10))}); err != nil {
		t.Fatal()
	}
}
  1. 再次查看jaeger可以看到一共有三个记录,其中最下面有3个span的trace是我们主动发起数据库操作的记录,上面两个trace是xorm自行发起的数据库操作

image

  1. 点击进入trace,展开子span,我们可以看到xorm执行的SQL语句和参数、执行时间以及所占的比例

image

image

五、 Q&A

1. jaeger没有记录?

  • 如果访问jaeger发现压根没有服务请求jaeger请务必检查初始化opentracing是否成功(特别检查一下LocalAgentHostPort参数是否填写正确)
  • span没有finish

2. 为什么通过日志模块侵入不能实现并发安全?

  • xorm的会话在调用日志使用的是值传递去传递ContextHook,所以不能把span寄存到ContextHook中的上下文Ctx,而是只能暂时寄存在全局日志Logger中,这也导致了日志实例中的span是并发不安全的,高并发情况下会丢失span
  • 日志模块侵入依旧是xorm1.0.2以下的版本最好的侵入方式,但是不推荐

3. 为什么有一些莫名其妙的SQL查询?

  • xorm有时候会根据特殊情况对SQL进行优化,我们可以看到有时候xorm会查询一下表结构,以方便后续的查询

4. 有什么实际用处?

  • 方便业务上线后进行追踪,实际Opentracing的用处就是如此

六、 源码分析(没兴趣可以不看)

1. 注册钩子结构体

xorm -> engine.go

func (engine *Engine) AddHook(hook contexts.Hook) {
	engine.db.AddHook(hook)
}

xorm -> db.go

func (db *DB) AddHook(h ...contexts.Hook) {
	db.hooks.AddHook(h...)
}

xorm -> hook.go

type Hook interface {
	BeforeProcess(c *ContextHook) (context.Context, error)
	AfterProcess(c *ContextHook) error
}

type Hooks struct {
	hooks []Hook
}

func (h *Hooks) AddHook(hooks ...Hook) {
	h.hooks = append(h.hooks, hooks...)
}

我们需要传入一个contexts.Hook,是一个接口类型,我们只需要实现两个方法就能实现这个接口

2. 钩子上下文结构体

xorm -> hook.go

// ContextHook represents a hook context
type ContextHook struct {
    // 开始时间
	start       time.Time
	// 上下文
	Ctx         context.Context
	// SQL语句
	SQL         string        // log content or SQL
	// SQL参数
	Args        []interface{} // if it's a SQL, it's the arguments
	// 查询结果
	Result      sql.Result
	// 执行时间
	ExecuteTime time.Duration
	// 如果发生错误,会赋值
	Err         error // SQL executed error
}

ContextHook结构体作为Hook接口调用函数的入参,包括了我们需要的基本数据

3. 执行SQL语句时调用逻辑

xorm -> db.go

func (db *DB) beforeProcess(c *contexts.ContextHook) (context.Context, error) {
	if db.NeedLogSQL(c.Ctx) {
	    // <-- 重要,这里是将日志上下文转化成值传递
	    // 所以不能修改context.Context的内容
		db.Logger.BeforeSQL(log.LogContext(*c))
	}
	// Hook是指针传递,所以可以修改context.Context的内容
	ctx, err := db.hooks.BeforeProcess(c)
	if err != nil {
		return nil, err
	}
	return ctx, nil
}

func (db *DB) afterProcess(c *contexts.ContextHook) error {
    // 和beforeProcess同理,日志上下文不能修改context.Context的内容
    // 而hook可以
	err := db.hooks.AfterProcess(c)
	if db.NeedLogSQL(c.Ctx) {
		db.Logger.AfterSQL(log.LogContext(*c))
	}
	return err
}
  • 这一段就是实际SQL查询过程中调用日志和Hook的过程,从这里可以非常明显的看到日志模块传入的是值而不是指针,从而导致了我们无法修改日志模块中的上下文实现span的传递,只能利用全局日志实例来传递span,这直接出现了并发安全问题
  • 而Hook的传递使用的是指针传递,将contexts.ContextHook的指针传入钩子函数执行流程,允许我们直接操作Ctx