How to log all the request-responses in spring res

Question

The application should log the following information without impacting a client, asynchronously(in a separate thread).

• Request HTTP Method and URI
• Request Headers (Except the default)
• Client's IP Address
• Request Processing Time(In milliseconds)
• Request Body
• Response Body

If we consume inputstream in the filter, then it cant be consumed again by spring for json to object mapping. Somewhere during the input stream to object mapping, can we plug our logger?

Update:

We can write over logging code in a MessageConverter, but it doesnt seems to be a good idea.

public class MyMappingJackson2MessageConverter extends AbstractHttpMessageConverter<Object> {
    ...
    protected Object readInternal(Class<? extends Object> clazz, HttpInputMessage inputMessage)
            throws IOException, HttpMessageNotReadableException {
        InputStream inputStream = inputMessage.getBody();
        String requestBody = IOUtils.toString(inputStream, StandardCharsets.UTF_8);
        String method = request.getMethod();
        String uri = request.getRequestURI();
        LOGGER.debug("{} {}", method, uri);
        LOGGER.debug("{}", requestBody);
        return objectMapper.readValue(requestBody, clazz);
    }

    protected void writeInternal(Object o, HttpOutputMessage outputMessage)
            throws IOException, HttpMessageNotWritableException {
        String responseBody = objectMapper.writeValueAsString(o);
        LOGGER.debug("{}", responseBody);
        outputMessage.getBody().write(responseBody.getBytes(StandardCharsets.UTF_8));
    }
}

Answer 1

You can achieve this using spring aspect. It provides you some annotations like: @Before , @AfterReturning, @AfterThrowing etc. You may not don't need all endpoints log, so here have some filters based on package. Here are some examples:

For Request:

@Before("within(your.package.where.is.endpoint..*)")
    public void endpointBefore(JoinPoint p) {
        if (log.isTraceEnabled()) {
            log.trace(p.getTarget().getClass().getSimpleName() + " " + p.getSignature().getName() + " START");
            Object[] signatureArgs = p.getArgs();


            ObjectMapper mapper = new ObjectMapper();
            mapper.enable(SerializationFeature.INDENT_OUTPUT);
            try {

                if (signatureArgs[0] != null) {
                    log.trace("\nRequest object: \n" + mapper.writeValueAsString(signatureArgs[0]));
                }
            } catch (JsonProcessingException e) {
            }
        }
    }

here `@Before("within(your.package.where.is.endpoint..*)")` has the package path. All endpoints within this package will generate the log.

For Response:

@AfterReturning(value = ("within(your.package.where.is.endpoint..*)"),
            returning = "returnValue")
    public void endpointAfterReturning(JoinPoint p, Object returnValue) {
        if (log.isTraceEnabled()) {
            ObjectMapper mapper = new ObjectMapper();
            mapper.enable(SerializationFeature.INDENT_OUTPUT);
            try {
                log.trace("\nResponse object: \n" + mapper.writeValueAsString(returnValue));
            } catch (JsonProcessingException e) {
                System.out.println(e.getMessage());
            }
            log.trace(p.getTarget().getClass().getSimpleName() + " " + p.getSignature().getName() + " END");
        }
    }

here `@AfterReturning("within(your.package.where.is.endpoint..*)")` has the package path. All endpoints within this package will generate the log. Also Object returnValue has the response.

For Exception:

@AfterThrowing(pointcut = ("within(your.package.where.is.endpoint..*)"), throwing = "e")
public void endpointAfterThrowing(JoinPoint p, Exception e) throws DmoneyException {
    if (log.isTraceEnabled()) {
        System.out.println(e.getMessage());

        e.printStackTrace();


        log.error(p.getTarget().getClass().getSimpleName() + " " + p.getSignature().getName() + " " + e.getMessage());
    }
}
here `@AfterThrowing(pointcut = ("within(your.package.where.is.endpoint..*)"), throwing = "e")`  has the package path. All endpoints within this package will generate the log. Also Exception e has the error response.

Here is the full code:

import com.fasterxml.jackson.core.JsonProcessingException;
import com.fasterxml.jackson.databind.ObjectMapper;
import com.fasterxml.jackson.databind.SerializationFeature;
import org.apache.log4j.Logger;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.annotation.AfterReturning;
import org.aspectj.lang.annotation.AfterThrowing;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;

@Aspect
@Order(1)
@Component
//@ConditionalOnExpression("${endpoint.aspect.enabled:true}")
public class EndpointAspect {
    static Logger log = Logger.getLogger(EndpointAspect.class);

    @Before("within(your.package.where.is.endpoint..*)")
    public void endpointBefore(JoinPoint p) {
        if (log.isTraceEnabled()) {
            log.trace(p.getTarget().getClass().getSimpleName() + " " + p.getSignature().getName() + " START");
            Object[] signatureArgs = p.getArgs();


            ObjectMapper mapper = new ObjectMapper();
            mapper.enable(SerializationFeature.INDENT_OUTPUT);
            try {

                if (signatureArgs[0] != null) {
                    log.trace("\nRequest object: \n" + mapper.writeValueAsString(signatureArgs[0]));
                }
            } catch (JsonProcessingException e) {
            }
        }
    }

