Monday, 3 February 2014

Optimising Your ApplicationContext

There’s a problem with Spring, it’s been there for some time and I’ve come across it in a number of projects. It’s nothing to do with Spring, or the Guys at Spring, it’s down to Spring’s users like you and me. Let me explain… In the old days of Spring 2 you had to configure your Application Context by hand, manually creating an XML configuration file that contained all your bean definitions. The down side of this technique was that it was time-consuming to create these XML files and then, you had the headache of maintaining this increasingly complex file. I seem to remember that at the time, it was known as “Spring Config Hell”. On the upside, at least you had a central record of everything that was loaded into the context. Bowing to demand and the popular notion that annotations were the way to go, Spring 3 introduced a whole raft of stereotyping classes such as @Service, @Component, @Controller and @Repository together with an addition to the XML configuration file of the <context:component-scan/> element. This made, from a programming point of view, things a lot simpler and is a hugely popular way of constructing Spring contexts.

There is, however, a downside to using Spring annotations with wild abandon and peppering everything with @Service, @Component, @Controller or @Repository that becomes especially troublesome in large codebases. The problem is that your context becomes polluted with stuff that just doesn’t need to be there and that’s a problem because:
  • You unnecessarily use up your perm gen space leading to the risk of more “out of perm gen space errors”.
  • You unnecessarily use up your heap space.
  • Your application can take a lot longer to load.
  • Unwanted objects can “just do stuff”, especially if they’re multithreaded, have a start() method or implement InitializingBean.
  • Unwanted objects can just stop your application from working…
In small applications I guess that it doesn’t really matter if you have a couple of extra objects in your Spring context, but, as I said above, this can be particularly troublesome if your application is large, processor intensive or memory hungry. At this point it’s worth sorting this situation out and to do this you have to first figure out exactly what it is you’re loading into your Spring context.

One way of doing this is just to enable debugging on the com.springsource package by adding something like the following to your log4j properties:

log4j.logger.com.springsource=DEBUG

In adding the above to your log4j properties (log4j 1.x in this case) you’ll get lots of information on your Spring context - and I mean lots. This is really only something you’d need to do if you’re one of the Guys at Spring and you’re working on the Spring source code.

Another more succinct approach is to add a class to your application that’ll report exactly what’s being loaded into your Spring context. You can then examine the report and make any appropriate changes.

This blog’s sample code consists of one class and it’s something that I’ve written two or three times before, working on different projects for different companies. It relies on a couple of Spring features; namely that Spring can call a method in your class after the Context has loaded and that Spring’s ApplicationContext interface contains a few methods that’ll tell you all about its internals.

@Service
public class ApplicationContextReport implements ApplicationContextAware, InitializingBean {

 
private static final String LINE = "====================================================================================================\n";
 
private static final Logger logger = LoggerFactory.getLogger("ContextReport");

 
private ApplicationContext applicationContext;

 
@Override
 
public void setApplicationContext(ApplicationContext applicationContext) throws BeansException {
   
this.applicationContext = applicationContext;
 
}

 
@Override
 
public void afterPropertiesSet() throws Exception {
   
report();
 
}

 
public void report() {

   
StringBuilder sb = new StringBuilder("\n" + LINE);
    sb.append
("Application Context Report\n");
    sb.append
(LINE);

    createHeader
(sb);
    createBody
(sb);
    sb.append
(LINE);

    logger.info
(sb.toString());
 
}

 
private void createHeader(StringBuilder sb) {

   
addField(sb, "Application Name: ", applicationContext.getApplicationName());
    addField
(sb, "Display Name: ", applicationContext.getDisplayName());

    String startupDate = getStartupDate
(applicationContext.getStartupDate());
    addField
(sb, "Start Date: ", startupDate);

    Environment env = applicationContext.getEnvironment
();
    String
[] activeProfiles = env.getActiveProfiles();
   
if (activeProfiles.length > 0) {
     
addField(sb, "Active Profiles: ", activeProfiles);
   
}
  }

 
private void addField(StringBuilder sb, String name, String... values) {

   
sb.append(name);
   
for (String val : values) {
     
sb.append(val);
      sb.append
(", ");
   
}
   
sb.setLength(sb.length() - 2);
    sb.append
("\n");
 
}

 
private String getStartupDate(long startupDate) {

   
SimpleDateFormat df = new SimpleDateFormat("yyyy-MM-dd'T'HH:mm:ss.SSSZ");
   
return df.format(new Date(startupDate));
 
}

 
private void createBody(StringBuilder sb) {
   
addColumnHeaders(sb);
    addColumnValues
(sb);
 
}

 
private void addColumnHeaders(StringBuilder sb) {
   
sb.append("\nBean Name\tSimple Name\tSingleton\tFull Class Name\n");
    sb.append
(LINE);
 
}

 
private void addColumnValues(StringBuilder sb) {
   
String[] beanNames = applicationContext.getBeanDefinitionNames();

   
for (String name : beanNames) {
     
addRow(name, sb);
   
}
  }

 
private void addRow(String name, StringBuilder sb) {
   
Object obj = applicationContext.getBean(name);

    String fullClassName = obj.getClass
().getName();
   
if (!fullClassName.contains("org.springframework")) {

     
sb.append(name);
      sb.append
("\t");
      String simpleName = obj.getClass
().getSimpleName();
      sb.append
(simpleName);
      sb.append
("\t");
     
boolean singleton = applicationContext.isSingleton(name);
      sb.append
(singleton ? "YES" : "NO");
      sb.append
("\t");
      sb.append
(fullClassName);
      sb.append
("\n");
   
}
  }
}

