【原创】经验分享：一个Content-Length引起的血案(almost....)

前言

上周在工做中遇到一个问题，挺有意思，这里记录一下。上周在工做中遇到一个问题，挺有意思，这里记录一下。标题起的很唬人，这个问题差点引起血案，花哥仍是很严谨的一我的，后面备注了almost....前端

在测试环境中，前端调用咱们服务一个接口时发现巨慢无比，响应时间超过了30s，简直没法忍受！！java

查看日志显示是咱们服务在经过Feign请求调用另外一个服务的GET接口时一直超时，而后重试了一直直到失败。可是奇怪的是手动经过ip+端口请求这个超时的GET接口时却响应速度很快。apache

这就很奇怪了，以前一直调用好好的接口，怎么如今就一直超时呢？此时的我是满脑子问号。。。tomcat

现象

前端调用咱们服务(这里叫作服务A)的一个查询接口，这里前端用的是POST请求，咱们服务又会经过Feign调用到另外一个服务(这里叫作服务B)的一个接口，这个接口对外提供GET形式的调用。markdown

从现象上来看就是调用咱们服务特别慢，一个请求响应几十秒，具体流程以下：架构

问题排查

当时脑子中出现的疑惑就是太奇怪了，以前一只调用的接口不该该会出现这种状况，并且手动经过ip+端口去调用的话响应速度很快的，因而找了服务B对外开发的同窗一块儿看，由于本身忽略了一些重要的日志信息，因此这里走了很多弯路，在同事的帮助下本身也将这个问题梳理清楚了。app

问题的根本缘由是咱们在GET请求的Header中传递了Content-Length参数，并且服务B近期添加了一个jar包，jar中有一个拦截器作了一些事情致使了这个问题。我这里从源码层面上梳理下整个问题的根本缘由，以及之后如何避免此类问题！socket

对于这个问题，本身本地分别启动服务A和服务B，以DEBUG模式启动，发现能够稳定重现，并且能够看到在调用服务B卡住时候的堆栈信息：工具

服务A发起的请求卡住的缘由是在awaitLatch()被挂起了，到了这里才算是找到了问题缘由的突破口，下面继续往上一步步跟踪就能够找到问题的所在了，下面会一步步认真分析。oop

问题缘由

这里问题的缘由实际上是经过上面问题排查反推出来的：

前端调用服务端接口时，由于是post请求，因此header中传递的有Content-Length属性，调用feign请求时，不论get仍是post请求，公司底层包中有个Feign拦截器会将前端请求Header属性赋值给feign请求中的Header，致使咱们发送的GET请求Header中也含有Content-Length属性。

ps: 这一点很坑，依赖的底层包加了一个Feign拦截器，咱们是经过打印feign请求日志在控制台才看到Content-Length属性的，最后跟踪到这个FeignInterceptor中的

服务B恰好依赖了另外一个jar包，该包中包含一个Filter拦截器，它会读取发送的请求body数据，而后作一些日志打印。并且这个jar包依赖也是他们刚加的，他们使用该包中的其余一些工具类

public class ChannelFilter implements Filter {
    public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain) throws IOException, ServletException {
        if (servletRequest instanceof HttpServletRequest) {
            requestWrapper = new RequestWrapper((HttpServletRequest)servletRequest);
            log.info("Http RequestURL : {}, Method : {}, RequestParam : {}, RequestBody : {}", new Object[]{((HttpServletRequest)servletRequest).getRequestURL(), ((HttpServletRequest)servletRequest).getMethod(), JSON.toJSON(servletRequest.getParameterMap()), ((RequestWrapper)requestWrapper).getBody()});
        }


        filterChain.doFilter((ServletRequest)requestWrapper, servletResponse);
    }


    public void destroy() {
    }
}

public class RequestWrapper extends HttpServletRequestWrapper {
    private static final Logger log = LoggerFactory.getLogger(RequestWrapper.class);
    private final String body;

    public RequestWrapper(HttpServletRequest request) {
        super(request);
        StringBuilder stringBuilder = new StringBuilder();
        BufferedReader bufferedReader = null;
        ServletInputStream inputStream = null;

        try {
            inputStream = request.getInputStream();
            if (inputStream != null) {
                bufferedReader = new BufferedReader(new InputStreamReader(inputStream));
                char[] charBuffer = new char[4096];
                boolean var6 = true;

                int bytesRead;
                while((bytesRead = bufferedReader.read(charBuffer)) != -1) {
                    stringBuilder.append(charBuffer, 0, bytesRead);
                }
            }
        } catch (IOException var19) {
            log.error(var19.getMessage(), var19);
        }
    }
}
复制代码

