Log4Fox: A Logging API for Visual FoxPro

By Lisa Slater Nicholls
January 2006

To truly understand what's going on when your application runs, you have to instrument it, so it provides trace data in all code areas. Microsoft's DotNet Framework has the System.Diagnostics.TraceListener class, and Sun's Java Platform includes the java.util.logging package, to serve this purpose.

Although Visual FoxPro's SET COVERAGE, SET DEBUGOUT, and SET EVENTTRACKING features have been steadily enhanced in each version, VFP doesn't offer native support for fine-tuning the levels and types of trace data as completely as many other environments do. No problem; VFP's OOP and output-handling resources make it easy to provide class libraries to handle all the required tasks.

When you investigate instrumentation APIs in different environments, you find that their similarities are many and their differences are minor. It makes sense to follow the classic logging patterns for VFP, as well. You may be surprised to hear that I didn't follow either Microsoft's or Sun's lead when I wrote a VFP-based logging class library. However, there is a clear winner in the open source development world, log4j, a java toolkit, which seems to be more widely used than either vendor's solution. The log4j toolkit is definitely more fully-featured than java.util.logging. You'll also find that many dotNet developers choose to emulate log4j's API and features, or even to use wrappers around it when possible.

Because I find myself missing log4j's capabilities when I work in VFP, I decided to emulate it in Log4Fox, the programmatic class library supplied as the source code for this article.

How a logging API works

The features I missed, and which I'll describe here as belonging to log4j, could just as easily be a description of most other implementations of logging APIs. They generally share the following class types:

• A collection of output observers, each of which understands how to send output to a specific target device. In pattern terms, an application run, like a REPORT FORM run, is an Observable event, and output observers, like VFP's own ReportListener class, take independent action during the course of this event. For example, one object can e-mail an Administrator while another writes to the system event log. Many observer types are called listeners, because they listen, as if to a symphony of application activity, for the notes and melodies they want to hear. The log4j toolkit calls these objects appenders, to emphasize that each is sending messages to one target, which accumulates the information.
• An owner object for the observer collection, to which your application directs its trace output. This object has methods you use to start and stop logging, and another method to send your event messages. Unless you wish to configure the observer objects explicitly, you interact only with this owner object, not its collection or its collection's references, during your application run.
• A format or layout interface, usually provided as a helper object to each output object. This promotes a standard way of specify how messages can be decorated, while allowing each observer to use different types of decorations as appropriate to their content. For example, the e-mail observer might add HTML formatting while the event-log observer might impose a maximum length.

These three class types are usually tightly-coupled, which means that they are specifically designed to work together. In many cases they will refuse to instantiate if they do not find themselves in the proper environment. You can see the functional relationships of these classes in Figure 1.

Figure 1. Log4Fox Class Diagram.

In addition to these standard class types and interactions, each API includes some idea of message level or severity. For example, System.Diagnostics.TraceLevel supports the Off, Error, Warning, Info, and Verbose levels, and java.utility.logging has seven levels from FINEST to SEVERE. You can configure each observer separately, for the level of severity which a message must meet or succeed, for its type of output.

When you send an event message, you also indicate the level of the message you're sending, and the observer compares the level of this message with the level of messages it is configured to log. The message level must be as severe, or more severe, than the observer's level to trigger output.

The first example message event below would trigger output from an observer configured at the Info or Debug level, but it would not trigger output from an observer configured at the Warning level. The second line would trigger output from both observers:

    MyApplication.MyLoggerImplementation.Log(;
        "User chose to run this report: " + ;
        lcReport, ; 
        LOGLEVEL_INFO)
    MyApplication.MyLoggerImplementation.Log(;
        "Cannot run the following program: " + ;
        lcApp, ; 
        LOGLEVEL_ERROR)

Log4Fox (like log4j) supplies the levels FATAL, ERROR, WARN, INFO, and DEBUG, in descending order of severity, or (to think about it another way) ascending levels of verbosity. I've added ALL to Log4Fox as one more level after DEBUG. In Log4Fox, the ALL level means "Whether I'm debugging or not, I still want every single message logged." I didn't want to change log4j's core enumerated values, but I found the use of the label DEBUG for the purpose of VERBOSE very confusing.

