Insights

Introduction

This article provides a brief overview of creating a custom Trace Listener. For our purpose, the trace listener will log its information to a database using an Asynchronous Logger queue. Subjects that will be covered include Trace Listeners, Exceptions, Queues and the Singleton Pattern.

Why do I need such a mechanism?

It is prudent for all Enterprise software applications to provide a method by which error and informational messages can be logged. When choosing how your information should be logged, you should keep in mind any security issues relevant to your system. Often, information that is saved during logging may be sensitive in nature and must conform to the security practices defined by the architecture of the system.

Ideally, you should consider having a separate database to handle logging. By separating logging from your application database, you can avoid impacting your application’s DB performance by increasing the number of DB transactions, network bandwidth and growing the DB backup size. A separate data source can be utilized to capture the logging data. This doesn’t even need to be a relational database; the nature of the information being logged may make a non-relational database, such as mongoDB, a better choice for a low footprint, high performance data source.

Using a synchronous logging model will halt execution of the current thread until logging is completed. This may have a serious impact on your system performance. The approach used in this article is an asynchronous model, lightweight and decoupled, ensuring minimal impact on the performance of the application.

There are two important properties of this technique:

• High Reliability
  • The purpose of logging systems is to track information related to audit events or system errors. This information is critical to the operation of the application and cannot be lost. Given that we are proposing to use a database as the target for logging, there is a real possibility that a problem with database connectivity may prevent logging from occurring. In this instance, we need a backup plan for logging critical messages. Two good options would be the file system or the event viewer.
• High Performance
  • The logging mechanism shouldn’t create undue overhead for the system. If the system is generating some important data that needs to be logged, the loss of which cannot be tolerated, then the implementation has to ensure all such events are logged. The events being logged may occur at any instant, and the volume of logging events can be sporadic, creating a real challenge for the developer to maintain system performance.

1. Concepts

This section provides some brief information about exceptions, trace listeners in .NET, and Queue and Singleton Pattern that you need to understand before starting to develop the logging mechanism.

   1.1 Exception

