1.1.6
Log4
r
Manual
 

Table of Contents


Scope of this Manual

Most of the API documentation resides in the Log4r RDoc API, so this manual will be brief and targeted to people starting to learn about Log4r or who want to see what Log4r has to offer.

Besides the general overview, a section called The Art of Logging provides tricks and tips in using Log4r efficiently.

Click on the section title to go back to the Table of Contents at any time.


What Log4r Is

Log4r is a comprehensive and flexible logging library written in Ruby for use in Ruby programs. It features a hierarchical logging system of any number of levels, custom level names, logger inheritance, multiple output destinations, execution tracing, custom formatting, thread safteyness, XML and YAML configuration, and more.

Log4r is an adherent to the philosophy of logging using simple print statements. What Log4r adds to this philosophy is a flexible way of controling the information being logged. Log information can be sent to any kind of destination and with varying degrees of importance. Log4r is designed so that logging statements can remain in production code with almost no extra computational cost.

Log4r intends to be easy to use and configure, no matter the complexity. Casual scripts can use Log4r right away with minimal configuration, while more sophisticated applications can set up a structured configuration file in XML or YAML. Comprehensive documentation is provided, with a user's manual, a reference API, and over a dozen examples. Log4r attempts to abide by the Principle of Least Surprise, which means that it works as intended at all points.

Log4r was inspired by and provides much of the features of the Apache Log4j project, but is not a direct implementation or clone. Aside from superficial similarities, the projects are not related in any way and the code base is completely distinct. Log4r was developed without even looking at the Apache Log4j code.

Log4r is an Open Source project and intends to remain that way. The Log4r license is similar to the Ruby Language license. It resides on

While Log4r is interpreted, it attempts to achieve optimal performance and scale well. Already, plans are being made to write the performance-critical components as a C extension to Ruby.

Log4r was inspired by and provides much of the features of the Apache Log4j project, but is not a direct implementation or clone. Aside from superficial similarities, the projects are not related in any way and the code base is completely distinct. Log4r was developed without even looking at the Apache Log4j code.

Log4r is an Open Source project and intends to remain that way. The Log4r license is similar to the Ruby Language license. It resides on this page and in the distribution in a file


Out of the Box

Here's an example of how to use Log4r right away.
require 'log4r'
include Log4r

# create a logger named 'mylog' that logs to stdout
mylog = Logger.new 'mylog'
mylog.outputters = Outputter.stdout

# Now we can log.
def do_log(log)
  log.debug "This is a message with level DEBUG"
  log.info "This is a message with level INFO"
  log.warn "This is a message with level WARN"
  log.error "This is a message with level ERROR"
  log.fatal "This is a message with level FATAL"
end
do_log(mylog)
The output will look something like this:
DEBUG mylog: This is a message with level DEBUG
 INFO mylog: This is a message with level INFO
 WARN mylog: This is a message with level WARN
ERROR mylog: This is a message with level ERROR
FATAL mylog: This is a message with level FATAL
For ease of access, the logger is stored in a hashtable keyed to its name:
mylog = Logger['mylog']        # Get our logger back
Suppose we want to turn off DEBUG, INFO and WARN messages and see only ERROR and FATAL. To do this, we set the level threshold for mylog to ERROR:
mylog.level = ERROR
Running do_log(mylog) yields:
ERROR mylog: This is a message with level ERROR
FATAL mylog: This is a message with level FATAL


Overview

We will now go over the components of Log4r. A summary of each is provided, and links to the Log4r RDoc API are provided for further perusal.


Levels

Log4r uses a hierarchical system of logging. That is, certain log events can have a higher priority than other log events. Hence, one can control how much information one wants to log by adjusting the level threshold of logging. By default, the logging levels and priorities are:
DEBUG < INFO < WARN < ERROR < FATAL
In the previous section, we saw how setting the level to ERROR prevented messages with levels DEBUG, INFO and WARN from showing up. The names and numbers of these levels are configurable. You can have any number of levels and name them whatever you wish. The logging methods we saw in the last section will be named after the custom levels. Log4r adjusts itself to suit your needs.

