日志打印规范

青旅半醒 2022-12-24 12:53 177阅读 0赞

正文在下面，先打个广告：  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2ZneWlidXBp_size_16_color_FFFFFF_t_70]

### 文章目录 ###

*  打印日志的目的
 *  日志级别
 *   *  ERROR
     *  WARN
     *  INFO
     *  DEBUG
 *  如何打印日志
 *   *  打印日志的位置
     *  打印输出哪些内容
 *  日志框架
 *  告警
 *   *  告警分级
     *  谁来处理告警
 *  拾遗
 *   *  空指针异常
     *  入参校验
 *  安全
 *  分布式链路追踪
 *  spring boot 全局统一日志打印
 *  spring boot 2.1学习笔记【十九】使用spring validation实现全局参数校验
 *  案例

> 灵魂之问：撸了那么多年代码，你真的会打日志吗？

# 打印日志的目的 #

不仅是初学者，很多老码农也不能很好的打印日志（**注意 : 技术大佬不是本文的目标读者**），本质的原因是没有意识到为什么要打印日志，打印日志的目的是什么，这里我就为大家介绍一下。

*  最重要的原则：在确保日志数量有限的情况下，可以`快速定位问题`。你仔细想想，在你遇到问题的时候，尤其是生产环境，是不是经常无法快速定位问题，明明打印了日志，却没有上下文，不知道哪个请求，哪个用户，输入参数是什么，然后只能去跟领导说：我要多打一些日志，发布一些才能定位问题。
 *  `跟踪应用的BUG/警告`。日志可以帮助开发者和软件测试人员快速跟踪程序崩溃的原因  
    \-`跟踪性能下降的问题范围`。很多时候，性能问题，很难在开发过程中暴露出来，这需要进行全方位的测试跟踪，而通过日志提供的详细执行时间记录可以很方便的找出应用的性能瓶颈
 *  跟踪操作流程。通过对日志跟踪，你可以获取操作发生的具体环境，操作的结果
 *  `排查疑难杂症`。很多问题可能开发测试无法发现，或者由于环境不同，请求量不同，导致一些问题在前期开发测试期间很难被发现，此时日志就发挥重要作用了。
 *  `了解项目的运行状态；了解一些长流程的执行情况`
 *  `商业用途`。很多大的企业，都会根据日志做一些技术分析，有一些是技术上的，如分析性能瓶颈，热点业务热点接口，是否被爬虫爬取，网站的TPS，响应耗时等等。有一些是产品或商业层面的，如分析用户喜好，用户习惯，AB测试等等

> 无论做什么事情，都要搞明白为什么要做，才能做的更好！思考：这些日志真的有人看吗？看到这条日志你能做什么？能不能给问题排查带来好处？

# 日志级别 #

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

## ERROR ##

ERROR：该级别的错误需要马上被处理，当ERROR错误发生时，已经影响了用户的正常访问，是需要马上介入并处理的。常见的ERROR异常有：空指针异常，数据库不可用，服务不可用，关键用例无法继续执行等。

**ERROR是错误的意思，但不代表出现异常的地方就该打ERROR。**  
ERROR是相对程序正确运行来说的，如果出现了ERROR那就代表出问题了，开发人员必须要查一下原因，或许是程序问题，或许是环境问题，或许是理论上不该出错的地方出错了。总之，如果你觉得某个地方出问题时需要解决，就打ERROR，如果不需要解决就不要打ERROR。

如，接口入参检查就不应该使用ERROR级别日志，甚至都不应该打印日志，而是直接返回错误码，交由上层调用方处理。  
否则频繁的告警会使运维，开发对错误告警麻木，无效的告警会将真正有问题的错误淹没掉。

**哪些错误应该打印ERROR级别?**

*  读写配置文件失败
 *  配置信息错误
 *  网络断线
 *  数据库不可用（这不是绝对的，后面会讲报警升级）
 *  所有第三方对接的异常(包括第三方返回错误码)
 *  所有影响**核心**功能使用的异常

## WARN ##

WARN：不应该出现但是不影响程序、当前请求正常运行的异常情况。对于WARN级别的日志，虽然不需要管理员马上处理，但是也需要引起重视。  
WARN日志有两种级别：一个是解决方案存在明显的问题(例如Try Catch语句中由于不确定会出现什么异常，而用Exception统一捕获抛出的问题)，另一个是潜在的问题和建议(例如系统性能可能会伴随着时间的迁移逐渐不能满足服务需要，或者非核心接口的偶尔超时)。应用程序可以容忍这些信息，不过它们应该被及时地检查及修复。

如果WARN出现的过于频繁或次数太多，那就代表你要检查一下程序或环境或依赖程序是否真的出问题了。此时应该监控warn日志的次数，达到阈值告警并处理。

