Using the Log4j MDC in Grails
Friday, January 14th, 2011I read this interesting blog post
about using the Log4j MDC to add information to logged messages that was referenced on the Grails User mailing list and wondered what it would take to get it working in Grails since the example is traditional Java. Turns out it’s pretty simple.
But first – what is the MDC? It’s Log4j’s MDC
class, which implements a Mapped Diagnostic Context. There’s a similar class, NDC, which implements a Nested Diagnostic Context. In this case there’s no need for nesting, we just want to store temporary information in thread-local storage under a key, so MDC makes more sense. Click the links to read the Javadoc for the two classes, and see this wiki page for a comparison of the two.
Also note that if there’s an SLF4j wrapper for this class that you can use if you want the logging implementation transparency that SLF4j provides.
Ok, so how would we use this in Grails? There are just two steps:
- create a filter to store data in the MDC
- edit the logging pattern to include the data
We have two options for the filter – either a Grails filter, or a servlet filter. Grails filters only apply to controller requests and are written in Groovy, whereas servlet filters apply to whatever request pattern you specify in web.xml and are written in Java or Groovy. So the decision about which to use comes down to what you want to filter, and if you have Groovy/Java performance concerns.
Grails Filter
To use a Grails filter, run the create-filters script, e.g.
and add this code to grails-app/conf/com/burtbeckwith/mdctest/LoggingFilters.groovy:
package com.burtbeckwith.mdctest
import org.apache.log4j.MDC
class LoggingFilters {
def filters = {
all(controller:'*', action:'*') {
before = {
MDC.put 'username', request.userPrincipal?.name ?: 'N/A'
}
afterView = { e ->
MDC.remove 'username'
}
}
}
}
We're storing the logged-in user's name to the MDC under the username key, or 'N/A' if there's no authenticated user. You can also store other request-specific information, but for this example we'll keep things simple. Also note that after the request is finished processing we remove the data from the MDC to avoid memory leak issues.
Servlet Filter
If you want to use a servlet filter, create a class in src/java, e.g. src/java/com/burtbeckwith/mdctest/MdcFilter.java, and add this code:
package com.burtbeckwith.mdctest;
import java.io.IOException;
import java.security.Principal;
import javax.servlet.Filter;
import javax.servlet.FilterChain;
import javax.servlet.FilterConfig;
import javax.servlet.ServletException;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import javax.servlet.http.HttpServletRequest;
import org.apache.log4j.MDC;
public class MdcFilter implements Filter {
public void doFilter(ServletRequest req, ServletResponse res, FilterChain fc)
throws IOException, ServletException {
try {
Principal principal =1;
chain.doFilter(req, res);
}
finally {
MDC.remove("username");
}
}
public void init(FilterConfig fc) {/*nothing to do*/}
public void destroy() {/*nothing to do*/}
}
You'll need to add this to web.xml, so run
if you haven't already and add a filter and a filter-mapping element:
<filter> <filter-name>com.burtbeckwith.mdctest.MdcFilter</filter-name> <filter-class>com.burtbeckwith.mdctest.MdcFilter</filter-class> </filter> <filter-mapping> <filter-name>com.burtbeckwith.mdctest.MdcFilter</filter-name> <url-pattern>/*</url-pattern> </filter-mapping>
Edit the logging pattern
We need to update the logging pattern to include the MDC data, so add an appender override for the 'console' appender (update your other appenders similarly) in grails-app/conf/Config.groovy:
log4j = {
appenders {
console name: 'stdout',
layout: pattern(conversionPattern: '%c{2} %m - %X{username}%n')
}
...
}
The significant change is the addition of %X{username} to include the username value.
Testing
To test this, I installed the Spring Security plugin and added a test user. I created two simple controllers, one that requires authentication:
import grails.plugins.springsecurity.Secured
@Secured(['ROLE_ADMIN'])
class AdminController {
def index = {
log.debug 'accessing admin controller'
render 'Hello admin'
}
}
and one that doesn't:
class TestController {
def index = {
log.debug 'accessing test controller'
render 'Hello world'
}
}
Then I configured controllers to log at the debug level:
log4j = {
...
debug 'grails.app.controller'
...
}
and ran the application. Accessing /test shows that I'm not logged in:
and accessing /admin after logging in displays my username:
Download the sample application here.
There's a user 'admin' configured in BootStrap.groovy with password 'password' that you can use to test login.
Note that the sample application has both filters implemented, so you should remove the one you don't want to use.
- HttpServletRequest)req).getUserPrincipal(); MDC.put("username", principal == null ? "N/A" : principal.getName([back]
