Dwarf Logging Tutorial

This tutorial tells how to use logging in a DWARF system. Logging is especially usefull to debug DWARF, since it is massively distributed.

However, the trivial aproach of logging by just sending messages to a shell, is not sufficient in a large scale application. On the other hand, there are many free logging libraries available, which offer more soffisticated solutions. That includes adding context information to log messages, filtering by source, level of granularity or importance, and sending messages to different destinations. Furthermore it is possible to configure all of that globally, whithout having to modify the program source itself.

For DWARF, the log4x logging libraries from http://logging.apache.org where chosen. This is due to the fact, that there are implementations in many different languages, most notably C++ and Java. (A Python verson will hopefully apear soon) The different logging libraries are designed to be as similar as possible, which makes it easy for a developer, to use them in different programming languages. In addition their outputs are compatible to a certain degree, which enables cross language #DistributedLogging.

Dwarf logging conventions

Logging can only be useful, if it is applied systematicaly. This is especially true, when many developers work on a program simultaniosly, and when components are to be reused. Threfore the following conventions should be obeyed:

• All the output of any program involved in DWARF should be printed through a Logger offered by the respective log4x implementation. That is, print(), cout, System.out.print() should never be used directly.
  • This is especially important for reusable componants like helper classes or middleware wrappers.
  • An exception to this would be a text based UI.
• Any Exception caught should be reported through a Logger. The log message should describe how the application reacts on the Exception.
• The Loggers used should be set up by configuration files, not by program code.
• Loggers should follow a class based naming scheme. That is each class should have its own logger, named after the fully qualified name of the class.
• Only the standard log levels should be used.
  • @TODO specify the use of levels more closely!
• Verbose log messages may replace comments to a certain degree.
• Bracketing log messages should always have the same level.
• The logging configuration files are per service. Each service has its own one.
  • @TODO a basic global configuration and an override mechanism for this should be developed.
  • @TODO probably implement helper classes to offer a flexible way to obtain configuration.
• The logging configuration files in CVS should contain a basic setup interesting for all users. More versatile configurations should be local.
  • @TODO specify default log level to be used in CVS

Those conventions are just proposals. Please contribute your ideas!

Logging of Java Services

DWARF services written in Java use log4j for logging. (The jar-file necessarry is installed in the lab.) There is a good and short tutorial for log4j, but if you follow the following instructions you'll probably never need it.

Each class using it (i.e. every class in DWARF), only needs a few lines of code to set it up. It imports the Logger class, and stores a Logger in a field:

import org.apache.log4j.Logger;

private static final Logger LOG = Logger.getLogger(MyClass.class);

The Logger is initialized statically using a factory method. By specifying the current class as parameter, the Logger gets the same name as the fully qualified name of the class. Therefore the Logger hierarchy mirrors the hierarchy of packeges and classes. This makes it easy to filter log messages by class or package:

Finally you need to use the Logger to output your log messages. That is no more complicated than using System.out:

LOG.debug(message);   LOG.debug(message, exception);
LOG.info(message);    LOG.info(message, exception);
LOG.warn(message);    LOG.warn(message, exception);
LOG.error(message);   LOG.error(message, exception);
LOG.fatal(message);   LOG.fatal(message, exception);

The only thing you have to do is to chose a log level. This can be used for filtering later. The message should usually be a String, but you can log any other Object, too. It will be converted by its toString() method. Optionally you can add an Exception to attach to the message. This is usefull for logging all exceptions, and descriging their context by an additional message. You do not need to add context information (e.g. time, class, line, thread), since log4j will add that for you.

Logging of C++ Services

Comment Three years ago, I wrote the DEBUGSTREAM and TRACEDEBUGSTREAM macros for C++ code, especially in the ServiceManager. This has some special features that I need to debug the middleware, e.g. stack traces, thread identifiers etc. A lot of C++ DWARF services have used these macros as well, by copying code. This has become somewhat of a convention - but it could change, of course. -- AsaMacWilliams - 24 Mar 2004

@TODO Develop a logging scheme for C++ DWARF services.

• @TODO install log4cxx.
• @TODO How to use per service logging configurations. Those can not be packaged with the binary as in Java.

Logging of Python Services^?

@TODO Is there already a log4x implementation for Python? What alternatives are there?

Logging Configuration

To benefit from all advantages log4x offers, a configuration file should be used. That file contains all information about which log messages (filtered by the logger hierarchy and the log level) should be send to which destination (e.g. the console, a log file, a database, a syslog deamon, a log server, a GUI based log client, etc.).

The Configuration File Format

All version of log4x support more or less compatible configuratin files. Actually there are two formats for that: a Java Properties file and a XML file. For DWARF, where XML is used in many other places, only XML configuration files should be used for logging.

