小技术 | 让 Go 服务 SQL 行为一目了然（上）-六虎

笔者从前分享过两篇文章，分别是根据 GORM V2 和 XORM 在分布式链路追寻上的建设，此后偶然有网友联系笔者进行交流，首要关于项目运用 GORM V1 或者原生 SQL情况下，尽可能少侵入事务代码去做数据库操作的日志输出、错误监控和链路追寻。

本系列文章通过四点内容为一切 Go 事务上的 SQL 操作日志输出、监控和链路追寻问题供给处理思路。

运用 SQLHooks 在 sql.Driver 上挂载钩子函数。
ORM 、SQL 以及 SQLX 的实践。
Prometheus 收集 DB 操作指标。
Opentracing 链路追寻。

本文内容首要为第一步和第二步，后续 Prometheus 和 Opentracing 相关内容日后有机会更新，文章所用到的代码均已开源，有问题能够自行查阅，Github – sqlhooks-example 。

自界说驱动

众所周知 database/sql 原生库供给的是 interface{} 接口界说，在进行数据库操作时一般都是凭借 driver.Driver 和 driver.Conn进行的，关于这部分内容能够阅览 Go 言语设计与完成 – 数据库内容进行了解。

既然如此，咱们只需求在 Diver 和 Conn 上面封装一层就能完成全量 SQL 日志打印和监控。

在尽量避免造轮子的前提下，笔者凭借 Github 开源项目 SQLHooks 进行实践。值得留意的是，如果您需求应用到出产环境，可参考开源项目自行封装。

SQLHooks 的原理非常简略，封装了一个 Driver 完成原生库 driver.Driver，在调用 Exec、Query 以及 Prepare 等操作函数时调用开发者传入的钩子函数。

// Driver implements a database/sql/driver.Driver
type Driver struct {
	driver.Driver
	hooks Hooks
}
// Hooks instances may be passed to Wrap() to define an instrumented driver
type Hooks interface {
	Before(ctx context.Context, query string, args ...interface{}) (context.Context, error)
	After(ctx context.Context, query string, args ...interface{}) (context.Context, error)
}

此时，有开发经历的 Gopher 现已留意到 Hooks 接口的办法都带有 context.Context 参数，大概率现已猜到下文的操作。

以打印完整 SQL 和 Args 参数为例，咱们能够界说一个包含日志打印目标的结构体完成 Hooks 接口。

为了能更好呈现作用，本文的实践中加入了 SQL 耗时，一般该功能是在数据库中完成并呈现给 DBA 人员查询，但咱们开发人员一般也需求该指标用于确定 SQL 质量。

首先咱们界说 zapHook 结构体，该结构体包含一个 zap logger 目标和用于启用 SQL 耗时核算的布尔值。

// make sure zapHook implement all sqlhooks interface.
var _ interface {
	sqlhooks.Hooks
	sqlhooks.OnErrorer
} = (*zapHook)(nil)
// zapHook using zap log sql query and args.
type zapHook struct {
	*zap.Logger
	// 是否打印 SQL 耗时
	IsPrintSQLDuration bool
}
// sqlDurationKey is context.valueCtx Key.
type sqlDurationKey struct{}

接下来咱们需求界说 Before 函数需求做的两件事。

输出实践履行 SQL 的 Query 指令和参数日志。
将履行 SQL 的开端时刻目标注入到上下文。

func buildQueryArgsFields(query string, args ...interface{}) []zap.Field {
	if len(args) == 0 {
		return []zap.Field{zap.String("query", query)}
	}
	return []zap.Field{zap.String("query", query), zap.Any("args", args)}
}
func (z *zapHook) Before(ctx context.Context, query string, args ...interface{}) (context.Context, error) {
	if z == nil || z.Logger == nil {
		return ctx, nil
	}
	z.Info("log before sql exec", buildQueryArgsFields(query, args...)...)
	if z.IsPrintSQLDuration {
		ctx = context.WithValue(ctx, (*sqlDurationKey)(nil), time.Now())
	}
	return ctx, nil
}

依照相同的流程，咱们需求界说 After 函数需求做的流程。

