RestTemplate打印日志的正确姿势

阅读：评论：0

背景

现在随着微服务的逐渐发展，越来越多的公司开始采用微服务架构，但随之而来的问题是，服务间如何调用，如何还能负载均衡，还必须开箱即用？答案就是Spring的RestTemplate啦（并不一定要使用RestTemplate，也不一定要是微服务架构，涉及到Http调用的服务，方式都可以，我这个是为了引出主题），但伴随而来的是一个问题，如何打印好日志，留下现场（防止扯皮），这才是我们关心的。这也是我们这篇文章的主题-RestTemplate打印日志的正确姿势。好了，不凑字数了，接下来进入正文。

1. 老实人干事

作为一个老实人，对于打日志这类请求，就是通过代理，找出核心方法，在方法后，打印日志参数即可。实时，我也就是这么做的，如下图：

我把RestTemplate的最底层方法进行了包装，然后在执行后，返回结果前但因日志。这样做，说实话，没毛病，并且我拿去运行，放在线上运行了好长一段时间，没出任何问题。但是…但是…，现实就是偏偏就欺(bu)负(xi)老(xin)实(ren)人(zhen)

2. 老实人翻盘

为什么说是欺(bu)负(xi)老(xin)实(ren)人(zhen)呢？最近我在看代码的时候，发现了ResTemplate提供了一个方法RestTemplate#setInterceptors，我们通过名称就知道，是设置拦截器的。只看名称，那还不一定，我们需要去瞅瞅源码才行。

2.1 源码追踪

setInterceptors方法如下：

// 设置拦截器
public void setInterceptors(List<ClientHttpRequestInterceptor> interceptors) {// Take getInterceptors() List as-is when passed in hereif (this.interceptors != interceptors) {this.interceptors.clear();this.interceptors.addAll(interceptors);// 对拦截器进行排序AnnotationAwareOrderComparator.sort(this.interceptors);}
}

setInterceptors逻辑很简单，就是添加拦截器。我们接下来要看看拦截器是在哪里使用的，这也是我们需要确认的点。接着往下。

// 构建RequestFactory
public ClientHttpRequestFactory getRequestFactory() {// 获取拦截器List<ClientHttpRequestInterceptor> interceptors = getInterceptors();if (!CollectionUtils.isEmpty(interceptors)) {// 拦截器不为空ClientHttpRequestFactory factory = this.interceptingRequestFactory;if (factory == null) {// 使用拦截器构建的RequestFactoryfactory = new RequestFactory(), interceptors);this.interceptingRequestFactory = factory;}return factory;}else {// 返回默认的 SimpleClientHttpRequestFactory，可以自己查看一下RequestFactory();}
}

在getRequestFactory中搜寻到了拦截器的使用，是通过拦截器，构建了一个InterceptingClientHttpRequestFactory对象。目前，我们通过名字大意可以看到，是构建了一个拦截器的请求工厂，但还是没有具体信息，让我们接着往下，看看这个InterceptingClientHttpRequestFactory里面是怎么使用的。

省略中间简单的逻辑，我们找到了最终逻辑。在InterceptingRequestExecution源代码如下：

