logback性能优化详解

前言

不正确的日志打印不但会降低程序运行性能，还会占用大量IO资源和硬盘存储空间。
本文主要总结一些能提高日志打印性能的手段。

一、通过AsyncAppender异步输出日志

我们通常使用的ConsoleAppender 和 RollingFileAppender都是同步输出日志，会阻塞程序运行。只有当日志打印完毕程序才会继续执行。

而通过AsyncAppender实现异步日志输出，会启用单独日志线程去记录日志，并且不会阻塞程序运行，可以极大的增加日志打印的吞吐量。

具体实现可以查看：​​logback异步输出日志详解​

配置示例：

添加一个基于异步写日志的 appender，并指向原先配置的 appender即可。

<configuration>
  <!-- 同步输出 -->
  <appender name="FILE" class="ch.qos.logback.core.FileAppender">
    <file>myapp.log</file>
    <encoder>
      <pattern>%logger{35} - %msg%n</pattern>
    </encoder>
  </appender>

  <!-- 异步输出 -->
  <appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
    <appender-ref ref="FILE" />
  </appender>

  <root level="DEBUG">
    <appender-ref ref="ASYNC" />
  </root>
</configuration>

二、禁用即时刷新immediateFlush=false

默认情况下，每个日志事件都会立即刷新到基础输出流。这种默认方法更安全，因为如果应用程序退出时没有正确关闭附加程序，那么日志事件就不会丢失。但是，为了显著提高日志吞吐量，我们可以将 immediateFlush 属性设置为 false。

<configuration>
  <appender name="FILE" class="ch.qos.logback.core.FileAppender">
    <file>testFile.log</file>
    <append>true</append>
    <!-- 禁用即时刷新提高日志吞吐量 -->
    <immediateFlush>false</immediateFlush>
    <encoder>
      <pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>
    </encoder>
  </appender>

  <root level="DEBUG">
    <appender-ref ref="FILE" />
  </root>
</configuration>

原理分析：

无论是ConsoleAppender还是 FileAppender，都是继承了OutputStreamAppender。

所有的日志输出本质都是I/O写入操作。

通过禁用即时刷新可以充分利用IO缓冲区，提高IO性能。

三、规范日志输出格式pattern

<encoder>
        <!-- 日志默认输出格式 -->
        <pattern>%-4relative [%thread] %-5level %logger{35} - %msg %n</pattern>
        <!-- 采用utf8字符格式输出，避免出现乱码 -->
        <charset>utf8</charset>
</encoder>

日志布局介绍：​​https://logback.qos.ch/manual/layouts.html​​

主要是需要禁止输出下面这些信息：

1、禁止输出文件名

输出发出日志记录请求的 Java 源文件的文件名。
生成文件信息并不是特别快。因此，应该避免使用它，除非执行速度不是问题。

2、禁止输出调用方类名

推荐采用%logger{26}输出日志记录器的名称，而不要输出类名。

3、禁止输出行号

输出发出日志记录请求的地方的行号，速度比较慢，尽量避免。

4、禁止输出调用方类名

输出发出日志记录请求的方法名，速度比较慢，尽量避免。

注意⚠️：
如果你的项目输出日志非常缓慢，赶紧检测下日志输出格式中是否包含上面这些内容。

四、提高生产环境的日志输出级别

可以根据项目运行的不同环境来限制日志输出的默认级别。
比如开发环境dev由于需要查看更详细的日志信息便于程序调试，可以将root的日志级别设置为DEBUG。
而测试环境test、生产环境prod不需要关注调试级别的日志信息，只需要将root日志级别设置为INFO。

logback 日志级别排序： ​​TRACE < DEBUG < INFO < WARN < ERROR​​

根据spring环境打印不同级别的日志：

<!-- 开发环境日志级别为DEBUG -->
<springProfile name="dev">
    <root level="DEBUG">
        <appender-ref ref="STDOUT"/>
        <appender-ref ref="FILE"/>
    </root>
</springProfile>

<!-- 测试环境日志级别为INFO -->
<springProfile name="test">
    <root level="INFO">
        <appender-ref ref="STDOUT"/>
        <appender-ref ref="FILE"/>
    </root>

<!-- 生产环境日志级别为INFO -->
<springProfile name="prod">
    <root level="INFO">
        <appender-ref ref="STDOUT"/>
        <appender-ref ref="FILE"/>
    </root>
</springProfile>

