Error handling and logging
I don't think any "enterprise application" can truly be called "enterprise" if it doesn't handle errors well and notify someone to address them. In an ASP.NET site, there are basically two forms of errors—errors that you have caught, and the ones you couldn't. Pretty simple, right? Well, not so fast! Whether you have trapped an error or not, the user of your application is still going to end up with some form of disruption in their surfing experience. So we need a way to not only provide users with a smooth disruption but also to fix the disruption so that it doesn't happen again.
Error handling is the act of doing your best to trap expected or possible errors. It is also the act of not allowing ugly error messages to get in front of your customers. Logging is what we do with these errors so that we can fix them down the road.
Error handling
I am pretty sure that most of you are aware of how to catch an error using the familiar try/catch/finally syntax. To those of you who are not, it looks something like this:
try
{
//code to run
}
catch (Exception e)
{
//code to run when an error occurs
}
finally
{
//code to run after the try or catch statement is complete
// ** this code is always executed no matter what
}
But what about errors those occur outside of the environment? What do you do then to prevent users from seeing some crazy geeked out error message? The easiest thing to do in a web environment is to tap into the Application_Error event handler using the Global.asax file.
To implement this, let's first add a Global.asax file to our FisharooWeb project. Right-click on the FisharooWeb project and select Add | New Item and select the Global Application Class item (leave the default name of Global.asax). Once this is added, we will want to take a look at the Application_Error method. This is the event that is raised when an unhandled error occurs. We want to do two things in this method:
- We first want to log what happened so that we can fix it
- Then we want to redirect the user to a friendly error page
We have not yet built the Log class, so for now, we will utilize the Redirector class that we built earlier.
To get started, make sure that you are in the Global.asax.cs file. At the top of this file ensure that you have at least these three using statements:
using System; using Fisharoo.FisharooCore.Core; using StructureMap;
Then, navigate to the already created Application_Error method and enter the following code:
protected void Application_Error(object sender, EventArgs e)
{
//TODO: Add logging logic here.
IRedirector redir = ObjectFactory.GetInstance<IRedirector>();
redir.GoToErrorPage();
}
Note that I have entered a placeholder to remind us that we need to come back and add some logic for logging our errors somewhere. Then I used StructureMap to get an instance of IRedirector. As we currently have defined only one class, it will return the Redirector class. Earlier, we defined a GoToHomePage() method that simply sends users to the homepage (see the Wrap Everything section covered earlier for more on the Redirector). Now let's define the GoToErrorPage() method to handle this new redirection.
Open the Redirector.cs file and add the following method:
public void GoToErrorPage()
{
Redirect("~/Error.aspx");
}
As we are providing a way to send a user to an error page, we should also create an error page. Add a webform to the root of the FisharooWeb project named Error.aspx. For now, I have included a simple message in the body of the page. We can modify this later to something more explanatory.
<%@ Page Language="C#" MasterPageFile="~/SiteMaster.Master" AutoEventWireup="true" CodeBehind="Error.aspx.cs" Inherits="Fisahroo.FisharooWeb.Error" %> <asp:Content ContentPlaceHolderID="Content" runat="server"> An error has occured! </asp:Content>
Now, let's move on to how we can handle the logging section of error handling!
Logging
Logging can either be overly complex, or really easy. As I don't have loads of time on my hands, I usually opt not to reinvent the wheel whenever possible! So in this case, I will be using the log4net framework that provides an extensive set of tools for various forms of logging.
Note
For more information regarding the log4net project look here: http://logging.apache.org/log4net/
To get log4net working, you will need to copy the log4net dll and the log4net.xml files into your bin directory in the FisharooCore project. Once it is there, add a reference to log4net. Then you will need to create a log4net.config file in the root of your FisharooWeb project or in the bin directory of the FisharooWeb project. Here is what our config file looks like:
Note
For more information about log4net configuration, look here http://logging.apache.org/log4net/release/config-examples.html
<?xml version="1.0" encoding="utf-8"?>
<log4net debug="false">
<appender name="RollingFileAppender" type="log4net.Appender.RollingFileAppender">
<file value="Logs/log4net.log" />
<appendToFile value="true" />
<rollingStyle value="Size" />
<maxSizeRollBackups value="10" />
<maximumFileSize value="1000KB" />
<staticLogFileName value="true" />
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%d [%t] %-5p %c - %m%n" />
</layout>
</appender>
<appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%d [%t] %-5p %c - %m%n" />
</layout>
</appender>
<appender name="OutputDebugStringAppender" type="log4net.Appender.OutputDebugStringAppender">
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%-5p %m - %c -%n" />
</layout>
</appender>
<appender name="TraceAppender" type="log4net.Appender.TraceAppender">
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%d [%t] %-5p %c - %m%n" />
</layout>
</appender>
<appender name="AspNetTraceAppender" type="log4net.Appender.AspNetTraceAppender">
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%d [%t] %-5p %c - %m%n" />
</layout>
</appender>
<root>
<level value="DEBUG" />
<appender-ref ref="RollingFileAppender" />
<appender-ref ref="OutputDebugStringAppender" />
<appender-ref ref="ConsoleAppender" />
<appender-ref ref="TraceAppender" />
<appender-ref ref="AspNetTraceAppender" />
</root>
<logger name="StructureMap" additivity="false">
<level value="WARN"/>
appender-ref ref="OutputDebugStringAppender" />
<appender-ref ref="ConsoleAppender" />
</logger>
<logger name="NHibernate" additivity="false">
<level value="INFO"/>
<appender-ref ref="AspNetTraceAppender" />
</logger>
</log4net>
Now, we can create a class to help us interact with what log4net provides us. Here is the entire listing. It's a big one!
using System;
using System.Collections.Generic;
using System.IO;
using log4net;
using log4net.Appender;
using log4net.Config;
using log4net.Layout;
namespace Fisharoo.FisharooCore.Core.Impl
{
public static class Log
{
private static Dictionary<Type, ILog> _loggers = new
Dictionary<Type, ILog>();
private static bool _logInitialized = false;
private static object _lock = new object();
public static string SerializeException(Exception e)
{
return SerializeException(e, string.Empty);
}
private static string SerializeException(Exception e, string
exceptionMessage)
{
if (e == null) return string.Empty;
exceptionMessage = string.Format(
"{0}{1}{2}\n{3}",
exceptionMessage,
(exceptionMessage == string.Empty) ? string.Empty :
"\n\n",
e.Message,
e.StackTrace);
if (e.InnerException != null)
exceptionMessage = SerializeException(e.InnerException,
exceptionMessage);
return exceptionMessage;
}
private static ILog getLogger(Type source)
{
lock (_lock)
{
if (_loggers.ContainsKey(source))
{
return _loggers[source];
}
else
{
ILog logger = LogManager.GetLogger(source);
_loggers.Add(source, logger);
return logger;
}
}
}
/* Log a message object */
public static void Debug(object source, object message)
{
Debug(source.GetType(), message);
}
public static void Debug(Type source, object message)
{
getLogger(source).Debug(message);
}
public static void Info(object source, object message)
{
Info(source.GetType(), message);
}
public static void Info(Type source, object message)
{
getLogger(source).Info(message);
}
public static void Warn(object source, object message)
{
Warn(source.GetType(), message);
}
public static void Warn(Type source, object message)
{
getLogger(source).Warn(message);
}
public static void Error(object source, object message)
{
Error(source.GetType(), message);
}
public static void Error(Type source, object message)
{
getLogger(source).Error(message);
}
public static void Fatal(object source, object message)
{
Fatal(source.GetType(), message);
}
public static void Fatal(Type source, object message)
{
getLogger(source).Fatal(message);
}
/* Log a message object and exception */
public static void Debug(object source, object message,
Exception exception)
{
Debug(source.GetType(), message, exception);
}
public static void Debug(Type source, object message,
Exception exception)
{
getLogger(source).Debug(message, exception);
}
public static void Info(object source, object message,
Exception exception)
{
Info(source.GetType(), message, exception);
}
public static void Info(Type source, object message,
Exception exception)
{
getLogger(source).Info(message, exception);
}
public static void Warn(object source, object message,
Exception exception)
{
Warn(source.GetType(), message, exception);
}
public static void Warn(Type source, object message,
Exception exception)
{
getLogger(source).Warn(message, exception);
}
public static void Error(object source, object message,
Exception exception)
{
Error(source.GetType(), message, exception);
}
public static void Error(Type source, object message,
Exception exception)
{
getLogger(source).Error(message, exception);
}
public static void Fatal(object source, object message,
Exception exception)
{
Fatal(source.GetType(), message, exception);
}
public static void Fatal(Type source, object message,
Exception exception)
{
getLogger(source).Fatal(message, exception);
}
private static void initialize()
{
string logFilePath =
Path.Combine(AppDomain.CurrentDomain.BaseDirectory,
"Log4Net.config");
if (!File.Exists(logFilePath))
{
logFilePath =
Path.Combine(AppDomain.CurrentDomain.BaseDirectory,
@"bin\Log4Net.config");
}
XmlConfigurator.ConfigureAndWatch(new
FileInfo(logFilePath));
}
public static void EnsureInitialized()
{
if (!_logInitialized)
{
initialize();
_logInitialized = true;
}
}
public static void EnsureInitializedForTesting()
{
if (!_logInitialized)
{
OutputDebugStringAppender appender1 = new
OutputDebugStringAppender();
appender1.Layout = new PatternLayout("%-5p %m - %c –
%n");
BasicConfigurator.Configure(appender1);
TraceAppender appender2 = new TraceAppender();
appender2.Layout = new PatternLayout("%d [%t] %-5p %c
- %m%n");
BasicConfigurator.Configure(appender2);
_logInitialized = true;
}
}
}
}
This class is mostly bloated with overrides for logging messages in various ways. You will see Debug, Info, Warn, Error, and Fatal methods for logging both message objects and exceptions. Let's quickly step through this class to understand it.
Initially, you will notice several using statements. The most important are the IO, and the log4net references. One way of logging to the file system is to include the IO reference. Everything else is so that log4net will work appropriately.
using System; using System.Collections.Generic; using System.IO; using log4net; using log4net.Appender; using log4net.Config; using log4net.Layout;
The SerializeException() method provides a way to convert an Exception into a string. This has overrides that allow you to pass in an Exception or an Exception and a message. Both return the exception as a string.
public static string SerializeException(Exception e)
{
return SerializeException(e, string.Empty);
}
private static string SerializeException(Exception e, string
exceptionMessage)
{
if (e == null) return string.Empty;
exceptionMessage = string.Format(
"{0}{1}{2}\n{3}",
exceptionMessage,
(exceptionMessage == string.Empty) ? string.Empty :
"\n\n",
e.Message,
e.StackTrace);
if (e.InnerException != null)
exceptionMessage =
SerializeException(e.InnerException,
exceptionMessage);
return exceptionMessage;
}
The next method we will look at is the getLogger method. It's responsible for spinning up the log for you. It takes the type of the caller and returns the appropriate log. You will see that most of the following methods use this method.
private static ILog getLogger(Type source)
{
lock (_lock)
{
if (_loggers.ContainsKey(source))
{
return _loggers[source];
}
else
{
ILog logger = LogManager.GetLogger(source);
_loggers.Add(source, logger);
return logger;
}
}
}
The next set of methods allows you to log a message object. There are two overrides for each method name. One method allows you to pass an unspecified object and a message while another requires a specific type and its message. You will see that the first method simply does some dirty work to determine the type of object passed in, and then calls the second version of itself. All these methods append to the log through the getLogger method.
public static void Debug(object source, object message)
{
Debug(source.GetType(), message);
}
public static void Debug(Type source, object message)
{
getLogger(source).Debug(message);
}
public static void Info(object source, object message)
{
Info(source.GetType(), message);
}
public static void Info(Type source, object message)
{
getLogger(source).Info(message);
}
public static void Warn(object source, object message)
{
Warn(source.GetType(), message);
}
public static void Warn(Type source, object message)
{
getLogger(source).Warn(message);
}
public static void Error(object source, object message)
{
Error(source.GetType(), message);
}
public static void Error(Type source, object message)
{
getLogger(source).Error(message);
}
public static void Fatal(object source, object message)
{
Fatal(source.GetType(), message);
}
public static void Fatal(Type source, object message)
{
getLogger(source).Fatal(message);
}
The next set of methods is the same as the first set with the exception that they provide us with additional overrides that allow an exception to be passed in as well.
public static void Debug(object source, object message,
Exception exception)
{
Debug(source.GetType(), message, exception);
}
public static void Debug(Type source, object message,
Exception exception)
{
getLogger(source).Debug(message, exception);
}
public static void Info(object source, object message,
Exception exception)
{
Info(source.GetType(), message, exception);
}
public static void Info(Type source, object message,
Exception exception)
{
getLogger(source).Info(message, exception);
}
public static void Warn(object source, object message,
Exception exception)
{
Warn(source.GetType(), message, exception);
}
public static void Warn(Type source, object message,
Exception exception)
{
getLogger(source).Warn(message, exception);
}
public static void Error(object source, object message,
Exception exception)
{
Error(source.GetType(), message, exception);
}
public static void Error(Type source, object message,
Exception exception)
{
getLogger(source).Error(message, exception);
}
public static void Fatal(object source, object message,
Exception exception)
{
Fatal(source.GetType(), message, exception);
}
public static void Fatal(Type source, object message,
Exception exception)
{
getLogger(source).Fatal(message, exception);
}
Now we get to the initialize() method. This code is responsible for making sure that the logger is ready to go. First, it looks in the root of the website for the log4net.config file. If it doesn't find it there, then it checks in the bin directory for the file. The method then spins up the XmlConfiguration class. Here is that code:
private static void initialize()
{
string logFilePath =
Path.Combine(AppDomain.CurrentDomain.BaseDirectory,
"Log4Net.config");
if (!File.Exists(logFilePath))
{
logFilePath =
Path.Combine(AppDomain.CurrentDomain.BaseDirectory,
@"bin\Log4Net.config");
}
XmlConfigurator.ConfigureAndWatch(new
FileInfo(logFilePath));
}
The initialize() method is called by the EnsureInitialized() method.
public static void EnsureInitialized()
{
if (!_logInitialized)
{
initialize();
_logInitialized = true;
}
}
The EnsureInitialized() method first checks to see if the log has already been initialized by checking the _logInitialized flag. If the log has not be initialized, it calls the initialize() method and sets the _logInitialized flag to true thereby making sure to initialize() the log only once for every application startup.
Let's add this to our newly created Global.asax file in the Application_Start() method so that each time the application starts up we run through this initialization process.
protected void Application_Start(object sender, EventArgs e)
{
Log.EnsureInitialized();
}
This basically states that when the application is first loaded, we want to make sure that our logging feature is set up and initialized correctly. If not, the application itself should fail entirely!
Now that the log4net wrapper is complete, all we have to do is send something to the log, which requires us to write the following code:
Log.Debug(this,"oops, something failed!");
Let's not forget to go back to our //TODO: in the Global.asax.cs file. Add this line where our //TODO: currently is:
Log.Error(sender,"Error caught by the Global.asax: " + e.ToString());
That should take care of our error handling and logging needs!