**哪些错误应该打印WARN级别?**

*  异常：由于在程序运行之前不能明确异常引发的原因，异常只进行了简单的捕获抛出，需要将这种笼统处理的异常打印为WARN格式的日志，提醒管理员干预处理。不过如果是核心业务，则需要打印ERROR级别
 *  有容错机制的时候出现的错误情况
 *  找不到配置文件，但是系统能自动创建配置文件（或使用默认配置）
 *  性能即将接近临界值的时候（也要看是否是核心系统，核心业务，如果是，则需要打印ERROR，报警，并自动或人工扩容）
 *  业务异常的记录，危险操作
 *  限流，降级，熔断的操作，都需要WARN级别日志打印
 *  出于提醒目的的日志。比如2B的业务中，用户数据不完善， 但不至于严重到系统（接口）不可用程度，此时就应该打印warn级别的日志，然后通知业务方进行数据补全。

## INFO ##

INFO：主要用于记录系统运行状态、核心用例执行结果、用户的操作行为等信息。该日志级别，常用于反馈系统当前状态给最终用户。

**需要打印的INFO级别的日志：**

*  接口请求与响应。通常情况下，无论是dubbo等RPC框架，还是http/https等restful风格的访问，只要涉及到微服务间的访问，都要打印入参与出参。
 *  一些需要观测执行情况的行为：如定时任务（尤其是分布式任务）等/大批量数据执行进度（批处理）/耗时操作等等
 *  不符合业务逻辑预期（尤其核心业务）：打印关键的参数，要能从这些参数中清楚地看出，谁的操作与预期不符，为什么与预期不符。并且唯一定位到这条日志，要包含用户id或者流水号
 *  系统模块的入口与出口处：可以是重要方法级或模块级，记录它的输入与输出，方便定位
 *  非预期执行：为程序在“有可能”执行到的地方打印日志（通常与业务挂钩，打印内容要看得出为什么走到这个分支 ）
    
     *  switch case语句块中的default
     *  if…else if…else中很少出现的else情况
     *  try catch语句块中catch分支。
 *  服务状态变化(尽可能记录线索)：程序中重要的状态信息的变化应该记录下来，方便查问题时还原现场，推断程序运行过程
 *  程序运行耗时：通过它可以跟踪为什么系统响应变慢或者太快。再配合链路追踪系统，可以方便的定位到那个系统哪个方法耗时长

## DEBUG ##

DEBUG：该级别日志的主要作用是对系统每一步的运行状态进行精确的记录。通过该种日志，可以查看某一个操作每一步的执行过程，可以准确定位是何种操作，何种参数，何种顺序导致了某种错误的发生。可以保证在不重现错误的情况下，也可以通过DEBUG级别的日志记录对问题进行诊断。  
一般来说，在生产环境中，不会输出该级别的日志。

# 如何打印日志 #

## 打印日志的位置 ##

*  程序入口：入口包括方法入口，对外暴露接口等。在入口打印日志是因为这个时候传递进来的参数没有经过任何处理，将它打印在日志文件中能一眼就知道程序的原始数据是否符合我们的预期，是不是传递进来的原始数据就出现 的问题。
 *  计算结果：测试关心的程序的输出结果是否符合预期，那么对于计算过程不应该关心，仅给出计算结果就能判断是否符合预期。
 *  重要信息（或关键步骤）：这一点可能很宽泛，因为不同的业务逻辑重点可能并不一样，例如在有的重要参数不能为空，此时就需要判断是否为空，如果为空则记录到日志中；还有的例如传递进来的参数经过一系列的算法处理过后，此时也需要打印日志来查看是否计算正确。但切记，尽量不要直接在for循环中打印日志，特别是for循环特别大时，这样你的日志可能分分钟被冲得不见踪迹，甚至带来性能上的影响。
 *  异常捕获：在异常打印出详细的日志能让你快速定位错误在哪里，例如在程序抛出异常捕获时，在平时我们经常就是直接在控制台打印出堆栈信息e.printStackTrace()，但在实际的生产环境更加艰苦，更别说有IDE来让你查看控制台信息，此时就需要我们将堆栈信息记录在日志中，以便发生异常时我们能准确定位程序在哪里出错。
 *  分支：无论是if-else还是switch，需要打印相关的日志，可以快速的看到根据什么参数走到了哪个分支。
 *  批量操作：涉及到数量的操作要打印log，比如查询数据库和批量拷贝文件、上传下载、批量格式转换等批量操作
 *  调用其他系统接口的前后：打印所调用接口的系统名称/接口名称和传入参数/响应参数，这样能方便做问题定界，通过这两条日志可以清楚地看出是否是所调用的系统出现了问题

## 打印输出哪些内容 ##