This concept, a structured hierarchy of message severity, is critical to your ability to manage and tune your tracing and application message strategies. For example, you can configure an e-mail observer with a level of LOGLEVEL_ERROR, so the Administrator only gets e-mails when something important happens. For the same application, you configure the event-log observer for messages of LOGLEVEL_INFO or higher.

Of course, each observer can also choose to take different types of action depending on level. The event-log observer in this example might write different messages for LOGLEVEL_INFO events than it does for LOGLEVEL_WARNING and LOGLEVEL_ERROR events.

Configuring and setting options for a Logging API

Another common feature in logging APIs is their ability to configure the logging process using some type of configuration object or file. No matter how it's implemented, the configuration resource allows the logging owner object to gather up its own collection of observers and to set their options without added code.

In Log4Fox, I've included one appender (Log4FoxSQLAppender) that shares Log4FoxConfigAlias's use of a cursor for some options, while the other appenders in the library do not read the cursor. This does not prevent Log4FoxSQLAppender from being used with other Log4Fox classes besides Log4FoxConfigAlias, and it does not prevent Log4FoxConfigAlias from instantiating other appenders in the library, and configuring them according to its global rules. However, this diversity is for the purposes of illustration only; you generally create observers that understand the same configuration device as their owner. Remember: these are tightly-coupled class types. You should be able to count on consistent configuration use throughout the different members of your logging class set.

Log4Fox has one standard formatter class, Log4FoxBaseFormatter, used by all the appenders in this class library. The abstract parent appender, Log4FoxAbstractAppender, supplies this reference if you don't configure an appender class with more specific instructions about what formatter you wish to use. Appenders instantiate formatters after they receive configuration information during their Init, and they can choose to change formatters any time you change their configuration information thereafter. In the source code for Log4FoxAbstractAppender, you'll see GetFormatter, HasValidFormatter, and GetDefaultFormatter methods for this purpose, along with other protected methods in this class not included in Figure 1.

Log4FoxBaseFormatter includes some typical logging option setting properties, which appear in the class diagram in Figure 1, and it also has its own Configuration member, so it has the ability to set these options according to whatever configuration scheme you choose. However, none of these options are required by the Log4Fox API.

To show you how simple a layout class can be, I've included a derived class not used by any of the appenders in this library: log4FoxStripHTMLFormatter. This class uses a regular expression object to strip any HTML tags out of the log message before sending the message to its target. Although it might seem counter-intuitive that a formatter strips formatting, rather than adding decoration, I have one application that sends HTML-formatted messages as one of its main activities. The HTML message body accumulates at various points during a long process. To archive these messages as an audit trail, we decided to add a log event that sent each message body, in its entirety, to a SQL database when the application finishes preparing the e-mail. We store only the message's contents, not its formatting, in the database.

Log4Fox's Class Hierarchy

As you can see in the Class Browser (shown in Figure 2), all three Log4Fox participant types have a common parent class: VFPHelperObject. I haven't mentioned it previously, because the techniques in this class are not specific to trace logging.

Figure 2. Log4Fox Class Hierarchy in VFP 9's Class Browser.

VFPHelperObject-derived classes expect to have a reference to an owner class, which they receive as an argument to their Init methods and can validate. If they are not satisfied with the type of owner, or do not receive any owner reference, they can refuse to instantiate. During their life span, they typically delegate error handling to the owner object rather than imposing their own error-handling strategy on the application.

VFPHelperObject allows a flag to be passed to the Init, indicating that you want to omit the owner requirement, and the Test_Log4Fox.PRG program you'll find in your source code makes use of this capability for the main Log4Fox object it instantiates. You can use this flag for convenience when debugging appenders and layouts, too. For production purposes, however, your main Log4Fox object reference will ordinarily be owned by an application object. You can probably understand why this approach is useful to a tightly choreographed group of classes like the Log4Fox set, and it doesn't impose any restrictions on your application object. If you don't, simply change the three ancestor classes to derive from Custom instead of VFPHelperObject.

As you see in Figure 2, Log4Fox provides four concrete implementations of appenders, since this class type is really the heart of the system. Each of the four manages output to a different target device:

