Real Coders Coding

• Published:May 20th, 2009
• Comments:No Comment
• Category:General Technology, Tricks, XML
• Share / Bookmark

We've all been there before--trying to track down some insipid bug which is impossible to reproduce on a developer's machine. What is the response? To add more logging of course!

That's all well and good, but eventually your log files are going to start getting huge. Don't get me wrong, I LOVE applications with good logging. (In my opinion it's much better to "overlog" than "underlog" [or not log at all!]). But, sometimes it makes sense to cut back on the amount of logging to save disk space, or to make the log files easier to digest...

How can this be done? Certainly not by removing logging from code!

As you may or may not know, log4net provides various "logging levels" which range from "INFO" to "FATAL" with several in between. However, in some cases I've found that these levels are not enough.

For instance, there are some applications where it makes sense to log every single method entry and exit (yes, I DO realize this is usually discouraged as it gives an architectural layout of your application to competitors, etc.). But, there is no appropriate logging level to correspond to this. Ideally, one might have something that looked like this:

 
 
private void DoSomething()
{
        log.Enter(System.Reflection.MethodBase.GetCurrentMethod().ToString());
 
//do more code here
 
        log.Exit(System.Reflection.MethodBase.GetCurrentMethod().ToString());
}
 

But alas, there is no such thing. We have to use the "Debug" logging level if we are to log enters/exits, like so:

 
 
constant string LOG_ENTER = "Enter - ";
constant string LOG_EXIT = "Exit - ";
 
private void DoSomething()
{
      if(log.IsDebugEnabled)
      {
           log.Debug(LOG_ENTER + System.Reflection.MethodBase.GetCurrentMethod().ToString());
      }
 
//do more code here
 
      if(log.IsDebugEnabled)
      {
           log.Debug(LOG_EXIT + System.Reflection.MethodBase.GetCurrentMethod().ToString());
      }
}
 

This works (although it's not the prettiest code in the world). We can keep track of when a method is entered, when it is exited, calculate how long it takes, look for inefficiencies, troubleshoot much easier, etc.

But when all of that is done, we don't want to ALWAYS log the method entries and exits. We could change our logging level, but since we are using "DEBUG" all of our other debug log statements will also disappear. What can we do?

Luckily there is an easy way to filter out all of our method enters/exits just by updating the configuration file with a string filter setup to filter out "Enter" and another one for "Exit" like so:

 
 
      <!-- NOTE: this filters out Enter statements in methods, uncomment to NOT print method enters
      <filter type="log4net.Filter.StringMatchFilter">

        <stringtomatch value="Enter" />
        <acceptonmatch value="false" />
      -->
 
      <!-- NOTE: this filters out Exit statements in methods, uncomment to NOT print method exits
      <filter type="log4net.Filter.StringMatchFilter">

        <stringtomatch value="Exit" />
        <acceptonmatch value="false" />
       -->
 

Just add this to the "appender" element in the log4net section in your configuration file and uncomment/comment out as necessary.