Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

How to effectively log asynchronously?

I am using Enterprise Library 4 on one of my projects for logging (and other purposes). I've noticed that there is some cost to the logging that I am doing that I can mitigate by doing the logging on a separate thread.

The way I am doing this now is that I create a LogEntry object and then I call BeginInvoke on a delegate that calls Logger.Write.

new Action<LogEntry>(Logger.Write).BeginInvoke(le, null, null); 

What I'd really like to do is add the log message to a queue and then have a single thread pulling LogEntry instances off the queue and performing the log operation. The benefit of this would be that logging is not interfering with the executing operation and not every logging operation results in a job getting thrown on the thread pool.

How can I create a shared queue that supports many writers and one reader in a thread safe way? Some examples of a queue implementation that is designed to support many writers (without causing synchronization/blocking) and a single reader would be really appreciated.

Recommendation regarding alternative approaches would also be appreciated, I am not interested in changing logging frameworks though.

like image 782
Eric Schoonover Avatar asked Jul 25 '09 08:07

Eric Schoonover


People also ask

How do you create asynchronous log?

To make all loggers asynchronous, add the disruptor jar to the classpath and set the system property log4j2.

What is asynchronous logging?

In synchronous logging, the data is directly written to the destination i.e a file or a database. In Asynchronous logging, the data is written to a queue first and then to the destination.

Is NLog asynchronous?

NLog 1.0 supports asynchronous logging, but there is no good support for asynchronous exception handling. This is because wrappers targets are not capable of receiving exceptions which are raised on other threads.


1 Answers

I wrote this code a while back, feel free to use it.

using System; using System.Collections.Generic; using System.Linq; using System.Text; using System.Threading;  namespace MediaBrowser.Library.Logging {     public abstract class ThreadedLogger : LoggerBase {          Queue<Action> queue = new Queue<Action>();         AutoResetEvent hasNewItems = new AutoResetEvent(false);         volatile bool waiting = false;          public ThreadedLogger() : base() {             Thread loggingThread = new Thread(new ThreadStart(ProcessQueue));             loggingThread.IsBackground = true;             loggingThread.Start();         }           void ProcessQueue() {             while (true) {                 waiting = true;                 hasNewItems.WaitOne(10000,true);                 waiting = false;                  Queue<Action> queueCopy;                 lock (queue) {                     queueCopy = new Queue<Action>(queue);                     queue.Clear();                 }                  foreach (var log in queueCopy) {                     log();                 }             }         }          public override void LogMessage(LogRow row) {             lock (queue) {                 queue.Enqueue(() => AsyncLogMessage(row));             }             hasNewItems.Set();         }          protected abstract void AsyncLogMessage(LogRow row);           public override void Flush() {             while (!waiting) {                 Thread.Sleep(1);             }         }     } } 

Some advantages:

  • It keeps the background logger alive, so it does not need to spin up and spin down threads.
  • It uses a single thread to service the queue, which means there will never be a situation where 100 threads are servicing the queue.
  • It copies the queues to ensure the queue is not blocked while the log operation is performed
  • It uses an AutoResetEvent to ensure the bg thread is in a wait state
  • It is, IMHO, very easy to follow

Here is a slightly improved version, keep in mind I performed very little testing on it, but it does address a few minor issues.

public abstract class ThreadedLogger : IDisposable {      Queue<Action> queue = new Queue<Action>();     ManualResetEvent hasNewItems = new ManualResetEvent(false);     ManualResetEvent terminate = new ManualResetEvent(false);     ManualResetEvent waiting = new ManualResetEvent(false);      Thread loggingThread;       public ThreadedLogger() {         loggingThread = new Thread(new ThreadStart(ProcessQueue));         loggingThread.IsBackground = true;         // this is performed from a bg thread, to ensure the queue is serviced from a single thread         loggingThread.Start();     }       void ProcessQueue() {         while (true) {             waiting.Set();             int i = ManualResetEvent.WaitAny(new WaitHandle[] { hasNewItems, terminate });             // terminate was signaled              if (i == 1) return;              hasNewItems.Reset();             waiting.Reset();              Queue<Action> queueCopy;             lock (queue) {                 queueCopy = new Queue<Action>(queue);                 queue.Clear();             }              foreach (var log in queueCopy) {                 log();             }             }     }      public void LogMessage(LogRow row) {         lock (queue) {             queue.Enqueue(() => AsyncLogMessage(row));         }         hasNewItems.Set();     }      protected abstract void AsyncLogMessage(LogRow row);       public void Flush() {         waiting.WaitOne();     }       public void Dispose() {         terminate.Set();         loggingThread.Join();     } } 

Advantages over the original:

  • It's disposable, so you can get rid of the async logger
  • The flush semantics are improved
  • It will respond slightly better to a burst followed by silence
like image 76
Sam Saffron Avatar answered Sep 28 '22 23:09

Sam Saffron