Logging response body (HTML) from HttpServletResponse using Spring MVC HandlerInterceptorAdapter

Question

I am trying to log (just to console write now for simplicity sake) the final rendered HTML that will be returned by the HttpServletResponse. (i.e. the body) To this end, I am using the HandlerInterceptorAdapter from Spring MVC like so:

public class VxmlResponseInterceptor extends HandlerInterceptorAdapter {
    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {
        System.out.println(response.toString());
    }
}

This works as expected and I see the HTTP response headers in the console. My question is if there is a relatively simple way to log the entire response body (i.e. final rendered HTML) to the console without having to resort to doing jumping jacks with PrintWriters, OutputStream's and the like.

Thanks in advance.

Answer 1

This would be better done using a Servlet Filter rather than a Spring HandlerInterceptor, for the reason that a Filter is allowed to substitute the request and/or response objects, and you could use this mechanism to substitute the response with a wrapper which logs the response output.

This would involve writing a subclass of HttpServletResponseWrapper, overriding getOutputStream (and possibly also getWriter()). These methods would return OutputStream/PrintWriter implementations that siphon off the response stream into a log, in addition to sending to its original destination. An easy way to do this is using TeeOutputStream from Apache Commons IO, but it's not hard to implement yourself.

Here's an example of the sort of thing you could do, making use of Spring's GenericFilterBean and DelegatingServletResponseStream, as well as TeeOutputStream, to make things easier:

public class ResponseLoggingFilter extends GenericFilterBean {

   @Override
   public void doFilter(ServletRequest request, ServletResponse response, FilterChain filterChain) throws IOException, ServletException {
      HttpServletResponse responseWrapper = loggingResponseWrapper((HttpServletResponse) response);     
      filterChain.doFilter(request, responseWrapper);
   }

   private HttpServletResponse loggingResponseWrapper(HttpServletResponse response) {
      return new HttpServletResponseWrapper(response) {
         @Override
         public ServletOutputStream getOutputStream() throws IOException {
            return new DelegatingServletOutputStream(
               new TeeOutputStream(super.getOutputStream(), loggingOutputStream())
            );
         }
      };
   }

   private OutputStream loggingOutputStream() {
      return System.out;
   }
}

This logs everything to STDOUT. If you want to log to a file, it'll get a big more complex, what with making sure the streams get closed and so on, but the principle remains the same.

Answer 2

If you're using (or considering) logback as your logging framework, there is a nice servlet filter already available that does exactly that. Checkout the TeeFilter chapter in the documentation.

Answer 3

I've been looking for a way to log full HTTP Request/Response for a while and discovered it has been solved for me in the Tomcat 7 RequestDumperFilter. It works as advertised from a Tomcat 7 container. If you want to use it in Jetty, the class works fine stand-alone or, as I did, copied and adapted to the specific needs of my environment.

Answer 4

I made a small library spring-mvc-logger available via maven central.

Add to pom.xml:

<dependency>
    <groupId>com.github.isrsal</groupId>
    <artifactId>spring-mvc-logger</artifactId>
    <version>0.2</version>
</dependency>

Add to web.xml:

<filter>
    <filter-name>loggingFilter</filter-name>
    <filter-class>com.github.isrsal.logging.LoggingFilter</filter-class>
</filter>

<filter-mapping>
    <filter-name>loggingFilter</filter-name>
    <url-pattern>/*</url-pattern>
</filter-mapping>

Add to log4j.xml:

<logger name="com.github.isrsal.logging.LoggingFilter">
    <level value="DEBUG"/>
</logger>

Answer 5

the code pasted below works with my tests and can be downloaded from my github project, 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;
        }

    }
}