Java Workshop
 

Performing Logging

Jargon

Component
A piece of software with a clear function that can be isolated and replaced by another component with equivalent functionality.
Configuration
The way that a program or computer is set up, various settings are used in the configuration.
Debugging
The process of locating errors in source code whether logical or syntactic and fixing them often through the use of a debugger.
Fatal Error
An error that causes a program to stop executing. See Error and Application Failure.
File
A block of information in the form of bytes, stored together on a computer or external digital storage medium, and given a name. A file may be a program, a document, a database, or some other collection of bytes.
Framework
A Skeletal software component that performs functions required by a system and which is incorporated into the design of such systems.
Logger
A component with sole responsibility of handling the logging operations in a logging framework.
Logging
The process of storing information about events that occurred in an application, used for debugging purposes.
Message
Any information sent as a component interacts with another.
Output
Information that has been manipulated by the central processing unit (CPU) of the computer, and displayed either on the video monitor or rendered on paper or film as hard copy, or saved on disk in a digital format.

Introduction

Logging is a useful technique for debugging medium to large scale applications. It is also useful when traditional debuggers are ineffective.

Typically most novice programmers simply use System.out.println to check that a program reaches a section of code or to print out the value of a variable. This is fine for a small application or a snippet of code, but is not the preferred way for medium and large scale applications, or for professional commercial applications.

A logging framework is used to replace all the System.out.println statements and to send the output to a different target, instead of the console, we can print that information to a file or any other destination imaginable.

You can get Log4J @ logging.apache.org

What Is Logging?

Logging As Debugging

Logging is a technique that is used to assist in the debugging process and may be the only way to perform debugging in cases where debuggers are not available or useful such as distributed applications. Logging equips the developer with a detailed context for application failures and should not be confused with testing. Testing provides quality assurance and confidence in the application, logging and testing are complimentary.

Many people may argue that log statements pollute source code, decrease the legibility of the code and increase its size. Another argument against logging is the fact that it impacts performance of the application. This means that the speed of a logging framework is particularly important.

Using Log4J, it is possible to enable or disable logging at run-time without having to recompile the application binary, the framework is designed so that the log statements can remain in the code without incurring a heavy performance cost.

How Does Logging Work?

The application developer decides to generate a message that needs to be logged whenever something important in the application occurs, for example: the click of a button. The developer then decides where this message should go, its target, typically a file, and the developer may control the message's format.

An important aspect is the ability to assign different priority levels to the message and further to only log messages with a certain priority level. This affords the developer a large amount of control over how logging gets performed, for example, messages of a certain priority can be logged to a file and other messages with a different priority to another target.

The basic idea is that a Logger is responsible for actually performing the logging in an application by handling the log operations, the Appender is responsible for appending the message to its target and controlling that output, and the Layout is responsible for formatting the logging message.

Five Core Components

Log4J makes use of five core components and in order to understand how Log4J works we need to understand how these components work and interact with one another.

These components are Levels, LoggingEvents, Layouts, Appenders and Loggers. We will look at how each of them works and how they cooperate to provide the core functionality of the logging framework.

Levels

Every event that is logged has an assigned priority level. Fatal errors would naturally be more severe than a simple warning and thus would have a higher priority level. In this regard, each level has an integer value assigned to it so that it can be compared to other levels.

There are five levels by default, namely (lowest priority to highest): DEBUG, INFO, WARN, ERROR and FATAL. Users can quite easily add more levels as they see fit. Using these levels it is possible to only log events of a certain priority level, say for example: error, which results in only that level and any level with a higher priority being logged. This means that all error and fatal messages will be logged, since fatal has a higher priority than error while all debug, info and warn messages will be ignored.

Two special priority levels exist, these are ALL and OFF, all is used to log all messages of any priority level, even user defined ones while off is used to ignore all messages regardless of their priority level. In essence, during debugging, all should be used while production code should use off.

Logging Events

Logging events represent the actual event that gets logged and an instance is created whenever the Log4J suite makes an affirmative decision to log something. Logging events contain vital information such as the time it was created, the message itself, any exception if an exception is raised and an associated priority level.

The LoggingEvent is passed around to the various Log4J components that use it and the information contained in the logging event is used to format and print the information to the desired target so that it can be analyzed at a later stage.

LoggingEvents are not usually used by application developers but rather only internally by Log4J.

Layouts

Layouts provide the functionality of formatting logging events into any number of appropriate formats. The layout takes the LoggingEvent and formats it appropriately into a string so that it can be written to the target by the Appender. Layout is abstract and subclassed by a number of concrete layout classes that provide an implementation of the format(LoggingEvent) method.

