HttpClient中隐藏的BUG解析一下

1,981 阅读7分钟

这是我参与2022首次更文挑战的第3天,活动详情查看:2022首次更文挑战

前言

  • 在项目开发过程中,总会有和外部三方接口进行交互的场景。一般而言,这类接口通常都是用http请求访问。
  • 调用http请求一般可以使用HttpClient和OkHttp发送请求。
  • 本篇文章描述一下HttpClient使用过程中的一些需要注意的情况。

HttpClient请求示例

  • 首先通过idea创建一个简易的springboot项目,并引入httpclient的maven配置
        <dependency>
            <groupId>org.apache.httpcomponents</groupId>
            <artifactId>httpclient</artifactId>
            <version>4.5.6</version>
        </dependency>
  • 构建一个简易的HttpClient使用工具类,配置超时时间都是3000毫秒,连接池最大200个,里面有一个发送get请求的方法。
/**
 * http请求工具类
 *
 * @author zrh
 */
@Slf4j
public final class HttpClientUtil {

    private HttpClientUtil () {
    }

    /**
     * 超时时间配置,单位(毫秒)
     */
    private static final int SOCKET_TIMEOUT = 3000;
    private static RequestConfig requestConfig;
    private static CloseableHttpClient httpClient;

    static {
        PoolingHttpClientConnectionManager cm = new PoolingHttpClientConnectionManager();
        cm.setMaxTotal(200);
        cm.setDefaultMaxPerRoute(100);

        requestConfig = RequestConfig.custom()
                .setConnectionRequestTimeout(SOCKET_TIMEOUT)
                .setConnectTimeout(SOCKET_TIMEOUT)
                .setSocketTimeout(SOCKET_TIMEOUT)
                .build();

        httpClient = HttpClients.custom()
                .setConnectionManager(cm)
                .setConnectionManagerShared(true)
                .build();
    }

    public static String httpGetRequest (String url) {
        long start = System.currentTimeMillis();
        HttpGet httpGet = new HttpGet(url);
        try {
            // 设置超时配置
            httpGet.setConfig(requestConfig);
            // 执行请求
            CloseableHttpResponse response = httpClient.execute(httpGet);
            log.info("HttpRequest请求 耗时:{}", (System.currentTimeMillis() - start));
            // 获取请求结果
            HttpEntity entity = response.getEntity();
            if (entity != null) {
                String result = EntityUtils.toString(entity);
                response.close();
                return result;
            }
        } catch (IOException e) {
            log.info("HttpRequest请求耗时:{},异常:{}", (System.currentTimeMillis() - start), e.getMessage());
            e.printStackTrace();
        }
        return null;
    }
}
  • 项目配置文件里端口设置8801,然后开一个对外接口,并写个main方法进行http访问接口。

/**
 * @Author: ZRH
 * @Date: 2022/1/24 15:00
 */
@Slf4j
@RestController
public class HttpClientController {

    @GetMapping("/httpClient/test")
    public String test () throws InterruptedException {
        log.info("接口请求进来成功");
        return "ok";
    }

    public static void main (String[] args) {
        String url = "http://localhost:8801/httpClient/test";
        String result = HttpClientUtil.httpGetRequest(url);
        System.out.println("请求结果:" + result);
    }
}
  • springboot项目启动后,执行当前main方法,结果如下图: 1.png

2.png

请求发生异常不走重试

  • HttpClient是默认开启重试配置的,配置的源码在HttpClientBuilder.build()方法里:
public CloseableHttpClient build() {
        // Create main request executor
        // We copy the instance fields to avoid changing them, and rename to avoid accidental use of the wrong version

        ......        

        // Add request retry executor, if not disabled
        if (!automaticRetriesDisabled) {
            HttpRequestRetryHandler retryHandlerCopy = this.retryHandler;
            if (retryHandlerCopy == null) {
                retryHandlerCopy = DefaultHttpRequestRetryHandler.INSTANCE;
            }
            execChain = new RetryExec(execChain, retryHandlerCopy);
        }
        ......
    }
  • 通过DefaultHttpRequestRetryHandler.INSTANCE默认配置可以进入DefaultHttpRequestRetryHandler类。
  • DefaultHttpRequestRetryHandler实现了HttpRequestRetryHandler接口,里面有一个retryRequest(IOException exception, int executionCount, HttpContext context)方法。retryRequest方法主要执行重试逻辑,三个参数分表是发生的异常,重试的次数,当前请求链路的上下文。
  • 这里既然默认开启重试机制,那把服务端接口进行阻塞睡眠几秒,看客户端是否会进行重试呢。。。
    @GetMapping("/httpClient/test")
    public String test () throws InterruptedException {
        log.info("接口请求进来成功");
        Thread.sleep(4000);
        return "ok";
    }

