记录一次Feign调用500错误

最近某个应用在服务间使用Feign时一直报500 status reading，严重影响到公司业务进行。

报错如下：

首先跟踪了feign源码发现报错是在response中返回的，然后查看被调用方无任何日志信息。此时判断非业务异常返回。

再确认非业务异常后，通过tcpdump将tcp信息导出得到以下信息

拿到报文后，显示自己调用该接口来测试是否报错，但无论如何都调用成功，在经过一段时间折腾后发现host与tcp的请求地址不一致，为什么会出现这种情况？

http是应用层的东西只是规定了一种协议，而真正发起连接是tcp，而tcp只是发数据根本不知道host是啥。也就意味着host可以随意变更。

发现host不一致时，尝试着更改host，最终尝试更改host也并不会引发报错。所以到现在只能为最老实的方式 → 复制所有的header和参数与报文保持一致。此时调用报错且与tcpdump结果一致。然后通过删减header最终确认了是Content-Length和content-length同时存在导致tomcat服务器直接拦截了请求。

此时思路就来，那么在何时产生的两个名称相同但大小写不同的key存在。接下来就跟随Feign源码查看问题。通过调试进入了feign初始化request的代码SynchronousMethodHandler

public Object invoke(Object[] argv) throws Throwable {
    // 通过feignclient获取，如果为post请求会添加Content-Length头
    RequestTemplate template = buildTemplateFromArgs.create(argv);
    Retryer retryer = this.retryer.clone();
    while (true) {
      try {
        return executeAndDecode(template);
      } catch (RetryableException e) {
        retryer.continueOrPropagate(e);
        if (logLevel != Logger.Level.NONE) {
          logger.logRetry(metadata.configKey(), logLevel);
        }
        continue;
      }
    }
  }