• Log4FoxConsoleAppender uses DEBUGOUT.
• Log4FoxMessageBoxAppender uses MESSAGEBOX with a Timeout option.
• Log4FoxFileAppender uses TEXTMERGE to a file.
• Log4FoxSQLAppender uses SQL passthrough to write to a specified table format using a SQL handle you provide. (You'll find the table structure included in the source code.)

Each class has its own considerations and options as appropriate to its target type. For example, the file and SQL implementations have "append/overwrite" capabilities, but this feature would be meaningless to the Debug Window or MESSAGEBOX command. Each appender must also consider how, or if, it should implement the OpenLog and CloseLog methods.

The only method that each appender must implement, if it wants to have any output, is its protected SendLog method. When the appender's public DoLog method has evaluated the log level values and determined that output should occur, it applies its Layout member to whatever information you sent. SendLog receives the already-formatted message string and must write it in whatever manner is appropriate to the appender's target device.

Each SendLog method is extremely simple; the SQL implementation builds up a string, which it will send to the database when the log is closed, the file appender emits a textmerge line, and so on. Each appender does whatever it's been configured to do; in Figure 3, you see console and messagebox appenders during the same run, with their layout objects' IncludeLogEvent flags set differently.

Figure 3. Console and MessageBox appenders, each with a different style and configuration settings, handle the same application events.

How you use Log4Fox

The output in Figure 3 comes from Test_Log4Fox.PRG, which shows you Log4Fox in use. The main object in this case is Log4FoxConfigAlias. The test program first creates a cursor on the fly with some instructions for appenders that the Log4FoxConfigAlias object should add to its collection, and then instantiates the Log4Fox owner object:

    * We will not require an owner object ;
    * for this test:
    loLogger = CREATEOBJECT("Log4FoxConfigAlias", ;
                            NULL,.T.,"myConfigCursorAlias") 
    * Ordinarily this object has an owner:
    * loLogger = CREATEOBJECT("Log4FoxConfigAlias", ;
                             THIS.App,.F.,"myConfigCursorAlias")
    

The test program then adds a SQL appender explicitly, if you give it a handle (the test program tries to validate your database for the existence of a suitable table). Because the SQL appender requires a valid handle, you need to instantiate this appender explicitly or provide some information about the handle in its configuration data, which I've omitted in this example:

    IF NOT EMPTY(iHandle)
        CREATEOBJECT("Log4FoxSQLAppender", ;
                     loLogger,.F.,iHandle) 
        ? "# appenders after adding SQL appender: ", ;
          TRANSFORM(loLogger.Appenders.COUNT)
    ENDIF
    

Notice that you don't have to use the Log4Fox.Appenders collection's Add method. After validating their owner reference, the Appenders add themselves to the collection automatically, providing a unique key. They do this to make sure they can null out references appropriately, no matter how, or in what order, these partnered objects are released. Once appenders are in place, you start logging with a simple command, and instrument your code with log calls anywhere required:

    loLogger.Open()
    loLogger.Log(;
       "This is a test at level LOGLEVEL_ERROR", ;
       LOGLEVEL_ERROR)
    loLogger.Log(;
       "This test shows the log event param for " + ;
       "those appenders formatted to show it.",;
       LOGLEVEL_INFO,"TestEvent")
    loLogger.Close()
    

You can close and open logs any time required during an application run. All appenders are "aware" of whether logging is currently opened or closed, so no harm results if you issue a call to the Log method when logging is not available. The test program sets various logging levels for the different appenders in use, so you can see that different numbers of log output lines occur for differently-configured members of the collection (see Figure 4).

Figure 4.SQL and File appenders, each with a different log level,do not handle all the same events.

Will you use Log4Fox?

Even in this simplified version, Log4Fox contains switches and features I haven't discussed. log4j has more options and configuration possibilities than I could ever dream of. Still, some people want even more choice. log4j is a project of the Apache Software Foundation and Apache offers, not just log4j, but a Logging Services API, a harness into which log4j fits.

It's a great, big, wonderful world out there. In Log4Fox, I'm not convinced that I've written the world's best port of log4j that you could possibly write in Visual FoxPro. I am convinced that you, and all developers, need sophisticated tracing toolkits, and that exposure to this implementation should give you some great ideas for your own.