To find out more about levels, please see rdoc/Log4r.html.


Loggers

The principle interface in Log4r is a Logger. Loggers have one logging method for each level and any number of output destinations. A logger's level threshold and output destinations may be changed dynamically. Loggers are stored within a Repository for retrieval at any time. Loggers provide all kinds of data for logging: the log message itself, the line number and file it was called in, a timestamp, the log priority, and so on.

Loggers can inherit other Loggers. Inheritance means that a Logger initially adopts the characteristics of its parent if none are specified. A Logger's level is inherited once, and a Logger will write to its parents output destinations as well as its own. This behavior is optional, but allows one to structure a powerful, and easily configurable logging system.

To find out more about loggers, please see rdoc/Log4r/rdoc/logger.html.


Outputters

An output destination (file, raw IO, stdout, etc.) is represented by an Outputter object. An Outputter has a particular means of formatting data (Formatter) and has a level threshold of its own. Outputters, like Loggers, are stored in a repository and can be retrieved and manipulated at any time. Every outputter is thread-safe, meaning that multiple threads can log to the same Outputter without worrying about race conditions.

There is a growing collection of outputters provided: raw IO, to stdout, to stderr, to files (including one that splits and zips up logs periodically), to syslog and to an email address. If a specialized Outputter is needed, one can be created from scratch in almost no time, thanks to the ease of extending log4r outputters, the well documented code and the open source license.

To find out more about outputters, please see rdoc/Log4r/rdoc/outputter.html.


Formatters

A Formatter is responsible for rendering a log message into an output format. Several Formatters are provided, including the powerful PatternFormatter. PatternFormatter uses sprintf-like directives to format log messages and eliminates the need for custom Formatters.

To find out more about formatters, please see rdoc/Log4r/rdoc/formatter.html.
To find out more about PatternFormatter, please see rdoc/Log4r/rdoc/patternformatter.html.


Configuration

Configuring Log4r is accomplished via the Configurator and YamlConfigurator classes. They allow one to set custom levels and load up XML or YAML configurations. The XML and YAML grammar used by Log4r is extremely flexible and can accomodate the configuration of custom Outputters and Formatters with no extra work. That is, if a custom Outputter is created, it can immedieately be configured without needing to write extra code. This is acomplished by taking advantage of Ruby's powerful reflection capabilities.

To find out more about configuration, please see rdoc/Log4r/configurator.html.
For YAML configuration, also see rdoc/Log4r/yamlconfigurator.html


Remote Logging

It is possible to send log events from an Outputter to a Logger over a network. This is accomplished using the distributed Ruby library ROMP, a subclass of Logger called LogServer, and a RemoteOutputter.

To find out more about remote logging, please see rdoc/Log4r/rdoc/logserver.html

Alternatively, one can just send log reports via email using EmailOutputter.

To find out more about EmailOutputter, please see rdoc/Log4r/EmailOutputter.html


The Art of Logging

Log4r in itself does not automatically enable people to understand logging, however it does provide tools to assist in The Art of Logging. We will now cover some of the techniques in this art and how to use Log4r to accomplish them.


Avoiding Parameter Evaluation

Suppose we have a complex structure and don't have the time to make a special to_s method. When we want to log the contents of the object, we end up doing something like this:
log.debug( myobj.collect{|e| e.collect{|p| p.to_s}} )
It is expensive to do this because every time the debug method is called, the parameters passed to it will be evaluated. Because this is a feature of Ruby, setting the logger to OFF will not prevent the evaluation. There are two ways to get around parameter evaluation. The first is to perform a simple if condition:
if log.debug?
  log.debug( myobj.collect{|e| e.collect{|p| p.to_s}} )
end
Here we are introduced to log.debug?, which is called a query method. It returns true if DEBUG messages are being logged, otherwise it returns false. Query methods are very cheap to invoke and are a great way to encapsulate complext logging statements. The query methods, like the logging ones, are named after the levels, but with a question mark at the end. As another example, log.info? will find out if INFO is being logged and so on.

The second way around parameter evaluation is to pass a block to the logging method:

