Banner showing base of Eiffel tower

Github

Download version 1.4.8: Windows or Linux

Runtime Library: Multi-threaded Logging

The Multi-threaded Logging library has 36 classes.

ECF: logging.ecf

Source code: directory list

Logging library featuring color highlighted output and mimicry of Eiffel routine code in output.

General Features

Output Format

The beauty of Eiffel-Loop logging is that the output is indented to show the entry and exit from routines. Each entry and exit to a routine is documented with a header and trailer output text based on the class name and routine name. The following is some sample output from a test program for the Eiffel Loop VTD-XML API. The test function executes an xpath query looking for http urls in an XML document.

1>     VTD_XML_TEST_APP.test_bio_2 (
1>         argument (1) = "//value[@type='url' and contains (text(), 'http://')]"
1>     ) is
1>       doing
1>         
1>         EL_XPATH_ROOT_NODE_CONTEXT.context_list is
1>           doing
1>             
1>           end -- EL_XPATH_ROOT_NODE_CONTEXT
1>         http://iubio.bio.indiana.edu/grid/runner/
1>         http://iubio.bio.indiana.edu/grid/runner/docs/bix.dtd
1>         http://www-igbmc.u-strasbg.fr/BioInfo/ClustalW/
1>         http://geta.life.uiuc.edu/~gary/programs/fastDNAml.html
1>         
1>       end -- VTD_XML_TEST_APP

The code which produced the above output is as follows:

class
   VTD_XML_TEST_APP

inherit
   EL_SUB_APPLICATION

feature -- Basic operations

   test_bio_2 (xpath: STRING) is
      -- list all url values
      local
         node_list: EL_XPATH_NODE_CONTEXT_LIST
      do
         log.enter_with_args ("test_bio_2", << xpath >>)
         node_list := bio_info_root_node.context_list (xpath)
         from node_list.start until node_list.after loop
            log.put_line (node_list.context.string_value)
            node_list.forth
         end
         log.exit
      end

feature {NONE} -- Implementation

   bio_info_root_node: EL_XPATH_ROOT_NODE_CONTEXT

Note that each logged routine must start and finish with a paired call to enter_with_args and exit and that the first argument to enter_with_args matches the name of the routine. The log object maintains a logging call stack. A call to enter_with_args pushes a new routine onto the stack and exit pops the entry. The second argument is of type ARRAY [ANY] and is used to log any routine arguments. Routine enter_with_args calls the out function from the universal ancestor class ANY for each of the array items and lists them each on a separate line as argument (1), argument (2) etc.

Comment on Java

