欢迎您访问程序员文章站本站旨在为大家提供分享程序员计算机编程知识!
您现在的位置是: 首页

记一次“Axis2客户端调用产生大量CLOSE_WAIT连接”的解决过程 博客分类: 原创 axis2webserviceGCclose_wait 

程序员文章站 2024-03-22 08:32:52
...
背景: 程序使用1.6.2版本的axis2做WebService客户端调用。
代码:
public static Object sendRequest(Object req) throws AxisFault
{
	String returnMsg = "";
	RPCServiceClient serviceClient = null;
	serviceClient = new RPCServiceClient();
	Options options = serviceClient.getOptions();
	EndpointReference targetEPR = new EndpointReference(PropertiesUtils.getproperty("send.ws.targetEPR", ""));
	
	options.setTo(targetEPR);
	options.setTimeOutInMilliSeconds(Long.valueOf(PropertiesUtils.getproperty("send.ws.timeout", "30000")));
	//设置客户端关闭连接
	//options.setProperty(HTTPConstants.HEADER_CONNECTION, HTTPConstants.HEADER_CONNECTION_CLOSE);
	
	QName opAddEntry = new QName(PropertiesUtils.getproperty("send.ws.namespace", ""), PropertiesUtils.getproperty("send.ws.method", ""));
	Object[] opAddEntryArgs = new Object[] { req };
	Class[] classes = new Class[] { String.class };
	log.info("发送请求XML:"+req);
	returnMsg = (String) serviceClient.invokeBlocking(opAddEntry, opAddEntryArgs, classes)[0];
	log.info("收到返回XML:"+returnMsg);
	return returnMsg;

}
 现象:程序上线后,观察WebService的调用情况,发现服务端响应很慢(服务端是另一家厂商,动不了他),每个请求延时都在5秒左右,在使用netstate查看连接数的时候,意外发现了程序产生大量CLOSE_WAIT状态的连接,而且数量稳定增长,一个小时就接近300个连接。
#netstat -tnp|grep 7011|grep CLOSE_WAIT|wc -l
#271

 

折腾:发现这个问题后,就开始baidu.然后各种折腾。axis2的HTTPConstants.HEADER_CONNECTION ,

HEADER_CONNECTION_KEEPALIVE参数沾边的都试了遍,无效果。

两个小时过去了,没有进展。

 

看着一直增长的连接数,好象血管在一直流血一样。这样下去内存应该也会增长吧。看看jvm内存是不是有对象泄漏,导致HttpClient没有回收(axis2底层使用这个类发送WebService请求)?

 

jmap -histo 18041 |grep com.xxxxxxx
果然,程序new出来的对象,每一分钟增长一次(对应每分钟循环一次)。

 

 

此时心中有一个大大的问号:  为什么GC没有回收掉?

如果GC回收了,TCP连接会Close吗? 带着这个疑问,用tcpdump监控下tcp连接。

 

jmap -histo:live 18041 |grep com.xxxxxx # live会引起GC:没有找到根据,但确实是这样。
 在GC的瞬间,tcpdump看到客户端发出的reset包,同时CLOSE_WAIT连接都消失了。 

 

 

15:27:50.152698 IP WOOS1.46262 > 137.32.25.62.talon-disc: R 1384067195:1384067195(0) ack 4094862191 win 72 <nop,nop,timestamp 536888568 1094736905>
15:27:50.152710 IP WOOS1.44490 > 137.32.25.62.talon-disc: R 1983758145:1983758145(0) ack 4199192243 win 72 <nop,nop,timestamp 536888568 1094821918>
15:27:50.152723 IP WOOS1.58174 > 137.32.25.62.talon-disc: R 1982916452:1982916452(0) ack 4178184596 win 72 <nop,nop,timestamp 536888568 1094806915>
15:27:50.152738 IP WOOS1.32940 > 137.32.25.62.talon-disc: R 1748662783:1748662783(0) ack 4206843128 win 72 <nop,nop,timestamp 536888568 1094826919>
15:27:50.152762 IP WOOS1.36913 > 137.32.25.62.talon-disc: R 815070216:815070216(0) ack 4200525319 win 72 <nop,nop,timestamp 536888568 1094826919>
15:27:50.152775 IP WOOS1.40743 > 137.32.25.62.talon-disc: R 4116878055:4116878055(0) ack 4209835792 win 72 <nop,nop,timestamp 536888568 1094836922>
15:27:50.152788 IP WOOS1.33267 > 137.32.25.62.talon-disc: R 2893572903:2893572903(0) ack 4218047967 win 72 <nop,nop,timestamp 536888568 1094841922>
15:27:50.152802 IP WOOS1.38644 > 137.32.25.62.talon-disc: R 1232744431:1232744431(0) ack 12002951 win 72 <nop,nop,timestamp 536888568 1094931936>
 
解决问题:
     既然GC可以关闭连接,只要能让jvm即时GC就可以解决问题。 考虑到程序时各种大量的List , Map的对象互相引用,是否是这个原因导致 不能及时GC?(这是工作以来,第一次遇到GC的问题,脑子里关于GC的知识太少)
    于是修改程序,在List , Map 超出作用域时,clear掉。 用jmap观察程序,对象不再无限制增长:增长到一定值后大减,被GC掉。同时连接数也不再无限制增长,最大到30左右连接就会被关闭掉。
教训:
代码中没有考虑GC效率问题,尤其是map,list对象很多,对象间引用关系复杂,导致GC无法及时回收过期对象。   对于java的GC策略也不了解。看来要花些时间了解GC了。