Creating a Simple Event Logger with Delphi

Ever found yourself in a situation where you cannot use Delphi's integrated debugger? For example, if you're creating a DLL, shell extension, or a Open Tools API Expert you will quickly find that debugging one can be difficult, if not impossible. However, if you need information about what you code does or you need simple variable "watching" features, help is near. In this How To we create a simple event logger unit which you can use to aid debugging. (Please note that Windows NT has its own "event logger". This document is not about that feature.)

When debugging for example a DLL, you often ask questions like: "Did procedure A get called?" or "What was the value of variable X before function B got called?". Answering such questions can be very difficult, especially if the DLL is not interactive by nature. To avoid this situation, a simple solution, an event logger can be used.

Event logger is simply put a routine which you call from your code whenever you think that something might go wrong. The event logger then "logs" the event, along with time and date information, for example. You can then later on examine the log to see what your code did. The "log" could itself be for example a file, the screen or a list box.

For example, using an event logger might look like this:

Procedure Test(I : Integer);
Var J : Integer;
Begin
  LogEvent('Test: Parameter I equals: '+IntToStr(I));
  J := I*Random(50);
  LogEvent('Test: J equals: '+IntToStr(J));
End;

Above, you insert "LogEvent" calls in places where you think the code might go wrong. This allows you to see which execution path your code took and which values the variables and parameters had. But why do we need a separate event logger - why won't for example "ShowMessage" calls do? Excellent question.

For very simple situations ShowMessage might do quite well, that's true. But in some situations, for example in a loop, clicking the OK button dozens of times can be a horror story. Secondly, in some situations, using ShowMessage can destroy application behaviour. For example, if you're debugging a WM_PAINT message, calling ShowMessage in the middle can lead to an infinite loop, effectively hanging you program. Thirdly, if you use ShowMessage calls, you can't later on examine the log.

How to create an event logger then? First of all, we need to define the procedures which are used to log the events. In our unit, this looks like this:

Procedure LogEvent(Event : String);
Procedure LogClassEvent(Sender : TObject; Event : String);

The "LogEvent" procedure is almost the simplest event logger call you can get. It simply logs the event you specified along with current time and date if required. The "LogClassEvent" is a bit more sophisticated version of "LogEvent". It is meant to be used within classes, and it simply uses RTTI (run-time type information) to add the class name (and a pointer value) to the specified event string.

Inside the unit, the above procedures are implemented as follows:

Procedure LogEvent(Event : String);
Begin
  OutputEvent(GetCurrentTime+Event);
End;

Procedure LogClassEvent(Sender : TObject; Event : String);
Begin
  OutputEvent(GetCurrentTime+
              Sender.ClassName+' ['+IntToHex(Integer(Sender),8)+']:'+
              Event);
End;

Above, both procedures call internal OutputEvent procedure which does the actual logging. Also, if needed, GetCurrentTime (internal function, defined later) returns the current time and date. Note that LogClassEvent also logs the class name and the pointer to the object. The typecast "Integer(Sender)" is safe because object variables are actually pointers. A pointer is a 32-bit value, as is an integer. If you want, the typecast could also be "Integer(Pointer(Sender))".

Internally, OutputEvent is defined as:

Procedure OutputEvent(Event : String);
Const DefaultTextHeight = 18;
Var DC : hDC;
Begin
  Case Destination of
    eldFile       : WriteLn(EventLogFile,Event);
    eldScreen     : Begin
                      DC := GetWindowDC(GetDesktopWindow);
                      TextOut(DC,10,TextPos,PChar(Event),Length(Event));
                      ReleaseDC(GetDesktopWindow,DC);
                      Inc(TextPos,DefaultTextHeight);
                    End;
    eldStringList : StringList.Add(Event);
  End;
End;

Above, "Destination" is a global variable defined in the unit, which tells where OutputEvent should log the event. The two situations, "eldFile" and "eldStringList" are trivial. eldScreen requires explanation, however. (Note that "StringList", "EventLogFile" and "TextPos" are global variables too.)

When eldScreen destination is selected, OE "logs" the event to the left side of the screen. This is useful if a file or string list cannot be used. The actual drawing is done with plain Win32 API calls to avoid unnecessary bloat. If you have never used API calls to draw something, you might find this difficult. However, we only need to get a device context (DC) to the screen (something like a "canvas handle"), draw the text, and release the DC again. Then we simply increase our vertical position so that we won't draw over the same place over and over. (Note that if you draw too much to the screen, the text will go off the screen. This is a bug, but I'll leave it to you as homework.)

Now you know how the event logger works. Only few more things require explanation. The internals of GetCurrentTime are as follows:

Function GetCurrentTime : String;
Begin
  If IncludeTime Then
    Result := DateToStr(Date)+' at '+TimeToStr(Time)+' ';
End;

Here, if IncludeTime (a global variable again) is true, GCT returns the current date and time. Otherwise it simply returns nothing.

How about the global variables then? Simply put:

Type
  TEventLogDestination = (eldFile,eldScreen,eldStringList);

Var
  Destination : TEventLogDestination; { default: eldFile }
  IncludeTime : Boolean;              { default: false   }
  StringList  : TStrings;             { nil by default!! }

And what about the two missing parameters? These are defined in the implemenation section of the unit:

Var
  EventLogFile : TextFile;
  TextPos      : Integer;

Simple enough? Well, almost as simple things follow:

initialization
  AssignFile(EventLogFile,'c:\eventlog.txt');
  Rewrite(EventLogFile);
finalization
  CloseFile(EventLogFile);
end.

These were the intialization and finalization sections of the unit. We open the log file in the very beginning so that the event log is ready whenever you need it. The finalization section gurantees that the log file also gets closed so that all information is written to the file and won't stay in the file cache - even if an exception occurs.

Now that you have a simple event logger unit ready, you can put it to real work. I've also included a simple test program which demostrates how to use the unit - if that isn't clear already. If this unit helps you create better programs, mail me. That would be really interesting.