MyException - 我的异常网
当前位置:我的异常网» 综合 » java线程数过高缘故分析

java线程数过高缘故分析

www.MyException.Cn  网友分享于:2013-08-09  浏览:0次
java线程数过高原因分析

作者:鹿丸不会多项式  出处:http://www.cnblogs.com/hechao123   转载请先与我联系。

一、问题描述

前阵子我们因为B机房故障,将所有的流量切到了A机房,在经历了推送+自然高峰之后,A机房所有服务器都出现java线程数接近1000的情况(1000是设置的max值),在晚上7点多观察,java线程数略有下降,但还是有900+的样子,而此时,单台服务器的TPS维持在400/s,并不是一个特别大的量。然后将A机房一台机器下线,继续观察,到了晚上9点多,那台下线的机器,jetty进程的java线程数还是7、800的样子。同时,同一机房的另外一台还在线的机器在重启jetty之后,在同样tps400+的情况,线程数一直保持在只有300多。这就很奇怪了,下线的机器都没有请求了,java线程数怎么还是这么多?会不会是多线程竞争资源,导致阻塞?开始研究这个问题。

二、保存现场

保存哪些现场

我先查看并记录了当时的jetty进程的线程数、db连接数、cpu负载、内存使用情况、tps、nginx连接数、jetty错误日志、GC情况、tcp连接状态等,都是正常。
然后我用jstack命令导出当前jvm的所有线程快照,用jmap命令将当前java堆转储快照导出,结果发现,除了java线程数之外,其他指标也都是正常。
这里先说下jstack和jmap使用的常用参数举例和注意事项:

找到jetty进程pid

对于这两个命令,首先都需要找出jetty进程对应的pid,当然可以使用jps命令来查找对应的pid。
但是,我当前linux用户是自己的用户名用户,而公司外网服务器我并没有jetty的权限,也就是说jps命令只有jetty用户可以查看。
在网上找了下资料,这里我采用的是这种方式,用ps aux|grep jetty.xml找到了jetty进程对应的pid。

jstack保存线程快照

我使用jstack完整命令是:“sudo -u jetty /data/java/bin/jstack -l pid >> ~/jstack.txt”。-l 参数是将锁的信息也打印出来。
这里,有个比较隐蔽的坑,我们的jetty进程是jetty用户的。如果在linux上是root用户或者其他用户直接执行jstack -l pid,会出现报错。所以,需要在命令前加上sudo -u jetty,用jetty账户来执行这个命令。
而jetty账户又不一定将/data/java/bin加入环境变量,所以需要执行jstack的完整路径。
执行完毕的结果存放在home目录下的jstack.txt文件中。(这里是找运维同事协助完成的)

jmap保存堆转储快照

同样,jmap命令也需要注意命令执行的用户。我使用的完整命令是:“sudo -u jetty /data/java/bin/jmap -dump:format=b,file=~/jmap.hprof   pid”。
导出来的hprof文件非常大,保存了当时堆中对象的快照。hprof不能直接阅读,需要用专门的工具来分析。最常用的是mat和jhat。mat是图形界面的工具,有windows版的,比较方便。但是mat有个死穴,当分析的hprof文件过大时,会出现内存溢出的错误而导致无法得到结果。我曾经尝试解决这个问题,但是一直没有找到有效的方法。所以这里我用的是jhat。

jhat分析堆转储快照

jhat是java自带的命令行工具,比较简朴。但是对于特别大的文件,好像是唯一的选择。将hprof文件压缩,下载到开发环境的虚拟机上,就可以开始用jhat分析了。
我使用的完整命令是:“jhat -J-d64 -J-mx9g -port 5000 jmap.hprof”。来解释一下参数。-J-d64:因为jetty进程是在64位的系统上运行,所以需要指定64位。-J-mx9g:表示jhat进程最多可以分配9G的堆内存,这就是为什么jhat可以分析超大文件的原因了,因为可以指定堆内存大小。-port 5000:jhat分析完毕之后,会启动一个web服务,可以通过指定端口来访问,这就是指定的端口。
 
参数就介绍完了,但是这样的命令会有一个问题。上面的命令执行完,jhat进程是在前台的。换句话说,如果你ctrl+c(或者xshell连接超时)结束了这个前台进程,那么jhat提供的web服务就结束了,你刚才分析了那么久的文件得重新再来。解决这个问题,用到linux上的nohup和&组合。通过命令“nohup jhat -J-d64 -J-mx9g -port 5000 jmap.hprof &”,就可以将进程放到后台执行。有兴趣可以研究一下nohup,在这里不做赘述。
 
jhat分析需要一定时间。可以用top命令看,当jhat进程没有疯狂的吃cpu的时候,说明分析已经结束了。此时,可以通过ip:port来访问刚才分析出的结果了。

