By Willy Van den Driessche

2 Log or not 2 Log

If there is one thing that every robust application needs, then it is logging. Logging is the act of dumping messages that might be interesting.  This messages can typically prove invaluable when tracking down problems.

Logging is the formal incarnation of the ancient debug.Print statements in the code.

Now it is one thing to know that every application needs logging, it is quite another thing to define what should be in a logging Component. I came up with the following requirements :

• You should be able to log a message
• You should be able to see where the message comes from
• You should be able to give severities to a message.
• Client code should not bother where the log message goes to.

When I have requirements such as these, I immediately formalize them in an interface definition.  Here is what I came up with :

Interface iLogContext
Public Enum eLogType
   eltFirstLogType = 1
   eltFatalError = 1
   eltError = 2
   eltWarning = 3
   eltHint = 4
   eltLastLogType = 4
End Enum

Public Sub LogString( ByVal eType As eLogType, _
                     ByVal strModuleName As String, _
                     ByVal strMessage As String)

A file logger

The first and by far most important implementation I wrote for this interface is cLogCtxFile. This logcontext dumps its message to a file. The implementation code is below :

Option Explicit

Implements iLogContext

Private mLogginglevel     As eLogType
Private mFileName         As String

Friend Sub Initialize(ByVal strFileName As String)
  mFileName = strFileName
End Sub

Private Sub Log(strMessage As String)
  On Error GoTo brutallyInterruptUser
  Dim iFile As Integer
  iFile = FreeFile
  Open mFileName For Append As File
  Print iFile, strMessage
  Close iFile
  Exit Sub
 
brutallyInterruptUser:
  MsgBox strMessage, vbCritical
End Sub
Public Sub iLogContext_LogString( _
                   ByVal eType As eLogType, _
                   ByVal strModuleName As String, _
                   ByVal strMessage As String)
   Dim strSignature As String
   Select Case eType
       Case eltHint
           strSignature = "[HINT]          "
       Case eltWarning
           strSignature = "[WARNING]       "
       Case eltError
           strSignature = "[**ERROR**]     "
       Case eltFatalError
           strSignature = "[**FATAL ERROR**]"
   End Select
   Log Now & "[" & strModuleName & "] :" & strSignature & strMessage
End Sub

If you read the code above, you’ll see the brutallyInterruptUser label.  This is typical in any logger. Loggers can do little else than be silent or noisy.  Since loggers are the most basic stuff of an application, they can’t build on any other application service.

Another detail is that the file is opened and closed for every message.  This ensures that all messages are written in case of a GPF and that other components can use the file while the logger doesn’t use them.

Since a FileLogger is never threated any different than any other logger, I made the class private and I let users create it with a small factory function:

Public function CreateFileLogger(byval strFileName as string ) as iLogContext
   dim objResult as cLogCtxFile
   set objResult = new cLogCtxFile
   objResult.initialize strFileName
   set CreateFileLogger = objResult
end sub

A Singleton

Now a logcontext is typically something which is set up at application startup and then never changed again.  I therefore decided to make the logger a singleton that can be used by the entire application. That adds up to the following code :

Private mLoggerSingleton as iLogContext
Public sub setLogger (byval aLogger as iLogContext)
   set mLoggerSingleton = aLogger
end sub
public function Logger as iLogContext
   set Logger = mLoggerSingleton
end function

With this code in place, a client can already write code like this :

Logger.LogString eltHint, "MyComp.myClass.myMethod", "this happens"

Notice that I use the convention “PROGID.CLASSNAME.METHODNAME” for the modulename parameter.  Any convention will do, but “here”, and “there” are not exactly useful when you want to debug an application.  Make up your own mind about it.

A Facade

Now there are two problems.  First : this code is a little to long to write. Therefore the logger will probably be used less than it needs to.  I therefore created 5 facade methods :

Sub LogString(ByVal eType As eLogType, _
                     ByVal strModuleName As String, _
                     ByVal strMessage As String)
Sub LogHint(ByVal strModuleName As String, _
                   ByVal strMessage As String)
Sub LogWarning(ByVal strModuleName As String, _
                     ByVal strMessage As String)
Sub LogError(ByVal strModuleName As String, _
                   ByVal strMessage As String)
Sub LogFatalError(ByVal strModuleName As String, _
                     ByVal strMessage As String)

All of these methods route their call to the singleton.  These methods reduce the previous call to

LogHint "MyComp.myClass.myMethod", "this happens"

In addition, I wrote an other two facade methods, which are very useful :

Sub LogErrorObject(ByVal strModuleName As String, _
                     ByVal objError As ErrObject)
Sub LogErrorObjectAndRaise(ByVal strModuleName As String, _
                     ByVal objError As ErrObject)

The first method will log an error, the second will do the same but ‘reRaise’ the error.

Default logger : MsgBoxLogger

There is still one issue with the current implementation.  If the client logs a message before the singleton is installed, a runtime error (Object Variable or With Block not set) occurs.   I decided to let the singleton default to a MsgBoxLogger. That way the message that occur when the application starts up and before the singleton is officially installed are popped up as a MessageBox. Needless to say, the singleton should be installed a fast as possible.  Having a MessageBox logger is so annoying that you will soon change the application code to initialize the logger in time.  Therefore the singleton code becomes :

public function Logger as iLogContext
  if mLoggerSingleton is nothing then _
     set mLoggerSingleton = CreateMsgBoxLogger
  set Logger = mLoggerSingleton
end function

More loggers

Now I had a functionaing activeX DLL that would handle my logging needs. It quickly became clear that I needed more implementations for logger.  The first of these is cLogCtxImmediate which would log its messages to the Immediate Window when debugging the application inside the VB IDE.

The next logger I wrote is a decorator : cLogCtxFiltered. This logContext will decorate any other logcontext. It has an internal log level. It will only pass the requests that are above the level to the log context it wraps. With this logcontext, you are able to log only errors and fatalErrors. For a production setup this is sufficient.  There is no need to bother your clients with hints or warnings all the time.

Another logger is a composite : CLogCtxMultiPlexer. As the name implies, this LogContext holds any number of other Logcontexts and sends each request to all of them. This allows you to view your messages in the immediate window and have them logged to a file at the same time. If you combine this with the Filtered Logger, you can even have your errors pop up in a message box, all message are written to a file and written to the immediate window.

There is one thing about loggers that makes them less useless. If you log your errors silently to a file, chances are you will never see them.  You won’t notice and you won’t be opening the file all the time.  Therefore I wrote a cLogCtxRichText, which will log all its messages in a rich text.  It will use color to indicate the severity of the message. If you have a box like that on your main screen, there won’t be any message that slip your attention.

Here’s a final overview of all logger implementations:

Conclusion

A topic highly related to Logging is Tracing.  With tracing you typically write a message upon method entry and another upon message exit. I wrote a little addin to write this code for me. It uses the logging component to write out the messages.

This concludes my little logging component.  I am quite happy with it, since it never gets in the way. Is is simple to use and set up.  The decorator and composite make it very flexible and up until now, I didn’t have any other logging needs. If you wan to log to the NT Log can always create a wrapper of App.LogEvent.

Subitems :