Managing Cross Cutting Concerns - The Logger and Logging

Cross cutting concerns (a.k.a Aspects) are part of each every project built or being built and so called the Infrastructure. A quick definition of CCC (Cross cutting concerns), An essential part of software application that cuts across the layers of the application. CCC can include things like Logging, Exception/Error Handling, Caching, Monitoring, Security, Communication, etc. and there’s a list of operation that are integral part of an application and needs to be performed across the layers. Take a look at the layered application architecture. It has DataLayer, BusinessLayer and UI or Presentation Layer. Those usually managed separately in individual projects but what kept me thinking is the way to manage the cross cutting. The challenge comes with the fact that CCC is shared across the layer. It can make maintenance of an application a nightmare if not implemented correctly.



In this post we’ll be looking at the pain areas and possible solution for better implementation of CCC but we’ll discuss a type of Aspect of an application architecture in Cross cutting concern, a set of sample problems and what can be best practices to avoid them, etc. Unlike Java in C# Aspect oriented programming (AOP) is not fully supported. Using Aspects (Attributes in C#) is one way of introducing cross cutting concerns in an application. But that’s a topic that we’ll discuss later in this post.

The problem

To depict the idea of the problem let’s start with simplest things known as Logging in CCC. Let’s talk about the logging aspect in an application from various developer’s point of view. There could be possible cases during application development:

Case 1: Developer didn’t care about it unless

This is the least and last thing that I’ve seen people care about unless the application is ready for Production or it’s already in production and bugs/problems are reported from the end users. Then the developer realized the importance of logs (Logging) and the whole picture gets clear dictating importance and necessity of logging in application. What happened during development could be:

1. Least or almost no logging.
   
   
2. Resulting in hot patch in production with minimum logging support (Too much risk).
   
   
3. Consequence of #1 and #2 resulting in last moment code changes and end up with hard coded trace/log statement at random places.

Case 2: Developer cared about it too much

In this case developer knows the importance of logging in each layer and logs messages and any critical things that could happen in application. But usually end up in situations like the following:

1. Methods are cluttered with logging statements. A case of violation of SRP (Single Responsibility Principle).
   

   try
   {
       // some operations here.
   }
   catch (Exception ex)
   {
       this.logger.Log(ex);
       throw;
   }

2. Too much usage of Try..catch almost used in each function. A case of violation of DRY principle (Don’t Repeat Yourself).
   
   
3. Too much logging.

Case 3: The optimistic developer

This is a case when developer have knowledge of not overflooding the code with log statement and he.she is also concerned about managing the cross cutting across components. But he/she might get confused with the way to manage it having the following options available:

1. A static logger factory to provide logger instance access.
   

   public class MyController: BaseController
   {
       private static readonly ILog Logger = LogManager.GetCurrentClassLogger();
       public IList < Customers > Get()
       {
           Logger.Debug("Done! I can use it!");
       }
   }

2. Adding logger property in every class via property or constructor injection and using DI container to inject the logger.
   

   public class MyController
   {
       private readonly ILog _logger;
       public MyController(ILog logger)
       {
           _logger = logger;
       }
       public IList < Customers > Get()
       {
           _logger.Debug("I am injected via constructor using some IoC!");
       }
   }

3. Use AOP (Aspect oriented programming).
   
   Now we all must have seen these cases or must felt somewhere by ourself somewhere in our career phase. Now let’s talk about the possible solutions to avoid such situations.

Solution approach [Case 1]

This situation can be avoided by Design. Why the developer failed or didn’t care about the logging is because the design didn’t had enough support for Infrastructure in early stage of development. If they failed to incorporate cross cutting it wasn’t developer’s fault at all. It was the vague design of application.

To visualize it in real life scenario, let’s think of a building at construction site. If design doesn’t include the Hoses, Vent, Electricity wiring pipes, Windows, etc. then later things might end-up breaking into walls and ceilings to get those small but necessary setup done. This is exactly what happens with software applications; end-up plumbing those cross cutting concerns later on. Situations like this are surely not a good sign.

Introduce a solid infrastructure in early designing phase before development starts. Cross cuttings concerns should be well defined. Infrastructure components which are required on an individual layer should be available by design.

E.g. On a business layer side a base class can have access to a logger factory or logger instance that can be accessed for logging purpose in all derived classes.

public abstract class BaseCommand
{
    protected ILogger Logger
    {
        get;
        private set;
    }
    public BaseCommand()
    {
        Logger = NullLogger.Instance;
    }
    public BaseCommand(ILogger logger)
    {
        Logger = logger;
    }
}

Now let’s discuss few aspects of above design:

 

1. Logger in base class would be a good place, why? Because this piece of information can be shared to all derived classes.
   
   
2. Default instance can have a Null logger so it’s not a dependency any more. A system should work without an Aspect like logging. It shouldn’t be defined as dependency in your application design.
   
   
3. Now developer doesn’t have to worry about introducing logging by himself/herself in first place.
   
   This might not be a perfect example but this is “a way” of putting infrastructure/cross cutting concerns in right place at right time.

Solution Approach [Case 2]

Which in short says, Logging aspect viz. Infrastructure component is used but not correctly, sample shown above in problem Case 2. Defining “What and When to log” is very important. This  again should be defined in early stage of development. Areas that should be addressed on individual layer are: What application should log on individual layer? E.g. Error, Exception (Handled/Unhandled), Trace info, etc. along with which information must be shared across the layers.

The case of exception handling is very common that required logging to be done and exception would be wrapped and sent to another layer. In this case:

