The Spring Framework (and its portfolio projects) contain a lot of functionality already by themselves. However there are also some nice hidden gems inside the framework, in this blog I will (un)cover a couple of them. The code for the sample(s) can be found on Github.

Log incoming Requests

A lot of projects I worked on wanted, for debugging purpose, log the incoming requests. Sadly I also saw a lot of homegrown solutions for this (although not necessarily a bad thing). The Spring Framework has a nice servlet filter which already provides this functionality out-of-the-box. The AbstractRequestLoggingFilter provides 3 concrete implementations, one for Commons Logging, one for Log4J and 1 that uses the servlet context for logging.

Using Spring Boot the following bean definition will enable request logging, it will include the information from the client (always the IP Address and optional the session id and username), the query string and the posted payload (if any is available).

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

To enable logging the log level for org.springframework.web.filter.CommonsRequestLoggingFilter must be set to DEBUG, this can be done using the application.properties by adding:

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

When a request comes in the following lines will be available in the logging.

2015-06-30 08:52:44.581 DEBUG 66103 --- [nio-8080-exec-3] o.s.w.f.CommonsRequestLoggingFilter : Before request [uri=/hello-world?name=World;client=0:0:0:0:0:0:0:1]
2015-06-30 08:52:44.584 DEBUG 66103 --- [nio-8080-exec-3] o.s.w.f.CommonsRequestLoggingFilter : After request [uri=/hello-world?name=World;client=0:0:0:0:0:0:0:1]

Logging method invocations

At times you might want to log the different method invocation, including method arguments and/or return values or errors. Spring has a very customizable interceptor for this, which is conveniently named CustomizableTraceInterceptor. As the interceptor is pretty old, it exists since Spring 1.2, you need to do some additional configuration to get it to work.

First configure the interceptor

@Bean
public CustomizableTraceInterceptor customizableTraceInterceptor() {
    CustomizableTraceInterceptor cti = new CustomizableTraceInterceptor();
    return cti;
}

Next configure an Advisor so that it can be applied when enabling AOP.

@Bean
public Advisor traceAdvisor() {
    AspectJExpressionPointcut pointcut = new AspectJExpressionPointcut();
    pointcut.setExpression("execution(public * biz.deinum..*.*(..))");
    return new DefaultPointcutAdvisor(pointcut, customizableTraceInterceptor());
}

This advisor basically says intercept all public methods to classes in the biz.deinum package and all sub-packages. We also need to enable class based proxies, as we also want to intercept calls to the HelloWorldController which doesn’t implement an interface. To enable this add the following to the application.properties.

spring.aop.proxy-target-class=true

One last step is to enable TRACE logging for the interceptor else nothing will be logged, again this is as easy as adding an entry to the application.properties again.

logging.level.org.springframework.aop.interceptor.CustomizableTraceInterceptor=TRACE

Now when restarting the application and issuing a request the following lines are added to the logging.

2015-06-30 09:13:33.577 TRACE 66322 --- [nio-8080-exec-1] o.s.a.i.CustomizableTraceInterceptor     : Entering method 'sayHello' of class [biz.deinum.gems.web.HelloWorldController]
2015-06-30 09:13:33.583 TRACE 66322 --- [nio-8080-exec-1] o.s.a.i.CustomizableTraceInterceptor     : Entering method 'greet' of class [biz.deinum.gems.SimpleHelloWorldService]
2015-06-30 09:13:33.588 TRACE 66322 --- [nio-8080-exec-1] o.s.a.i.CustomizableTraceInterceptor     : Exiting method 'greet' of class [biz.deinum.gems.SimpleHelloWorldService]
2015-06-30 09:13:33.589 TRACE 66322 --- [nio-8080-exec-1] o.s.a.i.CustomizableTraceInterceptor     : Exiting method 'sayHello' of class [biz.deinum.gems.web.HelloWorldController]

Although this tells you when a method is entered and left it doesn’t include the method arguments or performance metrics. For this we need to configure the enter and exit message for the CustomizableTraceInterceptor.

@Bean
public CustomizableTraceInterceptor customizableTraceInterceptor() {
    CustomizableTraceInterceptor cti = new CustomizableTraceInterceptor();
    cti.setEnterMessage("Entering method '" + PLACEHOLDER_METHOD_NAME + "("+ PLACEHOLDER_ARGUMENTS+")' of class [" + PLACEHOLDER_TARGET_CLASS_NAME + "]");
    cti.setExitMessage("Exiting method '" + PLACEHOLDER_METHOD_NAME + "' of class [" + PLACEHOLDER_TARGET_CLASS_NAME + "] took " + PLACEHOLDER_INVOCATION_TIME+"ms.");
    return cti;
}

Now when restarted the value of the method arguments is included as well as the time it took to execute the method.