三、定位问题

首先,来看刚才的jstack.txt。
在近900个线程里面,有600+个线程都是wait在同一个对象<0x0000000734afba50>上,而且这600+个线程的调用栈都是一模一样的。去查了一下,这个org.eclipse.jetty.util.thread.QueuedThreadPool的作用,就是jetty的worker线程池。每当一个请求来临的时候,jetty就从这个QueuedThreadPool中新建一个线程或者取一个空闲线程来处理这个请求。
看到调用栈里面的“at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:526)”,感觉好像这些线程都在等待任务来处理。当然,这是猜的。
为了验证这个猜想,找到刚才jhat已经分析好的堆的快照结果。首先,我找到“class org.eclipse.jetty.util.thread.QueuedThreadPool”这个类,然后依次点击,进入到QueuedThreadPool的唯一的实例中。

到这里,就可以看到QueuedThreadPool这个对象中所有成员变量了:

 
其中,有两个AtomicInteger型变量在这里需要关心:_threadsStarted和_threadsIdle。
_threadsStarted表示QueuedThreadPool当前拥有的线程数,而_threadsIdle表示QueuedThreadPool中空闲的线程数。
点击进去,就看到这两个成员变量的值,value分别是707和613。
这表示,QueuedThreadPool当前开启了707个用于处理用户请求的线程,而其中有613个处于闲置状态。
 到这里,我们上面的猜想基本得到验证。那些大量的time_wait的线程,真的是处在等待请求到来的状态。那么问题是,既然是闲置的线程,为什么jetty没有进行回收,time_wait有这么长时间吗?

四、分析jetty源码,确定原因

要继续确定为什么空闲线程没有被回收原因,分析jetty源码是一种思路。我只找到和线上jetty大版本一样,小版本接近的jetty源码。但是不妨碍理清这部分的逻辑。
继续回到刚才的jstack的结果中:
熟悉阻塞队列的人都知道,栈中的“org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:342)”,就是从一个指定的阻塞队列中去获取任务。如果此时阻塞队列中没有任务可取,线程就会被阻塞住,直到队列中有任务可取或者超时。如果超时,poll方法将返回null值。进入到idleJobPoll()方法中,也很容易就发现,poll的超时时间也是用了刚才的_maxIdleTimeMs变量,也就是60s。所以才会发生600+个线程同时wait一个条件的情况。这些线程都在等待BlockingArrayQueue中任务来临这个Condition。那么,是谁让线程调用poll的?为什么poll设置了超时时间,在超时之后,线程没有结束呢?为什么这些空闲线程没有被及时回收呢?
带着这些问题,我们来看QueuedThreadPool的源码。我们直接找到调用了idelJobPoll()方法的这块代码,如下:
这里有几个变量和方法需要先说明一下。_maxIdelTimeMs是QueuedThreadPool中的一个成员变量,表示超时的毫秒数,默认值是60000(表示60秒),可以在刚才jhat分析的结果中查询到这个值。_lastShrink也是QueuedThreadPool的一个成员变量,是线程安全的AtomicLong类型,表示上一次线程退出时的时间戳,被所有线程池中的线程共享。campareAndSet方法,就是著名的CAS(比较后赋值)。例如:_lastShrink.compareAndSet(last,now)的意思是,先将_lastShrink和last比较看是否相同,相同则将_lastShrink的值等于now并返回true,否则不进行赋值并返回false。
当一个空闲线程从idelJobPool()方法中超时后获取到null值,会再次进入while循环。此时的线程数size(700+)是要大于_minThreads(设置的为200),所以会进入框中的if代码块。if代码块中主要经历了以下步骤:

1.将last赋值为上一个线程池中的线程退出时的时间戳,将当前时间赋值给now。

2.然后“if (last==0 || (now-last)>_maxIdleTimeMs)”这一句判断,now距离上一个线程退出是否超过了maxIdleTimeMs(60000,60秒)。

3.如果2步骤中条件成立,会对_lastShrink重新赋值为当前时间,并将QueuedThreadPool中的线程计数减一。

campareAndSet保证了,每一次只会有一个线程能够赋值成功。

赋值成功后,就会return,让线程跳出while循环,这个线程就结束了。

对于赋值不成功的线程,会继续执行到idleJobPoll(),和步骤4相似。

4.如果2步骤中条件不成立,会重新回到idleJobPoll(),阻塞住线程,又会尝试从阻塞队列中获取任务。

也就是说,每当一个空闲线程执行到框中的代码时,都要判断现在距离上次有线程退出是否超过60s。如果没有超过60s,这个线程会继续回到idelJobPool方法中去等待任务。换句话说,1分钟之内,QueuedThreadPool最多只能允许一个线程退出。那么,我们600+个空闲线程如果要全部退出,那就要600分钟,也就是10个小时!!
难怪,会有那么多空闲线程在那里啊,虽然这些空闲线程可以被重复利用并不影响业务,但也是占用了线程资源。不知道这个算不算是个bug,但是真的很坑。由其影响通过java线程数去判断业务的繁忙情况,容易受到误导。

