go-admin框架分析（3）—日志系统

代码地址，logger分支：https://gitee.com/lsjWeiYi/go-admin/tree/logger/

go-admin的日志系统看起来很详细，真的是整个流程的每个过程都有记录，而且他贯穿了整个框架，它封装了非常多的模块。里面都和日志系统强耦合。
优点：

1. 丰富的日志，对复杂系统的运维非常有帮助。
2. 开发人员无需关注http请求和数据库操作的日志记录，只需要关注业务
3. 对于分布式系统，能够做到同一请求的日志唯一ID追踪。

缺点：

1. 耦合在整个框架中，无法单独剥离下来
2. 也许会占用系统的资源（未验证）

日志系统项目的核心内容，但是go-admin将其贯穿全程，所以这里先把日志系统给分析清楚，后面的功能都对其有耦合。

logger 模块

为了效果明显，先将日志的配置修改未记录到文件：

  logger:
    # 日志存放路径
    path: temp/logs
    # 日志输出，file：文件，default：命令行，其他：命令行
    stdout: file #输出到文件
    # 日志等级, trace, debug, info, warn, error, fatal
    level: info
    # 数据库日志开关
    enableddb: false

然后启动项目后，他就会在temp/logs目录创建一个日志文件“2022-02-23.log”

我们先不启用它的日志模块，运行系统，发现并没有日志记录。我们打开swagger，发起一个get请求：

1. 在我们没有在代码中显式做日志记录的情况下，并没有日志记录到文件中。
2. 我们在代码中显式调用日志记录，可以发现，日志文件中记录了日志：

import "github.com/go-admin-team/go-admin-core/logger"

// 只提取了相关代码
name := c.DefaultQuery("name", "默认值")
logger.Info(name)

2022-02-23 09:31:15.554+0800 file:apis/health.go:23 level:info 默认值

这里就是我们在第二篇提到过，找不到哪里可以完全去掉它的日志模块，因为很明显的，我在配置文件中删掉日志的配置，就会报错。

而我们前面所说的日志系统，是系统的隐式日志，记录的是http请求和数据库操作记录。这些过程不是业务中记录的。是框架自己记录的。下面我们启用：

进入swagger，发现它就记录了不少日志：

2022-02-23 09:36:21.943+0800 file:middleware/logger.go:88 latencyTime:0s level:info method:GET statusCode:200 uri:/swagger/index.html x-request-id:c503e88a-9f2b-4604-b780-1cf296035dd3 
2022-02-23 09:36:22.005+0800 file:middleware/logger.go:88 latencyTime:999.7µs level:info method:GET statusCode:200 uri:/swagger/swagger-ui-standalone-preset.js x-request-id:2138c91f-ef82-4855-af0c-7633e9d58cc8 
2022-02-23 09:36:22.005+0800 file:middleware/logger.go:88 latencyTime:999.7µs level:info method:GET statusCode:200 uri:/swagger/swagger-ui.css x-request-id:018804aa-4277-477f-a85f-5f8b33ecc6bb 
2022-02-23 09:36:22.007+0800 file:middleware/logger.go:88 latencyTime:2.4296ms level:info method:GET statusCode:200 uri:/swagger/swagger-ui-bundle.js x-request-id:c9b43b6a-7d32-4b09-a8c6-2b4abefe14ab 
2022-02-23 09:36:22.312+0800 file:middleware/logger.go:88 latencyTime:0s level:info method:GET statusCode:200 uri:/swagger/favicon-16x16.png x-request-id:b13961dc-6aed-47d2-8294-5daf90faef80 
2022-02-23 09:36:22.312+0800 file:middleware/logger.go:88 latencyTime:373.6µs level:info method:GET statusCode:200 uri:/swagger/doc.json x-request-id:d2f8a3ec-0e67-44b1-ad4f-e0d616386b13 

可以看到，日志的信息非常详细。就是一个普通的请求都记录下来了。我们再发起同样的get请求：

