LogManager Tests

Question

I should have started with this code. I wrote my logging API without writing unit tests, and since I recently wrote an automagic unit testing API I though I might as well go ahead and use it.

So I wrote a MockLogger implementation of the ILogger interface, still with a default instance (like all other ILogger implementations in the library), but I kept it private, so client code can't see/use it.

MockLogger class module

This logger doesn't actually log anything - instead, it raises a Logging event that the test code can listen to and evaluate the logger name, log level and message being passed to it by the LogManager:

Option Explicit Private Type TMockLogger Name As String MinLevel As LogLevel Formatter As ILogMessageFormatter End Type Private this As TMockLogger Public Event Logging(ByVal loggerName As String, ByVal level As LogLevel, ByVal message As String) Implements ILogger Public Function Create(ByVal loggerName As String, ByVal loggerMinLevel As LogLevel, Optional ByVal logFormatter As ILogMessageFormatter = Nothing) If logFormatter Is Nothing Then Set logFormatter = DefaultLogMessageFormatter.Instance End If Dim result As New MockLogger Set result.Formatter = logFormatter result.MinLevel = loggerMinLevel result.Name = loggerName 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 Formatter() As ILogMessageFormatter Set Formatter = this.Formatter End Property Friend Property Set Formatter(ByVal value As ILogMessageFormatter) Set this.Formatter = value End Property Private Property Get ILogger_Formatter() As ILogMessageFormatter Set ILogger_Formatter = this.Formatter End Property Private Sub ILogger_Log(ByVal level As LogLevel, ByVal message As String) RaiseEvent Logging(this.Name, level, message) 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

LogManagerTests class module

This is the crux of the code I'd like peer reviewed here; this class contains all the tests for the LogManager class:

TestCannotRegisterLoggerTwice ensures that a given logger name can only be registered once.
TestMustRegisterLogger ensures that a named logger is registered before it can be used.
TestTraceLoggerEnablesAllLogLevels ensures that IsEnabled will return True for all levels when a logger is registered with MinLevel set to Trace (the lowest level).
TestLogManagerPassesSpecifiedMessage ensures that the LogManager passes the specified message without altering it.
TestOnlySpecifiedLoggerLogs ensures that when a specific logger is specified to the LogManager.Log method, only the specified logger will write a log entry.

The TestEngine class was slightly modified with a new feature:

Initialize method runs before every test if it exists in the test class.
Cleanup method runs after every test if it exists in the test class.

Option Explicit Private expectedLogger As String Private expectedLevel As LogLevel Private expectedMessage As String Private WithEvents mock As MockLogger Private WithEvents mock2 As MockLogger Public Sub Initialize() LogManager.UnregisterAll End Sub Public Sub Cleanup() LogManager.UnregisterAll If Not mock Is Nothing Then Set mock = Nothing expectedLevel = -1 expectedMessage = vbNullString End Sub Public Sub TestCannotRegisterLoggerTwice() On Error GoTo ExpectedError Dim logger As ILogger Set logger = MockLogger.Create("TestLogger", TraceLevel) LogManager.Register logger LogManager.Register logger Assert.Fail "Expected error was not raised." CleanExit: Exit Sub ExpectedError: Assert.AreEqual LogManagerError.DuplicateLoggerError, Err.Number Err.Clear Resume CleanExit End Sub Public Sub TestMustRegisterLogger() On Error GoTo ExpectedError If LogManager.IsEnabled(TraceLevel) Then Assert.Inconclusive "Trace level was enabled before test started." End If LogManager.Log TraceLevel, "This shouldn't be working.", "TestLogger" Assert.Fail "Expected error was not raised." CleanExit: Exit Sub ExpectedError: Assert.AreEqual LogManagerError.LoggerNotRegisteredError, Err.Number Err.Clear Resume CleanExit End Sub Public Sub TestTraceLoggerEnablesAllLogLevels() If LogManager.IsEnabled(TraceLevel) Then Assert.Inconclusive "Trace level was enabled before test started." End If LogManager.Register MockLogger.Create("TestLogger", TraceLevel) Assert.IsTrue LogManager.IsEnabled(TraceLevel), "Trace level is not enabled." Assert.IsTrue LogManager.IsEnabled(DebugLevel), "Debug level is not enabled." Assert.IsTrue LogManager.IsEnabled(InfoLevel), "Info level is not enabled." Assert.IsTrue LogManager.IsEnabled(WarnLevel), "Warn level is not enabled." Assert.IsTrue LogManager.IsEnabled(ErrorLevel), "Error level is not enabled." Assert.IsTrue LogManager.IsEnabled(FatalLevel), "Fatal level is not enabled." End Sub Public Sub TestLogManagerPassesSpecifiedMessage() expectedLogger = "TestLogger" expectedLevel = TraceLevel expectedMessage = "test message" Set mock = MockLogger.Create(expectedLogger, TraceLevel) LogManager.Register mock LogManager.Log expectedLevel, expectedMessage End Sub Public Sub TestOnlySpecifiedLoggerLogs() expectedLogger = "TestLogger" expectedLevel = TraceLevel expectedMessage = "test message" Set mock = MockLogger.Create(expectedLogger, TraceLevel) LogManager.Register mock Set mock2 = MockLogger.Create("unexpected logger", TraceLevel) LogManager.Register mock2 LogManager.Log expectedLevel, expectedMessage, expectedLogger End Sub Private Sub mock_Logging(ByVal loggerName As String, ByVal level As LogLevel, ByVal message As String) Assert.AreEqual expectedLogger, loggerName Assert.AreEqual expectedLevel, level Assert.AreEqual expectedMessage, message End Sub Private Sub mock2_Logging(ByVal loggerName As String, ByVal level As LogLevel, ByVal message As String) Assert.AreEqual expectedLogger, loggerName Assert.AreEqual expectedLevel, level Assert.AreEqual expectedMessage, message End Sub

