Logging user activity in web app

Question

I'd like to be able to log user activities in a web app. I'm currently using log4j which works well for logging errors etc, but I'm unsure what the best approach is to log the user, executed servlet method, and method params. I'm using spring security for the authentication.

A typical servlet could look like:

public class BankAccountServlet {
    @RequestMapping("/deposit")
    public void deposit(double amount) {
        ...
    }

    @RequestMapping("/checkBalance")
    public double checkBalance() {
        ...
    }
}

If there are two users, foo and bar, where foo checks his balance and bar deposits two sums of cash 10.00 and 5.00. I'd like the logs to look like:

01/01/1970 23:59:59 - foo - checkBalance
02/01/1970 23:59:59 - bar - deposit - 10.00
02/01/1970 23:59:59 - bar - deposit - 5.00

If anyone could offer some advice I'd really appreciate their help.

Answer 1

It's actually pretty simple to achieve using MDC/NDC functionality built into Log4J (SLF4J and Logback only support MDC).

Implementing MDC filter

First, implement a servlet filter that will add username to MDC/NDC. Logback provides convenient MDCInsertingServletFilter, Spring framework also adds Log4jNestedDiagnosticContextFilter to the store. Look at them but you will need a custom one like this:

public class UserToMdcFilter implements javax.servlet.Filter
{
    @Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
        MDC.put("user", SecurityContextHolder.getContext().getAuthentication().getPrincipal());
        try {
            chain.doFilter(request, response);
        } finally {
            MDC.remove("user");
        }
    }

    //...
}

Adding MDC value to your logging pattern

Make sure this filter is applied in web.xml after Spring security filter. MDC feature is really slick - it will add all values saved in MDC thread-local map to each and every logging statement if requested. In your case, simply add this:

%X{user}

to your logging pattern.

Unobtrusive logging method parameters/values

Logging method name, parameters and return values is up to you (username will be added automatically), but there are some elegant ways to remove boilerplate logging code completely. Try this Spring built-in aspect:

<bean id="customizableTraceInterceptor" class="org.springframework.aop.interceptor.CustomizableTraceInterceptor">
    <property name="enterMessage" value="Entering $[methodName]($[arguments])"/>
    <property name="exitMessage" value="Leaving $[methodName](): $[returnValue]"/>
</bean>
<aop:config>
    <aop:advisor advice-ref="customizableTraceInterceptor" pointcut="execution(public * BankAccountServlet.*(..))"/>
</aop:config>

Final thoughts

• Look at this thread: http://forum.springsource.org/showthread.php?88890-MDC-Log4j-Filter-with-Spring-Security-3.0.2
• Consider using Logback as a logging library and stick with SLF4J API.