测验从上下文获取履行 SQL 的开端时刻目标。
输出履行 SQL 完毕的 Query 和参数日志（一般仅在 Before 函数输出一次，但本文实践为了作用进行了二次输出）。

func (z *zapHook) After(ctx context.Context, query string, args ...interface{}) (context.Context, error) {
	if z == nil || z.Logger == nil {
		return ctx, nil
	}
	var durationField = zap.Skip()
	if v, ok := ctx.Value((*sqlDurationKey)(nil)).(time.Time); ok {
		durationField = zap.Duration("duration", time.Now().Sub(v))
	}
	z.With(durationField).Info("log after sql exec", buildQueryArgsFields(query, args...)...)
	return ctx, nil
}

咱们还需求完善 OnError 产生错误时的钩子函数，这个函数一般是必要的，咱们希望在 SQL 履行失利后进行日志输出或上报指标和原因。

func (z *zapHook) OnError(_ context.Context, err error, query string, args ...interface{}) error {
	if z == nil || z.Logger == nil {
		return nil
	}
	z.With(zap.Error(err)).Error("log after err happened", buildQueryArgsFields(query, args...)...)
	return nil
}

至此咱们现已完成了 SQLHooks 一切接口的完成，最终一步是运用 SQLHooks 库供给的 Wrap 办法创立新的 Driver 注册到大局驱动上。

// 大部分 MySQL 操作都运用 go-sql-driver 作为驱动.
import (
	"database/sql"
	"github.com/go-sql-driver/mysql"
)
// 覆盖驱动名 mysql 会导致 panic, 因此需求创立新的驱动.
//
// database/sql/sql.go:51
const driverName = "mysql-zap"
func initZapHook(log *zap.Logger) {
	if log == nil {
		log = zap.L()
	}
	hook := &zapHook{Logger: log, IsPrintSQLDuration: true}
	sql.Register(zapDriverName, sqlhooks.Wrap(new(mysql.MySQLDriver), hook))
}

接下来咱们就能够凭借该钩子函数输出悉数 DB 结构生成的 SQL 的日志。

事务实践

在进行本文实践进程前，您需求了解本文根据以下环境进行。

Go 1.17
go-sql-driver v1.6.0
SQLX 1.3.4
GORM 1.22.3
TiDB 5.2.2

接下来将会分成四个环节进行实践。

界说测试表结构和 Go 结构体。
查看 Go 原生 SQL 履行和查询作用。
查看 SQLX 结构履行和查询作用。
查看 GORM 结构履行和查询作用。

界说测试表结构和 Go 结构体

首先笔者手动界说了一个简略的数据库表结构体并创立。

CREATE TABLE `test_table`
(
    `id`        bigint(20) NOT NULL AUTO_INCREMENT,
    `score`     bigint(20) NOT NULL,
    `create_at` timestamp  NOT NULL DEFAULT CURRENT_TIMESTAMP,
    `update_at` timestamp  NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,
    PRIMARY KEY (`id`)
) ENGINE = InnoDB
  DEFAULT CHARSET = utf8mb4
  COLLATE = utf8mb4_bin
  AUTO_INCREMENT = 30001;

接下来需求在 Go 代码中编写对应的结构体，此进程能够通过各类 SQL 转 struct 工具简化。

import "gorm.io/gorm/schema"
// 完成 GORM 表名接口
var _ schema.Tabler = (*testTable)(nil)
type testTable struct {
	ID       uint      `db:"id"`
	Score    int64     `db:"score"`
	CreateAt time.Time `db:"create_at" gorm:"<-:false"`
	UpdateAt time.Time `db:"update_at" gorm:"<-:false"`
}
func (*testTable) TableName() string { return "test_table" }
type testTableSlice []*testTable
// GoString 输出人类看得懂的日志
func (t testTableSlice) GoString() string {
	var output strings.Builder
	for _, v := range t {
		output.WriteString(fmt.Sprintf("- id: %d, score: %d, createAt: %s, updateAt: %s\n", v.ID, v.Score, v.CreateAt.String(), v.UpdateAt.String()))
	}
	return output.String()
}

在编写事务代码之前，咱们需求进行必要的初始化流程。

