Java日志Logback

1、目标

  1. 日志输出到文件并根据LEVEL级别将日志分类保存到不同文件
  2. 通过异步输出日志减少磁盘IO提高性能

  3. 异步输出日志的原理

    2、配置文件logback-spring.xml

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

    1. <?xml version="1.0" encoding="utf-8"?>
    2. <configuration>
    3.  <property resource="logback.properties"/>
    4.  <appender name="CONSOLE-LOG" class="ch.qos.logback.core.ConsoleAppender">
    5.      <layout class="ch.qos.logback.classic.PatternLayout">
    6.          <pattern>[%d{yyyy-MM-dd' 'HH:mm:ss.sss}] [%C] [%t] [%L] [%-5p] %m%n</pattern>
    7.      </layout>
    8.  </appender>
    9.  <!--获取比info级别高(包括info级别)但除error级别的日志-->
    10.  <appender name="INFO-LOG" class="ch.qos.logback.core.rolling.RollingFileAppender">
    11.      <filter class="ch.qos.logback.classic.filter.LevelFilter">
    12.          <level>ERROR</level>
    13.          <onMatch>DENY</onMatch>
    14.          <onMismatch>ACCEPT</onMismatch>
    15.      </filter>
    16.      <encoder>
    17.          <pattern>[%d{yyyy-MM-dd' 'HH:mm:ss.sss}] [%C] [%t] [%L] [%-5p] %m%n</pattern>
    18.      </encoder>
    20.      <!--滚动策略-->
    21.      <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
    22.          <!--路径-->
    23.          <fileNamePattern>${LOG_INFO_HOME}//%d.log</fileNamePattern>
    24.          <maxHistory>30</maxHistory>
    25.      </rollingPolicy>
    26.  </appender>
    27.  <appender name="ERROR-LOG" class="ch.qos.logback.core.rolling.RollingFileAppender">
    28.      <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
    29.          <level>ERROR</level>
    30.      </filter>
    31.      <encoder>
    32.          <pattern>[%d{yyyy-MM-dd' 'HH:mm:ss.sss}] [%C] [%t] [%L] [%-5p] %m%n</pattern>
    33.      </encoder>
    34.      <!--滚动策略-->
    35.      <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
    36.          <!--路径-->
    37.          <fileNamePattern>${LOG_ERROR_HOME}//%d.log</fileNamePattern>
    38.          <maxHistory>30</maxHistory>
    39.      </rollingPolicy>
    40.  </appender>
    42.  <root level="info">
    43.      <appender-ref ref="CONSOLE-LOG" />
    44.      <appender-ref ref="INFO-LOG" />
    45.      <appender-ref ref="ERROR-LOG" />
    46.  </root>
    47. </configuration>

    部分标签说明
    <root>标签，必填标签，用来指定最基础的日志输出级别

  • <appender-ref>标签，添加append

<append>标签，通过使用该标签指定日志的收集策略

  • name属性指定appender命名
  • class属性指定输出策略，通常有两种，控制台输出和文件输出，文件输出就是将日志进行一个持久化。ConsoleAppender将日志输出到控制台

<filter>标签，通过使用该标签指定过滤策略

  • <level>标签指定过滤的类型

<encoder>标签，使用该标签下的<pattern>标签指定日志输出格式。
<rollingPolicy>标签指定收集策略，比如基于时间进行收集

  • <fileNamePattern>标签指定生成日志保存地址 通过这样配置已经实现了分类分天日志的目标了

    3、logback 高级特性异步输出日志

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

0 256 

  1. <a name="OGlKK"></a>
  2. ### 4、异步输出日志性能测试
  3. 既然能提高性能的话，必须进行一次测试比对，同步和异步输出日志性能到底能提升多少倍？
  4. <a name="bDyQD"></a>
  5. ### 5、服务器硬件
  7. - CPU 六核
  8. - 内存 8G
  9. <a name="YLZtC"></a>
  10. ### 6、测试工具
  11. Apache Jmeter
  12. <a name="kG6BU"></a>
  13. ### 7、同步输出日志
  15. - 线程数：100
  16. - Ramp-Up Loop(可以理解为启动线程所用时间) ：0 可以理解为100个线程同时启用
  17. - 测试结果
  19. ![](https://cdn.nlark.com/yuque/0/2022/webp/396745/1641555561772-cfdc5fe9-b549-476b-b68f-8d50c01a7c27.webp#clientId=ua6bf87e6-e2ca-4&crop=0&crop=0&crop=1&crop=1&from=paste&id=u69991553&margin=%5Bobject%20Object%5D&originHeight=536&originWidth=1000&originalType=url&ratio=1&rotation=0&showTitle=false&status=done&style=none&taskId=u44b43c71-e93e-4245-ad84-76d81456386&title=)<br />重点关注指标 Throughput【TPS】 吞吐量：系统在单位时间内处理请求的数量，在同步输出日志中 TPS 为 44.2/sec
  20. <a name="HzcPx"></a>
  21. ### 8、异步输出日志
  23. - 线程数 100
  24. - Ramp-Up Loop：0
  25. - 测试结果
  27. ![](https://cdn.nlark.com/yuque/0/2022/webp/396745/1641555561977-344f8d1f-4a32-494e-bed2-b327f8a596da.webp#clientId=ua6bf87e6-e2ca-4&crop=0&crop=0&crop=1&crop=1&from=paste&id=u182986dc&margin=%5Bobject%20Object%5D&originHeight=548&originWidth=1009&originalType=url&ratio=1&rotation=0&showTitle=false&status=done&style=shadow&taskId=ue31e31fb-361d-4a38-b776-7046f93216f&title=)<br />TPS 为 497.5/sec ， 性能提升了10多倍！！！
  28. <a name="I41TZ"></a>
  29. ### 9、异步日志输出原理
  30. 从logback框架下的Logger.info方法开始追踪。一路的方法调用路径如下图所示：<br />![](https://cdn.nlark.com/yuque/0/2022/webp/396745/1641555562183-f5581712-f50e-4bfa-9f42-411234a6a615.webp#clientId=ua6bf87e6-e2ca-4&crop=0&crop=0&crop=1&crop=1&from=paste&id=u8f2ccbae&margin=%5Bobject%20Object%5D&originHeight=578&originWidth=742&originalType=url&ratio=1&rotation=0&showTitle=false&status=done&style=shadow&taskId=u073445bf-5a18-4540-9e4f-e2fa9e578d4&title=)<br />异步输出日志中最关键的就是配置文件中ch.qos.logback.classic``AsyncAppenderBase``append
  31. ```java
  32. protected void append(E eventObject) {
  33.     if(!this.isQueueBelowDiscardingThreshold() || !this.isDiscardable(eventObject)) {
  34.         this.preprocess(eventObject);
  35.         this.put(eventObject);
  36.     }
  37. }

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

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

从阻塞队列中取出一个日志，并调用AppenderAttachableImpl类中的appendLoopOnAppenders方法维护一个Append列表。Worker线程中调用方法过程主要如下图：
Logback 配置文件优化 - 图1
最主要的两个方法就是encodewriteencode