Using Remoting to Implement Distrubuted Logging


In an earlier article we had discussed how new tracing and debugging techniques in .NET make debugging easier. In this article we will view the event logging API that comes with .NET. We will also create a small library that can be used in most enterprise level applications that overcome a few shortcomings of the standard .NET API for event logging.

Basic event logging 

All the classes required for logging events to the windows event log are in the System.Diagnostics package. The most important class is the EventLog class. This allows reading and writing of event log entries. However, before any logs can be written an EventSource must be defined. Thus, in the simplest of scenarios, the following needs to be done

  • Define (or create) an EventSource
  • Write event logs for this source using various methods of the EventLog class.

The source can also be defined (or created) during the writing itself. The API checks for the existence of the source and if none exists a source is created on the fly.

For reading event logs the EventLog class has a property called Entries which is a EventLogEntryCollection. As is obvious, this is a collection of EventLogEntry. Every entry is any event log is an instance of EventLogEntry. Along with some obvious properties, like Message and EventId it has an EntryType property. This is an enumeration which indicates the type of the event log. The different values of the Enumeration are Error, FailureAudit, Information, SuccessAudit and Warning. This allows grouping of log event entries into different levels of severity.

The following example code writes 10 event logs, reads them and prints them out on the console. The program also deletes the log, although in real life this is never done since you would want the log around for reviewing purposes.

using System;
using System.Diagnostics;
namespace EventsTest
{
class Test
{
[STAThread]
static void Main(string[] args)
{
// write the events
for(int i = 0; i < 10; i ++)
{
EventLog.WriteEntry("MyNewLog", "Message number " + i, EventLogEntryType.Information);
}
//read the events
EventLog log = new EventLog("MyNewLog");
foreach(EventLogEntry ei in log.Entries)
{
System.Console.WriteLine(ei.Message);
}
//delete the Log
EventLog.Delete("MyNewLog");
}
}
}

One important thing to notice is that almost all the methods have an override that takes a machine name. This allows a program to write to the event log of a remote machine. This is useful when many applications are logging to a central server.  

One interesting place where event logging is beneficial is the Application_Error method of an application in ASP.NET.

A single line of event logging can greatly ease tracking down of all exceptions that are not being specifically caught by the application code. The following line of code can be used.

EventLog.WriteEntry("MyLogname",Server.GetLastError().ToString(),EventLogEntryType.Error);

Limitations of .NET Logging API

Now that we have taken a look at what can be done let us see what cannot be done.

When event log is written using the standard NT API calls, the system stores a structure that contains, among other things, an integer, called the message identifier. It also stores any replacement strings - called inserts for the message - instead of storing the message text itself. There are three main advantages in doing things this way. Firstly, the message store now is significantly smaller also making logging operations faster. Secondly, just storing the message ID and replacement strings also means that the same message can be viewed in different languages if required. All that is required is the lookup table of the messages in the particular language desired. Lastly, different sections of programs (or different programs altogether) logging the same  event now do not have to worry whether they are sending the correct textual string for the message. In the next section when we develop our event logging library we will remedy this situation by allowing events to have a message id along with inserts. {It is intriguing that while the .NET API allows the reading of message ids and inserts from the in built Windows event logs, it does not allow writing such entries.}

Another problem that is usually faced with event logging is in distributed applications like a web farm scenario. In this case the disparate parts of an application are on different machines. If each application logs to its local event log then seeing the chronology of events would entail putting together event logs from all the machines. This could be a very cumbersome task. A better solution would be for all machines to write event logs to the  event log of a central machine. This however has the following shortcomings.

  • If we want to change the central event store to some other computer then we have to change the configurations on all machines that are logging. Not a pleasant scenario for application management.

  • Since now the central event log is logging events from many sources it can quickly grow very large which can affect its performance slowing down all applications logging to it. It may be necessary to consider a more sophisticated event store like a database. However, we cannot do this with the standard .NET event logging API.

  • Every computer now has to have permissions to access the central computer's event logs.

In the following section we develop a library that alleviates the above problems.

A distributed event logging library

The amount of code in this library is surprisingly small considering the amount of work it does. Let us first get a high level view of the classes involved and their relationships.

Every event is described by an Event class. Every application that needs to log events must define its event source described by the EventSource class. Thus, while EventSource  captures all data about the source, Event captures data about the individual events.

Every application logs events using the LocalEventLog class which is implemented as a singleton. The LocalEventLog does the job of buffering the logs of the events as they are generated by the application. This buffer is maintained as a hashtable of EventCollection. Each EventCollection buffers data from one EventSource only. Thus the LocalEventLog contains as many EventCollection as there are EventSource. When the buffer for a particular EventCollection is full it downloads all events in its buffer to a GlobalEventLog which is running on a remote machine. The communication between the local log and the global log is implemented using remoting. The GlobalEventLog then persists the events as necessary. It can persist them in one or more event stores if required.

