Aug 16 2011

Log4Net... Friend or Foe?

Despite the title, I'm actually a big fan of Log4Net. While powerful, Log4Net can become the bottleneck for some applications so we need to explore these issues a little more closely so you can configure Log4Net in a way that’s optimal for your system. Identifying this as a potential performance bottleneck is relatively straightforward. If you have a repeatable performance test, profile the application with your normal production log configurations, and then again with all your logging disabled. If the change in performance is dramatic, then you may want to consider a new strategy.

Check logging levels before logging

To avoid repeating information from the authors of this component… as a general rule you should always test if the target log level is enabled before you actually log anything. This will offset some hidden costs which the vendor’s article details.
 
More information can be found on the vendor’s site (http://logging.apache.org/log4net/release/manual/internals.html).

Using the RollingFileAppender

As a file I/O-bound resource, this Appender can block your application from doing real work while the Appender flushes its buffer to disk. Profiling your application will uncover this and there are a couple options to mitigate this expense.

Mitigation strategies
  • Disable the immediate flush option. According to the Log4Net documentation, this can result in performance increases of 15-20% but has a risk that the final buffer may not be flushed to disk if the host process crashes

Using the AdoNetAppender

As a database I/O-bound resource, this Appender can block your application from doing real work while the Appender flushes its buffer to the database. If you analyze this closely, you’ll see that the native Appender will execute a Stored Procedure or SQL command for each and every log entry to be sent to the database. Unlike the RollingFileAppender, buffering will never offset the cost of these database interactions. As a result, more invasive strategies will be required.

Mitigation strategies
  • Implement a custom Appender that inherits from AdoNetAppender and override the SendBuffer(LoggingEvent[]) method. At this point you can then change the implementation to suite your performance demands while preserving all the base class functionality such as managing connections, etc… Here are a few ideas on what you could implement:
    • Write to shared memory and offload to an external process to perform write-behind
    • Perform bulk inserts into the database
    • Batch multiple log entries into a single Stored Procedure call
    • Queue to an MSMQ and use an external process to perform write-behind
    • Etc…
  • Avoid using custom parameter formatters. Under the covers many of the underlying PatternConverters result in the creation of StringBuilders which can be quite expensive. If you’re building a custom implementation of this Appender, it may be more performant to handle this using different patterns

Hope this helps you find that little something extra and find performance that you need. :-)

Tags: ,