Running the tests produces this output in the immediate pane:

TestEngine.RunAllTests "Logging", new LogManagerTests 2014-09-29 23:19:24 TestCannotRegisterLoggerTwice: [PASS] 2014-09-29 23:19:24 TestMustRegisterLogger: [PASS] 2014-09-29 23:19:24 TestTraceLoggerEnablesAllLogLevels: [PASS] 2014-09-29 23:19:24 TestLogManagerPassesSpecifiedMessage: [PASS] 2014-09-29 23:19:24 TestOnlySpecifiedLoggerLogs: [PASS]

I have mixed feelings about the event handling and instance-level variables here, I wonder if there would be a better way of writing these unit tests, especially given that TestOnlySpecifiedLoggerLogs is delegating all assertions to the event handlers.

Also.. have I missed some test opportunities?

Here's the SUT, for context:

LogManager class module (System Under Test)

Option Explicit Public Enum LogLevel TraceLevel = 0 DebugLevel InfoLevel WarnLevel ErrorLevel FatalLevel End Enum Public Enum LogManagerError DuplicateLoggerError = vbObjectError + 1098 LoggerNotRegisteredError End Enum Private Type TLogManager Loggers As New Dictionary End Type Private this As TLogManager Public Sub Register(ByVal logger As ILogger) If Not this.Loggers.Exists(logger.Name) Then this.Loggers.Add logger.Name, logger Else Err.Raise LogManagerError.DuplicateLoggerError, "LogManager.Register", "There is already a logger registered with name '" & logger.Name & "'." End If End Sub Public Sub UnregisterAll() this.Loggers.RemoveAll 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 LogManagerError.LoggerNotRegisteredError, "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 level, message End If End Sub

I've got nothing.... I don't like having multiple asserts in a test, but how else would you test TestTraceLoggerEnablesAllLogLevels()? — RubberDuck
– RubberDuck, Commented Oct 1, 2014 at 20:45
@RubberDuck I found a pretty clean solution, I'll only post it after the bounty expires, if it's not posted already by then. 200-points hint — Mathieu Guindon
– Mathieu Guindon, Commented Oct 4, 2014 at 5:59

Malachi · Accepted Answer · 2014-10-07 19:17:18Z

As I was looking through this code the duplicate registration was rubbing me the wrong way, so I investigated it a little bit because I was thinking to myself, what if I want to re-register the logger?

That is when I noticed that you don't have a method for releasing (un-Registering) one single logger, you can only release (un-register) all or nothing.

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

I don't necessarily want to release one as I might want to reset it, but both methods would be helpful I think.

What if I just want to dispose the logger? Maybe I am going too far here for VBA...

Okay, so I am looking at TestTraceLoggerEnablesAllLogLevels and at first I couldn't make heads or tails of what is supposed to pass and what is supposed to fail, but I think that I figured that out.

So what I would do first is create a fun array and go through this in a for loop or use a list (if I have that functionality in VBA)

I guess what I would do is take the already created Enum LogLevels and iterate through that asserting what is true...

I probably changed the code slightly because I don't think I have the right syntax, but here is what I am thinking

