Geek Speak: How to Create a Testable SQL Trace Listener
In some situation, logging to the file system or to the event log, may not be sufficient to handle your error handling needs. For us at Microsoft, that is the case. Our production applications are “hands-off”, we don’t have physical access to the machines. Our primary way for developers to determine the activity of the application is through SQL. This example will show you how to create a “Testable” SQL logger with Unit Tests.
(! Please note this is a long Post!!! ) Attached at the bottom is the source code.
This implementation will be a basic implementation of the SQL Logger. We will be expanding on this implementation next time. The application that we are implementing is using Model-View-Presenter. Jeffrey Palermo (https://codebetter.com/blogs/jeffrey.palermo/archive/2005/04/02/128598.aspx) has a great diagram that describes better the architecture than me describing it.
1) Create ILogger Provider
First, I need to create an interface for the database, and since I want to keep it simple, I will use an object to pass information back and forth from my data layer.
namespace Listeners
{
public interface ILoggerProvider
{
void WriteMessage(LogMessage logMessage);
}
}
2) Create LogMessage object ( Domain / Business Object)
Using the above as my interface, I need to define my business object that will hold the information. The sole purpose is to be just a container. All of the important logic will be handled before the information is stuffed into the object. We are just going to cover the simplest, a message and a category.
public class LogMessage
{
private string message;
private string source;
private DateTime msgTime;
public LogMessage(string msg,string src,DateTime logTime)
{
message = msg;
source = src;
msgTime = logTime;
}
public string Message
{
get { return message; }
set { message = value; }
}
public string Source
{
get { return source; }
set { source = value; }
}
public DateTime MessageTime
{
get { return msgTime; }
set { msgTime = value; }
}
}
3) Implement SqlLogger
Now we are ready to get started to do some real work. The next step is to create the actual class that will be doing the logging. In this example, this class will be called SqlLogger. Because, we are going to use the System.Diagnostics Trace classes, this class must derive from System.Diagnostics.TraceListener.
namespace Listeners
{
public class SqlLogger : TraceListener
{
private ILoggerProvider dataprovider;
public SqlLogger(ILoggerProvider provider)
{
dataprovider = provider;
}
public override void Write(string message)
{
this.WriteLine(message);
}
public override void Write(string message, string category)
{
this.WriteLine(message, category);
}
public override void WriteLine(string message, string category)
{
LogMessage msg =
new LogMessage(message, category, DateTime.Now);
dataprovider.WriteMessage(msg);
}
public override void WriteLine(string message)
{
this.WriteLine(message, string.Empty);
}
}
}
You will notice that my constructor, is so that I can pass my data provider. This gives the flexibility for testing or changing the data source. In the most basic implementation, you have to implement the Write(string message) and WriteLine(string message) functions from the TraceListener object. You will notice that all of the Write and WriteLine implementations actually are in a pair, so remember when you implement one you need to implement the other. You will notice in my implementation, only one method is actually doing any work. The others are must filling in information.
4) Create SqlLogger Test
We are now ready to show the test that will test some of the functionality, note – these are not complete, there are many more test that need to be here just for this simple implementation. ( That will come later in another example.) The following is the test for this class.
namespace ListenerTests
{
[TestClass]
public class SqlLoggerTest
{
public SqlLoggerTest() { }
private class MockLogProvider : ILoggerProvider
{
public LogMessage ExpectedMessage;
#region ILoggerProvider Members
public void WriteMessage(LogMessage logMessage)
{
TestingHelpers.CompareLogMessages(ExpectedMessage, logMessage);
}
#endregion
}
[TestMethod]
public void ShouldCreateMessageUsingWriteWithMessageOnly()
{
MockLogProvider provider = new MockLogProvider();
SqlLogger logger = new SqlLogger(provider);
string message = "Sample Message";
provider.ExpectedMessage = new LogMessage(message, string.Empty, DateTime.Now);
logger.Write(message);
}
[TestMethod]
public void ShouldCreateMessageUsingWriteWithMessageAndCategory()
{
MockLogProvider provider = new MockLogProvider();
SqlLogger logger = new SqlLogger(provider);
string message = "Sample Message";
string category = "Sample Category";
provider.ExpectedMessage = new LogMessage(message,category, DateTime.Now);
logger.Write(message,category);
}
[TestMethod]
public void ShouldCreateMessageUsingWriteLineWithMessageOnly()
{
MockLogProvider provider = new MockLogProvider();
SqlLogger logger = new SqlLogger(provider);
string message = "Sample Message";
provider.ExpectedMessage = new LogMessage(message, string.Empty, DateTime.Now);
logger.WriteLine(message);
}
[TestMethod]
public void ShouldCreateMessageUsingWriteLineWithMessageAndCategory()
{
MockLogProvider provider = new MockLogProvider();
SqlLogger logger = new SqlLogger(provider);
string message = "Sample Message";
string category = "Sample Category";
provider.ExpectedMessage = new LogMessage(message, category, DateTime.Now);
logger.WriteLine(message, category);
}
}
}
4a) Implement custom ILoggerProvider for testing
The most important part of these test are the fact that I am using my own implementation of the ILoggerProvider. I would love to say that I came up with this idea, but I did not. I actually stole the idea from Jim Newkirk (See below)
private class MockLogProvider : ILoggerProvider
{
public LogMessage ExpectedMessage;
#region ILoggerProvider Members
public void WriteMessage(LogMessage logMessage)
{
TestingHelpers.CompareLogMessages(ExpectedMessage, logMessage);
}
#endregion
}
This allows the separation of checking the logger against information and not having to use SQL as part of the test. Actually, SQL will come later as part of the test. Now with this framework, I can implement all of the methods that I choose from the TraceListener and I don’t have to worry about other stuff yet. (This is were we will make significant improvements next time). We will implement more part of the Trace Listener and adjust our LogMessage object in the process.
4b) Create shared Testing Library
One of the things that you will notice is that I am not doing object comparisons, using Trace.AreEqual(). I like to do a property by property comparison. This allows me to check for other things also. The following is the class that has my common helpers for my test.
namespace ListenerTests
{
public static class TestingHelpers
{
public static void CompareLogMessages(LogMessage expected,LogMessage actual)
{
Assert.IsNotNull(expected);
Assert.IsNotNull(actual);
Assert.AreEqual(expected.Message, actual.Message);
Assert.AreEqual(expected.Source, actual.Source);
Assert.AreEqual(expected.MessageTime.ToString(), actual.MessageTime.ToString());
}
}
}
As I modify my LogMessage object, I just have one place to make adjustments for my comparisons. So, when you are done with this process, you will have a stable Logger object and LogMessage object. With this information you can now implement, the SQL data provider. Since our interface is very simple to the data provider, there is only one main method, and there will be a couple of support methods, that can be used how ever you need to.
namespace Listeners
{
public class SqlDataLogProvider : ILoggerProvider
{
private string connectionString;
public SqlDataLogProvider(string ConnectionName)
{
connectionString = ConfigurationManager.ConnectionStrings[ConnectionName].ConnectionString;
}
#region ILoggerProvider Members
public void WriteMessage(LogMessage logMessage)
{
SqlConnection con = new SqlConnection(connectionString);
con.Open();
SqlCommand cmd = new SqlCommand("INSERT INTO MessageLog (Message,Source,LogTime) VALUES (@Message,@Source,@LogTime)", con);
cmd.Parameters.Add(new SqlParameter("@Message", logMessage.Message));
cmd.Parameters.Add(new SqlParameter("@Source", logMessage.Source));
cmd.Parameters.Add(new SqlParameter("@LogTime", logMessage.MessageTime));
cmd.ExecuteNonQuery();
cmd.Dispose();
con.Close();
con.Dispose();
}
#endregion
public List<LogMessage> FetchMessages()
{
DataSet ds = new DataSet();
List<LogMessage> list = new List<LogMessage>();
SqlDataAdapter da = new SqlDataAdapter("Select * from MessageLog", connectionString);
da.Fill(ds);
foreach (DataRow dr in ds.Tables[0].Rows)
{
list.Add(new LogMessage(dr["Message"] as string,dr["Source"] as string,(DateTime)dr["LogTime"]));
}
return list;
}
public void DeleteMessages()
{
SqlConnection con = new SqlConnection(connectionString);
con.Open();
SqlCommand cmd = new SqlCommand("Delete FROM MessageLog", con);
cmd.ExecuteNonQuery();
cmd.Dispose();
con.Close();
con.Dispose();
}
}
}
So, from my above implementation, I have one method from the interface ILoggerProvider, the others are for my case, testing. I wrote separate test that show if I have my data correctly setup.
namespace ListenerTests
{
/// <summary>
///This is a test class for Listeners.SqlDataLogProvider and is intended
///to contain all Listeners.SqlDataLogProvider Unit Tests
///</summary>
[TestClass()]
public class SqlDataLogProviderTest
{
private SqlDataLogProvider target;
[TestInitialize()]
public void MyTestInitialize()
{
target = new SqlDataLogProvider("TestDb");
}
//
//Use TestCleanup to run code after each test has run
//
[TestCleanup()]
public void MyTestCleanup()
{
target.DeleteMessages();
}
//
#endregion
#region Constructor Test
/// <summary>
///A test for SqlDataLogProvider ()
///</summary>
[TestMethod()]
public void ConstructorTest()
{
SqlDataLogProvider target = new SqlDataLogProvider("TestDb");
Assert.IsNotNull(target, "The SqlDataLogProvider class was not created correctly");
}
#endregion
#region Database Test
/// <summary>
///A test for WriteMessage (LogMessage)
///</summary>
[TestMethod()]
public void WriteMessageTest()
{
LogMessage expected = new LogMessage("TestMessage","Test Source",DateTime.Now);
target.WriteMessage(expected);
LogMessage actual = FetchTestData();
TestingHelpers.CompareLogMessages(expected, actual);
}
#endregion
#region Private Methods
private LogMessage FetchTestData()
{
List<LogMessage> messages = target.FetchMessages();
return messages[0];
}
#endregion
#region Integration Test with System.Diagnostics / Configuration
[TestMethod]
public void CreateMessageWithWriteWithMessageOnly()
{
LogMessage expected = new LogMessage("Test Message", string.Empty, DateTime.Now);
Trace.Write("Test Message");
LogMessage actual = FetchTestData();
TestingHelpers.CompareLogMessages(expected, actual);
}
[TestMethod]
public void CreateMessageWithWriteWithMessageWithCategory()
{
LogMessage expected = new LogMessage("Test Message", "Test Category", DateTime.Now);
Trace.Write("Test Message","Test Category");
LogMessage actual = FetchTestData();
TestingHelpers.CompareLogMessages(expected, actual);
}
[TestMethod]
public void CreateMessageWithWriteLineWithMessageOnly()
{
LogMessage expected = new LogMessage("Test Message", string.Empty, DateTime.Now);
Trace.WriteLine("Test Message");
LogMessage actual = FetchTestData();
TestingHelpers.CompareLogMessages(expected, actual);
}
[TestMethod]
public void CreateMessageWithWriteLineWithMessageWithCategory()
{
LogMessage expected = new LogMessage("Test Message", "Test Category", DateTime.Now);
Trace.Write("Test Message","Test Category");
LogMessage actual = FetchTestData();
TestingHelpers.CompareLogMessages(expected, actual);
}
#endregion
}
}
These test, are implemented by three different areas, which are being tested.
- Constructors
- Database Test
- Implementation With System.Diagnostics
For the first we are just making sure that the application will find the Sql Connection String correctly. I will need to create an App.Config file for my testing project and add the following.
<connectionStrings>
<add name="TestDb" connectionString="<Your Connection Information>" />
</connectionStrings>
After add this to the configuration the first two types of test will run correctly. But, the real test is the last set of test that is using the System.Diagnostics namespace. This is a true end to end test. As the SqlLogger class is currently implemented, it will not work for our integration test. We need to add some constructors to our class and add some more stuff to the configuration file.
-- Add the following to the configuration file
<system.diagnostics>
<trace>
<listeners>
<clear/>
<add name="SqlListener" type="Listeners.SqlLogger,Listeners" initializeData="TestDb"/>
</listeners>
</trace>
</system.diagnostics>
You will notice that there is an InitializeData tag added to our listener, this requires a constructor that takes a string method as follows.
public SqlLogger() { }
public SqlLogger(string arg) : this(new SqlDataLogProvider(arg)) {}
By adding this implementation, we now have a functional class that works end to end using the System.Diagnostics Trace/Debug methods which log to SQL.
I hope that this was helpful for you. Next time around we will gather Web information and show how it can be tested this implementation.