apache httpcomponents client 의 timeout 동작 테스트

이전글에서 timeout 에 대한 설명을 적어놨었다. 이후 실제로 문서에 나와있는대로 동작하는지 확인해보기로 했다. 해당글에서 정리한 내용이 정확하다면 response timeout 과 socket timeout 을 훨씬 초과하여 응답이 오더라도 바이트들만 제 시간 내에 도착한다면 예외없이 요청이 성공해야한다.
 
테스트에 사용한 apache httpcomponents client 의 버전은 5.5이다.
org.apache.httpcomponents.client5:httpclient5:5.5
 

# 코드준비

먼저 stream 으로 응답을 하는 간단한 API 하나를 구성했다.

@GetMapping(value = "/stream", produces = MediaType.TEXT_PLAIN_VALUE)   
public StreamingResponseBody stream() {                                 
    return outputStream -> {                                            
        for (int i = 0; i < 50; i++) {                                 
            String data = "data " + i + "\n";                           
            outputStream.write(data.getBytes(StandardCharsets.UTF_8));  
            outputStream.flush();
            try {                                                       
                Thread.sleep(100); // 100ms 간격                          
            } catch (InterruptedException e) {                          
                e.printStackTrace();                                    
            }                                                           
        }                                                               
    };                                                                  
}

해당 API 는 "data 0, data 1, data 2 ..." 형태로 응답을 스트리밍으로 하게된다. 그리고 스트리밍 간격은 100ms 이다. 로컬에서 서버를 구동시켜서 curl 로 실행해보면 응답을 확인해볼 수 있다.
curl http://localhost:8080/stream
 
해당 API 를 호출할 클라이언트 코드를 작성한다.

public static void main(String[] args) throws Exception {                                                                  
    ConnectionConfig connectionConfig = ConnectionConfig.custom()                                                          
            .setConnectTimeout(50, TimeUnit.MILLISECONDS)                                                                  
            .setSocketTimeout(100, TimeUnit.MILLISECONDS) // socket timeout 100ms                                                                  
            .build();                                                                                                      
                                                                                                                           
    PoolingHttpClientConnectionManager poolingHttpClientConnectionManager = new PoolingHttpClientConnectionManager();      
    poolingHttpClientConnectionManager.setDefaultConnectionConfig(connectionConfig);                                       
                                                                                                                           
    RequestConfig requestConfig = RequestConfig.custom()                                                                   
            .setConnectionRequestTimeout(200, TimeUnit.MILLISECONDS)                                                       
            .setResponseTimeout(100, TimeUnit.MILLISECONDS) // response timeout 100ms                                                                 
            .build();                                                                                                      
                                                                                                                           
    CloseableHttpClient httpClients = HttpClients.custom()                                                                 
            .setConnectionManager(poolingHttpClientConnectionManager)                                                      
            .setDefaultRequestConfig(requestConfig)                                                                        
            .build();                                                                                                      
                                                                                                                           
    HttpGet httpGet = new HttpGet("http://localhost:8080/stream");                                                         
    httpClients.execute(httpGet, (classicHttpResponse) -> {                                                                
        HttpEntity entity = classicHttpResponse.getEntity();                                                               
                                                                                                                           
        try (InputStream in = entity.getContent();                                                                         
             BufferedReader reader = new BufferedReader(                                                                   
                     new InputStreamReader(in, StandardCharsets.UTF_8))) {                                                 
                                                                                                                           
            String line;                                                                                                   
            while ((line = reader.readLine()) != null) {                                                                   
                System.out.println(line);                                                                                  
            }                                                                                                              
        }                                                                                                                  
        return null;                                                                                                       
    });                                                                                                                    
}

timeout 4개를 모두 설정하고 있지만 주석으로 표시한 socketTimeout, responseTimeout 이 핵심이니 이 부분만 변경해주며 테스트하면 된다.
 

# 테스트

## socketTimeout 150ms responseTimeout 150ms

