Gorm慢查詢、SQL日志與Go項目日志的整合與串聯
如果僅集成到這個程度,功能開發完全沒有問題,但如果你還要長期維護項目的話,那么問題可大了去了。
原因是,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級別的日志。