Non-invasive Audit logging

Non-invasive Audit logging
Which developer hasn’t worked on a project where, at some point in time before the final delivery, some guy from maintenance wakes up and asks the development team whether they can perform audit logging… Specifically he wants to have a “detailed log”. It should contain the IPAddress of the user, his login name, and some information about which actions he performed and what the results were…

Basically logging is an everyday part of the developer’s life. It makes it easier to solve bugs when you have clear and concise logging, and it gives you an overview of what your application is doing. But now this maintenance guy asks you to put logging in at specific points in your application. But also, what’s more, he wants you to adapt the interfaces of your services, because you also need to log the IPAddress and username of the user. In most web applications only the frontend is aware of the fact that you’re on the web. So how can you achieve this…?
Enter Spring-AOP and Log4J…
Using Aspect Oriented Programming you can declaratively add logging to your application, which is exactly what we want in this case. We don’t want to go through our application adding logging, specifically not since we already know that once the maintenance guy has seen the logging, he probably wants more locations logged, or he wants a different format. So we introduce the following AuditLogAdvice

public class AuditLogAdvice implements MethodInterceptor {
   private static final Log log = LogFactory.getLog("AuditLogger");
   /**
    * @see org.aopalliance.intercept.MethodInterceptor#invoke(
    *         org.aopalliance.intercept.MethodInvocation)
    */
   public Object invoke(MethodInvocation invocation) throws Throwable {
      StringBuilder logLine = new StringBuilder();
      logLine.append("Calling: ");
      Method m = invocation.getMethod();
      logLine.append(m.getDeclaringClass().getName())
         .append(".")
         .append(m.getName())
         .append("(");
      Object[] params = invocation.getArguments();
      if (params != null && params.length > 0) {
         int counter = 0;
         for (Object param : params) {
            logLine.append(param);
            counter++;
            if (counter < params.length) {
               logLine.append(", ");
            }
         }
      }
      logLine.append(")");
      log.debug(logLine);
      Object returnValue = invocation.proceed();
      StringBuilder logReturnLine = new StringBuilder();
      logReturnLine.append("Returned: ").append(returnValue);
      log.debug(logReturnLine);
      return returnValue;
   }
}

This advice can now be applied to method calls using a pointcut in your Spring applicationContext.xml file. This snippet for example matches all calls to the DAO classes of your application:

   
   
      
      
         
            .*DAO.*
         
      
   

That’s it, we’re done… But wait, didn’t the maintenance guy also want the IPAddress and userName logged. How can we do this? Luckily for us, we are using Log4J to do the logging. Log4J contains an Object called NDC (Nested Diagnostic Context), which allows us to register some information specific to a thread. Now we need some location where we have access to the HttpServletRequest. We don’t want to put the IPAddress of the user on the NDC stack in each Struts Action / Spring-MVC Controller / Tapestry Page, but instead we want to do this in exactly one location. One of the ideal locations is in a javax.servlet.Filter, as each and every request from the clients’ browser passes through the Filter (if correctly mapped in your web.xml). So let’s define the Filter:

public class AuditLogFilter implements Filter {
   private static final Logger logger = Logger.getLogger("AuditLogger");
   /**
    * @see javax.servlet.Filter#init(javax.servlet.FilterConfig)
    */
   public void init(FilterConfig arg0) throws ServletException {
   }
   /**
    * @see javax.servlet.Filter#doFilter(javax.servlet.ServletRequest,
    *         javax.servlet.ServletResponse, javax.servlet.FilterChain)
    */
   public void doFilter(ServletRequest request, ServletResponse response,
         FilterChain chain) throws IOException, ServletException {
      String ndc = request.getRemoteAddr();
      ndc += "/" + request.getParameter("userId");
      NDC.push(ndc);
      chain.doFilter(request, response);
      NDC.pop();
   }
   /**
    * @see javax.servlet.Filter#destroy()
    */
   public void destroy() {
      NDC.remove();
   }
}

Now we are really done. Using these classes, we are able to declaratively log what the maintenance guy wants (IPAddress, userName, actions and results), in a consistent format. And it is easy to adapt at a later stage!