<< You want Members with your catalog? | Home | Re: LotusScript Singletons >>

Making changes to the OpenLog application

Logging is central to all applications to find out what's going on and to help in development and debugging. The NotesLog class from LotusScript just doesn't cut it in that regard which is why we should be happy for OpenLog. I find OpenLog to be a valuable additional to my LotusScript development tool arsenal.

Before we could start using it in production we had to make a few changes to the standard OpenLog application (thank God for OpenSource):

  1. Default location of openlog.nsf to be the same directory as the current database
  2. SEVERITY_DEBUG and filtering on severity level at runtime
  3. Grouping of log documents
  4. A small bug fix

Below I will discuss each of the changes made in its own section. I would really like some feedback on the changes so please let me know if you have any. Of cause the changes will also be sent to Julian so he can decide whether to incorporate them in the standard application template.

It's so much more fun when we share... :-)

Ad. 1: Default location of openlog.nsf...
We normally recommend our customers to organize the databases on their servers with one application per directory (e.g. one directory for helpdesk, one for sales force automation etc.) Because of this it really makes sense for us to have an Openlog database per application residing in the application directory and to have the default location of the openlog.nsf be the openlog.nsf in the current directory.

This means we can use the same "Openlog Functions" script library for all applications without having to modify the path to the log database (in the Initialize event). Instead of hardcoding the logDbName variable to "openlog.nsf" we compute the path based on the current database path.

'** this should be the name and path of the database that
'** you're logging everything to -- you need to explicitly name
'** it because it probably won't be the database that you're
'** running agents from
Dim session As New NotesSession
Dim sep As String
If Left(session.Platform, 7) = "Windows" Then
   sep = |\|
Else
   sep = |/|
End If
logDbName = Strleftback(session.CurrentDatabase.FilePath, sep) + sep + "OpenLog.nsf"

Ad. 2: SEVERITY_DEBUG and filtering...
One of the things I really like about the log4j (and similar) frameworks is the concept of logging levels and the ability to filter on the logging levels at runtime. OpenLog has the concept of logging levels but not the filtering at runtime.

OpenLog currently has the following logging levels:

  • SEVERITY_HIGH
  • SEVERITY_MEDIUM
  • SEVERITY_LOW
These logging levels are fine but I really miss a SEVERITY_DEBUG. SEVERITY_DEBUG should be used to output information usable in troubleshooting situations so you can have an added log output without having to insert "Print" or "Msgbox" statements in the code.

The filtering at runtime means that the logging framework will filter the log records actually being written to the openlog.nsf database at runtime. The idea is that you specify a severity with every log statement in the application code, and a filter logging level to the logging framework. Below the filter logging level is set in the "OpenlogFunctions" script library but it could as well be taken from a configuration document in the OpenLog database as well. There are pros and cons with each solution.

The default filter logging level should be SEVERITY_LOW which would make the logging framework ignore log requests of a lower severity that is log requests of severity SEVERITY_DEBUG. Setting the filter logging level to SEVERITY_HIGH would make the logging framework only output logging requests with SEVERITY_HIGH.

To incorporate this kind of functionality I have made the following changes (additions in italic).

Declarations
'** common severity types
Const SEVERITY_DEBUG = "-1"
Const SEVERITY_LOW = "0"
Const SEVERITY_MEDIUM = "1"
Const SEVERITY_HIGH = "2"

'** current severity level we log - we will log everything which is at the 
'** specified level and higher
Dim logSeverityLevel As String


Initialize
'initialize logging filter severity level to LOW
logSeverityLevel = SEVERITY_LOW

LogErrorEx-method
Function LogErrorEx (msg As String, severity As String, doc As NotesDocument) As String
   '** log an error with some descriptive information
   On Error Goto processError
   If Cint(severity) < Cint(logSeverityLevel) Then Exit Function
   ...
   ...
End Sub

LogEvent-method
Function LogEvent (msg As String, severity As String, doc As NotesDocument) As Integer
   '** log a general event
   On Error Goto processError
   If Cint(severity) < Cint(logSeverityLevel) Then Exit Function
   ...
   ...
End Sub

Ad. 3: Grouping of log documents We have a lot of agents that run multiple times a day. With the default behaviour of OpenLog it can be very difficult to distinguish the log documents from one execution from the log documents from another since they are listed together only separated by the time. To alleviate this we have added the concept of log document grouping.

Above the "Test LogGroup"-agent has been run 4 times at various times. The log documents for each run is grouped inside its own group (e.g. "Main loop (09-12-2005 08:37:48)") which makes it easy to locate the log documents for a particular run. We've taken it a bit further though since you can nest groups within groups. Combining this nesting with SEVERITY_DEBUG you have the option of logically grouping log documents for document processing logic and only have it output when debugging.

The below example show the log documents for two separate runs. The first is run with a log filter of SEVERITY_LOW and the second with a filter of SEVERITY_DEBUG. As you can see the second run has a group of log documents for each of the 3 documents being processed. This is nice since many Domino agents will process documents and often it makes sense to group log documents based on the document they are based on.

The code that produces the above example is very simple and is shown below. As you can see the code uses two additional methods called EnterGroup(String) and LeaveGroup() which are not standard OpenLog methods. These are the methods that tell OpenLog when to start, nest and leave group so it can be output to the log documents.

Option Public
Option Explicit
Use "OpenLogFunctions"

Sub Initialize
   Dim i As Integer
   Dim j As Integer
   
   Call EnterGroup("Main loop (" & Now & ")")
   Call LogEvent("Starting to run...", SEVERITY_LOW, Nothing)
   For i=0 To 2
      Call EnterGroup("Interation - group " & i)
      For j=0 To 2
         Call LogEvent("Logging event " & j, SEVERITY_DEBUG, Nothing)
      Next
      Call LeaveGroup()
   Next
   Call LogEvent("Done running...", SEVERITY_LOW, Nothing)
End Sub
The handling og logging groups and nested logging groups is implemeted using a Stack. When entering a group, by calling the EnterGroup(String)-method the group name is pushed on the stack and when leaving a group (using the LeaveGroup()-method) the top group is popped from the Stack. Simple.

The Stack is from Johan Känngards website.

Apart from the Stack there is a small addition to the LogEntry class to allow the logGroup to be set before the log document is saved to the database.

Ad. 4: A small bug fix
When logging you sometimes need to log an error even though no "real" LotusScript occured (i.e. the Error function will return an empty string). When this happens the logged message in the OpenLog database will be blank since the error message is always taken from the Error function.

This is simple to fix though and can be done with 3 lines in the LogErrorEx()-method. The fix is simple - if there is no output from the Error function use the error text supplied to the method. The change in the snipped method code below is highlighted with italics.

Function LogErrorEx (msg As String, severity As String, doc As NotesDocument) As String
   ...
   ...
   
   With globalLogItem
      ...
      ...
      
      If (stackTrace.traceData = "") Then
         ...
      Else
         ...
      End If
      
      'if the method is called without an actual error having occured (e.g. a flaw in 
      'necessary setup) Error will be empty. Test for this and set message 
      'accordingly
      If .errMsg = "" Then
         .errMsg = .message
      End If
   End With
   
   ...
   ...
   
End Function