CODEWITHSUNDEEP
c#logginglog4netc#-2.0
oberfreak
oberfreak

Reputation: 1807

Logging done right

So my problem is about logging, and how to handle the log statements which can have influence on your code and your runtime behavior.

Log files... every program should write those for propper problem solving but how to do it right?

The most log-statements are verry expensive to get because they should provide usefull information and they are always built even the logging is disabled totaly.

The logging can be configured by xmls, inCode or in some settings etc. but this doesn't solve the string building problem.

For example the following code is always loading a huge lazy loaded tree which would never be loaded totaly during normal execution.

The whole tree is only created for this logging statement to be displayed in the log file

(Ok, I know..., but this is just a replacement for all the complex logging methods that exists in the most programs which should never be executed during normal release execution)

public void SomeMethod(){
    logger.Debug(someObject.GetHeavyDescriptionFromLazyTree());
}

The Method someObject.GetHeavyDescriptionFromLazyTree() is always invoked even if logging is turned off, so there are some common solutions for this problem like:

public void SomeMethod(){
#if DEBUG
    logger.Debug(someObject.GetHeavyDescriptionFromLazyTree());
#endif       
}

public void SomeMethod(){
    if(logger.DoLogDebug())
        logger.Debug(someObject.GetHeavyDescriptionFromLazyTree());
}

I think it's clear that the #if DEBUG compiler flag is no solution for productive code. If I use the logger.DoLogDebug() there would be excessive code for checking if the logging is enabled... so this can't be the solution either.

I thought the ConditionalAttribute could help but it's also bound to the compiler flags and it doesn't deactivate the call to GetHeavyDescriptionFromLazyTree

[Conditional("DEBUG")]  
public void Debug(string debugMessage) 
{ 
    Console.WriteLine(debugMessage); 
}

So I'm looking for a logging solution which

Extra loglines for the best answer ;-)

Edited: I'm looking for a solution in .NET 2.0

Upvotes: 8

Views: 2447

Answers (3)

user47589
user47589

Reputation:

The most log-statements are verry expensive to get because they should provide usefull information and they are always built even the logging is disabled totaly.

Not precisely true. See here:

if (Log.IsDebugEnabled)
{
    StackFrame f = new StackFrame(2);
    Log.Debug("Very expensive message to put together and stuff." + f.GetMethod().Name);
}

Your message won't be built if debug logging isn't enabled at all. This satisfies all three of your conditions and is fairly standard practice.

Edit: I should add that IsDebugEnabled takes into account whether debug logging is enabled globally and any override configuration for this particular logger. It's very specific, and is determined at runtime, but is also cached until the configuration changes.

Edit2:

If I use the logger.DoLogDebug() there would be excessive code for checking if the logging is enabled... so this can't be the solution either.

The if statement I outlined above isn't excessive and is evaluated very quickly. I suggest you experiment with it and evaluate for yourself if it is performant enough. If you are finding that you have these if blocks all over the place, the standard suggestion is to consolidate them when possible.

A key idea here is log4net has five logging levels, each of which can be considered completely independently of the others. So you might have IsDebugEnabled in one place, and IsInfoEnabled in another place. You won't get this with conditional compilation very easily, and that would prove even more cumbersome. This scenario is actually quite common in code I've worked on:

if (Log.IsDebugEnabled)
{
    StackFrame f = new StackFrame(2);
    Log.Debug("Very expensive message to put together and stuff." + f.GetMethod().Name);
}
if (Log.IsInfoEnabled)
{
    StackFrame f = new StackFrame(2);
    Log.Debug("Very expensive message to put together and stuff." + f.GetMethod().Name);
}
if (Log.IsErrorEnabled)
{
    StackFrame f = new StackFrame(2);
    Log.Debug("Very expensive message to put together and stuff." + f.GetMethod().Name);
}

If you want to be able to tailor your log outputs by logging level and by class, or even by entire namespaces, this is the way to go.

Upvotes: 4

Alex Mendez
Alex Mendez

Reputation: 5150

You can make it configurable by the web.config or app.config. Add a item called EnableLogging (<add key="EnableLogging" value="false"/>). Then create a static method that gets the value from the .config and used that to check.

Upvotes: 0

Dan Bryant
Dan Bryant

Reputation: 27495

One approach to 'lazy logging' is to use an expression (to create a function delegate that returns the message) rather than using direct evaluation:

logger.Debug(() => someObject.GetHeavyDescriptionFromLazyTree());

This has its own downsides (construction of the delegate), but it can be cheaper than the expensive method. Typically you would provide this as an overload and only use it in the case where you know evaluating the expression is expensive.

Upvotes: 6

Related Questions