Monday, October 31, 2011

Logging in MVC Part 1- Elmah

Introduction

Logging is one of the most useful services that every production website should have.
When errors occur on your website you should be notified about them. Whilst you may think you have written perfect code and unit tested everything to the best of your ability errors can and will still happen. The database server may go down, a 3rd party website may be offline, the shared hosting environment of your website may suffer an outage, a previously undetected bug may occur and the list goes on.
Having a great logging system in place allows you to stay on top of errors when they do happen.
In this series we will be building a logging reporting system that will allow you to drill into the various events that get logged on your website.
Before we get started let’s take a look at the finished solution:

and we would also like to see some graphs so we can quickly pinpoint when errors occurred on our website:






and we also would like to have an RSS feed of our errors:

Goals

So let’s write down the goals for what we want to achieve:
1. Log all unhandled exceptions to a database
2. Log entries to our database whenever the website starts up, shuts down, recompiles etc.
3. Log any custom messages that we want to keep track of
4. Handle errors gracefully so that the end-user never sees a yellow screen of death error message.
5. Receive an email when an unhandled exception occurs
6. Allow multiple log providers to be easily swapped in and out of our website.
7. On the website, provide a logging reporting tool that lets us filter and view any message that has been logged.
8. The reporting tool should also allow us to view log entries as an RSS feed so that we can combine multiple feeds from all of the websites under our control.
9. The reporting tool should also have a dashboard or chart so that we can quickly get an overview of any activity on the website.
10. Provide an ability to manage logs, purge old logs, export logs to files or email them to someone.
Well that’s quite a list, so let’s get started!

Getting started

The first thing that we want to do is take care of unhandled exceptions so one of the best tools for that job is ELMAH. ELMAH was created by Atif Aziz and is used on many websites including StackOverflow.
To get started with ELMAH, the following article provides a very good overview of how to set it all up for a normal ASP.Net Web forms website:
http://www.asp.net/hosting/tutorials/logging-error-details-with-elmah-cs
I won’t go into all of the details here about setting up Elmah because the above article covers pretty much everything you need to know.
In simple terms you need to :
1. Download Elmah from it’s project page on CodePlex.
2. Extract the files from the zip.
3. The database script is located in the /src/Elmah directory. For SQL Server it is called “SQLServer.sql”. Run the database script to add the Elmah table and stored procs to your database.
4. Add a reference to Elmah for your website.
5. Modify the web.config file sections as explained in the article above. You can download the code I used at the end of this article to see the necessary web.config file alterations.

Configuring Elmah on MVC

However, as we will be using ELMAH on an MVC website we need to do a little bit more than the normal configuration to get it all working together nicely.
In MVC, you normally put [HandleError] attributes on your controllers to handle errors. Like this:
1namespace MySampleApp.Controllers
2{
3 [HandleError]
4 public class AccountController : Controller
5 {
6 }
7}
But because we would like to use Elmah to handle our exceptions instead of MVC, we will replace the standard MVC [HandleError] attribute with our own custom attribute called [HandleErrorWithElmah].
The StackOverflow question below provides the necessary details:
http://stackoverflow.com/questions/766610/
The code necessary is shown below:
01public class HandleErrorWithELMAHAttribute : HandleErrorAttribute
02    {
03        public override void OnException(ExceptionContext context)
04        {
05            base.OnException(context);
06
07            var e = context.Exception;
08            if (!context.ExceptionHandled   // if unhandled, will be logged anyhow
09                    || RaiseErrorSignal(e)      // prefer signaling, if possible
10                    || IsFiltered(context))     // filtered?
11                return;
12
13            LogException(e);
14        }
15
16        private static bool RaiseErrorSignal(Exception e)
17        {
18            var context = HttpContext.Current;
19            if (context == null)
20                return false;
21            var signal = ErrorSignal.FromContext(context);
22            if (signal == null)
23                return false;
24            signal.Raise(e, context);
25            return true;
26        }
27
28        private static bool IsFiltered(ExceptionContext context)
29        {
30            var config = context.HttpContext.GetSection("elmah/errorFilter")
31                                     as ErrorFilterConfiguration;
32
33            if (config == null)
34                return false;
35
36            var testContext = new ErrorFilterModule.AssertionHelperContext(
37                                                                context.Exception, HttpContext.Current);
38
39            return config.Assertion.Test(testContext);
40        }
41
42        private static void LogException(Exception e)
43        {
44            var context = HttpContext.Current;
45            ErrorLog.GetDefault(context).Log(new Error(e, context));
46        }
47    }
At this point we could subsitute the [HandleError] attribute with our [HandleErrorWithELMAH] attribute but we would need to remember to do this on all of our MVC controllers… There has to be a better, easier way! And there is!
The solution is to create a custom Controller factory! And we will also need to write our own ActionInvoker. Let’s write that one first:
01public class ErrorHandlingActionInvoker : ControllerActionInvoker
02 {
03 private readonly IExceptionFilter filter;
04
05 public ErrorHandlingActionInvoker(IExceptionFilter filter)
06 {
07 if (filter == null)
08 {
09 throw new ArgumentNullException("filter");
10 }
11
12 this.filter = filter;
13 }
14
15 protected override FilterInfo GetFilters(
16 ControllerContext controllerContext,
17 ActionDescriptor actionDescriptor)
18 {
19 var filterInfo =
20 base.GetFilters(controllerContext,
21 actionDescriptor);
22
23 filterInfo.ExceptionFilters.Add(this.filter);
24
25 return filterInfo;
26 }
27 }
And here is the code for the custom controller factory:
01public class ErrorHandlingControllerFactory : DefaultControllerFactory
02 {
03 public override IController CreateController(
04 RequestContext requestContext,
05 string controllerName)
06 {
07 var controller =
08 base.CreateController(requestContext,
09 controllerName);
10
11 var c = controller as Controller;
12
13 if (c != null)
14 {
15 c.ActionInvoker =
16 new ErrorHandlingActionInvoker(
17 new HandleErrorWithELMAHAttribute());
18 }
19
20 return controller;
21 }
22 }
The last step is to hook it all up so that happens automatically for each controller we have in our MVC project. To do that we wire up our new controller factory in the Global.asax.cs file:
1protected void Application_Start()
2 {
3 AreaRegistration.RegisterAllAreas();
4
5 RegisterRoutes(RouteTable.Routes);
6
7 ControllerBuilder.Current.SetControllerFactory(new ErrorHandlingControllerFactory());
8 }
So now that it is all wired up, we can actually go ahead and remove the [HandleError] attribute from all of our MVC controllers as our custom controller factory will now automatically inject the [HandleErrorWithElmah] attribute automatically.
The last step is to force an unhandled exception occurring in our application and view the elmah.axd page on our website to see the errors logged.
In the Home Controller I have this:
1public ActionResult About()
2 {
3 // Throw a test error so that we can see that it is handled by Elmah
4 // To test go to the ~/elmah.axd page to see if the error is being logged correctly
5 throw new Exception("A test exception for ELMAH");
6
7 return View();
8 }
and then we just browse to the About page which will generate an exception:

and then browse to the Elmah page to verify that the error was logged correctly.

Conclusion

That ends part 1 of this series. Next time we will look at logging things like when the application starts up, shuts down and recompiles etc.

No comments:

Twitter Bird Gadget