private class InterceptingRequestExecution implements ClientHttpRequestExecution {private final Iterator<ClientHttpRequestInterceptor> iterator;public InterceptingRequestExecution() {// 胡哦哦去拦截器的迭代器this.iterator = interceptors.iterator();}@Overridepublic ClientHttpResponse execute(HttpRequest request, byte[] body) throws IOException {if (this.iterator.hasNext()) {ClientHttpRequestInterceptor nextInterceptor = ();//每次将当前对象传入，循环迭代调用拦截器return nextInterceptor.intercept(request, body, this);}else {// 当拦截器执行完，开始执行请求逻辑HttpMethod method = Method();Assert.state(method != null, "No standard HTTP method");ClientHttpRequest delegate = URI(), method);Headers().forEach((key, value) -> Headers().addAll(key, value));...// 执行请求，并返回执行结果对象。ute();}}
}

在执行execute方法时，循环调用拦截器方法。当拦截器执行完后，构建请求对象，执行请求。请求执行完，返回请求结果对象。

3. 拨开迷雾

源码看我我TM悟了，原来别人提供了拦截器，我还自己搞那么复杂。这不是吃力不讨好吗？那不行，我的改造我的代码。

3.1 实现拦截器接口-ClientHttpRequestInterceptor

贴上我写的代码，如下所示：

/*** <br>日志拦截器</br>** @author fattyca1* @since 1.0*/
@Slf4j
public class LoggingRequestInterceptor implements ClientHttpRequestInterceptor {// 用来记录接口执行时间的最小接收值private final long timeoutMs;public LoggingRequestInterceptor(long timeoutMs) {this.timeoutMs = timeoutMs;}@Overridepublic ClientHttpResponse intercept(HttpRequest request, byte[] body, ClientHttpRequestExecution execution) throws IOException {long start = System.currentTimeMillis();ClientHttpResponse response = ute(request, body);long cost = System.currentTimeMillis() - start;if (cost > timeoutMs) {log.warn("Request uri: [{}], Cost times: {}ms", URI(), cost);}// 打印日志trace(request, body, response);return response;}private void trace(HttpRequest request, byte[] body, ClientHttpResponse response) throws IOException {// 记录日志String responseStr = Body(), StandardCharsets.UTF_8);log.info("n" +"URI          : {}, n" +"Method       : {}, n" +"Headers      : {}, n" +"Param        : {}, n" +"RespStatus   : {}, n" +"Response     : {}", URI(),Method(), Headers(), new String(body, StandardCharsets.UTF_8), StatusCode(), responseStr);}
}

代码逻辑很简单，实现拦截器，在拦截器中执行请求的时候，根据入参，出参，并打印结果。

3.2 构建RestTemplate对象

构建RestTemplate对象代码如下所示：

private RestTemplateWrapper buildHttpRestTemplate(CloseableHttpClient client) {RestTemplateWrapper restTemplate = new RestTemplateWrapper();HttpComponentsClientHttpRequestFactory clientHttpRequestFactory= new HttpComponentsClientHttpRequestFactory(client);// 连接超时clientHttpRequestFactory.ConnectionTimeOut());// 数据读取超时时间clientHttpRequestFactory.SocketTimeOut());// 连接不够用的等待时间clientHttpRequestFactory.ConnectionRequestTimeout());// 需要支持从response重复获取body数据// restTemplate.setRequestFactory(new BufferingClientHttpRequestFactory(clientHttpRequestFactory));restTemplate.setRequestFactory(clientHttpRequestFactory);// 设置拦截器restTemplate.setInterceptors(Collections.singletonList(new LogTimeoutMs())));return restTemplate;
}

我们通过一些列操作，到了构建RestTemplate对象这，并且设置了拦截器，可以开开心心的去注入RestTemplate对象啦。

3.3 坑，你躲开了吗

大家拿着RestTemplate开开心心去使用的时候，发现了没，会出错！！！是的，会报错！！！好气，我辛辛苦苦搞半天，还会出错，错误如下：

Caused by: java.io.IOException: Attempted read from closed stream.

出现这个错误原因，主要是因为Body()只能获取一次，在后续RestTemplate获取输出转化时会再次调用Body()。

 // 拦截器的打印日志代码中 Body() 只能获取一次，然后会关闭流，有兴趣的可以看看源码String responseStr = Body(), StandardCharsets.UTF_8);

既然知道问题了，那我们就得修改，那怎么修改呢？经过一番查找，找出了这个类BufferingClientHttpRequestFactory，瞅瞅这个注释（我怀疑就是坑！！不然为啥正好有一个这样的包装类）：

/*** Wrapper for a {@link ClientHttpRequestFactory} that buffers* all outgoing and incoming streams in memory.** <p>Using this wrapper allows for multiple reads of the* {@linkplain ClientHttpResponse#getBody() response body}.*/
public class BufferingClientHttpRequestFactory extends AbstractClientHttpRequestFactoryWrapper {}

注释中清楚地写着，可以多次调用ClientHttpResponse#getBody()。现在我们知道怎么解决这个问题了，那么就根据它的使用方法，重新构建RestTemplate对象。代码如下（上方构建RestTemplate对象中的注释打开）：

private RestTemplateWrapper buildHttpRestTemplate(CloseableHttpClient client) {RestTemplateWrapper restTemplate = new RestTemplateWrapper();HttpComponentsClientHttpRequestFactory clientHttpRequestFactory= new HttpComponentsClientHttpRequestFactory(client);// 连接超时clientHttpRequestFactory.ConnectionTimeOut());// 数据读取超时时间clientHttpRequestFactory.SocketTimeOut());// 连接不够用的等待时间clientHttpRequestFactory.ConnectionRequestTimeout());//通过BufferingClientHttpRequestFactory对象包装现有的ResquestFactory，用来支持多次调用getBody()方法restTemplate.setRequestFactory(new BufferingClientHttpRequestFactory(clientHttpRequestFactory));// 打印记录restTemplate.setInterceptors(Collections.singletonList(new LogTimeoutMs())));return restTemplate;
}

至此，我们在开始运行，才发行可以走的通。