Redeveloping WordTutor
Logging

As we progress building the WordTutor application, some of the functionality will be a great deal more complex - and that requires a better way to see what’s happening inside the application than we’ve had to date. It’s time to implement some logging.

We could, of course, use an existing logging library - but where’s the fun in that!

More seriously, the best logging library I ever used was one I used around twenty years ago while developing desktop applications in Delphi. This library had some innovative features, including the ability to automatically upload the logs to a central server if the application had previously crashed.

Perhaps the most useful feature of that library - and the one that I’d like to bring forward for use in the WordTutor, was support for hierarchical logging.

A problem I consistently see in application log files is that individual log messages lack context, making the messages less useful.

For example, what if you saw these log file messages:

21:07:23.012 INFO Configuration file 'foo.config' loaded from the application folder
21:07:23.014 ERROR Configuration file 'foo.config' could not be loaded from user folder

Does the error message indicate the application has failed? Or is this a normal condition that happens when an optional configuration file isn’t being used?

By providing additional context as a part of our logging framework, we can make it clear. To illustrate, what if our logging looked like this:

21:07:23.011 ACTION Loading application configuration files
21:07:23.012 INFO Configuration file 'foo.config' loaded from the application folder
21:07:23.014 ERROR Configuration file 'foo.config' could not be loaded from user folder
21:07:23.015 SUCCESS Loaded one configuration file

Now it’s clear that the ERROR is normal, and that we don’t need to pay it particular attention.

To achieve this, let’s create a very simple base ILogger interface:

public interface ILogger
{
    IActionLogger Action(string message);
    void Info(string message);
    void Debug(string message);
}

We’re supporting just three levels of information. The Info and Debug levels are likely obvious at first inspection - but why does Action have a return value?

The IActionLogger interface allows logging to be made in a nested context, tracking the events that happen during that action.

public interface IActionLogger : ILogger, IDisposable
{
    void Success(string message);
    void Failure(string message);
}

In addition to all the normal logging messages, we can also indicate whether the action was successful, or not.

What do you think of this approach? I’d be interested in your feedback.