There is a short description of the XML configuration file format in the log4j wiki. For the beginning a basic configuration file should be suffiecient. The following example just makes sure that all log messages with log level debug or less are sent to System.out. Each message is prepended with a line stating date, time, thread, log level and the name of the logger.

<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/" debug="false">
  <appender name="console" class="org.apache.log4j.ConsoleAppender">
    <param name="Target" value="System.out"/>
    <layout class="org.apache.log4j.PatternLayout">
      <param name="ConversionPattern" value="%d [%t] %-5p %-40.40c %x \n. %m\n"/>
    </layout>
  </appender>
  <root>
    <priority value="debug" />
    <appender-ref ref="console" />
  </root>
</log4j:configuration>

Loading Configuration Files

To configure log4x from such a configuration file, a helper class can be used. Logging should be configured once per DWARF-service, at sturtup. When using log4j, import DOMConfigurator and call its static configuration method, which takes the URL of a configuration file as parameter:

import org.apache.log4j.xml.DOMConfigurator;

DOMConfigurator.configure("Log4j.xml");

Setting up logging, is even more comfortable, when using the DWARF specific helper class Log4jConfigurator.java:

import de.tum.in.DWARF.util.Log4jConfigurator;

Log4jConfigurator.configure("ServiceName");

This class automatcally searches for service-specific and DWARF-global logging configuration files, and uses them to set up log4j. The advantage of using this class, is that all services use the same conventions for naming and placing configuration files. Another advantage is, that those conventions can easily be modified to match future needs, without changing the services. Refer to the API-documentation of Log4jConfigurator.java for details.

@TODO A similar logging helper class should be developed for C++ services.

Distributed Logging

The support of distributed logging provided by the log4x implementations might prove very usefull for DWARF. Since DWARF is highly distributed, keeping logging local bears several disadvantages. In a DWARF application consisting of many services each log has to be watched seperately in a naive approach. Though there may be many important dependencies between the messages of different services it will be hard to figure them out.

Distributed logging may avoid those problems by collecting all the log messages of a distributed application at one place. In fact this this usage of distributed logging might be called un-distributed loging, since centralization is contradictory to distribution. Never the less centralization is usefull when logging a distributed application like DWARF.

Comment This is an important and useful feature. A future idea: It would be interesting to do this within DWARF itself, e.g. send out the log messages as events which could be received by a DWARF logging service or viewed in DIVE. -- AsaMacWilliams - 24 Mar 2004

Sending log messages over the network

To achive distributed logging, we first have to make sure that log messages are sent to the network, rather than to be handled locally. This does not require writing any special code, since the log4x implementation does all the work. The only thing you have to do is to modify the configuration file, by adding an appender sending log messages to the network. For instance, when using log4j:

<appender name="network" class="org.apache.log4j.net.SocketAppender">
  <param name="RemoteHost" value="localhost"/>
  <param name="Port" value="4445"/>
  <param name="LocationInfo" value="true"/>
</appender>

Then you have to configure a logger to use the network appender:

<logger name="org.example.MyClass" additivity="true">
  <level value ="debug" />
  <appender-ref ref="network" />
</logger>

When the logger's additivity is true, the network appender is added to the other appenders, rather than replacing them. That means there will still be output on the console, if you configured the root logger or any other parent logger accordingly.

There are many other appenders capable of sending log messages over the network. The best way to discover their capabilities is to read the JavaDocs of the respective classes. Some examples are SocketAppender, SocketHubAppender, SMTPAppender, SyslogAppender and TelnetAppender.

The approach described above is not limited to Java. There are similar appenders for the other log4x implementation. As concerns the SocketAppender, it is said that the different implemantations use the same communication format. This should enable log messages sent by DWARF services written in different languages to be received by one logging server, as described below.

Receiving log messages

Sending log messages over the network is only usefull, when someone receives them. In the case of log4x it might be one the logging servers from the log4j distribution. There is for instance the SimpleSocketServer, which can be started like this:

java org.apache.log4j.net.SimpleSocketServer 4445 Log4j.xml

The first argument sates the port to listen for log messages. Any log messages send to this port by one or more =SocketAppender=s will be received.

The second argument refers to a configuration file, which describes what to do with the mesages received. This is the same kind of configuration file as used to configure loggers in DWARF services. (Though you should not use exactly the same one, to avoid network recursion.) Usually a simple configuration file sending all log messages to the console should be sufficient.

An even easier and more comfortable approach ist to use a GUI based logging server, like Chainsaw. No configuration file is neccessary here, since some simple settings can be made directly in the GUI. That even includes interactive filtering.

Chainsaw is included in the jar-file of the log4j distribution, so it is easy to start:

java -Dchainsaw.port=4445 org.apache.log4j.chainsaw.Main