EiffelLogger Documentation

0. Index

  1. About
  2. Installation
  3. Concepts and Design
    1. Loggers
    2. Appenders
    3. Events
      1. Simple Events
      2. Common Base Events
    4. Layouts
    5. Filters
    6. Configuration Files
    7. Changing Severity Levels at Runtime
  4. Examples
  5. Testcases
  6. Optimizations
    1. Synchronous vs. Asynchronous

1. About

EiffelLogger (elogger) is a multithreaded logging framework that is able to log Common Base Events (CBE) and other events, with high performance in mind. EiffelLogger is based on log4e, a lot of the credit goes to Glenn Maughan for his excellent logging framework. EiffelLogger has been tested on Microsoft Windows using the ISE Eiffel Compiler (EiffelStudio) and Microsoft VisualStudio 2003 C Compiler.

Dependencies:
Please see the wiki page for more information.

2. Installation

3. Concepts and Design

This is the simplified design of the logging framework, which will be explained in detail below.

simple design

3.1 Loggers

The main object to be used is the Logger (ELOG_LOGGER). The logger handles all requests to log certain events and provides an interface for various customizations. Each logger is embedded in a treestructure of loggers (the hierarchy) which can inherit the appenders and severity levels of their parents. A severity level determines what messages are processed and what messages are not. If a logger is set to the Warning severity level, it will only process and display messages of severity greater or equal to its own level.

The severity levels are integer values between 0 and 70:

Severity Level Severity Name Category
60 Fatal Error
50 Critical Error
40 Minor Error
30 Warning Warning
20 Harmless Warning
10 Information Information
0 Unknown Information

If no severity level is attached to a logger, it's parents severity is inherited (the root's severity level is set to Unknown by default and must not be void).

Every logger has a unique name, which identifies it in a given hierarchy. The name defines the tree structure, e.g. the logger "a.b.c" is a heir of "a.b", "a" and "root". If  a logger "a.b.c" is created before having created its parents "a.b" and "a", they will be created implicitly with default settings (void severity and appenders).

3.2 Appenders

Appenders define the target of the log messages. Every Appender has to conform to the deferred class ELOG_APPENDER, which makes exchanging appenders, or writing your own appenders, very easy. If appending a message fails, all the logs will be directed to a backup appender, which may be specified and usually is ELOG_STDOUT_APPENDER.

By default the appenders are set to append asynchronously, which means that they put the event in an event-pool and a consumer thread consumes and appends these threads "concurrently". This is very helpful if you are appending to a slow target, such as a network file.  By using the creation procedure 'make_synchronous' instead of 'make', all the appends are done synchronously (the program continues as soon as the appending has completed).

Event pool

In asynchronous mode, a queue is created. The client puts elements (events) in the queue synchronously and upon creation of the queue, a consumer thread is started, that consumes these incoming events. If too many events are created and the consumer thread cannot keep up with the pace, eventually you might run out of memory.  The solution to this problem is to set a maximal buffer size, with either the appender set to blocking (will wait at the put, until there is space for the event) or not blocking (the event will be discarded).

Every appender has its own queue and its own consumer thread. This is done, because certain appenders might be significantly slower than others.

3.3 Events

Log messages are events, not strings. Events contain a message, a severity, and a timestamp at creation, everything beyond that is optional.

3.3.1 Simple Events

Simple events are the smallest possible event objects, nothing more than message, severity and timestamp.

3.3.2 Common Base Events

If you would like to add more context information, common base events are a standardised way of doing so. Please refer to the specification of CBE for detailed information.

3.4 Layouts

Layouts generate strings from events. There are many different layouts to choose from, but if none of the layouts fit your needs you can write a new layout that conforms to ELOG_LAYOUT and attach it to any appender that is being used. The default layout used is ELOG_SIMPLE_LAYOUT. A layout can be registered with an appender by creating an instance of a layout class and passing it to set_layout.

The pattern layout class provides a flexible way of creating custom layouts using a printf like conversion pattern. The pattern string consists of plain text interspersed with escape sequences that will be substituted with event information. Each escape sequence consists of the character '@' followed by a predefined character that represents the information that will be substituted. The following table lists the escape sequences supported by the pattern layout.

Escape Sequence Result
@@ Insert the literal character '@'
@c Insert the name of the logger that raised the event.
@d Insert the event date
@t Insert the event time
@m Insert the event message
@r Insert a date and time relative to the start of execution
@s Insert the event severity
@n Insert new line

