性能测试三十七:线程死锁和阻塞

一、线程死锁

线程死锁就是有两个以上的线程,一个线程锁住了资源A,又想去锁定资源B,另外一个线程锁定了资源B,又想去锁定资源A,两个线程都想去得到对方的资源,而又不愿释放自己的资源
从而造成一种互相等待,无法执行的情况

 

接口:http://localhost:8080/PerfTeach/DeadServlet

因为要出现线程死锁至少要2个用户,所以用3个并发,永远跑

TPS:

响应时间

使用jstat -gcutil查看,JVM正常

 

使用dstat -tcdlmnsygr查看,cpu没什么压力

 

通过浏览器访问接口,没有响应

 

jvisualvm查看

 

jstack查看:使用jstack把堆栈日志打印到a.log里面

打开直接翻到最后,第8、4、7个线程出现死锁,并且会在下面把这三个线程拿出来打印

出现死锁的位置和原因:

所以是线程7锁定了资源,然后线程8和4在等待线程7解锁

看一下代码:出现了嵌套锁

 

 

现象:出现死锁后,tps降为0,压力测试工具无法得到服务器的响应,服务器硬件资源空闲,通过jvisualvm去查看线程情况,至少两个线程一直处于红色的阻塞状态
死锁经常表现为程序的停顿,或者不再响应用户的请求。从操作系统上观察,对应进程的CPU占用率为零

 

解锁办法:重启tomcat

 

定位方法:通过jvisualvm或者jstack,进行线程dump,对线程状态进行分析,获取到哪行代码导致的死锁,如:

Found one Java-level deadlock:
http-bio-8080"-exec-162":
waiting to lock monitor 0x0818abac (object 0x84b40ad0, a com.lee.domain.Order),
which is held by ""http-bio-8080"-exec-158"
""http-bio-8080"-exec-158":
waiting to lock monitor 0x08188cd0 (object 0x84b3bc48, a com.lee.domain.Order),
which is held by ""http-bio-8080"-exec-162"

Java stack information for the threads listed above:

 

死锁一般解决思路:
1、避免嵌套加锁
2、减小锁粒度,锁越少越不容易发生死锁

 

二、线程阻塞 

 

线程阻塞问题-log4j日志级别问题
接口:http://localhost:8080/PerfTeach/Block?userId=1

30个并发永远跑,dstat监控起来:dstat -tcdlmnsygr --disk-util

从资源上看,问题不大

TPS:550左右

响应时间:46左右

一般在项目中发现响应式时间长,监控一下线程

右上角Dump,多Dump几次,这里Dump3次,然后把3个快照里面的内容分别复制3个文本里面,直接ctrl+f搜BLOCKED

 

 

代码里面这一行在打印日志

 log4j代码里面有锁

 

解决方案:

1、还是用log4j,但是把日志打印级别提高,在代码里面减少不必要的日志打印输出

2、换其他日志组件如:log4j2、logback

 

log4j.xml中设置的日志级别,程序会打印在此级别之上日志
Error、Warn、Info、debug,级别越低,日志越多

cd /home/apps/app-PerfTeach/PerfTeach/WEB-INF/classes/

vi log4j.xml

默认打印级别是debug,改为error

 

重启tomcat

 

 还是30个并发,永远跑

 

看一下tomcat下的日志

cd /home/server/tomcat-PerfTeach01/bin/D\:/

tail -f output.log

全是error级别的

TPS:900左右

响应时间:40左右

和刚才相比,TPS和响应时间都有明显的提升,由于配置比较低,这里提升不明显,真实公司里面的配置,最少提升2--3倍

 

从线程监控看,阻塞情况减少很多了,这个阻塞情况是因为打印error的日志

 

线程问题排查流程:
1、做线程dump
2、在dump文件中搜索关键字"BLOCKED"、"TIME_WAITTING",查看每种状态的count数量
3、按照上述关键字搜索,查看跟本系统有关的业务代码堆栈信息

posted @ 2019-03-23 11:55  后知后觉~  阅读(421)  评论(0编辑  收藏  举报