A layout may also provide a header and footer as is the case in an HTML layout where an HTML document usually contains a header and a footer. These are returned by the getHeader and getFooter methods respectively. The default implementation returns empty strings for these. A layout can also choose to ignore any exceptions that are contained in the LoggingEvent, this can be determined from the ignoresException method which returns true by default. Naturally any subclasses that handle exceptions will override this method to return false such as in the XML layout.

The layouts provided by the Log4J package are:

HTMLLayout

HTMLLayout prints out log events in an HTML table. It returns appropriate header and footers to complete the HTML document.

Example output:

<tr>
<td>0</td>
<td title="main thread">main</td>
<td title="Level"><font color="#339933">DEBUG</font></td>
<td title="root category">root</td>
<td title="Message">Debug Message</td>
</tr>
                    

PatternLayout

PatternLayout formats a logging event according to a conversion pattern that is similar to the conversion pattern of the sprintf function in C. The conversion pattern consists of literal text and conversion specifiers.

Each conversion specifier starts with a percent sign (%) and is followed by optional format modifiers and a conversion character. The conversion character specifies the type of data, e.g. category, priority, date, thread name. The format modifiers control such things as field width, padding, left and right justification. The following is a simple example: %d [%5p] %m%n

Example output:

12/20/2005 4:53:33 PM [DEBUG] Debug message
                    

SimpleLayout

SimpleLayout provides basic formatting, the output from this layout is the priority level of the log message followed by a dash (-) and the log message itself. It returns the default implementation for all other methods defined in the Layout class, thus empty header and footer strings and it ignores exceptions.

Example output:

DEBUG - Button Clicked

TTCLayout

TTCCLayout consists of the time, thread, priority level and diagnostic context information.

Example output:

262 [main] DEBUG org.apache.log4j.examples.SortAlgo.OUTER i=1 - Outer loop.
                    

XMLLayout

The output of the XMLLayout consists of a series of log4j:event elements as defined in the log4j.dtd. It does not output a complete well-formed XML file. The output is designed to be included as an external entity in a separate file to form a correct XML file.

Example output:

<log4j:event logger="root" 
   timestamp="1135964385140" 
   level="DEBUG" 
   thread="main">
<log4j:message>
   <![CDATA[Debug Message]]>
</log4j:message>
</log4j:event>
                    

Appenders

An Appender is responsible for "appending" a log message to a specific target. Each appender specifies its own Layout (the formatting it will use) as well as a threshold which determines the level priority that it will log. Some appenders inherently require a layout but others might not.

The two most commonly used appenders are ConsoleAppender and FileAppender. Typically you will simply create an Appender instance and then add it to the logger instance you are using. You can add multiple appenders to a logger instance so that it may send log messages to multiple targets.

Loggers

Loggers are named entities with their names being case sensistive. Loggers are part of a hierarchy following a simple rule: A logger may be an ancestor of another if its name followed by a period (.) is the prefix of the descendant logger. A logger is the ancestor of a descendant if there are no ancestors between it and the descendant logger. As an example consider the name: com.mycompany.myproject. "com" is a parent of com.mycompany and an ancestor of com.myproject.mycompany.

A root logger exists and obeys two fundamental rules: 1) it always exists and 2) it cannot be retrieved by name. In order to access the root logger you use the static method Logger.getRootLogger. All other loggers are retrieved by name using Logger.getLogger(name).

Loggers may be assigned a priority level, if a given logger is not assigned a priority level then it inherits from the closest ancestor with a priority level. A log request with a given assigned level say S in a logger with level T is enabled if and only if S is greater or equal to T: S>=T.

Writing Log Statements

Installing and Using Log4J

Log4J is distributed in archive format using either zip or gzip compression. Once you have downloaded the archive of your choice you should extract it to the location of your choice. This will result in a folder named logging-log4j-version.

You will find a jar file named log4j-version.jarin the dist/lib directory in the log4j directory. You need to copy this archive to your project's lib directory and update your classpath as appropriate.

Configuring Log4J

If you try to run the following code without configuring Log4J you will get an error.

Logger logger = Logger.getRootLogger();
logger.debug("Debug Message");
                

The error will read:

log4j:WARN No appenders could be found for logger (root).
log4j:WARN Please initialize the log4j system properly.
                

In order to prevent this you need to configure Log4J properly.

Hard Coded Configuration

You can perform a simple configuration on the root logger manually in the code of your application. Suppose you only wish to use the root logger using a simple layout and a file appender, your application's main method will be as follows:

Layout layout = new SimpleLayout();
FileAppender appender= new FileAppender(layout, "app.log");
Logger logger = Logger.getRootLogger();
logger.addAppender(appender);
                    

Basic Configuration

You can use the BasicConfigurator to do a basic configuration which logs to the ConsoleAppender using TTCCLayout.

BasicConfigurator.configure();
Logger logger = Logger.getRootLogger();
logger.debug("Debug Message");
                    

Output on the console will be:

0 [main] DEBUG root  - Debug Message
                    