*  通用信息
    
     *  级别，例如 warn、info 和 error
     *  时间
     *  进程ID
     *  线程ID：线程ID相当重要，在解决多线程问题的时候，这一项信息是必不可少的
     *  模块：哪个类，假如是分布式服务的话，需要指明是哪个服务的哪个类
     *  Filter：主要用于查找某一类LOG时候方便，这个Filter是开发人员在开发过程中自己定义的，可以是方法名/业务模块名称/功能名称等等。
     *  请求id: 一个请求到来会经过很多服务的很多方法，一个唯一的请求id可以将该请求的所有日志串联起来
     *  耗时：可以通过拦截器或AOP来打印某服务或某核心方法的耗时，可以使用一些agent来拦截方法执行时间。

如某公司通用日志打印

[INFO] 2020-11-26 14:06:59.330[ConsumeMessageThread_56][2011280MD13623573890648168927232] c.w.w.r.h.SyncRequestHandler:108

*  入参出参  
    入参和出参不是每个地方都要打印的，只在服务对外暴露的API/核心方法提供即可。注意打印的参数一定要是原始参数，而不是经过转换后的参数，防止你参数转换的代码有问题。
 *  会话标识。能知道是哪个客户端或者是哪个用户触发、登陆账号、seesion信息等。
 *  场景信息（谁，什么功能等）；
 *  状态信息(开始，中断，结束)以及重要参数；
 *  日志格式：日志格式统一使用主语+谓语+宾语+状语的格式，日志打印应该遵从人类的自然语言，任何没有开发经验或是外行人都能从你的日志中捕获到有用的信息。使用 `[]` 进行参数变量隔离，这样的格式写法，可读性更好，对于排查问题更有帮助

# 日志框架 #

java生态中有很多日志框架可供选择，如log4j, log4j2， logback等等。他们各自的特点不是本文重点，请读者自行google。  
这里需要强调一点：  
**应用中不可直接使用日志系统（ Log4j、 Logback）中的 API，而应依赖使用日志框架SLF4J 中的 API，使用门面模式的日志框架，有利于维护和各个类的日志处理方式统一。**

import org.slf4j.Logger;
    import org.slf4j.LoggerFactory; 
    private static final Logger logger = LoggerFactory.getLogger(Abc.class);

# 告警 #

## 告警分级 ##

任何系统都有很多的接口和方法，首先要根据业务划分优先级，指定不同的业务级别。

除了上面降到的4种基本的告警级别外，还要根据业务级别划分不同的告警级别。

举个例子，比如接口超时，如果是核心业务，需要打印ERROR日志，并且出现一次就要报警；如果不是核心业务，那么可能只需要打印warn日志，然后配置在一定时间窗口内出现N次才报警处理。

## 谁来处理告警 ##

*  客服  
    当一个产品比较完善的时候，系统中可能出现的所有异常都已经暴露的差不多了，那么此时需要将各种异常进行分类汇总，并给出解决方案，交由客服。当有用户反馈时，客服会拦截处理一部分异常。  
    客服可以处理的异常通常会提供管理控制台来操作。
 *  运维  
    客服无法处理的异常，可能就需要运维人员根据用户信息和日志信息协助排查，定位问题，如果运维可以解决，比如系统扩容，硬件升级，那么运维解决，否则交由开发解决
 *  开发  
    如果到了开发同学这里，说明问题已经比较严重了，需要根据日志信息仔细排查，看是否是系统未发现的BUG。

# 拾遗 #

*  要特别注意打印日志本身抛出的异常。一是正确的空值校验，二是也可以try-cache。
 *  外部交互，统一错误码，便于沟通与排查问题。
 *  控制日志保存期限及大小，避免磁盘打爆。日志文件推荐至少保存 15 天，因为有些异常具备以“周”为频次发生的特点【阿里开发手册规约中有强调】
 *  日志可以进行分类，分文件打印，可以根据不同都日志级别，或不同都业务，便于排查。命名时需要注意：见名知意。如 `appName_logType_logName.log`。 logType:日志类型，推荐分类有 stats/desc/monitor/visit  
    等； logName:日志描述。这种命名的好处：通过文件名就可知道日志文件属于什么应用，什么类型，什么目的，也有利于归类查找。
 *  异步打印日志，避免日志成为系统性能负担
 *  **如果明确知道是什么原因导致的错误，那么堆栈可以不打印**，打印堆栈也是一个比较大的开销
 *  通常不再循环里打印日志
 *  写完功能，进行测试时，尽量不用编辑器的调试，而是通过日志来查看功能实现和进行异常定位、分析。当然这个要求对于开发者要求比较高。
 *  避免重复打印，务必在日志配置文件中设置additivity=false。
 *  一个类中通常只有一个静态的log对象
 *  日志中如果英文描述不清，可以用中文。不过用于定位错误信息的关键字推荐用英文。

