logback如何按线程打印日志
背景
在一次项目的性能调优中,发现出现竞争瓶颈,导致在资源未使用满的情况下,TPS已经无法提升。祭起JMC(JAVA MISSON CONTROL)飞行记录器大法后,发现线程集中等待在logback写日志的地方,如下图所示:
由于项目组多线程写如同一个文件日志,导致存在IO竞争,一般解决这种问题有三种选择方式
:
- 异步日志,但是会存在断电或者日志队列溢出丢失的可能
- 远程日志,日志放入外部消息队列,保证持久化,但需额外部署日志存储队列
- 多线程日志,按线程(或线程取模)记录日志,减少竞争,日志也能保证持久化
项目组权衡再三,决定采用第三种分线程日志的方式解决。
误入SiftingAppender大坑
项目组使用logback作为日志组件,loback是否有自动分线程写日志的功能呢?网上搜索logack multiThread 的第一篇文章就是教你如何使用SiftingAppender来分线程记录日志如下:
https://dzone.com/articles/si...
SiftingAppender是logback根据mdc中的变量动态创建appender的代理,只要我们将一个线程号作为日志名分发器discriminator注入到SiftingAppender中,它就可以动态的为我们创建不同的appender,达到分线程的目的,配置方式举例如下:
- 配置discriminator
public class ThreadDiscriminator extends ContextBasedDiscriminator {
String KEY ="threadName";
/**
* Return the name of the current context name as found in the logging event.
*/
public String getDiscriminatingValue(ILoggingEvent event) {
return event.getThreadName();
}
public String getDefaultValue() {
return KEY;
}
public String getKey() {
return KEY;
}
public void setKey(String key) {
this.KEY = key;
}
}
- 配置logback appender
<!-- 分线程输出源 -->
<appender name="frameworkthread" class="ch.qos.logback.classic.sift.SiftingAppender">
<discriminator class="ThreadDiscriminator">
<key>threadName</key>
</discriminator>
<sift>
<appender name="FILE-${threadName}" class="ch.qos.logback.core.rolling.RollingFileAppender">
<encoder>
<Encoding>UTF-8</Encoding>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS}[%c][%thread][%X{tradeNo}][%p]-%m%n</pattern>
</encoder>
<rollingPolicy
class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
<fileNamePattern>D:/test/threadlogs/${threadName}-%d{yyyy-MM-dd}.%i.log
</fileNamePattern>
<maxFileSize>100MB</maxFileSize>
<maxHistory>60</maxHistory>
<totalSizeCap>20GB</totalSizeCap>
</rollingPolicy>
</appender>
</sift>
</appender>
配置后查看输出结果也完全正确,网上的方法非常靠谱,真是piece of cake!但是接下来的性能测试让我再次懵逼:性能没有任何提升!反而更加糟糕了!这是怎么一回事呢?继续jmc查看线程状态:
这次写文件outputStream的IO等待竟然提升到了AppenderBase.doAppender方法级别!查看AppenderBase.doAppender实现,这个方法是Synchronized!这个父类的方法是SiftingAppender的入口方法,这意味着在获取/创建线程自己真正的Appender和写入日志之前都必须排队阻塞在这个方法上!阻塞的级别提升了,当然性能更糟糕了!
优化logback:增加无需同步的SiftAppender
logback Appender有两个最基础的抽象类,一个是同步AppenderBase,一个是不同步的UnsynchronizedAppenderBase,这两个类功能一样,只是doAppender方法的同步策略不一样(Synchronize VS ThreadLocal)。那么SiftingAppender为什么继承了AppenderBase而不是UnsynchronizedAppenderBase呢?分析原因应该是SiftingAppender作为Appender的代理集合,它即可能包含了继承自UnsynchronizedAppenderBase的OutputStreamAppender(FileAppender的基类,自行实现底层同步,doAppend方法未同步),也可能包含了继承AppenderBase的SocketAppender类(doAppend方法同步),为防止出现线程安全问题,它直接在自身的doAppend方法上进行了同步。
在项目组实际使用时,项目组只需要分线程写文件日志,这意味这它使用的最终FileAppender应该是线程安全,完全独立的。故我们尝试在logback新增继承于UnsynchronizedAppenderBase的ParrelSiftingAppender步骤如下:
- logback core中增加继承UnsynchronizedAppenderBase的UnsynchronizedSiftingAppenderBase
- logback classic中增加继承UnsynchronizedSiftingAppenderBase的ParrelSiftingAppender
- logback classic中SiftAction注册增加ParrelSiftingAppender的工厂注册
修改完成后测试发现果然性能提升了5倍左右,CPU资源利用率接近饱和,应该基本达到效果了,JMC分析应该是没有竞争了把,但是发现新的竞争方法出现了:
Appender<E> appender = appenderTracker.getOrCreate(discriminatingValue, timestamp);
最终改进:使用ConcurrentHashMap替换LinkedHashMap
原来在SiftingAppender内部使用了LinkedHashMap作为LRU Cache来管理Appender,会定期移除。由于LinkedHashMap不是线程安全的,故在getOrCreate方法上增加了Synchronized同步操作,造成竞争等待。
结合业务场景,这里完全可以使用ConcurrentHashMap作为Appender的缓存,ConcurrentHashMap读写锁分离,并且key值分区上锁,在多读少写的情况下,有很高的并发性能。并且真正生成的日志Appender也并不多(100个左右),定时清理完全也不会出现内存溢出问题。
开始动手修改appenderTracker步骤如下:
- logback core中增加AbstractConcurrentMapComponentTracker
- logback core中增加ConcurrentMapAppenderTracker继承
AbstractConcurrentMapComponentTracker
- 修改UnsynchronizedSiftingAppenderBase使用ConcurrentMapAppenderTracker进行Appender管理
最终性能测试结果:在资源相同的情况下,优化后比使用LinkedHashMap性能提高一倍。至此,整个logback多线程调优结束,通过充分优化同步竞争的方式,最终使得分线程记录日志的性能比最原始的多线程写同一文件提高了10倍(SiftAppender去锁提高到5倍,Map替换提高2倍)!
转载:https://segmentfault.com/a/1190000016204970
原文地址:https://www.cnblogs.com/minikobe/p/12161369.html
- Python 工匠:编写条件分支代码的技巧
- python3 下 Zabbix监控调用graph.get并且下载监控图
- 用R语言复盘美国总统大选结果~
- 最新Apache Spark平台的NLP库,助你轻松搞定自然语言处理任务
- 使用Seq2Seq+attention实现简单的Chatbot
- R语言可视化——用ggplot构造期待已久的雷达图
- 【实战】最新Deep Learning with Keras图书加代码,教你从零开发一个复杂深度学习模型(附下载)
- 基于zabbix 自动抓取每天监控数据!/usr/local/python/bin/python3.5
- 大过年的,一起来用Seq2Seq来作对联吧!
- python3 下调用zabbix api 获取多个机房的IP
- TensorFlow从0到1 - 14 - 交叉熵损失函数——防止学习缓慢
- 用优雅的配色来缔造图表专业主义~
- python文件名与包名冲突
- python3 Zabbix监控-api的使用-python
- JavaScript 教程
- JavaScript 编辑工具
- JavaScript 与HTML
- JavaScript 与Java
- JavaScript 数据结构
- JavaScript 基本数据类型
- JavaScript 特殊数据类型
- JavaScript 运算符
- JavaScript typeof 运算符
- JavaScript 表达式
- JavaScript 类型转换
- JavaScript 基本语法
- JavaScript 注释
- Javascript 基本处理流程
- Javascript 选择结构
- Javascript if 语句
- Javascript if 语句的嵌套
- Javascript switch 语句
- Javascript 循环结构
- Javascript 循环结构实例
- Javascript 跳转语句
- Javascript 控制语句总结
- Javascript 函数介绍
- Javascript 函数的定义
- Javascript 函数调用
- Javascript 几种特殊的函数
- JavaScript 内置函数简介
- Javascript eval() 函数
- Javascript isFinite() 函数
- Javascript isNaN() 函数
- parseInt() 与 parseFloat()
- escape() 与 unescape()
- Javascript 字符串介绍
- Javascript length属性
- javascript 字符串函数
- Javascript 日期对象简介
- Javascript 日期对象用途
- Date 对象属性和方法
- Javascript 数组是什么
- Javascript 创建数组
- Javascript 数组赋值与取值
- Javascript 数组属性和方法
- 深入解析Apache NIFI的调度策略
- Linux 帮助命令及工具(tldr,man,help,info)
- Json Jolt教程
- Linux 日常操作
- 回顾|腾讯云 CFS 文件存储给 Serverless 云函数带来的业务新场景
- Apache NIFI Run Duration深入理解
- Controller services are daemons
- 动手体验JVM中Class对象的唯一性
- Java SPI机制
- Apache NIFI项目结构的类资源隔离机制
- Java类加载器
- Java反射原理
- 小谈WEB简史
- Java 常用验证方法(commons-validator,hutool)
- 类加载机制