Spring RestTemplate 사용 시 HTTP request, response 로그 남기기

spring의 RestTemplate을 이용하면 대게 다음의 exchange 메소드를 이용하여 외부 API와 연동을 하게 된다.

ResponseEntity<P> response = restTemplate.exchange(requestUrl, httpMethod, requestEntity, p);

위의 exchange 메소드를 이용하여 연동을 할 때 HTTP request, response 전문을 로그로 남기고 싶을 때가 있어서 그 방법을 찾아보게 되었다.

첫 번째 방법은 log4j를 이용하여 로그를 남기는 방법인데 이 방법은 한 줄 로그로 남길 수 없다는 단점이 있어 포기했다. 무슨 말이냐하면 아래와 같이 여러 줄로 로그가 기록된다는 것이다. 여러 줄로 출력되는 로그는 멀티 쓰레드 환경에서는 오류에 대한 원인을 찾기가 힘들다.

[2015-10-14 16:49:49 DEBUG o.a.h.headers][273] - >> GET /test/check.json HTTP/1.1

[2015-10-14 16:49:49 DEBUG o.a.h.headers][276] - >> Accept: application/json, application/*+json

[2015-10-14 16:49:49 DEBUG o.a.h.headers][276] - >> Content-Type: application/json

[2015-10-14 16:49:49 DEBUG o.a.h.headers][276] - >> Host: test.com:8080

[2015-10-14 16:49:49 DEBUG o.a.h.headers][276] - >> Connection: Keep-Alive

[2015-10-14 16:49:49 DEBUG o.a.h.headers][276] - >> User-Agent: Apache-HttpClient/4.2.6 (java 1.5)

[2015-10-14 16:49:49 DEBUG o.a.h.wire][63] - << "HTTP/1.1 200 OK[\r][\n]"

[2015-10-14 16:49:49 DEBUG o.a.h.wire][63] - << "Content-Type: application/json[\r][\n]"

[2015-10-14 16:49:49 DEBUG o.a.h.wire][63] - << "Content-Length: 173[\r][\n]"

[2015-10-14 16:49:49 DEBUG o.a.h.wire][63] - << "Server: WebServer/9239402.2329 Instance/2.464680819[\r][\n]"

[2015-10-14 16:49:49 DEBUG o.a.h.wire][63] - << "[\r][\n]"

두 번재 방법은 RestTemplate에 interceptors 를 추가하는 것이다.

<bean id="restTemplate" class="org.springframework.web.client.RestTemplate">

<property name="interceptors">

<list>

<bean class="com.test.RestTemplateLoggingRequestInterceptor" />

</list>

</property>

</bean>

RestTemplate이 상속하고 있는 InterceptingHttpAccessor 클래스를 확인해 보면 interceptors를 주입받을 수 있게 되어 있다. 다음과 같이 로그 기록용 interceptor 클래스를 생성한 후 등록해 주면 HTTP request, response 로그를 남길 수 있다.

허나 여기서 끝이 아니다.

RestTemplateLoggingRequestInterceptor 클래스에서 response로그를 찍을 때 byte[] bodyData = IOUtils.toByteArray(is); 코드를 이용하여 response body의 데이터를 stream을 통해 읽어온 후 해당 stream을 close해 버린다. 그렇기 때문에 다른 코드상에서 response의 body를 읽게 되면 아래와 같은 오류 메세지를 만날 수 있게 된다.

Attempted read from closed stream

이 문제를 해결해 줄 수 있는 클래스가 BufferingClientHttpRequestFactory 이다.

BufferingClientHttpRequestFactory 코드 내에는 response의 body를 copy하는 로직이 있기 때문에 Attempted read from closed stream 오류를 회피할 수 있다.

최종적인 설정은 다음과 같다.

<bean id="connectionManager" class="org.apache.http.impl.conn.PoolingClientConnectionManager">

<property name="maxTotal" value="200" />

<property name="defaultMaxPerRoute" value="100" />

</bean>

<bean id="httpClient" class="org.apache.http.impl.client.DefaultHttpClient">

<constructor-arg ref="connectionManager"/>

</bean>

<bean id="httpClientFactory" class="org.springframework.http.client.HttpComponentsClientHttpRequestFactory">

<constructor-arg ref="httpClient" />

<property name="connectTimeout" value="10" />

<property name="readTimeout" value="10" />

</bean>

<bean id="bufferingClientHttpRequestFactory" class="org.springframework.http.client.BufferingClientHttpRequestFactory">

<constructor-arg ref="httpClientFactory" />

</bean>

<bean id="restTemplate" class="org.springframework.web.client.RestTemplate">

<constructor-arg ref="bufferingClientHttpRequestFactory" />

<property name="messageConverters">

<list>

<bean class="org.springframework.http.converter.StringHttpMessageConverter">

<constructor-arg value="UTF-8" />

</bean>

<bean class="org.springframework.http.converter.json.MappingJacksonHttpMessageConverter">

<property name="objectMapper">

<bean class="com.test.CustomObjectMapper" />

</property>

</bean>

<bean class="org.springframework.http.converter.xml.Jaxb2RootElementHttpMessageConverter" />

</list>

</property>

<property name="interceptors">

<list>

<bean class="com.test.interceptor.RestTemplateLoggingRequestInterceptor" />

</list>

</property>

</bean>