These go to eleven!

July 5, 2008

User context tracking in log4J

Filed under: Java — Zbigniew Cyktor @ 11:39 am

Majority of web applications based on Java platform use log4j library to record user activities. All is fun and games until the number of users and logged messages per unit of time exceed a specific threshold. Since log entries for multiple users are intermixed – it gets very difficult to analyze what exactly did a specific user do within a single request.

Fortunately log4j provides a very convenient way of solving this problem. A class org.apache.log4j.MDC provides a mechanism to ‘attach’ any arbitrary information to a given thread that processes a request and to output this information into the log entry. What we need to do is to invoke a static method MDC.put(“userId”, userId) somewhere at the beginning of request processing chain (by using servlet filter for example) and add the element %X{userId} to the row format definition in log4j configuration, for example:

log4j.appender.file.layout.ConversionPattern=%d %5p %c %X{userId} (%F:%L) – %m%n

After that every log entry will contain user identifier which is all we need in most cases. Sometimes we might want to put into the log some additional data. If our application uses AJAX a lot, then a single user might issue multiple requests at the same time, which still can get mixed. It might be a good idea then to add a unique index value incremented after each request etc.

If you add this feature to your application, the people who routinely have to analyze its logs and solve user problems will be most grateful!

Blog at WordPress.com.