logback异步输出日志详解
前言
logback应该是目前最流行的日志打印框架了,毕竟Spring Boot中默认的集成的日志框架也是logback。在实际项目开发过程中,常常会遇到由于打印大量日志而导致程序并发降低,QPS降低的问题,而通过logback异步日志输出则能很大程度上解决这个问题。
一、什么是Appender?
logback官方文档:https://logback.qos.ch/manual/appenders.html
logback中文文档
官方介绍:
Logback 将编写日志事件的任务委托给名为 Appenders 的组件,Appenders 必须实现ch.qos.logback.core.Appender的接口。
简单来说,Appender就是用来处理logback框架下日志输出事件的组件
。
Appender接口的核心方法如下:
package ch.qos.logback.core;import ch.qos.logback.core.spi.ContextAware;
import ch.qos.logback.core.spi.FilterAttachable;
import ch.qos.logback.core.spi.LifeCycle;public interface Appender<E> extends LifeCycle, ContextAware, FilterAttachable {public String getName();public void setName(String name);//核心方法:处理日志事件void doAppend(E event);}
其中doAppend()方法是 logback 框架中最重要的方法。它负责将日志事件以适当的格式输出到适当的输出设备
。
二、Appender类图
说明:
OutputStreamAppender 是另外三个附加程序的超类,即 ConsoleAppender 和 FileAppender,后者又是 RollingFileAppender 的超类。下一个图说明了 OutputStreamAppender 及其子类的类图。
1、控制台日志输出 ConsoleAppender
配置示例:
<configuration><appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"><encoder><pattern>%-4relative [%thread] %-5level %logger{35} - %msg %n</pattern></encoder></appender><root level="DEBUG"><appender-ref ref="STDOUT" /></root></configuration>
说明:
控制台日志输出主要是在开发环境采用,比如在IDEA中开发时,可以清楚直观得在控制台看到运行日志,更方便程序调试。当应用发布到测试环境、生产环境时,建议关闭控制台日志输出,以提高日志输出的吞吐量,减少不必要的性能开销。
2、单日志文件输出 FileAppender
配置示例:
<configuration><appender name="FILE" class="ch.qos.logback.core.FileAppender"><!-- 日志文件名称 --><file>testFile.log</file><!-- 是否追加输出 --><append>true</append><!-- 立即刷新,设置成false可以提高日志吞吐量 --><immediateFlush>true</immediateFlush><encoder><!-- 日志输出格式 --><pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern></encoder></appender><root level="DEBUG"><appender-ref ref="FILE" /></root>
</configuration>
弊端:
采用单日志文件输出日志,很容易导致日志文件的体积一直膨胀,不利于日志文件的管理和查看。一般很少采用。
3、滚动日志文件输出 RollingFileAppender
配置示例:
<configuration><appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender"><!-- 日志文件名称 --><file>logFile.log</file><rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"><!-- 按天滚动生成历史日志文件 --><fileNamePattern>logFile.%d{yyyy-MM-dd}.log</fileNamePattern><!-- 历史日志文件保存的天数和容量大小--><maxHistory>30</maxHistory><totalSizeCap>3GB</totalSizeCap></rollingPolicy><encoder><pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern></encoder></appender> <root level="DEBUG"><appender-ref ref="FILE" /></root>
</configuration>
说明:
通过rollingPolicy 配置日志文件的滚动生成策略,以及历史日志文件保存的天数和总容量大小,
是测试环境和生产环境最推荐的日志输出方式
。
三、同步输出和异步输出比较
同步输出
传统的日志打印采用的是同步输出的方式,所谓同步日志,即当输出日志时,必须等待日志输出语句执行完毕后,才能执行后面的业务逻辑语句。
使用logback的同步日志进行日志输出,日志输出语句与程序的业务逻辑语句将在同一个线程运行。在高并发场景下,日志数量不但激增,作为磁盘IO来说,容易产生瓶颈,导致线程卡顿在生成日志过程中,会影响程序后续的主业务,降低程序的性能。
异步输出
使用异步日志进行输出时,日志输出语句与业务逻辑语句并不是在同一个线程中运行,而是有专门的线程用于进行日志输出操作,处理业务逻辑的主线程不用等待即可执行后续业务逻辑。这样即使日志没有完成输出,也不会影响程序的主业务,从而提高了程序的性能。
四、异步日志实现原理AsyncAppender
logback异步输出日志是通过AsyncAppender实现的。AsyncAppender可以异步的记录 ILoggingEvents日志事件。
但是这里需要注意,AsyncAppender只充当事件分配器,它必须引用另一个Appender才能完成最终的日志输出。
示意图:
Logback的异步输出采用生产者消费者的模式,将生成的日志放入消息队列中,并将创建一个线程用于输出日志事件,有效的解决了这个问题,提高了程序的性能。
logback中的异步输出日志使用了AsyncAppender这个appender,通过看AsyncAppender源码,跟到它的父类AsyncAppenderBase,可以看到它有几个重要的成员变量:
AppenderAttachableImpl<E> aai = new AppenderAttachableImpl<E>();
BlockingQueue<E> blockingQueue;
AsyncAppenderBase<E>.Worker worker = new AsyncAppenderBase.Worker();
lockingQueue是一个队列,Worker是一个消费线程,基本可以判定是个生产者消费者模式。
再看消费者(work)的主要代码:
while (parent.isStarted()) {try {E e = parent.blockingQueue.take(); //单条循环aai.appendLoopOnAppenders(e);} catch (InterruptedException ie) {break;}
}
使用的是while单条循环 ,即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" /><!-- 设置异步阻塞队列的大小,为了不丢失日志建议设置的大一些,单机压测时100000是没问题的,应该不用担心OOM --><queueSize>10000</queueSize><!-- 设置丢弃DEBUG、TRACE、INFO日志的阀值,不丢失 --><discardingThreshold>0</discardingThreshold><!-- 设置队列入队时非阻塞,当队列满时会直接丢弃日志,但是对性能提升极大 --><neverBlock>true</neverBlock></appender><root level="DEBUG"><appender-ref ref="ASYNC" /></root></configuration>
核心配置参数说明:
属性名 | 类型 | 描述 |
---|---|---|
queueSize | int | BlockingQueue的最大容量,默认情况下,大小为256。 |
discardingThreshold | int | 设置日志丢弃阈值, 默认情况下,当队列还有20%容量,他将丢弃trace、debug和info级别的日志,只保留warn和error级别的日志。 |
includeCallerData | boolean | 提取调用方数据可能相当昂贵。若要提高性能,默认情况下,当事件添加到事件队列时,不会提取与事件关联的调用方数据。默认情况下,只复制线程名和 MDC 等“廉价”数据。通过将 includeecallerdata 属性设置为 true,可以指示此附加程序包含调用方数据。 |
maxFlushTime | int | 根据被引用的 appender 的队列深度和延迟,AsyncAppender 可能需要不可接受的时间来完全刷新队列。当 LoggerContext 停止时,AsyncAppender stop 方法将等待工作线程完成直到超时。使用 maxFlushTime 指定最大队列刷新超时(以毫秒为单位)。无法在此窗口内处理的事件将被丢弃。此值的语义与 Thread.join (long)的语义相同。 |
neverBlock | boolean | 默认是false,代表在队列放满的情况下是否卡住线程。也就是说,如果配置neverBlock=true,当队列满了之后,后面阻塞的线程想要输出的消息就直接被丢弃,从而线程不会阻塞。 |
默认情况下,event queue配置最大容量为256个events。如果队列已经满了,那么应用程序线程将被阻塞,无法记录新事件,直到工作线程有机会分派一个或多个事件。当队列不再达到最大容量时,应用程序线程可以再次开始记录事件。因此,当应用程序在其事件缓冲区的容量或附近运行时,异步日志记录就变成了伪同步。这未必是件坏事,AsyncAppender异步追加器设计目的是允许应用程序继续运行,尽管需要稍微多一点的时间来记录事件,直到附加缓冲区的压力减轻。
优化 appenders 事件队列的大小以获得最大的应用程序吞吐量取决于几个因素
。
下列任何或全部因素都可能导致出现伪同步行为:
大量的应用程序线程
每个应用程序调用都有大量的日志事件
每个日志事件都有大量数据
子级appenders的高延迟
为了保持事情的进展,增加队列的大小通常会有所帮助,代价是减少应用程序可用的堆
。
为了减少阻塞,在缺省情况下,当队列容量保留不到20% 时,AsyncAppender 将丢失 TRACE、 DEBUG 和 INFO 级别的事件,只保留 WARN 和 ERROR 级别的事件。这种策略确保了对日志事件的非阻塞处理(因此具有优异的性能) ,同时在队列容量小于20% 时减少 TRACE、 DEBUG 和 INFO 级别的事件。事件丢失可以通过将丢弃阈值属性设置为0(零)来防止。
六、性能测试
这部分自己还没时间做测试,引用网上的一些测试数据。
既然能提高性能的话,必须进行一次测试比对,同步和异步输出日志性能到底能提升多少倍?
服务器硬件
- CPU 六核
- 内存 8G
测试工具
- Apache Jmeter
1、同步输出日志
- 线程数:100
- Ramp-Up Loop(可以理解为启动线程所用时间) :0 可以理解为100个线程同时启用
测试结果:
重点关注指标 Throughput【TPS】 吞吐量:系统在单位时间内处理请求的数量,在同步输出日志中 TPS 为 44.2/sec
2、异步输出日志
线程数 100
Ramp-Up Loop:0
测试结果:
TPS 为 497.5/sec , 性能提升了10多倍!!!
参考文章:
logback那些事儿
logback异步输出日志详解相关推荐
- Snort日志输出插件详解
Snort日志输出插件详解 Snort是一款老×××的开源***检测工具,本文主要讨论他作为日志分析时的各种插件的应用.Snort的日志一般位于:/var/log/snort/目录下.可以通过修改配置 ...
- snort 日志 mysql_Snort日志输出插件详解
Snort日志输出插件详解 Snort是一款老×××的开源***检测工具,本文主要讨论他作为日志分析时的各种插件的应用.Snort的日志一般位于:/var/log/snort/目录下.可以通过修改配置 ...
- 从零开始玩转 logback、完整配置详解
官网地址:https://logback.qos.ch/manual/index.html 前些天发现了一个巨牛的人工智能学习网站,通俗易懂,风趣幽默,忍不住分享一下给大家.点击跳转到教程. 概述 L ...
- SpringBoot2.1.5(16)--- Spring Boot的日志详解
SpringBoot2.1.5(16)--- Spring Boot的日志详解 市面上有许多的日志框架,比如 JUL( java.util.logging), JCL( Apache Commons ...
- MySQL管理之日志详解
MySQL日志详解 错误日志 MySQL的错误信息是在data目录下的 错误日志本身所定义的内容本身是可以定义的 编辑配置文件,定义错误日志: log-error=/path/to/xx.err ...
- JVM GC 日志详解
本文采用的JDK版本: java version "1.8.0_144" Java(TM) SE Runtime Environment (build 1.8.0_144-b01) ...
- Android Loader 异步加载详解二:探寻Loader内部机制
Android Loader 异步加载详解二:探寻Loader内部机制 转载请标明出处:http://blog.csdn.net/zhaoyanjun6/article/details/7025991 ...
- JVM从入门到精通(十一): CMS日志详解,G1日志详解,JVM常见参数总结;补充纤程知识
CMS 日志格式分析 使用CMS:添加参数UserConcMarkSweepGC(CMS+ParNew) CMS常用参数 -XX:+UseConcMarkSweepGC -XX:ParallelCMS ...
- Hadoop日志详解
文章目录 1 Hadoop日志详解 2 Hadoop 系统服务输出的日志 2.1 修改Hadoop系统服务日志目录(包括NameNode.secondarynamenode.datanode.reso ...
最新文章
- 《LeetCode力扣练习》第136题 只出现一次的数字 Java
- shell实例第7讲:awk命令
- 计算机可执行指令吧,电脑“开始-运行”的常用命令及用法!很有用!
- DiskFileItemFactory API详解
- [探索] 利用promise做一个请求锁
- 定义一个类:实现功能可以返回随机的10个数字,随机的10个字母, 随机的10个字母和数字的组合;字母和数字的范围可以指定,类似(1~100)(A~z)...
- 直入灵魂的Python教学:《看动漫学Python》让学习不再枯燥
- 芯片业巨震!英特尔拟90亿美元卖掉NAND闪存业务
- nginx配置二级目录,反向代理不同ip+端口
- Unity3D实践3:BOSS血条
- 【小技巧】33 个神经网络「炼丹」技巧
- 62. 拆分初始化负载
- win32-字体名称中文名和英文名的对照-c++
- IDEA启动Tomcat中文乱码(已解决)
- Adobe Experience Cloud落地中国,Adobe、微软与世纪互联共庆三方合作
- 容易的计算机科技核心期刊,计算机类容易中的期刊
- 回流reflow与重绘repaint
- 可扩展性设计之数据切分
- 香港坚固金业的黑幕,属于非法投资平台。
- Go 1.19 发行说明(翻译)