The code for these classes is explained below.

The Event and EventSource classes come first. These are fairly simple classes with some readonly variables and a constructor. These can be modified as required to contain any other information about events as required. Notice that the  Event class does not have a message sting. Instead it has an eventid and an array of inserts. This is to make this event logger similar to NT event logging as described earlier. Also both these classes are marked Serializable since they need to be passed as arguments to a remote method call.

[Serializable]
public class EventSource
{
public readonly int ApplicationId;
public readonly string MachineName;
public readonly int ProcessId;
public EventSource(int appId)
{
ApplicationId = appId;
try
{
MachineName = System.Environment.MachineName;
ProcessId = System.Diagnostics.Process.GetCurrentProcess().Id;
}
catch { }
if(MachineName == null)
{
MachineName = "";
}
else
{
MachineName = MachineName.Trim();
}
}
}
[Serializable]
public class Event
{
public readonly int EventId;
public readonly long When;
public readonly string[] Inserts;
public Event( int eventId, string[] inserts)
{
EventId = eventId;
When = System.DateTime.Now.Ticks;
Inserts = inserts;
}
public override string ToString()
{
return EventId + ":" + new DateTime(When).ToString() + ":" + Inserts.ToString();
}
}

Once EventSource and Event is defined the EventCollection class almost writes itself. It has an array of Event and the EventSource that it represents passed to it in the constructor. It also has helper properties to check the state of the collection and a method to add events to this collection. It should be noticed that this class is not thread safe and synchronization is the responsibility of the caller.

public class EventCollection : IEnumerable
{
public const int SIZE = 10;
protected readonly EventSource _eventSource = null;
protected readonly Event[] _arrEvent = null;
protected int _eventCount = 0;
public EventCollection(EventSource source)
{
_eventSource = source;
_arrEvent = new Event[SIZE];
_eventCount = 0;
}
public EventSource EventSource
{
get
{
return _eventSource;
}
}
IEnumerator IEnumerable.GetEnumerator()
{
return _arrEvent.GetEnumerator();
}
public bool IsFull
{
get
{
return _eventCount >= _arrEvent.Length;
}
}
/// <summary>
/// This method is not thread safe. Thread safety is the responsibility of the caller.
/// </summary>
/// <param name="Event"></param>
internal void addEvent(Event event)
{
if (this.IsFull)
{
throw new Exception("Event Set full");
}
_arrEvent[_eventCount] = event;
_eventCount++;
}
internal void Clear()
{
_eventCount = 0;
}
}

Once EventCollection has been implemented it is time to implement the LocalEventLog that will use the EventCollection class to buffer the local events. This is also a fairly simple class as shown below. This class is implemented as a singleton with a property to access the singleton instance. It contains a hashtable of collections of events. The individual event collections are created as required. Almost all the work gets done in the LogEvent method. Here we check first to see if we need to create a new EventCollection. If we do, then an instance of EventCollection is created and added to the hashtable. Then the event is added to the collection. Of course, we check to see whether the buffer is full before adding to the set. If it is full the remote method is called to flush the set. The class also has an initialization method for setting up the remoting infrastructure.

public class LocalEventLog
{
private static LocalEventLog _instance = new LocalEventLog();
public static LocalEventLog Instance
{
get
{
return _instance;
}
}
private LocalEventLog()
{
}
private static string _GlobalLogUrl = "";
private static GlobalEventLog _GlobalLog = null;
private Hashtable _events = new Hashtable();
public static bool Init(string globalLogUrl)
{
_GlobalLogUrl = globalLogUrl;
TcpChannel chan = new TcpChannel();
ChannelServices.RegisterChannel(chan);
_GlobalLog = GlobalEventLog)Activator.GetObject(
typeof(DEvents.GlobalEventLog),_GlobalLogUrl);
return true;
}
/// <summary>
/// Possible enhancements: (a) The flushing can be done by a separate thread. Thn this thread just
/// creates another empty set and carries on. The flushing thread is handed over the full set
/// which flushes the events and destroys the set. (b) Instead of flushing to just one global log
/// the flushing could be done to many log listeners.
/// </summary>
/// <param name="s"></param>
/// <param name="e"></param>
public void LogEvent(EventSource s, Event e)
{
// get the event set for this source
// if none exist then create one
if(!_events.ContainsKey(s))
{
EventCollection eSet = new EventCollection(s);
_events.Add(s,eSet);
}
EventCollection currentSet = (EventCollection) _events[s];
// add the event to the set
// if the set is full flush this set to teh
// global sink
lock(currentSet)
{
if(currentSet.IsFull)
{
// Flush the events
foreach(Event ee in currentSet)
{
_GlobalLog.WriteLog(s, ee);
}
currentSet.Clear();
}
// add the event
currentSet.addEvent(e);
}
}
}

