Intercepting methods with Ninject for error logging

I am currently working on a fairly large Windows Azure projects that among other things conatins a Web Role where I use Ninject as a dependency container. As the business logic library grew larger I found myself writing a lot of repeating boiler plate code to log exceptions in many important methods. I wantet to remove all the boiler plate code and create a custom attribute, say LogErrorAttribute with one simple goal: each method decorated woth this attribute should log info about any occuring exception.

IL weaving?

I have been using Fody for some time to implement the INotifyPropertyChanged calls for me in Windows Phone and Windows 8 projects so it was my first choice.

There is a Fody.MethodDecorator extensions that allows you to execute your code on a methods start, exit and exception. Writing the exception to Console is trivial, but I wanted to use a implementation of my custom ILogFactory.

There was no way to inject a ILogFactory implementation into the InterceptorAttribute. The only way that could work would be to use a ServiceLocator and I did not want to do it.

Dynamic proxy!

I came across Castle Dynamic Proxy and realized that there are Ninject extensions that allow you to easily use it.

First you need to install Ninject.Extensions.Interception. It has no depedencies other that Ninject, but you also have to install Ninject.Extensions.Interception.DynamicProxy (and Castle.Core as a dependency) otherwise it will not work.

First, create a class implementing the IInterceptor interface

public class ErrorLoggingInterceptor : IInterceptor
{
    private readonly ILogFactory _logFactory;

    public ErrorLoggingInterceptor(ILogFactory logFactory)
    {
      _logFactory = logFactory;
    }

    public void Intercept(IInvocation invocation)
    {
      try
      {
        invocation.Proceed();
      }
      catch (Exception e)
      {
        var sb = new StringBuilder();
        sb.AppendFormat("Executing {0}.{1} (", invocation.Request.Target.GetType().Name, invocation.Request.Method.Name);
        var parameters = invocation.Request.Method.GetParameters();
        for (int i=0;i<invocation.Request.Arguments.Length;++i)
        {
            sb.AppendFormat("{0}={1},", parameters[i].Name, invocation.Request.Arguments[i]);
        }
        sb.AppendFormat(") {0} caught: {1})", e.GetType().Name, e.Message);
        _logFactory.Error(sb.ToString());
         throw e;
      }
    }
}

This class wraps the intercepted method invocation into a try..catch block and logs any occuring exception using my custom ILogFactory, including parameter values.

Next, create a class implementing the InterceptAttribute

public class LogErrorAttribute : InterceptAttribute
{
    public override IInterceptor CreateInterceptor(IProxyRequest request)
    {
        return request.Context.Kernel.Get<ErrorLoggingInterceptor>();
    }
}

This attribute uses the Ninject kernel to get an instance of the ErrorLoggingInterceptor so you do not have to concern yourself explictily with providing an ILogFactory implementation, Ninject will do all the work.

Now you can use the LogErrorAttribute to mark any method, but keep in mind that all the marked methods must be virtual

[LogError]
public virtual bool Send(string text, IEnumerable<string> languageCodes, string carId, string type, bool save=true)
{
    //error in this method will be logged  
}

See also