The topics I have been selecting to write about are a reflection of things that have come up over the previous week.  The topic this week is logging.  Logging is an extremely valuable tool when developing and debugging software.  It can make the difference between a thirty second scan of a text file and several hours of debugging.  Given the importance of logging there have been at least a few attempts at creating logging applications.  Log4xxx type loggers have tons of neat features.  As impressive is the feature list is, learning how to program a logger probably is not the most fun a programmer can have.  In the end, loggers should log information and then get out of the way.  Loggers should be easy to understand and easy to extend.  Loggers should not contain code to log to every possible log sink ever requested so that the feature list look more impressive.  It should be possible to write code for a specific type of sink and drop that code into projects when it is needed and cut it out when it is not.  This post covers the design for a very simple logging system, one that has proven itself over the years.

 

The logger interface

What the logger can do is described in this interface.  What may immediately stand out is that there is a specific method for each type of logging to be done.  Why is that?  Primarily it is due to making sure that any implementation of this interface provides exactly the same functionality, making the implementations interchangeable with each other.  Less obvious is the introduction of the TODO method.  Often code will incur some level of technical debt, the addition of a TODO log allows developers to track it and also to see how often code with technical debt is executed which gives an idea of the impact changing that code may have. 

 

    ///

    /// Declares the methods available for logging

    ///

    public interface ILogger

    {

        ///

        /// Debug messages should be used for a noisy spew of data that would help figure out specific problems

        ///

        /// Whatever you want to say

        void Debug(string message);

 

        ///

        /// Debug messages should be used for a noisy spew of data that would help figure out specific problems

        ///

        /// The format of your message, same as String.Format

        /// The values to go into the format

        void Debug(string format, params object[] args);

 

        ///

        /// Trace messages should be used to indicate when you have entered or left a section of code

        ///

        /// Whatever you want to say

        void Trace(string message);

 

        ///

        /// Trace messages should be used to indicate when you have entered or left a section of code

        ///

        /// The format of your message, same as String.Format

        /// The values to go into the format

        void Trace(string format, params object[] args);

 

        ///

        /// Info messages provide minor details - the results of specific actions, etc.

        ///

        /// Whatever you want to say

        void Info(string message);

 

        ///

        /// Info messages provide minor details - the results of specific actions, etc.

        ///

        /// The format of your message, same as String.Format

        /// The values to go into the format

        void Info(string format, params object[] args);

 

        ///

        /// Should only be used to indicate that the app is about to crash hard.

        ///

        /// Whatever you want to say

        void Fatal(string message);

 

        ///

        /// Should only be used to indicate that the app is about to crash hard.

        ///

        /// The format of your message, same as String.Format

        /// The values to go into the format

        void Fatal(string format, params object[] args);

 

        ///

        /// Places where we need to come back and fix something

        ///

        /// Helpful information

        void TODO(string message);

    }

 

The logger base class

