日志指南

参考:最佳日志实践


前言


几乎所有的应用开发者都知道“用户体验”的重要性,要提升用户体验就离不开一个完备的监控和上报系统,这其中日志(包括Crash上报)是最基本的问题跟踪和解决手段。

日志用来记录用户操作、系统运行状态等,是一个系统的重要组成部分。然而由于日志并非系统核心功能,通常情况下并不受团队的重视。在出现问题需要通过日志来定位时,才发现日志还存在很多问题。

日志作用:
- 好的日志记录系统出现问题时能快速定位
- 可以通过对日志的观察和分析
- 提前发现系统可能的风险
- 避免线上事故的发生


一、日志级别


通常使用的日志库(如log4j, logback 等)

日志基本分为以下几类(从低到高):

VERBOSEThe VERBOSE Level designates finer-grained informational events than the DEBUG

DEBUGThe DEBUG Level designates fine-grained informational events that are most useful to debug an application.

INFOThe INFO level designates informational messages that highlight the progress of the application at coarse-grained level.

WARNThe WARN level designates potentially harmful situations.

ERRORThe ERROR level designates error events that might still allow the application to continue running.

FATALThe FATAL level designates very severe error events that will presumably lead the application to abort.

  • 一个项目各个log级别的定义应该是清楚明确的,是每个开发人员所遵循的;
  • 即使是TRACE或者DEBUG级别的日志,也应该有一定的规范,要保证除了开发人员自己以外,包括测试人员和运维人员都可以方便地通过日志定位问题;
  • 对于日志级别的分类,有以下参考:
1
2
3
4
5
6
7
8
9
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)日志来定位问题;

Rule 1:整个团队(包括运维人员)需要对日志级别有明确的规定,什么日志记入什么级别的日志,什么级别的错误出现要如何处理等


二、对记录的日志要进行更新维护


由于DEBUG(或TRACE)级别的日志对于定位问题至关重要,因此该种日志记录是否完备且不冗余、格式是否规范等也需要花费大量精力来优化。此处有以下几个比较好的实践:

  • 定义好整个团队记录DEBUG(或TRACE)日志的规范,保证每个开发记录的日志格式统一;
  • 整个团队(包括开发,运维和测试)定期对记录的日志内容进行Review;

Rule 2:需要定期对日志内容进行优化更新,目的就是通过日志快速准确的定位问题


三、关于日志分类


日志从功能来说,可分为诊断日志、统计日志、审计日志。

诊断日志, 典型的有:

  • 请求入口和出口
  • 外部服务调用和返回
  • 资源消耗操作: 打开文件等
  • 容错行为: 譬如云硬盘的副本修复操作
  • 程序异常: 譬如数据库无法连接
  • 后台操作:清理程序
  • 启动、关闭、配置加载
  • 抛出异常时,不记录日志

统计日志:

  • 用户访问统计
  • 计费日志(如记录用户使用的网络资源或磁盘占用,格式较为严格,便于统计)

审计日志:

  • 管理操作

    将不同需求的日志记入到不同的日志文件中,可以方便相关问题(管理平台操作审计,用户操作计费等)的处理。针对每一种需求,需要对日志的格式,日志记录的内容等进行特别的记录。

Rule 3:要明确不同日志的用途,对日志内容进行分类


四、日志中不要记录无用信息


例如一些测试的log: log.i(“tag”, “数据加载成功”),可以打印一些比较有实用价值的Log, 例如:
log.i(“tag”, “数据加载成功,数据是:{}”, “XXXX”)

Rule 4: 绝不要打印没有用的日志,防止无用日志淹没重要信息


五、5. 日志记录信息要完整


问题描述:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
NOS提供分块上传的接口,用户可以通过以下的调用序列,来实现一次分块上传的流程:

- InitMultiUpload(生成一个UploadID)
- UploadPart
- UploadPart
- ……
- UploadPart
- CompleteMultiUpload(AbortMultiUpload)

之前在某个产品上线初期,由于其开发人员对NOS的熟悉程度不够等原因。出现过如下问题:客户端常常会收到NoSuchUpload的错误。该错误出现的原因是,用户在未调用InitMultiUpload之前,或者在调用了CompleteMultiUpload(AbortMultiUpload)之后再次调用UploadPart。

然而当我们查日志,希望可以看到该UploadPart请求对哪个UploadID进行操作,该UploadID又对应哪些操作时,却发现我们的日志中没有记录UploadPart请求对应的UploadID。

类似的问题还有很多,很多针对特定请求的日志缺失,导致很多问题无法定位。

因此,需要进一步对日志中需要记录哪些内容进行规定,此处推荐的需要在日志中记录的内容有:

