gorm的日志模块源码解析

2019年4月1日 291点热度 0人点赞 0条评论

如何让gorm的日志按照我的格式进行输出

这个问题是《如何为gorm日志加traceId》之后,一个群里的朋友问我的。如何让gorm的sql日志不打印到控制台,而打印到自己的日志文件中去。正好我实现了这个功能,就记录一下,并且再把gorm的logger这个线捋一下。

首先我写了一个demo来实现设置我自己的Logger。其实非常简单,只要实现print方法就行了。

 1package main
2
3import (
4    "fmt"
5    "github.com/jinzhu/gorm"
6    _ "github.com/jinzhu/gorm/dialects/mysql"
7    "log"
8)
9
10type T struct {
11    Id int `gorm:"id"`
12    A int `gorm:"a"`
13    B int `gorm:"b"`
14}
15
16func (T) TableName() string {
17    return "t"
18}
19
20type MyLogger struct {
21}
22
23func (logger *MyLogger) Print(values ...interface{}) {
24    var (
25        level           = values[0]
26        source          = values[1]
27    )
28
29    if level == "sql" {
30        sql := values[3].(string)
31        log.Println(sql, level, source)
32    } else {
33        log.Println(values)
34    }
35}
36
37
38
39func main() {
40    db, _ := gorm.Open("mysql""root:123456@(192.168.33.10:3306)/mysqldemo?charset=utf8&parseTime=True&loc=Local")
41    defer db.Close()
42
43    logger := &MyLogger{}
44
45    db.LogMode(true)
46
47    db.SetLogger(logger)
48
49    first := T{}
50    err := db.Find(&first, "id=1").Error
51    if err != nil {
52        panic(err)
53    }
54
55    fmt.Println(first)
56}

这里的mylogger就是实现了gorm.logger接口。

输出就是按照我logger的输出打印出来了

12019/04/02 09:11:16 SELECT * FROM `t`  WHERE (id=1sql /Users/yejianfeng/Documents/gopath/src/gorm-log/main.go:50
2{1 1 1}

但是这里有个有点奇怪地方,就是这个Print方法里面的values貌似是有隐含内容的,里面的隐含内容有哪些呢?需要追着看下去。

sql的请求怎么进入到Print中的?

我们在db.Find之前只调用过gorm.Open,db.LogMode,db.SetLogger。后面两个函数的逻辑又是极其简单,我们看到Open里面。

重点在这里:

1db = &DB{
2    db:        dbSQL,
3    logger:    defaultLogger,
4    callbacks: DefaultCallback,
5    dialect:   newDialect(dialect, dbSQL),
6}

这里的 callbacks 默认是 DefaultCallback。

 1var DefaultCallback = &Callback{}
2
3type Callback struct {
4    creates    []*func(scope *Scope)
5    updates    []*func(scope *Scope)
6    deletes    []*func(scope *Scope)
7    queries    []*func(scope *Scope)
8    rowQueries []*func(scope *Scope)
9    processors []*CallbackProcessor
10}
11

我们这里看到的DefaultCallback是空的,但是实际上,它并不是空的,在callback_query.go这个文件中有个隐藏的init()函数

1func init() {
2    DefaultCallback.Query().Register("gorm:query", queryCallback)
3    DefaultCallback.Query().Register("gorm:preload", preloadCallback)
4    DefaultCallback.Query().Register("gorm:after_query", afterQueryCallback)
5}

这个init的函数往DefaultCallback.queries里面注册了三个回调函数,queryCallback,preloadCallback,afterQueryCallback

然后再结合回db.Find的方法

1func (s *DB) Find(out interface{}, where ...interface{}) *DB {
2    return s.NewScope(out).inlineCondition(where...).callCallbacks(s.parent.callbacks.queries).db
3}

我们看到最终执行的 callCallbacks(s.parent.callbacks.queries) 就是将这三个方法 queryCallback,preloadCallback,afterQueryCallback 逐一调用。

很明显,这三个方法中,和我们有关系的就是queryCallback方法。

1func queryCallback(scope *Scope) {
2    ...
3
4    defer scope.trace(NowFunc())
5    ...
6}

这里有个赤裸裸的scope.trace方法

 1func (scope *Scope) trace(t time.Time) {
2    if len(scope.SQL) > 0 {
3        scope.db.slog(scope.SQL, t, scope.SQLVars...)
4    }
5}
6
7func (s *DB) slog(sql string, t time.Time, vars ...interface{}) {
8    if s.logMode == detailedLogMode {
9        s.print("sql", fileWithLineNum(), NowFunc().Sub(t), sql, vars, s.RowsAffected)
10    }
11}
12
13func (s *DB) print(v ...interface{}) {
14    s.logger.Print(v...)
15}

找到了,这里的调用链路大概如下:scope.db.slog->db.print->db.logger.Print

这个db.logger就是前面使用SetLogger设置为MyLogger的地方了。

欣赏下这里的print这行:

1s.print("sql", fileWithLineNum(), NowFunc().Sub(t), sqlvarss.RowsAffected)

第一个参数为 level,表示这个是个什么请求(有sql和log两种类型)

第二个参数为打印sql的代码行号,如/Users/yejianfeng/Documents/gopath/src/gorm-log/main.go:50,

第三个参数是执行时间戳

第四个参数是sql语句

第五个参数是如果有预处理,请求参数

第六个参数是这个sql影响的行数。

好了,这个逻辑圈画完了。对照我们前面的MyLogger的Print,我们要取出什么就记录什么就行了。

 1type MyLogger struct {
2}
3
4func (logger *MyLogger) Print(values ...interface{}) {
5    var (
6        level           = values[0]
7        source          = values[1]
8    )
9
10    if level == "sql" {
11        sql := values[3].(string)
12        log.Println(sql, level, source)
13    } else {
14        log.Println(values)
15    }
16}

总结

从gorm的log也能大概窥探出gorm的代码架构设计了。它的几个结构是核心,DB, Scope, 在Scope中,会注册各种回调方法,creates,updates, querys等,在诸如Find等函数触发了回调调用的时候,才去和真是的DB进行交互。至于日志,就埋藏在这些回调函数之中。

所以《如何为gorm日志加traceId》中如果需要在gorm中增加一个traceId,做不到的原因就是这个gorm.logger没有实现SetContext方法,并且在打印的时候没有将Context输出到Print的参数中。所以除非修改源码中调用db.slog的地方,否则无能为力。

图片

图片

Hi,我是轩脉刃,一个名不见经传码农,体制内的小愤青,躁动的骚年,2019年想坚持写一些学习/工作/思考笔记,谓之倒逼学习。欢迎关注个人公众号:轩脉刃的刀光剑影。

MORE | 更多原创文章

 gin框架使用注意事项

② 测试用例是开发人员最后一块遮羞布

③ mariaDB vs mysql的区别

④ 一次composer错误使用引发的思考

⑤ colly源码学习

⑥ 使用chan的时候选择对象还是指针

37000gorm的日志模块源码解析

这个人很懒,什么都没留下

文章评论