It would not take many implementations of the ILogger interface to discover that there is code that is almost always duplicated in each implementation.  Most of the code is determining if a logger is enabled and formatting strings.  Outside of that, it is calling the method that will actually write the text to a log, this is a classic example of where an abstract class is helpful.

 

    ///

    /// The abstract base class common to all types of loggers

    ///

    public abstract class LoggerBase : ILogger

    {

        ///

        /// Initializes a new instance of the LoggerBase class

        ///

        /// The flags that indicate which category of log messages should be displayed

        protected LoggerBase(LogFlag flags)

        {

            this.Flags = flags;

        }

 

        ///

        /// Gets the flags that indicate which category of log messages should be displayed

        ///

        protected LogFlag Flags { get; private set; }

 

        ///

        /// Debug messages should be used for a noisy spew of data that would help figure out specific problems

        ///

        /// Whatever you want to say

        public void Debug(string message)

        {

            if (this.Active(LogFlag.Debug))

            {

                this.WriteLog(LogFlag.Debug, message);

            }

        }

 

        ///

        /// Debug messages should be used for a noisy spew of data that would help figure out specific problems

        ///

        /// The format of your message, same as String.Format

        /// The values to go into the format

        public void Debug(string format, params object[] args)

        {

            this.Debug(string.Format(format, args));

        }

 

        ///

        /// Trace messages should be used to indicate when you have entered or left a section of code

        ///

        /// Whatever you want to say

        public void Trace(string message)

        {

            if (this.Active(LogFlag.Trace))

            {

                this.WriteLog(LogFlag.Trace, message);

            }

        }

 

        ///

        /// Trace messages should be used to indicate when you have entered or left a section of code

        ///

        /// The format of your message, same as String.Format

        /// The values to go into the format

        public void Trace(string format, params object[] args)

        {

            this.Trace(string.Format(format, args));

        }

 

        ///

        /// Info messages provide minor details - the results of specific actions, etc.

        ///

        /// Whatever you want to say

        public void Info(string message)

        {

            if (this.Active(LogFlag.Info))

            {

                this.WriteLog(LogFlag.Info, message);

            }

        }

 

        ///

        /// Info messages provide minor details - the results of specific actions, etc.

        ///

        /// The format of your message, same as String.Format

        /// The values to go into the format

        public void Info(string format, params object[] args)

        {

            this.Info(string.Format(format, args));

        }

 

        ///

        /// Should only be used to indicate that the app is about to crash hard.

        ///

        /// Whatever you want to say

        public void Fatal(string message)

        {

            this.WriteLog(LogFlag.Fatal, message);

        }

 

        ///

        /// Should only be used to indicate that the app is about to crash hard.

        ///

        /// The format to display the information in, same as string.Format

        /// The information to display

        public void Fatal(string format, params object[] args)

        {

            this.Fatal(string.Format(format, args));

        }

 

        ///

        /// Places where we need to come back and fix something

        ///

        /// Helpful information

        public void TODO(string message)

        {

            if (this.Active(LogFlag.TODO))

            {

                this.WriteLog(LogFlag.TODO, message);

            }

        }

 

        ///

        /// Determine if we should write to the log

        ///

        /// The specified output flad

        /// If true, write to the log

        protected bool Active(LogFlag flag)

        {

            return flag == (this.Flags & flag);

        }

 

        ///

        /// The method that decides how the log file is written

        ///

        /// The logflag that is enabled to allow this message to be written

        /// The message to write

        protected abstract void WriteLog(LogFlag flag, string message);

    }

 

DebugLogger

With the interface and the base class, implementing specific kinds of loggers become easy.  For example, this logger will output to the debug output window in VS2010.  Creating other classes of loggers requires an implementation of the WriteLog method which can go anywhere, a file, a webservice, a database, or whatever the problem dictates.

    ///

    /// The debug logger writes to the VS2010 debug window

    ///

    public class DebugLogger : LoggerBase

    {

        ///

        /// Initializes a new instance of the DebugLogger class.

        ///

        /// Which flags are enabled for output

        public DebugLogger(LogFlag flags)

            : base(flags)

        {

        }

 

        ///

        /// Write the log information to the debugger

        ///

        /// The logflag that is enabled to allow this message to be written

        /// The message to write

        protected override void WriteLog(LogFlag flag, string message)

        {

            System.Diagnostics.Debug.WriteLine(message, flag.ToString());

        }

    }

LogFlags

The most important thing about these flags is that they are bits, allowing for any combination of them to be turned on or off.

  

    [Flags]

    public enum LogFlag

    {

        ///

        /// Show Fatal Messages.  These are unhandled exceptions

        /// or anything that would amount to a bug.

        /// This can't be turned off

        ///

        Fatal = 0,

 

        ///

        /// Show Debug messages, this are very verbose and contain important information

        /// when trying to track down a problem

        ///

        Debug = 1,

 

        ///

        /// Show Info Messages.  These aren't very verbose and are only meant to give

        /// a brief insight as to what is going on in the system.

        ///

        Info = 2,

 

        ///

        /// Show Trace messages.  Use these to track entry / exit from methods when you

        /// want to see what is getting called.  They don't need to be on all methods,

        /// only the methods that are interesting to you.

        ///

        Trace = 4,

 

        ///

        /// A reminder to come back and do something. 

        /// Many times you need to do something that incurs some level of technical debt.

        /// Put a TODO log entry where the code lives, when you turn on TODO logging you

        /// can see what the impact of that code is.

        ///

        TODO = 8,

 

        ///

        /// Full Verbose - show all messages

        ///

        All = LogFlag.Debug | LogFlag.Info | LogFlag.Trace | LogFlag.TODO

    }

 

What is missing

The code provided will compile as it is, only an implementation to write to a debugger is provided.  What would an implementation that writes to a file look like?  How would a programmer create an instance of a logger?  How can a programmer allow for a change in the selected logger without recompiling the application?  How would a programmer allow for an implementation to be created in the future, and be able to call that implementation without recompiling? 

Those questions are intentionally unanswered; it is the understanding of the answers not the answers themselves that expose the simplicity of this logger design. 

In Conclusion

It is easy to learn and simple to extend.  Does it do everything the log4xxx loggers do?  Absolutely not, it also does not require a wiki site describing how to use it. 

It is a logger, it logs.