Object executeAndDecode(RequestTemplate template) throws Throwable {
		// 调用所有请求拦截器获取request
    Request request = targetRequest(template);

    if (logLevel != Logger.Level.NONE) {
      logger.logRequest(metadata.configKey(), logLevel, request);
    }

    Response response;
    long start = System.nanoTime();
    try {
      response = client.execute(request, options);
      // ensure the request is set. TODO: remove in Feign 10
      response.toBuilder().request(request).build();
    } catch (IOException e) {
      if (logLevel != Logger.Level.NONE) {
        logger.logIOException(metadata.configKey(), logLevel, e, elapsedTime(start));
      }
      throw errorExecuting(request, e);
    }

调用所有请求拦截器获取request

Request targetRequest(RequestTemplate template) {
    for (RequestInterceptor interceptor : requestInterceptors) {
      interceptor.apply(template);
    }
    return target.apply(new RequestTemplate(template));
  }

接下来看RequestInterceptor 的实现类有哪些，最终找到同事自己写的一个方法拦截器，如下

public class FeignInterceptor implements RequestInterceptor {
    @Override
    public void apply(RequestTemplate requestTemplate) {
        final ServletRequestAttributes attrs = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        if (attrs != null) {
            final HttpServletRequest request = attrs.getRequest();
            final Enumeration<String> headerNames = request.getHeaderNames();
            if (headerNames != null) {
                //遍历请求头里面的属性字段，将logId和token添加到新的请求头中转发到下游服务
                while (headerNames.hasMoreElements()) {
                    final String name = headerNames.nextElement();
                    final String value = request.getHeader(name);
                    requestTemplate.header(name, value);
                }
            }
        } else {
        }
    }
}

通过以上代码，估计就很快发现了问题，这里将本次请求的所有header都放进了feign调用的header里面。此时通过断点发现本次请求的请求头全是小写的content-length。此时就更加确信是这个问题导致。但这个拦截器我在其他服务上也看到了，但为什么偏偏只有这个服务出错了呢。所以为了最终到本质，继续往下看源码

经过一系列调试最终跟踪到了Okhttp(同事将原本默认的feign调用的httpclient换成了okhttp)

public feign.Response execute(feign.Request input, feign.Request.Options options)
      throws IOException {
    okhttp3.OkHttpClient requestScoped;
    if (delegate.connectTimeoutMillis() != options.connectTimeoutMillis()
        || delegate.readTimeoutMillis() != options.readTimeoutMillis()
        || delegate.followRedirects() != options.isFollowRedirects()) {
      requestScoped = delegate.newBuilder()
          .connectTimeout(options.connectTimeoutMillis(), TimeUnit.MILLISECONDS)
          .readTimeout(options.readTimeoutMillis(), TimeUnit.MILLISECONDS)
          .followRedirects(options.isFollowRedirects())
          .build();
    } else {
      requestScoped = delegate;
    }
    // 转换feign request为okhttp request。
    Request request = toOkHttpRequest(input);
    Response response = requestScoped.newCall(request).execute();
    return toFeignResponse(response, input).toBuilder().request(input).build();
  }

static Request toOkHttpRequest(feign.Request input) {
    Request.Builder requestBuilder = new Request.Builder();
    requestBuilder.url(input.url());

    MediaType mediaType = null;
    boolean hasAcceptHeader = false;
    for (String field : input.headers().keySet()) {
      if (field.equalsIgnoreCase("Accept")) {
        hasAcceptHeader = true;
      }

      for (String value : input.headers().get(field)) {
				// 将所有头放进header中，跟踪到里面发现使用list保存
        requestBuilder.addHeader(field, value);
        if (field.equalsIgnoreCase("Content-Type")) {
          mediaType = MediaType.parse(value);
          if (input.charset() != null) {
            mediaType.charset(input.charset());
          }
        }
      }
    }
    // Some servers choke on the default accept string.
    if (!hasAcceptHeader) {
      requestBuilder.addHeader("Accept", "*/*");
    }

    byte[] inputBody = input.body();
    boolean isMethodWithBody =
        HttpMethod.POST == input.httpMethod() || HttpMethod.PUT == input.httpMethod()
            || HttpMethod.PATCH == input.httpMethod();
    if (isMethodWithBody) {
      requestBuilder.removeHeader("Content-Type");
      if (inputBody == null) {
        // write an empty BODY to conform with okhttp 2.4.0+
        // http://johnfeng.github.io/blog/2015/06/30/okhttp-updates-post-wouldnt-be-allowed-to-have-null-body/
        inputBody = new byte[0];
      }
    }

    RequestBody body = inputBody != null ? RequestBody.create(mediaType, inputBody) : null;
    requestBuilder.method(input.httpMethod().name(), body);
    return requestBuilder.build();
  }

此时还有一个以为为何原来的不报错呢？同样跟踪下原来的代码,最终跟踪到Client#``convertAndSend

for (String field : request.headers().keySet()) {
        if (field.equalsIgnoreCase("Accept")) {
          hasAcceptHeader = true;
        }
        for (String value : request.headers().get(field)) {
          if (field.equals(CONTENT_LENGTH)) {
            if (!gzipEncodedRequest && !deflateEncodedRequest) {
              contentLength = Integer.valueOf(value);
              connection.addRequestProperty(field, value);
            }
          } else {
						// 这里面进行了一些受限header的屏蔽
            connection.addRequestProperty(field, value);
          }
        }
      }

public synchronized void addRequestProperty(String var1, String var2) {
        if (!this.connected && !this.connecting) {
            if (var1 == null) {
                throw new NullPointerException("key is null");
            } else {
                // 判断是否允许的外部扩展头
                if (this.isExternalMessageHeaderAllowed(var1, var2)) {
                    this.requests.add(var1, var2);
                    if (!var1.equalsIgnoreCase("Content-Type")) {
                        this.userHeaders.add(var1, var2);
                    }
                }

            }
        } else {
            throw new IllegalStateException("Already connected");
        }
    }

private static final String[] restrictedHeaders = new String[]{"Access-Control-Request-Headers", "Access-Control-Request-Method", "Connection", "Content-Length", "Content-Transfer-Encoding", "Host", "Keep-Alive", "Origin", "Trailer", "Transfer-Encoding", "Upgrade", "Via"};
private boolean isRestrictedHeader(String var1, String var2) {
        if (allowRestrictedHeaders) {
            return false;
        } else {
            var1 = var1.toLowerCase();
             // 包含了content-length        
            if (restrictedHeaderSet.contains(var1)) {
                return !var1.equals("connection") || !var2.equalsIgnoreCase("close");
            } else {
                return var1.startsWith("sec-");
            }
        }
    }

至此所有疑团消失。完结撒花！