Chapter 7. Controlling tracing.

Overview.

Up till now, we have activated or stopped the tracing by coding TRACE instructions in the procedure itself.

However, if you remember our discussion at the beginning of this lesson, then you should understand that you can switch tracing on (without modifying a program) by using the command SET EXECTRAC ON. You can also turn tracing on or off asynchronously (that is, while a program is running) by using the TS and TE immediate commands.

Before we give our comments, let's again review what the manual says about this :

You can interrupt the language processor during execution in several ways :

The HI (Halt Interpretation) immediate command causes all currently executing REXX programs to terminate, as though there has been a syntax error. This is especially useful when an editor macro gets into a loop, and it is desirable to halt it without destroying the whole environment (as HX would do). When a HI interrupt causes a REXX program to terminate, the program stack is cleared. A HI interrupt may be trapped by using SIGNAL ON HALT.
The TS (Trace Start) immediate command turns on the external tracing bit. If the bit is not already on, TS puts the program into normal interactive debug and you can then execute REXX instructions and so forth as normal (for example, to display variables, EXIT, and so forth). This too is useful when you suspect that a REXX program is looping--you can enter TS, and inspect and step the program before deciding whether to allow the program to continue or not.
The TE (Trace End) immediate command turns off the external tracing bit. If it is not already off, this has the effect of executing a TRACE Off instruction. This can be useful to stop tracing when not in interactive debug (as when tracing was started by issuing SET EXECTRAC ON and interactive debug was subsequently terminated by issuing TRACE ?).

The System External Trace Bit :

Before each clause is executed, an external trace bit, owned by CMS, is inspected. You can turn the bit on with the TS immediate command, and turn it off with the TE immediate command. You can also alter the bit by using the SET EXECTRAC command (described later). CMS itself never alters this bit, except that it is cleared on return to CMS command level.

The language processor maintains an internal "shadow" of the external bit, which therefore allows it to detect when the external bit changes from a 0 to a 1, or vice-versa. If the language processor sees the bit change from 0 to 1, ? (interactive debug) is forced on and the tracing action is forced to R if it is A, C, E, F, L, N, or O. The tracing action is left unchanged if it is I, R, or S.

Similarly, if the shadow bit changes from 1 to 0, all tracing is forced off. This means that tracing may be controlled externally to the REXX program : you can switch on interactive debug at any time without modifying the program. The TE command can be useful if a program is tracing clauses without being in interactive debug (that is, after SET EXECTRAC ON, TRACE ? was issued). You can use TE to switch off the tracing without affecting any other output from the program.

If the external bit is on upon entry to a REXX program, the source string is traced and interactive debug is switched on as usual--hence with use of the system trace bit, tracing of a program and all programs called from it, can be easily controlled.

The internal "shadow" bit is saved and restored across internal routine calls. This means that (as with internally controlled tracing) it is possible to turn tracing on or off locally within a subroutine. It also means that if a TS interrupt occurs during execution of a subroutine, tracing is also switched on upon RETURN to the caller.

You can use the CMSFLAG('EXECTRAC') function and the command QUERY EXECTRAC to test the setting of the system trace bit.

The command SET EXECTRAC ON turns on the trace bit. Using it before invoking a REXX program causes the program to be entered with debug tracing immediately active. If issued from inside a program, SET EXECTRAC ON has the same effect as TRACE ?R (unless TRACE I or TRACE S is in effect), but is more global in that all programs called are traced, too. The command SET EXECTRAC OFF turns the trace bit off. Issuing this when the bit is on is equivalent to the instruction TRACE Off, except that it has a system (global) effect.

SET EXECTRAC OFF turns off the system trace bit at any time ; for example, if it has been set by a TS immediate command issued while not in a REXX program.

Back to our views : best use of interactive debugging

