日志种类

软件记录日志非常重要，公司已积累了非常多的日志输出经验，也制定了不少的规范。通常会把业务软件系统的日志分为如下几种：

用于软件问题定界定位的日志：

• 调试日志：其目的是为了快速定位问题的根源，主要记录程序的执行轨迹，充当软件的调试器。
• 运行日志：其目的是为了跟踪程序的指标变化，主要记录程序各种关键指标数据统计，运行环境数据。
• 接口日志：其目的是为了快速对问题边界排查，主要记录接口的输入信息，以及处理结果。

用于用户行为安全审计的日志：

• 操作日志：其目的是为了跟踪用户操作安全审计，主要记录用户操作行为轨迹，操作什么资源内容，其结果是什么。
• 安全日志：其目的是为了跟踪用户安全变更审计，主要记录用户的登录录出事件，权限修改等安全事件或行为。

日志问题

对于安全审计日志，使用者主要是审计人员，所以一般都会经常严格的设计，采用结构化的信息，日志的有效性不会差到哪里去。

现在大都采用微服务开发框架，框架会对内嵌支持接口日志，输出用作服务间接口消息跟踪。但用于定位的调试日志与运行日志却是经常是被遗忘的角落，几乎完全依赖开发人员的经验与能力，很少有设计，日志风格与内容也是千差万别。

我们经常发现代码中充斥着大量日志打印代码，也经常出现日志泛滥与风暴，出现问题时却发现他们并没有给我们带来期望的价值。代码中打印日志是非常讲究技巧，如何正确地打印日志，提升软件的可维护性？

级别问题

日志通常有会使用四种级别，从高到低分别是：ERROR、WARN、INFO、DEBUG。

问题一：INFO与DEBUG如何区分？大概有90%的程序员都不太注意日志的级别，都是用一个级别来记录日志，通常不是INFO就是DEBUG。

• DEBUG：主要是记录程序的执行过程，一般会记录各层次的对象中的操作名称，操作的参数，执行的分支等，什么原因导致错误的发现。在不重现错误的情况下，可以通过DEBUG级别的日志记录对问题进行诊断。由于DEBUG级别的日志记录过细，这种级别的日志很容易出现日志泛滥，在生产环境中一般不会开启。所以个人觉得，对于业务系统中DEBUG级别的日志记录意义不是太大。而是对业务系统中接口处理定义明确的错误码，通过接口日志中记录的错误码来对问题进行诊断。在记录DEBUG日志时要先想想它是否能帮我带来收益，并不是记录越细越好。大量地输出无效日志，不利于系统性能提升，也不利于快速定位错误点，最后也不会有人去看它。

• INFO：主要是记录系统中系统操作行为、关键资源的变化等，并且这种操作通常不是非常频繁的，它常用于反馈系统当前状态给最终用户。由于INFO通常会在生产环境中开启，在记录INFO日志时，一定要想想它是否影响性能，是否能快速找到它。

  • 系统操作行为：如开启/销毁线程，打开/关闭连接，定时任务触发等
  • 资源或状态变化：系统初始化成功，关键资源的统计信息
  • 非预期执行：为程序在“有可能”执行到的地方打印日志，如switch case语句块中的default
  • 耗时的业务处理：如批处理，IO操作。输出他们运行耗时，大数据量的执行进度等

问题二：ERROR与WARN如何区分？

• WARN：出现WARN日志的地方，可能不会影响程序继续执行后续的逻辑，更多是一种重要提示需要引起重视。程序可以容忍这些信息，不过它们应该被及时地检查及修复。打印WARN日志典型有如下场景：

  • 潜在的问题和建议：如用户密码不足够安全，存在潜在的风险；系统参数未正确指定，采用系统默认值；系统性能处理导致服务降级等等
  • 存在明显问题但未影响系统：如当前数据不可用使用缓存数据；删除临时文件失败后面统一清理；调用服务接口失败正在重试等等
  • 存在危险的操作：如错误的密码登录；出现未允许的操作；正在删除重要的资源。

• ERROR：主要是记录发生了严重的错误，这种错误会导致检验用户体验，导致关键路径不能继续执行，甚至导致系统完全不可用：

  • 系统启动失败
  • 关键资源加载失败
  • 数据库连接失败
  • 关键资源清理失败
  • 业务处理逻辑错误
  • 调用外部系统接口返回失败

ERROR与WARN处理经验：

• ERROR：并不是所有出现异常的地方都要打ERROR，如果你觉得某个地方出问题时需要解决，就打ERROR，如果不需要解决就不要打ERROR。ERROR是相对程序正确运行来说的，如果出现了ERROR那就代表出问题了，开发人员必须要查一下原因，或许是程序问题，或许是环境问题，或许是理论上不该出错的地方出错了。
  • 举例：如果有一个接口。调用者传过来的参数不在你的接受范围内，在这种情况下你不能打ERROR，因为传什么值是用户决定的，并不影响程序正确运行。
