c# - How to effectively log asynchronously?

Question

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.

Answer 1

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