## 空指针异常 ##

*  基本每个使用到的对象，返回值，都要考虑是否会存在空都情况，做出正确判断。
 *  对于一些情况，当返回空时，可以采用返回非空对象的方式来代替。比如查询数据返回空集合`Collections.emptyList()`；`getOrDefault`方法。
 *  使用 if(null == obj) 而不是 if(obj == null) 来避免不必要的空指针异常

## 入参校验 ##

*  服务端不可以相信前端任何输入。需要对入参做严格都校验。
 *  微服务间，下层服务也需要对上层服务都入参做校验，不要以为调用方都是一个部门或公司的就忽略了
 *  对于批量操作，务必对请求都数据量做校验，避免大SQL或内存撑爆

# 安全 #

日志的打印需要对用户的身份证，密码等敏感信息脱敏。

# 分布式链路追踪 #

微服务系统需要配合链路追踪和ELK等工具。

*  [spring cloud Greenwich 学习笔记（十）spring cloud sleuth 服务链路追踪][spring cloud Greenwich _spring cloud sleuth]
 *  [spring boot 2.1学习笔记【十二】SpringBoot 2 集成 dubbo 2.6.5(最后一节介绍了dubbo链路追踪)][spring boot 2.1_SpringBoot 2 _ dubbo 2.6.5_dubbo]
 *  [ELK（二）nginx日志分析][ELK_nginx]
 *  [ELK（一）ELK日志收集分析系统环境搭建][ELK_ELK]

# spring boot 全局统一日志打印 #

[spring boot 全局统一日志打印][spring boot]

# spring boot 2.1学习笔记【十九】使用spring validation实现全局参数校验 #

[spring boot 2.1学习笔记【十九】使用spring validation实现全局参数校验][spring boot 2.1_spring validation]

# 案例 #

*  反例：日志冗余  
    ![在这里插入图片描述][20201128134005143.png]  
    如下， 已经有抛出异常了，那么没必要再打印一次error日志。但是，要注意将具体的错误信息封装成自然语言抛出异常，并且上层要捕获并打印error日志。

try { 
    	//do sth 
    } catch (Exception e) { 
    	logger.error('XX 发生异常', e);
    	throw new IOException();
    }

*  反例：未使用占位符  
    `log.error("具体业务信息,入参："+sceneId);`
 *  反例：日志没有有效信息，没有堆栈信息

try { 
        throw new Exception("测试日志");
    }catch (Exception e){ 
        logger.info(e.getMessage());//错误
        logger.info("输入日志1",e.getMessage());//错误
        logger.info("输入日志2",e);//正确
    }

如下:没有打印status的值。如果分支比较复杂，最好在status=1和2两个分支打印一下走向。当日在外层打印也行，只要能快速定位到走的哪个分支流程。

if(status=1){ 
    	//do sth
    }else if(status=2){ 
    	//do sth
    }else{     
    	log.warn("status 有误");
    }

*  反例：日志未能准确表达错误信息

Connection connection =ConnectionFactory.getConnection();
    if (connection == null) { 
    	log.warn("System initialized unsuccessfully"); 
    }

*  反例：由于打印日志，导致新的异常。通常是空指针异常

log.debug("Processing request with id: {}", request.getId());

*  反例：将数据库中的数据全部打印出来  
    有时候只需要打印数据量大小即可，如果打印了很多无用的数据，不仅性能损耗，占用额外的磁盘空间，还会给日志查看带来困扰
 *  反例：错误的打印对象  
    如下，如果parama是对象，那么可能打印的是对象的hashcode值。可以重写tostring方法或者转为json打印，推荐json

logger.error("calculate user fee error. parama=[{}], paramb=[{}]", parama, paramb, e)

正例：

logger.debug("UserName is:[{}] and age is : [{}] ", name, age);
    
    logger.error("calculate user fee error. parama=[{}], paramb=[{}]", json(parama), paramb, e)

[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2ZneWlidXBp_size_16_color_FFFFFF_t_70]: /images/20221120/31c27c7c909b49fb8b3bda31e7e5aaef.png
[spring cloud Greenwich _spring cloud sleuth]: https://blog.csdn.net/liubenlong007/article/details/87627928
[spring boot 2.1_SpringBoot 2 _ dubbo 2.6.5_dubbo]: https://blog.csdn.net/liubenlong007/article/details/86483545
[ELK_nginx]: https://it007.blog.csdn.net/article/details/53782961
[ELK_ELK]: https://it007.blog.csdn.net/article/details/53782955
[spring boot]: https://it007.blog.csdn.net/article/details/106573902
[spring boot 2.1_spring validation]: https://it007.blog.csdn.net/article/details/106013854
[20201128134005143.png]: https://img-blog.csdnimg.cn/20201128134005143.png