Monthly Archives: March 2009

Spring, Portlets and Annotation Configuration

Posted on by

There’s one thing that is easy to miss when setting up a Portlet using Spring MVC and Annotation configuration, and that is the correct placement of the <context:annotation-config /> elements. In the examples that I found, the element is only located in the applicationContext.xml file, unfortunately this doesn’t always work as you might expect.

In Spring MVC Portlets, the applicationContext file is used to define beans that should be available to all the portlets in that portlet application (or WAR). Similarly it also makes these beans available to any servlets that are defined in the WAR. So far so good, this is working correctly, and is exactly how you would expect it to work.

The problem arises when using Annotation Configuration, and it can be difficult to trace back to exactly what might be causing it. If you define <context:annotation-config /> in just the applicationContext.xml file, then the annotation configuration will appear to work (portlet initialization will work, and they should start up appearing to be fully wired). However when the portlets are used, they will start to throw NullPointerExceptions due to beans not being wired. It appears that @Autowired and @Resource are not being interogated when the portlet is running, but worked fine when it was being initialized.

Attempting to diagnoise this issue will have you looking at classpaths, ensuring that there are no duplicated JARs loaded by parent and child classloaders, tracing the spring logs for wiring errors, validating the presence of spring-aspects.jar, etc, etc, etc. While these are all valid approachs, and can be a good way to clean up an application, in all likelyhood what is wrong is that the <context:annotation-config /> element is missing from the individual portlet’s configuration file. Leaving this element out means that the spring autowiring won’t be enabled when the portlet is using the portal server’s classloader, but was enabled when the portlet was initialially loaded by the application server’s classloader. At least, this appears to be what’s happening in JBoss Portal Server, your miliage may vary with other servers.

How do you ensure that your annotated portlet will be wired correctly? Simple, add these to both your applicationContext.xml and xxx-Portlet.xml files:

<context:annotation-config />
<context:spring-configured />
<aop:aspectj-autoproxy/>

Note: In the case of the xxx-Portlet.xml files, its a good idea to create a common.xml file, then import that in each of the individual portlet files. This allows for commonality between all the portlets, even though they will get their own instance of any beans defined in it.
<import resource=”classpath:/com/foo/bar/context/common.xml”/>

Log at the correct level

Posted on by

We all know the importance of having good, clear, and useful log messages in our applications (if not then I suggest you read "Release It" from the Pragmatic bookshelf). However it is not always apparent that log messages are written at the correct level.

For example, Log4J has a number of log levels; trace, debug, info, warn, error and fatal. While it looks like its clear what you should log at each level, some major players get it wrong.

I’ve spent the last day looking into issues in JBoss Portal where my custom login module wasn’t working correctly. There was nothing unusual in the log, nor were any errors written to the screen, no indication as to what the problem might have been. After much staring at the config files, it turned out that the package name was wrong, resulting in a ClassNotFoundException. 2 seconds to fix and a few minutes to start the portal and we’re elected.

However, all of this could have been avoided if JBoss was logging something as important as a ClassNotFoundException at a level other than TRACE (see JIRA, TWITTER). At least ERROR, and probably even FATAL (given the severity of not having a login module) would have been appropriate.

The same issue can be seen with exceptions from the portlets themselves. JBoss logs these at INFO level, which is inappropriate as an exception emitting from the portlet’s execution stack will have resulted in the user experiencing an error.

So what are appropriate uses of the log levels?

TRACE – method entry/exit points, logging of method parameters, any other information that is only useful when tracing why something has gone wrong. This level will generate orders of magnitude more data than the other levels, so should only be enabled selectively on classes when diagnosing issues. Of course, that is not to say that it should only be written selectively, it should be everywhere (introduced using Aspects for the majority of cases), and it must be wrapped by if (logger.isTraceEnabled() when using string concatenation for performance reasons).

DEBUG – information relevant for the majority of debug cases, where we aim to get to the bottom of the problem without resorting to TRACE logging. E.g. database access information, generated SQL statements, etc. As with TRACE, these messages must be wrapped in if (logger.isDebugEnabled()).

INFO – informative messages from the application. e.g. Database insert took 500 ms, or HTTP POST received containing 600 bytes. These messages should be wrapped in if (logger.isInfoEnabled()).

WARN – something MAY be going wrong, but we’ve managed to recover from it for now. e.g. HTTP connection dropped, retrying.

ERROR – something HAS gone wrong, but its limited to the scope of a single user, or single operation. e.g. Database constraint violation, key already exists.

FATAL – something HAS SERIOUSLY went wrong. These errors affect multiple users, or multiple operations on the system. They usually need immediate action as the system may no longer be in operation. e.g. Database error: Database has gone away.

Using these simple rules, its not difficult to choose the correct level to log at. By doing so you’ll make life easier for the next guy.