Writing To The Event Log
This column never actually appeared in print as EXE
folded. However, because the articles were written a couple of moths in advance
I had already submitted this one and so it is made available here for
completeness.
This month I’m looking at the methods exposed by the
globally visible App object that are concerned with the logging of application
event data. The App object actually behaves differently in this respect
depending upon whether the program is running within Windows 9x or one of the
Windows NT family members (including Windows 2000 of course). The Windows 9x
environment will generally cause any log data to be written out to a
conventional file, whereas Windows NT offers the more sophisticated Event Log
service. In this article I’ll start by reviewing the Event Log service
itself in order to set the scene, after which we can go back and examine the
behaviour of the App object.
This article is very much aimed at applications which are
written for the Windows NT–based platform. If you are in a position where
you have to take into account a Windows 9x environment then, in my opinion,
there is no strictly correct answer as to where and how you should store
error/event information. Conventional wisdom would dictate a local file,
although support staff would understandably argue for visibility of this
information over a network. This could either entail writing to a shared
network drive or perhaps even a centralised database location, although in
these cases you must then take into account that part of the problem might be a
network failure and will have to act accordingly. Local best practice will be
the answer here.
Event Log
The Event Log runs as a true service within all versions of
the Windows NT platform and is designed to be a central repository for messages
generated by any application or components running on the machine. There are
three separate log streams maintained within this service: System, Security,
and Application.
-
System: More concerned with messages
generated by Windows itself. For example if a device driver fails to load then
a notification message of this failure, together with a reason for the failure
hopefully, will be recorded as a single event.
-
Security: Contains events that are of a
security nature, such as failed logon attempts. NB Any user on the current
machine can view the System and Application logs but you will need
administrative privileges to view this one.
-
Application:
Stores all messages that don’t fit into the first two categories;
basically anything that isn’t related to the operating
system. All applications will write their messages to this log location.
The actual messages themselves are also categorised into
levels of importance: Error, Warning, and Information. A couple of additional
types are also relevant to the security log, namely Success Audit and Failure
Audit.
The Event Viewer application (see Figure
1) is found under the Administrative Tools (Common) menu item
from the Start menu in Windows NT 4, or within the Administrative
Tools folder of the Control Panel in Windows 2000. This application
allows you to filter and sort event messages to any specific criteria
that you might have. Most importantly - for support staff particularly
- you can use the Event Viewer to view logs on other machines
on the network, allowing for the remote analysis of a problem.
This facility shouldn’t just be thought of as a repository
for error details however. Applications can also use this facility
to record that an important activity has been performed, such
as truncating a database table.
Figure 1: Event
viewer application
App object
The App object exposes the LogMode and LogPath properties, and
the LogEvent and StartLogging methods. If you’re trying this for the first
time then you need to be aware of one gotcha here: an event will only be logged
via the LogEvent method if the program is running as a compiled application;
calls made from a program running from within the Visual Basic IDE will not
actually work (by design). There are references within the Visual Basic
documentation which state that messages passed to the LogEvent method will be
displayed in the Immediate window when the application is being run from the
IDE. I can’t say I’ve found this to be the case.
The LogMode and LogPath properties are read–only at run
time which at first glance is a little deceptive because you would expect to be
able to use them. In fact these values are set by a call to the StartLogging
method, the syntax for which is:
App.StartLogging logTarget, logMode
where logTarget is the name of the file to write event
messages to (if appropriate) and logMode determines how logging will work.
Relevant predefined values for this parameter are vbLogAuto (which invokes
default behaviour), vbLogOff, vbLogToFile, and vbLogToNT. However, use of the
StartLogging method is optional because the default values will normally
suffice, particularly for Windows NT. By default a call to LogEvent while
running under Windows 9x will write to a file called <system
root>\vbevents.log.
The LogEvent method itself takes two parameters:
App.LogEvent logBuffer, eventType
where logBuffer is the string that you want to be written into
the log, and eventType sets the severity level; these can be
vbLogEventTypeError, vbEventTypeWarning, and vbLogEventTypeInformation.
Although the LogEvent method is a quick and efficient means of
writing to the EventLog there are a couple of features about it that might
irritate the purists. First is the fact that your message is always prefixed
with something along the lines of "The VB Application identified by the
event source logged this Application Project1: Thread ID: 312, Logged:".
I've not been able to find any way to disable this. The second issue is that
the Source column within the Event Viewer (as shown in Figure 1) always says
VBRuntime, whereas other applications are clearly able to show their own name.
If you really want to get round this then you are going to have to call the
relevant Event Log API calls directly. An article on the Microsoft knowledge
base, Q154576, discusses the various calls necessary to perform this.
Providing useful info
So that pretty much covers how to write events. The other
topic I’d like to consider is what to write. When an error occurs in an
application you will need to know what the actual error was – ideally in
terms of both the error number and the actual descriptive text – and, just
as importantly, where it occurred. To this end I would suggest that – if
you don't already – you devise a common template for each sub/function
that you create. Every routine that you write should start with an On Error
Goto statement which points to a local error handler. Within this error handler
you should capture at least the Description and Number properties, and then
call the Clear method. To illustrate this concept Listing 1 shows the idea in
skeletal form.
Private Sub MySub
On Error Goto MySub_Error
Const ERR_LOCATION = "modGlobal.MySub"
Goto MySub_Exit
MySub_Error:
Dim sErrDesc As String
Dim lErrNo As Long
Dim sErrMessage As String
sErrDesc = Err.Description
lErrNo = Err.Number
Err.Clear
On Error Resume Next
sErrMessage = "Error in " & ERR_LOCATION
& ": (" & _
CStr(lErrNo) & ") " & sErrMessage
Debug.Print sErrMessage
AppErrorHandler ERR_LOCATION, lErrNo, sErrDesc
MySub_Exit:
End Sub
Listing 1: Sub/function basic error handler template
I've made this code deliberately general because an error handler is something
that needs customising in virtually every case. For example you might want to
have several error handlers within the same routine in order that different
sections of code can be handled differently. You might also want to introduce a
Select Case statement to individually handle the predictable errors.
Furthermore you might well also wish to handle the error and then resume at the
next line, in which case you will need to reset the error handler action first,
such as
On Error Goto MySub_Error
Resume Next
The code makes reference to an imaginary routine called
AppErrorHandler. The code within this routine could be as simple or
sophisticated as you wish, but it will ultimately revolve around a single call
to App.LogEvent. Providing a centralised routine for handling your event
logging will always pay dividends here (as opposed to calling App.LogEvent
directly in each error handler) because you can quickly alter the overall
behaviour of your application as needed.
Most applications that I write involve using the Event Log for
error message trapping, but then again my target platform is invariably Windows
NT–based because I develop for the business community. If you do use the
Event Log then you will need to discipline yourself to keep an eye on it for a
while after the system goes live, and certainly on a very frequent basis during
the user testing phase. On a practical basis you also need to be careful about
being too quick to build and test from an EXE file; the early stages of testing
should always be performed from the IDE so that you can step through your code.
If you generate too many event messages at any one time then you will
eventually reach the maximum size and you will get messages of complaint until
you manually empty it. By default each storage log will have a maximum size of
512KB and messages will be retained for seven days, although both of these
values are configurable.
At this point I'd like to share a tip that Peet Morris of The
Mandelbrot Set (a.k.a. TheMSet) discusses in the book that I collaborated on,
Advanced Microsoft Visual Basic 6 (his chapter, entitled On Error Goto Hell, is
perhaps the definitive discussion on error handling with Visual Basic 6).
Visual Basic has provided since version 1.0 an undocumented global variable
called Erl that provides the line number that the error actually occurred on.
Of course in order to make this work you need to line number your code. The
reason I mention it is that a free utility for performing this task can be
found on their website at
http://www.themandelbrotset.com/Book/downloads.asp. The way it works is
that you provide the project file name as the input, and then you specify where
you would like the line–numbered copy to reside. This way your master
source is kept clean but your build code can include this very useful
additional information. Listing 2 shows a sample Event Log entry that includes
the information obtained from the Erl variable.
The VB Application identified
by the event source logged this Application Project1: Thread ID:
312 ,Logged:
An error occurred at 10/06/2000 09:26:13
The NT user account in use was elwisty
Version 1.0 Build 10
The error was captured in Global.main
The error line number was 18
The error code is 13
The VB description of this error is 'Type mismatch'
Listing 2: Sample event log entry
The usefulness of the data that you capture can perhaps be extended further by
capturing and reporting the call stack; sadly a feature that isn’t
currently supplied so you will need to implement your own mechanism for this.
Event logging, particularly in terms of
recording error details, is an area that often seems to be overlooked
by developers. I have occasionally seen applications that display
a rather daunting dialog box containing various technical details,
together with a note at the bottom asking the user to kindly pass
these details on to the help desk. This often fails because the
user will often press the OK button first just to see if they
can quickly get out of their predicament. Recording the details
and then displaying a simple one or two sentence message is much
more elegant, and definitely less intimidating approach. Although
some organisations might well have their own procedures for error
logging already in place this is the mechanism that Microsoft
has made available so it is worth using it if you can.
