小技术 | Go 基于原生库驱动 Driver 输出 SQL 日志 / 监控 / 链路追踪方案（上）

Go 基于原生库驱动 Driver 输出 SQL 日志方案（上）

笔者曾经分享过两篇文章，分别是基于 GORM V2 和 XORM 在分布式链路追踪上的建设，此后偶尔有网友联系笔者进行交流，主要围绕项目使用 GORM V1 或者原生 SQL的情况下，在尽可能少侵入业务代码的情况下做数据库操作的日志输出、错误监控和链路追踪。

本系列文章通过四点内容为所有 Go 业务上的 SQL 操作日志输出、监控和链路追踪问题提供解决思路。

1. 利用 SQLHooks 在 sql.Driver 上挂载钩子函数。
2. ORM 、SQL 以及 SQLX 的实践。
3. Prometheus 采集 DB 操作指标。
4. 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 函数需要做的两件事。

1. 输出实际执行 SQL 的 Query 命令和参数日志。
2. 将执行 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 函数需要做的流程。

1. 尝试从上下文获取执行 SQL 的开始时间对象。
2. 输出执行 SQL 完毕的 Query 和参数日志（通常仅在 Before 函数输出一次，但本文实践为了效果进行了二次输出）。

func (z *zapHook) After(ctx context.Context, query string, args ...interface{
   }) (context.Context, error) {
   
	if z == nil