var ctx = context.Background()
var dsn = os.Getenv("DSN")
func init() {
	initZapHook(setupZapLogging(zap.InfoLevel))
	rand.Seed(time.Now().UnixNano())
}

至此准备作业现已完成，接下来咱们需求依照对应的结构编写事务代码，统一的流程是刺进后查询。

Go 原生库 SQL

原生库 SQL 是 Go 开发常用的数据库操作库。

因为根据原生库的批量刺进需求凭借字符串拼接，为了简化流程，原生库的实践仅展现单个刺进的进程。

// database/sql
func rawSQLExample() {
	log.Println("going using database/sql exec sql")
	// 创立数据库连接目标
	connRaw, err := sql.Open(zapDriverName, dsn)
	if err != nil {
		log.Fatalln(err)
	}
	// 履行刺进操作前需求预处理再履行
	const rawInsertSQL = `INSERT INTO test_table (score) VALUES (?)`
	stmt, err := connRaw.PrepareContext(ctx, rawInsertSQL)
	if err != nil {
		log.Fatalln(err)
	}
	if _, err = stmt.ExecContext(ctx, rand.Int63()); err != nil {
		log.Fatalln(err)
	}
	// 查询操作
	resQuery, err := connRaw.QueryContext(ctx, "SELECT * FROM test_table")
	if err != nil {
		log.Fatalln(err)
	}
	defer func() { _ = resQuery.Close() }()
	var res testTableSlice
	for resQuery.Next() {
		tmp := new(testTable)
		if err = resQuery.Scan(&tmp.ID, &tmp.Score, &tmp.CreateAt, &tmp.UpdateAt); err != nil {
			log.Fatalln(err)
		}
		res = append(res, tmp)
	}
	log.Printf("%#v", res)
}

编写完事务代码之后咱们能够运转单元测试检验作用。

=== RUN   Test_zapHook
2021-11-14T22:00:07.255+0800	INFO	sqlhooks-exmaple/zap_example_test.go:41	going using database/sql exec sql
2021-11-14T22:00:07.256+0800	INFO	sqlhooks-exmaple/zap.go:54	log before sql exec	{"query": "INSERT INTO test_table (score) VALUES (?)", "args": [6720357018880391204]}
2021-11-14T22:00:07.261+0800	INFO	sqlhooks-exmaple/zap.go:72	log after sql exec	{"duration": "4.728028ms", "query": "INSERT INTO test_table (score) VALUES (?)", "args": [6720357018880391204]}
2021-11-14T22:00:07.261+0800	INFO	sqlhooks-exmaple/zap.go:54	log before sql exec	{"query": "SELECT * FROM test_table"}
2021-11-14T22:00:07.262+0800	INFO	sqlhooks-exmaple/zap.go:72	log after sql exec	{"duration": "1.098115ms", "query": "SELECT * FROM test_table"}
2021-11-14T22:00:07.262+0800	INFO	sqlhooks-exmaple/zap_example_test.go:73	- id: 30095, score: 6720357018880391204, createAt: 2021-11-14 22:00:07 +0800 CST, updateAt: 2021-11-14 22:00:07 +0800 CST
--- PASS: Test_zapHook (0.01s)
PASS

从日志输出来看，确实完成了咱们想要的作用 —— 日志输出和 SQL 履行耗时。

SQLX 结构

SQLX 是一款 Go 事务开发进程中比较常见的数据库操作结构，目前 Github 上有 11.1k 的 star。

得益于 SQLX 支撑命名参数，且命名参数支撑切片，笔者能够演示批量刺进的场景。

