Logback 配置文件这么写，TPS提高10倍

港控/mmm° 2021-09-01 08:58 297阅读 0赞

点击上方 [Java后端][Java]，选择 设为星标

优质文章，及时送达

--------------------

作者： 何甜甜在吗

链接：juejin.im/post/6844903909920604174

通过阅读本篇文章将了解到

1.日志输出到文件并根据`LEVEL`级别将日志分类保存到不同文件

2.通过异步输出日志减少磁盘`IO`提高性能

3.异步输出日志的原理

### 配置文件logback-spring.xml ###

`SpringBoot`工程自带`logback`和`slf4j`的依赖，所以重点放在编写配置文件上，需要引入什么依赖，日志依赖冲突统统都不需要我们管了。`logback`框架会默认加载`classpath`下命名为`logback-spring`或`logback`的配置文件。将所有日志都存储在一个文件中文件大小也随着应用的运行越来越大并且不好排查问题，正确的做法应该是将`error`日志和其他日志分开，并且不同级别的日志根据时间段进行记录存储。

<?xml version="1.0" encoding="utf-8"?>
    <configuration>
        <property resource="logback.properties"/>
        <appender name="CONSOLE-LOG" class="ch.qos.logback.core.ConsoleAppender">
            <layout class="ch.qos.logback.classic.PatternLayout">
                <pattern>[%d{yyyy-MM-dd' 'HH:mm:ss.sss}] [%C] [%t] [%L] [%-5p] %m%n</pattern>
            </layout>
        </appender>
        
        <appender name="INFO-LOG" class="ch.qos.logback.core.rolling.RollingFileAppender">
            <filter class="ch.qos.logback.classic.filter.LevelFilter">
                <level>ERROR</level>
                <onMatch>DENY</onMatch>
                <onMismatch>ACCEPT</onMismatch>
            </filter>
            <encoder>
                <pattern>[%d{yyyy-MM-dd' 'HH:mm:ss.sss}] [%C] [%t] [%L] [%-5p] %m%n</pattern>
            </encoder>
    
            
            <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
                
                <fileNamePattern>${LOG_INFO_HOME}//%d.log</fileNamePattern>
                <maxHistory>30</maxHistory>
            </rollingPolicy>
        </appender>
        <appender name="ERROR-LOG" class="ch.qos.logback.core.rolling.RollingFileAppender">
            <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
                <level>ERROR</level>
            </filter>
            <encoder>
                <pattern>[%d{yyyy-MM-dd' 'HH:mm:ss.sss}] [%C] [%t] [%L] [%-5p] %m%n</pattern>
            </encoder>
            
            <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
                
                <fileNamePattern>${LOG_ERROR_HOME}//%d.log</fileNamePattern>
                <maxHistory>30</maxHistory>
            </rollingPolicy>
        </appender>
    
        <root level="info">
            <appender-ref ref="CONSOLE-LOG" />
            <appender-ref ref="INFO-LOG" />
            <appender-ref ref="ERROR-LOG" />
        </root>
    </configuration>

部分标签说明

*  `<root>`标签，必填标签，用来指定最基础的日志输出级别
 *   *  `<appender-ref>`标签，添加`append`
 *  `<append>`标签，通过使用该标签指定日志的收集策略
 *   *  `name`属性指定`appender`命名
     *  `class`属性指定输出策略，通常有两种，控制台输出和文件输出，文件输出就是将日志进行一个持久化。
     *  `ConsoleAppender`将日志输出到控制台
 *  `<filter>`标签，通过使用该标签指定过滤策略
 *   *  `<level>`标签指定过滤的类型
 *  `<encoder>`标签，使用该标签下的`<pattern>`标签指定日志输出格式
 *  `<rollingPolicy>`标签指定收集策略，比如基于时间进行收集
 *  `    <fileNamePattern>`标签指定生成日志保存地址 通过这样配置已经实现了分类分天手机日志的目标了

![format_png][]

