Liz Douglass

Posts Tagged ‘Log4j NDC

Nested Diagnostic Contexts

leave a comment »

On my current project we have what I think is a very well thought out logging strategy. We generate a number of logs that serve a variety of different purposes. One thing that is common across all of them is that they are configured to print information from Nested Diagnostic Contexts (NDCs). An “NDC is an object that Log4j manages per thread as a stack of contextual information.” There is a very clear and short example of using an NDC and the output it can produce here.

In our application we use the NDC class in lots of places. For example we have a LoggingContextInterceptor that creates and destroys an NDC for our controller methods:

public class LoggingContextInterceptor extends HandlerInterceptorAdapter {

    private final UrlPathHelper helper = new UrlPathHelper();

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler)
            throws Exception {

        NDC.push(helper.getLookupPathForRequest(request));
        return true;
    }

    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex)
            throws Exception {

        NDC.clear();
        NDC.remove();
    }
}

Note that in the afterCompletion method above we are calling NDC.remove as well as NDC.clear. According to the API documentation the NDC clear method will empty and context information. The documentation also states that you need to call the remove method when exiting the thread because “this ensures that the memory used by the thread can be freed by the Java garbage collector”.

Inside our controllers we may push and pop additional information on and off the NDC, as well as log various events. A typical controller method in our app looks a bit like this:

    @RequestMapping(value = "/member/{memberNumber}/foostrategy", method = RequestMethod.PUT)
    public View updateFoo(@PathVariable("memberNumber") String memberNumber,
                          InputStream requestInputStream) throws IOException {

        // some processing

        logger.info("Updating " + strategy);
        service.update(strategy, fundCode);

        return StatusCodeView.ok();
    }

The logged message from this controller includes the NDC info:
2009-12-02 11:00:50,806 INFO [15554445@qtp-10481519-2 PUT /member/03003522/foostrategy] [FooController] – Updating FooStrategy[memberNumber=1234….]

Where the configuration for the Appender is:
log4j.appender.myAppender.layout.ConversionPattern=%d{ISO8601} %-5p [%t %x] [%c{1}] – %m%n

Logging with NDCs has proven to be very useful for helping the team understand and reproduce errors very quickly.

Advertisements

Written by lizdouglass

December 9, 2009 at 10:29 am

Posted in Uncategorized

Tagged with