log.debug { myobj.collect{|e| e.collect{|p| p.to_s} }
The block will be evaluated if and only if the logger is capable of handling DEBUG log events.


How Many?

How many loggers should one have? Only experience can tell, but a general rule of thumb is to create one static logger per class and one per service or state.

When dealing with a large number of loggers, logger inheritance and additivity can help organize what gets logged and to where.

The configuration possibilities in Log4r are uncountable and can sometimes be daunting. It's best to start with something simple and evolve it over time. To assist in this task, Log4r can be set up using XML or YAML configuration files.


Where To?

Log4r lets one associate any number of Outputters to a Logger. Logger additivity enables propagation of a log event upwards in the logger hierarchy. The outputters themselves can have their own level thresholds. Unlike normal loggers, Outputters can log at certain specific log levels. this allows one to channel particular data to a particular output. All things considered, log4r offers tremendous flexibility in deciding what gets logged where.


Where From?

Want to find out where a particular log statement came from? Loggers have tracers which record the call stack when turned on:
Logger['mylog'].trace = true
The trace is then accesible by a Formatter. e.g.



Who's Talking?

If there are many loggers that use logger inheritance, it's occasionally a good idea to show the full ancestry of a logger in the log statement. Here's how to set up PatternFormatter to show the full ancestry of a logger in a logging statement (in XML):
<formatter type="PatternFormatter">
  <!-- %C shows full ancestry -->
  <pattern>[%l %C] %m</pattern>
</formatter>
For a logger named 'me' with ancestors 'cain::grandpa::pa', it will produce:
[DEBUG cain::grandpa::pa::me] Log message


Contexts

In Log4j, there are two concepts used for adding in lightweight, free-form, information that can be included in a logged message: Nested, Mapped and Global Diagnostic Contexts (NDC, MDC and GDC). These are contextual pieces of information, available to the logging pattern methods, allowing extra information to be included for dynamic and larger concepts being expressed in the algorithm and libraries you create.

Nested Diagnostic Contexts (NDC)
An example of contextual information can be thought of as separate threads dealing with independent clients accessing a network application, e.g.
  INFO - client:10.3.0.21 - index
  INFO - client:10.3.0.22 - index
  INFO - client:10.3.0.21 - login
  INFO - client:10.3.0.22 - login
  INFO - client:10.3.0.21 - exit
  INFO - client:10.3.0.22 - exit

Here's how you would do this, first, setup the pattern format of your logged output:

  p = PatternFormatter.new :pattern => "%l - %x - %m"
%x Being the substitution pattern for NDC.

And, in the application, a particular section of code that handles client interactions:

...
 NDC.push('client:' + clientip)
 log.info('index')
...
 log.info('login')
...
 log.info('exit')
...
 NDC.pop
This can greatly simplify the logging related statements in the code and ties sections together by function in a concise manner. Substitution for the %x is also Fast.

NDC's operate as a stack, you can push more information onto it and then pop that information as you enter and exit different parts of your algorithms:

...
 NDC.push('client:' + clientip)
 log.info('index')
...
 NDC.push('auth')
 log.info(name)
 NDC.pop
...
 log.info('exit')
Produces:

 INFO - client:10.3.0.21 - index
 INFO - client:10.3.0.21 auth - Colby
 INFO - client:10.3.0.21 - exit
In multi-threaded code, each thread maintains an entirely separate and distinct NDC stack.
Mapped Diagnostic Contexts (MDC)
MDC operates like NDC's, but instead of being a stack, these are a hash map of name to value pairings.
p = PatternFormatter.new :pattern => "%l - %X{:user} %X{:userip} - %m"
...
MDC.put(:user, "colbygk")
MDC.put(:userip, "10.3.0.21")
...
log.info('login')
...
log.info('exit')
...
Produces:

INFO - colbygk 10.3.0.21 - login
INFO - colbygk 10.3.0.21 - exit
In multi-threaded applications, MDC's copy the contents of the parent (top) thread at the time a new MDC is created in a separate thread. After that point, they are isolated to that thread.
Global Diagnostic Contexts (GDC)
A federation or library of classes can be shared amongst many applications. Log4r is an example of this, a library that may be reused by many applications, some distributed, some stand-alone.

You may want your particular application to identify itself globally, across all of your shared libraries. Here's how:

 p = PatternFormatter.new :pattern => "%l - %g - %m"
Thread1
 GDC.set("BadWolf")
 log.info('startup')
Thread2
 log.info('processing')
Logged output:
INFO - BadWolf - startup
INFO - BadWolf - processing
The GDC is set as part of the primary parent thread. If set in any thread, the global information is changed for all threads as they converge on the parent thread.


Integration with Chainsaw

Part of the Apache Log4j project is a GUI application for viewing Log4j messages called Chainsaw. Log4r can integrate with Chainsaw by using the Log4jXmlFormatter and UDPOutputter:
...
require 'log4r/formatter/log4jxmlformatter'
require 'log4r/outputter/udpoutputter'
...
mylog = Logger.new 'mylog'
log4jformat = Log4jXmlFormatter.new
udpout = UDPOutputter.new 'udp', "localhost", 8071
udpout.formatter = log4jformat
mylog.outputters = [udpout]
...
NDC.push "saw test"
MDC.put "clientip", "10.33.33.33"
...
mylog.debug "This is a message with level DEBUG"
mylog.info "This is a message with level INFO"
mylog.warn "This is a message with level WARN"
mylog.error "This is a message with level ERROR"
mylog.fatal "This is a message with level FATAL"
mylog.fatal get_exception( "This is an exception" )
...
And configure chainsaw with the following (also available as examples/chainsaw_settings.xml if you down load the tarball):
<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/" debug="true">
  <plugin name="log4r_test" class="org.apache.log4j.net.UDPReceiver">
    <param name="Port" value="8071" />
  </plugin>
</log4j:configuration>
After starting up chainsaw and issuing log messages like the above, you should see:
Note that both NDC and MDC's are properly passed on to chainsaw as well.


The Null Logger

In addition to being the parent of all loggers, Logger.root is a null object. That means that it does absolutely nothing when its log methods are invoked. Its query methods always return false and it has no outputters. It is useful to turn loggers off from within code:
noisylog = Logger.root
noisy.debug "This won't do anything"


Internal Log4r Messages

Log4r maintains an internal log that is available by creating a logger with the name 'log4r'. The internal logs can provide information about what Log4r itself is doing and can provide error information for some modules that can fail silently (with no where to send logging messages) such as EmailOutputter and UDPOutputter. An example for sending internal Log4r information to standard-out:
require 'log4r/staticlogger'
require 'log4r/outputter/consoleoutputters'

...
log4r = Logger.new 'log4r'
log4r.level = ALL
log4r.outputters = StdoutOutputter.new 'log4r'
...


Gotchas

If you are using Log4r, there are a few gotchas that you should be aware of:
  • Logger levels can be dynamically redefined, but the change won't be noticed by any children. That is, if you set root.level=OFF after defining some loggers, none of the loggers will change their level to OFF. There is a good reason for this behavior.
  • Dynamically redefining levels, tracing or additivity is expensive. It's best to set up all your loggers in a config script and avoid making dynamic changes to Log4r objects. The dynamism is most useful for debugging and development, where local control of logging is a great convenience.
  • When an IOOutputter's IO is closed, the IOOutputter changes its level to OFF


Performance

Profiling has revealed that log4r is typically an order of magnitude or two slower than log4j. However, this is still damn fast! In particular, if a logger is set to OFF, the overhead of checking to see if a log event should be logged nearly vanishes. This was accomplished by dynamically redefining the unloggable logging methods to do nothing.

In the future, Log4r's performance critical features will be written as a C extension to Ruby. It will still be optional, but it will be available for those who absolutely need to squeeze every last ounce of performance out of Log4r. (No longer in the works, unfortunately.)


The Project Itself

Log4r was initially developed by one person and is slowly but surely gaining popularity and new developers. Please refer to the contact page for more information on the developers.
$Id: manual.html 16 2010-03-12 03:50:18Z colby $