    @AfterReturning(value = ("within(your.package.where.is.endpoint..*)"),
            returning = "returnValue")
    public void endpointAfterReturning(JoinPoint p, Object returnValue) {
        if (log.isTraceEnabled()) {
            ObjectMapper mapper = new ObjectMapper();
            mapper.enable(SerializationFeature.INDENT_OUTPUT);
            try {
                log.trace("\nResponse object: \n" + mapper.writeValueAsString(returnValue));
            } catch (JsonProcessingException e) {
                System.out.println(e.getMessage());
            }
            log.trace(p.getTarget().getClass().getSimpleName() + " " + p.getSignature().getName() + " END");
        }
    }


    @AfterThrowing(pointcut = ("within(your.package.where.is.endpoint..*)"), throwing = "e")
    public void endpointAfterThrowing(JoinPoint p, Exception e) throws Exception {
        if (log.isTraceEnabled()) {
            System.out.println(e.getMessage());

            e.printStackTrace();


            log.error(p.getTarget().getClass().getSimpleName() + " " + p.getSignature().getName() + " " + e.getMessage());
        }
    }
}

More info about AOP visit here:

Spring docks about AOP

Sample article about AOP

Answer 2

I would use 2 elements: A LoggingFilter and the Async support from Spring. For the first one, I would use a CommonsRequestLoggingFilter that already knows how to intercept the HTTP requests, create the configuration for that and the Async. You can do something like:

First Enable Async Support

@Configuration
@EnableAsync
public class SpringAsyncConfig { ... }

Then Create the loggingFilter:

public class LoggingFilter extends CommonsRequestLoggingFilter {

@Override
protected void beforeRequest(final HttpServletRequest request, final String message) {
    // DO something
    myAsyncMethodRequest(request, message)
}

@Override
protected void afterRequest(final HttpServletRequest request, final String message) {
    // Do something
   myAsyncMethodResponse(request, message)
}

// -----------------------------------------
// Async Methods
// -----------------------------------------

   @Async
   protected void myAsyncMethodRequest(HttpServletRequest request, String message) {

    // Do your thing
    // You can use message that has a raw message from the properties
   // defined in the logFilter() method. 
   // Also you can extract it from the HttpServletRequest using: 
   // IOUtils.toString(request.getReader());

   }

   @Async
   protected void myAsyncMethodResponse(HttpServletRequest request, String message) {

    // Do your thing
   }

}

Then create a custom logging configuration for the filter that you created:

@Configuration
public class LoggingConfiguration {

    @Bean
    public LoggingConfiguration logFilter() {
        LoggingFilter filter
                = new LoggingFilter();
        filter.setIncludeQueryString(true);
        filter.setIncludePayload(true);
        filter.setIncludeHeaders(true);

        return filter;
    }
}

To extract the data from the request you can use the message parameter or process the HttpServletRequest. Take as an example:

• https://eureka.ykyuen.info/2009/09/27/java-get-the-content-of-inputstream-from-httpservletrequest/
• Get the POST request body from HttpServletRequest

Answer 3

An answer from baeldung.com :

Spring provides a built-in solution to log payloads. We can use ready-made filters by plugging into Spring application using configuration. AbstractRequestLoggingFilter is a filter which provides basic functions of logging. Subclasses should override the beforeRequest() and afterRequest() methods to perform the actual logging around the request. Spring framework provides following concrete implementation classes which can be used to log the incoming request. These are:

• CommonsRequestLoggingFilter
• ServletContextRequestLoggingFilter

Spring Boot application can be configured by adding a bean definition to enable request logging:

@Configuration
public class RequestLoggingFilterConfig {

    @Bean
    public CommonsRequestLoggingFilter logFilter() {
        CommonsRequestLoggingFilter filter
          = new CommonsRequestLoggingFilter();
        filter.setIncludeQueryString(true);
        filter.setIncludePayload(true);
        filter.setMaxPayloadLength(10000);
        filter.setIncludeHeaders(false);
        filter.setAfterMessagePrefix("REQUEST DATA : ");
        return filter;
    }
}

Also, this logging filter requires the log level be set to DEBUG. In application.properties put

logging.level.org.springframework.web.filter.CommonsRequestLoggingFilter=DEBUG

To make the logging asynchronous, we may use asynchronous appenders. Unfortunately it does not support logging response payloads. :(

Answer 4

I guess your best option is to do the logging in an Async Method.

@Async
public void asyncMethodWithVoidReturnType() {
  System.out.println("Execute method asynchronously. "
    + Thread.currentThread().getName());
}

Please refer to:

Async

How to Async