13
\$\begingroup\$

Recently I wrote a logging API that features an ILogger interface. I wanted to extend my library with a DatabaseLogger implementation, and I had to modify the API a little bit for this to work, but I think it was worth it.

Each ILogger instance now has its own ILogMessageFormatter. I no longer needed all loggers to be formatted identically, and I can now have a DebugLogger that writes different-looking entries than those written with a FileLogger, or even with another DebugLogger instance.

Here's the new ILogger interface:

ILogger class module (interface)

Option Explicit

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

Public Property Get Name() As String
End Property

Public Property Get MinLevel() As LogLevel
End Property

Public Property Get Formatter() As ILogMessageFormatter
End Property

I didn't change the ILogMessageFormatter interface, but the DatabaseLogMessageFormatter implementation ignores the parameters and uses the FormatMessage method to supply the DatabaseLogger with the SQL command string:

DatabaseLogMessageFormatter class module

Like all public classes in the library, the formatter has a default instance. But unlike the DefaultLogMessageFormatter implementation, this one doesn't expose the default instance, and requires the client to call the Create factory method to get an instance.

Option Explicit

Private Type TDatabaseLogMessageFormatter
    SqlCommandText As String
End Type

Private this As TDatabaseLogMessageFormatter
Implements ILogMessageFormatter

Public Function Create(ByVal sql As String) As DatabaseLogMessageFormatter

    Dim result As New DatabaseLogMessageFormatter
    result.SqlCommandText = sql

    Set Create = result

End Function

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

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

Private Sub ValidateSQL(ByVal sql As String)

    'require an INSERT INTO command:
    If Not Framework.Strings.StartsWith("INSERT INTO ", sql, False) Then _
        OnInvalidSqlError

    'require 3 parameters (in that order, but that can't be validated):
    ' ?> @level
    ' ?> @logger
    ' ?> @message
    If Not Framework.Strings.Count(sql, "?") = 3 Then _
        OnInvalidSqlError

End Sub

Private Sub OnInvalidSqlError()
    Err.Raise vbObjectError + 1192, "SqlCommandText", "Command must be 'INSERT INTO', with 3 parameters."
End Sub

Private Function ILogMessageFormatter_FormatMessage(ByVal level As LogLevel, ByVal loggerName As String, ByVal message As String) As String
    ILogMessageFormatter_FormatMessage = this.SqlCommandText
End Function

The formatter puts a constraint on the SQL command, that it must contain 3 parameters. This would be a typical one:

INSERT INTO dbo.VBALogger(LogLevel,Logger,Message,DateInserted) VALUES (?,?,?,GETDATE());

The logger implementation is relatively simple - each instance encapsulates its own SqlCommand object, which wraps an ADODB connection.

DatabaseLogger class module

Option Explicit
Private Type TFileLogger
    Name As String
    MinLevel As LogLevel
    Formatter As ILogMessageFormatter
    SqlInsertCmd As String
    SqlCmd As SqlCommand
End Type

Private this As TFileLogger

Implements ILogger

Public Function Create(ByVal loggerName As String, ByVal loggerMinLevel As LogLevel, ByVal logFormatter As ILogMessageFormatter, ByVal connString As String, ByVal sqlInsert As String) As ILogger

    Dim result As New DatabaseLogger

    result.Name = loggerName
    result.MinLevel = loggerMinLevel
    Set result.Formatter = logFormatter
    result.SqlInsertCmd = sqlInsert
    Set result.SqlCmd = SqlCommand.Create(connString)

    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

Friend Property Get SqlCmd() As SqlCommand
    Set SqlCmd = this.SqlCmd
End Property

Friend Property Set SqlCmd(ByVal value As SqlCommand)
    Set this.SqlCmd = value
End Property

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

Friend Property Let SqlInsertCmd(ByVal value As String)
    this.SqlInsertCmd = 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)

    'parameters are assumed to be in that order:
    ' 1. @level
    ' 2. @logger
    ' 3. @message
    Dim sqlLevel As String
    sqlLevel = DefaultLogMessageFormatter.FormatLogLevel(level)

    Dim sqlLogger As String
    sqlLogger = this.Name

    Dim sqlMessage As String
    sqlMessage = message

    Dim result As Boolean
    result = this.SqlCmd.QuickExecuteNonQuery(this.Formatter.FormatMessage(level, this.Name, message), _
                                              sqlLevel, sqlLogger, sqlMessage)

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

I'm confident that client code would have a very hard time accidentally injecting executable SQL through the logging API, but I'd like at least another pair of eyes to confirm this.

SqlCommand.QuickExecuteNonQuery is, like all QuickXxxxx methods in the SqlCommand API, responsible for creating, opening, and closing the ADODB connection; because the instance has its own connection string, there could be two DatabaseLogger instances each logging to different databases/servers.


The client code needs to create the formatter, and pass it to the function that creates the logger. The below code registers a new DatabaseLogger with MinLevel at TraceLevel (the lowest log level), which means whenever a LogManager.Log call is made at any level, the logger will log the entry.

