Tracing Routines Explain Why The Computer Did What It Did
January 9, 2013 Ted Holt
Note: The code accompanying this article is available for download here.
Every week someone asks me why the computer did what it did. For instance, not long ago a buyer asked me why the computer did not send our requirements for a certain item to the vendor who supplies the item. I started digging through the program that generates the files we send to vendors. Then I realized there was a better way. Let me tell you about it.
In many shops, business rules are embedded in source code. Sometimes rules are hard-coded. I’ve seen code that directly referred to customer numbers, sales rep numbers, vendor IDs, etc. Sometimes rules are soft-coded, with logic controlled by the values in database tables. Either way, trying to figure out why the computer did not do what the user thought it should do requires investigation. When the buyer asked her question, I realized that I needed to make the computer help me do that investigation.
What I really needed to know were two things: I needed to know which path the system was taking through the program when processing the item in question, and I needed to know what data values were causing it to take that path. If that sounds obvious or familiar, that’s the same information we gather when we debug a program.
Of course, debugging was not feasible. The program in question ran in the wee hours of the morning, when I was slothfully slumbering in bed. Besides, even if I were awake, I would have no good way to interrupt the job stream and debug through a service job. In other words, I had to remove the requirement that I be present to win.
I solved my problem by writing a service program that would give me an easy way to see what had taken place while the computer was dealing with the item in question. My service program is called TRACERTNS, for Trace Routines. It lets me write anything I want to a printer file under the circumstances that I specify.
TRACERTNS contains the following exported subprocedures:
For more information about these subprocedures, see the Trace documentation Microsoft Word document in the downloadable code.
Here’s how to use the trace utility in an ILE RPG program. (COBOL and CL users will have to adjust accordingly.)
1. In the first line of your source member, define a condition to control compilation of the calls to the trace routines.
Condition all the trace-related code to this compiler directive.
2. Copy the procedure prototypes into the D specs of your program.
D/if defined(trace) D/copy prototypes,TraceRtns D/endif
3. Open the trace when you open your files.
/free open SomeFile; /if defined(trace) OpenTrace (%trim(psdsProcName) + ': Trace Vendor Requirements'); /endif
4. Start the trace when whatever you’re looking for happens. Here I start tracing (writing to the printer file) when the program processes a certain item.
/if defined(trace) StopTrace(); StartTraceIf (ItemNumber = '3001':'Start tracing ' + ItemNumber); /endif
The system will not process WriteTrace and WriteTraceIf subprocedures until you start the trace.
The call to the StopTrace subprocedure ensures that tracing ends when you no longer need it. This keeps irrelevant information out of the report.
5. Write whatever you wish to help you follow the behavior of your program. Some good things to write are:
• A message indicating that control enters or exits a subroutine, subprocedure, or section of code.
CSR GETBAL BEGSR /if defined(trace) /free WriteTrace ('060: Enter GETBAL'); /end-free /endif
• The value of a variable before that variable is used in a condition.
/if defined(trace) WriteTrace ('010: Bib=' + BIB + ', StNo=' + STNO); /endif if Bib = '1'; if StNo <> *blanks;
• The value of a variable that was changed in a subroutine.
exsr BigSub; /if defined(trace) WriteTrace ('055: *IN25=' + *in25); /endif
You’ll have to convert numeric data to character format. Use an appropriate built-in function, such as %CHAR or %EDITC.
/if defined(Trace) WriteTraceIf (OrdQty <> *zero: '110: ORDQTY=' + %char(OrdQty)); /endif
I have found that prefixing a unique three-digit number to the beginning of each comment helps me quickly match the trace report to the source code. That’s not a requirement. Write whatever’s meaningful to you.
Use your imagination. Think about the sorts of things you would want to see if you were watching the program run in a debugger.
6. Close the trace when you close your other files.
close *all; /if defined(trace) CloseTrace ('Close trace'); /endif
The end result is a report that you can use together with the program source to determine why the computer did what it did
7. After you’ve found the problem, change /DEFINE to /UNDEFINE and recompile. There’s no sense in running the trace when you’re not actively looking for a problem. I leave the trace code in the source member, in case I need it again someday.
So, what about my vendor problem? Did the trace utility work? You bet it did! Even though the program logic resembled a bucket of snakes, one production run told me what I needed to know, and I was able to explain to the user why the item requirements were not sent to the vendor.
I’ve used the trace utility several times since then. I’ve even used it instead of an interactive debugger when developing new programs.
I have only used the trace utility with ILE programs. I have plans for OPM wrappers, and will implement them if I ever need them.
One last point: You could add a printer file to a program and do the same thing without going to the trouble of binding to a service program. But if you’ve mastered ILE, you can insert calls to the trace routines much more quickly.
In an ideal world, everything would work properly and we’d never need to investigate problems or debug our programs. Since it’s not an ideal world, I depend on utilities like my trace routines to help me quickly identify and resolve problems.