2022-02-23 09:39:07.677+0800 file:apis/health.go:23 latencyTime:0s level:info method:GET statusCode:200 uri:/swagger/favicon-16x16.png x-request-id:b13961dc-6aed-47d2-8294-5daf90faef80 默认值
2022-02-23 09:39:07.677+0800 file:middleware/logger.go:88 latencyTime:0s level:info method:GET statusCode:200 uri:/v1/health x-request-id:77172d62-b760-45ee-95d0-c0babe1bc3f9

可以看到记录了两条日志

1. 第一条是我们代码显式调用的，可以发现都有"默认值"这三个字，但是记录的就比原来详细了非常多
2. 第二条应该就是系统默认记录的信息

因为这是正常的请求，没有具体的日志信息，如果有error报错的话，日志里也会显示出来。

PS:这里为简化模块，我删掉了一些暂时不需要的记录信息。

你以为到这里结束了，并没有。。。

生成Request-Id

分析代码发现代码还实现了个生成Request-Id的中间件，但是现在日志明明就有x-request-id了呀，怎么还需要，反正启用看看效果咯。
启用后，再看日志，诶，是有变化哦：

2022-02-23 10:10:32.998+0800 X-Request-Id:e7ad0ab0-d619-492a-849e-d2402a310bbc file:middleware/logger.go:88 latencyTime:0s level:info method:GET statusCode:200 uri:/swagger/index.html 
2022-02-23 10:10:33.036+0800 X-Request-Id:22672be9-983f-4f44-911d-f1de71f748d2 file:middleware/logger.go:88 latencyTime:1.9961ms level:info method:GET statusCode:200 uri:/swagger/swagger-ui.css 
2022-02-23 10:10:33.040+0800 X-Request-Id:c3c99d09-30e2-4549-8886-6ce18898e9be file:middleware/logger.go:88 latencyTime:2.8242ms level:info method:GET statusCode:200 uri:/swagger/swagger-ui-standalone-preset.js 
2022-02-23 10:10:33.043+0800 X-Request-Id:b343e788-e3c1-4a5a-934b-7742f8712d07 file:middleware/logger.go:88 latencyTime:4.2873ms level:info method:GET statusCode:200 uri:/swagger/swagger-ui-bundle.js 
2022-02-23 10:10:33.330+0800 X-Request-Id:0ed9cc72-1bad-48d1-b545-a81d27118044 file:middleware/logger.go:88 latencyTime:0s level:info method:GET statusCode:200 uri:/swagger/favicon-16x16.png 
2022-02-23 10:10:33.330+0800 X-Request-Id:3255964f-1fb2-4236-a3b6-f2d4edbff28d file:middleware/logger.go:88 latencyTime:873.7µs level:info method:GET statusCode:200 uri:/swagger/doc.json 

X-Request-Id到前面来了，变大写开头了，其他好像没啥不一样。。。不管他，总之应该是有用的，没有深入去看源码了。

到这里，还没结束。。

_go-admin-logger-request

代码中还一起启用了这个日志相关的中间件，也不知道干啥用，先启用看看：
好家伙，这个再启用之后，发现日志回到刚启用日志模块那会一样了，很神奇哈，所以这两个东西到底是干嘛的呢。纳闷，暂时没看明白源码的逻辑。放着先把，以后有进展了再补充。

代码改动

首先呢，要明白，前面提到的这些模块，都是中间件来的，那么，中间件的初始化，前面介绍过，就是放在“common/middleweware/init.go”里面：

func InitMiddleware(r *gin.Engine) {
	// 添加 requestID
	r.Use(RequestId(pkg.TrafficKey)) // 新增
	// 添加 go-admin-logger-request
	r.Use(api.SetRequestLogger) // 新增
	// 日志处理
	r.Use(LoggerToFile()) // 新增
	
	// 跨域处理
	r.Use(Options)
	// Secure is a middleware function that appends security
	r.Use(Secure)
}

加了三个中间件，然后添加了下面这些代码：

等有时间，有需要了，再来分析该代码。