1. Design should manage a sample case like error handling at common places so that logging can be performed without duplication and without avoiding SRP.

Let’s take an example of OrderProcessorCommand that processes an order this will be inherited from our above defined BaseCommand.

public class OrderProcessorCommand: BaseCommand
{
    public void Execute(Order order)
    {
        try
        {
            // Business logic for processing order
        }
        catch (InvalidOperationException exception)
        {
            Logger.LogError(string.Format("Invalid operation.Order {0}", order.OrderId, exception));
        }
    }
}

Think of 10 more commands like this and may be in future you require to create more commands mean more try..catch and logging statements cluttered in your application. Now let’s redesign the above classes.

Let’s start with extending BaseCommandClass.

public abstract class BaseCommand < T >
{
    protected ILogger Logger
    {
        get;
        private set;
    }
    public BaseCommand()
    {
        Logger = NullLogger.Instance;
    }
    public BaseCommand(ILogger logger)
    {
        Logger = logger;
    }
    public void Execute(T parameter)
    {
        try
        {
            CheckForNull(parameter); // common place for command parameter null checking :)
            ExecuteCore(parameter);
        }
        catch (InvalidOperationException exception) // gotcha! that's it handling all common commands errors here.
        {
            HandleError(exception.Message, exception);
        }
    }
    protected abstract void ExecuteCore(T Parameter);
    protected virtual void HandleError(string message, Exception exception)
    {
        // Do more with logging.
        Logger.LogError(message, exception);
    }
    private void CheckForNull(T parameter)
    {
        if (parameter == null)
        {
            throw new ArgumentNullException("Command parameter should not be null.");
        }
    }
}

Now the base class is equipped with more infrastructure support i.e. Error/Exception handling. Now the OrderProcessorCommand will look like this:

public class OrderProcessorCommand : BaseCommand<Order>
{
   protected override void ExecuteCore(Order Parameter)
   {
      // Business logic for processing order
   }
}

Neat! Isn’t it? Moreover if any particular command required to handle its exception in its own way then the new design is supporting it very well. E.g. the occurred exception has to be wrapped and should be sent to another layer.

public class UpdateOrderCommand: BaseCommand < Order >
{
    protected override void ExecuteCore(Order Parameter)
    {
        // Business logic for processing order
    }
    protected override void HandleError(string message, Exception exception)
    {
        // Let the logging done in first place.
        base.HandleError(message, exception);
        // For demo purpose only. In real scenario error codes can be used here.
        if (exception.GetType() == typeof(InvalidOperationException))
        {
            // Now pack it and tag it.
            throw new InvalidOrderException("The order has invalid items.");
        }
    }
}

As you can see we have removed the clutter of logging and exception handling at one place. You can imagine how neat your all command classes would look like.

Conclusion: A better design in application can provide much better way to manage and clean the Cross cutting concerns clutter. This is why design patterns are important during development.

Solution Approach [Case 3]

Now this case is really interesting. In this case developer knows the problems and keeps the infrastructure (CCC) stuff usage straight and clean in the application by following best practices. But again during those practices another question comes in mind about managing the objects and classes for infrastructure components or aspects like Logging. This is really a topic where individuals have their own opinions and all are interesting you can’t deny one straightforward. After researching and with all experience I had so far with Cross cuttings (logging for example in this blog post) following can be the best practices (IMO):

 

1. Infrastructure components like Logger shouldn’t be considered as Dependencies. Though one can use constructor injection but make sure it doesn’t become the “required” component. Application should work even without logger.
   
   
2. Singletons or Static logger factories are good to keep for shared instances. You should keep the infrastructure (CCC) stuff as thin as possible.
   
   
3. If you’re using Dependency injection, Logger object shouldn’t be registered with “Transient” life cycle.
   
   
4. Usage of AOP (Aspect oriented programming) for infrastructure (CCC) is really interesting one specially in C#. Found a definition of AOP which says,
   
   "Aspect Oriented Programming is a methodology to separate cross cut code across different modules in a software system."
   
   Means thinking of using AOP is not a false alarm at all. Unfortunately AOP is not fully supported in C#. C# supports Attributes but defining attributes isn’t enough a supporting actor class required to perform respective actions.
   
   E.g. Logging can be done using AOP. Castle.Dynamic provides interceptors that can be used to intercept the method invocation for logging.
   

   [EnableLogging]
   protected override void ExecuteCore(Order Parameter)
   {
      // Business logic for processing order
   }

Ayende has written a very informative article on logging via AOP. But using run time interceptors like Castle.DynamicProxy has their own runtime cost. As it works based on run time Proxy wrapper generation of each marked method/class. IMO this is too much cost for operations like Logging. You may not want to hamper the performance of your application just because of Logger operations. Look at some more types of approaches to achieve AOP in .NET.

But surely this can be a great way to incorporate cross cuttings in your application if done via Compile Time weaving or Link Time weaving. Let’s not go more deep about the AOP here. I’ll be writing another post details AOP possibilities in .NET C# separately.

Conclusion

Although Cross Cuttings Concerns are sometimes not considered major part of an application. Often they appear in Application architecture design diagram nicely but in application code it remains less important (Observed many instances in couple of project I looked upon). Cross cuttings are the infrastructure on which great applications are built. And their importance is as equal as any of the concrete layer in application architecture. This blog post mostly talked about Logging. The problems I addressed here for a small aspect like logging are real and often observed in development phase of application.



I’ll be writing more about other cross cutting concerns like Security/Error handling but let’s wrap things up here.

Hope you liked this post. Kindly share/like if it really helped you by improvising your thoughts over CCC.