Spring Boot - How to log all requests and responses with exceptions in single place?

In order to log requests that result in 400 only:

import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import javax.servlet.http.HttpSession;

import org.apache.commons.io.FileUtils;
import org.springframework.http.HttpStatus;
import org.springframework.http.server.ServletServerHttpRequest;
import org.springframework.stereotype.Component;
import org.springframework.util.StringUtils;
import org.springframework.web.filter.AbstractRequestLoggingFilter;
import org.springframework.web.filter.OncePerRequestFilter;
import org.springframework.web.util.ContentCachingRequestWrapper;
import org.springframework.web.util.WebUtils;

/**
* Implementation is partially copied from {@link AbstractRequestLoggingFilter} and modified to output request information only if request resulted in 400.
* Unfortunately {@link AbstractRequestLoggingFilter} is not smart enough to expose {@link HttpServletResponse} value in afterRequest() method.
*/
@Component
public class RequestLoggingFilter extends OncePerRequestFilter {

public static final String DEFAULT_AFTER_MESSAGE_PREFIX = "After request [";

public static final String DEFAULT_AFTER_MESSAGE_SUFFIX = "]";

private final boolean includeQueryString = true;
private final boolean includeClientInfo = true;
private final boolean includeHeaders = true;
private final boolean includePayload = true;

private final int maxPayloadLength = (int) (2 * FileUtils.ONE_MB);

private final String afterMessagePrefix = DEFAULT_AFTER_MESSAGE_PREFIX;

private final String afterMessageSuffix = DEFAULT_AFTER_MESSAGE_SUFFIX;

/**
* The default value is "false" so that the filter may log a "before" message
* at the start of request processing and an "after" message at the end from
* when the last asynchronously dispatched thread is exiting.
*/
@Override
protected boolean shouldNotFilterAsyncDispatch() {
return false;
}

@Override
protected void doFilterInternal(final HttpServletRequest request, final HttpServletResponse response, final FilterChain filterChain)
throws ServletException, IOException {

final boolean isFirstRequest = !isAsyncDispatch(request);
HttpServletRequest requestToUse = request;

if (includePayload && isFirstRequest && !(request instanceof ContentCachingRequestWrapper)) {
requestToUse = new ContentCachingRequestWrapper(request, maxPayloadLength);
}

final boolean shouldLog = shouldLog(requestToUse);

try {
filterChain.doFilter(requestToUse, response);
} finally {
if (shouldLog && !isAsyncStarted(requestToUse)) {
afterRequest(requestToUse, response, getAfterMessage(requestToUse));
}
}
}

private String getAfterMessage(final HttpServletRequest request) {
return createMessage(request, this.afterMessagePrefix, this.afterMessageSuffix);
}

private String createMessage(final HttpServletRequest request, final String prefix, final String suffix) {
final StringBuilder msg = new StringBuilder();
msg.append(prefix);
msg.append("uri=").append(request.getRequestURI());

if (includeQueryString) {
final String queryString = request.getQueryString();
if (queryString != null) {
msg.append('?').append(queryString);
}
}

if (includeClientInfo) {
final String client = request.getRemoteAddr();
if (StringUtils.hasLength(client)) {
msg.append(";client=").append(client);
}
final HttpSession session = request.getSession(false);
if (session != null) {
msg.append(";session=").append(session.getId());
}
final String user = request.getRemoteUser();
if (user != null) {
msg.append(";user=").append(user);
}
}

if (includeHeaders) {
msg.append(";headers=").append(new ServletServerHttpRequest(request).getHeaders());
}

if (includeHeaders) {
final ContentCachingRequestWrapper wrapper = WebUtils.getNativeRequest(request, ContentCachingRequestWrapper.class);
if (wrapper != null) {
final byte[] buf = wrapper.getContentAsByteArray();
if (buf.length > 0) {
final int length = Math.min(buf.length, maxPayloadLength);
String payload;
try {
payload = new String(buf, 0, length, wrapper.getCharacterEncoding());
} catch (final UnsupportedEncodingException ex) {
payload = "[unknown]";
}
msg.append(";payload=").append(payload);
}
}
}
msg.append(suffix);
return msg.toString();
}

private boolean shouldLog(final HttpServletRequest request) {
return true;
}

private void afterRequest(final HttpServletRequest request, final HttpServletResponse response, final String message) {
if (response.getStatus() == HttpStatus.BAD_REQUEST.value()) {
logger.warn(message);
}
}

}

You can also configure a custom Spring interceptor `HandlerInterceptorAdapter` for a simplified implementation of pre-only/post-only interceptors:

@Component
public class CustomHttpInterceptor extends HandlerInterceptorAdapter {

@Override
public boolean preHandle (final HttpServletRequest request, final HttpServletResponse response,
final Object handler)
throws Exception {

// Logs here

return super.preHandle(request, response, handler);
}

@Override
public void afterCompletion(final HttpServletRequest request, final HttpServletResponse response,
final Object handler, final Exception ex) {
// Logs here
}
}