Any other text not preceded by an '@' character is inserted as is. If any other character follows an '@' sign then an error will be raised. You can further modify the output of each escape sequence by adding format modifiers between the '@' sign and the specifier character. The next table shows the types of format modifiers you can use.

Escape Sequence
Left Justify
Minimum Width
Maximum Width
 Description
@20c
False
20
none
 Set the minimum length to 20 characters and right justify. Left pad with spaces if the logger name is less than 20 characters in length.
@-20c
True
20
none
 Set the minimum length to 20 characters and left justify. Right pad with spaces if the logger name is less than 20 characters in length.
@.30c
N/A
none
30
 Set the maximum length to 30 characters. Truncates from the beginning if the logger name is longer than 30 characters.
@20.30c
False
20
30
 Set the minimum length to 20 and the maximum length to 30 and right justify. Left pad if the logger name is shorter than 20 characters or truncate if it is longer than 30 characters.
@-20.30c
True
20
30
 Set the minimum length to 20 and the maximum length to 30 and left justify. Right pad if the logger name is short than 20 characters or truncate if it is longer than 30 characters.

The following convertion pattern:

@d @t [@12s] @c - @m%N

Will result in log events formatted with a date, space character, left square bracket, priority (left justified in a 6 character string), right square bracket, space character, the logger name, another space, the message, and finally, a newline character (which in Eiffel is converted to an appropriate %R%N pair if required by the operating system). Therefore, a log event sent to a logger named audit, with the severity INFORMATION and with the message "xyz successfully logged in", would result in the formatted string:

2006/10/16 6:30:00 [INFORMATION ] audit - xyz successfully logged in

3.5 Filters

Filters are a second level of filtering unwanted log events. The first level was the severity (of the message and the logger). Adding filters to appenders is completely optional, therefore the reference filter: ELOG_FILTER may be void.  Multiple filters can be added by using ELOG_AND_FILTER and/or ELOG_OR_FILTER to build a tree (does not have to be binary).  The comments of those files should be pretty much self-explanatory as to when a message is filtered. There are three levels of acceptance (Filter_reject, Filter_neutral and Filter_accept). If a filter returns Filter_neutral, the effect of the filter is ignored, but may be converted by using ELOG_NEUTRAL_TO_ACCEPT_FILTER and ELOG_NEUTRAL_TO_REJECT_FILTER to convert the results. 

3.6 Configuration Files

EiffelLogger provides a means of defining XML files, that specify a hierarchy configuration (loggers, appenders, layouts, and filters). This is useful, if you want to change for example the severity of an appender and do not want to recompile the whole project.

<?xml version="1.0"?>
<config xmlns="https://origo.ethz.ch/svn/elogger/spec/config">
	<!-- create file appender to log to app.log -->
	<appender name="file" type="file">
		<param name="filename" value="app.log"/>
		<param name="append" value="true"/>
		<layout type="pattern">
			<param name="pattern" value="@d [@-6p] @c - @m@n"/>
		</layout>
	</appender>
	<!-- configure logger 'audit' -->
	<logger name="audit"/>
	<!-- configure the root logger for info events and to log
		to the appender 'file' -->
	<root priority="info">
		<appender-ref ref="file"/>
	</root>
</config>

For more examples please view the examples directory.

3.7 Changing Severity Levels at Runtime

In order to be able to change severity levels upon runtime, a ELOG_CONFIGURATION_LISTENER has to be started.  
This could be done like the following:

	local
		conf_listener: ELOG_CONFIGURATION_LISTENER_THREAD
	do
		create conf_listener.start_listener_thread (8906, True)
		io.put_string ("Started configuration listener on port 8906%N")
	end

The application now listenes to the given port, and parses the strings sent. These command strings are applied to the shared hierarchy (ELOG_SHARED_HIERARCHY). The format of the command strings is:

  command_string := xml_config_file | logger_severity
  xml_config_file := "file:"+a_path_to_a_xml_file
  logger_severity := "logger:"+logger_name+":set_severity:"+severity_name
  severity_name := "FATAL" | "CRITICAL" | "MINOR" | "WARNING" | "HARMLESS" | "INFORMATION"

The configuration client command line tool ELOG_CONFIGURATION_CLIENT can connect to running applications and change the logging hierarchy at runtime. There are also some examples in the /examples directory.

