请教下日志打印的最佳实践

2018-05-24 01:17:04 +08:00
 xrlin

无论是线上还是开发环境,log 打印对排查 bug 都很有帮助,但是这就遇到个问题,如果要打印详细的 log 就会侵入到方法的实现,特别是如果调用链很常的时候,比如

controller -> validator -> serviceA -> serviceB -> model

这时如果要打印出详细的日志就必须在 controller、service、model .... 中都要加上打印语句,这样显得很麻烦,有没有更好的实现方式?虽然可以用类似 AOP 的方法,但是如果要精细一些还是要在方法实现中主动调用。

4304 次点击
所在节点    程序员
15 条回复
kslr
2018-05-24 04:50:52 +08:00
发出事件监听呢
billwsy
2018-05-24 05:43:09 +08:00
glog https://github.com/google/glog 可以在某些时候打印 stack trace
gaoyulong
2018-05-24 07:19:41 +08:00
mark
ppyybb
2018-05-24 08:43:37 +08:00
我在 rails 里面的简易做法是:
抛出异常
打出到 controller 层为止的 stack trace
打出需要的当前环境的状态
严重的发短信报警

另外,你 log 的目的是针对可能出现的异常情况做记录,方便出问题的时候查找。
还是已经发现比较奇怪的现象,但是找不到原因,准备打 log 排查?如果是后者,log 只是临时的,处理好有问题的调用链上的 log,专门写一个 logger 类来打出一整条链上的状态,事后清理即可
ksupertu
2018-05-24 09:18:36 +08:00
sentry 了解一下
jorneyr
2018-05-24 09:54:19 +08:00
很多日志都是根据业务逻辑进行打印,就必须侵入到不同层的代码里。AOP 只能打印一些通用的日志,例如访问方法的顺序,参数,执行的时间等。
hilow
2018-05-24 09:56:37 +08:00
在每个函数中返回 自定义的 *exerror.Error 类型变量。
此 err 变量中包含错误的上下文信息,如 userId, zerror 和 funcName@fileName.go:108 这样的 zcallstack
在调用函数时,如果返回非 nil 的 err,就能打印日志,日志中包含所有上下文信息。
实际业务中在不同代码中调用相同函数,可能出现同样错误,都返回了 err,这时能根据要求灵活决定是否打印出日志。
日志打印格式推荐“结构化日志信息”,比如`level=info msg="Recv RestRequest"` ,主要优点是,方便使用 grep awk 等工具过滤日志,详情参考[logrus]( https://github.com/sirupsen/logrus)
另外每行日志中增加一个`ReqId`,此 ID 全局唯一,用于关联同一会议的 ID

```log
cat log/server.log | grep ExtHwyApi_QLlUyYd9To
time="2018-05-24T09:42:02+08:00" level=info msg="Recv RestRequest" ReqHeader=map[Date:[2018-03-29T09:32:35+08:00] Accept:[application/json]] ReqId="ExtHwyApi_QLlUyYd9To" Url="/ext/api/product"
time="2018-05-24T09:42:02+08:00" level=warning msg="AuthTimeOut Disable" AuthTimeOutSeconds=0 ReqId="ExtHwyApi_QLlUyYd9To"
time="2018-05-24T09:42:03+08:00" level=error msg="RestDispatch Fail" ReqBody="{"seq":"ExtHwyApi_QLlUyYd9To","var":1}}" ReqId="ExtHwyApi_QLlUyYd9To" ResBody="{"Code":"812018","Msg":"发送失败"}" Tag="out_ccm" zcallstack="SendJsonReq@func.go:43 Handler@ext_hwy_api.go:44" zerror="dial tcp 127.0.0.1:5010: connectex: No connection could be made because the target machine actively refused it."
```
xrlin
2018-05-24 11:40:15 +08:00
@ppyybb 异常的话一般都会记录下,就是一些问题追踪比较难以排查,特别是遇到一些不常遇到的问题,这时如果没有记录下日志不好分析。
xrlin
2018-05-24 11:46:39 +08:00
@ppyybb 不过再想想,遇到不是异常而是某些逻辑分支的情况,即便的打上 log,也是设定为 info,在线上也不会启用,遇到问题出现时才启用记录。
lolizeppelin
2018-05-24 12:17:53 +08:00
Python 可以看看 openstack 的做法

配置里可以控制每个模块代码块的日志等级
EmdeBoas
2018-05-24 12:42:28 +08:00
平时都是无脑用 CAT...没想过这个问题..回头好好看看 CAT 里面怎么实现的
ywind
2018-05-24 13:15:31 +08:00
m
zj299792458
2018-05-24 13:23:29 +08:00
我想问问如果日志过多,比如播放视频的每一帧信息都记入日志,微秒级别记录,直接往文件操作符里写会阻塞正常逻辑么?还是一般自己实现 cache ?
yhding
2018-05-24 13:35:08 +08:00
我一直有个想法但是没有具体实现,就是在打印日志的时候写的详细一些,
比如: 文件路径 + 行数 + 想输出的信息.
大佬看如何啊
lxml
2018-12-11 03:56:17 +08:00
@yhding #14 调用 runtime 包就行了,缺点是性能差成狗

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

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

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

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

© 2021 V2EX