Then, you register as many interceptors as you want:

@Configuration
public class WebMvcConfig implements WebMvcConfigurer {

@Autowired
CustomHttpInterceptor customHttpInterceptor;

@Override
public void addInterceptors(InterceptorRegistry registry) {
registry.addInterceptor(customHttpInterceptor).addPathPatterns("/endpoints");
}

}


----------


***Note:** [just like stated by @Robert][1], you need to pay attention to the specific implementations of `HttpServletRequest` and `HttpServletResponse` your application is using.*

For example, for apps using the `ShallowEtagHeaderFilter`, the response implementation would be a `ContentCachingResponseWrapper`, so you'd have:

@Component
public class CustomHttpInterceptor extends HandlerInterceptorAdapter {

private static final Logger LOGGER = LoggerFactory.getLogger(CustomHttpInterceptor.class);

private static final int MAX_PAYLOAD_LENGTH = 1000;

@Override
public void afterCompletion(final HttpServletRequest request, final HttpServletResponse response,
final Object handler, final Exception ex) {
final byte[] contentAsByteArray = ((ContentCachingResponseWrapper) response).getContentAsByteArray();

LOGGER.info("Request body:\n" + getContentAsString(contentAsByteArray, response.getCharacterEncoding()));
}

private String getContentAsString(byte[] buf, String charsetName) {
if (buf == null || buf.length == 0) {
return "";
}

try {
int length = Math.min(buf.length, MAX_PAYLOAD_LENGTH);

return new String(buf, 0, length, charsetName);
} catch (UnsupportedEncodingException ex) {
return "Unsupported Encoding";
}
}

}

[1]:

[To see links please register here]

If you are seeing only part of your request payload, you need to call the `setMaxPayloadLength` function as it defaults to showing only 50 characters in your request body. Also, setting `setIncludeHeaders` to false is a good idea if you don't want to log your auth headers!

@Bean
public CommonsRequestLoggingFilter requestLoggingFilter() {
CommonsRequestLoggingFilter loggingFilter = new CommonsRequestLoggingFilter();
loggingFilter.setIncludeClientInfo(false);
loggingFilter.setIncludeQueryString(false);
loggingFilter.setIncludePayload(true);
loggingFilter.setIncludeHeaders(false);
loggingFilter.setMaxPayloadLength(500);
return loggingFilter;
}

Please refer to below link for actual answer
<https://gist.github.com/int128/e47217bebdb4c402b2ffa7cc199307ba>

Made some changes from above referred solution , request and response will log in console and in file too if logger level is info. we can print either in console or file.

