小谈日志与其实践

本文首发于泊浮目的专栏:https://segmentfault.com/blog...

前言

前阵子在论坛上看到一个问题,大致的意思就是日志该怎么打?或者说是,我们应该在日志中打印出哪些内容?

看了该问题,笔者真是有所感慨:从实习到现在,从接的外包小项目到企业级应用,从觉得日志没什么软用到在客户的环境中排bug在日志中看到蛛丝马迹。不得不说,日志真是太重要了。

什么是日志

日志文件是用于记录系统操作事件的记录文件或文件集合,是一个软件系统的重要组成部分。一般良好的日志可以帮助我们:

  • 了解项目的运行状态
  • 发现潜在的性能问题
  • 快速定位故障所在
  • 价值化(大数据分析等)
  • .....

日志的分类

就功能来说,我们一般分为诊断日志、审计日志、统计日志。

诊断日志

一般诊断日志包含的信息最为全面,包括但不限于:

  • Request && Response
  • 系统操作行为:读写文件、定时任务等
  • 异常行为:不可容错与容错行为
  • 第三方服务的调用

审计日志

记录账户对资源的操作行为。比起诊断日志,可能更加方便普通人的阅读,运营、运维同志们的福利。

统计日志

  • 用户访问统计:浏览、日活、IP、上传下载的数据量
  • 计费日志(常见于公有、私有云中)

日志中该记录什么

先来看看一段ZStack中的日志

2017-09-04 13:37:45,509 TRACE [CloudBusImpl2] {} [msg send]: {"org.zstack.header.host.APIDeleteHostMsg":{"uuid":"e36525b2fbe9429093450b72a4552656","deleteMode":"Permissive","session":{"uuid":"a7c068a7d3fd41388994e4b413cf4f7d"},"timeout":-1,"headers":{"correlationId":"f1ad7d11a73f472ca5dc2ea003f16006","replyTo":"zstack.message.cloudbus.bbaaa63f1b4d4b0cb96e452bf68eaccf","noReply":"false","schema":{},"task-context":{}},"id":"f1ad7d11a73f472ca5dc2ea003f16006","serviceId":"api.portal","createdTime":1504417065507}}

我们可以看到精确的时间,以及日志级别,日志调用者及其行为,以及参数。其中correlationId就是我们常说的RequestID。

RequestID:我们通常用RequestID来对请求进行唯一的标记,目的是可以通过RequestID将一个请求在系统中的执行过程串联起来,这在分布式系统中的威力是巨大的。该RequestID通常会随着响应返回给调用者,如果调用出现问题,调用者也可以通过提供RequestID帮助服务提供者定位问题。以Java为例,生成方法可以考虑如下:
public static String getUuid() {
      return UUID.randomUUID().toString().replace("-", "");
}
ps:去掉-是为了更方便的copy-paste。

这样我们便可以利用这个线索在日志中快速的找出问题啦。同时,我们也可以根据自己的需求来放入时间戳、业务属性等来组成RequestID

除之前提到的该记录的日志

  • Request && Response
  • 系统操作行为:读写文件、定时任务等
  • 异常行为:不可容错与容错行为(比如分布式系统中的心跳机制,请记录尝试的次数)
  • 第三方服务的调用
  • 还有:

    • 很少出现的else情况
    • 非预期执行
    • 批量插入操作记录
    • 服务状态变化(尽有可能记录线索)

我们也要去掉那些多余的日志,比如:

  • 明明可以一条输出却多条输出(无论从阅读还是性能上来看都不是较为好的选择)
  • 为调试而添加的临时日志
  • 预期会被正常处理的异常,却打出堆栈
  • 等...

关于日志级别

我们通常使用的日志库,将日志基本分为以下几类(从高到低):

  • FATAL – The FATAL level designates very severe error events that will presumably lead the application to abort.
  • ERROR – The ERROR level designates error events that might still allow the application to continue running.
  • WARN – The WARN level designates potentially harmful situations.
  • INFO – The INFO level designates informational messages that highlight the progress of the application at coarse-grained level.
  • DEBUG – The DEBUG Level designates fine-grained informational events that are most useful to debug an application.
  • TRACE – The TRACE Level designates finer-grained informational events than the
参考帖子:https://stackoverflow.com/que...

对于日志级别的分类,有以下参考:

FATAL

表示需要立即被处理的系统级错误。当该错误发生时,表示服务已经出现了某种程度的不可用,系统管理员需要立即介入。这属于最严重的日志级别,因此该日志级别必须慎用,如果这种级别的日志经常出现,则该日志也失去了意义。通常情况下,一个进程的生命周期中应该只记录一次FATAL级别的日志,即该进程遇到无法恢复的错误而退出时。当然,如果某个系统的子系统遇到了不可恢复的错误,那该子系统的调用方也可以记入FATAL级别日志,以便通过日志报警提醒系统管理员修复;

ERROR

该级别的错误也需要马上被处理,但是紧急程度要低于FATAL级别。当ERROR错误发生时,已经影响了用户的正常访问。从该意义上来说,实际上ERROR错误和FATAL错误对用户的影响是相当的。FATAL相当于服务已经挂了,而ERROR相当于好死不如赖活着,然而活着却无法提供正常的服务,只能不断地打印ERROR日志。特别需要注意的是,ERROR和FATAL都属于服务器自己的异常,是需要马上得到人工介入并处理的。而对于用户自己操作不当,如请求参数错误等等,是绝对不应该记为ERROR日志的;

WARN

该日志表示系统可能出现问题,也可能没有,这种情况如网络的波动等。对于那些目前还不是错误,然而不及时处理也会变为错误的情况,也可以记为WARN日志,例如一个存储系统的磁盘使用量超过阀值,或者系统中某个用户的存储配额快用完等等。对于WARN级别的日志,虽然不需要系统管理员马上处理,也是需要及时查看并处理的。因此此种级别的日志也不应太多,能不打WARN级别的日志,就尽量不要打;

INFO

该种日志记录系统的正常运行状态,例如某个子系统的初始化,某个请求的成功执行等等。通过查看INFO级别的日志,可以很快地对系统中出现的 WARN,ERROR,FATAL错误进行定位。INFO日志不宜过多,通常情况下,INFO级别的日志应该不大于TRACE日志的10%;

DEBUG or TRACE

这两种日志具体的规范应该由项目组自己定义,该级别日志的主要作用是对系统每一步的运行状态进行精确的记录。通过该种日志,可以查看某一个操作每一步的执 行过程,可以准确定位是何种操作,何种参数,何种顺序导致了某种错误的发生。可以保证在不重现错误的情况下,也可以通过DEBUG(或TRACE)级别的日志对问题进行诊断。需要注意的是,DEBUG日志也需要规范日志格式,应该保证除了记录日志的开发人员自己外,其他的如运维,测试人员等也可以通过 DEBUG(或TRACE)日志来定位问题;

其他

  • 注意制定规范,而不是让开发者随意打日志。对于日志的等级选择也要注意。
  • 注意日志的切片设置,以免文件过大不方便操作。
  • 过期的日志定期清理。
阅读 1.9k

推荐阅读
泊浮说
用户专栏

作者是个热爱分享交流的人,所以有了这个专栏。你的点赞是我最大的更新动力。

56 人关注
45 篇文章
专栏主页
目录