The first thing to note is that this version of the code implements Spring’s InitializingBean interface. Spring will check for this this interface when it loads a class in to the context. If it finds it then it’ll call the AfterPropertiesSet() method.

This is not the only way of getting Spring to call your class on start up, see: Three Spring Bean Lifecycle Techniques and Using JSR-250’s @PostConstruct Annotation to Replace Spring's InitializingBean

The next thing to note is that this report class implements Spring’s ApplicationContextAware interface. This is another useful Spring workhorse interface that’ll never normally need to use on a daily basis. The raison d’ĂȘtre behind this interface is to give your class access to your application’s ApplicationContext. It contains a single method: setApplicationContext(...), which is called by Spring to inject the ApplicationContext into your class. In this case, I’m simply saving the ApplicationContext argument as an instance variable.

The main report generation is done by the report() method (called by afterPropertiesSet()). All the report() method does is to create a StringBuilder() class and then append lots of information. I won’t go through each line individually as this kind of code is rather linear and really boring. The highlight comes in the form of the addColumnValues(...) method called by createBody(...).

  private void addColumnValues(StringBuilder sb) {
   
String[] beanNames = applicationContext.getBeanDefinitionNames();

   
for (String name : beanNames) {
     
addRow(name, sb);
   
}
  }

This method calls applicationContext.getBeanDefinitionNames() to get hold of an array containing the names of all the beans loaded by this context. Once I have this information I loop through the array calling applicationContext.getBean(...) on each bean name. Once you have the bean itself, you can add its class details to the StringBuilder as a row in the report.

Having created the report there’s not much point mucking about writing your own file handling code that’ll save the contents of the StringBuilder to disk. This sort of code has been written many times before. In this case I’ve chosen to leverage Log4j (via slf4j) by adding a this logger line to the Java code above:

  private static final Logger logger = LoggerFactory.getLogger("ContextReport");

...and by adding the following to my log4j XML config file:

<appender name="fileAppender" class="org.apache.log4j.RollingFileAppender">
      <param name="Threshold" value="INFO" />
      <param name="File" value="/tmp/report.log"/>
      <layout class="org.apache.log4j.PatternLayout">
         <param name="ConversionPattern" value="%d %-5p  [%c{1}] %m %n" />
      </layout>
   </appender>

    <logger name="ContextReport" additivity="false">
  <level value="info"/>    
       <appender-ref ref="fileAppender"/>
    </logger>

Note that if you’re using log4j 2.x, the XML would be different, but that's beyond the scope of this blog.

The thing to note here is that I use a RollingFileAppender, which writes a file to /tmp called report.log - though this file could obviously be located anywhere.

The other config point to notice is the ContextReport Logger. This directs all its log output to the fileAppender and, because of the additivity="false" attribute, only the fileAppender and no where else.

