Simon Wacker

Code must be debugged. With small projects debugging is not much of a problem, but when it comes to larger ones it is a pain to track down bugs that are only recognizable at run-time. These bugs may depend on some previous state and the interaction of large application modules. To make debugging easier it is necessary to trace the application’s execution. In Flash this can be done using “trace”. The problem with “trace” is that it is very primitive. It does not allow for different levels of output nor for custom output devices (an exception right now is the Motion-Twin ActionScript 2.0 Compiler, that allows you to replace calls to “trace” by a custom method prior to compilation). What is needed is a general easy to use logging API that allows for different log levels and that can be easily expanded to support an endless amount of different output possibilities and that can easily integrate other logging APIs without compromising their special functionalities.

You may wonder, why not just use a debugging tool? There are some major differences with instrumentation and debugging.

• Debugging sessions help you track down today’s bugs, but not tomorrow’s.
• Debugging is time consuming. It may be quicker to step through a log file to search for the bug source.
• Logging makes you think about your application.
• Logging let’s you easily track down bugs that occured when a client worked with your program. You may not be able to reproduce the bug or to fix it if you had not logged.
• Logging is more informative than debugging in that it provides detailed human written description on what is going on.
• Logging gives you control on how and where to log. You are not bloating your log file with trivial information.

As already stated a logging API should fulfil some general requirements.

• A simple API.
• Simple configuration.
• Several log levels or priorities, like debug, info, warning, error and fatal and the ability to choose which messages at which level to log.
• The ability to query whether messages with a given level will be logged. This may improve performance because it prevents unnecessary construction of messages that will not be logged.
• The ability to change message formatting.
• The ability to change output devices.

Given these functionalities it is also important when and how to log.

• Log heavily in important and error-prone code sections.
• Modify and improve log messages whenever you think of it to be necessary, like with ambiguous or unclear messages.
• Think about the correct log level for log messages. Log messages at the same level should be of the same level of detail.

“Logger” is the most important interface of the As2lib Logging API. It is the only interface you work with in your application code. All other classes and interfaces of the API just offer special configuration functionalities that are not visible to your application code; you only may use them for configuration on start-up.

That said, what exactly offers the “Logger” interface?

• Generic methods to log at different levels. These methods are in ascending priority: “debug”, “info”, “warning”, “error” and “fatal”.
• Generic methods to figure out whether messages at a given level will actually be logged. These methods, again in ascending priority, are: “isDebugEnabled”, “isInfoEnabled”, “isWarningEnabled”, “isErrorEnabled” and “isFatalEnabled”.

All these methods are generic because they are not bound to any underlying API. The log methods take any type of message as parameter and the query methods return primitive boolean values. How the messages will be logged or how the level is determined depends on the specific implementation. This general approach makes it very easy to switch between different implementations and gives you the ability to work with the logging API of another framework to savor all its special functionalities without tieing your logging code in your application to this logging API.

The As2lib itself offers broad support for different logging APIs and consoles. These include ASCB Library Logging API, LuminicBox Logging API, Flash Debug Panel Source from Bit-101, Alcon, Flashout and SWF Console from Music Theory. This support is offered by “Logger” implementations designed to work with the specific APIs and by “LogHandler” implementations which are discussed in a following tutorial page.

In your application code you obtain a logger through a general access point like your application context or config or from the “LogManager” of the As2lib Logging API. The “LogManager”s duty is simply holding a reference to a logger instance that shall be returned on a call to the static “LogManager.getLogger” method or holding a repository that is responsible for the actual creation or look-up of the logger instance to return. But again the application code is unaware of where the logger comes from.

In your application code you best use a logger as follows.

As you can see I am first checking whether the info message will actually be logged and only if this holds true I will actually log the message. In the above example this check may not be necessary because we are not concatenating strings or looking-up a class’s name using reflections, so this may not improve performance. But in most cases it really improves performance; thus I think of it to be good practice.

Note that also I used a string message in the above example, I could also have logged any kind of object. How the string representation is obtained from the object depends on the concrete “Logger” implementation. It may obtain it just by invoking the object’s “toString” method, but it may also iterate over the object’s variables and methods and log these. Using an object as message may also improve performance because for example the “toString” method of the object is only invoked if the message is actually going to be logged. This approach could be called “Lazy Log Message Generation”.

There is one method we have not talked about yet: “getLogger”. This method is in the above example responsible for returning the “Logger” instance. If you have an application context or config this method’s implementation may look like this:

As already mentioned you can also use the “LogManager” to get your logger.

The only thing you must keep care of is that the “LogManager” is configured with the logger to return before its “LogManager.getLogger” method is invoked.

In the above case we are configuring the “LogManager” with a “TraceLogger” instance. “TraceLogger” simply formats all messages using the “LogMessage” class and “trace”s the formatted message. The formatted message includes for example the log level of the message. You just have to replace this single line of configuration code to make all your application code log to a new console. If you are for example switching from the Macromedia Compiler (MMC) to the Motion-Twin ActionScript 2.0 Compiler (MTASC) you may want to log with Flashout.

I said above that the “Logger” interface can also be used just as delegate and general interface for other logging APIs. Such a API is for example the ASCB Library Logging API. Joey Lott has written a great article about this API: Flash Logging - A Better Trace. To gain all strengths of this API you can configure the “LogManager” with the “AscbLogger”. The “AscbLogger” simply wraps a logger of the ASCB Library Logging API. You can thus do everything the same as Joey Lott explains it in his article. The only thing that differs are the calls to the log methods; you call them on an instance of the generic “Logger” interface and not on the ASCB Logger directly.

