问题情景

　　服务器重新部署应用后，运行一段时间后，某一微服务开始出现错误提示：连接超时：服务忙，导致相关功能无法正常使用。

　　问题排查

　　日志查看

　　首先下载对应服务的日志查看报错内容，日志中出现了很多org.apache.http.conn.ConnectionPoolTimeoutException: Timeout waiting for connection from pool 的异常信息。可以看出日志中的错误定位在HttpClient连接池，连接超时可能是连接池连接耗尽，没有可用连接导致无法正常获取连接提供服务。

　　初步猜想

　　HttpClient连接池中为了防止连接被长期占用会设置超时时间，如果超时时间设置的不合理，比较长，而服务中的某些连接请求时间又很长的时候，会导致连接被长期占用不被释放，最终导致HttpClient连接池耗尽。如果初步猜想成立的话那么其他提供服务的机器应该也会出现这个问题，但是根据其他机器的日志分析来看，它们并没有出现连接池耗尽的情况，问题只出现在单个机器上。

　　定点分析

　　通过日志分析出问题出现在单个机器上，我们就登录该服务器查看服务器中连接池中各个连接的状态。可以通过 netstat -n | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}' 命令对各种状态的连接分组查看，结果如下图所示，可以看到有很多处于CLOSE_WAIT状态的连接，数据与我们在项目中配置的连接池最大数量一致，因此可以判断是有大量未关闭的连接占满了连接池，导致连接池耗尽无法提供正常连接。

图 1 连接状态分组结果

　　提到CLOSE_WAIT状态，我们就需要知道TCP的状态转移是如何进行的。通过下图我们可以分析得到，在被动关闭连接情况下，在已经接收到FIN，但是还没有发送自己的FIN的时刻，连接处于CLOSE_WAIT状态。通常来讲，CLOSE_WAIT状态的持续时间应该很短，正如SYN_RCVD状态。但是在一些特殊情况下，就会出现连接长时间处于CLOSE_WAIT状态的情况。出现大量close_wait的现象，主要原因是某种情况下对方关闭了socket链接，但是我方忙与读或者写，没有关闭连接。

图2 TCP状态转移图

　　问题定位

　　分析出具体的连接池耗尽原因后我们需要找到对应的代码。根据日志中出现的连接超时信息可以找到抛出该异常的错误代码位置，代码如下：

public void getResources(String url) {
    LogUtils.info("Get URL={}", url);
    CloseableHttpClient httpclient = HttpClients.createDefault();
    HttpGet httpGet = new HttpGet(url);
 
    try {
        CloseableHttpResponse response1 = httpclient.execute(httpGet);
        HttpEntity entity1 = response1.getEntity();
        // 一些业务操作
        EntityUtils.consume(entity1);
    } catch (Exception e) {
        LogUtils.error("Get error", e);
    }
}

　　可以看到代码中对response做完操作之后并没有进行关闭，导致数据流中有一个结束符EOF一直没有被接收，从而连接一直被占用。

　　修复问题

　　问题定位后，我们就要修复问题，对于返回回来的流我们获取数据做完操作之后应该及时关闭，所以按照这个思路进行了改动。

public void getResources(String url) {
    LogUtils.info("Get URL={}", url);
    CloseableHttpClient httpclient = HttpClients.createDefault();
    HttpGet httpGet = new HttpGet(url);
    CloseableHttpResponse response1 = httpclient.execute(httpGet);
    try {
        HttpEntity entity1 = response1.getEntity();
        // 一些业务操作
        EntityUtils.consume(entity1);
    } finally {
        response1.close();
    }
}

　　总结

　　出现CLOSE_WAIT的根本原因是应用端未关闭一个已经被对端关闭的连接导致，在出现该问题时，我们可以通过netstat等命令查看tcp的对端和端口，从而定位出现问题的地方并进行修改。还有就是平时进行流处理操作时需要及时关闭流，释放资源，避免后续资源死锁。

作者：谢远辉   

来源：51Testing软件测试网原创