It also registers a DebugLogger and a FileLogger, respectively at Debug and Error min log levels:

Public Sub TestLogger()

    On Error GoTo CleanFail

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

    Dim connString As String
    connString = "Provider=SQLOLEDB.1;Data Source=;Initial Catalog=CodeReviewSandbox;Integrated Security=SSPI;Persist Security Info=True;"

    Dim sqlInsert As String
    sqlInsert = "INSERT INTO dbo.VBALogger(LogLevel, Logger, Message, DateInserted) VALUES (?, ?, ?, GETDATE());"

    Dim logFormatter As DatabaseLogMessageFormatter
    Set logFormatter = DatabaseLogMessageFormatter.Create(sqlInsert)

    LogManager.Register DatabaseLogger.Create("DbLogger", TraceLevel, logFormatter, connString, sqlInsert)

    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 produces this output in the immediate pane:

TestLogger
2014-09-28 23:10:23 MyLogger    [INFO]  it works!
True
2014-09-28 23:10:23 MyLogger    [ERROR] Division by zero

..this output in a file saved under C:\Dev\VBA\log.txt:

2014-09-28 23:38:04 TestLogger  [ERROR] Division by zero

..and this output in [CodeReviewSandbox].[dbo].[VBALogger]:

Id  LogLevel Logger    Message                  DateInserted
1   TRACE    DbLogger  logger has been created. 2014-09-28 23:10:23.533
2   INFO     DbLogger  it works!                2014-09-28 23:10:23.553
3   ERROR    DbLogger  Division by zero         2014-09-28 23:10:23.570
\$\endgroup\$
6
+100
\$\begingroup\$

DatabaseLogMessageFormatter

I didn't change the ILogMessageFormatter interface, but the DatabaseLogMessageFormatter implementation ignores the parameters and uses the FormatMessage method to supply the DatabaseLogger with the SQL command string:

Okay wow. I don't think that ignoring parameters sent into ILogMessageFormatter_FormatMessage is a very good idea. It will only lead to confusion for the maintainer. If you're forcing someone to pass parameters into a method, you should be using those parameters. I'll admit that I don't immediately see a way to correct it, but I seriously recommend thinking on it.


The next one comes only from having reviewed other code of yours.

' ?> @level
' ?> @logger
' ?> @message

In your unit testing framework, you use the @ sign to indicate "special" comments. Be careful peppering your code with it where it does not designate a special comment. It won't cause you an issue now, but could become a maintenance nightmare if you decide to create other extensions that use it as an indicator for other things.


Private Sub ValidateSQL(ByVal sql As String)

    'require an INSERT INTO command:
    If Not Framework.Strings.StartsWith("INSERT INTO ", sql, False) Then _
        OnInvalidSqlError
  1. Don't use a line continuation to avoid an End If. Consider it to be like omitting braces in .
  2. What if you create a stored procedure to handle the logging? It will never validate.

Private Sub OnInvalidSqlError()
    Err.Raise vbObjectError + 1192, "SqlCommandText", "Command must be 'INSERT INTO', with 3 parameters."
End Sub
  1. Magic Number.
  2. I find it nice to expose error numbers to client code.

A public constant would correct both of those issues. (An Enum would currently be overkill IMO. It's easy enough to change if you add another error number later.)

I would also consider raising the built in Runtime Error 5; Invalid Argument or Procedure Call instead of creating a custom error number.


DatabaseLogger

  • I don't like the variable name result in the Create function. It's nitpicky, but result is fairly meaningless. I think dbLogger would be better.
  • This is a wise use of a line continuation.

    Dim result As Boolean
    result = this.SqlCmd.QuickExecuteNonQuery(this.Formatter.FormatMessage(level, this.Name, message), _
                                              sqlLevel, sqlLogger, sqlMessage)
    
  • but it would be unnecessary if you could figure a way to not ignore the parameters for Formatter.FormatMessage.


TestLogger

Dim connString As String
connString = "Provider=SQLOLEDB.1;Data Source=;Initial Catalog=CodeReviewSandbox;Integrated Security=SSPI;Persist Security Info=True;"

I know it's an example implementation, but people tend to write examples as they would any other code...

I wouldn't store connections in the code this way. There are a number of ways you could store connection strings, but pick one and use it. You shouldn't have to change code to change a database connection. Personally, I like using registry keys, but an *.ini file could also do the job fine. I tend to not muck with xml configuration files when dealing with VBA.

\$\endgroup\$
  • \$\begingroup\$ The UnitTesting library will only match '@ on the line that immediately precedes a public method's signature, and will only recognize a test method if '@ is followed by TestMethod... although I should probably write some ..unit tests for that :) \$\endgroup\$ – Mathieu Guindon Oct 1 '14 at 21:31
  • \$\begingroup\$ I'm confident of that too. Just calling it out as a potential future issue. =;)- \$\endgroup\$ – RubberDuck Oct 1 '14 at 22:02

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

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