工程师在日常开发工作中，更多的编码都是基于现有系统来进行版本迭代。在软件生命周期中，工程维护的比重也往往过半。当我们维护的系统出现问题时，第一时间想到的是查看日志来判断问题原因，这时候日志记录如果没有提供有效的信息，我们能做的只有深度 Code Review，耗时不说且效率低下。 日志 日志记录的好坏直接关系到系统出现问题时定位原因的速度。不少工程中都记录了挺多日志，但在实际问题排查中起到的作用却不大，开发人员还是需要打开 IDE 通过读代码来定位原因。那到底怎样的日志记录更合适呢？我们可以先思考一下这几个问题：
首先，日志需要用来记录用户操作、系统运行状态等信息，是一个系统的重要组成部分。然而由于日志并非系统核心功能，通常情况下并得不到开发人员的重视。在出现问题需要通过日志来定位时，才暴露中现有日志记录的很多不足。 其次，通过对日志的观察和分析，提前发现系统的潜在风险，避免线上事故的发生。 最终目标：线上系统出现问题时，通过日志就可以快速定位原因。 01 日志级别 在 slf4j 官网上可以看到官方对日志级别定义有8种之多： 这里介绍常用日志级别的同时顺带介绍一下不常见的日志级别 FATAL 和 TRACE。 FATAL - 表示需要立即被处理的系统级错误。当该错误发生时，服务已经出现了某种程度的不可用，系统管理员需要立刻处理。这是最严重的日志级别，因此该日志级别要慎用，如果这种级别的日志经常出现，那这日志也失去了意义。通常情况下，一个进程的生命周期中应该只记录一次FATAL级别的日志，即该进程遇到无法恢复的错误而退出时。 TRACE - 这个级别日志在开源框架中还挺常见，和DEBUG级别很像，主要作用是对系统每一步的运行状态进行精确的记录。通过它，可以查看某一个操作每一步的执行过程，精确定位是什么操作，有什么参数，执行顺序是怎样，最终导致了什么错误的发生。同时可以保证在不重现错误的情况下，通过分析 TRACE 级别的日志即可完成对问题的诊断。TRACE 和 DEBUG 用法相似，具体规范应该由团队自己定义，应该保证日志内容除了开发人员以外，运维、测试人员也可以通过 TRACE（或 DEBUG）日志来定位问题。 ERROR - 该级别的错误也需要马上被处理，但是紧急程度要低于FATAL。当ERROR错误发生时，已经影响了正常的业务功能。从这个意义上来说，实际上ERROR错误和FATAL错误对用户的影响是相当的。FATAL相当于整个服务已经挂了，而ERROR表示系统出现错误，但还能提供服务，只能不断地打印ERROR日志。特别需要注意的是，ERROR应当属于服务自己的异常，是需要马上得到人工介入并处理的，如果出现了ERROR日志业务上又不需要处理的就不应该记为ERROR级别，这一点是区别于INFO的明显标识。例如由于用户自己操作不当，传入非法请求参数时，是绝对不应该记为ERROR级别；还有业务处理结果为失败的情况，比如扣款操作遇到用户余额不足，也不能记为ERROR。 INFO - 该种日志记录系统处理业务的概要信息，例如一个业务请求的入参和执行结果以及耗时等等。通过查看INFO级别的日志，可以很快地对系统中业务情况有个基本了解，有哪些业务处理成功哪些又失败了。INFO日志不宜过多，太多的话造成信息干扰不利于查问题； WARN - 该日志表示系统可能出现问题，也可能没有，标识的是系统潜在问题，例如网络抖动造成的rpc调用时长超过阈值。对于那些目前还不是错误，然而不及时处理也会变为错误的情况，也可以记为WARN日志，例如一个存储系统的磁盘使用量超过阀值，或者系统中某个用户的存储配额快用完等等。对于WARN级别的日志，虽然不需要系统管理员马上处理，也是需要即使查看并处理的。因此此种级别的日志也不应太多，能不打WARN级别的日志，就尽量不要打； Rule 1: 整个团队（包括运维）对日志级别有明确规范。 Rule 2: 绝不打印没有用的日志，防止无用日志淹没重要信息。 02 日志维护 通过系统出现的问题来优化日志，是一项长期的实践，不断地从日志发现系统的问题，不断地从系统错误发现日志的问题。
在线上出现问题的时候，需要尽快发现问题并解决；同时，需要借此机会好好思考一下当前系统的日志是否合理，应该考虑以下问题：
通过系统出现的问题来优化日志，是一项长期实践，需要不断从日志中发现系统的问题，同时也需要不断从系统异常中发现日志的问题。 Rule 3: 定期对日志内容进行优化更新。 03 日志格式 日志格式一定要统一，不能任由开发人员的喜好来。系统中日志格式不统一，不利于自动化处理。不要出现个性化的日志，否则可能只有开发人员自己才能看懂。比如 logback 中 pattern 的格式，以及日志的切分轮转策略，团队内应该有统一的标准。 这么做的好处很明显：团队内任何一个人甚至团队以外的人看到这段错误日志时，都能根据记录的有效信息来帮助快速定位问题。 Rule 4: 把日志的格式、大小，切分轮转策略等作为规范建立起 来。 实践 这里介绍一下账户团队在工程维护中对日志实践的一些经验。 原先日志文件有3个：info.log, error.log, sql.log，日志按天轮转保留 3 天，info、error 记录混乱没有明显区别。这里来几个教科书级别的错误示范，贴几段遗留 INFO 级别日志。
看完这些，手中 40 米的大刀已经饥渴难耐。 线上出现问题时，光是寻找日志中的“蛛丝马迹”就花去不少时间，还是得靠 Code Review 来解决。开发环境联调，系统之间 rpc 调用没有日志记录，出了问题也不知道哪个环节出错。 针对上面这些情况，是时候做一些改变了，经过团队商议，对日志做了一些改造，重点解决2个问题：
01 日志分类 info.log：业务关键步骤信息。 error.log：业务发生的错误以及堆栈信息。 sql_info.log：超过10ms的SQL调用。 api_info.log：api调用的关键信息。 rpc_info.log：rpc调用的信息。 这里说下 api_info.log、rpc_info.log，这会是分布式系统中相互调用的关键凭证，里面记录了这些信息：
和运维团队沟通后，统一了 logback pattern 配置: 张同学：这里说的 traceId 是个啥？ traceId 的作用是把分散在各个日志文件中的日志信息都串起来，即一个请求产生的所有日志都有同一个唯一的 traceId，这样在ELK中查询日志时，把 traceId 作为查询条件一步就把这次请求的所有日志都查出来。同时 traceId 作为响应参数之一，便于系统间排查问题。
李同学：traceId 需要侵入线程上下文，在不对业务代码做修改的情况下，有办法实现吗？ 当然是有的，在 Controller 的 AOP 中使用 slf4j MDC 把 traceId 放到线程上下文，对业务编码无入侵。traceId 的生成策略，可以有很多选择，只要在当天的日志索引中唯一即可，并没有太强的要求，账户团队最后使用的是毫秒时间戳 + 幂等ID + 6位随机数。
有了 traceId 之后，通过日志定位问题就只有2步：
监控、报警 最后介绍一下达达运维团队提供基于日志监控的实时报警系统。
上面提到对于 ERROR 级别的日志，需要立即介入处理，所以这是日志中的重点监控对象。这套架构中 Filebeat 负责把日志实时采集到监控系统中用以分析，监控系统同时提供多种灵活的报警策略，支持邮件、短信、电话等多种报警形式。 监控报警的场景不仅限于ERROR级别，我们通过监控 INFO 级别日志可以发现一些系统的潜在风险，比如中间件或者 rpc 调用时长超过 100ms，在1分钟内出现超过 20 次，需要报警提醒。我们可以根据业务特点，和运维一块设定灵活的报警策略。 总结 为了实现仅通过日志信息就能定位问题的最终目标，更为了有效提高工程质量，我们最后再回顾一下日志记录的几个标准操作。
|
|
|
