Problem:
This article discusses the Consolidated Tracing Facility (CTF), which is now part of the functionality offered in the latest versions of Net Express and Server Express.
Resolution:
Overview
CTF provides reliable, fast, and configurable tracing capabilities. Eventually it will interleave trace events output from all the components involved in running applications. At present the runtime system (RTS) is the only enabled component: all components are expected to convert to use CTF as their tracing mechanism in future releases of Micro Focus products. CTF is therefore a 'work in progress'.
CTF is enabled by using an environment variable to point to a 'side file' (configuration file) which contains one or more entries. CTF will then run a module, known as an 'emitter' (at present the only emitter is one that produces a plain text file) giving details of the application(s) being run. The exact contents of this text file will depend upon the values of the entries in the side file.
CTF differs from the previously available FaultFinder utility. FaultFinder is designed to be called only when a runtime error occurs, whereas CTF will always run when (a) a side file exists, containing valid entries, and (b) the environment variable is set.
A detailed description of all the features of CTF is beyond the scope of this article; the product documentation will give all the information required.
Setting up CTF: the side file
As described, a side file must exist. This is a plain text file, referenced by the environment variable MFTRACE_CONFIG.
The side file can contain the following entries:
mftrace.application
mftrace.level
mftrace.level.component-name
mftrace.comp.component-name#property
mftrace.emitter.emitter-name#property
Blank lines, and lines beginning with '#', are treated as comments
To describe these entries briefly:
mftrace.level specifies the default tracing level for all components. Possible values are DEBUG, INFO, WARN, ERROR, FATAL, and NONE (these are in decreasing order of verbosity). For example:
mftrace.level=error
mftrace.level.component-name specifies the tracing level for a single component. This option has no real meaning as yet, with only one component available. An example of this would be
mftrace.level=warn
mftrace.level.mf.rts=debug
where the default level is 'warn', whereas the runtime system (mf.rts) would produce more messages, as its level is set to 'debug'.
mftrace.application will restrict tracing to a specific application. For example, to restrict CTF to tracing the executable 'myapp', the entry would be
mftrace.application=myapp
whereas if you wish to trace an executable, say progw, with a trigger program (run in Net Express, cobrun in Server Express), the entry would be
mftrace.application=(progw)
mftrace.comp.component-name#property sets a component property. The product documentation will describe all component values. An example might be
mftrace.comp.mf.rts#all=true
mftrace.comp.mf.rts#memory=false
which would set tracing on for all properties of the runtime (mf.rts), and then turn it off for memory management.
mftrace.emitter.emitter-name#property sets an emitter property. This is best shown with an example:
mftrace.emitter.textfile#location=e:\\logs mftrace.emitter.textfile#file=mytrace.dat_$(GEN)
mftrace.emitter.textfile#maxgeneration=3 mftrace.emitter.textfile#maxfilesize=200
The only possible emitter name at present is 'textfile'. The lines above will create an output text file in e:\\logs, and the file name will be 'mytrace.dat_1' (this is what the '$GEN' will produce.). If the size of the output file threatens to exceed 200 Kb (maxfilesize), then a file mytrace.dat_2 will be produced, and if necessary a third generation (the maxgeneration entry).
A sample side file would be
mftrace.level=error
mftrace.comp.mf.rts#pgm=true
mftrace.comp.mf.rts#pgmload=true
mftrace.emitter.textfile#location=d:\\rts_config
mftrace.emitter.textfile#file=ctf_log_$(GEN).txt
mftrace.emitter.textfile#maxgeneration=9
mftrace.emitter.textfile#maxfilesize=200
Here the pgm and pgmload components are set in order to highlight program entries and exits (pgm) and loads and unloads (pgmload).
N.B.: If you wish to be able to change the entries in a side file during a runtime session, then this cannot be done by editing a side file and expecting the system to pick up the changes. Instead the recommended approach is to have more than one side file (say, one may have mftrace.level=error and another file may instead contain mftrace.level=debug) and then to set the MFTRACE_CONFIG environment variable to whichever file is needed, later resetting the variable as appropriate.
Sample CTF output
Let us assume that we have the following scenario:
(1)
prog01 calls prog02, and then cancels prog02
(2)
prog01 then calls the non-existent program prognonesuch
This should produce a 173 runtime error (program not found). Assuming that the side file contains the entries shown above, the output file will contain values similar to the following:
"
# -MFTRACE Text Emitter-
# CommandLine = prog01
# ProcessId = 2156
# Date = 2005/07/26
# Time = 12:55:16.870
# Operating System = Windows XP Service Pack 2 (Build 2600)
# Computer Name = NWB-PTHXPLAP
# Format = $(TIME) $(COMPONENT) $(EVENT) $(LEVEL)$(DATA)
12:55:16.870 MF.RTS 128 1
12:55:16.870 MF.RTS 129 1
12:55:16.870 MF.RTS 19 1 0 0 "Prog01" "" ""
12:55:16.870 MF.RTS 6 1 17 0 "Prog01"
12:55:16.880 MF.RTS 23 1 0 0 "D:\\ctf01\\RELEASE\\prog02.dll" 61000000
12:55:16.880 MF.RTS 19 1 0 0 "Prog02" "" ""
12:55:16.880 MF.RTS 6 1 17 0 "Prog02"
12:55:16.880 MF.RTS 7 1
12:55:16.880 MF.RTS 20 1 0 0 "Prog02"
12:55:16.880 MF.RTS 6 1 17 0 "Prog02"
12:55:16.880 MF.RTS 7 1
12:55:16.880 MF.RTS 21 1 0 0 "Prog02"
12:55:16.880 MF.RTS 24 1 0 0 61000000
12:55:16.890 MF.RTS 255 3 173 1 "prognonesuch"
12:55:16.890 MF.RTS 23 1 0 0 "C:\\Program Files\\Micro Focus\\Net Express\\Base\\BIN\\cblvios.dll" 60090000
12:55:16.900 MF.RTS 38 1 0 0 "C:\\Program Files\\Micro Focus\\Net Express\\Base\\BIN\\MFLANG05.lbr"
12:55:16.900 MF.RTS 38 1 0 0 "C:\\Program Files\\Micro Focus\\Net Express\\Base\\BIN\\MFLANGDF.lbr"
12:55:18.563 MF.RTS 130 1
12:55:18.563 MF.RTS 20 1 0 0 "Prog01"
12:55:18.563 MF.RTS 6 1 17 0 "Prog01"
12:55:18.563 MF.RTS 7 1
12:55:18.563 MF.RTS 131 1
(This is a file produced under Net Express; the file will of course be somewhat different when produced on Server Express.)
Each line of the file shows an entry detailing a runtime event. For example, consider the following lines:
12:55:16.880 MF.RTS 19 1 0 0 "Prog02" "" ""
12:55:16.880 MF.RTS 6 1 17 0 "Prog02"
These have the following meanings:
(1)
RTS loads Prog02 (event ID 19); this is an informational message (severity 1)
(2)
RTS enters Prog02 (event ID 6), again this is an informational message
Later we have
12:55:16.880 MF.RTS 21 1 0 0 "Prog02"
12:55:16.880 MF.RTS 24 1 0 0 61000000
12:55:16.890 MF.RTS 255 3 173 1 "prognonesuch"
which equates to
(1)
RTS does a physical cancel of Prog02 (event ID 21). Again this is an informational message
(2)
RTS unloads Prog02 (event ID 24)
(3)
RTS fails to find 'prognonesuch'. This is an event ID of 255 (runtime system error 173) and has a severity of 3 (error)
Conclusion
It can be seen that Consolidated Tracing Facility already offers an unparalleled level of detailed information about an application being run. When all components contribute to CTF, there will be a detailed and chronological view of all application events, and this will greatly assist in the debugging of any runtime problems.
