HTTP 调用的过程分析及监控OKHttp请求过程

Waiting(TTFB)等待响应  通常是网络请求中最耗时的。 从发送请求到收到服务器第一个字节的之间的时间。 收到线路，服务器距离等因素的影响。

一个HTTP网络请求的生命周期的各个步骤以及可以优化的空间：

1. Stalled(阻塞)  对同一个主机域名的服务器的并发连接有数量限制。如果当前的连接已经达到上线，会有则塞，等待新的可用连接。

2.Proxy negotiation  与代理服务器连接的花费时间

3.DNS Lookup(域名解析) 请求某个域名下在资源，需要先通过DNS域名解析获取改服务器的IP地址，在DNS完成之前，不能从该服务器那里下载到任何的东西。

   a.利用DNS缓存，设置TTL时间

   b.利用Connect：keep-alive 特性建立持久连接，可以在当前连接上进行多个请求，无需在进行域名解析。

4.Initial connection（初始化连接） TCP建立三次握手的时间

5.Request sent（发送请求） 发送HTTP请求的时间（从第一个bit到最后一个bit）

   a、减少HTTP请求，可以使用CSS Sprites、内联图片、合并脚本和样式表等；

   b、对不常变化的组件添加长久的Expires头（相当于设置久远的过期时间），在后续的页面浏览中可以避免不必要的HTTP请求；

6.Waiting(TTFB)（等待响应）  通常是耗费时间最长的。从发送请求到收到服务器响应的第一字节之间的时间，受到线路、服务器距离等因素的影响

  a. 使用CDN，将用户的访问指向距离最近的工作正常的缓存服务器上，由缓存服务器直接响应用户请求，提高响应速度；

7. Content Download（下载）

OKHttp 支持记录更详细的事件，通过实现 EventListener.Factory去实现各个节点的事件

一般我们可以使用OKHttp去监控我们请求的过程中的各项耗时：

创建socket连接 = connectEnd - connectStart

发送时间 =  requestBodyEnd - requestHeadersStart

服务端处理时间(大于等于TTFB) =  responseHeadersStart - requestBodyEnd（或者requestHeadersEnd ）

接收时间 = responseBodyEnd  - responseHeadersStart

请求整体耗时 = callEnd - callStart

OkHttpClient.Builder builder = new OkHttpClient.Builder();
try {
    // 禁用https证书检测
    X509TrustManager disabledTrustManager = new X509TrustManager() {
        @Override
        public void checkClientTrusted(X509Certificate[] x509Certificates, String s) throws CertificateException {

        }

        @Override
        public void checkServerTrusted(X509Certificate[] x509Certificates, String s) throws CertificateException {

        }

        @Override
        public X509Certificate[] getAcceptedIssuers() {
            return new X509Certificate[0];
        }
    };
    SSLSocketFactory disabledSSLSocketFactory = null;
    TrustManager[] trustManagers = new TrustManager[1];
    trustManagers[0] = disabledTrustManager;
    SSLContext sslContext = SSLContext.getInstance("SSL");
    sslContext.init(null, trustManagers, new java.security.SecureRandom());
    disabledSSLSocketFactory = sslContext.getSocketFactory();
    builder.sslSocketFactory(disabledSSLSocketFactory, disabledTrustManager);
} catch (NoSuchAlgorithmException | KeyManagementException e) {
    log.warn("cant disable ssl validation", e);
}
httpClient = builder
        .connectTimeout(config.getConnectTimeout(), TimeUnit.MILLISECONDS)
        .readTimeout(config.getReadTimeout(), TimeUnit.MILLISECONDS)
        .retryOnConnectionFailure(false)
        .eventListenerFactory(new MetricEventListenerFactory(Tags.of("clientApp",config.getAppName(),"appId",config.getSecurityAppId())))
        //.dispatcher(dispatcher) // 因为所有请求都是走同步方法，所以不需要修改dispatcher
        // 每个后端连接最多保持一半的idle连接
        .connectionPool(new ConnectionPool(config.getMaxConnection()/2,60,TimeUnit.SECONDS))
        .build();

import io.micrometer.core.instrument.Counter;
import io.micrometer.core.instrument.Metrics;
import io.micrometer.core.instrument.Tag;
import io.micrometer.core.instrument.Tags;
import lombok.SneakyThrows;
import lombok.extern.slf4j.Slf4j;
import okhttp3.*;

import java.io.IOException;
import java.net.InetAddress;
import java.net.InetSocketAddress;
import java.net.Proxy;
import java.util.List;
import java.util.concurrent.TimeUnit;


@Slf4j
public class MetricEventListenerFactory implements EventListener.Factory {
    public static final String connectTimer = "ok.connect.timer";
    public static final String requestCallTimer = "ok.request.call.timer";
    public static final String requestSendTimer = "ok.request.send.timer";
    public static final String requestTTFBTimer = "ok.request.ttfb.timer";
    public static final String responseReceiveTimer = "ok.response.receive.timer";
    public static final long dnsSlowThresholdMills = 5;
    private final Counter requestTotal;
    private Tags tags;
    private Counter requestBusy;

    public MetricEventListenerFactory(Tags tags) {
        this.tags = tags;
        requestBusy = Metrics.counter("ok.request.busy", tags);
        requestTotal = Metrics.counter("ok.request.total", tags);
    }


    @Override
    public EventListener create(Call call) {
        return new MonitorEventListener(tags);
    }

    public final class MonitorEventListener extends EventListener {
        public MonitorEventListener(Iterable<? extends Tag> tags) {
            this.tags = tags;
        }

