Monday, 6 May 2013

Aspect-Oriented Programming in C# with PostSharp - Logging Aspect Example

I was looking at some code in a class library project with a colleague recently. One thing that stood out was that a lot of methods across the various classes in the library were using a "Logger" class to persist runtime information (things like actual parameters and exception messages). There was a clear pattern in how these methods were structured, they logged the fact that they were called (with parameter information) and then had logic specific to what they were supposed to do. Any exceptions raised by the main logic of the methods were also logged. The "Logger" instance was not being injected into each of these classes, it was a concrete implementation without an interface. In the end, we came to the conclusion that we could improve this code as follows:

  • We could de-couple the logger from all the classes by using dependency injection. This would involve creating an interface for the logger, ensuring the current logging class implements this interface and then rearchitecting the classes that use the logger so that they are IoC friendly. An IoC container such as Ninject could then be used to inject a specific implementation of the logger into the various classes at runtime.
  • Or, we can make use of Aspect-Oriented Programming (AOP)

The latter of these points is the subject of this blog post. AOP is a programming paradigm just like Object-Oriented Programming (OOP). But instead of focusing on classes, objects and methods - AOP focuses more on separating concerns through "aspects". AOP typically deals with concerns that "cross-cut" a codebase. Luckily for us, the most popular example of a cross-cutting concern seems to be logging. As my colleague and I witnessed in the class library project, logging was being applied across a number of classes, therefore tightly coupling the logger with these classes. Furthermore, it was clear that each method that was logging wasn't adhering to the single responsibility principle.

The goal was therefore to seperate these concerns in a clean way. AOP enables this by letting you implement cross-cutting concerns as aspects which are then applied to existing code through aspect weaving. The C# programming language doesn't have any first-class support for AOP as it is primarily an OOP language. But there are libraries that allow you to apply AOP concepts using existing C# language constructs. One such library is PostSharp, which makes it easy to write an aspect and then apply the aspect to existing code. In the example below, we'll make use of PostSharp to write an aspect for logging method call information to the debug output.

PostSharp Logging Aspect Example

The PostSharp library allows you to define aspects as standard C# attributes. You can do this by deriving from one of the aspect classes from the library and override the methods that are of interest to your aspect. In the logging aspect example below, we derive from the PostSharp.Aspects.OnMethodBoundaryAspect class and override the OnEntry, OnExit and OnException methods.

[Serializable]
public class LogAspectAttribute : OnMethodBoundaryAspect
{
    private Guid _methodCallIdentifier;
               
    public override void OnEntry(MethodExecutionArgs args)
    {
        _methodCallIdentifier = Guid.NewGuid();

        Debug.WriteLine("{0} - Entering method {1} with arguments: {2}",
            _methodCallIdentifier,
            args.Method.Name,
            string.Join(", ", args.Arguments));
    }

    public override void OnExit(MethodExecutionArgs args)
    {
        Debug.WriteLine("{0} - Exited method {1}",
            _methodCallIdentifier,
            args.Method.Name);
    }

    public override void OnException(MethodExecutionArgs args)
    {
        Debug.WriteLine("{0} - Method {1} raised exception with message: {2}",
            _methodCallIdentifier,
            args.Method.Name,
            args.Exception.Message);
    }
}

Note that PostSharp contains a number of predefined aspect classes that you can derive from depending on your particular use case. For instance, the class PostSharp.Aspects.MethodInterceptionAspect is particularly useful for implementing security on methods (i.e. you can decide in your aspect whether to allow the intercepted call to proceeed through).

Back to the example above, the OnEntry method is called just before the target method (the method that we'll annotate with this attribute) is called. The OnExit method is called once the target method completes executing and the OnException method is called if the target method raises an exception. Each of these three methods provide useful points for us to do some logging. The MethodExecutionArgs instance passed to each method also contains some useful context information for us to add to the log.

To now use this aspect, it's a simple case of annotating the methods you want to log with the [LogAspect] attribute, as shown below.

[LogAspect]
void SayHelloToWithoutException(string name)
{
    Console.WriteLine("Hello, {0}!", name);
}

[LogAspect]
void SayHelloToWithException(string name)
{
    Console.WriteLine("Hello, {0}!", name);
    throw new Exception("Oops! Something went wrong...");
}

The logging logic is now neatly encapsulated in one location. If we call the two methods above, one after the other, we'll get the debug output: