六虎

Troubleshooting系列-一次基于okhttp外部接口调用超时问题分析

Troubleshooting系列-一次基于okhttp外部接口调用超时问题分析

作者：

小综哥

在

1.问题现象

最近事务有做运用架构整合，将原先一部分事务从服务A移到服务B。其中接口功用中有一段http调用风控才能的逻辑。版别上线后，有部分此接口流量进入服务B，此刻发现一个非常古怪的问题，就是服务B这个http接口的超时比例比服务A高许多。

服务A 接口超时率在0.5%左右
服务B 接口超时率在10%左右

2.问题剖析

2.1 剖析源码

首先找到问题代码，当前写法类似如下，相关事务代码泛化调了

public class OkhttpTest {
    private static final ExecutorService OAS_CALL_THREAD_POOL =
            new ThreadPoolExecutor(2, 20, 60, TimeUnit.SECONDS, new LinkedBlockingQueue<>());
    public static void main(String[] args) {
        String ret = new OkhttpTest().getRisk();
        System.out.println("ret="   ret);
    }
    public String getRisk() {
        try {
            Future<String> result = OAS_CALL_THREAD_POOL.submit(() -> {
                return getRemoteRequest("https://openapi.vmall.com/rms/v1/comment/getCommentListByTag?pid=10086764961298&systemTagIds=10050001&pageSize=10&pageNum=2&gbomCode=&sortType=1&showStatistics=false&1711285500237");
            });
            return result.get(500, TimeUnit.MILLISECONDS);
        } catch (TimeoutException e) {
            System.out.println("time out");
            return "failed";
        } catch (Exception e) {
            System.out.println(e.getMessage());
            return "failed";
        }
    }
    private String getRemoteRequest(String url) {
        ConnectionPool connectionPool = new ConnectionPool(512,30, TimeUnit.MINUTES)
        OkHttpClient client = new OkHttpClient.Builder()
                .readTimeout(500, TimeUnit.MILLISECONDS)
                .connectTimeout(500, TimeUnit.MILLISECONDS)
                .connectionPool(connectionPool)
                .build();
        // 创立Request目标，指定URL和恳求办法
        Request request = new Request.Builder()
                .url(url)
                .build();
        String result;
        try {
            // 发送恳求并获取Response目标
            Response response = client.newCall(request).execute();
            // 查看恳求是否成功
            if (response.isSuccessful()) {
                // 读取响应体内容
                result = response.body().string();
                System.out.println("Response: "   result);
            } else {
                // 处理恳求失利的状况
                System.out.println("Request failed with code: "   response.code());
                result = String.valueOf(response.code());
            }
        } catch (IOException e) {
            // 处理网络反常
            e.printStackTrace();
            result = "IOException";
        } finally {
            // 关闭衔接（如果需求）
        }
        return result;
    }
}

这种写法经过future来操控超时时间，实际履行成果如下

time out
ret=failed
Response: {"data":xxx}

此刻发现虽然接口返回失利，可是恳求成果还是履行完结。

原因是由于http调用的超时时间readTimeOut 500,connecttimeout = 1000ms >  500
future 超时时间500
readTimeOut   connecttimeout = 1000ms > future 500 ms

虽然上述代码写的有问题，不应该采用线程池异步等候，可直接运用http的超时机制，可是由于服务A和服务B代码共同，感觉超时率忽然添加许多的原因很难解释。

2.2 剖析网络布置差异性

既然代码共同，后面就想到是否是两个运用服务在现网布置环境的差异性。
由于调用接口都是相同的，置疑网络出口带宽或许其他装备是否存在差异。

首先问询运维查看两个微服务布置网络差异性，反馈无差异，且服务B出口网络、带宽啥的监控没啥问题
接着我们在两台容器上运用tracerout和curl指令独自履行http指令看网络耗时 成果也是共同，并无太大不相同地方

至此，网络布置事务差异

2.3 持续剖析日志

持续剖析ELK上日志，发现服务A现网调用量很大

Troubleshooting系列-一次根据okhttp外部接口调用超时问题剖析
服务B现网调用量根本不是在一个量级上

Troubleshooting系列-一次根据okhttp外部接口调用超时问题剖析

在想会不会okhttp有啥衔接池之类的东西，由于http衔接如果首次衔接需求dns解析和树立衔接之类的操作，树立完之后，第2次会省去创立衔接实践

http长衔接机制

翻看创立httpClient代码,默许创立512个衔接，30分钟失效，可是实际上从上述调用量来看半个小时估计才调用30次作用，或许每次调用衔接都没法复用。

ConnectionPool connectionPool = new ConnectionPool(512,30, TimeUnit.MINUTES)

2.4 验证

修改ConnectionPool参数，持续验证

public static void main(String[] args) {
    long start = System.currentTimeMillis();
    String ret = new OkhttpTest().getRisk();
    long end1 = System.currentTimeMillis();
    System.out.println("ret="   ret);
    ret = new OkhttpTest().getRisk();
    long end2 = System.currentTimeMillis();
    System.out.println("ret1 time="   (end1 - start)   " ret2 time="   (end2 - end1));
}
public String getRisk() {
    return getRemoteRequest("https://openapi.vmall.com/rms/v1/comment/getCommentListByTag?pid=10086764961298&systemTagIds=10050001&pageSize=10&pageNum=2&gbomCode=&sortType=1&showStatistics=false&1711285500237");
}
private String getRemoteRequest(String url) {
    ConnectionPool connectionPool = new ConnectionPool(1, 30, TimeUnit.MINUTES);
   ...
}

运转成果,能够看出第2次履行时间大幅下降

Response: {"data":xxx
Response: {"data":xxx
ret1 time=1133 ret2 time=250

3.问题处理

处理措施如下：

  1. 将ConnectionPool中maxIdleConnections调小一些512->8（后续随着调用量上升在调大一些），keepAliveDuration时间从30min->60min，尽量保证衔接复用
  2. 将运用future和线程池调用方式改成直接http调用，削减不必要的逻辑
  3. 适当添加http超时时间装备

4.参考资料

浅显易懂 OkHttp 源码解析及运用实践
OkHttp 系列七：衔接池与恳求服务拦截器

更多文章