案例现场

某发布日，应用线上重启应用后，在运行一段时间后，所有通过 Apache HttpClient 发送的请求，会报 org.apache.http.conn.ConnectionPoolTimeoutException: Timeout waiting for connection from pool 错误，显示连接池耗尽。
后续大量应用出现同类状态，应用发布均未涉及 Apache HttpClient 使用方式的更改，尝试应用版本回滚后，问题依然存在。

为了定位问题，研发同学开始大量翻阅项目本身的发布历史、代码更改，但未发现异常。
在除线上之外的环境里，尝试压测均未能复现。

现场处理

现场处理的原则：优先解决问题，事后分析原因。
image.png

复现 POC

参考资料里有 POC 完整代码，可直接在 IDEA 中运行

先提一个问题：案例中我们为什么要去替换 entity 对象，原始需求是什么？
原始需求是：由于业务需要，我们需要提前读取返回内容记录日志，但是原始的 BasicHttpEntity 不支持通过 Entity.toString 多次读取，所以我们把这替换成了 BufferedHttpEntity ，实现可重复读。

下面是实际项目中，使用字节码框架注入代码的部分逻辑

  1. // 字节码注入代码
  2. // 注入：org.apache.http.message.BasicHttpResponse#getEntity
  3. public Object overwrite (EnhanceInstance enhanceInstance, Method method, Object[] allArguments, Class<?>[] argumentsTypes, OverwriteMethod originMethod) throws Throwable {
  4.     HttpEntity httpEntity = (HttpEntity) TracerReflectionUtils
  5.         .getFieldValueByClassAndFiledName(BasicHttpResponse.class,
  6.                                           "entity",
  7.                                           enhanceInstance);
  8.     if (null != httpEntity && !httpEntity.isRepeatable() && null == enhanceInstance.getDynamicField()) {
  9.         ((BasicHttpResponse) enhanceInstance)
  10.             .setEntity(new BufferedHttpEntity(httpEntity));
  11.         enhanceInstance.setDynamicField(true);
  12.         return httpEntity;
  13.     }
  14.     return originMethod.call(allArguments);
  15. }

注意 第 4 、9、12 行，如果我们使用 javassist 实现，等价于

StringBuilder sb = new StringBuilder();
sb.append("org.apache.http.entity.BufferedHttpEntity newEntity = new org.apache.http.entity.BufferedHttpEntity(this.entity);");
sb.append("org.apache.http.HttpEntity originalEntity = this.entity;");
sb.append("this.entity = newEntity;");
sb.append("return originalEntity;");
method.insertBefore(sb.toString());

问题定位

从 httpClient.execute 入手，一路跟踪到 MainClientExec（负责处理连接和通讯），关键代码如下。

// file => org/apache/http/impl/execchain/MainClientExec.java
// line => 333
// check for entity, release connection if possible
// response 为 BasicHttpResponse 实例，即为字节码更改的对象
final HttpEntity entity = response.getEntity(); 
if (entity == null || !entity.isStreaming()) {
    // connection not needed and (assumed to be) in re-usable state
    // 如果 entity 不是流数据，则直接释放当前连接
    connHolder.releaseConnection();
    return new HttpResponseProxy(response, null);
}

// 监听数据流是否到达 EOF，判断是否释放当前连接
return new HttpResponseProxy(response, connHolder);

跟踪进入 ResponseEntityProxy 

// file => org/apache/http/impl/execchain/ResponseEntityProxy.java

// line => 53
public HttpResponseProxy(final HttpResponse original, final ConnectionHolder connHolder) {
    this.original = original;
    this.connHolder = connHolder;
    // 绑定数据流和连接，我们继续调试跟踪进去
    ResponseEntityProxy.enchance(original, connHolder);
}

继续跟踪进入 ResponseEntityProxy

// file => org/apache/http/impl/execchain/ResponseEntityProxy.java

// line => 50
public static void enchance(final HttpResponse response, final ConnectionHolder connHolder) {
    final HttpEntity entity = response.getEntity();
    // 注意，只有 entity 为 Stream 流，才会绑定 ResponseEntityProxy 代理监听
    if (entity != null && entity.isStreaming() && connHolder != null) {
        response.setEntity(new ResponseEntityProxy(entity, connHolder));
    }
}

ResponseEntityProxy 的继承关系如下，通过对 Stream 流的监听，最终会触发 eofDetected ，使用 connHolder.releaseConnection 来释放连接。
Screen Shot 2021-03-04 at 12.09.55 AM.png

我们再回到开头，我们对 getEntity 的注入代码，看看代码之间是如何相互影响的。

StringBuilder sb = new StringBuilder();
// 此处的 BufferedHttpEntity 不是 stream 流，即 isStreaming = false
sb.append("org.apache.http.entity.BufferedHttpEntity newEntity = new org.apache.http.entity.BufferedHttpEntity(this.entity);");
// 原始的 entity 为 BasciHttpEntity，其 isStreaming = true
sb.append("org.apache.http.HttpEntity originalEntity = this.entity;");
// 原始值设置了 newEntity
sb.append("this.entity = newEntity;");
// 返回值却是原始值
sb.append("return originalEntity;");
method.insertBefore(sb.toString());

第一次调用 getEntity ，返回的是 originalEntity ，类型为 BasciHttpEntity ，导致直接释放连接的代码被跳过

// file => org/apache/http/impl/execchain/MainClientExec.java
// line => 333
final HttpEntity entity = response.getEntity(); 
// 返回 entity 为 originalEntity（BasciHttpEntity），无法进入该 if 逻辑以直接释放连接
if (entity == null || !entity.isStreaming()) {
    connHolder.releaseConnection();
    return new HttpResponseProxy(response, null);
}

第二次调用 getEntity ，返回的其实是第一次的 newEntity ，类型为 BufferedHttpEntity ，同样无法进入该 if 逻辑以监听 EOF 释放连接。

// file => org/apache/http/impl/execchain/ResponseEntityProxy.java

// line => 50
public static void enchance(final HttpResponse response, final ConnectionHolder connHolder) {
    final HttpEntity entity = response.getEntity();
    // 返回的是 newEntity（BufferedHttpEntity），同样无法进入该 if 逻辑以监听 EOF 释放连接
    if (entity != null && entity.isStreaming() && connHolder != null) {
        response.setEntity(new ResponseEntityProxy(entity, connHolder));
    }
}

综上，我们的请求完美错过了两次释放连接的机会，导致该连接被长时间持有。
随着请求越来越多，当未被及时释放的连接达到连接池上限的时候，就会曝出 Timeout waiting for connection from pool 错误。
**

如何避免踩坑

字节码注入本身就是个容易出事故的操作，我们可以从以下几个方面规避

  • CodeReview，但这对团队成员有较高的技术要求
  • 尽量让问题提前暴露，测试、预发环境的也加载与线上相同的环境依赖
  • 作为一名技术要持续学习，对关键项目有源码级的理解

参考资料