原因是,GORM产生的SQL记录、慢查询、以及数据库错误都是通过GORM自身的GormLogger写到日志的,而且GormLogger默认是写到标准输出的。。。而不是项目本身的日志文件里,这样一来如果真的是SQL错误、慢查询等导致的Bug,你只能知道发生Error了,但是在项目日志里却找不到Error的明细,那你解决BUG就只能靠猜和试啦。
图片
所以这节内容我们介绍怎么把GORM日志和项目日志整合到一起,让你拥有下面这样的SQL详细信息
{
"level": "debug",
"ts": "2024-10-09T17:09:07.603+0800",
"msg": "SQL DEBUG",
"sql": "INSERT INTO `orders` (`user_id`,`bill_money`,`order_no`,`state`,`is_del`,`created_at`,`updated_at`) VALUES (123453453,20,'20240627596615375920904456',1,0,'2024-10-09 17:09:07.586','2024-10-09 17:09:07.586')",
"rows": 1,
"dur(ms)": 53,
"traceid": "19d822280c64c5ed",
"spanid": "450ccc402492ed45",
"pspanid": "",
"file": "gormlog.go",
"line": 49
}
支持慢查询、SQL错误的详细记录,在开发环境还会增加SQL DEBUG输出把执行的SQL语句输出到日志文件和控制台,方便在开发阶段进行调试和验证。
我们同样会为GORM日志注入追踪ID,把它们归因到关联的请求上下文中去。这样一旦发生数据库相关的错误,我们可以通过监控主动发现、使用错误日志中的追踪ID还能把整个请求相关的日志都检索出来,查问题也会轻松很多。
加入项目后访问https://github.com/go-study-lab/go-mall/compare/c6...c7 能查看我们在项目中定制化GORM的整个过程
图片
Gorm Logger Interface
GORM 允许我们自定义Logger把它执行的数据库记录、产生的错误等都记录到项目自身的日志文件中去,
V1版本的GROM的 logger 接口长这个样子,仅仅提供了一个Print方法,Print方法的参数都是 create、updates、query 这些方法的回调中传递过去的,我们并没有办法传递Context。
type logger interface {
Print(v ...interface{})
}
所以前几年的项目流行使用GLS -- Goroutine Local Storage,因为官方不推荐也不认可GLS这个概念,GLS的实现都是第三方库,前几年我之前公司项目自己封装的Logger里就大量使用 jtolio/gls 这个库实现的GLS。
后来做新项目时我曾经还想偷懒直接使用之前公司的Logger,结果发现Go 1.19 版本以上 jtolio/gls 这个库就不能用了。
jtolio/gls 仓库地址: https://github.com/jtolio/gls
好在GORM在V2 版本的Logger 中增加了Context 回调的能力,这样就能把执行SQL时的上下文信息也记录到日志中来,这点在V1 版本是做不到的。
在GORM V2 中它新增了以下Logger 接口 logger.Interface:
type Interface interface {
LogMode(LogLevel) Interface
Info(context.Context, string, ...interface{})
Warn(context.Context, string, ...interface{})
Error(context.Context, string, ...interface{})
Trace(ctx context.Context, begin time.Time, fc func() (sql string, rowsAffected int64), err error)
}
每个方法都有应用的上下文Context参数传递进来,还专门提供了Trace方法让我们实现,供我们实现查询的SQL语句和消耗时间的记录。
接下来我们开始自定义GORM Logger,其中使用上我们前面已经封装好的项目的日志门面,通过日志门面实现把GORM日志和项目日志记录到同一个地方。
实现GormLogger 把GORM日志整合到项目日志
现在我们在项目的 dal/dao 目录下新建gormlog.go 文件,并添加以下代码。
type GormLogger struct {
SlowThreshold time.Duration
}
func NewGormLogger() *GormLogger {
return &GormLogger{
SlowThreshold: 500 * time.Millisecond,
}
新建GormLogger类型,在类型中的字段 SlowThreshold 用于设置慢查询的门槛,我们在这里设置超过500ms 就是慢查询,如果需要按环境定制化, 就把这个做成配置项放到配置文件中去。
接下来用GormLogger 实现上面GORM的logger.Interface 中定义的所有方法:
func (l *GormLogger) LogMode(lev gormLogger.LogLevel) gormLogger.Interface {
return &GormLogger{}
}
func (l *GormLogger) Info(ctx context.Context, msg string, data ...interface{}) {
logger.New(ctx).Info(msg, "data", data)
}
func (l *GormLogger) Warn(ctx context.Context, msg string, data ...interface{}) {
logger.New(ctx).Error(msg, "data", data)
}
func (l *GormLogger) Error(ctx context.Context, msg string, data ...interface{}) {
logger.New(ctx).Error(msg, "data", data)
}
func (l *GormLogger) Trace(ctx context.Context, begin time.Time, fc func() (sql string, rowsAffected int64), err error) {
// 获取运行时间
duration := time.Since(begin).Milliseconds()
// 获取 SQL 语句和返回条数
sql, rows := fc()
// Gorm 错误时记录错误日志
if err != nil {
logger.New(ctx).Error("SQL ERROR", "sql", sql, "rows", rows, "dur(ms)", duration)
}
// 慢查询日志
if duration > l.SlowThreshold.Milliseconds() {
logger.New(ctx).Warn("SQL SLOW", "sql", sql, "rows", rows, "dur(ms)", duration)
} else {
logger.New(ctx).Debug("SQL DEBUG", "sql", sql, "rows", rows, "dur(ms)", duration)
}
}
注意因为GORM的logger包跟我们自己的日志门面 logger 包名称冲突了,所以在导入包的时候要给它设置gormLogger这个别名。
上面的实现主要的逻辑是对Trace方法的重写,GORM在执行SQL回调Trace方法时,会把执行开始的时间、执行的SQL、返回的函数以及执行中的错误告诉我们。如果执行中发生错误就记录错误日志,如果消耗时间超过我们约定的500ms就记一条Warn级别的日志。