Tracing
Introduction
The tracing facility allows you to see a structured log of the flow of control through your system, feature by feature. By default, execution traces are written to standard output.
The "Trace" project setting
You can make tracing usable for a particular cluster by setting the Trace setting to True in your project settings for a particular cluster.
To do this:
- Open the Project Settings dialog.
- Under Clusters select the cluster you want to see traced.
- Set the value of Trace to True.
- Click Apply or OK.
- You must recompile your project for the changes to take effect.
This will cause a trace entry to be written to the console for any feature execution on a class in the cluster(s) you selected for tracing. To get a feel for this, look at the following trace outputs, built on the default Eiffel application ("Hello Eiffel World!).
First, here's what the "Hello Eiffel World!" output looks like without using the tracing facility.
Next, here's the output when the Trace project setting is set to True on the root cluster.
Last, here's the output when Trace is True for both the root cluster and EiffelBase.
Dynamic control
It is also possible to enable and disable the trace dynamically. To do this:
- Create an object of type TRACING_SETTING .
- Call enable_tracing on this object to start the trace.
- Call disable_tracing on this object to stop the trace.
In the root feature:
local ts: TRACING_SETTING -- Other local variables if necessary. do create ts.make ts.disable_tracing -- Program execution continues. ... -- Restore tracing before exiting for proper cleanup. ts.enable_tracing end
Then, in a feature in which tracing is desired:
local ts: TRACING_SETTING -- Other local variables if necessary. do create ts.make ts.enable_tracing -- Enable trace -- Section needing trace. ... ts.disable_tracing -- Disable trace end
Using a trace handler
You can do more complex tracing tasks by using a trace handler. The deferred class TRACE_HANDLER
contains a deferred feature trace
which you can effect in a descendant of TRACE_HANDLER
. Your effective version of trace
will be called whenever a trace event occurs. {TRACE_HANDLER}.trace
looks like this:
trace (a_type_id: INTEGER; a_c_class_name, a_c_feature_name: POINTER; a_depth: INTEGER; a_is_entering: BOOLEAN) -- Trigger a trace operation from a feature represented by `a_c_feature_name' defined in -- class `a_c_class_name' and applied to an object of type `a_type_id' at a call depth `a_depth'. -- If `a_is_entering' we are entering the routine, otherwise we are exiting it. require a_type_id_non_negative: a_type_id >= 0 a_depth_non_negative: a_depth >= 0 deferred end
You may notice in the specification for trace
above that the arguments representing the class and feature names are of type POINTER
(versus some variant of STRING
).
To make this facility more approachable for common tasks, EiffelBase also contains another class, a deferred descendant of TRACING_HANDLER
, called STRING_TRACING_HANDLER
in which the trace
feature's arguments for class and feature names are strings, and the argument for type is an instance of TYPE
rather than an integer type id as in TRACING_HANDLER
. {STRING_TRACING_HANDLER}.trace
looks like this:
trace (a_type: TYPE [detachable ANY]; a_class_name, a_feature_name: detachable STRING; a_depth: INTEGER; a_is_entering: BOOLEAN) -- Trigger a trace operation from a feature represented by `a_feature_name' defined in -- class `a_class_name' and applied to an object of type `a_type' at a call depth `a_depth'. -- If `a_is_entering' we are entering the routine, otherwise we are exiting it. require a_depth_non_negative: a_depth >= 0 deferred end
Suppose we wanted to write trace long entries in a private log file for the entry and exit of a number of routines during the run of a simple application. We could create a descendant of STRING_TRACING_HANDLER
that looks like this:
class EXAMPLE_HANDLER inherit STRING_TRACING_HANDLER feature trace (a_type: TYPE [ANY]; a_class_name, a_feature_name: STRING_8; a_depth: INTEGER_32; a_is_entering: BOOLEAN) -- <Precursor> do trace_log_file.put_string (create {STRING}.make_filled ('>', a_depth)) if a_is_entering then trace_log_file.put_string (" Is entering " + "{" + a_class_name + "}." + a_feature_name + "%N") else trace_log_file.put_string (" Is leaving " + "{" + a_class_name + "}." + a_feature_name + "%N") end end trace_log_file: PLAIN_TEXT_FILE -- Log file once create Result.make_open_write ("my_log_file.txt") end close_log_file -- Close log file do trace_log_file.close end end
In EXAMPLE_HANDLER
the procedure trace
is effected to write the desired information to the log_file
.
Then we could use EXAMPLE_HANDLER
in a class that might look like this:
class APPLICATION create make feature make -- Run application. local tracing_setting: TRACING_SETTING tracing_handler: EXAMPLE_HANDLER do create tracing_setting tracing_setting.enable_tracing create tracing_handler tracing_handler.activate call_depth_one tracing_handler.deactivate tracing_handler.close_log_file tracing_setting.disable_tracing end call_depth_one -- Call depth one routine do call_depth_two end call_depth_two -- Call depth two routine do call_depth_three end call_depth_three -- Call depth three routine do end end
In {APPLICATION}.make
, the instances of TRACING_SETTING
and EXAMPLE_HANDLER
are created. Tracing is enabled and the handler is activated. After the section of interest, the handler is deactivated, the log file closed, and tracing disabled.
Now consider a system in which {APPLICATION}.make
is the root, APPLICATION
is the only class in the root cluster, and that the project setting Trace is true for the root cluster only. After running the system, the content of my_log_file.txt
would be:
> Is entering {APPLICATION}.call_depth_one
>> Is entering {APPLICATION}.call_depth_two
>>> Is entering {APPLICATION}.call_depth_three
>>> Is leaving {APPLICATION}.call_depth_three
>> Is leaving {APPLICATION}.call_depth_two
> Is leaving {APPLICATION}.call_depth_one