小谈日志与其实践

本文首发于泊浮目的专栏： 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）日志来定位问题；

其余

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