4. Examples

A simple example of how this framework can be used.

        local
            h: ELOG_HIERARCHY
            logger, logger2: ELOG_LOGGER
            a1, a2, a3: ELOG_APPENDER
        do
            create h.make (Warning_severity)
            -- this creates a logger hierarchy, containing only the root logger

            logger := h.logger ("test")
            -- now we have the root logger and a logger called 'test'
            -- inheriting from it. The logger test inherits the severity
            -- level 'Warning_severity' because its severity is Void.

            logger2 := h.logger ("a.b.c")
            -- this implicitly creates the loggers 'a', 'a.b' (inheriting
            -- from 'a') and 'a.b.c' (inheriting from 'a.b')

            h.logger ("a.b").set_severity (Critical_severity)
            -- The severity of 'a.b' has been set to 'Critical_severity'.
            -- The logger 'a.b.c' has inherited this severity.
           
            -- Note: we still cannot log anything, because no appenders
            -- are attached by default.

            create {ELOG_STDOUT_APPENDER} a1.make ("stdout appender 1")
            h.logger ("a.b").add_appender (a1)
            -- Note: if a logger is used multiple times, it is better to
            -- copy the reference of the logger, than to fetch it every
            -- time by its name, because retreiving the actual instance of
            -- the logger takes some time.

            logger2.log_warning (create {ELOG_SIMPLE_EVENT}.make (
                "This will not be printed because the severity sevel is "+
                "lower than the level of the appender"))
            logger2.log_critical (create {ELOG_SIMPLE_EVENT}.make (
                "This will be printed because the severity sevel is "+
                "greater or equal to the level of the appender"))

            a1.set_synchronous_wait
            -- this will set the appender to synchronous and wait until
            -- the consumer thread has consumed all events.

            logger2.log_fatal (create {ELOG_SIMPLE_EVENT}.make (
                "This log is beeing handled synchronously. "))
        end

The output of this example is:
CRITICAL - This will be printed because the severity sevel is greater or equal to the level of the appender
FATAL - This log is beeing handled synchronously.

For more examples, have a look at the testcases in the test folder.

5. Testcases

The testcases can be found in the folder 'test', containing the deferred testcase files needed for getest (a gobo application) to generate the actual test suite (class TEST_ELOGGER). To generate these needed classes just run the 'getest' command in this folder. On Windows open the command shell (Start->Run...->cmd), navigate to the test folder and run 'getest'. On Linux, open a terminal, navigate to the test folder and run 'getest'. Please refer to the gobo installation guide, if the command is not recognized.

The testcases also provide a nice resource of examples.

6. Optimizations

One of the probably most important and easiest issues to solve is object creation. If we run the following code for example, the event object has already been created, before beeing tested for severity.

logger.set_severity (Fatal_severity)
logger.log_warning (create {ELOG_SIMPLE_EVENT}.make ("some log event"))

This event will not be logged due to its severity level, but still, the event object is created. This can be solved by first querying if this level will actually be processed at all (Note: Filters are not beeing checked yet, because filters check other attributes of the events than just the severity).

logger.set_severity (Fatal_severity)
if logger.is_enabled_for (Warning_severity) then
    logger.log_warning (create {ELOG_SIMPLE_EVENT}.make ("some log event"))
end

In this case, the event is not created unless it actually is enabled for the given severity.

6.1 Synchronous vs. Asynchronous

Understanding the difference between synchronous and asynchronous logging is very central. Every appender has the ability to process logs synchronously or asynchronously. Logging synchronously may take less time in average just to process the log, but the caller will block at the call of the log until logging is done completely (e.g. a string has been appended to the specified file). In some applications we do not want to wait for the log to finish completely and just continue with the program flow (in real-time applications for example). These logs are inserted into a buffer and are continuously consumed by a 'consumer_thread' (every asynchronous appender has an own event pool and consumer thread). Appenders can be switched from and to beeing synchronous/asynchronous at runtime. Depending on the used feature, the buffer is either discarded, or the caller (setting the appender to synchronous) waits until the buffer is empty.

When logging asynchronously, the buffer size can be specified to be infinite (buffer_size=0), or any positive integer. The buffer will hold up to 'buffer_size' events and either block (if 'is_blocking' is set to True), or will discard the unprocessable events.