An exception in software is basically a failure in the normal flow of the application. Given the complexity of today’s software applications, exceptions are inevitable. What we can do is handle the exceptions to provide predictable system behavior and track (log) problems in order to correct any system flaws. We do this by applying best practices for exception handling. (See http://msdn.microsoft.com/en-us/library/5b2yeyab.aspx). Our mechanism will focus on logging exceptions though the Logger Queue and will be able to log generic type objects.

Our mechanism will focus on logging exceptions though the Logger Queue and will be able to log generic type objects.

   1.2 Trace Listener

Trace Listeners are used to monitor execution of an application. Listeners are objects that can be used to route output messages to a target (i.e. a database) for subsequent storage and processing. Microsoft’s .NET framework provides some predefined listeners such as TextWriterTraceListener, EventLogTraceListener, DefaultTraceListener, and ConsoleWtraceListener.

The solution defined in this article will not use an existing listener but will create a custom listener inherited from the TraceListener base class to provide listener capability to a database target.

   1.3 Queue

A Queue is a data structure that represents the first-in, first-out collection of objects. Queue is very useful for our mechanism in that it will provide the output in the order it received the messages. We will be instantiating our Queue and will have to deal with making it thread safe as, by default, it is not guaranteed as such. (See http://msdn.microsoft.com/en-us/library/system.collections.queue.aspx)

   1.4 Singleton Pattern

A Singleton pattern, if applied to a class, will make it only allow a single instance of that class to be created. The logger mechanism we create will consist of a Singleton Queue so that we ensure all the exceptions are funneled to a unique data structure in our system and processed in the correct order.

2. Let’s Get to Work

We now have some introductory information for the concepts that we need to create the Asynchronous Logger for exception logging into our database in .NET. As mentioned above, our logger will have the ability to log any message object that implements an interface we define. This interface, IQueueableMessage, will have a Save() method to perform insertion of the data to be logged into the database. Another method, GetErrorTextForFile(), will return a user-friendly message that can be used for logging message objects to a file in case database logging somehow fails.

   IQueueableMessage
    {
         void Save();
       string GetErrorTextForFile();
    }

Now we have come to our exception entity to be logged into the database. We will call that entity ExceptionLog and, by ORM techniques, it will be mapped to a database table. We want our exception logs to include useful information such as server name, type (warning, error etc.), stack trace message, occuredDate and any other pertinent data such as the member id of the user who has generated the exception.

    public class ExceptionLog : Entity, IQueueableMessage
    {
        private int _exceptionLogID;
        private string _message;
        private string _serverName;
        private string _type;
        private int _memberID;
        
        public ExceptionLog()
        {
            // Construction method for your entity
        }
        
        public string GetErrorTextForFile()
        {
            string response = "ServerName: {0} \n Message: {1} \n MemberID: {2} \n Type: {3}";
            return String.Format(response, ServerName, Message, MemberID, Type);
        }
        public new void Save()
        {
            // Transaction should be handled in the service class.
            base.Save();
        
        }
     .
     .
     .
    }

Next, we will implement our Singleton Generic Typed Queue that will handle logging operations to the database. We call the class MessageLogger – remember that we want it to be used for any messages that we want to log to the database.

    public class MessageLogger<T> where T : IQueueableMessage
    {
        private bool isStarted = false;
        private Queue<T> queue;
        private object syncObject = new Object();
        private object syncObjectForOperations = new Object();
        private string _loggerNameDescriptor; // this is for debugging to see which logger is being processed

        public MessageLogger()
        {
            lock (syncObject)
            {
                if (queue == null)
                {
                    queue = new Queue<T>();
                }
            }
            _loggerNameDescriptor = AppDomain.CurrentDomain.FriendlyName;
        }
    .
    .
    .   
}
 

Our MessageLogger will contain the queue , which must be thread-safe, so we need to use a thread synchronization method. If your system has multiple tiers (Business application and Web application, for example), you will be dealing with two different MessageLoggers. This means our Singleton Queue is in the scope of the Application Domain, not in the system scope. So for debugging purposes, let’s put a string called _loggerNameDescriptor so that we can track which tier’s queue is processing. We also need to have a flag called isStarted to indicate if the Queue has already started processing.

public bool HasItems
{
    get
    {
        lock (syncObjectForOperations)
        {
            return queue.Count > 0;
        }
    }
}

public void Enqueue(T obj)
{
    lock (syncObjectForOperations)
    {
        queue.Enqueue(obj);
    }
}

private T Dequeue()
{
    lock (syncObjectForOperations)
    {
        return queue.Dequeue();
    }
}

protected virtual void WriteMessage(T t)
{           
    t.Save();
}
 

Our MessageLogger will have basic queue operations like Enqueue and Dequeue, supported with a HasItems property which returns the number of items in the queue, and a WriteMessage method which calls the Save() method of the class that implements IQueueableMessage. Everything seems correct thus far, but how do we get the queue to begin its processing? One way is a method that makes queue operations start in a separate thread and ensures that only one thread is used. Recall earlier we defined a flag isStarted as an instance variable so that we could verify that the logger has started by inspecting the flag.

public void EnsureLoggerStarted(){

            if (!isStarted) {
                try{
                    Thread td = new Thread(new ThreadStart(MessageLoggerThreadCall));
                    td.IsBackground = true;
                    td.Start();
                    isStarted = true;
                }
                catch
                {
                    isStarted = false;
                    WriteToLogFile("ERROR: Database Logger couldn't be started!");
                }
   }

private void WriteToLogFile(string exceptionMessage)
        {
            // Here goes your implementation of writing to file as “Plan B”
        }
  
}

EnsureLoggerStarted() method is called from our Custom Trace Listener and is called only once during the application’s lifetime. For our mechanism’s high reliability property to be satisfied, logging to a file or an event viewer is suggested in the event that database logging fails. This can be easily accomplished by implementing the WriteToLogFile(string msg) method. Now we must implement the method MessageLoggerThreadCall which contains the main logic of logging and is called from the EnsureLoggerStarted method. For our mechanism’s high performance property, we want to sleep the queue operations for some time if no message is being enqueued. For this purpose, we must define an integer constant as an instance variable called INTERVALLIMIT.

    public class MessageLogger<T> where T : IQueueableMessage
        {
            const int INTERVALLIMIT;
        .
        .    
            
    }

We will start with a zero millisecond sleep time at the beginning. As the loop to check if items exist in the queue continues and no items are being enqueued, the time to sleep will be increased (in our example, it is multiplied by 2, assigning an initial value of 25 ms) and will have the limit of INTERVALLIMIT we defined. This limit value should be decided according to how much of a delay the system can tolerate on messages being logged.

 private void MessageLoggerThreadCall()
        {
            var timer = 0;

            while (true)
            {
                Thread.Sleep(timer);
                if (HasItems)
                {
                    timer = 0;
                    T t = Dequeue();
                    if (t != null)
                    {
                        try
                        {
                            WriteMessage(t);
                        }
                        catch (Exception ex)
                        {
                            WriteToLogFile(ex.ToString());
                            WriteToLogFile(t.GetErrorTextForFile());
                        }
                    }
                }
                else
                {
                    if (timer < IntervalLimit)
                    {
                        if (timer == 0)
                            timer = 25;
                        else
                            timer *= 2;
                    }
                    else
                    {
                        timer = IntervalLimit;
                    }
                }

            }
        }

Finally, we need to implement our custom TraceListener. TraceListener will instantiate our MessageLogger<t> object, listen for any Trace information generated in the system, and enqueue them into our MessageLogger. Also, don’t forget to enable your trace listener from the application’s config file.

public class CustomTraceListener : TraceListener
    {
        static MessageLogger<exceptionlog> messageLogger;
        public CustomTraceListener(String initializeData)
        {
            messageLogger = new MessageLogger<exceptionlog>();
            messageLogger.EnsureLoggerStarted();
            
        }        
       
        /// <summary>
        /// Write a line into the output stream.
        /// </summary>
        /// <param name="message" /> 
        public override void WriteLine(string message)
        {
             ExceptionLog exc = new ExceptionLog(true);
             // exc.MemberID = implement your own here
             exc.Message = message;
             exc.ServerName = System.Environment.MachineName;
             exc.Type = AppDomain.CurrentDomain.FriendlyName;

             messageLogger.Enqueue(exc); 
        }
                
        public override void Write(string message)
        {
            this.WriteLine(message);
        }
    }

 

5. References

Writing custom .NET trace listeners
A C# Central Logging Mechanism using the Observer and Singleton Patterns
Exception handling