Logging Your Application for Fun and Profit Part 1
When writing applications, I often have a good idea about what
it's supposed to be doing when it's running, after all I wrote/helped write the
darn thing. But once you start adding WCF services, databases, authentications,
and other things not controlled directly by you, it's hard to make sure the
program you wrote is working like you intended it to. Was the WCF call
successful? Was the database authenticated successfully? Naturally, if your
application is working then everything is doing what you programed it to. But
when it's not - and there will be times it doesn't - it's good to know where
the problem lies, and what caused it.
In the past, I've had several instances when I was sitting
at my desk and someone would come over and say "Casey! Your death ray
controller application is down!" in which I would proceed to spend time
debugging the application to find out why it all of a sudden wasn't working
when it used to. Maybe the database is down... maybe the host machine ran out of
resources... maybe there was a change to a server that caused one of my
components to break. It was usually something odd. But the problem wasn't that
it broke, the problem was the length of time it took to find what the problem
was. "What do you mean you have no idea?!" They would say. "You WROTE the
program!"
Soon I learned that adding some logging to the application
can QUICKLY shorten the time it takes to determine what the problem is. It also
helps to give you some piece of mind that the application is running, so you
can feel comfortable handing the application off to someone else.
There are a couple of different ways of logging your application,
and a couple of different situations in which you should do the logging. For
logging you have: Event Logs, DebugView, text file, web page, and console.
Event Logs are the least helpful to other programmers, but most helpful to
admins. The opposite is true for DebugView. Text files, web pages, and the
console works good also for some cases and can be a helpful way to check the
status of your application.
So let's make a class called "DeathRayController", and do
some logging against it...
class DeathRayController
{
public DeathRayController() { }
public void Zap()
{
if (IsDeathRayConnected() == true & IsDeathRayTempOkay() == true)
{
Console.WriteLine("ZZZZZAAAAAPPPPPP!!!!");
}
}
private bool IsDeathRayTempOkay()
{
//Since we don't have an ACTUAL death ray (yet), lets simulate some conditions...
Random rnd = new Random(DateTime.Now.Millisecond);
int action = rnd.Next(0, 20);
if (action <= 5) { return false; } //Death Ray is too hot! Can't use!
if (action == 13) { throw new DeathRayOutOfMemoryException(); } //Weird exception we dont handle...
return true;
}
private bool IsDeathRayConnected()
{
//again, no death ray, so lets simulate some conditions.
Random rnd = new Random(DateTime.Now.Millisecond);
int action = rnd.Next(0, 20);
if (action == 5 | action == 7 | action == 14) { throw new UnableToConnectToDeathRayException(); } //unable to connect!
return true;
}
}
public class UnableToConnectToDeathRayException : Exception { }
public class DeathRayOutOfMemoryException : Exception { }
...and then we run through it 10 times...
static void Main(string[] args)
{
DeathRayController dr = new DeathRayController();
for (int i = 0; i < 10; i++) //Lets use the Death Ray 10 times!
{
dr.Zap();
Console.WriteLine();
System.Threading.Thread.Sleep(1000); //Just wait a bit...
}
}
Now
when we run this, a few things can happen. We could see a console
output ZZZZZAAAAAPPPPPP!!!!, or we can see nothing, or we throw an
exception.
If
this is a console application, we can just display the problem on the
console, and hope then when it's run, someone will see this. If it's a
service though (death ray service?), nobody will get to see a console,
or maybe it's run on a remote machine somewhere that's not always
monitored (on the moon!)
This is when logging comes in handy.
Let us create a logging class, something that we can use for... logging.
class Logger
{
public static void LogError(string message)
{
Console.WriteLine("ERROR: " + message)
}
}
Then,
we can alter our DeathRayController class to take advantage of the
logging, here I've altered the IsDeathRayTempOkay class...
private bool IsDeathRayTempOkay()
{
//Since we don't have an ACTUAL death ray (yet), lets simulate some conditions...
try
{
Random rnd = new Random(DateTime.Now.Millisecond);
int action = rnd.Next(0, 20);
if (action <= 5)
{
Logger.LogError("Death Ray is too hot, please wait for cooling.");
return false;//Death Ray is too hot! Can't use!
}
if (action == 13)
{
throw new DeathRayOutOfMemoryException(); //Weird exception we dont handle...
}
}
catch (DeathRayOutOfMemoryException)
{
Logger.LogError("Exception Thrown! Death Ray is out of memory!");
}
return true;
}
I've highlighted the area of my code when we access our logger.
Again, it's only going to log to the console. But that's okay for now...
lets see this thing in action...
Okay! now we see how our our logger is logging to the console... Lets expand it a little bit, and write to the DebugView.
What the heck is the DebugView?
Debug view is part of the SysInternals that you can download from technet here.
The benefit to DebugView, is you can write to the debugger and it will
display live on the DebugView application. No need for the console, and
you can access it from a different machine! Let's alter our class so we
can take advantage of the DebugView application.
First, we need to add a reference to
System.Diagnostics;
...and then all we have to do is add a new line to our class...
public static void LogError(string message)
{
Console.WriteLine("ERROR: " + message);
Debug.Write(message, "DeathRayControllerERROR");
}
now, if we open up DbgView, and run our application a few times, we can see the log that's produced:
As you can see, we get all the benefits of console-like logging
without even having a console window. Again, this works great when you
have an application that doesn't open in a console window, or isn't
installed on a machine that you have access to. Just like a console
window, you can see this live as the application is running. The problem
is, of course, it wont tell you what WAS happening, only what IS
happening. Though the DbgView still has it benefits to being used. For
knowing what HAS happened, you need to either write to a text file, or
write to the event log.
In Part 2, I will discuss connecting to the Event Log...