如何更好的打印日志

126 天前
 XdpCs

在日常的生产过程中,会出现一些 bug ,导致很难查找问题的所在

想问问各位前辈 有什么打印日志的标准

是否能给予一些例子

谢谢各位大佬

1406 次点击
所在节点    Go 编程语言
6 条回复
vczyh
126 天前
首先分离责任边界,对外提供的接口的入参都打印出来,出现错误的话必须打印出来,可以在出现错误的时候打印,也可以在最高层统一打印,永远不要直接吞掉错误。
kuanat
125 天前
以打印日志的方式来 debug ,在开发阶段和生产阶段是有区别的。正好前两天我在 https://v2ex.com/t/1038327 这个帖子里有个回复,可以参考一下。

以我的经验来看,日志 debug 这个话题表面上看是个技术问题,然而我更倾向于把它们定义为工程问题。把问题聚焦在代码怎么写上面很难形成有效的思路,想明白动机和目标之间的联系,才能得出如何正确实现的方法。



我就针对生产环境日志打印做个补充,这里就拿一般 go 服务器后端的场景来说明。

- 日志采集的方式

一般要么写本地文件,然后有 agent 负责汇总到日志服务器。要么直接根据配置向日志数据库来写。也就是说一般生产环境里日志排错主要靠数据库查询。

- 日志生成方式

上面帖子里有提到,生产环境的日志是“共享”的,也就是说日志主数据库很可能是全链路的信息都在,而某个 go 模块的信息只是一部分。这个主日志里面,多数时间理论上只包含业务信息,无法用于 debug 。

所以在我接触的项目里,会构建 release/debug 两个版本,线上部署 release 版本。当出现故障需要排错的时候,切一部分流量进入 debug 版本,debug 版本单独输出详细日志。这个日志包含程序运行信息,stack trace 等等。

- 日志记录的内容

生产环境排错主要是回答两个问题:首先是判断是不是该模块的错误,其次才是为什么出错。利用日志作为 debug 手段属于某种意义上的“异步”,感到困难的主要原因是,这个异步行为很难在本地开发工作流中复现。

如果能方便且顺利地在本地复现,困难可能就解决了一半。为了达到复现的目的,需要 debug 级日志中一定要包含进入本模块的输入,以及离开本模块的输出。



回到代码的层面,要做的就是把上面的思路具体化。

- 构建测试用例

当拿到输入和输出的时候,就可以在本地开发流程构建测试用例了。考虑到 go 实现的功能模块会涉及其他模块的调用,那就需要以 mock 的方式,直接引入其他模块的输入输出结果。这里就能看出来,debug 级别的日志,一定要包含和其他模块交互的输入输出。

这里顺便一提,mock 实现本地测试应该是开发流程中就要做的。

- 日志可读性

如果 go 实现的模块比较复杂,要记录各种输入输出就需要一定的组织规范,这就是你提到的问题。如果直接回答如何做,可能很难帮助你解决问题。

由于异常分析要在请求层面上,所以要求整个系统必须有统一的 traceID 之类的标志,不然就会可能拿着不匹配的输入与输出做调试。多数时候这个 traceID 是以中间件控制,或者在各个模块之间显式传递,无论哪种实现方式,都一定要有。

大的层面上,一定要记录 stack trace 即调用栈的回溯信息。它的作用是帮助你快速定位出问题的子模块,我个人比较倾向使用的方式类似于 error wrapping 的方式,可以参考 https://go.dev/blog/go1.13-errors 这篇文章。

这样对于错误,可以输出类似于 `调用方法 A ,入参 XXX : 调用方法 B ,入参 XXX : ...` 这样形式的字符串,冒号用于分隔。怎么记录不重要,标准一致即可。如果有需要,可以本地额外做一个更加 verbose 的 debug 版本,利用反射机制输出调用代码的行数等等。(这个事情主要是 API 接口相关的,模块内部流程的底层错误建议 wrap ,到达模块边界只返回定义好的 sentinel 错误。)

对于非错误的情况,一般在每个调用的入口和出口,根据调用的状态来输出不同等级的信息,比如某个方法调用的入口,输出 log.Info("XXX"),如果是走的正常分支,就在出口处再记录 log.Info("XXX"),如果走的是异常分支,可以在出口处记录 log.Warning("XXX")。这样最终会形成类似

```
INFO: 调用 A 开始
INFO: > 调用 B 开始
INFO: >> 调用 C 开始
INFO: << 调用 C 分支 C1
WARN: < 调用 B 分支 B2
INFO: 调用 A 结束
```

这个样子的日志记录,可以肉眼观察也可以利用文本工具来筛选。

这个日志的主要作用是帮助你确定异常发生时,对应的逻辑流程是什么,免去了你动态调试跟踪的麻烦。即便后续需要动态调试,也可以很准确地在目标位置下断点。

- 其他细节

我暂时能想起来一部分,如果以后想起来再补充。

日志层面一定要使用结构化的方式来记录,这样无论是写入数据库,还是查询筛选都会方便很多。

代码层面不要忽略任何错误,所有的错误都要有相应的处理(忽略也是一种处理,但一定要有对忽略错误这个行为的日志记录)。

模块内部对于所有外部输入都做 mock ,以提高测试覆盖率,方便后期 debug 。

这个事情的终极目标就是,出问题的时候,日志数据库筛一下就知道业务层面上是否有异常。有的话,立即切 debug 版本就能复现输入输出。拿到输入输出直接扔给本地 mock 版本,跑一下流程就知道是自己模块的问题,还是涉及其他交互模块的问题。如果确定是自己的问题,看 verbose 日志快速确定是哪个方法哪一行的错误。

写日志本质上就是以上述思路为目标做准备。
gvison
124 天前
把请求经过的整条链路日志打印出来,通过 trace_id 或 request_id 把入参信息、返回信息、错误信息串联起来,通过 id 过滤可以查看整条请求链路日志信息,排查 bug 挺方便。可以参考这里封装的 gin 中间件 https://github.com/zhufuyi/sponge/blob/main/pkg/gin/middleware/logging.go
qloog
98 天前
wusu
91 天前
@qloog 正则可以定义成全局变量,提升一点性能
Charlie17Li
24 天前
@vczyh 一直很纠结,是在出错的地方打印,还是上层打印。在出错的地方打印,有时候链不知道调用链路,在上层打印,链路一长,定位起来也不够直观

这是一个专为移动设备优化的页面(即为了让你能够在 Google 搜索结果里秒开这个页面),如果你希望参与 V2EX 社区的讨论,你可以继续到 V2EX 上打开本讨论主题的完整版本。

https://www.v2ex.com/t/1043663

V2EX 是创意工作者们的社区,是一个分享自己正在做的有趣事物、交流想法,可以遇见新朋友甚至新机会的地方。

V2EX is a community of developers, designers and creative people.

© 2021 V2EX