Properties File Configuration

Log4J can be configured through a java properties file. The file has the same format as java properties, that is name=value pairs, one on a line. The file should ideally be named log4j.properties and on the classpath, but you can name it anything and then load it in your application.

Controlling Log4J's Internal Logging

Log4J's internal logging is controlled through the log4j.debug directive. Those who are interested to see what Log4J is doing can set this value to true. This results in a file named log4j.log. If you do not wish to have internal logging then set this value to false.

log4j.debug=false
                        
Configuring the Root Logger

The next thing to do is to set the root logger by specifying the priority level and an appender's name. The format is log4j.rootLogger=LEVEL, AppenderName. The LEVEL is any one of DEBUG, INFO, WARN, ERROR or FATAL and the AppenderName is any alpha-numeric string of no more than 255 characters. As an example, consider setting the root logger to debug and using a file appender:

log4j.rootLogger=DEBUG, fileAppender
                        
Configuring the Appender

The first step is to tell Log4J which appender you wish to use by giving the appender class's name.

log4j.appender.fileAppender=org.apache.log4j.FileAppender
                        

Some appender's require additional information, these are set using directives that match the appender's setter methods. The FileAppender class has a setFile method that can be used as follows:

log4j.appender.fileAppender.File=app.log
                        
Setting the Layout

Some appenders require a layout. This is easily set using the layout directive and specifying the layout class to use.

log4j.appender.fileAppender.layout=org.apache.log4j.SimpleLayout	
                        

As a complete example, consider the following configuration file:

log4j.rootLogger=DEBUG, consoleAppender
log4j.appender.consoleAppender=org.apache.log4j.ConsoleAppender
log4j.appender.consoleAppender.layout=org.apache.log4j.SimpleLayout

log4j.logger.test.app=ERROR, fileAppender
log4j.appender.fileAppender=org.apache.log4j.FileAppender
log4j.appender.fileAppender.File=app.log
log4j.appender.fileAppender.layout=org.apache.log4j.PatternLayout
log4j.appender.fileAppender.layout.ConversionPattern=%d [%-5p] %c - %m%n
                    
Loading the File in Your Application

To load the properties from your application you would simply place the properties file on the classpath and Log4J should find it. If it isn't in the classpath you can manually load it from your application.

You can simply pass the filename to the PropertyConfigurator's configure method.

PropertyConfigurator.configure("log4j.properties");
                        

Or you can simply create a java.util.Properties object and load the properties into that then pass the Properties instance to the PropertyConfigurator's configure method.

Properties props = new Properties();
props.load(new FileInputStream("log4j.properties"));
PropertyConfigurator.configure(props);
                        

Log Statements

Using the given properties file from the example above, we can write log statements to one of the two loggers, either the root logger or the application logger which is set to the ERROR level.

Logger rootLogger = Logger.getRootLogger();
rootLogger.debug("Debug message.");
		
Logger appLogger = Logger.getLogger("test.app");
appLogger.error("An error message.");
                

This results in the following output on the console:

DEBUG - Debug message.
ERROR - An error message.
                

and the following in the app.log file.

2006-01-02 10:11:20,000 [ERROR] test.app - An error message.
                

Summary

Log4J is a powerful and flexible logging framework for the Java platform. Logging is a technique that enables debugging and is especially useful in situations where traditional debuggers are ineffective like distributed systems.

Exercise Set

Multiple Choice

  1. Logging is a technique for debugging.

    1. True
    2. False
  2. Logging is useful when debuggers are ineffective such as distributed applications.

    1. True
    2. False
  3. Arguments against logging include:

    1. Log statements pollute source code
    2. Decreases the legibility of the code
    3. Increase the size of the code base
    4. Impacts performance of the application
    5. All the above
  4. The target of a logging message is

    1. The format of the message
    2. Its destination
    3. A file
  5. Which is not a default prioirty level?

    1. ALL
    2. DEBUG
    3. ERROR
    4. EXCEPTION
    5. WARN
  6. Which is not a core components

    1. Level
    2. LoggingEvent
    3. Layout
    4. WriterAppender
    5. Logger
  7. To install Log4J

    1. Extract the archive
    2. Include the jar file in your project's code base
    3. Update your classpath
    4. All the above
    5. None of the above
  8. Log4J is configured automatically.

    1. True
    2. False
  9. Log4J can be configured through

    1. Hard Coded Configuration
    2. Basic Configuration
    3. Properties File Configuration
    4. All the above
    5. None of the above
  10. To turn of log4j's internal loggin you would use

    1. log4j.debug=true
    2. log4j.debug=false

Exercises

  1. Read through the Log4J short manual to discover more wbou the different components in the Log4J framework.

Programming Exercises

  1. Complete the following:
    1. Add logging to one of your projects using the Log4J framework.