The only other chunk of config to remember is to add the report package to Spring’s component-scan element so that Spring will detect the @Service annotation and load the class.

<context:component-scan base-package="com.captaindebug.report" />

To prove that it works, I’ve also created a JUnit test case as shown below:

@RunWith(SpringJUnit4ClassRunner.class)
@WebAppConfiguration
@ContextConfiguration
({ "file:src/main/webapp/WEB-INF/spring/appServlet/servlet-context.xml" })
public class ApplicationContextReportTest {

 
@Autowired
 
private ApplicationContextReport instance;

 
@Test
 
public void testReport() {

   
System.out.println("The report should now be in /tmp");
 
}

}

This uses the SpringJUnit4ClassRunner and the @ContextConfiguration annotation to load the application’s live servlet-context.xml file. I’ve also included the @WebAppConfiguration annotation to tell Spring that this is a web app.

If you run the JUnit test you’ll get a report.log that contains something like this:

2014-01-26 18:30:25,920 INFO   [ContextReport]
====================================================================================================
Application Context Report
====================================================================================================
Application Name:
Display Name: org.springframework.web.context.support.GenericWebApplicationContext@74607cd0
Start Date: 2014-01-26T18:30:23.552+0000

Bean Name       Simple Name     Singleton       Full Class Name
====================================================================================================
deferredMatchUpdateController   DeferredMatchUpdateController   YES     com.captaindebug.longpoll.DeferredMatchUpdateController
homeController  HomeController  YES     com.captaindebug.longpoll.HomeController
DeferredService DeferredResultService   YES     com.captaindebug.longpoll.service.DeferredResultService
SimpleService   SimpleMatchUpdateService        YES     com.captaindebug.longpoll.service.SimpleMatchUpdateService
shutdownService ShutdownService YES     com.captaindebug.longpoll.shutdown.ShutdownService
simpleMatchUpdateController     SimpleMatchUpdateController     YES     com.captaindebug.longpoll.SimpleMatchUpdateController
applicationContextReport        ApplicationContextReport        YES     com.captaindebug.report.ApplicationContextReport
the-match       Match   YES     com.captaindebug.longpoll.source.Match
theQueue        LinkedBlockingQueue     YES     java.util.concurrent.LinkedBlockingQueue
BillSykes       MatchReporter   YES     com.captaindebug.longpoll.source.MatchReporter
====================================================================================================

The report contains a header that contains info such as Display Name and Start Date followed by the main body. The body is a tab separated table that contains the following columns: the bean name, the simple class name, whether or not the bean is a singleton or prototype and the full class name.

You can now use this report to spot classes that you don’t want loaded into your Spring Context. For example, if you decided that you didn’t want to load the BillSykes instance of com.captaindebug.longpoll.source.MatchReporter, then you have the following options.

Firstly, it’s probably the case that the BillSykes bean has loaded because it in the wrong package. This usually happens when you try to organise project structures along class type lines, for example putting all services together in a service package and all controllers together in a controller package; hence, including the service module into your application will load ALL service classes, even the ones you don’t need and that could cause you problems. It’s usually better to organise along functional lines as described in How Do You Organise Maven Sub-Modules?.

Unfortunately, reorganising your entire project is particularly costly and will not yield much revenue. The other, cheaper way of solving the problem is to make adjustments to the Spring context:component-scan Element and to exclude those classes that are causing problems.

<context:component-scan base-package="com.captaindebug.longpoll" />
        <context:exclude-filter type="regex" expression="com\.captaindebug\.longpoll\.source\.MatchReporter"/>
    </context:component-scan>

…or all classes from any given package:

<context:component-scan base-package="com.captaindebug.longpoll" />
        <context:exclude-filter type="regex" expression="com\.captaindebug\.longpoll\.source\..*"/>
    </context:component-scan>

Using exclude-filter is a useful technique, but there’s a lot been written about it together with its counterpart: include-filter and so a full explanation of this XML config is beyond the scope of this blog though, maybe I'll cover it at a later date.


The code for this blog is available on GitHub as part of the long poll project at: https://github.com/roghughe/captaindebug/tree/master/long-poll


1 comment:

Oliver Jones said...


Hi, just wanted to tell you, I enjoyed this article. It was funny. Keep on posting! sign in to gmail