As you may have noticed there is a weakness with our way of configuring the “LogManager”. We always return the same logger. It would be great if we could for example return different loggers depending on different logger names. These loggers may also be part of a hierarchy and share their configuration, like the log level, with their children. As you may have guessed this functionalities can actually be achieved with no more than a few lines of configuration code. This is covered in the next tutorial page; just go on.

A logger repository manages multiple loggers. The “LoggerRepository” declares only one method “getLogger(String):Logger”. This method returns a logger appropriate to the passed-in logger name. At its simplest form a “LoggerRepository” implementation just creates, stores and returns loggers by name. But a logger repository can also be more complex.

Let us begin with a simple logger repository, the AscbLoggerRepository. This repository does exactly the things I said when refering to the simplest form of repository. On invocation of the “getLogger” method it first looks whether a logger with the given name has already been stored. If so, this logger will be returned. Otherwise a new “AscbLogger” instance will be created, stored and then returned. As you can see there is not much magic going on. The great thing about this is that the returned loggers are configured with the given name and that this name is shown (by default) with the logged message. This makes it very easy to find out who logged which messages. We can of course still use the “LogManager” as on the previous tutorial page. We just have to configure it with the “AscbLoggerRepository”.

We also have to change the call to the static “LogManager.getLogger” method; we must include a name now. Note that you should decide at the beginning of the project whether to use named loggers or just one logger for the whole project. This largely depends on the size of your application. With small applications it may not be necessary to include a logger name in a message. You can also just always invoke the “LogManager.getLogger” method with a name regardless of whether the underlying configuration supports named loggers. This enables you to switch between the two styles of logger management as you please. You might also use a complex and slower logger management during production to be able to track down problems fast and a simple and fast logger management when the application is in use. The simple management may just ignore the given name. Following is the body of the “getLogger” method of the example of the previous tutorial page.

A complex logger repository is the “LoggerHierarchy”. It manages loggers hierarchical. Every class that gets a logger passes in its name (as we did in the previous example) that is used as the logger’s name. This firstly clearly states which class logged which message in the log output and secondly makes up the hierarchical structure. A fully qualified class name consists of its namespace, that is its preceding package structure, plus the name of the class; for example “org.as2lib.env.except.Exception”. In this case the parent of the logger with full name “org.as2lib.env.except.Exception” is “org.as2lib.env.except” and the parent of this parent is “org.as2lib.env” and so on. It is now possible to configure every node in this hierarchical structure and its children will inherit this configuration unless they overwrite it. The call to the “LogManager.getLogger” method stays the same. Again, what has to be changed is the configuration.

In the above configuration example we are first creating a new “LoggerHierarchy” instance. We are then instantiating two hierarchy able loggers, “coreLogger” and “invisibleLogger”, that are assigned to two nodes in the hierarchy, “org.myproject” and “org.myproject.invisiblemodule”, and adding these two loggers to the hierarchy. The hierarchy itself is set as repository on the “LogManager”. The “coreLogger” logs to the Flash Output Panel (”TraceHandler”) and to the Flashout Console (”FlashoutHandler”). The “invisibleLogger” inherits the handlers from its parent logger, the “coreLogger”, but it sets its log level to “NONE”. This means that it does not log messages.

If we now execute the following code, the message “This is an informative message.” will be logged to the Flash Output Panel and to the Flashout Console.

But if our class is somewhere in the “org.myproject.invisiblemodule” package or any sub-package no log output will be made.

It is important to note that with “SimpleHierarchicalLogger” instances the log level is, if not specified directly, the level of its parent and the handlers are all handlers of its parents. The children inherit the configuration of their parent or parents.

In the above example I have introduced a new notion: log handlers. The following tutorial page gives more insight into their usage.

A “LogHandler” is responsible for the actual logging of messages with some loggers. All loggers that offer hierarchy support for the “LoggerHierarchy” repository must work with log handlers, because otherwise inheriting the output devices of the parents would not be possible. Such a logger is the “SimpleHierarchicalLogger”. But log handlers are not only helpful in a hierarchy. Also non-hierarchical loggers like the “SimpleLogger” can benefit from log handlers. Log handlers enable a logger to support more than one output device. With log handlers one and the same logger can for example log to the Flash Output Panel and to a log file.

When you now invoke any log method on the above “SimpleLogger” instance it will dispatch a “LogMessage” instance containing all information about the actual message, like its level, to all regitered handlers that are then responsible for creating the string representation of the given “LogMessage” instance, probably via the “LogMessage.toString” method, and for writing this string to the actual output device.

As you can see, loggers supporting log handlers are much more flexible than the ones that do not, like “TraceLogger” that is hard-coded to log to the Flash Output Panel. But you must also see the downside of this approach: it costs performance, even if there is only one handler added. I thus recommend using loggers with handler support only in production and only if they are needed and switching to hard-coded loggers when the application is actually in use.

There are some loggers that work with the “LogMessage” class; above all loggers that work with “LogHandler”s. A “LogMessage” simply holds all information regarding an actual log message. These information are the message itself, the level at which the message is logged, the name of the logger the message is logged on and the time at which the log message was created. To now actually log the message it must be stringified, this means a string representation of the message including all extra information must be generated. To do this you simply have to invoke the “LogMessage.toString” method. The string this method returns is generated through a stringifier that can be set via the “LogMessage.setStringifier” method. There also exists a customizable “LogMessage” stringifier, “PatternLogMessageStringifier”. You can use this stringifier or a custom one to format log messages as you please.