Performance Tricks for C# Logging

Question

I am looking into C# logging and I do not want my log messages to spend any time processing if the message is below the logging threshold. The best I can see log4net does is a threshold check AFTER evaluating the log parameters.

Example:

_logger.Debug( "My complicated log message " + thisFunctionTakesALongTime() + " will take a long time" )

Even if the threshold is above Debug, thisFunctionTakesALongTime will still be evaluated.

In log4net you are supposed to use _logger.isDebugEnabled so you end up with

if( _logger.isDebugEnabled )
    _logger.Debug( "Much faster" )

I want to know if there is a better solution for .net logging that does not involve a check each time I want to log.

In C++ I am allowed to do

LOG_DEBUG( "My complicated log message " + thisFunctionTakesALongTime() + " will take no time" )

since my LOG_DEBUG macro does the log level check itself. This frees me to have a 1 line log message throughout my app which I greatly prefer. Anyone know of a way to replicate this behavior in C#?

Answer 1

If you can target .NET 3.5 (C# 3.0) you can use extension methods to wrap the if statements.

so you can do the equivalent "macro":

logger.Log_Debug("Much faster");

logger.Log_Debug(() => { "My complicated log message " + thisFunctionTakesALongTime() + " will take no time" });

by wrapping the check in this method:

public class Log4NetExtensionMethods {
    // simple string wrapper
    public void Log_Debug(this log4net.ILog logger, string logMessage) {
        if(logger.isDebugEnabled) {
             logger.Debug(logMessage);
        }
    }

    // this takes a delegate so you can delay execution
    // of a function call until you've determined it's necessary
    public void Log_Debug(this log4net.ILog logger, Func<string> logMessageDelegate) {
        if(logger.isDebugEnabled) {
             logger.Debug(logMessageDelegate());
        }
    }
}

Answer 2

17.4.2 The Conditional attribute

The attribute Conditional enables the definition of conditional methods. The Conditional attribute indicates a condition by testing a conditional compilation symbol. Calls to a conditional method are either included or omitted depending on whether this symbol is defined at the point of the call. If the symbol is defined, the call is included; otherwise, the call (including evaluation of the parameters of the call) is omitted.

[ Conditional("DEBUG") ]
public static void LogLine(string msg,string detail)
{
    Console.WriteLine("Log: {0} = {1}",msg,detail);
}

public static void Main(string[] args)
{
    int Total = 0;
    for(int Lp = 1; Lp < 10; Lp++)
    {
        LogLine("Total",Total.ToString());
        Total = Total + Lp;
    }
}

Answer 3

The problem here is that all method parameters must be evaluated before the method is invoked. There is no way around this, given the syntax you are using. Since C# does not have a real preprocessor or macros, you can't do anything like "LOG_DEBUG". The best you could do is use if (logger.isDebugEnable) as suggested.

The only thing I can think of is maybe using something like a lambda expression to delay evaluation. But I would warn you that this will almost certainly have more of a performance hit in the end.

internal class Sample
{
    private static void Main(string[] args)
    {
        DelayedEvaluationLogger.Debug(logger, () => "This is " + Expensive() + " to log.");
    }

    private static string Expensive()
    {
        // ...
    }
}

internal static class DelayedEvaluationLogger
{
    public static void Debug(ILog logger, Func<string> logString)
    {
        if (logger.isDebugEnabled)
        {
            logger.Debug(logString());
        }
    }
}