Wednesday, December 1, 2010

How to print user specific information in the application server logs using Log4J

There may be situations where you need to print user specific information into the logs to differentiate between log entries created by different user actions. Log4J provides two ways to accomplish this. The NDC(Nested Diagnostic Context) and the MDC (Mapped Diagnostic Context)
Both NDC and MDC are contexts that are created per thread. You can store values to the context and display it in the log messages at runtime. The only difference between NDC and MDC is that, NDC uses stack to store the values and MDC use a map to store the values.
First let us see how we can use NDC.


Use the following lines of code in your server side component
String userInfo1 = <get userinfo 1 from session, like user id>

String userInfo2 = <get userinfo 2 from session, like user name>
org.apache.log4j.NDC.push(userInfo1);

org.apache.log4j.NDC.push(userInfo2);
LogFactory.getLog(ABC.class).debug("Testing user specific information");

org.apache.log4j.NDC.pop();

org.apache.log4j.NDC.pop();
These statements push userInfo1 and userInfo2 into the stack
In the log4j.properties, now you can extract the information using a %x operator

log4j.appender.DEBUG.layout.ConversionPattern= [%x] %m %n
Given the below values
User1 = 123, userName1
User2 = 456, userName2
the log entries will look like
123 userName1 Testing user specific information

456 userName2 Testing user specific information
Let us see how we can use the MDC. As discussed before, MDC uses a map to store the information, instead of a stack
So we have to use a key value pair. The code will look as below.

String userInfo1 = <get userinfo 1 from session, like user id>

String userInfo2 = <get userinfo 2 from session, like user name>
org.apache.log4j.MDC.put("Id", userInfo1);

org.apache.log4j.MDC.put("Name",userInfo2);
LogFactory.getLog(ABC.class).debug("Testing user specific information");

org.apache.log4j.MDC.remove("Id");

org.apache.log4j.MDC.remove("Name");
and in the log4j.properties we have to use %X{<key>} to extract the information. So our example will look like
log4j.appender.DEBUG.layout.ConversionPattern=[%X{Id} %X{Name}] %m %n
There could be a problem while using NDC as mentioned in the log4j wiki:
NDC use can lead to memory leaks if you do not periodically call the NDC.remove() method. The current NDC implementation maintains a static hard link to the thread for which it is storing context. So, when the thread is released by its creator, the NDC maintains the link and the thread (and its related memory) is not released and garbage collected like one might expect. NDC.remove() fixes this by periodically checking the threads referenced by NDC and releasing the references of "dead" threads. But, you have to write your code to call NDC.remove().  

Blog Archive