Friday, October 16, 2020

Use MSMQ For Logging Errors And Informational Items

I was involved in writing a Windows Service application several years ago, and one of the requirements was to have a methodology for logging error messages and informational messages. For various reasons (which I won't go into in this blog post, as they are not relevant to the topic), we didn't want to write to the Windows Event Log. Instead, we opted to write such messages into a SQL Server database table.

We needed "must deliver" capabilities for these messages ... by that I mean that if something went wrong with the application, the messages still needed to be able to be "delivered" to the database, which we accomplished by Transactions and Message Queuing (MSMQ). By making the MSMQ queue "transactional", messages would remain in the queue until able to be delivered to the database.

There are two parts to this process.

  • First, there's a class I'll call OutputLog, containing static properties and methods. This class allows you to easily send a message (composed of a string of information and an optional category) to a queue (MSMQ) by calling a static method, WriteLog("your message") from any place in your application.

  • Second, there's a class I'll call ProcessLog, which is a continuously running Thread that reads from the MSMQ queue and writes the message to a database. In the examples I'll show, it's simply doing a Console.WriteLine() rather than messing with a database (I've shown commented-out code for the database parts).

I have put all of this example into a solution that you can download and run to see it in action. You can download it here: 

We needed "must deliver" capabilities for these messages ... by that I mean that if something went wrong with the application, the messages still needed to be able to be "delivered" to the database, which we accomplished by Transactions and Message Queuing (MSMQ). By making the MSMQ queue "transactional", messages would remain in the queue until able to be delivered to the database.

There are two parts to this process.

  • First, there's a class I'll call OutputLog, containing static properties and methods. This class allows you to easily send a message (composed of a string of information and an optional category) to a queue (MSMQ) by calling a static method, WriteLog("your message") from any place in your application.

  • Second, there's a class I'll call ProcessLog, which is a continuously running Thread that reads from the MSMQ queue and writes the message to a database. In the examples I'll show, it's simply doing a Console.WriteLine() rather than messing with a database (I've shown commented-out code for the database parts).

I have put all of this example into a solution that you can download and run to see it in action. You can download it here: 

We needed "must deliver" capabilities for these messages ... by that I mean that if something went wrong with the application, the messages still needed to be able to be "delivered" to the database, which we accomplished by Transactions and Message Queuing (MSMQ). By making the MSMQ queue "transactional", messages would remain in the queue until able to be delivered to the database.

There are two parts to this process.

  • First, there's a class I'll call OutputLog, containing static properties and methods. This class allows you to easily send a message (composed of a string of information and an optional category) to a queue (MSMQ) by calling a static method, WriteLog("your message") from any place in your application.

  • Second, there's a class I'll call ProcessLog, which is a continuously running Thread that reads from the MSMQ queue and writes the message to a database. In the examples I'll show, it's simply doing a Console.WriteLine() rather than messing with a database (I've shown commented-out code for the database parts).

I have put all of this example into a solution that you can download and run to see it in action. You can download it here:

ConsoleMSMQLogging 

The code in the downloaded project has comments, that are hopefully self-explanatory. But I'm going to show bits and pieces of it here as well. So now, let's see some code.

First, the OutputLog class. You can see from this code that everything is static.

 

// For MSMQ, be sure to add: using System.Messaging;
// You may also have to add it to your Project's references, it's not one of the normal references
//
// For the DataContract (in DataLog class), add: using System.Runtime.Serialization;
// Make sure to add it to your Project's references also.
public class OutputLog
{
#region Declarations/Properties

// The MSMQ name *must* start with ".\\private$\\"
protected static string m_QueueName = ".\\private$\\MyApplication.Shared.OutputLog";
public static string QueueName
{
get { return m_QueueName; }
// If you want a different queue name for different purposes
set { m_QueueName = m_QueueName.Replace("Shared", value); }
}
// Since messages are written to the database, we must have the Connection String set
// So, this is a good spot to set up the Message Queue while we're at it
protected static string m_LoggingConnectionString;
public static string LoggingConnectionString
{
get { return m_LoggingConnectionString; }
set
{
m_LoggingConnectionString = value;
SetupQueue(QueueName);
}
}
public static MessageQueue OutputQueue { get; set; }

// private
private static object lockobject = new object();

#endregion

#region Methods

//public
public static void WriteLog(string message)
{
Send(new DataLog(DateTime.Now, message));
}
public static void WriteLog(string message, string category)
{
Send(new DataLog(DateTime.Now, message, category));
}

//protected
protected static void Send(DataLog data)
{
System.Messaging.Message msg = new Message(data);
Send(msg);
}
protected static void Send(System.Messaging.Message msg)
{
if (OutputQueue == null)
return;
lock (lockobject)
{
using (MessageQueueTransaction tx = new MessageQueueTransaction())
{
tx.Begin();
try
{
OutputQueue.Send(msg, tx);
tx.Commit();
}
catch (Exception ex)
{
tx.Abort();
}
}
}
}
protected static void SetupQueue(string QueueName)
{
if (!MessageQueue.Exists(QueueName))
{
// The true parameter makes it transactional
MessageQueue.Create(QueueName, true);
}
OutputQueue = new MessageQueue("FormatName:DIRECT=OS:" + QueueName);
OutputQueue.Formatter = new XmlMessageFormatter(new Type[] { typeof(DataLog) });
OutputQueue.MessageReadPropertyFilter = SettingsForQueue.SetPropertyFilter();
}
#endregion
}

Two other classes are needed by the OutputLog class (and also needed by the ProcessLog class, which I'll show after these two): the DataLog class (which is a serializable object that contains the data that gets written to the database), and a SettingsForQueue class (which sets a MSMQ MessagePropertyFilter for the Queue you are creating):

[DataContract(Namespace = "http://MyCompanyName")]
[Serializable]
public class DataLog
{
private static object lockobject = new object();
[DataMember]
public DateTime LogTime { get; set; }
[DataMember]
public string Message { get; set; }
[DataMember]
public string Category { get; set; }

public DataLog() { }
public DataLog(DateTime time, string message)
{
lock (lockobject)
{
LogTime = time;
Message = message;
Category = "";
}
}
public DataLog(DateTime time, string message, string category)
{
lock (lockobject)
{
LogTime = time;
Message = message;
Category = category;
}
}
}
public class SettingsForQueue
{
public static MessagePropertyFilter SetPropertyFilter()
{
MessagePropertyFilter filter = new MessagePropertyFilter();
filter.SetDefaults();
filter.AppSpecific = true;
filter.Label = true;
filter.Priority = true;
filter.Extension = true;
filter.SentTime = true;
filter.ArrivedTime = true;
filter.Id = true;
filter.CorrelationId = true;
filter.SourceMachine = true;
return filter;
}
}

And now, the ProcessLog class:

public class ProcessLog
{
private Thread ProcessThread;
private bool EndLoop = false;
private bool IsStarted = false;
private MessageQueue ProcessQueue;
private string QueueName;
private TimeSpan TimeoutInterval = TimeSpan.FromMilliseconds(1000);

public ProcessLog()
{
ThreadStart threadStart = new ThreadStart(RunThread);
this.ProcessThread = new Thread(threadStart);
}

// Public Methods
public virtual void Start()
{
if (!this.IsStarted)
{
QueueName = OutputLog.QueueName;
if (!MessageQueue.Exists(QueueName))
{
MessageQueue.Create(QueueName, true);
}
ProcessQueue = new MessageQueue("FormatName:DIRECT=OS:" + QueueName);
ProcessQueue.Formatter = new XmlMessageFormatter(new Type[] { typeof(DataLog) });
ProcessQueue.MessageReadPropertyFilter = SettingsForQueue.SetPropertyFilter();
this.ProcessThread.Start();
}
this.IsStarted = true;
}
public virtual void Stop()
{
this.EndLoop = true;
this.IsStarted = false;
}

// Private Methods
private void RunThread()
{
while (!this.EndLoop)
{
Thread.Sleep(500); // sleep 500 milliseconds, so the CPU doesn't churn constantly

// And now we'll do the work
try
{
// see my blog post about creating a Utility class to make this less messy:
// http://geek-goddess-bonnie.blogspot.com/2010/12/transactionscope-and-sqlserver.html
// If you already have a Utility class, add a static GetTransactionScope() method with these settings:
// (TransactionScopeOption.Required, new TransactionOptions() { IsolationLevel = IsolationLevel.ReadCommitted }))
using (TransactionScope scope = new TransactionScope()) // you really want to use some options, like above
{
try
{
System.Messaging.Message msg = ProcessQueue.Receive(TimeoutInterval, MessageQueueTransactionType.Automatic);
DataLog data = (DataLog)msg.Body;
if (this.Save(data))
scope.Complete();
else
{
Thread.Sleep(1000);
}
}
catch (MessageQueueException ex)
{
if (ex.MessageQueueErrorCode != MessageQueueErrorCode.IOTimeout)
Console.WriteLine(ex.MessageQueueErrorCode + ": " + ex.Message);
}
catch (Exception ex)
{
Console.WriteLine(ex.Message);
}
}
}
catch (Exception ex)
{
Console.WriteLine(ex.Message);
}
}
}
private bool Save(DataLog data)
{
// For the purposes of illustrating how this works, I'll *not* actually write to a database,
// but the database code is here, commented, if you want to use it

Console.WriteLine($"{data.Message}");
if (string.IsNullOrWhiteSpace(data.Category))
Console.WriteLine($"{data.LogTime}");
else
Console.WriteLine($"{data.LogTime} \t {data.Category}");
return true;

//try
//{
// using (SqlConnection Connection = new SqlConnection(LogOutput.TrackingConnectionString))
// {
// SqlCommand Command = new SqlCommand();
// Command.Connection = Connection;
// Command.CommandType = CommandType.StoredProcedure;
// Command.CommandText = "usp_logdataput"; // write your own Stored Proc or simply use an INSERT INTO with parameters
// Command.Parameters.AddWithValue("@logdatetime", data.LogTime);
// Command.Parameters.AddWithValue("@message", data.Message);
// Command.Parameters.AddWithValue("@category", data.Category);
// Command.Parameters.AddWithValue("@machine", Environment.MachineName);
// Connection.Open();
// Command.ExecuteNonQuery();
// return true;
// }
//}
//catch (Exception ex)
//{
// Console.WriteLine(ex.Message);
// Thread.Sleep(30000);
// return false;
//}
}
}

OK, so now how do run this process? As mentioned in the comments in the code for the ProcessLog class, I'm not going to actually write to the database in this example. However, if you look at the OutputLog class, you'll see that the LoggingConnectionString property needs to be set, since it's in that property's setter that the Queue is created and configured. So, here's how we get the thing started:


OutputLog.LoggingConnectionString = "";

// Again, for illustration purposes, I will simply be spinning off a thread, that will always be running
// The thread's purpose is to simply read data off the Queue and write the data to the database
// In reality, my own Windows Service application has many "processor" threads that process data coming from many places

ProcessLog processLog = new ProcessLog();
processLog.Start();

// OK, now that the thread has started, we've got to give it something to do.
// Let's test it by logging some messages
for (int i = 0; i < 100; i++)
{
OutputLog.WriteLog("This is Message #" + i);
}

 

Those messages are getting written to the MSMQ queue by the OutputLog class.

Then the processLog thread that we just started pops them off the queue and displays them in the Console window.

 

// Hit Any Key to stop, after you've seen all the messages displayed
Console.ReadKey();
processLog.Stop();

You can take a look and see them in the MSMQ queue in Message Queuing | Private Queues from the Computer Management application (run compmgmt from another command window, or a right-click on the Start, which should have it). If you look before they are all processed, you'll see how many remain in the queue (and you can refresh the queue, to see them disappearing as they are popped off), as you can see from this screenshot:

You can also see how they stay in the queue waiting to be delivered if you stop the process before they are all displayed! Of course, after you restart it, you'll get 100 more messages dumped in the queue. Do it enough times, without letting them all get processed, and you'll start to have a lot of messages in that queue. Not a problem, you can simply right-click on the "Queue messages", under your Queue and choose "All Tasks | Purge", as shown in this screenshot:

Even though this thread is running constantly in a while loop, you can see from the screenshot below, that it's barely taking up any CPU cycles (less than 1% ... it varied, but never much more than what you see here). This is because we sleep the thread for 500 milliseconds in between each loop iteration. It doesn't have to be 500 milliseconds ... longer or shorter is fine ... but you *do* need to have a brief sleep, otherwise CPU usage would shoot up and you'd also have a tough time stopping the loop gracefully.

There is one more topic to cover and that is Distributed Transactions. Both MSMQ and SQL Server are transactional in this scenario, and consequently once you actually throw SQL Server into the mix (which you can see, I've skillfully avoided in this example), the Transactions get elevated to distributed transactions and you can run into DTC issues, unless you've already configured DTC (Distributed Transaction Controller) to properly allow for distributed transactions. I just so happen to have a blog post about this, which should be useful:

https://geek-goddess-bonnie.blogspot.com/2020/10/configure-msdtc-for-distributed.html

Happy Coding!!   =0)

No comments:

Post a Comment