------------运行main方法,执行结果如下:
17:07:59.229 logback [main] INFO  com.mysql.web.utils.HttpClientUtil - HttpRequest请求耗时:3040,异常:Read timed out
请求结果:null
java.net.SocketTimeoutException: Read timed out
   at java.net.SocketInputStream.socketRead0(Native Method)
   at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
   at java.net.SocketInputStream.read(SocketInputStream.java:171)
   at java.net.SocketInputStream.read(SocketInputStream.java:141)
   at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137)
   at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153)
   at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:280)
   at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138)
   at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56)
   at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259)
   at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163)
   at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:165)
   at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273)
   at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125)
   at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272)
   at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185)
   at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
   at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
   at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
   at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
   at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)
   at com.mysql.web.utils.HttpClientUtil.httpGetRequest(HttpClientUtil.java:75)
   at com.mysql.web.controller.HttpClientController.main(HttpClientController.java:41)
  • 可以看到这里直接抛出了一个读取链接超时异常:java.net.SocketTimeoutException: Read timed out。并没有走重试流程。
  • 源码之下没有秘密,既然这和我们想象中的结果不一样,那就深入源码看看其执行流程是如何的。。。
    • 首先是判断重试次数有没有超过3次,如果有就不再重试,否则继续往下走,
    • 再判断本次发生的异常是否在this.nonRetriableClasses对象里面,this.nonRetriableClasses是一个set集合,通过名称可知道这是一个不可重试类集合,
    • 再判断异常是否具有集合this.nonRetriableClasses里的子类实例,
    • 再后面流程就和节点无关,按下不表。
/**
     * Used {@code retryCount} and {@code requestSentRetryEnabled} to determine
     * if the given method should be retried.
     */
    @Override
    public boolean retryRequest(
            final IOException exception,
            final int executionCount,
            final HttpContext context) {
        Args.notNull(exception, "Exception parameter");
        Args.notNull(context, "HTTP context");
        if (executionCount > this.retryCount) {
            // Do not retry if over max retry count
            return false;
        }
        if (this.nonRetriableClasses.contains(exception.getClass())) {
            return false;
        } else {
            for (final Class<? extends IOException> rejectException : this.nonRetriableClasses) {
                if (rejectException.isInstance(exception)) {
                    return false;
                }
            }
        }
        final HttpClientContext clientContext = HttpClientContext.adapt(context);
        final HttpRequest request = clientContext.getRequest();

        if(requestIsAborted(request)){
            return false;
        }

        if (handleAsIdempotent(request)) {
            // Retry if the request is considered idempotent
            return true;
        }

        if (!clientContext.isRequestSent() || this.requestSentRetryEnabled) {
            // Retry if the request has not been sent fully or
            // if it's OK to retry methods that have been sent
            return true;
        }
        // otherwise do not retry
        return false;
    }
  • 了解上述重试流程后,通过debug可知走到rejectException.isInstance(exception)判断里最后返回了false,最后就没有走重试

3.png

  • this.nonRetriableClasses集合有4个不同的异常类,通过DefaultHttpRequestRetryHandler构造函数可知。
  • 所以当http请求抛出异常属于下列四种异常时,就不会走重试,而之前测试示例中异常SocketTimeoutException属于InterruptedIOException异常,所以最后没有走重试机制。
  • 注:当前构造函数里的参数retryCount为默认重试次数3次
    /**
     * Create the request retry handler using the following list of
     * non-retriable IOException classes: <br>
     * <ul>
     * <li>InterruptedIOException</li>
     * <li>UnknownHostException</li>
     * <li>ConnectException</li>
     * <li>SSLException</li>
     * </ul>
     * @param retryCount how many times to retry; 0 means no retries
     * @param requestSentRetryEnabled true if it's OK to retry non-idempotent requests that have been sent
     */
    @SuppressWarnings("unchecked")
    public DefaultHttpRequestRetryHandler(final int retryCount, final boolean requestSentRetryEnabled) {
        this(retryCount, requestSentRetryEnabled, Arrays.asList(
                InterruptedIOException.class,
                UnknownHostException.class,
                ConnectException.class,
                SSLException.class));
    }
  • 如果想要走重试机制,那可以自定义实现HttpRequestRetryHandler接口,重写其中retryRequest方法的逻辑。只需在httpclient工具类中新增以下配置即可:
        httpClient = HttpClients.custom()
                .setConnectionManager(cm)
                .setConnectionManagerShared(true)
                .setRetryHandler(new HttpRequestRetryHandler() {
                    @Override
                    public boolean retryRequest (IOException exception, int executionCount, HttpContext context) {
                        if (executionCount > 3) {
                            // Do not retry if over max retry count
                            return false;
                        }
                        // 允许进行重试的异常
                        if (exception instanceof SocketTimeoutException) {
                            return true;
                        }
                        // otherwise do not retry
                        return false;
                    }
                })
                .build();
  • 最后再次只需main方法,其运行结果如下:
