Tripping over logs: A story of Unity - Part 1
Welcome to the first part in my series on using Unity, which is a Dependency Injection or Inversion of Control tool/framework/thing from the p&p group. It’s a big and (over)complicated topic, so if what I have just said means nothing, fear not—it will all make sense soon. I have broken this into a series to make it easier to digest. What I am going to do is look at a practical approach to using Unity. I will not be going into DI or IoC—those topics have already been covered better by smarter people than me (links in Part 6). If you want the theory, look elsewhere; if you want to get running with Unity, this is for you.
This is a multi-part series, so here’s the series guide in case you’re looking for the rest:
- Part 1 – Introduction to the problem
- Part 2 – Changing the code to use basic Unity functions
- Part 3 – Lifetime management
- Part 4 – Changing the code to use interception
- Part 5 – Interception supplementary
- Part 6 – Wrap-up
The Problem
A few years back, I was developing an enterprise solution for a bank that integrated MSCRM](https://www.microsoft.com/dynamics/crm/default.mspx) into a number of systems—and so I needed to make sure I did logging (that’s what enterprise apps have, right?). Initially, I had a simple “write to text file” logging system, which worked fine on my machine. That is, until we started testing, ramped up usage, and hit concurrency and locking issues. That prompted me to rip out all the logging and use the logging within System.Diagnostics.Trace, as it seemed like it would work better—and it did, for a long time. At some point, I was pulled back into the project (I had left it for a while) and needed to change the logging to use the p&p [Enterprise Library logging. It was only then that I stopped calling System.Diagnostics.Trace directly in each place for logging and started calling a custom method. This is what it sort of looked like—except, I had many more parameters on the logging (log level, source component, etc.)—and we logged every time something changed, not just entry and exit:
public void DoSomething()
{
LogThis("Do Something Start");
// ...
LogThis("Do Something End");
}
When I changed it out, I did some number-crunching and realized that 40% of all the lines of code were these logging calls! I remember thinking how proud I was of my logging skills. Nowadays, I look back at that and laugh—not because I did logging, but because of how much code was spent on it and how tightly coupled it was. So how could I do it better today? Well, through a principle called Dependency Injection and an implementation of it called Unity (from the p&p team in their Enterprise Library).
Note: I’m using logging as the problem to solve, but really, DI can be applied anywhere.
I must admit that Unity is anything but simple—it’s one of the hardest things I’ve had to learn in a while. What made it tough was understanding the documentation, which enables you to learn Unity, but you need to understand Unity first to understand the documentation—talk about a catch-22! It’s odd because other blocks in EntLib are easy to get up and running, but with Unity, the samples are confusing and the documentation even more so. In the end, some search kung fu + luck + patience seems to be what’s needed to get through it. That said, I feel a simple series of blog posts may help others out—which is exactly what this is!
Starting Block
A special note: this series is heavy with code, making the articles look long—but actually, I’m repeating the code each time so you can compare the changes easily.
Let’s start with a simple application as our base to make it clear what we have and what we’ll change to get Unity working. As those who attend any of my sessions know, I love console apps—so I’ve whipped up a simple one that writes to the screen. The code looks like this:
using System;
namespace BigSystem
{
class Program
{
static void DoSomething(string Username)
{
Console.WriteLine("Hello {0}", Username);
}
static void Main(string[] args)
{
DoSomething("Robert");
Console.ReadKey();
}
}
}
And the solution looks like this (note the references—super clean):
Now, using my “enterprise skills” from earlier, we add some logging like so:
static void LogThis(string Message)
{
System.Diagnostics.Debug.WriteLine(String.Format("{0}: {1}", DateTime.Now, Message));
}
static void DoSomething(string Username)
{
LogThis("DoSomething Called with Username Parameter set to:" + Username);
Console.WriteLine("Hello {0}", Username);
LogThis("DoSomething Completed");
}
static void Main(string[] args)
{
LogThis("Application started");
DoSomething("Robert");
Console.ReadKey();
LogThis("Application Completed");
}
Right, so that code isn’t bad—it works, which makes the (imaginary) customer happy. But it’s also not good, because if we want to change anything, it’s a huge issue—likely solved by a global find-and-replace. A better approach would be to extract logging into a separate class that implements an interface. That way, we create the class once and change it in a single place to affect all the code. So, it would look like this:
class Program
{
static ILogger logger = new DebugLogger();
static void DoSomething(string Username)
{
logger.LogThis("DoSomething Called with Username Parameter set to:" + Username);
Console.WriteLine("Hello {0}", Username);
logger.LogThis("DoSomething Completed");
}
static void Main(string[] args)
{
logger.LogThis("Application started");
DoSomething("Robert");
Console.ReadKey();
logger.LogThis("Application Completed");
}
}
public interface ILogger
{
void LogThis(string Message);
}
public class DebugLogger : ILogger
{
public void LogThis(string Message)
{
System.Diagnostics.Debug.WriteLine(String.Format("{0}: {1}", DateTime.Now, Message));
}
}
Note the logger constructor and the interface/class below. The reason this is powerful is that if I wanted to change this to output to the console, I could spin up a new class and just change the constructor for logger, as shown below:
class Program
{
static ILogger logger = new ConsoleLogger();
static void DoSomething(string Username)
{
logger.LogThis("DoSomething Called with Username Parameter set to:" + Username);
Console.WriteLine("Hello {0}", Username);
logger.LogThis("DoSomething Completed");
}
static void Main(string[] args)
{
logger.LogThis("Application started");
DoSomething("Robert");
Console.ReadKey();
logger.LogThis("Application Completed");
}
}
public interface ILogger
{
void LogThis(string Message);
}
public class DebugLogger : ILogger
{
public void LogThis(string Message)
{
System.Diagnostics.Debug.WriteLine(String.Format("{0}: {1}", DateTime.Now, Message));
}
}
public class ConsoleLogger : ILogger
{
public void LogThis(string Message)
{
Console.WriteLine("{0}: {1}", DateTime.Now, Message);
}
}
This is great—but to change the type of logger, I still need to change the code. Wouldn’t it be better if:
- I could specify in a configuration file what should be used?
- Instead of instantiating a logger (like with the constructor), I could have a central “bag” where code could ask for a logger?
This is exactly what Unity provides at a basic level—and we’ll implement it in the next post. Trust me, it goes much further and becomes much more powerful.