一般来说,日志具有以下几个功能:
- 快速定位问题:我们通常会依据自己对业务的理解,在程序中增加相应的日志记录。当程序出现问题时,我们会第一时间想到通过日志,查看当时用户进行了什么操作,有没有出现程序报错等,这也是定位问题原因的关键。有时我们在进行业务数据埋点时,也会使用日志来查看更详细的业务数据信息。
- 便于调试:开发人员在进行应用开发时,都会在测试或本地环境中调试。添加日志可以让你感知到它进入了某个函数,执行了某些行为,甚至进入了代码层级,记录代码判断后的行为。我们一般会将日志设置为调试级别,或者在上线前将它们统一删除。
- 高度定制化:日志是结构化的。同时,我们又可以在代码的任意位置对日志进行编写。无论应用是在执行业务请求,还是在执行定时任务,只要是在程序可执行的代码位置都可以编写日志。
- 信息埋点:我刚才有提到,日志是高度定制化的,所以你可以将自己的业务信息以日志的形式保存起来,比如用户在 21:22 的时候进行了准备支付操作,在 21:23 进行了支付结束操作,这一行为就可以记录下来。
- 追踪数据变化:日志同样可以将数据实时地记录下来,它会比一些统计系统记录得更加详细,因为统计系统一般只会记录某个时间段的信息,而日志可以精确到某个时间点。通过读取这部分数据,我们可以更好地了解系统运行时的状态,可以快速跟踪程序崩溃的原因,跟踪性能下降的问题范围
- 数据分析:基于对信息的埋点,我们可以将收集到的信息统一写入一个文件中。数据分析系统可以定期解析这些日志文件,从而得出每个用户的具体操作,比如大数据分析师可以利用这个分析用户行为,指引下一步的整体战略。
1. 日志级别
日志打印通常有四种级别,从高到低分别是:ERROR、WARN、INFO、DEBUG。
1.1. ERROR
该级别的错误需要马上被处理,当ERROR错误发生时,已经影响了用户的正常访问,是需要马上介入并处理的。常见的ERROR异常有:空指针异常,数据库不可用,服务不可用,关键用例无法继续执行等。
ERROR是错误的意思,但不代表出现异常的地方就该打ERROR。 ERROR是相对程序正确运行来说的,如果出现了ERROR那就代表出问题了,开发人员必须要查一下原因,或许是程序问题,或许是环境问题,或许是理论上不该出错的地方出错了。总之,如果你觉得某个地方出问题时需要解决,就打ERROR,如果不需要解决就不要打ERROR。如,接口入参检查就不应该使用ERROR级别日志,甚至都不应该打印日志,而是直接返回错误码,交由上层调用方处理。否则频繁的告警会使运维,开发对错误告警麻木,无效的告警会将真正有问题的错误淹没掉。
哪些错误应该打印ERROR级别?
- 读写配置文件失败
- 配置信息错误
- 网络断线
- 数据库不可用(这不是绝对的,后面会讲报警升级)
- 所有第三方对接的异常(包括第三方返回错误码)
- 所有影响核心功能使用的异常
1.2. WARN
不应该出现但是不影响程序、当前请求正常运行的异常情况。对于WARN级别的日志,虽然不需要管理员马上处理,但是也需要引起重视。WARN日志有两种级别:一个是解决方案存在明显的问题(例如Try Catch语句中由于不确定会出现什么异常,而用Exception统一捕获抛出的问题),另一个是潜在的问题和建议(例如系统性能可能会伴随着时间的迁移逐渐不能满足服务需要,或者非核心接口的偶尔超时)。应用程序可以容忍这些信息,不过它们应该被及时地检查及修复。
如果WARN出现的过于频繁或次数太多,那就代表你要检查一下程序或环境或依赖程序是否真的出问题了。此时应该监控warn日志的次数,达到阈值告警并处理。
不能使用 error 级别来记录 warning 级别的内容,这会使得不太关键的信息也会在查看故障日志时被筛选出来,导致对故障原因产生误判,浪费大量的时间。
哪些错误应该打印WARN级别?
- 异常:由于在程序运行之前不能明确异常引发的原因,异常只进行了简单的捕获抛出,需要将这种笼统处理的异常打印为WARN格式的日志,提醒管理员干预处理。不过如果是核心业务,则需要打印ERROR级别
- 有容错机制的时候出现的错误情况
- 找不到配置文件,但是系统能自动创建配置文件(或使用默认配置)
- 性能即将接近临界值的时候(也要看是否是核心系统,核心业务,如果是,则需要打印ERROR,报警,并自动或人工扩容)
- 业务异常的记录,危险操作
- 限流,降级,熔断的操作,都需要WARN级别日志打印
- 出于提醒目的的日志。比如2B的业务中,用户数据不完善, 但不至于严重到系统(接口)不可用程度,此时就应该打印warn级别的日志,然后通知业务方进行数据补全。
1.3. INFO
主要用于记录系统运行状态、核心用例执行结果、用户的操作行为等信息。该日志级别,常用于反馈系统当前状态给最终用户。我们一般也是通过这个日志等级完成上面提到的功能,比如信息埋点、追踪数据变化、数据分析等。
我们需要避免把info 级别当作 debug 级别,这样会输出很多没必要的日志内容,导致线上环境产生了大量的垃圾和重复信息,很不便于日志检索。
需要打印的INFO级别的日志:
- 接口请求与响应。通常情况下,无论是dubbo等RPC框架,还是http/https等restful风格的访问,只要涉及到微服务间的访问,都要打印入参与出参
- 一些需要观测执行情况的行为:如定时任务(尤其是分布式任务)等/大批量数据执行进度(批处理)/耗时操作等等
- 不符合业务逻辑预期(尤其核心业务):打印关键的参数,要能从这些参数中清楚地看出,谁的操作与预期不符,为什么与预期不符。并且唯一定位到这条日志,要包含用户id或者流水号
- 系统模块的入口与出口处:可以是重要方法级或模块级,记录它的输入与输出,方便定位
- 非预期执行:为程序在“有可能”执行到的地方打印日志(通常与业务挂钩,打印内容要看得出为什么走到这个分支 )
- switch case语句块中的default
- if…else if…else中很少出现的else情况
- try catch语句块中catch分支。
- 服务状态变化(尽可能记录线索):程序中重要的状态信息的变化应该记录下来,方便查问题时还原现场,推断程序运行过程
- 程序运行耗时:通过它可以跟踪为什么系统响应变慢或者太快。再配合链路追踪系统,可以方便的定位到那个系统哪个方法耗时长
1.4. DEBUG
该级别日志的主要作用是对系统每一步的运行状态进行精确的记录。通过该种日志,可以查看某一个操作每一步的执行过程,可以准确定位是何种操作,何种参数,何种顺序导致了某种错误的发生。可以保证在不重现错误的情况下,也可以通过DEBUG级别的日志记录对问题进行诊断。一般来说,在生产环境中,不会输出该级别的日志。
2. Log4j的8个日志级别
log4j定义了8个级别的log(除去OFF和ALL,可以说分为6个级别),优先级从高到低依次为:OFF、FATAL、ERROR、WARN、INFO、DEBUG、TRACE、 ALL。
2.1. 致命错误「FATAL」
表示需要立即被处理的系统级错误。当该错误发生时,表示服务已经出现了某种程度的不可用,系统管理员需要立即介入。
这属于最严重的日志级别,因此该日志级别必须慎用,如果这种级别的日志经常出现,则该日志也失去了意义。
通常情况下,一个进程的生命周期中应该只记录一次FATAL
级别的日志,即该进程遇到无法恢复的错误而退出时。
当然,如果某个系统的子系统遇到了不可恢复的错误,那该子系统的调用方也可以记入FATAL
级别日志,以便通过日志报警提醒系统管理员修复。
2.2. 错误 「ERROR」
错误日志是用来传递系统或应用程序中出现的各种级别的错误。例如,操作系统在无法同步缓存区到磁盘的时候会生成错误信息。不确定的是,许多错误信息只能给出为什么出错的起点,要寻找出导致错误发生的根本原因还需要进一步分析。
该级别的错误也需要马上被处理,但是紧急程度要低于FATAL
级别。当ERROR错误发生时,已经影响了用户的正常访问。从该意义上来说,实际上ERROR
错误和FATAL
错误对用户的影响是相当的。
FATAL
相当于服务已经挂了,而ERROR
相当于好死不如赖活着,然而活着却无法提供正常的服务,只能不断地打印ERROR
日志。
特别需要注意的是,ERROR
和FATAL
都属于服务器自己的异常,是需要马上得到人工介入并处理的情况。而对于用户自己操作不当,如请求参数错误等等,是绝对不应该记为ERROR
日志的。
2.3. 警告 「WARN」
警告信息是在系统即将丢失东西,而又不影响系统运行下而产生的,例如一个应用程序在没有获得正确数量的参数传递的时候,但是它又能够在没有这些参数的情况下正常运行,这种情况下可能就是记录警告信息提示使用者或者管理员。
该日志表示系统可能出现问题,也可能没有问题,这种情况在例如网络的波动等情况。对于那些目前还不是错误,然而不及时处理也会变为错误的情况,也可以记为WARN
日志,例如一个存储系统的磁盘使用量超过阀值,或者系统中某个用户的存储配额快用完等等。
对于WARN
级别的日志,虽然不需要系统管理员马上处理,也是需要即时查看并处理的。因此此种级别的日志也不应太多,能不打WARN
级别的日志,就尽量不要打。
2.4. 信息 「INFO」
这种类型的信息被设计成告诉用户或者开发者一些没有风险的事情发生了。该种日志记录系统正常运行状态,例如某个子系统的初始化,某个请求的成功执行等等。
通过查看INFO
级别的日志,可以很快地对系统中出现的WARN
,ERROR
,FATAL
错误进行定位。INFO日志不宜过多,通常情况下,INFO
级别的日志应该不大于TRACE
日志的10%。
2.5. 调试 DEBUG or TRACE
软件系统在应用程序代码运行时生成的调式信息,是为了给软件开发人员提供故障检测和定位问题的帮助。
这两种日志具体的规范应该由项目组自己定义,该级别日志的主要作用是对系统每一步的运行状态进行精确的记录。
通过该种日志,可以查看某一个操作每一步的执行过程,可以准确定位是何种操作,何种参数,何种顺序导致了某种错误的发生。可以保证在不重现错误的情况下,也可以通过DEBUG(或TRACE)级别的日志对问题进行诊断。
需要注意的是,DEBUG
日志也需要规范日志格式,应该保证除了记录日志的开发人员自己外,其他的如运维,测试人员等也可以通过DEBUG
(或TRACE
)日志来定位问题。
3. 日志来源
3.1. 终端层
这里的终端层指的是像网页、App、小程序这样的形式。在这一层的所有日志信息都不在我们的服务器端,而是在用户的电脑、手机中。所以我们想要收集的话,一般是通过打点的形式上传到后端服务,再记录下来。
终端层更偏向用户的真实操作行为和一些异常信息的记录,比如用户当前的网络环境、系统状态、手机型号等。通过观察这部分数据,我们可以看出是哪一类用户在操作时容易产生问题,这也更加方便后端和终端的研发人员定位问题。
3.2. 网关层
网关层可以理解为请求被接收之后,最先经过的地方,就像水龙头流出的水会先经过过滤器。最常见的网关层是 Nginx、Kong
- 访问日志:当服务请求到达网关层后,会生成一条日志,记录这个请求从开始接收到最终反向代理的整个流程信息,其中不仅包括请求中的基本信息,如请求 IP、请求 UA,还包含与下游服务相关的 IP 地址、响应时长信息等。同时,这个文件也支持高度定制化。以 Nginx 举例,在 Nginx 中有相当多的环境变量可供选择,这些变量基本覆盖了一个请求生命周期中绝大部分的数据信息。
- 错误日志:记录网关服务在执行过程中出现的问题。不过除非是使用了第三方框架,不然网关层一般不会出现问题。
3.4. 应用层
应用层一般指的是我们业务程序代码的执行位置。我们一般将应用程序分为基于容器托管的应用程序和普通的应用程序。
- 容器启动日志:以 Tomcat 为例,容器的 logs 目录中经常会有“catalina.日期.log”,这部分日志就是 Tomcat 在启动时的日志,它通常会随着控制台日志一同被打印出来。有时候某些程序异常没有被记录,在这里会有显示。
- 请求访问日志:这个和我们刚才在网关层讲的类似,请求访问日志会记录与上游相关的访问时间、访问地址等信息,这里的日志信息和网关层的日志是一一对应的。
- 普通应用程序:其日志文件我们通常会通过框架编写,这里面的写法就相对多样和自由。
3.5. 组件层
像我们经常使用的 MySQL 和 Redis 会产生日志,这些日志就属于组件层。
-
应用运行时产生的日志:一般第三方应用运行时,会输出一些程序执行时的日志内容。当业务程序与组件通信出问题了,我们可以尝试通过这个日志定位,看应用当时是否出现了某些数值的波动或是其他异常。
-
慢查询日志:在一般的数据库类型的应用中,都会有这种日志,用于记录业务系统在进行数据库查询时出现的“查询速度慢”这一现象。如果某个系统中突然出现了大量的“慢查询”,我们就需要监控这个问题,从而获取更加完整的数据库查询语句和来源信息,以便更好地解决问题。
-
审计日志:这个同样适用于数据库。审计日志的主要作用是在进行相关操作的时候,将相关的操作行为记录下来,比如一次数据库查询、一次数据插入。一般这样的数据日志输出量会比较大,对应用的性能有一定的损耗,所以大多数情况下并不会使用。但是像金融行业中有特殊审计场景的需求,审计日志就是必不可少的。
3.6. 基础层
基础层中的日志就更偏向于运维。它的功能更倾向于日志审计、系统问题等,这里我列举一下比较常见的日志:
- 系统日志:一般指的是 Linux 平台中的“/var/log/messages”,这里会记录系统中比较关键的日志。当系统启动了某个程序,或某个程序因为内存过高引发了系统级别的 kill ,就会记录在这个文件中。
- 操作日志:通常 Linux 的日志会通过环境变量定制。通过这个日志,我们可以查询到哪个人在哪个时间点进行了哪些操作,也可以在系统出现异常问题时,查看是谁,因为什么操作而导致的。
4. 参考资料
https://mp.weixin.qq.com/s/H5pt5-v8lvAIYiorExZuFA
https://mp.weixin.qq.com/s/Sa6cv8yBfhC84tinevd_ww
《分布式链路追踪实战 》