AsyncLoggers: the idea

AsyncLoggers strives to provide high-quality asynchronous wrappers for all well-known logging frameworks.
  • There is an AsyncTraceListener for making your TraceListeners asynchronous.
  • There is an OrderedAsyncAppender for log4Net, as prepackaged appender for log4Net allows only logging out of order -- not a great idea unless you provide a timestamped message and a log-viewing utility or your logger has some other way of tolerating this.
  • There is an asynchronous logger for Enterprise Library 5.0. While Enterprise Library allows asynchronous logging via MSMQ, it's slower than asynchronous logging with in-memory buffering which we provide (slower, but more reliable), and it relies on an additional administrative endpoint (an MSMQ queue). This might be just right for some applications, but our logger is there so you have some kind of choice in the matter.
  • There will be no asynchronous logger for NLog as that framework already has a decent async implementation of its own.

Fundamental flaws of asynchronous logging

The biggest issue with in-memory asynchronous loggers is they don't guarantee that buffered messages will be logged, should your process terminate abruptly. If you run into problems with your application, you might be thinking to trace the state of your system by looking at logs, only you won't be able to assume your asynchronously-written logs are complete (there might be subtle a way to tell, whether they are, but in general you don't know). The flip side to that coin is: that kind of loggers are the fastest, at least in theory (we haven't optimized ours yet). So it's up to you to decide, whether the gain is worth the pain.

Of course, asynchronous loggers in general (not just in-memory loggers) can avoid the problem mentioned above, if the log their intentions synchronously to a durable storage before making moves (the way database logs transactions). That's slower and that's what AsyncLoggers don't do at the moment and probably never will. They all work in-memory now.

Second problem is that asynchronous loggers do not report errors right away -- but this weirdness is common for multithreaded applications in general.

Usage

Using the AsyncTraceListener: using app.config-ured listeners

Here is the pattern you should follow to get asynchronous logging from your TraceListeners. Step one is to configure your listeners in the application' configuration file, as you always do. Note that Trace.AutoFlush is set to false.

Here is an example:
<?xml version="1.0" encoding="utf-8" ?>
<configuration>
  <system.diagnostics>
    <!-- Note that it never makes sense to set AutoFlush to True for the Trace class if you're using AsyncLoggers -->
    <trace autoflush="false" indentsize="4">
      <listeners>
        <add name="logListener" type="System.Diagnostics.EventLogTraceListener" initializeData="Application" />
        <remove name="Default" />
      </listeners>
    </trace>
  </system.diagnostics>
</configuration>
Then, after your application starts, you can swap any named logger for asynchronous version. To achieve this, you call into TraceAsyncLoggers.SwapTraceListenerForAsynchronous(string nameOfTraceListenerToBeSwapped). Or, you can swap all of them at once by calling TraceAsyncLoggers.SwapAllTraceListenersForAsynchronous(). This creates asynchronous wrappers around your listeners in the Trace.Listeners collection (which gets all the messages traced via the Trace class during execution of your application). See the source code for a working sample.

Using the AsyncTraceListener: constructing listeners directly in code

Creating an asynchronous TraceListener in code is easy. All you have to do is get yourself a real TraceListener and wrap it with AsyncTraceListener. AsyncTraceListener has a contract identical to the contract of your regular TraceListener, hence you can use it the same way.

var asyncTraceListener = new AsyncTraceListener(regularSyncTraceListener);
asyncTraceListener.WriteLine("Log me");

Using the OrderedAsyncAppender: the way of configuration

As for Log4Net, there is extensive configuration you're probably already using. Here is how you wrap any Appender into an asynchronous Appender in configuration. Note the AsyncConsoleAppender configuration. The wrapping goes on there.

<?xml version="1.0"?>
<configuration>
  <configSections>
    <section name="log4net"
      type="log4net.Config.Log4NetConfigurationSectionHandler, log4net"/>
  </configSections>
  <log4net>
    <appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%thread] %-5level  - %message%newline"/>
      </layout>
    </appender>

    <appender name="AsyncConsoleAppender" type="AsyncLoggers.Log4Net.OrderedAsyncAppender, AsyncLoggers">
      <appender-ref ref="ConsoleAppender" />
      <!-- Note: this property (named Fix) is a performance gamechanger as capturing some things -->
      <!-- on the calling thread can slow this appender down drastically. Make sure you only fix the properties -->
      <!-- that you're actually going to use -->
      <Fix value="ThreadName, Message"/>
    </appender>

    <root>
      <level value="ALL" />
    </root>
    <logger name="Logger">
      <level value="ALL" />
      <appender-ref ref="ConsoleAppender"/>
    </logger>
    <logger name="AsyncLogger">
      <level value="ALL" />
      <appender-ref ref="AsyncConsoleAppender" />
    </logger>
  </log4net>
</configuration>

Here is some code that shows how one can use the asynchronous logger (same way you would use your synchronous one):

ILog asyncLogger = LogManager.GetLogger("AsyncLogger");

for (int i = 0; i < 1000; i++)
{
 asyncLogger.Info("Dear deer John");
}

See the source code for a working sample.

Last edited Feb 24, 2013 at 7:45 PM by MikhailDutikov, version 16

Comments

No comments yet.