性能文章>记一次异步日志设置不合理导致线程阻塞问题排查>

记一次异步日志设置不合理导致线程阻塞问题排查原创

8月前
182503

作为PerfMa解决方案管理部门的技术专家,我在工作遇见过很多各种问题导致的性能问题,并参与了为客户的系统进行性能诊断调优的全过程。其中有一次,碰到了一个异步日志设置不合理导致线程阻塞的情况。用文字记录下了问题的整个发现-排查-分析-优化的过程,排查过程中使用了我司商业化产品——XSea压测平台
和XLand性能分析平台,通过文章主要希望跟大家分享下分析和优化思路以及注意点,有兴趣深入了解的同学可以评论交流。

问题现象:

压测过程中发现响应时间较长(1秒多),但从XSea链路视角并未发现获取db连接慢,慢sql,访问db/redis次数特别高的情况。

分析过程:

1.png
2.jpg

一笔请求访问21次redis,54次oracle,2次mysql,从链路树看获取连接,mybatis层的SelectOne和SelectList方法比较慢,但执行sql,redis交互都很快。
3.jpg
通过离线线程dump发现大量tomcat线程处于waiting状态。
4444.jpg
继续分析线程栈发现大量业务线程阻塞在写日志相关方法上,注意栈上有个ArrayBlockingQueue.put方法,由此怀疑logback配置了异步日志,业务线程将需要打印的日志放入队列,由专门的日志线程输出到各Appender。

查看logback配置发现确实配置了异步日志,但一般情况下配置异步日志就是用来解决业务线程由于打印日志导致IO阻塞的问题,为什么还会阻塞呢?

继续检查logback配置,发现两个问题:
1.日志级别是debug,所以日志量比较多
2. 设置了<discardingThreshold>0</discardingThreshold>,discardingThreshold是一个阈值。

当队列的剩余容量小于这个阈值并且当前日志level TRACE, DEBUG or INFO,则丢弃这些日志,当discardingThreshold为0则不会丢弃日志level TRACE, DEBUG or INFO的日志。而此时由于日志级别为debug,日志量很大,且磁盘IO性能不高,异步日志线程已经来不及输出,队列也满了,业务线程又不能丢弃日志,就会导致阻塞

优化建议:

1.discardingThreshold设置大于0的值,当队列满时允许丢弃TRACE, DEBUG,INFO级别的日志

2.设置neverBlock为true,则写日志队列时候会调用ArrayBlockingQueue对的offer方法而不是put,而offer是非阻塞的。可知如果队列满则直接返回,而不是被挂起当前线程。
5.png

请先登录,再评论

暂无回复,快来写下第一个回复吧~

为你推荐

慌了!LinkedHashMap和hashTable的Entry居然有500w之多,还无法回收
故障介绍某一日早上七点,我还在睡梦之中,8点醒来发现运维群内有人at。一看说是用户服务的一个节点挂掉了。然后大概原因是因为OOM,运维还在群里发了一个jstack 的栈dump文件,未必是事故发生时的
一次 ES-APM 导致的大量线程阻塞问题排查
前段时间我们接入了某公司出品的 Elastic-APM 作为全链路监控平台,终结了我好几年前撸的字节码注入全链路监控平台。前段时间有一个业务在启动过程中,会概率性出现大量线程阻塞,导致可对外提供服务的
HeapDump性能社区Full GC异常问题排查实战案例精选合集
处理过线上问题的同学基本都遇到过系统突然运行缓慢,CPU 100%,以及 Full GC 次数过多的问题。这些问题最终导致的直观现象就是系统运行缓慢,并且有大量的报警。本期小编集合了HeapDump性
记一次异步日志设置不合理导致线程阻塞问题排查
作为PerfMa解决方案管理部门的技术专家,我在工作遇见过很多各种问题导致的性能问题,并参与了为客户的系统进行性能诊断调优的全过程。其中有一次,碰到了一个异步日志设置不合理导致线程阻塞的情况。用文字记
记一次类加载失败导致线程阻塞问题排查
作为PerfMa解决方案管理部门的技术专家,我在工作遇见过很多各种问题导致的性能问题,并参与了为客户的系统进行性能诊断调优的全过程。这一次碰到了一个类加载失败导致的性能问题。用文字记录下了问题的整个发
Spring Cloud Gateway 雪崩了,我人都傻了
大家好,我又人傻了。这次的经验告诉我们,出来写代码偷的懒,迟早要还的。 问题现象与背景昨晚我们的网关雪崩了一段时间,现象是:1.不断有各种微服务报异常:在写 HTTP 响应的时候,连接已经关闭:```
Netty堆外内存泄漏排查盛宴
如果使用了 Netty 堆外内存,那么可以自行监控堆外内存的使用情况,不需要借助第三方工具,我们是使用的“反射”拿到的堆外内存的情况。逐渐缩小范围,直到 Bug 被找到。当我们确认某个线程的执行带来 Bug 时,可单步执行,可二分执行,定位到某行代码之后,跟到这段代码,然后继续单步执行或者二分的方
Java 问题排查技术分享
最近翻看以前写的 PPT, 发现了在2019年做的一次技术分享,关于 Java 问题排查,由于没什么公司机密可言,整理下分享给大家~线上问题处理流程直接放PPT截图吧,现在看来依然不过时问题排查可从三个方面入手知识:有些问题,思考一下就有答案,就像传说中多隆那样,回忆下就知