Managing Cross Cutting Concerns - The Logger and Logging

Cross-cutting concerns (a.k.a Aspects) are part of every project built or being built and so-called 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 operations that is an 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 solutions for better implementation of CCC but we’ll discuss a type of Aspect of 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 the 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 the importance and necessity of logging in the application. What happened during development could be:

1. Least or almost no logging.
2. Resulting in a 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, the developer knows the importance of logging in to each layer and logs messages and any critical things that could happen in the 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 the DRY principle (Don’t Repeat Yourself).
    
3. Too much logging.

Case 3: The optimistic developer

 

This is a case when the developer has 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 has 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 ourselves 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 have enough support for Infrastructure in the early stage of development. If they failed to incorporate cross-cutting it wasn’t the developer’s fault at all. It was the vague design of the application.

 

To visualize it in a real-life scenario, let’s think of a building at a construction site. If the 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 the early designing phase before development starts. Cross cuttings concerns should be well defined. Infrastructure components that 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 purposes 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 a few aspects of the above design:

1. Logger in base class would be a good place, why? Because this piece of information can be shared with all derived classes.
    
2. Default instance can have a Null logger so it’s not a dependency anymore. A system should work without an Aspect like logging. It shouldn’t be defined as a dependency in your application design.
    
3. Now the developer doesn’t have to worry about introducing logging by himself/herself in the 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, the sample shown above in problem Case 2. Defining “What and When to log” is very important. This again should be defined in the early stage of development. Areas that should be addressed on an individual layer are: What application should log on an 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 the 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 orders
        }
        catch (InvalidOperationException exception)
        {
            Logger.LogError(string.Format("Invalid operation.Order {0}", order.OrderId, exception));
        }
    }
}

Think of 10 more commands like this and maybe in the future you require to create more commands means 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 orders
   }
}

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 orders
    }
    protected override void HandleError(string message, Exception exception)
    {
        // Let the logging done in the first place.
        base.HandleError(message, exception);
        // For demo purpose only. In a 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 in one place. You can imagine how neat your all command classes would look like.

 

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

 

Solution Approach [Case 3]

 

Now, this case is really interesting. In this case, the 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 to 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 a 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 the “Transient” life cycle.
    
4. Usage of AOP (Aspect-oriented programming) for infrastructure (CCC) is a really interesting one, especially 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 orders
   }

Ayende has written a very informative article on logging via AOP. But using run-time interceptors like Castle.DynamicProxy has its 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 deeper 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 a major part of an application. Often they appear in the Application architecture design diagram nicely but in application code it remains less important (Observed many instances in a couple of projects 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 the 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 the development phase of an 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.