• WARN：出现了不影响程序正确运行的问题，WARN也是问题但不影响程序正常运行，如果WARN出现的过于频繁或次数太多，那就说明你要检查一下程序或环境或依赖程序是否真的出问题了。
  • 举例：服务接口调用超时打印WARN，如果此类WARN出现极其频繁，那可能对端服务可能直接出问题了。

有些日志规范还定义了FATAL与EMERGENCY级别，他们都比ERROR严重，严重级别是EMERGENCY小于FALAL。

• EMERGENCY：问题是突发并紧急的，如系统达到最大负载。
• FATAL：问题是致命的，如数据库连接失败导致系统完全不可用。

出现FATAL与EMERGENCY应该是向告警系统发现告警，通知管理员及时处理。

内容问题

日志需要打印什么内容，日志应该是结构化的。日志框架已解决了时间、进程ID、线程ID、级别、模块等通用信息，但日志内容却没有严格限制。日志内容应该考虑是可读性与可分析性，符合人的理解。

• 日志格式：采用 主语+谓语+宾语+状语 的格式，日志打印应该遵从人类的自然语言:
• 主语：会话的发起者
• 谓语：将要具体进行什么样的操作
• 宾语：行为对象
• 状语：行为产生的结果
• 分析性：各个字段可以加入分隔符，使用分隔符使每个字段都能够清晰识别
• 可读性：使用[]进行参数变量隔离，这样的格式写法，对于排查问题更有帮助（如是否存在空白字符）
• 可读性：尽可能不要只打印标识，而是也要打印相应的名称、描述等。如不应该只打印错误码标识，而是要打印错误码对应的错误名称与描述，一个错误码标识只是一个数字，不查手册根本不知代表什么
• 可读性：不打无用的、无意义、不完全的日志，例如不是打印 “Unknown message type”，而是打印 “Unknown message type，type= , supported types=[A,B,C]”
• 安全性：避免在日志中输出一些敏感信息，例如密码与Key等；同时对于用户输入的内容打印到日志中要考虑日志注入风险

性能问题

日志写到文件还是数据库，都需要消耗IO资源。适当的控制日志的输出也有利于提高程序的性能。

• 禁止字符串拼接：使用字符串拼接的方式打印日志，可读性、可维护性都比较差
• 必要的级别判断：INFO与DEBUG级别的日志输出，必须使用条件输出形式或者使用占位符的方式
• 禁止循环打印：大循环中逐行打印影响性能，而是考虑循环外汇总打印
• 适当地打印堆栈：预期会被正常处理的异常，仅需要打印基本信息留作记录，不需要去打印异常堆栈信息，使用堆栈的跟踪是一个巨大的开销，要谨慎使用
• 避免一条日志过大：当处理列表、数组类数据时，避免输出所有内容，而是打印处理的条数或者关键信息（如对象标识列表）
• 日志本地不落盘：一般日志是输出到文件，会产生IO操作，而文件IO通常阻塞，适当考虑日志本地不落盘，直接通过网络IO输出到日志系统
• 日志异步输出：对于非常频繁的日志，可以考虑采用进程内队列或进程内队列异步输出到日志系统

重复问题

像我司规范了文章开头说的多种日志类型，实际上见过代码中大量在一处打印不同的日志问题。日志非常重要，但我们还是有一些技术手段来避免重复打印日志的代码，日志的重复出现的问题。

• 重复输出到不同文件：一条日志重复输出到不同的文件中，如像Java中log4j配置文件中，可以设置additivity=false
• 重复输出到不同类型：能在接口日志中打印的就不要在调试日志中打印，日志关联借助外部日志分析工具，而不是在代码中打印两次
• 不层次重复打印日志：比如下层catch异常时打印日志，异常继续往上抛，在上层catch又打印日志。对于异常处理建议是统一拦截打印日志
• 重复的日志打印代码：比如接口入口与出口打印日志，以及各处catch异常打印日志，不是要每处代码点打印而是可以借助AOP、拦截器等机制统一处理

在java体系的语言中，解决代码重复的主要技术有：

• AOP：定义切入点，在方法执行之前与之后打印日志
• Filter：实现一个Filter类，在Filter的doFilter方法中执行前后的日志打印
• Interceptor：自定义注解，实现HandlerInterceptor，在preHandle与postHandle根据注解输出日志

日志工具

工欲善其事，必先利其器。在java体系中，slf4j是最好的日志API:

• slf4j提供 {} 占位符，不仅提升日志代码的可读性，而且减少字符串拼接
• slf4j是门面模式，统一API，后端可以对接多种日志输出框架，如log4j2，logback

日志框架应该可以扩展与过滤：

• 对敏感信息进行过滤，如密码，卡号等
• 防止日志注入，对日志内容过滤与检查
• 支持对接不同的日志系统，日志不落盘

结语

日志写好其实不难，只要我们站在日志使用者角度多思考。日志也应该像代码一样易于阅读和理解，正确的日志级别让日志更容易使用。在日志输出技巧上可以使用AOP/Filter/Interceptor等机制集中统一输出，减少相似日志代码。