        private Iterable<? extends Tag> tags;
        private long callStart;
        private long callFinished;
        private long requestHeadersStart;
        private long requestHeadersEnd;
        private long requestBodyStart;
        private long requestSendFinished;
        private long responseHeadersStart;
        private long responseHeadersEnd;
        private long responseReceiveFinished;
        private long responseBodyStart;
        private long connectStart;
        private long connectFinished;
        private long dnsStart;
        private long dnsEnd;
        private String domainName;
        private InetSocketAddress inetSocketAddress;
        private Exception requestFailedException;
        private IOException responseFailedException;
        private Exception callFailedException;

        @Override
        public void callEnd( Call call) {
            recodeAfterCallFinished(call);
        }

        @Override
        public void callFailed( Call call, IOException ioe) {
            callFailedException = ioe;
            recodeAfterCallFinished(call);
        }

        private void recodeAfterCallFinished(Call call) {
            callFinished = System.nanoTime();
            requestBusy.increment(-1);
            Metrics.timer(requestCallTimer, getTags(call, callFailedException)).record(callFinished - callStart, TimeUnit.NANOSECONDS);
            if (requestSendFinished > 0) {
                Metrics.timer(requestSendTimer, getTags(call, requestFailedException)).record(requestSendFinished - requestHeadersStart, TimeUnit.NANOSECONDS);
            }
            if (responseHeadersStart > 0) {
                Metrics.timer(requestTTFBTimer, getTags(call)).record(responseHeadersStart - requestSendFinished, TimeUnit.NANOSECONDS);
            }
            if (responseReceiveFinished > 0) {
                Metrics.timer(responseReceiveTimer, getTags(call, responseFailedException)).record(responseReceiveFinished - responseHeadersStart, TimeUnit.NANOSECONDS);
            }
        }


        private Tags getTags(Call call) {
            return getTags(call, null);
        }

        private Tags getTags(Call call, Exception ex) {
            String remoteServiceName = call.request().url().pathSegments().get(0);
            String apiClass = MeopenapiInvocationHandler.getCurrentMethod().get().getDeclaringClass().getSimpleName();
            String apiMethod = MeopenapiInvocationHandler.getCurrentMethod().get().getName();
            call.request().url().url().getPath();
            return Tags.concat(this.tags, "remoteService", remoteServiceName, "apiClass", apiClass, "apiMethod", apiMethod, "exception", ex == null ? "none" : ex.getClass().getSimpleName());
        }

        @Override
        public void callStart( Call call) {
            callStart = System.nanoTime();
            requestTotal.increment();
            requestBusy.increment();
        }

        @Override
        public void connectEnd( Call call,  InetSocketAddress inetSocketAddress,  Proxy proxy,Protocol protocol) {
            connectFinished = System.nanoTime();
            Metrics.timer(connectTimer, getTags(call)).record(connectFinished - connectStart, TimeUnit.NANOSECONDS);
        }

        @Override
        public void connectFailed(Call call,  InetSocketAddress inetSocketAddress,  Proxy proxy, Protocol protocol, IOException ioe) {
            connectFinished = System.nanoTime();
            Metrics.timer(connectTimer, getTags(call, ioe)).record(connectFinished - connectStart, TimeUnit.NANOSECONDS);
        }

        @Override
        public void connectStart( Call call, InetSocketAddress inetSocketAddress,  Proxy proxy) {
            connectStart = System.nanoTime();
            this.inetSocketAddress = inetSocketAddress;
        }

//            @Override
//            public void connectionAcquired(@NotNull Call call, @NotNull Connection connection) {
//                log.info("connectionAcquired");
//                connectionAcquired = System.nanoTime();
//            }

//            @Override
//            public void connectionReleased(@NotNull Call call, @NotNull Connection connection) {
//                log.info("connectionReleased");
//                connectionReleased = System.nanoTime();
//            }

        @Override
        public void dnsEnd( Call call,  String domainName,  List<InetAddress> inetAddressList) {
            dnsEnd = System.nanoTime();
            this.domainName = domainName;
            if (dnsEnd - dnsStart > dnsSlowThresholdMills * 1000_1000) {
                log.warn("dns lookup too slow: {} ms", (dnsEnd - dnsStart) / 1000_000);
            }
        }

        @Override
        public void dnsStart(Call call,  String domainName) {
            dnsStart = System.nanoTime();
        }


        @Override
        public void requestBodyEnd( Call call, long byteCount) {
            requestSendFinished = System.nanoTime();
        }

        @Override
        public void requestBodyStart( Call call) {
            requestBodyStart = System.nanoTime();
        }

        @Override
        public void requestFailed( Call call, IOException ioe) {
            requestSendFinished = System.nanoTime();
            requestFailedException = ioe;
        }

        @SneakyThrows
        @Override
        public void requestHeadersEnd( Call call,Request request) {
            requestSendFinished = System.nanoTime();
        }

        @Override
        public void requestHeadersStart( Call call) {
            requestHeadersStart = System.nanoTime();
        }

        @Override
        public void responseBodyEnd( Call call, long byteCount) {
            responseReceiveFinished = System.nanoTime();
        }

        @Override
        public void responseBodyStart( Call call) {
            responseBodyStart = System.nanoTime();
        }

        @Override
        public void responseFailed( Call call, IOException ioe) {
            responseReceiveFinished = System.nanoTime();
            responseFailedException = ioe;
        }

        @Override
        public void responseHeadersEnd( Call call,  Response response) {
            responseReceiveFinished = System.nanoTime();
        }

        @Override
        public void responseHeadersStart( Call call) {
            responseHeadersStart = System.nanoTime();
        }


//            @Override
//            public void secureConnectEnd(@NotNull Call call, @Nullable Handshake handshake) {
//                secureConnectEnd = System.nanoTime();
//            }
//
//            @Override
//            public void secureConnectStart(@NotNull Call call) {
//                secureConnectStart = System.nanoTime();
//            }
    }

}