Spring – Log Incoming Requests

1. Introduction

In this quick tutorial, we’re going to show the basics of logging incoming requests using Spring’s logging filter. If you’re just getting started with logging, check out this logging intro article, as well as the SLF4J article.

2. Maven Dependencies

The logging dependencies will simply be the same as the ones in the intro article; let’s simply add Spring here:

<dependency>
    <groupId>org.springframework</groupId>
    <artifactId>spring-core</artifactId>
    <version>5.0.5.RELEASE</version>
</dependency>

The latest version can be found here for spring-core.

3. Basic Web Controller

First of all, let’s define a controller which will be used in our example:

@RestController
public class TaxiFareController {

    @GetMapping("/taxifare/get/")
    public RateCard getTaxiFare() {
        return new RateCard();
    }

    @PostMapping("/taxifare/calculate/")
    public String calculateTaxiFare(
      @RequestBody @Valid TaxiRide taxiRide) {

        // return the calculated fare
    }
}

4. Custom Request Logging

Spring provides a mechanism for configuring user-defined interceptors to perform actions before and after web requests.

Among the Spring request interceptors, one of the noteworthy interfaces is HandlerInterceptor, which can be used to log the incoming request by implementing the following methods:

  1. preHandle() – this method is executed before the actual controller service method

  2. afterCompletion() – this method is executed after the controller is ready to send the response

Furthermore, Spring provides the default implementation of HandlerInterceptor interface in the form of HandlerInterceptorAdaptor class which can be extended by the user.

Let’s create our own interceptor – by extending HandlerInterceptorAdaptor as:

@Component
public class TaxiFareRequestInterceptor
  extends HandlerInterceptorAdapter {

    @Override
    public boolean preHandle(
      HttpServletRequest request,
      HttpServletResponse response,
      Object handler) {
        return true;
    }

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

Finally, we’ll configure the TaxiRideRequestInterceptor inside MVC lifecycle to capture pre and post-processing of controller method invocations which are mapped to path /taxifare defined in TaxiFareController class.

@Configuration
public class TaxiFareMVCConfig implements WebMvcConfigurer {

    @Autowired
    private TaxiFareRequestInterceptor taxiFareRequestInterceptor;

    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        registry.addInterceptor(taxiFareRequestInterceptor)
          .addPathPatterns("/**/taxifare/**/");
    }
}

In conclusion, the WebMvcConfigurer adds the TaxiFareRequestInterceptor inside spring MVC lifecycle by invoking addInterceptors() method.

The biggest challenge is to get the copies of request and response payload for logging and still leave the requested payload for the servlet to process it.

The main issue with the reading request is that, as soon as the input stream is read for the first time, it’s marked as consumed and cannot be read again.

The application will throw an exception after reading the request stream:

{
  "timestamp": 1500645243383,
  "status": 400,
  "error": "Bad Request",
  "exception": "org.springframework.http.converter
    .HttpMessageNotReadableException",
  "message": "Could not read document: Stream closed;
    nested exception is java.io.IOException: Stream closed",
  "path": "/rest-log/taxifare/calculate/"
}

To overcome this problem, we can leverage caching to store the request stream and use it for logging.

Spring provides few useful classes such as ContentCachingRequestWrapper and ContentCachingResponseWrapper which can be used for caching the request data for logging purpose.

Let’s adjust our preHandle() of TaxiRideRequestInterceptor class to cache the request object using ContentCachingRequestWrapper class.

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

    HttpServletRequest requestCacheWrapperObject
      = new ContentCachingRequestWrapper(request);
    requestCacheWrapperObject.getParameterMap();
    // Read inputStream from requestCacheWrapperObject and log it
    return true;
}

As we can see, we have cached the request object using ContentCachingRequestWrapper class which can be used to read the payload data for logging without disturbing the actual request object:

requestCacheWrapperObject.getContentAsByteArray();

Limitation

  • ContentCachingRequestWrapper class only supports the following:

Content-Type:application/x-www-form-urlencoded
Method-Type:POST

  • We must invoke the following method to ensure that request data is cached in ContentCachingRequestWrapper before using it:

requestCacheWrapperObject.getParameterMap();

5. Spring Built-In Request Logging

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 three concrete implementation classes which can be used to log the incoming request. These three classes are:

  • CommonsRequestLoggingFilter

  • Log4jNestedDiagnosticContextFilter (deprecated)

  • ServletContextRequestLoggingFilter

Now, let’s move on to the CommonsRequestLoggingFilter and configure it to capture incoming request for logging.

5.1. Configure Spring Boot Application

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. We can enable the DEBUG mode by adding the below element in logback.xml:

<logger name="org.springframework.web.filter.CommonsRequestLoggingFilter">
    <level value="DEBUG" />
</logger>

Another way of enabling the DEBUG level log is to add the following in application.properties:

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

5.2. Configure Traditional Web Application

In the standard Spring web application, Filter can be set via either XML configuration or Java configuration. Let’s set up the CommonsRequestLoggingFilter using conventional Java based configuration.

As we know, the includePayload attribute of CommonsRequestLoggingFilter is set to false by default. We would need a custom class to override the value of the attribute to enable includePayload before injecting into the container using Java configuration:

public class CustomeRequestLoggingFilter
  extends CommonsRequestLoggingFilter {

    public CustomeRequestLoggingFilter() {
        super.setIncludeQueryString(true);
        super.setIncludePayload(true);
        super.setMaxPayloadLength(10000);
    }
}

Now, we need to inject the CustomeRequestLoggingFilter using Java based web initializer:

public class CustomWebAppInitializer implements
  WebApplicationInitializer {
    public void onStartup(ServletContext container) {

        AnnotationConfigWebApplicationContext context
          = new AnnotationConfigWebApplicationContext();
    context.setConfigLocation("com.baeldung");
    container.addListener(new ContextLoaderListener(context));

    ServletRegistration.Dynamic dispatcher
          = container.addServlet("dispatcher",
          new DispatcherServlet(context));
    dispatcher.setLoadOnStartup(1);
    dispatcher.addMapping("/");

    container.addFilter("customRequestLoggingFilter",
          CustomeRequestLoggingFilter.class)
          .addMappingForServletNames(null, false, "dispatcher");
    }
}

6. Example in Action

Now, we can wire up a Spring Boot with context and see in action that logging of incoming requests works as expected:

@Test
public void givenRequest_whenFetchTaxiFareRateCard_thanOK() {
    TestRestTemplate testRestTemplate = new TestRestTemplate();
    TaxiRide taxiRide = new TaxiRide(true, 10l);
    String fare = testRestTemplate.postForObject(
      URL + "calculate/",
      taxiRide, String.class);

    assertThat(fare, equalTo("200"));
}

7. Conclusion

In this article, we showed how to implement basic web request logging using interceptors; we also showed the limitations and challenges of this solution.

Then we showed the built-in filter class which provides ready to use and simple logging mechanism.

As always, the implementation of the example and code snippets are available over on GitHub.

Leave a Reply

Your email address will not be published.