1、在Linux通过jmeter -n -t test.jmx脚本设置50-100-150并发、点击调度器、持续压测300秒
2、发现TPS在50并发的时候就已经可以达到3000/sec、但是分别设置并发为100和150的时候、此时的TPS还是3000/sec
3、但是通过dstat -tcmnd --disk-util 命令去监控的时候发现CPU的使用率始终没有很大的波动、空闲95%左右、只占用了5%左右、说明此时不存在fullGC和youngGC 内存泄露和内存溢出的问题
4、那么此时只能进行进一步的排查和定位、通过jstack 进程号 >1.log jstack 进程号 2.log命令去获取对应的日志、看一下是不是线程阻塞的问题
5、然后把捕捉的日志下载到本地用notepad++打开、发现Thread.stat:Blocked阻塞的地方多达70多个地方
6、log4j发生了阻塞、通过分析代码发现log4j的jar通过反编译工具打开之后、找到了Category.class这个类、里面的第204行调了一个方法叫做callAppenders里面用了synchronized的锁
7、log4j里面的加了很多的锁、其实也是为了打日志的时候保证线程安全、为了保证日志的完整性一行一行的打日志、但是确牺牲了大部分的性能
8、那么怎么解决这个问题呢? ==》最好的办法就是不用log4j、但是现在大部分项目还是需要打日志功能的、或者减少代码中没有必要的日志输出、提升日志等级减少日志
可以进入项目中找到log4j.properties这个文件把log4j.rootLogger=info 中的info改为error、提升打日志的等级 =》然后重启项目
这个进行优化之后、重新压测发现TPS达到了9400/sec 、优化阻塞之后发现性能提升了3倍左右、CPU也占用了15%左右
9、还可以用log4j2==》这个在原来的log4j的基础上做了重构做了性能的优化、做了异步处理比log4j和logback有了18倍的性能的提升
10、线程阻塞问题的排查方法:
1)先做线程的dump拉取日志
2)在dump文件里面搜索blocked和time_waiting查看每种状态的count数量
3)按照关键字的搜索、然后找到和本系统有关的业务代码的堆栈信息进行进一步的排查