在执行request body读取的代码时使用到：

while((bytesRead = bufferedReader.read(charBuffer)) != -1) {
   stringBuilder.append(charBuffer, 0, bytesRead);
}
复制代码

bufferedReader.read()最终会调用到Tomcat 中org.apache.tomcat.util.net.NioBlockingSelector.read()的方法读取request中的body属性：

int keycount = 1; 
while(!timedout) {
    if (keycount > 0) { //only read if we were registered for a read
        read = socket.read(buf);
        if (read != 0) {
            break;
        }
    }
    try {
        if ( att.getReadLatch()==null || att.getReadLatch().getCount()==0) att.startReadLatch(1);
        poller.add(att,SelectionKey.OP_READ, reference);
        if (readTimeout < 0) {
            att.awaitReadLatch(Long.MAX_VALUE, TimeUnit.MILLISECONDS);
        } else {
            att.awaitReadLatch(readTimeout, TimeUnit.MILLISECONDS);
        }
    } catch (InterruptedException ignore) {
        // Ignore
    }
}
复制代码

这里由于GET请求的body为空，因此socket.read() 返回为0，进而走到att.awaitReadLatch(readTimeout, TimeUnit.MILLISECONDS);

protected void awaitLatch(CountDownLatch latch, long timeout, TimeUnit unit) throws InterruptedException {
    if ( latch == null ) throw new IllegalStateException("Latch cannot be null");
    latch.await(timeout,unit);
}
复制代码

这里就会调用到LockSuport.parkNanos(time) 接口直到超时，此时的大家会不会仍然有疑惑，为何Header中传递了Content-Length就会走这个逻辑链路呢？别急，继续往下看，后面还有更精彩的分析......

解决方案

服务B取消有问题jar包的依赖
修改问题jar包中Filter的配置，判断只有Post请求才去读取body属性
接口调用方添加配置若是是GET请求时过滤掉Content-Length属性(主要缘由)
修改底层依赖包FeignInterceptor，判断请求的方式而后再针对Header赋值(公司底层依赖的包咱们不太好修改)

其实最应该修改的是方案4，只是这个是全公司都会依赖的一个底层包，若是改动起来须要通知架构组等等，并且影响面会比较大。

最终咱们先采用方案3，在咱们请求链路中去作一些判断，去除GET请求中Content-Length的传递。

解决原理

接下来就是真正原理的地方了，当服务端发出feign请求后，必定会走Tomcat中的org.apache.coyote.http11.Http11Processor.prepareRequest()方法，代码如图：

若是contentLength >= 0，那么会添加一个org.apache.coyote.http11.filters.IdentityInputFilter类，在服务B添加的jar包中的RequestWrapper中的bufferedReader.read()会调用到 org.apache.coyote.http11.filters.IdentityInputFilter.doRead() 方法：

这个方法又会直接调用到 org.apache.tomcat.util.net.NioBlockingSelector.read()中：

由于GET请求的request body为空，因此这里经过socket去读取时返回为0，直接运行下面的awaitReadLatch() 方法，这里会调用LockSuport.parkNanos(time) 接口直到超时，这也是为何咱们每次feign请求都会超时的缘由。

可是若是服务请求方配置了传递的Content-Length为空呢？这里会构造一个org.apache.coyote.http11.filters.VoidInputFilter，这个拦截器的构造在上面Http11Processor.prepareRequest()图示中已经标明：

显而易见，这里直接返回-1，不会再去调用NioBlockingSelector.read() 方法了，因此成功解决此问题，这也是问题的关键所在。

总结

这里没有过多的去介绍Content-Length的概念，默许你们都知道这个，若是不太清楚的还能够参考： blog.piaoruiqing.com/2019/09/08/…

一个简单的Content-Length确实难住了我，请求的不规范才是此次问题的真正缘由。而排查出来这个问题也花费了不少时间，不过这些都是挺值得的，一我的的成长离不开各类问题的洗礼，但愿你们阅读完也会有所收获。