RestTemplate使用ClientHttpRequestInterceptor请求耗时不正确

记录RestTemplate的请求相关信息写了如下拦截器

    private ClientHttpRequestInterceptor logInterceptor() {
        return (request, body, execution) -> {
            StopWatch stopWatch = new StopWatch("request time");
            stopWatch.start();
            ClientHttpResponse response = execution.execute(request, body);
            stopWatch.stop();
            RestLog restLog = new RestLog();
            restLog.setMethod(request.getMethodValue());
            restLog.setUrl(request.getURI().toString());
            restLog.setCostTime(stopWatch.getTotalTimeMillis());
            if (canPrint(request.getHeaders())) {
                restLog.setReqBody(new String(body, StandardCharsets.UTF_8));
            }
            restLog.setReqContentType(request.getHeaders().getContentType());
            if (canPrint(response.getHeaders())) {
                restLog.setRespBody(IOUtils.toString(response.getBody(), StandardCharsets.UTF_8));
            }
            restLog.setRespContentType(response.getHeaders().getContentType());
            log.info(restLog);
            return response;
        };
    }

实际使用过程中发现即使请求时间很长，restLog的costTime依然只有0-2ms，这显然不科学，这里很容易联想到（假设你没有怀疑stopwatch有问题）

ClientHttpResponse response = execution.execute(request, body);

这一步是异步的，这里确实需要考虑响应式编程场景，所以改下stop的位置吧。

附上完整代码：

import org.apache.commons.io.IOUtils;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.springframework.boot.autoconfigure.condition.ConditionalOnClass;
import org.springframework.boot.autoconfigure.condition.ConditionalOnMissingBean;
import org.springframework.boot.web.client.RestTemplateBuilder;
import org.springframework.context.annotation.Bean;
import org.springframework.http.HttpHeaders;
import org.springframework.http.MediaType;
import org.springframework.http.client.BufferingClientHttpRequestFactory;
import org.springframework.http.client.ClientHttpRequestInterceptor;
import org.springframework.http.client.ClientHttpResponse;
import org.springframework.http.client.SimpleClientHttpRequestFactory;
import org.springframework.util.StopWatch;
import org.springframework.web.client.RestTemplate;

import java.nio.charset.StandardCharsets;
import java.time.Duration;

/**
 * @author wxy
 * @version 1.0.0
 * @date 2023/4/11 16:39
 */
@ConditionalOnClass(RestTemplate.class)
@ConditionalOnMissingBean(RestTemplate.class)
public class RestTemplateSupport {

    private static final Log log = LogFactory.getLog("RestLogger");

    @Bean
    public RestTemplate restTemplate(RestTemplateBuilder builder, SpringBootProperties properties) {
        RestProperties rest = properties.getRest();
        return builder
                .requestFactory(() -> new BufferingClientHttpRequestFactory(new SimpleClientHttpRequestFactory()))
                .setReadTimeout(Duration.ofMillis(rest.getReadTimeOut()))
                .setConnectTimeout(Duration.ofMillis(rest.getConnectTimeOut()))
                .additionalInterceptors(logInterceptor())
                .build();
    }

    private ClientHttpRequestInterceptor logInterceptor() {
        return (request, body, execution) -> {
            StopWatch stopWatch = new StopWatch("request time");
            stopWatch.start();
            ClientHttpResponse response = execution.execute(request, body);
            RestLog restLog = new RestLog();
            restLog.setMethod(request.getMethodValue());
            restLog.setUrl(request.getURI().toString());
            if (canPrint(request.getHeaders())) {
                restLog.setReqBody(new String(body, StandardCharsets.UTF_8));
            }
            restLog.setReqContentType(request.getHeaders().getContentType());
            if (canPrint(response.getHeaders())) {
                restLog.setRespBody(IOUtils.toString(response.getBody(), StandardCharsets.UTF_8));
            }
            restLog.setRespContentType(response.getHeaders().getContentType());
            stopWatch.stop();
            restLog.setCostTime(stopWatch.getTotalTimeMillis());
            log.info(restLog);
            return response;
        };
    }

    private static boolean canPrint(HttpHeaders headers) {
        MediaType contentType = headers.getContentType();
        return contentType != null &&
                (contentType.includes(MediaType.APPLICATION_JSON) || contentType.includes(MediaType.TEXT_PLAIN));
    }

}