Log All Save and Delete Transactions

by Curtis Krauskopf

One of the most difficult types of problems to debug is trying to find out why records are mysteriously being deleted or overwritten.

Your users come to you swearing up and down that they know they saved a record but now they can't find it. They might even have documentation that the record existed at one point but now it's no longer there.

So, you try the obvious things:

reindexing the datafile
writing a small program to examine every record for some unique piece of information
doing a code-walk of every key.save and enter.save routine
randomly poking around in the source code to see if there might be something obviously wrong

When the problem is important enough, at some stage, the finger pointing starts happening. You blame the DataFlex runtime. Data Access Corporation says that their runtime doesn't lose records. You blame a faulty network card or router. The network administrator says all the network cards test fine and besides, if it was a network issue, why does it only happen on that one datafile? You blame a hypothetical malicious user of deleting the record intentionally. And the finger pointing goes on and on.

What you really need is some way of being able to log every datafile SAVE and DELETE transaction so that you can find out, retroactively, what happened when the record mysteriously disappeared. The logging needs to be multiuser compatible because the problem might manifest itself only in a multiuser situation.

At this point you start groaning because you'll have to go into every program that opens the datafile in question and manually add code that logs the saves and deletes. On top of that, you might need to deal with legacy macro code written by somebody else that is also doing saves and deletes deep inside of custom-written macros. And if that wasn't enough, you have to make all of these modifications and not break any of the working code -- a concept known as making things worse.

You might even be tempted to take a shortcut and say "there's no way any of these lookup programs could be saving or deleting records so I'll just skip those." Well, that could be an unfortunate assumption because that might be exactly where the problem is at.

A Solution

To help solve these problems, I created a module to help a DataFlex developer discover why records are being mysteriously deleted or overwritten. It does this by logging the key fields and other important information when a record in a specific datafile is saved or deleted. This solution is only suitable for character-mode DataFlex.

This solution falls under the category of "desperate times call for desperate measures". You really should only do this if you have exhausted every other avenue available to solve the problem. The good news is that every time I've used this technique, I've been able to find the problem as soon as a user caused the problem to occur.

The overall scheme of this technique is to insert some code into an FMAC macro that saves and deletes records. The code will log, to a DataFlex datafile, each time a record is created or updated for a specific file. Because the code is inserted at the macro level, every source file, module, package, and include file anywhere in the application that uses SAVE, SAVERECORD and DELETE on the monitored file will have the transaction logged.

This solution is compatible with every known technique (both documented and undocumented) for saving and deleting records:

Save filename
Save (integer)
Save indirect_file.recnum
SaveRecord filename
SaveRecord (integer)
SaveRecord indirect_file.recnum
Delete filename
Delete (integer)
Delete indirect_file.recnum

Because the log file is a DataFlex datafile, it's automatically multiuser compatible. The log file doesn't require any indexes and each record is small, so the logging of saves and deletes will have a minimal impact on the system throughput even when used in a tight loop.

Where to Start

This solution is designed to require a minimum number of changes to the source code. Three lines are required to be inserted at the top of each source file (macro files and include files don't need the three lines). The lines are simple enough that a DataFlex program could be written to do this insertion, or if you're handy with PERL, AWK or your editor's macro language, you could use any of those techniques to insert those lines too.

Other macros, such as the ENTER macro, will need to be slightly modified to log saves in those macros too. Detailed instructions for modifying the ENTER macro (and custom macros similar to the ENTER macro) are provided in the readme.txt file in the distribution tdm_log.zip file (see below). If none of your programs use an ENTER macro or use custom macros, then you can skip that part.

What Is The Result?

The log file will contain a list of SAVE and DELETE transactions that occurred in chronological order. An example of one line from the log file is:

invoice, S, 01/27/2004, 1315, 4115, jim, 12345, 5, 1500

In the above line, 'invoice' is the name of the program that saved ('S') the record #1500 on 01/27/2004 at 1:13pm (1315). The user's name was jim and the save occurred in the invoice program on line 4115 (see invoice.prn to correlate this number with an actual source code line number). The key fields for the record affected are 12345 and 5.

Later, if users complain that a record with a key 12345-5 is missing, you can search for it in the log file and find the above record. Now that you know it was saved to record 1500, you can then search for other transactions that occurred to record 1500. You might find this line:

invmaint, D, 01/27/2004, 1317, 1277, sally, 12345, 5, 1500

It looks like sally accidentally or otherwise deleted that record at 1:17pm (1317) in the invmaint program. The exact line number that caused the deletion is line number 1277. You can use the INVMAINT.PRN file to find out which source line was actually involved with the deletion. Mystery solved.

Or maybe you'll see:

inv_lkup, S, 01/28/2004, 1015, 5523, joe, 12377, 2, 1500

That line says that the inv_lkup program overwrote ('S') record 1500 with line item 12377-2 at 10:15am the next day. I don't know why a lookup program would be doing that, but line 5523 in the INV_LKUP.PRN file is the place to start trying to figure out why it happened.

The important point here is that once you know the record number of the missing data, you can then find out what other programs edited, deleted or overwrote that record.

Installation

Complete installation instructions are provided in the readme.txt file that is located in the distribution file (see below). Be warned, though, that a certain level of experience with the DataFlex language is required to be able to install these changes and that even though the readme.txt provides instructions that cover most situations (and all of the common ones), that it can't handle every situation.

The Database Managers, Inc. is providing this file as a service to the DataFlex community. If you're able to use this technique to find and solve your problem, then we know you're happy and we're happy along with you.

If the programming involved is beyond your capabilities or you just want to off-load the entire project to someone else, then The Database Managers will be glad to help you examine your source files, look for anomalies and to incorporate this solution into your project. Please contact us to find out our rates for doing this kind of work. Depending on what needs to be done, the price will range from a few hundred dollars to a few thousand dollars.

tdm_log.zip (11k)

readme.txt (in HTML, view in your browser)

Finally, good luck and I hope that you can solve your missing record mysteries.

This article was written by Curtis Krauskopf (email at ).

Curtis Krauskopf is a software engineer and the president of The Database Managers (www.decompile.com). He has been writing code professionally for over 25 years. His prior projects include multiple web e-commerce applications, decompilers for the DataFlex language, aircraft simulators, an automated Y2K conversion program for over 3,000,000 compiled DataFlex programs, and inventory control projects. Curtis has spoken at many domestic and international DataFlex developer conferences and has been published in FlexLines Online, JavaPro Magazine, C/C++ Users Journal and C++ Builder Developer's Journal.

The Database Managers helps companies to:

become more profitable
grow their business
fix programs that are behaving badly
write new programs to solve business problems
do more with fewer resources

Email them at

to find out how to make your company more successful.

Other Popular DataFlex topics at The Database Managers, Inc.: