29
\$\begingroup\$

Whenever I need logging functionality in , I use a logging framework, such as NLog. Obviously there's no logging framework for , at least none that I know of.

As much as I love using NLog, the way it works, with targets, rules and loggers, was going to be way too heavy and complex for my needs.

So I kept the idea of a logger, and centralized log message formatting in a LogManager static class - this class provides the entire client API; client code doesn't directly deal with ILogger implementations, rather calls the LogManager.Log method, which "dispatches" the log message to all relevant loggers.

LogManager class module

Option Explicit

Public Enum LogLevel
    TraceLevel = 0
    DebugLevel
    InfoLevel
    WarnLevel
    ErrorLevel
    FatalLevel
End Enum

Private Type TLogManager
    Formatter As ILogMessageFormatter
    Loggers As New Dictionary
End Type

Private this As TLogManager

Public Property Get Formatter() As ILogMessageFormatter
    Set Formatter = this.Formatter
End Property

Public Property Set Formatter(ByVal value As ILogMessageFormatter)
    Set this.Formatter = value
End Property

Public Sub Register(ByVal logger As ILogger)
    If Not this.Loggers.Exists(logger.Name) Then
        this.Loggers.Add logger.Name, logger
    Else
        Err.Raise vbObjectError + 1098, "LogManager.Register", "There is already a logger registered with name '" & logger.Name & "'."
    End If
End Sub

Public Function IsEnabled(ByVal level As LogLevel) As Boolean

    Dim logger As ILogger
    Dim item As Variant
    For Each item In this.Loggers.Items
        Set logger = item
        If level >= logger.MinLevel Then
            IsEnabled = True
            Exit Function
        End If
    Next

End Function

Public Sub Log(ByVal level As LogLevel, ByVal message As String, Optional ByVal loggerName As String)

    Dim logger As ILogger
    If loggerName = vbNullString Then

        Dim item As Variant
        For Each item In this.Loggers.Items
            Set logger = item
            LogWith logger, level, message
        Next

    ElseIf this.Loggers.Exists(loggerName) Then

        LogWith this.Loggers(loggerName), level, message

    Else
        Err.Raise vbObjectError + 1099, "LogManager.Log", "There is no registered logger named '" & loggerName & "'."
    End If

End Sub

Private Sub LogWith(ByVal logger As ILogger, ByVal level As LogLevel, ByVal message As String)
    If level >= logger.MinLevel Then
        logger.Log FormatMessage(level, logger.Name, message)
    End If
End Sub

Friend Function FormatMessage(ByVal level As LogLevel, ByVal loggerName As String, ByVal message As String)
    FormatMessage = this.Formatter.FormatMessage(level, loggerName, message)
End Function

Private Sub Class_Initialize()
    Set this.Formatter = New DefaultLogMessageFormatter
End Sub

I don't like *Manager names, so suggestions are more than welcome... OTOH NLog does have a LogManager class.

ILogMessageFormatter class module (interface)

Option Explicit

Public Function FormatMessage(ByVal level As LogLevel, ByVal loggerName As String, ByVal message As String) As String
End Function

This interface, along with the LogManager.Formatter property, allows configuring how log messages are output. Here's the default implementation:

DefaultLogMessageFormatter class module

Option Explicit
Implements ILogMessageFormatter

Private Function ILogMessageFormatter_FormatMessage(ByVal level As LogLevel, ByVal loggerName As String, ByVal message As String) As String
    ILogMessageFormatter_FormatMessage = Framework.Strings.Format("{0:s}\t{1}\t[{2}]\t{3}", Now, loggerName, FormatLogLevel(level), message)
End Function

Private Function FormatLogLevel(ByVal level As LogLevel) As String

    Select Case level

        Case LogLevel.DebugLevel
            FormatLogLevel = "DEBUG"

        Case LogLevel.ErrorLevel
            FormatLogLevel = "ERROR"

        Case LogLevel.FatalLevel
            FormatLogLevel = "FATAL"

        Case LogLevel.InfoLevel
            FormatLogLevel = "INFO"

        Case LogLevel.TraceLevel
            FormatLogLevel = "TRACE"

        Case LogLevel.WarnLevel
            FormatLogLevel = "WARNING"

    End Select

End Function

The ILogger interface merely stipulates that a logger has a name and min level property, and a Log method accepting the formatted log output:

ILogger class module (interface)

Option Explicit

Public Sub Log(ByVal output As String)
End Sub

Public Property Get Name() As String
End Property

Public Property Get MinLevel() As LogLevel
End Property

I have written 2 implementations for the ILogger interface, both in classes with a default instance, PublicNotCreatable and exposing a Create method to return an instance; one writes to the immediate pane and is called DebugLogger:

DebugLogger class module

Option Explicit

Private Type TDebugLogger
    Name As String
    MinLevel As LogLevel
End Type
Private this As TDebugLogger

Implements ILogger

Public Function Create(ByVal loggerName As String, ByVal loggerMinLevel As LogLevel) As ILogger

    Dim result As New DebugLogger
    result.Name = loggerName
    result.MinLevel = loggerMinLevel
    Set Create = result

End Function

Friend Property Get Name() As String
    Name = this.Name
End Property

Friend Property Let Name(ByVal value As String)
    this.Name = value
End Property

Friend Property Get MinLevel() As LogLevel
    MinLevel = this.MinLevel
End Property

Friend Property Let MinLevel(ByVal value As LogLevel)
    this.MinLevel = value
End Property

Private Sub ILogger_Log(ByVal output As String)
    Debug.Print output
End Sub

Private Property Get ILogger_MinLevel() As LogLevel
    ILogger_MinLevel = this.MinLevel
End Property

Private Property Get ILogger_Name() As String
    ILogger_Name = this.Name
End Property

The other one writes to a specified text file, and is called FileLogger:

FileLogger class module

Option Explicit

Private Type TFileLogger
    Name As String
    MinLevel As LogLevel
    LogFile As String
    Writer As TextWriter
End Type
Private this As TFileLogger

Implements ILogger

Public Function Create(ByVal loggerName As String, ByVal loggerMinLevel As LogLevel, ByVal path As String) As ILogger

    Dim result As New FileLogger
    result.Name = loggerName
    result.MinLevel = loggerMinLevel
    Set result.Writer = TextWriter.Create
    result.LogFile = path
    Set Create = result

End Function

Friend Property Get Name() As String
    Name = this.Name
End Property

Friend Property Let Name(ByVal value As String)
    this.Name = value
End Property

Friend Property Get MinLevel() As LogLevel
    MinLevel = this.MinLevel
End Property

Friend Property Let MinLevel(ByVal value As LogLevel)
    this.MinLevel = value
End Property

Friend Property Get LogFile() As String
    LogFile = this.LogFile
End Property

Friend Property Let LogFile(ByVal value As String)
    this.LogFile = value
End Property

Friend Property Get Writer() As TextWriter
    Set Writer = this.Writer
End Property

Friend Property Set Writer(ByVal value As TextWriter)
    Set this.Writer = value
End Property

Private Sub ILogger_Log(ByVal output As String)
    If this.Writer.OpenFile(this.LogFile) Then

        this.Writer.WriteLine output
        this.Writer.CloseFile

    Else
        Err.Raise vbObjectError + 1092, "ILogger.Log", "FileLogger.LogFile could not be opened."
    End If
End Sub

Private Property Get ILogger_MinLevel() As LogLevel
    ILogger_MinLevel = this.MinLevel
End Property

Private Property Get ILogger_Name() As String
    ILogger_Name = this.Name
End Property

This FileLogger uses a TextWriter object that handles opening, writing and closing files - it's out of scope for this post, but it's reviewable here.

Client Code

The client code could implement ILogger differently, and make one that writes log entries into, say, a database. FileLogger and DebugLogger are provided for convenience, but nothing forbids implementing and registering custom ILoggers on the client side.

Referencing this Logging.xlam Excel add-in in a VBAProject enables writing code like this:

Public Sub TestLogger()

    On Error GoTo CleanFail

    LogManager.Register DebugLogger.Create("MyLogger", DebugLevel)
    LogManager.Register Filelogger.Create("TestLogger", ErrorLevel, "C:\Dev\VBA\log.txt")

    LogManager.Log TraceLevel, "logger has been created."
    LogManager.Log InfoLevel, "it works!"

    Debug.Print LogManager.IsEnabled(TraceLevel)

    Dim boom As Integer
    boom = 1 / 0

CleanExit:
    LogManager.Log DebugLevel, "we're done here.", "TestLogger"
    Exit Sub

CleanFail:
    LogManager.Log ErrorLevel, Err.Description
    Resume CleanExit

End Sub

This code generates the following output in C:\Dev\VBA\log.txt:

2014-09-28 19:42:44 TestLogger  [ERROR] Division by zero

And the following output in the immediate pane:

TestLogger
2014-09-28 19:42:44 MyLogger    [INFO]  it works!
False
2014-09-28 19:42:44 MyLogger    [ERROR] Division by zero

