最轻量方式是在业务层用 time.Now() + defer 封装 Query/Exec 等调用,避免拼接完整 SQL 防泄密;sqlx 可包装方法加计时,gorm v2+ 应实现 logger.Interface 的 Trace 方法获取真实耗时。

怎么给 database/sql 查询加执行时间日志
Go 标准库的 database/sql 本身不暴露查询耗时,得靠 sql.Driver 层或中间件式包装。最轻量且可控的方式是用 sql.Register 注册一个带计时逻辑的驱动代理,或者更推荐:在业务层统一用 sql.Conn 或 sql.Tx 执行前打点。
实操建议:
立即学习“go语言免费学习笔记(深入)”;
- 不要动
sql.Open返回的*sql.DB,它只是连接池抽象;真正要监控的是每次Query、Exec、QueryRow这些方法调用 - 用
time.Now()+defer包一层封装函数,比如logQuery(ctx, "SELECT * FROM users WHERE id = ?", id) - 避免在日志里拼接完整 SQL(尤其含参数),防止敏感信息泄露;用占位符 + 参数类型/长度代替,如
"SELECT ... WHERE id = ? (int64)"
sqlx 或 gorm 里怎么拿到真实执行耗时
第三方库通常把底层 database/sql 调用包得更深,直接 hook driver.Stmt 不现实。它们一般提供钩子(hook)或可插拔的日志器接口。
实操建议:
立即学习“go语言免费学习笔记(深入)”;
-
sqlx没内置耗时统计,但你可以包装sqlx.DB的Queryx等方法,自己加计时逻辑;注意别漏掉Get、Select这些快捷方法 -
gormv2+ 支持logger.Interface,实现LogMode和Trace方法即可捕获开始/结束时间;关键是要检查ctx是否带context.WithTimeout,否则耗时可能包含等待上下文超时的时间 - 别信
gorm.Config.Logger默认输出的 “duration” 字段——那是从 prepare 到 scan 完毕的总时间,不含网络往返和锁等待,和 MySQL 的Slow_log对不上
为什么 SHOW PROCESSLIST 看到的 Time 和应用日志差很多
MySQL 的 Time 列表示线程空闲或等待锁的时间,不是 SQL 执行耗时;而 Go 应用日志里测的是从 db.Query 调用到 rows.Close() 或结果解析完成的整个周期,两者根本不在同一维度。
常见错误现象:
- 应用日志显示 50ms,但
PROCESSLIST显示Time=0→ 实际查询很快,但 Go 层在做大量 struct scan 或 JSON marshal - 应用日志 2s,
PROCESSLISTTime却是 1800 → 说明连接被复用,前面某条语句卡住(如没 close rows),当前查询在排队 - 用
SET profiling = 1查到单条语句 10ms,但 Go 日志记了 300ms → 大概率是连接池阻塞,db.Query在等空闲连接
监控上线后必须关掉的三个默认行为
本地调试时开着的耗时日志,上线不关会吃 CPU、撑大日志体积、暴露 SQL 结构,甚至拖慢 DB 连接复用效率。
实操建议:
立即学习“go语言免费学习笔记(深入)”;
- 禁用所有
fmt.Printf/log.Println形式的裸日志;改用结构化日志(如zerolog)并按 level 控制,debug级才打耗时 - 关闭
gorm的Config.LogMode(gorm.LoggerInfo),生产环境只设Warn或Error - 别在
http.Handler中对每个请求都db.Stats()——DBStats是原子读,但高频调用仍会竞争,想看连接池状态应该定时采样,不是 per-request
真正难的不是记录时间,而是区分清楚:这是网络延迟?SQL 执行慢?Go 层反序列化慢?还是连接池配置太小导致排队?每种情况对应的排查路径和修复方式完全不同,别让日志格式统一就误以为原因也统一。