另外spring boot下，还可以针对项目中的特定类指定不同的日志输出级别：
比如开发环境dev，将mapper目录下的日志设置为trace级别，这样就可以将数据库操作的sql、入参以及返回都打印出来，方便调试。
但是针对测试和生产环境，则一定要禁止。
application-dev.properties

logging.level.com.laowan.test.demo.mapper=trace

application-prod.properties

#可以注释掉该行，使其继承root的日志级别，也可以主动设置为info
logging.level.com.laowan.test.demo.mapper=info

五、非控制台输出严禁彩色打印

在上篇文章​​logback控制台彩色日志输出​​中提到过，彩色日志只有在控制台输出才能展示彩色效果，如果是文件类型的日志输出，会输出大量彩色渲染的识别码，不利于日志查看，同时也会增加日志输出的压力。

彩色日志的文件输出：

六、根据日志的输出级别保存到不同文件

​​虽然采用多日志文件输出可以在一定程度避免IO进程对单文件的竞争，但是日志输出文件频繁切换也可能会对日志输出性能造成一定影响，单日志文件的顺序写入有可能性能更高。​​

由于该方式的没有经过具体的性能测试，具体是否能起到优化效果暂未可知，所以​​只推荐在希望分离出error级别日志，方便问题定位的时候使用​​。

通过配置LevelFilter控制日志输出级别：

<appender name="errorlog" class="ch.qos.logback.core.rolling.RollingFileAppender">  
     <file>${BUILD_FOLDER:-logs}/error/error.log</file>  
     <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">  
            <FileNamePattern>${BUILD_FOLDER:-logs}/error/error-%d{yyyy-MM-dd}.log</FileNamePattern>  
            <MaxHistory>10</MaxHistory>  
      </rollingPolicy>  
     <encoder>  
        <pattern>[%-5level] %d{HH:mm:ss.SSS} [%thread] %logger{36} - %msg%n</pattern>  
        <charset>utf8</charset>  
    </encoder>  
    <filter class="ch.qos.logback.classic.filter.LevelFilter">  
        <level>error</level>  
        <onMatch>ACCEPT</onMatch>  
        <onMismatch>DENY</onMismatch>  
    </filter>  
</appender>

七、根据日志具体作用设置对应的日志输出级别

只有在程序开发的过程中，在打印日志的时候设置了合适的日志级别，这样我们在logback中根据各个环境控制的不同日志级别才能达到更好的效果。
不然调试级别的日志输出采用info级别，异常日志输出又采用info级别，就完全失去了日志级别控制的意义。

log.trace("trace级别日志，一般用于调试跟踪，常见的比如mapper层日志打印输出sql执行返回");
log.debug("调试级别日志，一般用于调试跟踪");
log.info("info级别日志输出，一般用于输出一些关键信息，比如请求入参，方法耗时等");
log.warn("告警级别日志输出");
log.error("异常级别日志输出");

典型的错误用法：

1、胡乱采用error级别输出关键日志信息

public void order(OrderReq req) {
    log.error("请求入参为:{}",req);
    //具体业务处理
}

2、异常日志采用info级别输出

try {
   //逻辑处理
}catch (Exception ex){
    log.info("请求失败,异常原因",ex);
}

八、减少不必要的日志输出

分析日志是否有输出的必要，是否可以对输出的日志降级。
有时候减少一些不必要的日志输出，可以极大的减少日志输出的IO压力，提高程序性能。

九、其他

1、字符串连接输出

反例：采用+号进行字符串连接

public void add(User user) {
    log.info("新增用户ID:"+user.getId()"，年纪:"+user.getAge());
    //具体业务处理
}

正例：采用{}替换符连接

public void add(User user) {
    log.info("新增用户ID:{}，年纪:{}",user.getId(),user.getAge());
    //具体业务处理
}

2、异常日志输出

反例:采用e.printStackTrace()打印日志堆栈

try {
   //逻辑处理
}catch (Exception e){
    e.printStackTrace();
}

正例：采用log.error(“异常描述”,e)打印日志堆栈

try {
   //逻辑处理
}catch (Exception e){
    log.error("请求失败,异常原因",e);
}

总结

本文主要是对logback日志输出的相关优化手段进行了总结说明。
1、通过AsyncAppender进行异步输出日志和禁止即时刷新是比较直接有效的手段，但需要注意​​​两者都要日志丢失的风险​​，在需要进行日志收集归档的情况的要谨慎使用。

2、设置日志输出级别，对性能优化至关重要。

3、注意日志的打印格式pattern，​​严禁日志输出中包含文件名，类名，方法名以及行号​​。

4、减少不必要的日志输出。