Given the possibilities as explained above, to debug a procedure, there are at least 2 methods :
Method 1 Change the exec to include trace commands for areas you want to trace. The advantages are that only specific parts will be traced (just what's needed), and other options than just ?R are possible.
Method 2 SET EXECTRAC ON and start the exec. Main advantage is that there is no need to modify the procedure.

If you have to trace a 'foreign' procedure (one you didn't develop), then remember to make a copy of it before you change it when using method 1 above, so that you keep the original time stamp and contents (may be important when communicating problems to the change team).
The time stamp problem also makes it a bad idea to "SET PF3 FILE" in XEDIT

Comments: Method 2 is useful to do a first raw trace to spot the area where the procedure gives problems. If then needed, more accurate tracing can be activated by including a TRACE ?R or even a TRACE ?I in the exec to do 'fine' debugging as suggested by method. To improve the whole process, the EXECCALL goodie can be of great help. If you include following PF-key settings in your PROFILES,

In PROFILE EXEC: 'CP SET PF10 IMM TRACE OFF'
In PROFILE XEDIT, when editing a procedure:
'SET PF10 EXECCALL';'SET PF22 EXECCALL .TS'.

then REXX tracing is only one key away.

EXECCALL is explained in Appendix C. With the definitions as above, PF10 runs without tracing, while PF22 sets the tracing bit on (SET EXECTRAC ON) so that the procedure gets traced.

You can try the EXECCALL procedure by calling it from XEDIT's command line, and if you like it, define your PF-keys in your XEDIT PROFILE as explained above. If you call it from the command line, then the format is:
EXECCALL [.TS] [parameters]

Structuring your procedures

If you use TS or SET EXECTRAC ON, you can get a lot of trace output. To circumvent this problem, you should structure your procedures.

A structured procedure looks like the one below:

A structured procedure

/***************** structured procedure *******************************/ parse upper arg parameters '(' options if parameters='' | parameters='?' then call help PROCESS: call analyze_parameters parameters call analyze_options options call initialize call do_first_step call do_second_step call terminate call exit /***************/ /* Subroutines */ /***************/ HELP: say 'This procedure does...' call exit ANALYZE_PARAMETERS: parse arg parm1 parm2 parm3 . if parm3='' then parm3='DEFAULT VALUE' ... return ... TERMINATE: 'FINIS' say 'Procedure successfully terminated' return EXIT: exit rc

A structured procedure
/*************** structured procedure ***************************/ parse upper arg parameters '(' options if parameters='' \| parameters='?' then call help PROCESS: call analyze_parameters parameters call analyze_options options call initialize call do_first_step call do_second_step call terminate call exit /************/ / Subroutines / /**************/ HELP: say 'This procedure does...' call exit ANALYZE_PARAMETERS: parse arg parm1 parm2 parm3 . if parm3='' then parm3='DEFAULT VALUE' ... return ... TERMINATE: 'FINIS' say 'Procedure successfully terminated' return EXIT: exit rc

If you want to have a more complete example, look at Appendix A. "Sample structured procedure.".

The first, and probably greatest advantage of the structure is that you can better analyze the procedure. It is also more readable at the terminal if each subroutine is not larger than the size of the screen (ideal situation). Subroutines can be coded and tested separately.

Also, when the procedure starts for example the subroutine Analyze_Parameters and you are pretty sure that the routine is working correctly, then just press PF10 (CP's one containing the command TRACE OFF), so that the subroutine is not traced (nor the underlying subroutines). When the subroutine returns to the mainline of the procedure, then tracing is resumed automatically by the interpreter, due to the scope of tracing.

Another technique may be to use the trace() function as explained in "Scope of tracing.".

14
Why is SET EXECTRAC ON useful, as we have a much shorter TS command ?

15
If you have access to a disk containing our goodies, then what happens if you enter HI on XEDIT's command line ? And, what happens if you enter TS on XEDIT's command line ? Can you explain the difference ?

Note: When you are XEDITing a structured procedure, it is useful to be able to jump quickly to the subroutine you want to have a look at. This becomes easy when you follow a quite common coding convention:

Code the label statements in column one and all other statements starting from column 2.
Give all important points in your exec a label, even when REXX will never use the label (previous example labels the main stream as PROCESS:).

If you follow this coding style, then you're able to use XEDIT's FIND subcommand to quickly point to a subroutine via its label(footnote). For example when you would like to have a look at your main structure, then issue fi process: (or FU PROCESS: for backward search) command.

If you are regularly coding or debugging REXX procedures, it may be worth to devote some of your precious PF-keys for direct locating, like these:

   SET PF19 MACRO LAB PREV   /* go to previous label */
   SET PF20 MACRO LAB NEXT   /* go to next label */
   SET PF21 MACRO LAB        /* display all labels and more */

LAB is yet another of our goodies that considers each line that starts with a word ending by a colon as a label. The definition for PF21 deserves more explanation. This are 3 functions in one:

With the cursor on XEDIT's command line, press PF21, and you will see all lines recognized as labels.
With the cursor on one of the labels, press PF21 again and you will see that routine at the top of your display.
With the cursor on a statement containing a call MySubrout, press PF21 and you'll be positioned on the subroutine named MySubrout.

Numeric TRACE Options

Overview.

If interactive debug is active and if the option specified is a positive whole number (or an expression that evaluates to a positive whole number), that number indicates the number of debug pauses to be skipped over. However, if the option is a negative whole number (or an expression that evaluates to a negative whole number), all tracing, including debug pauses, is temporarily inhibited for the specified number of clauses. For example, TRACE -100 means that the next 100 clauses that would normally be traced are not, in fact, displayed. After that, tracing resumes as before.

If interactive debug is not active, numeric options are ignored.

Tracing Tips

When a loop is being traced, the DO clause itself is traced on every iteration of the loop.
If no option is specified on a TRACE instruction, or if the result of evaluating the expression is null, the default tracing actions are restored. The defaults are TRACE N, command inhibition (!) off, and interactive debug (?) off.
You can retrieve the trace actions currently in effect by using the TRACE() built-in function.
If available at the time of execution, comments associated with a traced clause are included in the trace, as are comments in a null clause, if you specify TRACE A, R, I, or S.
removes the comments when the REXX procedure is tokenized and stored in the extended attributes. So, comments are not seen in the trace on OS/2.
Commands traced before execution always have the final value of the command (that is, the string passed to the environment), and the clause generating it produced in the traced output.
Trace actions are automatically saved across subroutine and function calls. In other words, internal subroutines inherit the trace settings from the calling routine, but changing the trace setting in the subroutine remains local to that routine.

Skipping trace output / tracing without pause

Let's talk a bit about TRACE -n and TRACE +n.

By using a negative number as trace option, we can skip the tracing for some statements (they are executed, but you don't see their trace output). This is handy when you trace for example a loop and you know that you have a problem at the 10th iteration of the loop. If the loop has 3 statements, then you can suppress the tracing of 27 statements by issuing the trace -27 command. You'll come immediately to the 10th iteration.

Next figure shows an example of trace suppression.

» ttest ?i
     8 *-* do i=1 to 4
       >L>   "1"
       >L>   "4"
       +++ Interactive trace.  TRACE OFF to end debug, ENTER to continue. +++
» trace -4
    10 *-* end
     8 *-* do i=1 to 4
    11 *-* call subrout
    13 *-*  SUBROUT:
» trace off
Value of i= 5
       +++ Interactive trace.  TRACE OFF to end debug, ENTER to continue. +++
» trace off
Ready; T=0.01/0.01 10:41:17

You can also enter positive numbers, but then, REXX will bypass n pauses. The trace output will be shown.

Our comments/guidelines:

There is a real problem to find a "good" value for "n" ; "n" is the number of REXX clauses that would have been traced. But this doesn't necessarily correspond to the number of lines in the source file.
If you use TRACE -n and n is too big, then REXX goes too far in the procedure and you miss the part you want to see.
It also depends on what you trace. With TRACE ?L, a TRACE -3, means 3 "don't trace 3 labels", while with TRACE ?C, it means "don't trace 3 commands".
When tracing loops, you often know where your loop will go wrong (e.g. when handling the 130'th record).
You have however, most of the time, no clue of the number of REXX clauses you need to skip to reach the failing point, as the number of REXX clauses executed in a single iteration can even vary depending on the contents of the records. Comment records may, for example, use a shorter path in your procedure.

These are possible solutions for our problems:

use small values for -n

trace -20
say i             if var i still much lower than 130 another trace -20
trace -20
 ...
say i             if var i now approaches what we need, do a trace +n
trace +10         if our n was too much, then due to the + we at least
                                         saw our statement(s) traced

Modify your procedure ; don't forget that TRACE is a normal REXX statement that can be placed anywhere, so even after an IF statement to make it conditional, like in this example:

   ....
   do i=1 to record.0
      if i=130 then trace ?i
      parse var record.i w1 w2 . w4 . 0 c1 2
      if c1='*' then iterate i
      ....
   end

Slight variation: suppose you know it fails when user becomes equal to MAINT:

   ....
   do i=1 to record.0
      if user='MAINT' then trace ?i
      parse var record.i w1 w2 . w4 . 0 c1 2
      if c1='*' then iterate i
      ....
   end

If you know things go bad after 129 iterations, you could also manipulate the iteration counter interactively (i=129) to skip unwanted iterations. This will of course only work if you don't work with the stack, or if previous records have no influence on the 130th iteration...

In chapter 8, we will give even more hints and tips for when you have to trace a procedure.

Footnotes:

For those who don't know: FIND is not a synonym of XEDIT's LOCATE command. LOCATE /string/ requests XEDIT to look for a line containing the string in the current zone, while with FIND string XEDIT looks for a line starting with string. For more info about the pitfalls/benefits: HELP XEDIT FIND. Variations/abbreviations: FInd, FINDUp or FU, NOTFInd or NFInd, NFINDUp or NFU
Back to text

Method 1	Change the exec to include trace commands for areas you want to trace. The advantages are that only specific parts will be traced (just what's needed), and other options than just ?R are possible.
Method 2	`SET EXECTRAC ON` and start the exec. Main advantage is that there is no need to modify the procedure.