### logback 高级特性异步输出日志 ###

之前的日志配置方式是基于同步的，每次日志输出到文件都会进行一次磁盘IO。采用异步写日志的方式而不让此次写日志发生磁盘IO，阻塞线程从而造成不必要的性能损耗。异步输出日志的方式很简单，添加一个基于异步写日志的`appender`，并指向原先配置的`appender`即可

<appender name="ASYNC-INFO" class="ch.qos.logback.classic.AsyncAppender">
            
            <discardingThreshold>0</discardingThreshold>
            
            <queueSize>256</queueSize>
            
            <appender-ref ref="INFO-LOG"/>
        </appender>
    
        <appender name="ASYNC-ERROR" class="ch.qos.logback.classic.AsyncAppender">
            
            <discardingThreshold>0</discardingThreshold>
            
            <queueSize>256</queueSize>
            
            <appender-ref ref="ERROR-LOG"/>
        </appender>

### 对了，更多 Java实战相关的文章可以关注微信公众号 Java后端，回复 666 下载。 ###

### 异步输出日志性能测试 ###

既然能提高性能的话，必须进行一次测试比对，同步和异步输出日志性能到底能提升多少倍？

###### 服务器硬件 ######

*  ###### `CPU` 六核 ######
 *  ###### 内存 8G ######

###### 测试工具 ######

`Apache Jmeter`

###### 同步输出日志 ######

*  ###### 线程数：100 ######
 *  ###### `Ramp-Up Loop`(可以理解为启动线程所用时间) ：0 可以理解为100个线程同时启用 ######
 *  ###### 测试结果 ######

![format_png 1][]

重点关注指标`Throughput【TPS】`吞吐量：

系统在单位时间内处理请求的数量，在同步输出日志中`TPS`为**44.2/sec**

###### 异步输出日志 ######

*  线程数 100
 *  `Ramp-Up Loop`：0
 *  测试结果

![format_png 2][]

`TPS`为**497.5/sec**，**性能提升了10多倍！！！**

### 异步日志输出原理 ###

从`logback`框架下的`Logger.info`方法开始追踪。一路的方法调用路径如下图所示：

![format_png 3][]

异步输出日志中最关键的就是配置文件中`ch.qos.logback.classic`包下`AsyncAppenderBase`类中的`append`方法，查看该方法的源码:

protected void append(E eventObject) {
            if(!this.isQueueBelowDiscardingThreshold() || !this.isDiscardable(eventObject)) {
                this.preprocess(eventObject);
                this.put(eventObject);
            }
        }

通过队列情况判断是否需要丢弃日志，不丢弃的话将它放到阻塞队列中，通过查看代码，这个阻塞队列为`ArrayBlockingQueueu`，默认大小为256，可以通过配置文件进行修改。`Logger.info(...)`到`append(...)`就结束了，只做了将日志塞入到阻塞队列的事，然后继续执行`Logger.info(...)`下面的语句了。在`AsyncAppenderBase`类中定义了一个`Worker`线程，`run`方法中的关键部分代码如下:

E e = parent.blockingQueue.take();
    aai.appendLoopOnAppenders(e);

从阻塞队列中取出一个日志，并调用`AppenderAttachableImpl`类中的`appendLoopOnAppenders`方法维护一个`Append`列表。`Worker`线程中调用方法过程主要如下图：

![format_png 4][]

最主要的两个方法就是`encode`和`write`方法，前一个法方会根据配置文件中`encode`指定的方式转化为字节码，后一个方法将转化成的字节码写入到文件中去。所以写文件是通过新起一个线程去完成的，主线程将日志扔到阻塞队列中，然后又去做其他事情了。

![format_png 5][]

最后附项目完整代码：https://github.com/TiantianUpup/springboot-log

\-END-

如果看到这里，说明你喜欢这篇文章，请 转发、点赞。同时 标星（置顶）本公众号可以第一时间接受到博文推送。