@Component
public class LoggingFilter extends OncePerRequestFilter {

private static final List<MediaType> VISIBLE_TYPES = Arrays.asList(
MediaType.valueOf("text/*"),
MediaType.APPLICATION_FORM_URLENCODED,
MediaType.APPLICATION_JSON,
MediaType.APPLICATION_XML,
MediaType.valueOf("application/*+json"),
MediaType.valueOf("application/*+xml"),
MediaType.MULTIPART_FORM_DATA
);
Logger log = LoggerFactory.getLogger(ReqAndResLoggingFilter.class);
private static final Path path = Paths.get("/home/ramesh/loggerReq.txt");
private static BufferedWriter writer = null;
@Override
protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException {
try {
writer = Files.newBufferedWriter(path, Charset.forName("UTF-8"));
if (isAsyncDispatch(request)) {
filterChain.doFilter(request, response);
} else {
doFilterWrapped(wrapRequest(request), wrapResponse(response), filterChain);
}
}finally {
writer.close();
}
}

protected void doFilterWrapped(ContentCachingRequestWrapper request, ContentCachingResponseWrapper response, FilterChain filterChain) throws ServletException, IOException {
try {
beforeRequest(request, response);
filterChain.doFilter(request, response);
}
finally {
afterRequest(request, response);
response.copyBodyToResponse();
}
}

protected void beforeRequest(ContentCachingRequestWrapper request, ContentCachingResponseWrapper response) throws IOException {
if (log.isInfoEnabled()) {
logRequestHeader(request, request.getRemoteAddr() + "|>");
}
}

protected void afterRequest(ContentCachingRequestWrapper request, ContentCachingResponseWrapper response) throws IOException {
if (log.isInfoEnabled()) {
logRequestBody(request, request.getRemoteAddr() + "|>");
logResponse(response, request.getRemoteAddr() + "|<");
}
}

private void logRequestHeader(ContentCachingRequestWrapper request, String prefix) throws IOException {
String queryString = request.getQueryString();
if (queryString == null) {
printLines(prefix,request.getMethod(),request.getRequestURI());
log.info("{} {} {}", prefix, request.getMethod(), request.getRequestURI());
} else {
printLines(prefix,request.getMethod(),request.getRequestURI(),queryString);
log.info("{} {} {}?{}", prefix, request.getMethod(), request.getRequestURI(), queryString);
}
Collections.list(request.getHeaderNames()).forEach(headerName ->
Collections.list(request.getHeaders(headerName)).forEach(headerValue ->
log.info("{} {}: {}", prefix, headerName, headerValue)));
printLines(prefix);
printLines(RequestContextHolder.currentRequestAttributes().getSessionId());
log.info("{}", prefix);

log.info(" Session ID: ", RequestContextHolder.currentRequestAttributes().getSessionId());
}

private void printLines(String ...args) throws IOException {

try {
for(String varArgs:args) {
writer.write(varArgs);
writer.newLine();
}
}catch(IOException ex){
ex.printStackTrace();
}

}

private void logRequestBody(ContentCachingRequestWrapper request, String prefix) {
byte[] content = request.getContentAsByteArray();
if (content.length > 0) {
logContent(content, request.getContentType(), request.getCharacterEncoding(), prefix);
}
}

private void logResponse(ContentCachingResponseWrapper response, String prefix) throws IOException {
int status = response.getStatus();
printLines(prefix, String.valueOf(status), HttpStatus.valueOf(status).getReasonPhrase());
log.info("{} {} {}", prefix, status, HttpStatus.valueOf(status).getReasonPhrase());
response.getHeaderNames().forEach(headerName ->
response.getHeaders(headerName).forEach(headerValue ->
log.info("{} {}: {}", prefix, headerName, headerValue)));
printLines(prefix);
log.info("{}", prefix);
byte[] content = response.getContentAsByteArray();
if (content.length > 0) {
logContent(content, response.getContentType(), response.getCharacterEncoding(), prefix);
}
}

private void logContent(byte[] content, String contentType, String contentEncoding, String prefix) {
MediaType mediaType = MediaType.valueOf(contentType);
boolean visible = VISIBLE_TYPES.stream().anyMatch(visibleType -> visibleType.includes(mediaType));
if (visible) {
try {
String contentString = new String(content, contentEncoding);
Stream.of(contentString.split("\r\n|\r|\n")).forEach(line -> {
try {
printLines(line);
} catch (IOException e) {
// TODO Auto-generated catch block
e.printStackTrace();
}
});
// log.info("{} {}", prefix, line));
} catch (UnsupportedEncodingException e) {
log.info("{} [{} bytes content]", prefix, content.length);
}
} else {

log.info("{} [{} bytes content]", prefix, content.length);
}
}

private static ContentCachingRequestWrapper wrapRequest(HttpServletRequest request) {
if (request instanceof ContentCachingRequestWrapper) {
return (ContentCachingRequestWrapper) request;
} else {
return new ContentCachingRequestWrapper(request);
}
}

private static ContentCachingResponseWrapper wrapResponse(HttpServletResponse response) {
if (response instanceof ContentCachingResponseWrapper) {
return (ContentCachingResponseWrapper) response;
} else {
return new ContentCachingResponseWrapper(response);
}
}
}


Output in File:

127.0.0.1|>
POST
/createUser
127.0.0.1|>
session Id:C0793464532E7F0C7154913CBA018B2B
Request:
{
"name": "asdasdas",
"birthDate": "2018-06-21T17:11:15.679+0000"
}
127.0.0.1|<
200
OK
127.0.0.1|<
Response:
{"name":"asdasdas","birthDate":"2018-06-21T17:11:15.679+0000","id":4}

Here my solution (Spring 2.0.x)

Add the maven dependency:

<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-actuator</artifactId>
</dependency>

Edit the **application.properties** and add the following line:

management.endpoints.web.exposure.include=*

Once your spring boot application is started you can track the latest 100 http requests by calling this url:
*http://localhost:8070/actuator/httptrace*

Spring already provides a filter that does this job. Add following bean to your config

@Bean
public CommonsRequestLoggingFilter requestLoggingFilter() {
CommonsRequestLoggingFilter loggingFilter = new CommonsRequestLoggingFilter();
loggingFilter.setIncludeClientInfo(true);
loggingFilter.setIncludeQueryString(true);
loggingFilter.setIncludePayload(true);
loggingFilter.setMaxPayloadLength(64000);
return loggingFilter;
}

Don't forget to change log level of `org.springframework.web.filter.CommonsRequestLoggingFilter` to `DEBUG`.

the code pasted below works with my tests and can be downloaded from my [github project][1], sharing after applying a solution based on that on a production project.