-----------------------客户端打印:
17:31:39.097 logback [main] INFO  o.a.http.impl.execchain.RetryExec - I/O exception (java.net.SocketTimeoutException) caught when processing request to {}->http://localhost:8801: Read timed out
17:31:39.100 logback [main] INFO  o.a.http.impl.execchain.RetryExec - Retrying request to {}->http://localhost:8801
17:31:42.103 logback [main] INFO  o.a.http.impl.execchain.RetryExec - I/O exception (java.net.SocketTimeoutException) caught when processing request to {}->http://localhost:8801: Read timed out
17:31:42.103 logback [main] INFO  o.a.http.impl.execchain.RetryExec - Retrying request to {}->http://localhost:8801
17:31:45.106 logback [main] INFO  o.a.http.impl.execchain.RetryExec - I/O exception (java.net.SocketTimeoutException) caught when processing request to {}->http://localhost:8801: Read timed out
17:31:45.106 logback [main] INFO  o.a.http.impl.execchain.RetryExec - Retrying request to {}->http://localhost:8801
17:31:48.108 logback [main] INFO  com.mysql.web.utils.HttpClientUtil - HttpRequest请求耗时:12063,异常:Read timed out
请求结果:null
java.net.SocketTimeoutException: Read timed out
......

----------------------服务端打印:
17:31:36.143 logback [XNIO-1 task-1] INFO  c.m.w.c.HttpClientController - 接口请求进来成功
17:31:39.102 logback [XNIO-1 task-2] INFO  c.m.w.c.HttpClientController - 接口请求进来成功
17:31:42.107 logback [XNIO-1 task-1] INFO  c.m.w.c.HttpClientController - 接口请求进来成功
17:31:45.107 logback [XNIO-1 task-2] INFO  c.m.w.c.HttpClientController - 接口请求进来成功
  • 所以最后执行了重试机制,而且通过结果可以知道一共重试了3次http请求,然后在加上最初的请求,所以最后其实一共发送了4次http请求。

socketTimeout作用域

  • 上述示例中对httpClient工具类中增加了一下链接超时配置:
    • connectionRequestTimeout:从本地连接池中获取连接超时配置。
    • connectTimeout:连接服务器socket超时配置。
    • socketTimeout:读取服务器socket数据包超时配置。
  • 其中socketTimeout配置表示当前客户端已经连接到服务端socket连接,但是读取数据超时,比如服务端发生超时阻塞等等。
  • 但是这里socketTimeout仅代表数据包传输读取时间,如果一个http请求响应分为多个数据包回传,然后每个数据包都没有达到socketTimeout超时配置,但总的数据包传输时间超过socketTimeout配置,那也不会报超时异常。
  • 举个例子,httpclient还是之前3000毫秒配置,然后新增下列方法,方法中每隔2秒往HttpServletResponse对象里写入一个数据,最后打印耗时时间:
    @GetMapping("/httpClient/test/string")
    public void string (HttpServletResponse response) throws InterruptedException, IOException {
        final long start = System.currentTimeMillis();
        log.info("接口请求进来成功");
        String[] arr = new String[]{"a", "b", "c", "d"};
        for (int i = 0; i < 4; i++) {
            response.setStatus(HttpServletResponse.SC_OK);
            response.getWriter().println(arr[i]);
            response.flushBuffer();
            Thread.sleep(2000);
        }
        log.info("接口总耗时:{}", (System.currentTimeMillis() - start));
    }

    public static void main (String[] args) {
        final long start = System.currentTimeMillis();
        String regUrl = "http://localhost:8801/httpClient/test/string";
        String respStr = HttpClientUtil.httpGetRequest(regUrl);
        System.out.println("请求耗时:" + (System.currentTimeMillis() - start));
        System.out.println(respStr);
    }

---------------------运行main方法,服务端打印:
17:49:24.928 logback [XNIO-1 task-2] INFO  c.m.w.c.HttpClientController - 接口总耗时:8007

---------------------客户端打印:
17:57:24.022 logback [main] INFO  com.mysql.web.utils.HttpClientUtil - HttpRequest请求 耗时:48
请求耗时:8436
a
b
c
d
  • 服务端总耗时执行了8秒左右,但客户端也没有报异常:java.net.SocketTimeoutException: Read timed out

最后

e.png

  • 上述的问题很明显其实不是HttpClient的bug,其设计理念和思路是符合大部分场景。
  • 只有当使用者不清楚其实现机制原理,在项目中使用不当时就有可能会写出bug代码。
  • 虚心学习,共同进步 -_-