When Things Go Wrong (part 2 of 3) – ERRORLOG

In this second part of how to handle errors gracefully whilst at the same time capturing as much information as possible, I will introduce the errorlog file.

There are two things I want to look at.  First is the name and location of the file, and secondly how is it populated.

The errorlog file is started by the startlog() built-in function near the beginning of your program …

CALL startlog(path STRING)

As simple as this sounds, the common mistake I see is developers use the same file for ALL programs, so something like …

CALL startlog("error.log")

The problem of this is that all the errors for every single program are then written to the same file.  If you then have to read the file, you have no idea what lines correspond to the current investigation.

I would suggest you take heed from the who, what, when concept of the previous article and encode some or all of this information into the filename.  Something like this …

CALL startlog(SFMT("%1_%2_%3.log", l_who, l_what, l_when))

… will give you an individual file for each running instance of a program that would tie-in to an entry in the whowhatwhen table introduced in the previous article.   Alternative strategies include using process id or session id as part of the filename.

For simplification, I omitted a directory in the path so the file is written to the current working directory, in reality you would most likely use FGL_GETENV() to read an environment variable, and os.Path.join to build up the full path and/or include the date in the directory name to ease maintenance e.g.

CALL startlog(os.Path.join(FGL_GETENV("MY_LOGDIR"),
    SFMT("%1_%2_%3.log", l_who, l_what, l_when))

The key point is to avoid using  the same path and filename for all running instances, but to split the potential output into multiple smaller files.

Having created the file, how do you populate it?  You can insert content into the file using the errorlog built-in function.   It takes as argument a string e.g.

CALL errorlog("Program started")

… and this will write that string to the errorlog file along with a date time and time stamp e.g.

Date: 02/02/2020 Time: 15:27:54
Program started

What will also happen, and this is where it gets useful, is if a program crashes, it will attempt to write an error message, date, time, filename, and line number into the errorlog.    As an example, try this little program …

MAIN
    CALL STARTLOG("askreuben15.log")  
    CALL ERRORLOG("Program started")
    WHENEVER ANY ERROR STOP
    DISPLAY 1/0
END MAIN

This should give you the following output in askreuben15.log

Date: 02/02/2020 Time: 15:30:04
Program started
Date: 02/02/2020 Time: 15:30:04
Program error at 'askreuben15.4gl', line number 5.
FORMS statement error number -1202.
An attempt was made to divide by zero.

We have the information written by the errorlog() call, and then we have the information written by the runner when an error occurred.  Note this includes the source file and line number, and the error number which are documented here.

(Also note in that example I used a constant filename for the errorlog.  Note what happens if you run the program multiple times, how that file grows)

To summarise, put a bit of thought into errorlog filename, don’t use the same file for all programs, create multiples files so that when an error occurs, you can find information easier.  Output debug information to this file, and note the information written to this file for you when a program crashes, when a program does crash, this information is the starting point to analyse what has gone wrong.

Next week I will look at how you can control the program behaviour and UI when a crash occurs.  Do we want the program to stop immediately?, or do we want to ignore the error if possible?, or do we want the program to die gracefully given the end-user a soft message that something unexpected has occurred.