A couple of years ago I wrote a number of blog posts about LotusScript / VoltScript classes. The topic is relevant to both languages, we’ve not made any changes to how classes are managed in VoltScript, even though we discussed adding some things added to Visual Basic since LotusScript was created, things like additional modifiers. Even though classes are still the same, we’ve used some quite sophisticated aspects of class, as will be apparent to anyone who has looked at VoltScript Testing, its LotusScript port bali-unit, VoltScript JSON Converter, or VoltScript Collections.
Three particular aspects I used in those projects are of particular relevance for this blog post.
Base and Derived Classes
The first is base and derived classes. We’re writing a logging framework, with a session class holding entries. But unlike OpenLog or Enhanced Log, the log entries doesn’t handle how it writes out the content or where it writes to. Instead the LogSession class takes one or more LogWriters, which handle where it writes to and what it outputs from the log entries. The BaseLogWriter just prints out the content. But the documentation will show a derived class that writes to a file.
This is a concept I’ve already used in VoltScript JSON Converter and VoltScript Collections, base classes that can be extended by the user and passed into another class, which then calls known functions to perform other functionality.
Delete Method
The second is exploiting the Delete method of a class to always perform functionality at the end of the script. This is used in VoltScript Testing and bali-unit to write out the unit test results. It means developers don’t need to remember to call a particular function at the end of their script and ensure it’s called if there’s an error.
In the case of VoltScript Logging, the Delete method of the LogWriter was writing out the logs.
Singletons Accessed from a Function
The third was an approach I blogged about a couple of years ago for creating a singleton, using a property or function to lazy-load a static private variable. This ensures the same instance is used throughout the life of the script, but prevents developers creating a new - or worse, multiple new - instances.
So What’s New?
All should have worked fine. After all, I’d already done writing stuff from the Delete method in VoltScript Testing. It’s been in use for years and runs on every build of various repositories. And it’s run on demand to generate the test results we post in our documentation.
However, when the code ran none of the logs was written out. Cue troubleshooting!
You can see the problem if you use this code as LotusScript or VoltScript. You can trigger it with the following code:
Dim lw as New BaseLogWriter()
Call getLogSession().addLogWriter(lw)
Before it generates an error, you’ll get this output:
Creating new logSession
In LogSession Delete
Testing logWriter - False
Testing globalLogSession - True
Creating new logSession
Writing out
In BaseLogWriter delete
In LogSession Delete
Testing logWriter - True
The first line is generated by the call the getLogSession(). Then the script starts unloading content. The True / False are check for whether the previous variable is Nothing. As one would expect, in LogSession’s Delete() function the LogWriter is correctly still valid.
However, at line 4 when we get into the BaseLogWriter’s Delete() function, the globalLogSession variable is Nothing. I think this is because LogSession.Delete has already triggered. With the next call for getLogSession() you can see that on line 5 creates a new instance. Then the BaseLogWriter is deleted.
If you remove the call to getLogSession() in the writeToLog() and add a check for whether globalLogSession is Nothing in BaseLogWriter.Delete(), and it’s still Nothing.
Solution…Part One
There are a few changes we need to make to get this to work.
The first is remove the getLogSession() variable. It’s now pointless, because if used in the wrong place, it will reinitialize it.
The second is we need to create the globalSession variable somewhere. The right place to do this is in the Sub Iniitialize() of the script containing the classes - the VoltScript Library Module or LotusScript Script Library.
The third is there is no point using BaseLogWriter.Delete(). The globalSession has already been set to Nothing by then, regardless of whether it is declared before or after the LogSession class. However, the logWriter is not Nothing during LogSession.Delete(), so we can call the writeToLog() method from there. However, we now need to pass the session across.
Perfect…Right?
But the LogWriter is designed to be extended. And so we created a sample for that, one that writes to a file. This FileLogWriter class and the test script were in a separate script file, as they would be in reality. When we tested the code, it didn’t write out. Cue more troubleshooting!
First off, a bit of clarification. The actual LogSession iterated through the LogWriters - it’s designed to have more than one - and checked if it was Nothing first. A bit of additional logging showed that when we added a FileLogWriter and a BaseLogWriter, the BaseLogWriter was not Nothing (as we already know) but the FileLogWriter was Nothing.
Terminate Method
We’ve seen the use of the Sub Initialize, to track this down we added print statements to the FileLogWriter.Delete method and to a Sub Terminate that we added in the scripts. Looking at the output again, the cause became obvious: the script with the main script and the FileLogWriter was unloaded before the script with the BaseLogWriter and LogSession.
Just to double-check, we tried moving the FileLogWriter class to a separate script, but this didn’t solve the problem.
From adding print statements to the Sub Initialize and Sub Terminate of all scripts, it became apparent the cause. The key to understanding is to do with the Use statements and the dependency tree. Initialize methods are fired from trunk to leaf and Terminate methods are fired in reverse. Scripts that have no Use statement load first, then scripts that use those scripts, then scripts that use those scripts, and so on.
So by the time LogSession.Delete() triggers, all scripts containing custom LogWriters will already have been unloaded and the variables containing them set to Nothing.
So how do we solve this?
Solution Part Two
To solve the problem, we come back to our initial plan: write out from the Sub Delete of the BaseLogWriter class.
The reason it didn’t work for a start was because it was running from the BaseLogWriter. But this time it won’t be: it will be running from the custom LogWriter. Let’s work with a basic structure: main script with custom LogWriter class in it (Script A) using a script with the logging classes (Script B). For the print statement in LogSession.Delete, we modify it to print out the TypeName of each LogWriter and whether it’s Nothing. With the print statements we’ve used and initializing the custom LogWriter, this is what we’ll see:
Initializing logging
Initializng main
In BaseLogWriter delete
Testing globalSession - False
Terminating main
Terminating logging
In LogSession Delete
Testing logWriter - BASELOGWRITER: False
Testing logWriter - EMPTYCLASS : True
In BaseLogWriter delete
Testing globalSession - True
Script B is initialized first, then script A. The custom LogWriter is deleted at the end of script A’s Sub Initialize and, because it extends BaseLogWriter and has no Delete method of its own, it calls BaseLogWriter.Delete(). And this time globalSession is not Nothing. That’s because then script A is terminated and script B is then terminated. Then the LogSession is deleted. But we see something interesting. The BaseLogWriter is not Nothing, but the custom one is. Moreover, TypeName() returns “EMPTYCLASS”. This is because the class has already been unloaded, so it can’t tell what class it’s an instance of. Finally the BaseLogWriter is deleted, at which point globalSession is Nothing.
Full Solution
So we can write out the logs from BaseLogWriter if globalSession is not Nothing. And in LogSession.Delete() we can write out the logs where the LogWriter is not Nothing. It may seem convoluted, but it’s the cleanest solution.
See For Yourself
VoltScript Logging will be open sourced within the next couple of weeks, as have all our VoltScript Library Modules, so I’m not revealing any state secrets here. And you’ll be able to see what it looks like for yourself.