HttpURLConnection 资源未释放造成的线程阻塞。继程序编码后,继续被无情摧残折磨第二次。
背景
工程从WebSphere上迁移到Tomcat7,程序运行平稳,但是隔断时间就会宕机。服务器进程还在,单独访问Tomcat端口也无响应。查看日志,并没有特别的异常。而且发生的时间随机。
问题排查
- 迁移平台后代码有新功能改动,排查是否由于改动引起(排除)
- 发生两次之后,将两次宕机时间点的日志对比查看(排除)
- JVM不足or GC时间/程序运行时间比过长(排除)
- WebSphere中也曾出现过此问题,但是不确定是不是相同的原因(应该是相同因素)
- 服务器报警依次为IP、TCP、HTTP 有时有Java
1、从有改动的代码看起,并无异常之处。对比宕机(说Tomcat无响应更合适)时间点之前的日志信息,没什么规律都是正常的抛出异常。
2、通过监控系统及服务器后台查看平时JVM堆栈分布、GC情况;宕机时(负载均衡,一台宕机有时间差可以操作)查看JVM堆栈分布、GC情况。jmap -heap PID
jstat -gcutil PID 2000 1000
内存及GC也都在合理范围内。不过查看到http-bio-8080的Idle Threads报满。
3、调整了一次Tomcat的maxThreads;另外仔细查阅了一遍JVM参数及说明。按照观察的结果,与maxThreads及JVM无关。
4、再次宕机时,抓取dump日志。
#1 查找Java进程与最耗CPU进程
jps or top
#2 找出Java进程中最耗CPU的线程
top -p -H <PID>
#抓取dump信息
jstack <PID> >111.log
将获取的最耗CPU线程转16进制(程序员计算器)然后在111.log中查询。
"catalina-exec-18" daemon prio=10 tid=0x00000000011d6000 nid=0x3848 runnable [0x00007f3894393000]
java.lang.Thread.State: RUNNABLE
at java.lang.Throwable.fillInStackTrace(Native Method)
at java.lang.Throwable.fillInStackTrace(Throwable.java:783)
- locked <0x00000006868c7bd8> (a java.lang.IllegalStateException)
.....
- locked <0x0000000781944778> (a sun.net.www.protocol.http.HttpURLConnection)
at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:468)
at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1250)
- locked <0x0000000781944778> (a sun.net.www.protocol.http.HttpURLConnection)
at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:468)
at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1250)
- locked <0x0000000781944778> (a sun.net.www.protocol.http.HttpURLConnection)
at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:468)
at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1340)
- locked <0x0000000781944778> (a sun.net.www.protocol.http.HttpURLConnection)
at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:468)
at cn.xxx.modules.common.util.ComUtils.isConnect(ComUtils.java:152)
- locked <0x00000007454c2ae8> (a java.lang.Class for cn.xxx.modules.common.util.ComUtils)
at cn.xxx.modules.sys.utils.UserUtils.getPoto(UserUtils.java:207)
at cn.xxx.modules.archives.info.service.ArchivesInfoService.getTeamMembers(ArchivesInfoService.java:306)
at cn.xxx.modules.archives.info.service.ArchivesInfoService$$FastClassBySpringCGLIB$$8409cac5.invoke(<generated>)
第二次日志
"catalina-exec-46" daemon prio=10 tid=0x00007ffcd005c000 nid=0x4639 waiting for monitor entry [0x00007ffd005bb000]
java.lang.Thread.State: BLOCKED (on object monitor)
at cn.xxx.modules.common.util.ComUtils.isConnect(ComUtils.java:145)
- waiting to lock <0x000000074859d488> (a java.lang.Class for cn.xxx.modules.common.util.ComUtils)
at cn.xxx.modules.sys.utils.UserUtils.getPoto(UserUtils.java:224)
at cn.xxx.modules.archives.record.web.RecordInformationController.findInforOfMy(RecordInformationController.java:135)
at sun.reflect.GeneratedMethodAccessor505.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Deleg
线程锁死在了ComUtils.isConnect的145行,代码如下:
public static synchronized boolean isConnect(String url) {
URL urlStr;
HttpURLConnection connection = null;
if (url == null || url.length() <= 0) {
return false;
}
try {
urlStr = new URL(url);
connection = (HttpURLConnection) urlStr.openConnection();
connection.setConnectTimeout(1000);//设置连接主机超时(单位:毫秒)
int state = connection.getResponseCode();
if (state == 200) {
return true;
}
} catch (Exception ex) {
return false;
}
return false;
}
设置setConnectTimeout,但是没有设置setReadTimeout(默认是0,即超时为无穷大)导致线程阻塞。
处理
1、指定setReadTimeout值,并且增加设置InputStream和OutputStream关闭(如果有用)。
2、去掉synchronized,HttpURLConnection 是无状态的与线程无关。不存在共享变量问题。
查看更改后连接情况:
netstat -n | awk '/^tcp/'
参考文章:
http://blog.csdn.net/cuihaiyang/article/details/51585364
http://blog.csdn.net/h3c4lenovo/article/details/9985719
http://blog.sina.com.cn/s/blog_56beadc60100j9zu.html
http://tool.oschina.net/apidocs/apidoc?api=jdk-zh