Public Sub TestTraceLoggerEnablesAllLogLevels() If LogManager.IsEnabled(TraceLevel) Then Assert.Inconclusive "Trace level was enabled before test started." End If LogManager.Register MockLogger.Create("TestLogger", TraceLevel) Dim level as LogLevel For level = TraceLevel To FatalLevel Assert.IsTrue LogManager.IsEnabled(level), level & "level is not enabled." Next level End Sub

TBH the UnregisterAll method was added because the class is static, and I needed a way to make the tests independent from each other - you're probably right, some Unregister method could be useful. Any idea for cleaning up the multiple assertions in TestTraceLoggerEnablesAllLevels? BTW this has already "gone too far for VBA" ;) — Mathieu Guindon
– Mathieu Guindon, Commented Oct 7, 2014 at 17:07
It went too far for VBA before @Mat'sMug took my idea and ran with it. =;)- — RubberDuck
– RubberDuck, Commented Oct 7, 2014 at 19:15

Community · Accepted Answer · 2017-05-23 12:40:49Z

Public Sub TestCannotRegisterLoggerTwice() On Error GoTo ExpectedError Dim logger As ILogger Set logger = MockLogger.Create("TestLogger", TraceLevel) LogManager.Register logger LogManager.Register logger Assert.Fail "Expected error was not raised." CleanExit: Exit Sub ExpectedError: Assert.AreEqual LogManagerError.DuplicateLoggerError, Err.Number Err.Clear Resume CleanExit End Sub

That's a rather ugly way of making a test expect an error. How about this instead:

'@ExpectedError(1098) Public Sub TestCannotRegisterLoggerTwice() Dim logger As ILogger Set logger = MockLogger.Create("TestLogger", TraceLevel) LogManager.Register logger LogManager.Register logger End Sub

This requires a number of changes in the UnitTesting and Reflection libraries, to recognize the ExpectedErrorAttribute and make attributes support parameters. These libraries are outside the scope of this review, but require the SUT LogManager class to raise an application-defined or object-defined error instead, as shown on Stack Overflow - adding vbObjectError to the error number causes the testing library to only see an error #440 - Automation error, which prevents these automagic "attributes" from working properly.

So this:

Public Enum LogManagerError DuplicateLoggerError = vbObjectError + 1098 LoggerNotRegisteredError End Enum

Becomes this:

Public Enum LogManagerError DuplicateLoggerError = 1098 LoggerNotRegisteredError End Enum

And now the tests that expect an error can be greatly simplified:

'@ExpectedError(1098) Public Sub TestCannotRegisterLoggerTwice() Dim logger As ILogger Set logger = MockLogger.Create("TestLogger", TraceLevel) LogManager.Register logger LogManager.Register logger End Sub '@ExpectedError(1099) Public Sub TestMustRegisterLogger() If LogManager.IsEnabled(TraceLevel) Then Assert.Inconclusive "Trace level was enabled before test started." End If LogManager.Log TraceLevel, "This shouldn't be working.", "TestLogger" End Sub

This also requires the TestEngine to no longer treat tests without assertions as inconclusive, as recommended here - such tests should simply pass.

A test that expects an error should succeed if the specified error is raised, fail if it isn't, and be inconclusive if an unexpected error is raised.

Actually, since these automagic comments/attributes are so fantastic, why not use them, and drop this annoying Test prefix to all test method names, which are already verbose enough as is?

'@TestMethod '@ExpectedError(1098) Public Sub CannotRegisterLoggerTwice() Dim logger As ILogger Set logger = MockLogger.Create("TestLogger", TraceLevel) LogManager.Register logger LogManager.Register logger End Sub '@TestMethod '@ExpectedError(1099) Public Sub MustRegisterLogger() If LogManager.IsEnabled(TraceLevel) Then Assert.Inconclusive "Trace level was enabled before test started." End If LogManager.Log TraceLevel, "This shouldn't be working.", "TestLogger" End Sub

Note that the order of the attributes isn't important, but it's best to have them in the same order in every method, for consistency.

This StackOverflow answer has a very interesting explanation about vbObjectError and the behavior of custom error numbers. Bottom line: "At my workplace, the standard is to ignore vbObjectError to take advantage of this behaviour." — Mathieu Guindon
– Mathieu Guindon, Commented Oct 5, 2014 at 2:03

Stack Exchange Network

LogManager Tests

2 Answers 2

You must log in to answer this question.

Linked

Hot Network Questions

LogManager Tests

2 Answers 2

You must log in to answer this question.

Linked

Related

Hot Network Questions