Spring RestTemplate - how to enable full debugging/logging of requests/responses?
I have been using the Spring RestTemplate for a while and I consistently hit a wall when I'am trying to debug it's requests and responses. I'm basically looking to see the same things as I see when I use curl with the "verbose" option turned on. For example :
curl -v http://twitter.com/statuses/public_timeline.rss
Would display both the sent data and the received data (including the headers, cookies, etc.).
I have checked some related posts like : How do I log response in Spring RestTemplate? but I haven't managed to solve this issue.
One way to do this would be to actually change the RestTemplate source code and add some extra logging statements there, but I would find this approach really a last resort thing. There should be some way to tell Spring Web Client/RestTemplate to log everything in a much friendlier way.
My goal would be to be able to do this with code like :
restTemplate.put("http://someurl", objectToPut, urlPathValues);
and then to get the same type of debug information (as I get with curl) in the log file or in the console. I believe this would be extremely useful for anyone that uses the Spring RestTemplate and has problems. Using curl to debug your RestTemplate problems just doesn't work (in some cases).
Just to complete the example with a full implementation of ClientHttpRequestInterceptor to trace request and response:
import java.io.BufferedReader;
import java.io.IOException;
import java.io.InputStreamReader;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.http.HttpRequest;
import org.springframework.http.client.ClientHttpRequestExecution;
import org.springframework.http.client.ClientHttpRequestInterceptor;
import org.springframework.http.client.ClientHttpResponse;
public class LoggingRequestInterceptor implements ClientHttpRequestInterceptor {
final static Logger log = LoggerFactory.getLogger(LoggingRequestInterceptor.class);
@Override
public ClientHttpResponse intercept(HttpRequest request, byte[] body, ClientHttpRequestExecution execution) throws IOException {
traceRequest(request, body);
ClientHttpResponse response = execution.execute(request, body);
traceResponse(response);
return response;
}
private void traceRequest(HttpRequest request, byte[] body) throws IOException {
log.info("===========================request begin================================================");
log.debug("URI : {}", request.getURI());
log.debug("Method : {}", request.getMethod());
log.debug("Headers : {}", request.getHeaders() );
log.debug("Request body: {}", new String(body, "UTF-8"));
log.info("==========================request end================================================");
}
private void traceResponse(ClientHttpResponse response) throws IOException {
StringBuilder inputStringBuilder = new StringBuilder();
BufferedReader bufferedReader = new BufferedReader(new InputStreamReader(response.getBody(), "UTF-8"));
String line = bufferedReader.readLine();
while (line != null) {
inputStringBuilder.append(line);
inputStringBuilder.append('\n');
line = bufferedReader.readLine();
}
log.info("============================response begin==========================================");
log.debug("Status code : {}", response.getStatusCode());
log.debug("Status text : {}", response.getStatusText());
log.debug("Headers : {}", response.getHeaders());
log.debug("Response body: {}", inputStringBuilder.toString());
log.info("=======================response end=================================================");
}
}
Then instantiate RestTemplate using a BufferingClientHttpRequestFactory and the LoggingRequestInterceptor:
RestTemplate restTemplate = new RestTemplate(new BufferingClientHttpRequestFactory(new SimpleClientHttpRequestFactory()));
List<ClientHttpRequestInterceptor> interceptors = new ArrayList<>();
interceptors.add(new LoggingRequestInterceptor());
restTemplate.setInterceptors(interceptors);
The BufferingClientHttpRequestFactory is required as we want to use the response body both in the interceptor and for the initial calling code. The default implementation allows to read the response body only once.
in Spring Boot you can get the full request/response by setting this in properties (or other 12 factor method)
logging.level.org.apache.http=DEBUG
this outputs
-DEBUG .i.c.DefaultHttpClientConnectionOperator : Connecting to localhost/127.0.0.1:41827
-DEBUG .i.c.DefaultHttpClientConnectionOperator : Connection established 127.0.0.1:39546<->127.0.0.1:41827
-DEBUG o.a.http.impl.execchain.MainClientExec : Executing request POST /v0/users HTTP/1.1
-DEBUG o.a.http.impl.execchain.MainClientExec : Target auth state: UNCHALLENGED
-DEBUG o.a.http.impl.execchain.MainClientExec : Proxy auth state: UNCHALLENGED
-DEBUG org.apache.http.headers : http-outgoing-0 >> POST /v0/users HTTP/1.1
-DEBUG org.apache.http.headers : http-outgoing-0 >> Content-Type: application/json;charset=UTF-8
-DEBUG org.apache.http.headers : http-outgoing-0 >> Content-Length: 56
-DEBUG org.apache.http.headers : http-outgoing-0 >> Host: localhost:41827
-DEBUG org.apache.http.headers : http-outgoing-0 >> Connection: Keep-Alive
-DEBUG org.apache.http.headers : http-outgoing-0 >> User-Agent: Apache-HttpClient/4.5.2 (Java/1.8.0_102)
-DEBUG org.apache.http.headers : http-outgoing-0 >> Accept-Encoding: gzip,deflate
-DEBUG org.apache.http.wire : http-outgoing-0 >> "POST /v0/users HTTP/1.1[\r][\n]"
-DEBUG org.apache.http.wire : http-outgoing-0 >> "Content-Type: application/json;charset=UTF-8[\r][\n]"
-DEBUG org.apache.http.wire : http-outgoing-0 >> "Content-Length: 56[\r][\n]"
-DEBUG org.apache.http.wire : http-outgoing-0 >> "Host: localhost:41827[\r][\n]"
-DEBUG org.apache.http.wire : http-outgoing-0 >> "Connection: Keep-Alive[\r][\n]"
-DEBUG org.apache.http.wire : http-outgoing-0 >> "User-Agent: Apache-HttpClient/4.5.2 (Java/1.8.0_102)[\r][\n]"
-DEBUG org.apache.http.wire : http-outgoing-0 >> "Accept-Encoding: gzip,deflate[\r][\n]"
-DEBUG org.apache.http.wire : http-outgoing-0 >> "[\r][\n]"
-DEBUG org.apache.http.wire : http-outgoing-0 >> "{"id":null,"email":"[email protected]","new":true}"
and response
-DEBUG .i.c.DefaultHttpClientConnectionOperator : Connecting to localhost/127.0.0.1:41827
-DEBUG .i.c.DefaultHttpClientConnectionOperator : Connection established 127.0.0.1:39546<->127.0.0.1:41827
-DEBUG o.a.http.impl.execchain.MainClientExec : Executing request POST /v0/users HTTP/1.1
-DEBUG o.a.http.impl.execchain.MainClientExec : Target auth state: UNCHALLENGED
-DEBUG o.a.http.impl.execchain.MainClientExec : Proxy auth state: UNCHALLENGED
-DEBUG org.apache.http.headers : http-outgoing-0 >> POST /v0/users HTTP/1.1
-DEBUG org.apache.http.headers : http-outgoing-0 >> Content-Type: application/json;charset=UTF-8
-DEBUG org.apache.http.headers : http-outgoing-0 >> Content-Length: 56
-DEBUG org.apache.http.headers : http-outgoing-0 >> Host: localhost:41827
-DEBUG org.apache.http.headers : http-outgoing-0 >> Connection: Keep-Alive
-DEBUG org.apache.http.headers : http-outgoing-0 >> User-Agent: Apache-HttpClient/4.5.2 (Java/1.8.0_102)
-DEBUG org.apache.http.headers : http-outgoing-0 >> Accept-Encoding: gzip,deflate
-DEBUG org.apache.http.wire : http-outgoing-0 >> "POST /v0/users HTTP/1.1[\r][\n]"
-DEBUG org.apache.http.wire : http-outgoing-0 >> "Content-Type: application/json;charset=UTF-8[\r][\n]"
-DEBUG org.apache.http.wire : http-outgoing-0 >> "Content-Length: 56[\r][\n]"
-DEBUG org.apache.http.wire : http-outgoing-0 >> "Host: localhost:41827[\r][\n]"
-DEBUG org.apache.http.wire : http-outgoing-0 >> "Connection: Keep-Alive[\r][\n]"
-DEBUG org.apache.http.wire : http-outgoing-0 >> "User-Agent: Apache-HttpClient/4.5.2 (Java/1.8.0_102)[\r][\n]"
-DEBUG org.apache.http.wire : http-outgoing-0 >> "Accept-Encoding: gzip,deflate[\r][\n]"
-DEBUG org.apache.http.wire : http-outgoing-0 >> "[\r][\n]"
-DEBUG org.apache.http.wire : http-outgoing-0 >> "{"id":null,"email":"[email protected]","new":true}"
or just logging.level.org.apache.http.wire=DEBUG which seems to contain all of the relevant information