Because there's no logger with a MinLevel at TraceLevel, all TraceLevel log entries are ignored; the client code can use the LogManager.IsEnabled(LogLevel) function to check if a given log level is currently enabled, and register loggers conditionally.

Improve this question
\$\endgroup\$
10
  • \$\begingroup\$ This is pretty awesome. One minor item, but not with the code: I don't know if it got changed after this post, but the TextWriter class referenced in the FileLogger class isn't found at the link provided. Perhaps FileWriter used to be called TextWriter? Either way, I assume the class used at the time has a methods that Create, Open, Close, and WriteLine to a text file with the loggerFile name. \$\endgroup\$
    – GlennFromIowa
    Jul 20, 2016 at 16:12
  • \$\begingroup\$ This is a bit beyond the scope of you code here, but I don't know how else to reach you. I've been reading through a bunch of your code reviews in my attempts to get much more OOP in my use of vba. When you write components like this (logger, filewriter, etc), do you usually keep them in their own .xlam files and then reference them as if they are libraries? \$\endgroup\$
    – ArcherBird
    Aug 15, 2019 at 18:29
  • 1
    \$\begingroup\$ @ArcherBird until someone comes up with a package manager solution for VBA code (e.g. nuget, npm, etc.), that's a good way to keep these components nearby. Another way is to have a \Dev\VBA folder with all the modules (under git source control!) from which files can easily be imported into any new VBA project. \$\endgroup\$
    – Mathieu Guindon
    Aug 15, 2019 at 18:34
  • 1
    \$\begingroup\$ @ArcherBird if you're using Rubberduck, the VB_PredeclaredId = True hidden attribute that gives a class a default instance is easily added with a @PredeclaredId annotation at the top of the module, and there's a "predeclared class" template you can add to your project from the Code Explorer toolwindow, so that you get the attribute for free. This logger code uses factory methods off default instances (and predates Rubberduck!).. I'm finding factory methods (combined with explicit interfaces) rather awesome, actually - especially in an add-in setting: you really shape up a public API. \$\endgroup\$
    – Mathieu Guindon
    Aug 15, 2019 at 20:37
  • 1
    \$\begingroup\$ @ArcherBird it's a rather hard-to-discover feature.. See VB_Attribute Annotations and Using Folder annotations on the repository's wiki. \$\endgroup\$
    – Mathieu Guindon
    Aug 15, 2019 at 21:05

1 Answer 1

Reset to default
8
\$\begingroup\$

  • It's really nit-picky, but there's no reason to declare the starting point for an Enum unless you don't want to start at zero.

    Public Enum LogLevel
  TraceLevel = 0
  DebugLevel
  '.....

    You're also repeating yourself a lot here. It's almost hungarian. They're all LogLevels. I think you'd be fine to shorten these up to Trace,Debug, Info etc. Of course, can be a bit strange about when you can and can't call enum members with a full reference like this LogLevel.Trace, so you may or may not want to actually do that. I'm on the fence about it personally. But you can't, because Debug is a reserved keyword....

  • I really recommend an Enum for your custom error numbers. It's much easier to maintain if they're all in one place.

    Err.Raise vbObjectError + 1098, "LogManager.Register", "There is already a logger registered with name '" & logger.Name & "'."
'.......
Err.Raise vbObjectError + 1099, "LogManager.Log", "There is no registered logger named '" & loggerName & "'."

    These become much simpler with an Enum that looks something like this.

    Public Enum LogMangerError
    SomeError = vbObjectError + 1098
    SomeOtherError 
End Enum

'......

Err.Raise SomeError, "LogManager.Register", "There is already a logger registered with name '" & logger.Name & "'."

  • This is an absolute pleasure to read. Great use of white space.

    Select Case level

    Case LogLevel.DebugLevel
        FormatLogLevel = "DEBUG"

    Case LogLevel.ErrorLevel
        FormatLogLevel = "ERROR"

    Case LogLevel.FatalLevel
        FormatLogLevel = "FATAL"

    Case LogLevel.InfoLevel
        FormatLogLevel = "INFO"

    Case LogLevel.TraceLevel
        FormatLogLevel = "TRACE"

    Case LogLevel.WarnLevel
        FormatLogLevel = "WARNING"

End Select

Maybe I'm tired, or maybe it's just good. I can't tell for sure at the moment, but I think you have some pretty solid code here. Good naming and formatting, as well as a very nice abstraction and use of interfaces.

Improve this answer
\$\endgroup\$

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge that you have read and understand our privacy policy and code of conduct.

Not the answer you're looking for? Browse other questions tagged or ask your own question.