첫번째 바이트를 대기하는 responseTimeout 도 안정권이고, 바이트 간격을 대기하는 socketTimeout 도 안정권이다. 성공적으로 응답을 받고, 차례대로 출력하는걸 볼 수 있다.
 

## socketTimeout 150ms responseTimeout 80ms

첫번째 바이트를 대기하는 시간이 80ms 로 줄었다. 하지만 위 예제 API 는 첫번째 바이트는 sleep 없이 바로 응답하고, 두번째 바이트부터 sleep 을 걸고있기 때문에 timeout 이 문서대로 동작한다면 요청은 성공해야한다.

하지만 요청이 실패했다. 그런데 자세히보면 첫번째 바이트인 "data 0" 은 정상출력한걸 볼 수 있다. 즉 두번째 바이트를 대기하다가 예외가 발생한 것이다.
 

## socketTimeout 80ms responseTimeout 150ms

이번엔 두 타임아웃 값을 반대로 변경했다. 예상대로 동작한다면 위에서 발생한 예외가 위가 아니라 여기서 발생해야한다.

오잉 성공했다.
 

## socketTimeout 80ms responseTimeout 80ms

예상대로 동작한다면 첫번째 바이트만 출력되고, 예외가 발생해아한다.

예상대로 동작한다.
 

# 문제

socketTimeout 과 responseTimeout 이 모두 여유롭거나 모두 부족할땐 예상대로 동작했는데 두 값이 한쪽만 부족할땐 예상과 다르게 동작하고 있다. 원인이 무엇일까?
apache httpcomponents client 는 제대로된 문서가 없고, javadoc 이 문서를 대체하고있어 일단 공식적인 문서자료를 확인하기가 매우 어려웠다. 결국은 코드를 들여다볼 수 밖에 없었는데 코드에서 원인을 찾을 수 있었다.

PoolingHttpClientConnectionManager.java

먼저 직접적인 HTTP Connection 을 생성하는 PoolingHttpClientConnectionManager 클래스를 확인해보면 이렇게 connection 생성시 socketTimeout 을 설정하고 있다. 그런데 코드를 더 들어가보면

InternalExecRuntime.java

실제로 요청을 실행하는 시점에 responseTimeout 을 꺼내고, socketTimeout 에 설정하고 있다.
 
이걸 확인하는 순간 responseTimeout 이 발생하는 시점에도 ResponseTimeoutException 이 아니라 SocketTimeoutException 이 발생하는 이유까지 밝혀졌다. responseTimeout 이 socketTimeout 을 덮어쓰고 있는 것이다.
즉 문서에서 명시하고 있는대로 첫번째 응답 바이트까지 responseTimeout 이 관여하고, 두번째 바이트부터 socketTimeout 이 관여하는게 아니다. 사실 이전에 timeout 정리를 할때 개인적으로 느꼈던 부분은 responseTimeout 과 socketTimeout 을 이 정도로 분리해서 관리하면 코드 작성하기가 번거롭겠다 라고 생각했었는데, 그저 그냥 덮어쓰고 있던 것이다.
 
그리고 socketTimeout 은 ConnectionConfig 에서, responseTimeout 은 RequestConfig 라는 서로 다른 Config 객체를 통해 설정하고 있던것도 문맥을 이해하게 되었다. socketTimeout 은 connection 생성시 전달하고, responseTimeout 은 실제 요청(request)시 전달하기 때문이었던 것이다. 이 때문에 connection 수준에서는 socketTimeout 이 적용되고, 요청 수준에서는 responseTimeout 이 적용된다. responseTimeout 을 설정했다면 socketTimeout 은 적용되지 않는다!!!
 

# 마무리

이런 내용은 공식문서는 물론이고, 웹 검색에서도 찾기가 쉽지 않았다. 하지만 apache httpcomponents 를 사용하는 입장에서는 매우 중요한 요소이다. 생각보다 문서화가 상당히 부실하여 실망스럽기도 했지만 문서 변경에 대한 PR( https://github.com/apache/httpcomponents-client/pull/712 ) 을 제출했다. 받아들여질지는 모르겠지만.