Now all that remains for our library is to implement the GlobalEventLog class. As is evident from the code above all we need is a method called WriteLog. This method can do pretty much whatever it wants. It can write the logs to a database and/or write to the Windows event log. For our present purpose of demonstration we just write to the console.

public class GlobalEventLog : MarshalByRefObject
{
public void WriteLog(EventSource s, Event e)
{
System.Console.WriteLine("Source: " + s.MachineName + ":" + e.ToString());
}
}

Now we are ready to test our library. We wrap it all in a namespace DEvents and compile it into a dll (and optionally register it with the GAC). The client code is as follows. All it does is create a bunch of events and logs them with the LocalLog.

using System;
using System.Configuration;
using System.Collections;
using DEvents;
namespace DEvents
{
public class Client
{
public static void Main(string[] args)
{
IDictionary config = (IDictionary) ConfigurationSettings.GetConfig("GlobalLog");
LocalEventLog.Init((string)config["url"]);
string[] inserts = {"Insert 1", "Insert 2"};
for(int i = 0; i < 100; i ++)
{
LocalEventLog.Instance.LogEvent(es,new Event(i,inserts));
}
}
}
}

This implementation requires a config file since we do not want to hardcode the remote logs url. The following config file can be used.

<configuration>
<configSections>
<section name="GlobalLog"type="System.Configuration.SingleTagSectionHandler" />
</configSections>
<GlobalLog url="tcp://GlobalLog:8085/LogEvent" />
</
configuration>

The server is equally simple. The only important thing is that the server is implemented as a singleton client. We use tcp as the protocol for remote communication. Obviously, http can also be used, but tcp provides much better performance and it is fair to assume that the applications are all on a local LAN where tcp will not have any problems.

using System;
using System.Runtime.Remoting;
using System.Runtime.Remoting.Channels;
using System.Runtime.Remoting.Channels.Tcp;
namespace DEvents
{
public class Server
{
public static void Main(string[] args)
{
TcpChannel chan = new TcpChannel(8085);
ChannelServices.RegisterChannel(chan);
RemotingConfiguration.RegisterWellKnownServiceType( typeof DEvents.GlobalEventLog), "LogEvent", WellKnownObjectMode.Singleton); System.Console.WriteLine("Hit to exit...");
System.Console.ReadLine();
}
}
}

Test Results

On running the client on two machines and the server on one we see the typical output on the server as shown below.

Source: UTPAL-NY1:13:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY1:14:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY2:15:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY2:16:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY2:17:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY1:18:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY1:19:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY1:20:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY2:21:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY1:22:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY1:23:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY2:24:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY2:25:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY1:26:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY2:27:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY1:28:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY1:29:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY2:30:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY1:31:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY2:32:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY1:33:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY2:34:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY1:35:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY2:36:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY1:37:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY1:38:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY2:39:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY1:40:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY2:41:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY2:42:12/18/2002 5:32:21 PM:System.String[]
Source: UTPAL-NY1:43:12/18/2002 5:32:21 PM:System.String[]

Enhancements to the library

For production purposes this library needs to be enhanced in the following way. 

  • The remote calls to global event log must be wrapped in an asynchronous remote call. This is important so that local logging calls can finish in a deterministic time instead of waiting for the remote call to finish.

  • Alternatively, the flushing of the logs to the global log can be done in a separate thread while the local event log call returns immediately. Another approach would be to have a producer-consumer model where a background thread continuosly flushes the buffer. In this implementation the buffer needs to be implemented as a FIFO queue where the local event logger writes to the tail of the queue and the buffer flushing thread logs the events to the global server by removing events fromt the head of the queue. The priority of this flushing thread can be adjusted depending on the length of the buffer.

  • Lastly, the global log can write to a whole set of LogListeners (which need to be defined). These can be dynamically added at runtime. The same strategy can also be applied to the local event log.

Conclusion

We saw how to use the standard event logging API of .NET to log events to the Windows event log. These classes can be helpful in monitoring applications and tracking down errors. However, the in built event logging API has a few drawbacks. We also created a small library to alleviate these that allow multiple machines to log to a central event log which can have one or more event stores.