五、实验验证

为了进一步验证这个结论,我在开发环境部署了一样的业务,纯净且没有其他人访问。用ab以1000并发量发起30000个请求,迅速将java线程数提升至1000(最大值)。然后用watch命令,每5分钟观察一次java线程数,下面是部分结果:

可以看到,每5分钟,线程数都下降了5。确实是1分钟退出一个线程啊!

六、结论

这整个过程最重要的结论就是,当发现java线程数非常高的时候,不必太担心。有可能只是jetty没有及时回收空闲线程而已。更重要的是,要掌握分析的工具和方法,查找出现象背后的原因。

文章评论

老美怎么看待阿里赴美上市
老美怎么看待阿里赴美上市
程序员应该关注的一些事儿
程序员应该关注的一些事儿
我跳槽是因为他们的显示器更大
我跳槽是因为他们的显示器更大
Google伦敦新总部 犹如星级庄园
Google伦敦新总部 犹如星级庄园
Web开发者需具备的8个好习惯
Web开发者需具备的8个好习惯
老程序员的下场
老程序员的下场
为什么程序员都是夜猫子
为什么程序员都是夜猫子
要嫁就嫁程序猿—钱多话少死的早
要嫁就嫁程序猿—钱多话少死的早
程序员眼里IE浏览器是什么样的
程序员眼里IE浏览器是什么样的
我是如何打败拖延症的
我是如何打败拖延症的
60个开发者不容错过的免费资源库
60个开发者不容错过的免费资源库
程序员和编码员之间的区别
程序员和编码员之间的区别
10个帮程序员减压放松的网站
10个帮程序员减压放松的网站
编程语言是女人
编程语言是女人
程序员周末都喜欢做什么?
程序员周末都喜欢做什么?
为啥Android手机总会越用越慢?
为啥Android手机总会越用越慢?
程序猿的崛起——Growth Hacker
程序猿的崛起——Growth Hacker
我的丈夫是个程序员
我的丈夫是个程序员
聊聊HTTPS和SSL/TLS协议
聊聊HTTPS和SSL/TLS协议
写给自己也写给你 自己到底该何去何从
写给自己也写给你 自己到底该何去何从
科技史上最臭名昭著的13大罪犯
科技史上最臭名昭著的13大罪犯
每天工作4小时的程序员
每天工作4小时的程序员
“肮脏的”IT工作排行榜
“肮脏的”IT工作排行榜
2013年美国开发者薪资调查报告
2013年美国开发者薪资调查报告
当下全球最炙手可热的八位少年创业者
当下全球最炙手可热的八位少年创业者
如何区分一个程序员是“老手“还是“新手“?
如何区分一个程序员是“老手“还是“新手“?
十大编程算法助程序员走上高手之路
十大编程算法助程序员走上高手之路
程序员的一天:一寸光阴一寸金
程序员的一天:一寸光阴一寸金
那些争议最大的编程观点
那些争议最大的编程观点
程序员的鄙视链
程序员的鄙视链
旅行,写作,编程
旅行,写作,编程
亲爱的项目经理,我恨你
亲爱的项目经理,我恨你
程序员必看的十大电影
程序员必看的十大电影
那些性感的让人尖叫的程序员
那些性感的让人尖叫的程序员
不懂技术不要对懂技术的人说这很容易实现
不懂技术不要对懂技术的人说这很容易实现
Java程序员必看电影
Java程序员必看电影
总结2014中国互联网十大段子
总结2014中国互联网十大段子
5款最佳正则表达式编辑调试器
5款最佳正则表达式编辑调试器
如何成为一名黑客
如何成为一名黑客
代码女神横空出世
代码女神横空出世
鲜为人知的编程真相
鲜为人知的编程真相
看13位CEO、创始人和高管如何提高工作效率
看13位CEO、创始人和高管如何提高工作效率
团队中“技术大拿”并非越多越好
团队中“技术大拿”并非越多越好
漫画:程序员的工作
漫画:程序员的工作
做程序猿的老婆应该注意的一些事情
做程序猿的老婆应该注意的一些事情
初级 vs 高级开发者 哪个性价比更高?
初级 vs 高级开发者 哪个性价比更高?
程序员最害怕的5件事 你中招了吗?
程序员最害怕的5件事 你中招了吗?
一个程序员的时间管理
一个程序员的时间管理
“懒”出效率是程序员的美德
“懒”出效率是程序员的美德
软件开发程序错误异常ExceptionCopyright © 2009-2015 MyException 版权所有