// jmoiron/sqlx
func sqlxExample() {
	log.Println("going using jmoiron/sqlx exec sql")
	// 根据 SQLX 建立数据库链接
	connSqlx, err := sqlx.ConnectContext(ctx, zapDriverName, dsn)
	if err != nil {
		log.Fatalln(err)
	}
	// 履行刺进操作前需求进行命名参数替换和预处理
	const sqlxNameInsertSQL = `INSERT INTO test_table (score) VALUES (:score)`
	var valuesToInsert = []*testTable{{Score: rand.Int63()}, {Score: rand.Int63()}, {Score: rand.Int63()}}
	newInsertSQL, args, err := sqlx.Named(sqlxNameInsertSQL, valuesToInsert)
	if err != nil {
		log.Fatalln(err)
	}
	stmt, err := connSqlx.PreparexContext(ctx, newInsertSQL)
	if err != nil {
		log.Fatalln(err)
	}
	if _, err = stmt.ExecContext(ctx, args...); err != nil {
		log.Fatalln(err)
	}
	// 查询操作能够凭借 Select 办法 Scan 到对应的结构体切片
	var res testTableSlice
	if err = connSqlx.Select(&res, "SELECT * FROM test_table"); err != nil {
		log.Fatalln(err)
	}
	log.Printf("%#v", res)
}

运转单元测试咱们获得对应的输出作用。

=== RUN   Test_zapHook
2021-11-14T22:24:50.118+0800	INFO	sqlhooks-exmaple/zap_example_test.go:78	going using jmoiron/sqlx exec sql
2021-11-14T22:24:50.119+0800	INFO	sqlhooks-exmaple/zap.go:54	log before sql exec	{"query": "INSERT INTO test_table (score) VALUES (?),(?),(?)", "args": [415829244009450172,3465963981601780078,2197712931404613967]}
2021-11-14T22:24:50.124+0800	INFO	sqlhooks-exmaple/zap.go:72	log after sql exec	{"duration": "4.85822ms", "query": "INSERT INTO test_table (score) VALUES (?),(?),(?)", "args": [415829244009450172,3465963981601780078,2197712931404613967]}
2021-11-14T22:24:50.124+0800	INFO	sqlhooks-exmaple/zap.go:54	log before sql exec	{"query": "SELECT * FROM test_table"}
2021-11-14T22:24:50.125+0800	INFO	sqlhooks-exmaple/zap.go:72	log after sql exec	{"duration": "1.119153ms", "query": "SELECT * FROM test_table"}
2021-11-14T22:24:50.125+0800	INFO	sqlhooks-exmaple/zap_example_test.go:106	- id: 30096, score: 415829244009450172, createAt: 2021-11-14 22:24:50 +0800 CST, updateAt: 2021-11-14 22:24:50 +0800 CST
- id: 30097, score: 3465963981601780078, createAt: 2021-11-14 22:24:50 +0800 CST, updateAt: 2021-11-14 22:24:50 +0800 CST
- id: 30098, score: 2197712931404613967, createAt: 2021-11-14 22:24:50 +0800 CST, updateAt: 2021-11-14 22:24:50 +0800 CST
--- PASS: Test_zapHook (0.01s)

SQLX 结构和原生库 SQL 的输出作用是一样的，同样能够得到履行的 SQL 和耗时。

GORM 结构

高度封装的 GORM 结构获取对应的 SQL 和履行时刻难度高（特别是 V1 版本），而根据驱动的方式能磨平原生库与结构的差异，在数据库操作入口和出口捕捉咱们所需求的 SQL 信息。

留意观察以下代码，咱们只需求在 DB 目标创立时调整参数即能调用想要的 Hooks 钩子函数。

// GORM V2, need to focus driver name is zapDriverName.
func gormExample() {
	log.Println("going using gorm V2 exec sql")
	// 创立 GORM 链接，需求留意修正 DriverName 参数
	dialector := mysql.New(mysql.Config{DSN: dsn, DriverName: zapDriverName})
	// GORM 需求开启 PrepareStmt，不然会报 driver.ErrSkip 错误
	connGorm, err := gorm.Open(dialector, &gorm.Config{PrepareStmt: true})
	if err != nil {
		log.Fatalln(err)
	}
	// 履行刺进操作只需求调用 API，非常方便，但无法直观查看实践生效的 SQL
	valuesToCreate := []*testTable{{Score: rand.Int63()}, {Score: rand.Int63()}, {Score: rand.Int63()}}
	if err = connGorm.CreateInBatches(valuesToCreate, len(valuesToCreate)).Error; err != nil {
		log.Fatalln(err)
	}
	var res testTableSlice
	// 查询也是相同道理，无法直观查看实践生效的 SQL
	if err = connGorm.Find(&res).Error; err != nil {
		log.Fatalln(err)
	}
	log.Printf("%#v", res)
}