文末福利：我准备了一份 166 页的 Java 面试题库，高清 PDF 版本，涵盖了 7 大模块，涵盖常见、重点的面试题目。图文并茂，源码解释，喜欢的文末下载。

![format_png 6][]

**下载方式**

***1. *****首先扫描下方二维码**

***2. *****关注后，自动推送下载链接**

![format_png 7][]

[Java]: http://mp.weixin.qq.com/s?__biz=Mzg2MjEwMjI1Mg%3D%3D&chksm=ce0da17bf97a286df119047a25b7de51621fe542816673bb4aa3ebd8ab97b09a86ed7db2e2ee&idx=3&mid=2247489272&scene=21&sn=ce74938072fc73a808d83ccb474db46d#wechat_redirect
[format_png]: /images/20210730/d3a2ebe5f7a94b5b9fcde7dc59f73a58.png
[format_png 1]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9tbWJpei5xcGljLmNuL21tYml6X3BuZy9vVEtIYzZGOHRzZzhZUkIzdWJpY1BuSmFqZU1tcUFpYURVN1VVRzRTOGlhTnVRY1NvdHZDcmdSYVd4ODY5WXRNSXd1dTR2TVM4QkRvNkVRZG5pYW41UXZIOVEvNjQw?x-oss-process=image/format,png
[format_png 2]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9tbWJpei5xcGljLmNuL21tYml6X3BuZy9vVEtIYzZGOHRzZzhZUkIzdWJpY1BuSmFqZU1tcUFpYURVY3FwM3ltaWJJelBOajlKS2Z5QVcwbTlRV1JTZnNlQlByM2ZpY3lyQWd0ZGdMNTgwZTB1dDdIY0EvNjQw?x-oss-process=image/format,png
[format_png 3]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9tbWJpei5xcGljLmNuL21tYml6X3BuZy9vVEtIYzZGOHRzZzhZUkIzdWJpY1BuSmFqZU1tcUFpYURVQkRkQXExWHB1VlE4a1MzeVlCNGJsTDVpYjRoNkY1VUFGWE51Sk1qcEhrTFF5blNUU09BMWFldy82NDA?x-oss-process=image/format,png
[format_png 4]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9tbWJpei5xcGljLmNuL21tYml6X3BuZy9vVEtIYzZGOHRzZzhZUkIzdWJpY1BuSmFqZU1tcUFpYURVNm1EcWliZ0lJTTNtYVNxOFBYN0JBaWJ0VGdmbWV2NzhSVHRIQU1Va3dENzBXcDZNZUJDdklQZmcvNjQw?x-oss-process=image/format,png
[format_png 5]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9tbWJpei5xcGljLmNuL21tYml6X3BuZy9vVEtIYzZGOHRzZzhZUkIzdWJpY1BuSmFqZU1tcUFpYURVdWZlUmx6OFFKWU91aFR0NGljTGxMZzdpYmp2RlNoMGF2eWZYRDhzMWRLZ0RQeWd3NEpydUdnancvNjQw?x-oss-process=image/format,png
[format_png 6]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9tbWJpei5xcGljLmNuL21tYml6X3BuZy9vVEtIYzZGOHRzalV6N1F5QTQzc0pzaWNQcENBUk5jU1FFRnpxVVBmb2tyejJrbFlCeHU1anhtNHRrV3RGUkpCV0tNRkE1dlVGWmJ0OHh1MVU4elZOQkEvNjQw?x-oss-process=image/format,png
[format_png 7]: https://imgconvert.csdnimg.cn/aHR0cHM6Ly9tbWJpei5xcGljLmNuL21tYml6X2pwZy9vVEtIYzZGOHRzalV6N1F5QTQzc0pzaWNQcENBUk5jU1F0VlFEWnRrR3g0ekhTa1A5MUtVNFFQTHo4ams3WGZpYm5BbG92OHBaRVdJQnYwYkgybnNXaWJSdy82NDA?x-oss-process=image/format,png