一万八千条线程,线程为啥释放不了?
大家好,我是魔性的茶叶,今天和大家带来的是我在公司里面排查的另一个性能问题的过程和结果,相当有意思,分享给大家,为大家以后有可能的排查增加一些些思路。当然,最重要的是排查出来问题,解决问题的成就感和解决问题的快乐,拽句英文,那就是 its all about fun。
噢对了,谢绝没有同意的转载。
事情发生在某个艳阳高照的下午,我正在一遍打瞌睡一边写无聊的curd。坐在我身边的郑网友突然神秘一笑。 "有个你会感兴趣的东西,要不要看看",他笑着说,脸上带着自信揣测掌握我的表情。
我还以为他准备说啥点杯奶茶,最近有啥有意思的游戏,放在平时我可能确实感兴趣,可是昨天晚上我凌晨二点才睡,中午休息时间又被某个无良领导叫去加班,困得想死,现在只想赶紧码完代回家睡觉。
"没兴趣",我说。他脸上的表情就像被一只臭皮鞋梗住了喉咙,当然那只臭皮鞋大概率是我。
"可是这是之前隔壁部门那个很多线程的问题,隔壁部门来找我们了",他强调了下。
"噢!是吗,那我确实有兴趣",我一下子来了精神,趴过去看他的屏幕。屏幕上面是他和隔壁部门的聊天,隔壁部门的同事说他们看了比较久时间都找不到问题,找我们部门看看。让我臊的不行的是这货居然直接还没看问题,就开始打包票,说什么"我们部门是排查这种性能问题的行家"这种高斯林看了都会脸红的话。
"不是说没兴趣吗?"他嘿嘿一笑。我尬笑了一下,这个问题确实纠结我很久了,因为一个星期前运维同事把隔壁部门的应用告警发到了公共群,一下子就吸引到了我:
这个实例的线程数去到差不多两万(对,就是两万,你没看错)的线程数量,1w9的线程处于runnable状态。说实话,这个确实挺吸引我的 ,我还悄悄地地去下载了线程快照,但是这是个棘手的问题,只看线程快照完全看不出来,因为gitlab的权限问题我没有隔壁部门的代码,所以只能作罢。但是这个问题就如我的眼中钉,拉起了我的好奇心,我隔一会就想起这个问题,我整天都在想怎么会导致这么多条线程,还有就是jvm真的扛得住这么多条线程?
正好这次隔壁部门找到我们,那就奉旨除bug,顺便解决我的困惑。
等待代码下拉的过程,我打开skywalking观察这个应用的状态。这次倒没到一万八千条线程,因为找不到为啥线程数量这么多的原因,每次jvm快被线程数量撑破的时候运维就重启一遍,所以这次只有接近6000条,哈哈。
可以看到应用的线程在一天内保持增加的状态,而且是一直增加的趋势。应用没有fgc,只有ygc,配合服务的调用数量很低,tomcat几乎没有繁忙线程来看并不是突发流量。jvm的cpu居高不下,很正常,因为线程太多,僧多粥少的抢占时间片,不高才怪。
拿下线程快照导入,导入imb analyzer tool查看线程快照。
直接看最可疑的地方,有1w9千条的线程都处于runnbale线程,并且都有相同的堆栈,也就是说,大概率是同一段代码产生的线程:
这些线程的名字都以I/O dispatcher 开头,翻译成中文就是io分配者,说实话出现在dubbo应用里面我是一点都不意外,可是我们这是springmvc应用,这个代码堆栈看上去比较像一种io多路轮询的任务,用人话说就是一种异步任务,不能找到是哪里产生的这种线程。说实话这个线程名也比较大众,网上一搜一大把,也没啥一看就能定位到的问题。
这种堆栈全是源码没有一点业务代码堆栈的问题最难找了。
我继续往下看线程,试图再找一点线索。接着我找到了大量以pool-命名开头的线程,虽然没有1w9千条这么多,也是实打实几百条:
这两条线程的堆栈很相近,都是一个类里面的东西,直觉告诉我是同一个问题导致的。看到这个pool开头,我第一个反应是有人用了类似new fixThreadPool()这种api,这种api新建出来的线程池因为没有自定义threadFactory,导致建立出来的线程都是pool开头的名字。
于是我在代码中全局搜索pool这个单词,想检查下项目中的线程池是否设置有误:
咦,这不是刚刚看到的堆栈里面的东西吗。虽然不能非常确定是不是这里,但是点进去看看又不会掉块肉。
这是个工具类,我直接把代码拷过来:
private static class HttpHelperAsyncClient {
private CloseableHttpAsyncClient httpClient;
private PoolingNHttpClientConnectionManager cm;
private HttpHelperAsyncClient() {}
private DefaultConnectingIOReactor ioReactor;
private static HttpHelperAsyncClient instance;
private Logger logger = LoggerFactory.getLogger(HttpHelperAsyncClient.class);
public static HttpHelperAsyncClient getInstance() {
instance = HttpHelperAsyncClientHolder.instance;
try {
instance.init();
} catch (Exception e) {
}
return instance;
}
private void init() throws Exception {
ioReactor = new DefaultConnectingIOReactor();
ioReactor.setExceptionHandler(new IOReactorExceptionHandler() {
public boolean handle(IOException ex) {
if (ex instanceof BindException) {
return true;
}
return false;
}
public boolean handle(RuntimeException ex) {
if (ex instanceof UnsupportedOperationException) {
return true;
}
return false;
}
});
cm=new PoolingNHttpClientConnectionManager(ioReactor);
cm.setMaxTotal(MAX_TOTEL);
cm.setDefaultMaxPerRoute(MAX_CONNECTION_PER_ROUTE);
httpClient = HttpAsyncClients.custom()
.addInterceptorFirst(new HttpRequestInterceptor() {
public void process(
final HttpRequest request,
final HttpContext context) throws HttpException, IOException {
if (!request.containsHeader("Accept-Encoding")) {
request.addHeader("Accept-Encoding", "gzip");
}
}}).addInterceptorFirst(new HttpResponseInterceptor() {
public void process(
final HttpResponse response,
final HttpContext context) throws HttpException, IOException {
HttpEntity entity = response.getEntity();
if (entity != null) {
Header ceheader = entity.getContentEncoding();
if (ceheader != null) {
HeaderElement[] codecs = ceheader.getElements();
for (int i = 0; i 0){
resp = rsp.get(timeoutmillis,TimeUnit.MILLISECONDS);
}else{
resp = rsp.get(DEFAULT_ASYNC_TIME_OUT,TimeUnit.MILLISECONDS);
}
System.out.println("获取返回值的resp----->"+resp);
entity = resp.getEntity();
StatusLine statusLine = resp.getStatusLine();
respObject.setCode(statusLine.getStatusCode());
System.out.println("Response:");
System.out.println(statusLine.toString());
headerLog(resp);
String result = new String();
if (respObject.getCode() == 200) {
String encoding = ("" + resp.getFirstHeader("Content-Encoding")).toLowerCase();
if (encoding.indexOf("gzip") > 0) {
entity = new GzipDecompressingEntity(entity);
}
result = new String(EntityUtils.toByteArray(entity),UTF8);
respObject.setContent(result);
} else {
StringBuilder sbuilder=new StringBuilder();
sbuilder.append("n{").append(request.getURI().toString()).append("}nreturn error "
+ "{").append(resp.getStatusLine().getStatusCode()).append("}");
System.out.println(sbuilder.toString());
try {
result = new String(EntityUtils.toByteArray(entity),UTF8);
respObject.setError(result);
} catch(Exception e) {
logger.error(e.getMessage(), e);
result = e.getMessage();
}
}
System.out.println(result);
} catch (Exception e) {
logger.error("httpClient.execute异常", e);
} finally {
EntityUtils.consumeQuietly(entity);
System.out.println("执行finally中的 closeClient(httpClient)");
closeClient(httpClient);
}
return respObject;
}
private static void closeClient(CloseableHttpAsyncClient httpClient) {
if (httpClient != null) {
try {
httpClient.close();
} catch (IOException e) {
e.printStackTrace();
}
}
}
}
这段代码里面用到了CloseableHttpAsyncClient的api,我大概的查了下这个玩意,这个应该是一个异步的httpClient,作用就是用于执行一些不需要立刻收到回复的http请求,CloseableHttpAsyncClient就是用来帮你管理异步化的这些http的请求的。
代码里面是这么调用这个类的:
HttpHelperAsyncClient.getInstance().execute(request, timeoutMillis)
捋一下逻辑,就是通过HttpHelperAsyncClient.getInstance()
拿到HttpHelperAsyncClient的实例,然后在excute方法里面执行请求并且释放httpClient对象。按我的理解,其实就是一个httpClient的工具类
我直接把代码拷贝出来,试图复现一下,直接在mian方法进行一个无限循环的调用
while (true){
post("https://www.baidu.com",new Headers(),new HashMap(),0);
}
从idea直接拿一份dump:
耶?怎么和我想的不一样,只有一条主线程,并没有复现上万线程的壮观。
就在我懵逼的时候,旁边的郑网友开口了:"你要不要试试多线程调用,这个请求很有可能从tomcat进来的"。
有道理,我迅速撸出来一个多线程调用的demo:
ThreadPoolExecutor threadPoolExecutor = new ThreadPoolExecutor(10,20,100,TimeUnit.DAYS,new ArrayBlockingQueue(100));
while (true) {
Thread.sleep(100);
threadPoolExecutor.execute(new Runnable() {
@Override
public void run() {
try {
post("https://www.baidu.com", new Headers(), new JSONObject(), 0);
} catch (Exception e) {
throw new RuntimeException(e);
}
}
});
}
因为线程涨的太猛,这次idea都没办法拿下线程快照,我借助JvisualVM监控应用状态,线程数目如同脱缰的野马, 迅速的涨了起来,并且确实是I/O dispatcher线程居多
到这里,基本能说明问题就出现在这里。我们再深究一下。
可能有的朋友已经发现了,HttpHelperAsyncClient类中的httpclient是线程不安全的,这个HttpHelperAsyncClient这个类里面有个httpclient的类对象变量,每次请求都会new一个新的httpclient赋值到类对象httpclient中,在excute方法执行完会调用closeClient()方法释放httpclient对象,但是closeClient的入参直接从类的成员对象中取,这就有可能导致并发问题。
简单的画个图解释下:
http-1-thread调用方法init()把类变量httpclient设置为自己的实例对象,http-1-client
此时紧接着http-2-thread进来,调用方法init()把类变量httpclient设置为自己的实例对象,http-2-client
接着http-1-thread执行完请求,调用closeHttpclient()方法释放httpclient,但是因为http-2线程已经设置过类变量,所以它释放的是http-2-client
http-2-thread执行完请求,也去调用closeHttpClient()方法释放httpclient,但是大概率会因为http-2-client已经释放过报错
不管http-2-client如何,http-1-client是完完全全的被忘记了,得不到释放,于是他们无止境的堆积了起来。
如何解决呢?其实也很简单,这里httpclient对象其实是属于逃逸了,我们把它变回成局部变量,就可以解决这个问题,在不影响大部分的代码情况下,我们把生成httpclient的代码从HttpHelperAsyncClient.getInstance()
移动到execute()
中,并且在释放资源的地方传入局部变量而不是类变量:
private CloseableHttpAsyncClient init() throws Exception {
//省略部分代码
httpClient.start();
//现在init方法返回CloseableHttpAsyncClient
return httpClient;
}
private Response execute(HttpUriRequest request, long timeoutmillis) throws Exception {
//省略部分代码
//改动在这里 client直接new出来
CloseableHttpAsyncClient httpClient = init();
//省略部分代码
closeClient(httpClient);
//省略部分代码
}
经过改造后的代码升级后登录skywalking查看效果:
可以看到线程数量恢复成了180条,并且三天内都没有增加,比之前一天内增加到6000条好多了。也就是区区一百倍的优化,哈哈。
总结
其实这个算比较低级的错误,很简单的并发问题,但是一不注意就容易写出来。但是排查难度挺高的,因为大量的线程都是没有我们一点业务代码堆栈,根本不知道线程是从哪里创建出来的,和以往的排查方法算是完全不同。这次是属于运气爆棚然后找到的代码,排查完问题我也想过,有没有其他的方法来定位这么多相同的线程是从哪里创建出来的呢?我试着用内存快照去定位,确实有一点线索,但是这属于是马后炮了,是我先读过源码才知道内存快照可以定位到问题,有点从结果来推过程的意思,没啥好说的。
总而言之,在定义这种敏感资源(文件流,各种client)时,我们一定要注意并发创建及释放资源的问题,变量能不逃逸就不逃逸,最好是局部变量。