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.

Note: The tracing facility is not supported on the Microsoft .NET platform.

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:

Tip: To enable tracing on only part of a system, disable tracing at the very beginning of the program, enable it just before the part of the code that should be traced, and then disable it again after this section. The code below illustrates this tip.

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

Warning: Enabling/disabling tracing as shown above has to be done within the same routine otherwise the computed depth would be inaccurate and this would cause some unpredictable results.

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