Tracing Examples

Restriction: CTF is supported for native COBOL only.

By default, tracing is disabled for all components, so the absolute minimum you need to do to enable run-time system tracing is to specify an mftrace.level or mftrace.level.mf.rts entry in the configuration file. For example, if you have set the MFTRACE_CONFIG environment variable set as follows:

and contains only the following entry:

mftrace.level=error

a trace file with an entry for event id 255 would be created by any process that generated a run-time system error. Note that you do not have to specify any properties for the mf.rts component for this event to be emitted; having the trace level set to error is enough.

In the examples that follow, the application mymain is used. This application comprises two programs: mymain.cbl and mysub.cbl that include the following code:

mymain.cbl:

 identification division.
 program-id. mymain.
 environment division.
 data division.
 working-storage section.
 01 my-var pic 9(9) external.
 procedure division.
     move 1 to my-var

     perform 5 times
         call 'mysub'
         add 1 to my-var
     end-perform

     cancel 'mysub'

     call 'myprog'
     goback.

mysub.cbl:

 identification division.
 program-id. mysub.
 environment division.
 data division.
 working-storage section.
 01 my-var pic 9(9) external.
 procedure division.
     display my-var
     goback.

When mymain is executed, run-time system error 173 (“Called program file not found in drive/directory”) occurs because of the call to myprog. The contents of a trace file generated using the configuration above look similar to the following:

The entries marked 1> through 8> are header records output by the TEXTFILE emitter giving information about the application being traced. 8> indicates the format of the subsequent trace entries (this example is using the default trace entry format), so the fields in entry 9> can be interpreted as follows:
Information in Trace File Pseudo-variable Description
$(TIME) The time the trace entry was output.
MF.RTS $(COMPONENT) The name of the component outputting the trace entry. MF.RTS indicates the run-time system.
255 $(EVENT) The event identifier. Event identifier 255 for the mf.rts component indicates a run-time system error.
3 $(LEVEL) The level of the error, based on the following values:
  • 0 = debug
  • 1 = info
  • 2 = warning
  • 3 = error
  • 4 = fatal
173 1 "myprog" $(DATA) Event-specific data.

If you now rerun mymain after changing the statement in the configuration file to specify a trace level of INFO, as follows:

mftrace.level=info

the trace file created contains entries for the run-time system initialization and de-initialization events in addition to the run-time system error event. The trace file looks similar to the following:

To see which programs the application has invoked before the run-time system error occurred you need to set the PGM property. If you want to see where the programs have been loaded from and when they are canceled, you also need to set the PGMLOAD property, as follows:

mftrace.level=info
mftrace.comp.mf.rts#pgm=true
mftrace.comp.mf.rts#pgmload=true

When you rerun mymain, the trace file created contains additional entries for program load, entry, exit, and cancel events. The trace file looks similar to the following:

The entries marked 1> and 2> show event type 6 and 7 entries (program entry and exit) for a program immediately after an event type 20 entry (logical cancel) for the same program. This is because the Compiler embeds a cancel routine in all programs to close any files that the program may have opened. These cancel routines are implicitly invoked by the run-time system as part of a logical cancel operation.

To enable the tracing of all run-time system events with the exception of the memory management ones, you use the following configuration file entries:

mftrace.level = info
mftrace.comp.mf.rts#all=true
mftrace.comp.mf.rts#memory=false

When you rerun mymain, the trace file created contains additional entries for external data items. If you have compiled the programs with the AMODE directive, there would also be entries for each of the Mainframe Pointer Manager events. The trace file looks similar to the following:

The entries marked 1> and 2> show the additional entries for external data items.