This type of logging would be difficult to implement in Java as multiple return instructions could appear anywhere in the routine. (Not that I haven't tried, in fact this framework originally started life as a Java framework) This is another argument in favor of languages like Eiffel which disallow arbitrary returns mid routine. Also Java is littered with all kinds of exception handling which greatly increases the number of exit paths from a routine (not to mention making the code more difficult to read). Eiffel has exception handling too but the philosophy of Eiffel is to head off unbridled use of exceptions by extensive debugging with the use of contracts instead of relying on exceptions to show you the bugs.

Enter and exit variations

A number of variations exist for the enter and exit procedures in the log object:

If you do not wish to log any routine arguments you can use the form:

log.enter ("test_bio_2")

If you wish to suppress the routine header and trailer output text you can use the form:

log.enter_no_header ("test_bio_2")
..
log.exit_no_trailer

Managing exceptions

In order to maintain the integrity of the logging routine stack it is important to balance every call to log.enter with a call log.exit on exiting a logged routine. However if your routine has a rescue clause and an exception occurs, these exit calls are skipped not only in the current routine but also in all sub routines before the point where the exception was thrown. If you wish to recover from the exception by doing a routine retry you need a way to restore the logging routine stack back to what it was before the first log.enter call at the start of the routine. You can accomplish this by saving the state of the logging stack to a local variable before the log.enter call and use this variable to restore the logging stack in the rescue clause. The following code illustrates:

my_routine is
      -- Exception handling routine
   local
      log_stack_pos: INTEGER
   do
      log_stack_pos := log.call_stack_count
      log.enter ("my_routine")
      ..
      log.exit
   rescue
      log.restore (log_stack_pos)
      ..
      retry
   end

Including logging in your application

There are a number of ways to include logging in your application. The first is to inherit EL_LOGGED_SUB_APPLICATION in your root class and implement the function Log_filter (see below). You must then make sure that init_logging is the first routine called in the application entry make procedure. A slightly simpler way is to inherit from class EL_SUB_APPLICATION in your root class. This class has a make procedure already defined which calls init_logging, you only have to implement the procedures initialize and run. The routine make must be listed as a creation procedure.

Inheriting from class EL_SUB_APPLICATION has some incidental benefits including:

To including logging facilities in any class, inherit from class EL_MODULE_LOG and add an entry for that class in the log filter array. (see below)

By default logging is not active in the application. It must be turned on using the -logging command line switch.

Log output filtering

The logging framework offers a simple way to filter the output by class and routine. The root class of your application should inherit class EL_LOGGED_SUB_APPLICATION and implement the routine Log_filter as a once function returning an array of tuples. The Log_filter for class TEST_VTD_XML_APP is implemented as follows:

feature {NONE} -- Constants

   Log_filter: ARRAY [like CLASS_ROUTINES]
         --
      do
         Result := <<
            [{TEST_VTD_XML_APP}, All_routines]
         >>
      end

Each tuple in the array consists of the name of the class you wish to enable logging for, followed either by a list of individual routines or a All_routines to indicate that any and all routines are to be logged for that class. You can disable logging for any particular routine by prefixing the name with a hyphen. In the case of a wildcard, prefixing with a hyphen disables all logging for that class. The class filter is compared only with the generating class name so all child classes in a particular inheritance tree must be listed individually.

Command Options

A list of command options which effect the logging system can be found in class EL_LOG_COMMAND_OPTIONS.

User step-through logging

For debugging purposes you may wish to pause execution on the exit of each logged routine. The following call causes the application to stop execution on the exit of every logged routine and prompts the user to press enter to continue:

Logging.set_prompt_user_on_exit (true)

The logging object is available in the root class or by inheriting EL_MODULE_LOGGING.

Logging threads

Logging a separate thread just requires that you inherit from EL_LOGGED_IDENTIFIED_THREAD and make sure the routine on_start gets called. It will anyway unless you do something to over-ride this routine.

feature {NONE} -- Event handling

   on_start
      do
         Log_manager.add_thread (Current)
      end

By default it is the log output of the main thread that is visible in the console terminal. To change the logging output visible in the console to another thread call redirect_thread_to_console with the thread's index. The index of the main launch thread is 1. Subsequently added threads have indexes of 2, 3, 4 etc. Use function is_valid_console_index to check if the index is valid.

Log_manager.redirect_thread_to_console (index)

It is this index which is displayed as part of the log output prompt. If you are not sure what the index of the thread is you can obtain it from the thread name with a call like:

my_thread_index := Log_manager.thread_index ("My thread")

Logging Routines

Access to the logging routines is through feature log of class EL_MODULE_LOG. The log object conforms to type EL_LOGGABLE which has numerous procedures for writing to the log as well as some useful functions.

The procedure form:

put_<lowercase type name>

is use to output the following types: STRING, INTEGER, CHARACTER, REAL and DOUBLE.

The procedure form:

put_<lowercase type name>_field

is used to output the following types prefixed with a field label: STRING, INTEGER, INTEGER_INTERVAL, REAL and DOUBLE.

The procedure put_string_field_to_max_length is used to output a multi-line block of text in abbreviated form. The beginning and last 30 characters of the string is output up to a maximum number of characters (or 1/3 of the maximum length, whichever is smaller). If the text contains more than one line, tab indents are inserted to left align the text to the correct logging indent. The boolean function current_routine_is_active can be tested in order to conditionally execute a block of code if the current routine is unfiltered by any routine filter.

Always on logging

Class EL_MODULE_LOG also has a special logging object named lio, short for "log or io". This is used in the same way as the usual log object with the difference that the output will still be written to the console even if logging is globally disabled. It can be used to write to the console instead of the usual io medium from class ANY.

Log files

All log files are put in a sub directory logs of the current working directory. If you are making your application loggable using EL_SUB_APPLICATION then these log files are automatically deleted when the application exits. If you want a chance to inspect the log files in an editor before they disappear there are a number of ways to do this:

Use the command line switch -keep_logs. The log files will not be deleted and will not be overwritten during subsequent application runs. It is recommended to delete them manually.

If you are using the Eiffel Loop multi application mode framework then the log files are placed in the following subdirectory of the user home directory derived from the executable name and sub application name.

/<user>/home/.<executable name>/<sub app name>/logs   

For example if the executable is named foo and the sub application is bar then for user joeblogs the log directory path is:

/joeblogs/home/.foo/bar/logs

Commenting out log lines

Allthough having logging turned off is usually sufficient to maximize performance of the application it may sometimes be desirable to comment out all the logging lines. An autoedit utility application is included for that purpose in the toolkit project. The best strategy is to comment out logging calls by hand in performance critical sections.

Future enhancements

At present changes to the log filtering necessitates a recompilation of the code. A useful enhancement being considered will allow the default log filtering to be overridden by a Pyxis logging configuration file.

Directory: library/runtime/logging

[ . ]

. /concurrency

. /concurrency/producer-consumer

. /concurrency/producer-consumer/distributer

. /concurrency/thread-type

. /console-and-file

. /file-processing

. /support

[ . ]

EL_LOGGED_COMMAND_LINE_SUB_APPLICATION

Logged command line sub application

EL_LOGGED_SUB_APPLICATION

Logged sub application

EL_MODULE_LOG

Access to the Eiffel-Loop log output routines defined by class EL_LOGGABLE

Notes If inheriting this module in a class which already inherits EL_MODULE_LIO then undefine these factory functions from EL_MODULE_LIO

undefine
   new_lio, new_log_manager
end

This is because EL_MODULE_LIO redefines the lio object to be loggable.

EL_MODULE_LOGGING

Module logging

EL_MODULE_LOG_MANAGER

Module log manager

concurrency

EL_LOGGED_MUTEX_REFERENCE

Guards objects that require thread synchronization and helps to detect deadlock. Any time a thread is forced to wait for a lock it is reported to the thread's log.

EL_LOGGED_SINGLE_THREAD_ACCESS

Logged single thread access

EL_LOGGED_THREAD_MANAGER

Logged thread manager

EL_LOGGED_THREAD_SAFE_STACK

Logged thread safe stack

EL_SHARED_LOGGED_THREAD_MANAGER

Shared logged thread manager

concurrency/producer-consumer

EL_LOGGED_CONSUMER

Logged consumer

EL_LOGGED_CONSUMER_THREAD

Logged consumer thread

EL_LOGGED_DELEGATING_CONSUMER_THREAD

Logged delegating consumer thread

EL_LOGGED_EVENT_COUNTER

Intermittently log counting of timed event activity in thread classes like EL_REGULAR_INTERVAL_EVENT_PRODUCER or EL_CONSUMER. Output frequency is determined by Logs_per_minute constant.

EL_LOGGED_MANY_TO_ONE_CONSUMER_THREAD

Logged many to one consumer thread

EL_LOGGED_REGULAR_INTERVAL_EVENT_PROCESSOR

Logged regular interval event processor

EL_LOGGED_REGULAR_INTERVAL_EVENT_PRODUCER

Logged regular interval event producer

EL_LOGGED_THREAD_PRODUCT_QUEUE

Logged thread product queue

EL_LOGGED_TIMEOUT

Logged timeout

concurrency/producer-consumer/distributer

EL_LOGGED_FUNCTION_DISTRIBUTER

Logged function distributer

EL_LOGGED_PROCEDURE_DISTRIBUTER

Logged procedure distributer

EL_LOGGED_WORK_DISTRIBUTER

Logged work distributer

concurrency/thread-type

EL_LOGGED_IDENTIFIED_THREAD

Logged identified thread

EL_LOGGED_WORKER_THREAD

Worker thread with logging output visible in console

EL_LOGGED_WORK_DISTRIBUTION_THREAD

Logged work distribution thread

console-and-file

EL_CONSOLE_AND_FILE_LOG

Console and file log

EL_CONSOLE_AND_FILE_ROUTINE_LOG

Logs routines which are set to have logging enabled in the global configuration

EL_FILE_AND_CONSOLE_LOG_OUTPUT

File and console log output

EL_FILE_AND_HIGHLIGHTED_CONSOLE_LOG_OUTPUT

File and highlighted console log output

file-processing

EL_BATCH_FILE_PROCESSING_THREAD

Batch file processing thread

EL_FILE_PROCESS_THREAD

Thread for file serialization with progress notification

EL_LOGGED_FILE_PROCESS_THREAD

Logged file process thread

support

EL_CONSOLE_MANAGER

Console manager

EL_GLOBAL_LOGGING

Global logging

EL_LOG_COMMAND_OPTIONS

Command line options for logging

EL_LOG_MANAGER

Log manager