@Configuration
public class LoggingFilter extends GenericFilterBean {

/**
* It's important that you actually register your filter this way rather then just annotating it
* as @Component as you need to be able to set for which "DispatcherType"s to enable the filter
* (see point *1*)
*
* @return
*/
@Bean
public FilterRegistrationBean<LoggingFilter> initFilter() {
FilterRegistrationBean<LoggingFilter> registrationBean = new FilterRegistrationBean<>();
registrationBean.setFilter(new LoggingFilter());

// *1* make sure you sett all dispatcher types if you want the filter to log upon
registrationBean.setDispatcherTypes(EnumSet.allOf(DispatcherType.class));

// *2* this should put your filter above any other filter
registrationBean.setOrder(Ordered.HIGHEST_PRECEDENCE);

return registrationBean;
}

@Override
public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain)
throws IOException, ServletException {

ContentCachingRequestWrapper wreq =
new ContentCachingRequestWrapper(
(HttpServletRequest) request);

ContentCachingResponseWrapper wres =
new ContentCachingResponseWrapper(
(HttpServletResponse) response);

try {

// let it be ...
chain.doFilter(wreq, wres);

// makes sure that the input is read (e.g. in 404 it may not be)
while (wreq.getInputStream().read() >= 0);

System.out.printf("=== REQUEST%n%s%n=== end request%n",
new String(wreq.getContentAsByteArray()));

// Do whatever logging you wish here, in this case I'm writing request
// and response to system out which is probably not what you wish to do
System.out.printf("=== RESPONSE%n%s%n=== end response%n",
new String(wres.getContentAsByteArray()));

// this is specific of the "ContentCachingResponseWrapper" we are relying on,
// make sure you call it after you read the content from the response
wres.copyBodyToResponse();

// One more point, in case of redirect this will be called twice! beware to handle that
// somewhat

} catch (Throwable t) {
// Do whatever logging you whish here, too
// here you should also be logging the error!!!
throw t;
}

}
}

In order to log all the requests with input parameters and body, we can use **filters** and **interceptors**. But while using a filter or interceptor, we cannot print the request body multiple times.
The better way is we can use spring-AOP. By using this we can decouple the logging mechanism from the application. AOP can be used for logging **Input and output** of **each method** in the application.


My solution is:


import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import org.aspectj.lang.reflect.CodeSignature;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
import com.fasterxml.jackson.databind.ObjectMapper;
@Aspect
@Component
public class LoggingAdvice {
private static final Logger logger =
LoggerFactory.getLogger(LoggingAdvice.class);

//here we can provide any methodName, packageName, className
@Pointcut(value = "execution(* com.package.name.*.*.*(..) )")
public void myPointcut() {

}

@Around("myPointcut()")
public Object applicationLogger(ProceedingJoinPoint pjt) throws Throwable {
ObjectMapper mapper = new ObjectMapper();
String methodName = pjt.getSignature().getName();
String className = pjt.getTarget().getClass().toString();
String inputParams = this.getInputArgs(pjt ,mapper);
logger.info("method invoked from " + className + " : " + methodName + "--Request Payload::::"+inputParams);
Object object = pjt.proceed();
try {
logger.info("Response Object---" + mapper.writeValueAsString(object));
} catch (Exception e) {
}
return object;
}

private String getInputArgs(ProceedingJoinPoint pjt,ObjectMapper mapper) {
Object[] array = pjt.getArgs();
CodeSignature signature = (CodeSignature) pjt.getSignature();

StringBuilder sb = new StringBuilder();
sb.append("{");
int i = 0;
String[] parameterNames = signature.getParameterNames();
int maxArgs = parameterNames.length;
for (String name : signature.getParameterNames()) {
sb.append("[").append(name).append(":");
try {
sb.append(mapper.writeValueAsString(array[i])).append("]");
if(i != maxArgs -1 ) {
sb.append(",");
}
} catch (Exception e) {
sb.append("],");
}
i++;
}
return sb.append("}").toString();
}
}

Don't write any Interceptors, Filters, Components, Aspects, etc., this is a very common problem and has been solved many times over.

Spring Boot has a modules called [Actuator][1], which provides HTTP request logging out of the box. There's an endpoint mapped to `/trace` (SB1.x) or `/actuator/httptrace` (SB2.0+) which will show you last 100 HTTP requests. You can customize it to log each request, or write to a DB.

To get the endpoints you want, you'll need the spring-boot-starter-actuator dependency, and also to "whitelist" the endpoints you're looking for, and possibly setup or disable security for it.

Also, where will this application run? Will you be using a PaaS? Hosting providers, Heroku for example, provide request logging as part of their service and you don't need to do **any** coding whatsoever then.

[1]:

[To see links please register here]

If you have Spring boot Config server configured then just enable Debug logger for class :

`Http11InputBuffer.Http11InputBuffer.java`

Debugs will log all the requests and responses for every request