- 在系统启动或初始化时记录重要的系统初始化参数
- 记录系统运行过程中的所有的错误
- 记录系统运行过程中的所有的警告
- 在持久化数据修改时记录修改前和修改后的值
- 记录系统各主要模块之间的请求和响应(如在NOS中的视频处理模块在接收到请求和发送应答时,或者向客户端发送回调请求时)
- 重要的状态变化(如NOS中对系统白名单的修改等)
- 系统中一些长期执行的任务的执行进度

不推荐记录日志的内容有:

  • 函数入口信息 —— 除非该函数入口表示了一个重要事件的开始,或者将该信息记入DEBUG级别日志
  • 文件内容或者一大段消息的内容 —— 如果实在需要记录,则可以截取其中一些重要的信息来记入日志
  • “良性”错误 —— 有时候虽然出现了错误,然而错误处理的流程可以正确解决这种情况,例如插入数据库时有重复的记录,尽管是个错误,然而错误处理流程可以对这种情况进行处理

Rule 5:日志信息要准确全面,能做到仅凭日志就可以定位问题

解决办法:整理所有的请求处理流程,针对每一个操作(去重,分块上传……)打印特定的日志。


六、测试的日志


测试代码(单元测试,接口测试……)的日志同样重要。特别是,当一个测试失败时,可以通过日志很快确定是测试代码有问题,还是系统出现了故障,如果做不到这一点,那就需要优化测试的日志了。

测试日志应该包含以下内容:

  • 测试执行的环境
  • 测试执行前的初始状态
  • 测试的详细步骤
  • 测试和系统的交互信息
  • 测试期望的返回结果
  • 测试实际的返回结果

Rule 6:要以同样严格的要求对待测试程序的日志


七、从问题中完善日志


在线上出现问题的时候,需要尽快发现问题并解决,而同时,需要借此机会好好思考一下当前系统的日志是否合理。需要考虑以下问题:

  • 如果定位问题花费了很长时间,那就说明系统日志还存在问题,需要进一步完善和优化
  • 需要思考是否可以通过优化日志,来提前预判该问题是否可能发生(如某种资源耗尽而导致的错误,可以对资源的使用情况进行记录)

通过系统出现的问题来优化日志,应该是一项长期的实践,不断地从日志发现系统的问题,不断地从系统异常发现日志的问题。

Rule 7:日志的优化是一件持续不断需要投入精力的事,需要不断从错误中学习


八、对日志进行监控报警,比客户先发现系统问题


crash关键字报警:

程序崩溃的时候,会出现crash 字样,可以获取到相关日志,会严重影响用户的实用,可以动态获取崩溃日志

类似的关键字报警还有很多:如对空指针, 数组越界,内存溢出 等等。

Rule 8:对日志进行监控报警,比客户先发现系统问题


九、关于日志格式


日志格式一定要统一,不能任由开发人员的喜好来。举例来说,对于NOS视频截图超时的ERROR日志,有以下几种方式打印:

1
2
3
4
5
6
7
8
第一种:
logger.error(“Gearman timeout exception for request ” + getRequestID() + ” value: ” + value, e);

第二种:
logger.error(“RequestID: ” + getRequestID() + “, Error Message: Gearman timeout exception: ” + e);

第三种:
logger.error(getErrorMessage(getRequestID(), getErrorMessage(), e));

第一种方式打印日志即是开发人员按照自己的喜好来的,这种方法带来的问题是:

  • 系统中日志格式不统一,不利于自动化处理
  • 有些日志可能只有开发人员自己才能看懂
  • 代码规范性不好

而第三种方式,通过一个函数来规范日志格式,所有开发人员便可以通过该接口实现统一的日志。

Rule 9:日志格式要统一规范


十、错误日志输出到不同文件


在性能测试中遇到的另一个问题是,当并发量很大时,可能会有一些请求处理失败(如0.5%),为了对这些错误进行分析,需要去查这些错误请求的日志。而由于这种情况下并发量很大,使得对错误日志的分析变得困难。

这种情况下可以将所有的错误日志同时输出到一个单独的文件之中。

Rule 10:将错误日志输出到一个单独的文件中进行分析


十一、关于日志文件大小


日志文件不宜过大,过大的日志文件对于日志监控,问题定位等都会带来不便。因此需要进行日志文件的切分,日志文件的切分可以通过log4j等日志工具来配置,日志文件应该按天来分割,还是按照小时来分割,应该根据日志量来决定,原则就是方便开发或运维人员能快速查找日志。

为了防止日志文件将整个磁盘空间占满,需要定期对日志文件进行删除。例如,在收到磁盘报警时,可以将两个月以前的日志文件删除。此处比较好的实践是:

  • 将所有日志文件收集起来,这样即使在记录日志的机器上删除,也可以通过收集的日志对之前的问题进行定位;
  • 每天通过定时任务来删除过期日志,如每天在凌晨4点删除60天前的日志

Rule 11:要把日志的大小,如何切分,如何删除等作为规范建立起来


gdky005 wechat
加微信好友,一起交流