restTemplate拦截器抛异常引发的问题

问题代码：

// 自定义restTemplate错误处理类 屏蔽restTemplate原来的错误处理
@Slf4j
public class ThrowErrorHandler implements ResponseErrorHandler {  

    @Override    
    public boolean hasError(ClientHttpResponse response) {        
        // 返回false表示不管response的status是多少都返回没有错        
        // 这里可以自己定义那些status code你认为是可以抛Error        
        return false;   
    } 
    
    @Override    
    public void handleError(ClientHttpResponse response) { 
    }
}

// 自定义restTemplate拦截器  在拦截器中进行了请求信息的打印，还对请求的返回做了异常处理(造成本次问题的问题的根源)
@Component@Slf4j
public class RestTemplateLogInterceptor implements ClientHttpRequestInterceptor { 

    @Override    
    public ClientHttpResponse intercept(HttpRequest httpRequest, byte[] bytes, ClientHttpRequestExecution clientHttpRequestExecution) throws IOException { 
    
        // 打印访问前日志        
        traceRequest(httpRequest, bytes);        
        ClientHttpResponse execute = clientHttpRequestExecution.execute(httpRequest, bytes); 
        
        // 请求的统一异常处理        
        if (!execute.getStatusCode().is2xxSuccessful()) {            
            throw new BusinessException(MessageFormat.format("请求错误, url={0}, statusCode={1}, statusText={2}", httpRequest.getURI(), execute.getStatusCode(), execute.getStatusText()));        
        } 
        
        // 打印访问后日志        
        traceResponse(execute);        
        return execute;    
    }
    
    // 打印一条访问前日志    
    private void traceRequest(HttpRequest httpRequest, byte[] bytes) {        
        log.info("请求开始,url={},method={},RequestBody={}",httpRequest.getURI(), httpRequest.getMethod(), new String(bytes, StandardCharsets.UTF_8));    
    } 
    
    // 打印一条访问后日志    
    private void traceResponse(ClientHttpResponse response) throws IOException {        
        log.info("请求结束,statusCode={},statusText={}",response.getStatusCode(), response.getStatusText());    
    }
}

// restTemplate配置类
@Configuration
public class RestTemplateConfig { 

    @Autowired    
    private RestTemplateLogInterceptor restTemplateLogInterceptor;    
    
    @Bean(name = "restTemplate")    
    public RestTemplate restTemplate() { 
    
        RestTemplateBuilder builder = new RestTemplateBuilder();        
        return builder
            // 设置http请求连接超时时间
            .setConnectTimeout(1000) 
            // 设置http请求读数据超时时间
            .setReadTimeout(1000) 
            // 自定义拦截器
            .interceptors(restTemplateLogInterceptor) 
            // 自定义异常处理
            .errorHandler(new ThrowErrorHandler())                
            .build();    
    }
}

问题：

线上出现请求超时问题，restTemplate设置的readTimeout参数未生效。
以为是请求问题，对请求进行复现后发现请求所在负载不存在，请求后立马会由nginx返回502错误响应，不应该存在超时问题。

在本地进行debug后发现前五此访问可以正常抛出异常退出，第六次请求会阻塞，阻塞时的栈信息如下所示：

restTemplate异常栈信息.png

通过打印栈信息发现是由org.apache.http.pool.AbstractConnPool类的getPoolEntryBlocking方法的await导致。而此方法只有在拿不到请求连接，等待已有的连接释放时才会被触发。

通过查看配置说明发现httpClient连接池默认配置10个连接，对同一路由地址只能使用5个连接，这与上面5次访问成功不谋而合。

故推测，应该是请求完成后没有释放连接导致。

此时自定义拦截器中的异常处理显得尤为可疑，在正常的请求中系统会自动帮我们进行请求连接的释放工作，但在拦截器抛出异常时，可能会导致原有释放连接的流程被中断。

故在自定义拦截器中抛出异常前手动进行连接的释放，添加如下代码：

    // 只会将连接归还到连接池，并不会正真释放掉连接
    execute.close();

然后即可通过测试。

总结

在类似拦截器的工作场景中，对于抛异常等中断操作一定要进行全局的分析，因为中断操作会导致后续的处理流程直接作废，可能会造成对于资源的销毁、连接的释放等destory操作的失效，进而引发异常。

最后编辑于：2019.06.24 23:03:07