Tuesday, May 13, 2008

Viewing Logs as Trees using NDC/Viewer

One of the problems that one tends to find when attempting to diagnose a problem using logs is the sheer volume of information that one has to digest. I've been thinking about that a little over the last couple of days, and it seems to me that with a little work you could display logs in tree form, like a call stack, which would give you the ability to do many of the kinds of things you can only do with a profiler right now, such as:

  • Track down the hibernate logging that relates to a particular HTTP request so that you can diagnose a tricky persistence problem.
  • Analyze the number of SQL calls made by a single HTTP request.
  • Get a rough outline of the time involved at each layer of a request.
In order to make that happen, it seems like you'd want:
  • Judicious application of the nested diagnostic context in Log4J or Logback to store a sense of the layer. This is probably done easiest with an aspect that could be applied at various tiers (services, daos, etc.)
  • Some kind of request-tracking key, whether this is the thread, or some kind of context-free identifier stored in the mapped diagnostic context. Again, this could be applied via an aspect.
  • Better log-parsing/viewing tooling. Using the above pieces of information, you could display logs as a tree, allow for querying, etc.
It's an interesting idea. Like most interesting ideas, it would take someone to actually follow through on it, and i'm not convinced that's going to be me. ;)

2 comments:

Ceki said...

Regarding the rough outline of the time involved at each layer of a request, the upcoming release of logback, that is version 0.9.10, will include a poor man's profiler. Please let me know whether it meets your needs or not.

Yuri Schimke said...

Hey, I have a log file viewer (curses based, written in java) that can show you a reformatted log file, and let you jump to requests (via NDC info) or define Events and jump to those.

If you would like to beta test it, then I would be very happy to have another user.

One feature I have worked on recently is ability to reuse the same config and run a scripted report e.g.

http://fisheye.codehaus.org/browse/~raw,r=184/kolja/trunk/kolja/kolja-widefinder/src/test/script/wfii.groovy

Send me a sample of your log file, and I can set up the config file for it.