Introduction

Aspect Oriented Programming (AOP) is a very powerful approach to avoid boilerplate code and archive better modularity. The main idea is to add behavior (advice) to the existing code without making any changes in the code itself. AOP provides a way of weaving an aspect into the code. An aspect is supposed to be generic so it can be applied to any object and an object should not have to know anything about advice. AOP allows the developer to separate cross-cutting concerns and makes it easier to follow the Single Responsibility Principle (one of the SOLID principles). Logging, security, transactions, and exception handling are the most common examples of using AOP. If you are not familiar with this programming technique you can read this or this. Don’t be scared if you still do not understand what it's all about. After looking at several examples, it becomes much easier to understand.

In Java, AOP is implemented in the AspectJ and Spring frameworks. There are PostSharp (not free), NConcern, and some other frameworks (not very popular or easy to use) to do almost the same stuff in.NET.

It is also possible to use the RealProxy class to implement AOP. You can find some examples of how to do it here:

• Example 1: Aspect-Oriented Programming: Aspect-Oriented Programming with the RealProxy Class. This article also contains a good explanation of AOP, how the Decorator Design Pattern works, and examples of implementing logging and authentication using AOP.

• Example 2: MSDN.

Unfortunately, these examples have some significant drawbacks. Example 1 does not support out parameters. Example2 has its limitations: the decorated class should be inherited from MarshalByRefObject (it could be a problem if it is not a class designed by you). Also, both examples do not support asynchronous functions as expected. Several months ago, I changed the first example to support Task results and output parameters and wrote an article about it. (Aspect-Oriented Programming in C# with RealProxy).

Unfortunately, .NET Core does not have a RealProxy class. There is a DispatchProxy class instead. Using the DispatchProxy class is a bit different than using the RealProxy class.

Let’s implement logging using the DispatchProxy class.

The code for this article and example of using RealProxy with unit tests can be found on GitHub.

Solution

Extension to Log Exception (extensions.cs)

using System;
using System.Text;

namespace AOP
{
    public static class Extensions
    {
        public static string GetDescription(this Exception e)
        {
            var builder = new StringBuilder();

            AddException(builder, e);

            return builder.ToString();
        }

        private static void AddException(StringBuilder builder, Exception e)
        {
            builder.AppendLine($"Message: {e.Message}");
            builder.AppendLine($"Stack Trace: {e.StackTrace}");

            if (e.InnerException != null)
            {
                builder.AppendLine("Inner Exception");
                AddException(builder, e.InnerException);
            }
        }
    }
}

Logging Advice (loggingadvice.cs)

public class LoggingAdvice<T> : DispatchProxy
{
    private T _decorated;
    private Action<string> _logInfo;
    private Action<string> _logError;
    private Func<object, string> _serializeFunction;
    private TaskScheduler _loggingScheduler;

    protected override object Invoke(MethodInfo targetMethod, object[] args)
    {
        if (targetMethod != null)
        {
            try
            {
                try
                {
                    LogBefore(targetMethod, args);
                }
                catch (Exception ex)
                {
                    //Do not stop method execution if exception
                    LogException(ex);
                }

                var result = targetMethod.Invoke(_decorated, args);
                var resultTask = result as Task;

                if (resultTask != null)
                {
                    resultTask.ContinueWith(task =>
                        {
                            if (task.Exception != null)
                            {
                                LogException(task.Exception.InnerException ?? task.Exception, targetMethod);
                            }
                            else
                            {
                                object taskResult = null;
                                if (task.GetType().GetTypeInfo().IsGenericType &&
                                    task.GetType().GetGenericTypeDefinition() == typeof(Task<>))
                                {
                                    var property = task.GetType().GetTypeInfo().GetProperties()
                                        .FirstOrDefault(p => p.Name == "Result");
                                    if (property != null)
                                    {
                                        taskResult = property.GetValue(task);
                                    }
                                }

                                LogAfter(targetMethod, args, taskResult);
                            }
                        },
                        _loggingScheduler);
                }
                else
                {
                    try
                    {
                        LogAfter(targetMethod, args, result);
                    }
                    catch (Exception ex)
                    {
                        //Do not stop method execution if exception
                        LogException(ex);
                    }
                }

                return result;
            }
            catch (Exception ex)
            {
                if (ex is TargetInvocationException)
                {
                    LogException(ex.InnerException ?? ex, targetMethod);
                    throw ex.InnerException ?? ex;
                }
            }
        }

        throw new ArgumentException(nameof(targetMethod));
    }

    public static T Create(T decorated, Action<string> logInfo, Action<string> logError,
        Func<object, string> serializeFunction, TaskScheduler loggingScheduler = null)
    {
        object proxy = Create<T, LoggingAdvice<T>>();
        ((LoggingAdvice<T>)proxy).SetParameters(decorated, logInfo, logError, serializeFunction, loggingScheduler);

        return (T)proxy;
    }

    private void SetParameters(T decorated, Action<string> logInfo, Action<string> logError,
        Func<object, string> serializeFunction, TaskScheduler loggingScheduler)
    {
        if (decorated == null)
        {
            throw new ArgumentNullException(nameof(decorated));
        }

        _decorated = decorated;
        _logInfo = logInfo;
        _logError = logError;
        _serializeFunction = serializeFunction;
        _loggingScheduler = loggingScheduler ?? TaskScheduler.FromCurrentSynchronizationContext();
    }

    private string GetStringValue(object obj)
    {
        if (obj == null)
        {
            return "null";
        }

        if (obj.GetType().GetTypeInfo().IsPrimitive || obj.GetType().GetTypeInfo().IsEnum || obj is string)
        {
            return obj.ToString();
        }

        try
        {
            return _serializeFunction?.Invoke(obj) ?? obj.ToString();
        }
        catch
        {
            return obj.ToString();
        }
    }

    private void LogException(Exception exception, MethodInfo methodInfo = null)
    {
        try
        {
            var errorMessage = new StringBuilder();
            errorMessage.AppendLine($"Class {_decorated.GetType().FullName}");
            errorMessage.AppendLine($"Method {methodInfo?.Name} threw exception");
            errorMessage.AppendLine(exception.GetDescription());

            _logError?.Invoke(errorMessage.ToString());
        }
        catch (Exception)
        {
            // ignored
            //Method should return original exception
        }
    }

    private void LogAfter(MethodInfo methodInfo, object[] args, object result)
    {
        var afterMessage = new StringBuilder();
        afterMessage.AppendLine($"Class {_decorated.GetType().FullName}");
        afterMessage.AppendLine($"Method {methodInfo.Name} executed");
        afterMessage.AppendLine("Output:");
        afterMessage.AppendLine(GetStringValue(result));

        var parameters = methodInfo.GetParameters();
        if (parameters.Any())
        {
            afterMessage.AppendLine("Parameters:");
            for (var i = 0; i < parameters.Length; i++)
            {
                var parameter = parameters[i];
                var arg = args[i];
                afterMessage.AppendLine($"{parameter.Name}:{GetStringValue(arg)}");
            }
        }

        _logInfo?.Invoke(afterMessage.ToString());
    }

    private void LogBefore(MethodInfo methodInfo, object[] args)
    {
        var beforeMessage = new StringBuilder();
        beforeMessage.AppendLine($"Class {_decorated.GetType().FullName}");
        beforeMessage.AppendLine($"Method {methodInfo.Name} executing");
        var parameters = methodInfo.GetParameters();
        if (parameters.Any())
        {
            beforeMessage.AppendLine("Parameters:");

            for (var i = 0; i < parameters.Length; i++)
            {
                var parameter = parameters[i];
                var arg = args[i];
                beforeMessage.AppendLine($"{parameter.Name}:{GetStringValue(arg)}");
            }
        }

        _logInfo?.Invoke(beforeMessage.ToString());
    }
}

Let’s assume that we have an interface and a class.

public interface IMyClass
{
    int MyMethod(string param);
}

public class MyClass
{
    public int MyMethod(string param)
    {
        return param.Length;
    }
}

To decorate MyClass by using LoggingAdvice, we should do the following:

var decorated = LoggingAdvice<IMyClass>.Create(
                new MyClass(),
                s => Debug.WriteLine("Info:" + s),
                s => Debug.WriteLine("Error:" + s),
                o => o?.ToString());

To understand how it works, we call MyMesthod of the decorated instance.

var length = decorated.MyMethod("Hello world!");

This line of code does:

1. decorated.MyMethod("Hello world!") calls the Invoke method of LoggingAdvice with targetMethod equal to MyMethod and args equal to an array with one element equal to "Hello world!"
2. Invoke method of LoggingAdvice class logs the MyMethod method name and input parameters (LogBefore).
3. The Invoke method of LoggingAdvice class calls the MyMethod method of MyClass.
4. If the method call is successful, the output parameters and result are logged (LogAfter) and the Invoke method returns a result.
5. If the method call throws an exception, the exception is logged (LogException) and Invoke throws the same exception.
6. The result of the Invoke method execution (result or exception) returns as a result of calling MyMethod of a decorated object.

Example

Let assume that we are going to implement calculator which adds and subtracts integer numbers.

public interface ICalculator
{
    int Add(int a, int b);
    int Subtract(int a, int b);
}

public class Calculator : ICalculator
{
    public int Add(int a, int b)
    {
        return a + b;
    }

    public int Subtract(int a, int b)
    {
        return a - b;
    }
}

It is easy. Each method has only one responsibility.

One day, some users start complaining that sometimes Add(2, 2) returns 5. You don’t understand what's going on and you decide to add logging.

public class CalculatorWithoutAop: ICalculator
{
    private readonly ILogger _logger;

    public CalculatorWithoutAop(ILogger logger)
    {
        _logger = logger;
    }

    public int Add(int a, int b)
    {
        _logger.Log($"Adding {a} + {b}");
        var result = a + b;
        _logger.Log($"Result is {result}");

        return result;
    }

    public int Subtract(int a, int b)
    {
        _logger.Log($"Subtracting {a} - {b}");
        var result = a - b;
        _logger.Log($"Result is {result}");

        return result;
    }
}

There are 3 problems with this solution.

1. The Calculator class is coupled with logging. Loosely coupled (because ILoger is an interface), but coupled. Every time you make changes in the ILoger interface it affects Calculator.
2. Code becomes more complex.
3. It breaks the Single Responsibility Principle. The Add function doesn't just add numbers. It logs input values, adds values, and logs result. The same for Subtract.

The code in this article allows you to not have to touch the Calculator class at all.

You just need to change the creation of the class.

public class CalculatorFactory
{
    private readonly ILogger _logger;

    public CalculatorFactory(ILogger logger)
    {
        _logger = logger;
    }

    public ICalculator CreateCalculator()
    {
        return LoggingAdvice<ICalculator >.Create(
            new Calculator(),
            s => _logger.Log("Info:" + s),
            s => _logger.Log("Error:" + s),
            o => o?.ToString());
    }
}

Conclusion

This code works in my cases. If you have any examples of when this code does not work, or you have ideas how this code could be improved, fill free to contact me in any way.

That's it — enjoy!