日志输出规范

1. 组件

日志组件有很多，日志门面的选择

Slf4j
Apache Commons Logging

日志的实现有：

log4j
logback
log4j2
Java Util Logging(jul)
Jboss Logging

建议统一使用Slf4j作为日志门面，logback作为日志实现。

2. 级别

日志的级别有很多，我们一般只用四个。日志级别由低到高DEBUG - INFO - WARN - ERROR。

DEBUG（调试）：开发调试日志。一般来说，在系统实际运行过程中，不会输出该级别的日志。
INFO（通知）：INFO日志级别主要用于记录系统运行状态等关联信息。在这里输出的信息，应该对最终用户具有实际意义。
WARN（警告）：WARN日志常用来表示系统模块发生问题，但并不影响系统运行。虽然不需要马上处理，但是也需要引起重视。某些用户危险的操作，例如一直采用错误密码尝试登陆管理员账号的行为，可以提升到WARN日志级别记录。
ERROR（错误）：此信息输出后，主体系统核心模块需要修复才能正常工作。系统中出现该级别日志应该及时解决。

3. 场景

在我们的系统中，不同的日志级别的打印场景大致如下：

日志级别	打印场景
DEBUG	调试日志。没有严格要求。
INFO	业务日志。用来记录业务的主流程的走向。
WARN	警告日志。一般来说，发生对整个系统没什么影响的异常时，可以打印该级别的日志。
ERROR	错误日志。级别比较高，一般如果发生一些异常，都需要打印。

4. 使用方式

编写位置

系统/应用启动和参数变更。当系统启动时，可以将相关的参数信息进行打印，以便出现问题时，更准确地查询原因；参数信息可能并不存储在本地，需要通过配置中心获取，而参数信息有变更时，也需要将变更后的内容输出在日志中。
关键操作节点。最典型的就是在关键位置添加日志，记录用户进行的某个操作。
大型任务进度上报。当系统在处理某个比较大型的任务时，可以在这个过程中增加相关的日志来表明任务处理的进度，防止因为长时间没有处理而无法得知程序执行的状态，比如在定时任务中，增加当前任务完成百分比。
异常。如果是通过 try-catch 处理，需要注意日志编写的位置。如果需要将日志在本层抛出，则不需要进行日志记录，否则会出现日志重复的问题。
批量操作。涉及到数量的操作要打印log，比如查询数据库和批量拷贝文件、上传下载、批量格式转换等批量操作，设计到的数量要打印出来。

格式

日志的格式布局会影响日志内容收集与管理的效率。日志编写时需要注意的事项：

系统之间格式保持一致：每个应用在日志格式上尽量保持统一，这样，在进行日志收集时，就可以采用统一的日志模板来收集和格式化内容。
不编写多行的日志内容：除了异常堆栈信息，不对日志内容进行多行的输出，多行的内容十分不便于数据解析，可能会出现生成多条日志的情况。
不要使用日志中的常见内容来分割：如果采用日志中常见的内容来分割，会在格式解析时出现问题，比如用户 ID 中的空格就是比较常见的内容。

面向接口

private static final Logger logger = LoggerFactory.getLogger(AuthAspect.class);

使用时应面向接口编程，要求使用slf4j日志门面，LOGGER/LoggerFactory应该都是slf4j的API。严禁直接使用日志实现包。原因大致有两点，第一是面向接口编程更优雅，这点不必说明；第二，便于切换具体的日志实现方式，举个例子，因为log4j已经几年不更新，老的项目可能使用了log4j，现在想要换用logback或者log4j2，如果是直接使用log4j的API，不利于选型更换与API的统一。

禁止

禁止字符串拼接

例如：

LOGGER.debug("当前用户是:" + user + ",传入参数是:" + userId);

严禁使用字符串拼接的方式打印日志，可读性、可维护性都比较差。
建议的写法如下：

LOGGER.debug("当前用户是:{},传入参数是:{},返回值是:{},用户信息:{}", new Object[]{token, userId, userInfo, authcInfo});

Slf4j有占位符填充的功能。多个占位符可放在Object数组中。
占位符优点：

节约性能。不停叠加字符串而占用过多的内存、CPU 资源，导致性能浪费。
便于编写。先确认日志所想要表达的内容，再确认你所需要编写的参数，这样在写日志时，目的也会更加明确。
便于查看。在代码 review 时，更方便查看日志想表达的意思，而不会被日志的参数打乱。

无需使用级别判断

