前言

不正确的日志打印不但会降低程序运行性能,还会占用大量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、禁止输出文件名

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

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

2、禁止输出调用方类名

参数说明
C{length}
class{length}
输出发出日志记录请求的调用方的完全限定类名。生成调用方类信息并不是特别快。因此,应该避免使用它,除非执行速度不是问题。

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

3、禁止输出行号

参数说明
L / line输出发出日志记录请求的地方的行号。
生成行号信息并不是特别快。因此,应该避免使用它,除非执行速度不是问题。

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

4、禁止输出调用方法名称

参数说明
M / method输出发出日志记录请求的方法名。
生成方法名并不是特别快。因此,应该避免使用它,除非执行速度不是问题。

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

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

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

可以根据项目运行的不同环境来限制日志输出的默认级别。
比如开发环境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、减少不必要的日志输出。

Logo

开放原子开发者工作坊旨在鼓励更多人参与开源活动,与志同道合的开发者们相互交流开发经验、分享开发心得、获取前沿技术趋势。工作坊有多种形式的开发者活动,如meetup、训练营等,主打技术交流,干货满满,真诚地邀请各位开发者共同参与!

更多推荐