[置顶] sprign boot项目实战：日志

日志是运维、排错的一个重要助手，很多人应该都维护过没有日志的项目，知道排查问题是什么感觉。所以搭建基础项目框架时，自然不能少了日志。

日志组件选择

从网上各种搜索对比，在log4j2和logback之间选择了log4j2,综合各处评价，log4j2在性能方法有一定优势。但是在一个项目内使用后就发现，spring boot内log4j2不支持spring profile机制，也就是在本地环境、测试环境、预发布环境、正式环境需要手动切换配置，当前公司的多个环境在相同的服务器上，所以这种方式会导致多个环境的日志生成在了同一个文件内，很不利于问题排查。因此又将日志组件换回了logback，因为对当前公司的项目来说，日志支持profile机制更重要，性能瓶颈绝不在日志这块。

logback配置

spring boot内配置logback还是很简单的，只需要在src/main/resources目录下创建logback-spring.xml，在xml内添加自己的日志配置即可。支持三个环境local、dev、prod的日志配置如下：

<?xml version="1.0" encoding="UTF-8"?>

<configuration scan="true" scanPeriod="30 seconds">
<property name="LOG_PATH" value="/mnt/diskb/logs"/>

<springProfile name="local">
<logger name="com.onecoderspace" level="debug" additivity="true"/>
<appender name="logfile" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ssS} %5p [%c]:%L-%m%n</pattern>
</encoder>
</appender>
</springProfile>

<springProfile name="dev">
<logger name="com.onecoderspace" level="info" additivity="true"/>
<appender name="logfile" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${LOG_PATH}/projectName/projectName_dev.log</file>
<append>true</append>
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ssS} %5p [%c{5}#%M]:%L-%m%n%caller{0}</pattern>
</encoder>
<prudent>false</prudent>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<!-- daily rollover -->
<fileNamePattern>${LOG_PATH}/projectName/projectName_dev.%d{yyyy-MM-dd}.log.gz
</fileNamePattern>
<maxHistory>30</maxHistory>
</rollingPolicy>
</appender>
&
4000
lt;/springProfile>

<springProfile name="prod">
<logger name="com.onecoderspace" level="info" additivity="true"/>
<appender name="logfile" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${LOG_PATH}/projectName/projectName.log</file>
<append>true</append>
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ssS} %5p [%c{5}#%M]:%L-%m%n%caller{0}</pattern>
</encoder>
<prudent>false</prudent>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<!-- daily rollover -->
<fileNamePattern>${LOG_PATH}/projectName/projectName.%d{yyyy-MM-dd}.log.gz
</fileNamePattern>
<maxHistory>30</maxHistory>
</rollingPolicy>
</appender>
</springProfile>

<root level="info">
<appender-ref ref="logfile" />
</root>

</configuration>

spring-boot-starter-web内已经包含了logback和slf4j的依赖，所以只要项目依赖了spring-boot-starter-web，就不需要做其他额外的配置了。

日志使用

调用日志时建议使用slf4j，虽然基本不会在后续变更日志组件，但使用slf4j是一个好的习惯。

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

debug日志

debug日志建议添加logger.isDebugEnabled()判断，在重要的流程上都留下日志，这样当系统出现问题时，可以通过debug日志，快速定位问题，能代替很多断点调试的时间。

if(logger.isDebugEnabled()){
logger.debug("user={} login success",username);
}

info日志

比较重要的信息，对于系统运行有比较重要的参考意义，同时不会对性能造成影响，可以在正式环境展示的信息，使用info基本打印，如定时任务运行时间等。

logger.info("end fetcher proxy use time={}", System.currentTimeMillis()- t);

error日志

error日志相对来说是最重要的，但使用时需要注意使用方式，不正确的方式会导致很多信息被隐藏。可以参考如下方式：

logger.error(String.format("error msg ,arg1=%s,arg2=%s",arg1,arg2), e);

尽可能的带上异常发生时的参数，这个对排查问题很有意义

打印异常的完整堆栈信息，仅打印e.getMessage()会导致很多信息被隐藏

只在异常发生时或明确的业务错误时使用error，不要用error来打印调试、普通信息

总结

spring boot项目内日志组件选择logback比较好，内嵌的日志组件，支持profile机制；

logback配置方式为在src/main/resources目录下创建logback-spring.xml，配置内容参考上文；

调用日志时使用slf4j，注意合理使用日志级别

注意以下几点tips

tips

1、 应用日志尽量放在数据盘上，不要放在系统盘上，遇到了不止一次日志写满系统盘导致服务暂停的情况

2、 技术负责人定好日志规范，在代码review时指出几次日志使用的问题，能够很快让良好使用日志成为团队的习惯

3、 正式环境的日志基本最低为info，通常可以调整为warn或error

4、 在while循环内有异常捕获时，注意当异常发生时，不能无限打印日志，如下代码：

while (flag) {
try {
byte[] bb = _queue.poll(1, TimeUnit.SECONDS);
if (bb != null) {
@SuppressWarnings("unchecked")
Map<String, Object> m = JacksonSupport.decode1(new ByteArrayInputStream(bb), Map.class);
E event = _consumer.getEventType().newInstance();
event.fromMap(m);
_consumer.onEvent(event);
}
} catch (Exception e) {
logger.error("redis queue poll due to error", e);
}
}

从基于redis开发的一个blockingQueue内获取元素进行消费，代码运行了一年多十分正常，但是有一次几乎把磁盘写满了，因为当时运维调整，redis停掉了， _queue.poll这里就开始抛异常，然后下面就狂写日志，一直把磁盘写满。类似这样的地方，可以进行一个计数，连续错误达到多少次，就终止循环并以某些方式提醒运维人员。

5、不要使用System.out.println()，建议隔段时间全局搜索一次，发现了就在小组会议上提一下，很快这种现象就会杜绝