Things they never told you about log4s [Updated]


I’ve been using log4s, Instantiations’ logging framework for VA Smalltalk, in several situations before and it does a nice job.

I always started it with a piece of code and therefor had no problems with it. But log4s has an option to auto-start and initialize itself from the abt.ini file that accompanies a VA Smalltalk image.

So I wanted to try this for the first time and immediately stumpled upon a few problems.

First, let’s take a look at the ini stanza that I wanted to use:

[log4s]
debugEnabled=true
quietMode=false
globalLevel=All
dailyRollingFileAppender =(MyRollingFileAppender, root, MyLog.log, false, Info, EsPatternLayout, '%date{ISO8601}: [%level] %message', true, topOfDay )

With this I had several problems.

I had to find out the hard way (if you can call breakpoints hard) that the three parameters #(‘debugEnabled’ ‘quietMode’ ‘globalLevel’) always have to be present. The framwork does not assume any defaults for them. Unfortunately, it seems this is not in the documentation. But now you know😉

[Update] Actually, it is in the documentation and I somehow managed to ignore it and believe in its non-existence hard enough to believe it. It’s clearly stated in the VA Smalltalk User’s Guide in section “Initializing the log4s Framework”. So I could have saved some time by simply RTFM… Thanks to Don McQueen who pointed me to it . [/Update]

Why did I have to find out the hard way? because the logger logs errors to TranscriptTTY if it cannot log. Now, how can I look at TranscriptTTY on windows? I guess there is a way to do so, but I didn’t find it. So I would hope for a default log file in the image directory and probably also some ini parameter for the location of the EsLogLog file location. Another option would be to look if we are in a dev image where the Transcript is available and log there too. And maybe it should even throw an exception when it cannot log at all because setting up failed (like on of the above mentioned settings are missing). log4s never tells you it’s not logging because of some setup problem. An example: if you misspell quietMode as quiteMode, you wont’t get any feedback that teh startup of your logging simply gave up. No exception, no error log, just TranscriptTTY.
That is really not a good situation.

[Update] Again, Don McQueen clarified on the question how to see what’s being logged by the logger if it cannot log anywhere else, namely what it outputs to TranscriptTTY. You can start VAST with an optional parameter -lCON. I still think that is too hidden, or at least not good enough, but at least there is way to search for info. I’d like log4s to make problems more obvious to me, and TranscriptTTY (or stdout/stderr) should just be the very last resort. And still I think log4s should throw an exception if it cannot initialize its logging. [/Update]

Another thing that I found it is that if I have a running rollingFileAppender and save the image and also change the log file name in the .ini file, the next time the image starts up it will continue logging to the old file. Without further debugging I guess this is due to the fact that the appender is still active in the image, and the startup sequence didn’t change the file name on image start.

[Update] There is an easy fix to this problem, and Don posted it to the VAST support group:

add this line to EsLogManager>>shutDown:

self removeAllLoggers

I guess it will be in the next release of VA ST. So at least this rant had one positive outcome and I am a happy boy again😉

[/Update]

 

So I still think the fact that log4s is part of every base VAST image starting with VAST version 8.5 is a good thing, and I still like how it works (once it works). I had been using Toothpick before that and liked it even a little bit better, but log4s is not bad. I haven’t seen much of a performance penalty and the API is quite clean. But it is a 1.0 version and has its little edges.