不优雅示例：

if (LOGGER.isDebugEnabled()) {
    LOGGER.debug("当前用户是{}", token);
}

应直接使用如下形式就OK了。

LOGGER.debug("当前用户是{}", token);

或者输出对象

LOGGER.debug("当前用户是{}", JSONObject.toJSONString(userInfo));

反例

//重复
//直接打印堆栈
try {...}
catch (Exception e) {
    logger.error("getTerminalDetailsBatch() 发生异常",e);
    e.printStackTrace();
}

//System.out.println
//拼接
System.out.println("收到："+iccids);

//向上抛出异常又打印日志
LOG.info("智能诊断{}，查产品资料失败，接口返回空：{}", cardEntity.getIccidMark(), responseStr);
throw new Exception("接口返回空");

//没有参数、状态、耗时、结果
@Scheduled(cron = "0 0 */1 * * ?")
public void stopCard() {
    this.logger.info("=============开始停机=================");
    this.cardViewComp.stopCard();
    this.logger.info("=============结束停机=================");
}

//暴露敏感信息
log.info(userName + " 登录 原始密码[" + password + "] pwd[" + pwd + "] 数据库中密码[" + entity.getPassword() + "]" );

不建议用System.out
System.out日志打印不可控制、打印时间无法确定、不能添加过滤器、日志没有级别区分
尽量不用e.printStackTrace
主要原因有以下几点：
1、占用太多内存，造成锁死
要打印字符串输出到控制台上，需要字符串常量池所在的内存块有足够的空间。然而，因为e.printStackTrace() 语句要产生的字符串记录的是堆栈信息，太长太多，内存有可能被填满了，此时大量线程产出字符串产出到一半，等待有内存被释放，就锁死了，整个应用都会挂掉。
2、日志交错混合，不易读
printStackTrace()默认使用了System.err输出流进行输出，与System.out是两个不同的输出流，那么在打印时自然就形成了交叉。再就是输出流是有缓冲区的，所以对于什么时候具体输出也形成了随机。
日志的频繁打印会对模块的性能产生极大的影响
当日志产生的速度大于日志文件写磁盘的速度，会导致日志内容积压在内存中，导致内存泄漏。
一般不在循环里打印日志
不打无用的、无意义、不完全的日志

if(message instanceof TextMessage){
    //do sth
}else{    
    log.warn("Unknown message type");
}

日志打印的时候不能因为打印日志引入新的异常，例如空指针异常

log.debug("Processing request with id: {}", request.getId());
//request对象如果是null，那么就会出现NPE。

输出参数不宜过大
不对大字段、无用字段输出，因为这很影响程序执行效率和日志的内容。比如大段的Html，或者大段的对象信息，甚至整个图片流信息。

建议

如果你在方法的开始和结束都记录了日志，那么你可以人工找出效率不高的代码，也可以用切面实现。
因为打印的日志有时间戳，你可以根据开始和结束时间获得执行时间，如果执行时间较长，可能就是代码效率有问题。

在日志中增加以下信息提高可读性

会话标识：当前操作的用户和与当前请求相关的信息，类似 Session。当出现问题/查看行为时，可以根据这个值来快速识别到相关的日志。
请求标识：每个请求都拥有一个唯一的标识，这样在查看问题时，我们只需要查看这一个请求中的所有日志即可。一般我们会配合链路追踪系统一同使用，因为后者可以实现跨应用的日志追踪，从而帮助我们过滤掉不相关的信息。
参数信息：在日志中增加参数信息能帮你了解到，是什么情况下产生的问题，这样你也很容易复现问题，以及辨别错误的原因。
发生数据的结果：和参数信息相互对应，一个是执行前，一个是执行后。发生数据的结果可以帮你了解程序执行的结果。

日志 review
好的日志不是一次就能写好的，而是通过代码评审、不断迭代等方式进行完善的。之前因为定位问题打的日志，若无必要也可以删除，避免过多无用日志。（矛盾：出了问题才知道日志有没有用，多打点也无妨）

日志归档

一般情况下，我们会对日志按照日期来归档，每天生成一个日志文件，这样在日志备份和恢复时，可以按照日期来进行。
目前系统两个地方有日志

/data/tomcat/logs目录，四个模块，分error和info两种，info包含error，按天分割文件。
tomcat的logs目录下的catalina.out文件，包含所有info级别以上信息，文件较大，需要定时清理。建议取消打印控制台日志，避免冗余。

image.png