运转单元测试，咱们能够得到输出作用。

=== RUN   Test_zapHook
2021-11-14T22:43:02.364+0800	INFO	sqlhooks-exmaple/zap_example_test.go:111	going using gorm V2 exec sql
2021-11-14T22:43:02.365+0800	INFO	sqlhooks-exmaple/zap.go:54	log before sql exec	{"query": "SELECT VERSION()"}
2021-11-14T22:43:02.366+0800	INFO	sqlhooks-exmaple/zap.go:72	log after sql exec	{"duration": "274.358s", "query": "SELECT VERSION()"}
2021-11-14T22:43:02.367+0800	INFO	sqlhooks-exmaple/zap.go:54	log before sql exec	{"query": "INSERT INTO `test_table` (`score`) VALUES (?),(?),(?)", "args": [6926252270182587172,1587531254996719592,6405207277469356629]}
2021-11-14T22:43:02.370+0800	INFO	sqlhooks-exmaple/zap.go:72	log after sql exec	{"duration": "3.442791ms", "query": "INSERT INTO `test_table` (`score`) VALUES (?),(?),(?)", "args": [6926252270182587172,1587531254996719592,6405207277469356629]}
2021-11-14T22:43:02.437+0800	INFO	sqlhooks-exmaple/zap.go:54	log before sql exec	{"query": "SELECT * FROM `test_table`"}
2021-11-14T22:43:02.438+0800	INFO	sqlhooks-exmaple/zap.go:72	log after sql exec	{"duration": "1.187731ms", "query": "SELECT * FROM `test_table`"}
2021-11-14T22:43:02.438+0800	INFO	sqlhooks-exmaple/zap_example_test.go:133	- id: 30099, score: 6926252270182587172, createAt: 2021-11-14 22:43:02 +0800 CST, updateAt: 2021-11-14 22:43:02 +0800 CST
- id: 30100, score: 1587531254996719592, createAt: 2021-11-14 22:43:02 +0800 CST, updateAt: 2021-11-14 22:43:02 +0800 CST
- id: 30101, score: 6405207277469356629, createAt: 2021-11-14 22:43:02 +0800 CST, updateAt: 2021-11-14 22:43:02 +0800 CST
--- PASS: Test_zapHook (0.07s)
PASS

日志输出的作用和预期相同，都能正常输出实践履行的 SQL 和耗时。

值得留意的是，虽然咱们没有编写额定的内容，但 GORM 结构仍然在初始化进程履行了 SELECT VERSION() 指令。

留意事项

笔者认为本文的内容比较基础，能给部分有需求的同学供给处理问题的思路，但仍有需求留意的事项。

本文根据 SQLHooks 开源库进行编写，值得留意的是，在出产环境下，基建工程尽量自行封装或者供给装备开关。
输出还是收集都是开支较大的作业，可供给参数关闭或者调整收集概率。
在条件允许的情况下，核心事务削减或避免运用 ORM，降低人为误操的危险。

非常感谢您的阅览，如果您有更好的想法或问题，欢迎私信笔者。

参考资料

Github – sqlhooks-example
Github – SQLHooks
Go 言语设计与完成 – 数据库
Github – SQLX
GORM

小技术 | 让 Go 服务 SQL 行为一目了然（上）

自界说驱动

事务实践

界说测试表结构和 Go 结构体

Go 原生库 SQL

SQLX 结构

GORM 结构

留意事项

参考资料

作者信息

推广

小技术 | 让 Go 服务 SQL 行为一目了然（上）

自界说驱动

事务实践

界说测试表结构和 Go 结构体

Go 原生库 SQL

SQLX 结构

GORM 结构

留意事项

参考资料

相关文章

GitHub 主页美化 & 显示掘金最近发布文章 Top10 🔥

GLCC/Amazon 扩展DJL-零项目经历

Whistle 开发调试最佳实践

Rust修仙笔记下境界-炼气期

作者信息

推广