Writing rich logging solution

Tests tell us if our software works as expected. But they tell us almost nothing about side effects of technical environment where system lives. We can face different problems when test users start testing system in their environment and we want to be ready to react fast to all problems. To get information about system’s work we need advanced logging.

Example: SharePoint and Unified Logging System (ULS)

SharePoint uses very rich logging system called Unified Logging System. You can read more about it from my blog entry SharePoint: Writing messages to ULS (Unified Logging System). The use of ULS is very good example about rich logging. Of course, if you let SharePoint to log everything then it performs a lot of IO operations and logs are growing very fast. To keep logging under control you can set logging levels for different parts of system. You can find logging options under Central Admin when choosing Operations => Diagnostic Logging.

SharePoint event throttling settings

When system works stable we want to log less information to avoid massive amount of IO actions. When we are looking for some problem then we want to have more information to find out what is going on. That’s why we are using log or event levels (look at the screenshot above).

How we will log

ULS is just one logger implementation and using it when testing the system is pointless – we want to find out bugs in system code not in logging mechanism. For tests we have to use some dummy logger that is not able to cause any problems. One option is to use IoC container like shown in my blog entry Hiding loggers implementations using Unity.

Let’s see now one method that does something important. If this method fails we want to see what it did before failure.

public void ProcessTransactions()
{
    Logger.Log(
"ProcessTransaction: start"
);

    Logger.Log(
"ProcessTransaction: ask transctions"
);
   
// ...
    // ask transactions that need to be processed
    // ...
    Logger.Log("ProcessTransaction: transctions retrieved"
);

   
// ...
    // some more code with logging
    // ...

    Logger.Log(
"ProcessTransaction: finish");
}

By example, you can find similar logging when exploring SharePoint DLL-s with Reflector.

Logging solution

As we saw in my blog entry Hiding loggers implementations using Unity we can use IoC container. But if we use IoC container we will depend on it. Maybe we want to use some other IoC container in the future. If we have calls to current IoC container in our methods then we have to change all these methods when we start using other IoC container. Let’s hide this fact from our code.

In my loggers example I defined interface for loggers and enumerator for log message types. Now I want to avoid enumerator so our methods should know less details about logging solution. I define the following ILogger interface.

public interface ILogger
{
   
public void LogInfo(string
message);
   
public void LogWarning(string
message);
   
public void LogException(Exception
ex);
   
public void LogFatalError(string message);
}

This interface are for logger implementations only. We will use class with static methods to log messages.

public class Logger
{
   
private static readonly ILogger
_logger;
 
   
static
Logger()
    {
        _logger =
// ask logger instance from IoC container
    }
 
   
public static void LogInfo(string
message)
    {
        _logger.LogInfo(message)
    }
   
public etatic void LogError(Exception
ex)
    {
        _logger.LogException(ex);
    }
   
public static void LogWarning(string
message)
    {
        _logger.LogWarning(message);
    }
   
public static void LogFatalError(string message)
    {
        _logger.LogFatalError(message);
    }
}

Maybe this class is not nice and, of course, it just replaces dependency of IoC container with dependency of itself but it “our” dependency not a “foreign” dependency and we have strong control over “our” dependency. I don’t what to show logger instance to other classes because this produces only longer calls and makes no difference.

Null logger

Okay you may say that this class is not testable at all and it is hard to modify etc. Well, this class is just a wrapper that takes current logger and offers same methods statically that logger has. This class asks logger from IoC container and information about IoC container is not visible to other classes. We can still test logger classes separately.

And if we want to test methods that write messages to log we can use test configuration. For tests we define null logger that does nothing and we say in IoC container configuration that this is our current logger implementation.

public class NullLogger : ILogger
{
   
public void LogInfo(string
message)
    {
    }
 
   
public void LogWarning(string
message)
    {
    }
 
   
public void LogException(Exception
ex)s
    {
    }
 
   
public void LogFatalError(string message)
    {
    }
}

This logger does really nothing and we can use it easily for our tests.

Conclusion

It is not hard to add rich logging functionality to your applications and make your logging mechanism highly configurable and easy to use for other classes in your code. I still have to warn you to be careful with logging – use it only as much as you really need and not more.

Gunnar Peipman

Gunnar Peipman is ASP.NET, Azure and SharePoint fan, Estonian Microsoft user group leader, blogger, conference speaker, teacher, and tech maniac. Since 2008 he is Microsoft MVP specialized on ASP.NET.

    Leave a Reply

    Your email address will not be published. Required fields are marked *