2015-06-30 09:21:55.595 TRACE 66368 --- [nio-8080-exec-1] o.s.a.i.CustomizableTraceInterceptor     : Entering method 'sayHello(World)' of class [biz.deinum.gems.web.HelloWorldController]
2015-06-30 09:21:55.602 TRACE 66368 --- [nio-8080-exec-1] o.s.a.i.CustomizableTraceInterceptor     : Entering method 'greet(World)' of class [biz.deinum.gems.SimpleHelloWorldService]
2015-06-30 09:21:55.608 TRACE 66368 --- [nio-8080-exec-1] o.s.a.i.CustomizableTraceInterceptor     : Exiting method 'greet' of class [biz.deinum.gems.SimpleHelloWorldService] took 6ms.
2015-06-30 09:21:55.608 TRACE 66368 --- [nio-8080-exec-1] o.s.a.i.CustomizableTraceInterceptor     : Exiting method 'sayHello' of class [biz.deinum.gems.web.HelloWorldController] took 13ms.

Performance Logging

Although you can use the CustomizableTraceInterceptor to log performance you might want to have a bit more information regarding your performance logging. There are various solution out there one of them is JAMon and Spring provides the convenient JamonPerformanceMonitorInterceptor to intregrate with this.

First add the JamonPerformanceMonitorInterceptor as a bean

@Bean
public JamonPerformanceMonitorInterceptor jamonPerformanceMonitorInterceptor() {
    return new JamonPerformanceMonitorInterceptor();
}

Next add the point cut expression to assure that the interceptor is executed when a method is executed.

@Bean
public Advisor performanceAdvisor() {
    AspectJExpressionPointcut pointcut = new AspectJExpressionPointcut();
    pointcut.setExpression("execution(public * biz.deinum..*.*(..))");
    return new DefaultPointcutAdvisor(pointcut, jamonPerformanceMonitorInterceptor());
}

The final step is to enable the logger by setting the log level for this class to TRACE.

logging.level.org.springframework.aop.interceptor.JamonPerformanceMonitorInterceptor=TRACE

Now when the application is restart again the following lines will appear in the logs.

2015-06-30 09:43:01.748 TRACE 66496 --- [nio-8080-exec-7] s.a.i.JamonPerformanceMonitorInterceptor : JAMon performance statistics for method [biz.deinum.gems.web.HelloWorldController.sayHello]:
JAMon Label=biz.deinum.gems.web.HelloWorldController.sayHello, Units=ms.: (LastValue=0.0, Hits=4.0, Avg=3.5, Total=14.0, Min=0.0, Max=13.0, Active=0.0, Avg Active=1.0, Max Active=1.0, First Access=Tue Jun 30 09:42:52 CEST 2015, Last Access=Tue Jun 30 09:43:01 CEST 2015)

Note: JAMon itself has more in-depth support for performance logging (also for web requests, JDBC etc.) you might want to check out.

Expose Hibernate SessionFactory when using JPA

When in the proces of migrating a classic Hibernate based application to JPA (or simply needing a SessionFactory) you might need both an EntityManagerFactory and SessionFactory in the same application. You can configure both beans and try to get it to work with 2 different PlatformTransactionManagers but it can be done easier. Spring provides the HibernateJpaSessionFactoryBean to expose the underlying SessionFactory from the EntityManagerFactory.

To configure the bean simply add it to the configuration

@Bean
public HibernateJpaSessionFactoryBean sessionFactory(EntityManagerFactory emf) {
    HibernateJpaSessionFactoryBean jssfb = new HibernateJpaSessionFactoryBean();
    jssfb.setEntityManagerFactory(emf);
    return jssfb;
}

And now you can use the underlying SessionFactory to get access to a plain Session.

WebUtils and ServletRequestUtils

When writing controller classes or otherwise working with the HttpServletRequest or HttpSession can be cumbersome, especially when doing type conversion or null checks for the existence of the HttpSession for instance. The WebUtils and [ServletRequestUtils](http://docs.spring.io/spring-framework/docs/current/javadoc-api/org/springframework/web/bind/ServletRequestUtils.html) classes have some nice helper methods to ease working with the session and request attributes respectively.

When needing an attribute from the session you often do request.getSession(false) and check if the session is null. Code like this is not uncommon to see:

        HttpSession session = request.getSession(false);
        if (session != null) {
            String foo = session.getAttribute("foo");
        }

When using the WebUtils this can be reduced to a oneliner.

String foo = WebUtils.getSessionAttribute(request, "foo");

When the property is required you can use the getRequiredSessionAttribute method, which in case of a missing attribute throws an exception.

When using a (Http)ServletRequest sometimes you need to get a parameter of the request and sometimes need to convert it to a different type. (Although I would recommend using @RequestParam in your method signature for that). You can use the ServletRequestUtils to make that easier.

        String name = request.getParameter("name");
        if (name == null) {
            name = "Stranger";
        }

When using the helper methods from ServletRequestUtils this becomes:

String name = ServletRequestUtils.getStringParameter(request, "name", "Stranger");

If the parameter is required you can use the getRequiredStringParameter. Next to getting a text based parameter it can also help with converting to a different type.

        String val = request.getParameter("someId");
        long id = val == null ? -1L : Long.valueOf(val);

With the helper methods.

long id=ServletRequestUtils.getLongParameter(request, "someId", -1L);

Note: Although it makes your code easier it also makes your code (more) dependent on Spring, you have to consider for yourself if this is a bad thing or not. The WebUtils and ServletRequestUtils will be mainly used in controllers which are generally already using Spring interfaces or annotations.