How to optimize logging performance

Overview

Logging can take a considerable amount of time. This document helps you understand why it happens so and provides some performance tips that can speed up your logging.

Logging process described

Every time you use log a message several things need to be done to check if the message is to be logged, and where to write the output to. Each call to Debug, Info, Warn, Error, Fatal or the generic Log incolves the following operations:

1. The logging parameters are prepared. This is the job of a CLI runtime (.NET/Mono) and may introduce some considerable overhead - in most cases related to boxing or hidden array construction.
2. The appropriate logging method (Debug(), Info(), Warn(), Error(), Fatal() or Log()) is called with the prepared parameters.
3. The logging method roughly checks if the output is enabled for the specified logger at the specified level. This is done very quickly (a single comparison) because of the data structures used.
4. If the previous check succeeded, there's still a chance that the message will not get logged - in this step filters are evaluated and they have a chance to reject the method. Note that filters can be expensive in terms of the time of execution.
5. After the message is qualified to be logged - the log message is formatted based on message and parameters passed to the logging function. This can be pretty slow because the String.Format isn't very fast.
6. The last step is passing the log event to one or more targets so that they can to write the event to output. This is usually the most time-consuming part of the process because targets are typically some kind of persistent storage (file, database) and it takes time to write to such outputs.

"This is bad news...", you might think, but fortunately NLog provides many mechanisms that help speed up your logging.

Performance Tips

Cache your logger instance

Once you get your logger from LogManager.GetLogger() it's advised to store the reference somewhere and reuse it without calling LogManager.GetLogger() again. A static member to your class is quite a good idea. The following example describes it:

using NLog; 
 
class MyClass { 
    // storing logger reference in a static variable is clean and fast 
    static Logger logger = LogManager.GetLogger("MyClass"); 
 
    static void Main() 
    { 
        logger.Debug("This is a debugging message"); 
 
        // it is not recommended to get the logger and store it in a local variable 
        Logger logger2 = LogManager.GetLogger("MyClass"); 
        logger2.Debug("This is a debugging message"); 
    } 
}

TODO: add more tips here

Last updated: 2006-07-10 11:32:55