Apache Jakarta and Beyond: A Java Programmeramp;#039;s Introduction [Electronic resources] نسخه متنی

11.2. Log4j

Log4j is a logging system originally developed by IBM and later turned over to the Jakarta project. It has a great deal of similarity to the Java Logging API, which is not surprising because Java Logging was greatly influenced by Log4j, although the APIs were simplified and streamlined. Consequently, the built-in API is somewhat simpler to use but also somewhat less powerful.

11.2.1. Using Log4j

At first glance, the log4j APIs closely resemble those for Java logging. Both use a class called Logger as their entry point, and loggers in log4j also have a hierarchical relationship. Both APIs also have Level classes, along with static instances used to indicate the levels of messages and set the level of loggers. The levels in log4j are called DEBUG, INFO, WARN, ERROR, and FATAL.

Loggers in log4j also have convenience methods named after the various log levels. Apart from some slight naming differences, the following log4j code


Logger logger1 = Logger.getLogger("com.awl.toolbook");
Logger logger2 =
Logger.getLogger("com.awl.toolbook.chapter11");
logger2.setLevel(Level.WARN);
logger1.debug("Hello");
logger1.log(Level.WARN,"something is amiss");
logger2.warn("Something is amiss");

exactly resembles the corresponding Java logging code.

Beyond this, the two APIs start to diverge. Log4j uses Appenders instead of Handlers and Layouts instead of Formats. Despite these name differences, programmatically configuring log4j is very similar to configuring Java logging, as shown in Listing 11.3

Listing 11.3. Programmatically configuring log4j

package com.awl.toolbook. chapter11;
import org.apache.log4j.*;
public class L4JManual {
public static void main(String argv[]) {
Logger theLogger =
Logger.getLogger(L4JManual.class.getName());
FileAppender appender = new FileAppender();
appender.setFile("manual.log");
Layout layout =
new PatternLayout("[%p] %d{HH:mm}   - %m\n");
appender.setLayout(layout);
appender.activateOptions();
theLogger.addAppender(appender);
theLogger.setLevel(Level.INFO);
theLogger.info("Hello");
}
}

The only elements that stand out in this example are the call to activateOptions() and the pattern used in the Layout.activateOptions() is used to turn on the appender. It is needed because there are typically many parameters that must be set to configure an appender, each of which must be done through a separate call. The appender has no way to know when the final parameter has been set, and any attempt to open the log repository before all parameters have been set may result in an error or the wrong action being taken.

The pattern provides many options to specify how log messages will be stored. See the documentation for PatternLayout for full details on the available options. These are some particularly useful options:

%p indicates the priority level of the message.
%m is the message provided in the code.
%d is the date and time. Following %d with braces and an inner pattern indicates how the date and time should be formatted, following the rules for the DateFormat class in java.text.
%l turns into information about the calling class, method, and line. The documentation for log4j indicates that obtaining this information can be extremely slow and so should be not be used except when speed is not an issue.

After running Listing 11.3, the "manual.log" file will contain


[INFO] 13:21 - Hello

Log4j supports filters similar to those used in the Java logging API, with some important differences. The first is that it is possible to associate multiple filters with an appender, and these filters will each be checked in order. Consequently, filters may return three values instead of a boolean. These values are DENY, meaning the log message will be discarded without consulting any other filters; ACCEPT, meaning the log message will be recorded without consulting the other filters; and NEUtrAL, meaning the rest of the filters will be consulted. If the last filter returns NEUtrAL, the message will be recorded.

11.2.2. Configuring Log4j

One of the biggest differences between log4j and Java logging is in the configuration files; log4j configuration files are much more flexible. The most immediate difference is that lines that specify a level for a logger may also specify the set of appenders to which that logger will send records. The following lines

log4j.rootLogger=WARN, appender1, appender2
log4j.logger.com.awl.toolbook=DEBUG, appender1

specify that the root logger and all its descendants should log at the WARN level and send their output to appenders called appender1 and appender2. The logger called com.awl.toolbook and all its descendants should log at the DEBUG level and send their output to appender1 only.

Each appender is defined on a separate set of lines:

log4j.appender.appender1=org.apache.log4j.FileAppender
log4j.appender.appender1.File=debug.log
log4j.appender.appender1.layout=org.apache.log4j.PatternLayout
log4j.appender.appender1.layout. ConversionPattern=[%p] %d{HH:mm:ss} - %m (%l)
log4j.appender.appender2=org.apache.log4j.ConsoleAppender
log4j.appender.appender2.layout=org.apache.log4j.PatternLayout
log4j.appender.appender2.layout. ConversionPattern=[%p] %d{HH:mm} - %m

The first set of lines specifies that appender1 should send output to the file called debug.log, using PatternLayout to do the formatting. Likewise, the second set of lines indicates that appender2 should send output to the console with a specified pattern.

Although the properties file format is a little easier to read for very simple log files, the preferred format for log4j is XML.^[1]The XML syntax groups attributes together in a cleaner way and clarifies the distinction between log levels and appenders. These attributes appear undifferentiated on one line in the property file. The XML equivalent of the above configuration would contain the following:

^[1] Indeed, the properties file format is deprecated and may be removed in a future release.

<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration
xmlns:log4j='http://jakarta.apache.org/log4j/'>
<appender name="appender1"
>
<param name="File" value="temp"/>
<layout>
<param name="ConversionPattern"
value="[%p] %d{HH:mm:ss } - %m (%l)"/>
</layout>
</appender>
<appender name="appender2"
>
<layout>
<param name="ConversionPattern"
value="[%p] %d{HH:mm} - %m"/>
</layout>
</appender>
<category name="com.awl.toolbook">
<priority value="warn"/>
<appender-ref ref="appender1"/>
</category>
<root>
<priority value ="debug"/>
<appender-ref ref="appender1"/>
<appender-ref ref="appender2"/>
</root>
</log4j:configuration>

The term "category" in this file really means "logger." This is a holdover froman early version of the API.

Another advantage to the XML format is that it allows the definition of filters, which cannot be done through a property file. For example, the StringMatchFilter examines log messages and can either DENY or ACCEPT, based on whether the string is found. To allow only messages about new users to be logged, the following configuration would be used:


<appender name="appender2"
>
<layout>
<param name="ConversionPattern"
value="[%p] %d{HH:mm} - %m\n"/>
</layout>
<filter>
<param name="StringToMatch" value="new user"/>
<param name="AcceptOnMatch" value="true"/>
</filter>
</appender>

Log4j obtains its configuration file differently than Java logging. Log4j will search the CLASSPATH for a files called log4j.properties and log4j.xml and will use the first one it finds. This means that no information needs to be provided explicitly on the command line, and hence configuration files can be shipped as part of a Web application without requiring any special treatment when the application is installed.

11.2.3. The Log4j Appenders

Log4j comes with a rich set of appenders beyond the basic ConsoleAppender and FileAppender already encountered. The set discussed following is not exhaustive but does represent the variety of available options.

RollingFileAppender

This is an extension of the FileAppender that

rolls the logs. Rolling consists of maintaining a set of log files, with names like "log.1" through "log.4." When a certain criteria has been met, such as size of the file reaching a specified maximum, "log.3" would be renamed to "log.4"; "log.2" would be renamed to "log.3"; and so on. "log.4" would be discarded, and a new current log file would be started.

The extra attributes needed to configure a RollingFileAppender are the number of backup log files to maintain, and the size a file should reach before being rolled. These may be specified in either the property-based or XML-based configuration filefor example,

<appender name="appender1"
>
<param name="File" value="log"/>
<param name="maxBackupIndex" value="4"/>
<param name="maxFileSize" value="10KB"/>
<layout>
<param name="ConversionPattern"
value="[%p] %d{HH:mm:ss} - %m (%l)\n"/>
</layout>
</appender>

Note that the file size is specified as the combination of a numberin this case, 10and a unitin this case, kilobytes. This means that the log will be rolled when the file exceeds 10240 bytes in length. A similar property, maximumFileSize, can be used with a number in bytes.

DailyRollingFileAppender

This is a variation of the RollingFileAppender that rolls files based on time instead of file size. Therefore, in the configuration a parameter indicating the times at which logs should be rolled must be provided. This parameter is called datePattern.

The syntax used to specify times comes from the SimpleDateFormat class. Conceptually, this is used by continuously formatting the current time, using the specified pattern. If the resulting string is different than the last time this was done, then the log is rolled. So the pattern "YYYY" would result in the logs being rolled once a year at midnight on January 1. "YYYY-MM" would result in the logs being rolled at midnight on the first of each month. "YYYY-MM-dd" would cause the logs to roll once a day, and so on.

The pattern is also used to name the rolled files. Using the pattern, "YYYY-MM-dd" would result in files with names like "log.2003-01-01," "log.2003-01-02," and so on. Note that this means there is no limit to the number of log files that will be maintained.

Although a pattern like "YYYY/MM" would roll on the same schedule as "YYYYMM," the slash in the former pattern would be interpreted as a directory when the log is rolled. This may or may not be what is desired, but it does mean that some care must be taken when choosing patterns.

SocketAppender

This appender sends log records to a socket in a binary format that is not meant to be human-readable. The other end of the socket is supposed to be server running a SocketNode, a class that receives log records and handles them according to the configuration on the

server end. That means that one client could send records to many servers, and each server could log a different subset of events or format them differently. This provides a mechanism for an application to report on its status and activities to several different people at once, while avoiding the need for all of those people to have access to any particular set of files.

For example, the marketing department might have a log server that filters out everything except reports on how the system is being used. The administrators might have another server that reports any SEVERE messages about system problems. The developers might have yet another server that captures debugging information.

The appender on the client side needs the name of a server and the port to which to connect.

<appender name="appender1"
>
<param name="remoteHost" value="log_host"/>
<param name="port" value="8099"/>
</appender>

Note that no format is provided because all formatting is done on the server. Note also that only a single host and port are specified. If logging information should be sent to many servers, each will need its own appender.

There is nothing special about configuration on the server side, and any set of appenders can be used. The logger that is invoked on the server side will be the one with the same name as that which wrote to the SocketAppender on the client. That is, if the logger writing to appender1 in the preceding example were named foo.bar, then the server would also look for a logger called foo.bar. As always, if there is no such logger on the server, it will use the properties associated with foo if any are specified and the root logger otherwise.

It is quite easy to create a basic log server because the SocketNode does most of the work. All the application code needs to do is set up the basic server functionality. A very basic server is shown in Listing 11.4.

Listing 11.4. A simple log server

package com.awl.toolbook.chapter11;
import java.net.Socket;
import java.net.ServerSocket;
import org.apache.log4j.*;
import org.apache.log4j.net.*;
import org.apache.log4j.spi.LoggerRepository;
public class LogServer {
public static void main(String argv[])
throws Exception
{
int port = Integer.parseInt(argv[0]);
ServerSocket serverSocket = new ServerSocket(port);
LoggerRepository theRepository =
LogManager.getLoggerRepository();
while(true) {
Socket socket = serverSocket.accept();
SocketNode handler =
new SocketNode(socket,theRepository);
Thread t = new Thread(handler);
t.start();
}
}
}

As usual, all the configuration on the server side will happen through the log4j.properties or log4j.xml files.

The SocketAppender only supports TCP (Transmission Control Protocol) sockets, which ensures that if the server is running, all packets will eventually reach it. Developers needing or desiring UDP (User Datagram Protocol) sockets need to write their own implementation.

TelnetAppender

This appender provides some of the same functionality as the SocketAppender but works in almost the exact opposite way. Whereas the SocketAppender acts as a client and reports log records to a remote server, the TelnetAppender acts as a server to which clients can connect to see log messages. Records are sent to clients in a format that is specified by a Layout. The protocol is simple, which means the standard telnet program can be used to connect, but it also means that each client cannot do its own filtering and will display all the records that the server chooses to send.

The only parameter needed is the port on which to listen for clients. With the following connection in place

<appender name="appender1"
>
<param name="port" value="8099"/>
<layout>
<param name="ConversionPattern"
value="[%p] %d{HH:mm:ss} - %m (%l)\n"/>
</layout>
</appender>

a client could view log events with

telnet localhost 8099

The TelnetAppender places no restrictions on who may connect or how many connections may be present. Both of these represent potential security concerns. Typically, this appender would only be used during development in environments where the file system and standard output are not readily available. If the TelnetAppender is to be used in production, then at the very least any application using this appender should be behind a firewall so that random users on the Internet cannot peek in on internal log messages. However, even allowing everyone in a company or department to see log information may be too insecure. If this is the case, it would be possible to extend TelnetAppender to require some sort of authentication. Because log messages are transmitted in plain text, there is also some danger that a third party may eavesdrop on log reports. This could be corrected by extending TelnetAppender to use SSL (Secure Sockets Layer), although doing so is well beyond the scope of this book.

SMTPAppender

This appender sends a formatted e-mail to a specified recipient. This is particularly useful for ERROR and FATAL message, even more so when combined with a service that forwards e-mail to a pager.

The configuration needed for this appender includes an address from which e-mail will be sent, the address to which e-mail will be sent, and the name of a computer with an SMTP (Simple Mail Transfer Protocol) server. This is typically the same computer that is used as the "outgoing mail server" in a mail client such as outlook. For example, using this configuration

<appender name="appender1"
>
<param name="SMTPHost" value="localhost"/>
<param name="from" value="logger@awl.com"/>
<param name="to" value="developer@awl.com"/>
<param name="subject" value="Log message from log4j"/>
<layout>
<param name="ConversionPattern"
value="[%p] %d{HH:mm:ss} - %m (%l)\n"/>
</layout>
</appender>

and the following code

Logger l = Logger.getLogger("com.awl.toolbook.sample");
l.debug("This is a debug message");
l.error("Yikes, this is an error message!!");

will result in the following e-mail being sent:

From: logger@awl.com
To: developer@awl.com
Subject: Log message from log4j
Date: Sat, 16 Aug 2003 17:54:16 -0400 (EDT)
[DEBUG] 17:54:15 - This is a debug message
(com.awl.toolbook.chapter11.L4JExample.main
(L4JExample. java:11))
[ERROR] 17:54:15 - Yikes, this is an error message!!
(com.awl.toolbook.chapter11.L4JExample.main
(L4JExample. java:12))

Notice that this one e-mail contains both messages. By default the SMTPAppender will buffer log messages until a ERROR or FATAL message is logged, at which point all buffered messages will be sent. An additional parameter called bufferSize can be used to control how many log records are kept in the buffer and hence sent with the e-mail. Typically, it is useful to see a few of the messages leading up to an error to help diagnose the problem.

The SMTPAppender requires the Java Mail API and the JavaBeans Activation Framework. Both are available from http://java.sun.com/products/javamail/.

NTEventLogAppender

This appender is used to log events to the system log on Windows NT-based systems. This cannot be done in pure Java and requires the use of native code, but log4j provides this in the form of NTEventLogAppender.dll. This dll must be placed in a directory that is somewhere in the PATH.

SyslogAppender

This appender is used to send log records to a Unix system logging daemon. The parameters needed are the host where the daemon is running and the "facility" to log to. See Unix manual for syslog, syslogd, and syslog.conf for more information on Unix logging.

Unlike system logging on NT, system logging on Unix requires no special native library. This is because Unix logging is based on standard sockets.

JDBCAppender

As the name implies, this appender can be used to write log records to a database. The parameters are the usual those for database activity: the name of the driver class, database URL, username, and password. In addition, a pattern is used to generate the SQL that will be executed. The syntax of this attribute is the same as that used for the PatternLayout. A typical log table might be defined as follows:

create table log (
level char(5),
timestamp datetime,
message   varchar(100)
)

With this log table, the configuration would be

<appender name="appender1"
>
<param name="user"      value="sa"/>
<param name="password"  value="/>
<param name="driver"    value="org.hsqldb.jdbcDriver"/>
<param name="URL" value="jdbc:hsqldb:jspbook:toolbook"/>
<param name="sql"
value="insert into log
values('%p', '%d{YYYY-MM-dd HH:mm}', '%m')"/>
</appender>

Note the use of single quotes in the expression and the use of the date pattern to render the timestamp in the standard SQL datetime format. Also note that if the message contains a single quote, the resulting SQL expression will be invalid.

Finally, the documentation for log4j states that the current incarnation of the JDBCAppender may change radically in the near future. It is expected that equivalent functionality will be provided, although the configuration may need to change.

AsyncAppender

The AsyncAppender is unlike all the other appenders seen so far in that it does not itself write log information to any destination. Instead, the AsyncAppender wraps another appender in a separate thread so all logging is handled asynchronously. This can be useful in conjunction with any of the appenders that may take some time to perform their actions, such as the JDBCAppender and the SMTPAppender.

The only parameter to the AsyncAppender is a reference to the name of another appender:

<appender name="appender2"
>
<appender-ref ref="appender1"/>
</appender>

Any logger may write to either appender1 or appender2; the latter will work asynchronously.

Note that the AsyncAppender can only be configured through XML-style configuration files because there is no notion of an appender-ref in the property files.

11.2.4. Extending Log4j

Log4j comes with a very complete set of appenders, as can be seen from the previous section. In the very rare instance where none of the provided appenders meets a particular need, it is easy enough to create new appenders. Most of the hard work is encapsulated in a class called AppenderSkeleton. All that a developer needs to do is provide implementations for a few abstract methods.

To illustrate how this is done, Listing 11.5 shows an appender that sends formatted log messages to an external program. This could be used to invoke an existing application that pops up an alert window on an administrators screen such as "net send" on Windows or "xmessage" under Unix.

This appender will need two parameters. The first is the program name that must be fully qualified if the program is not in the PATH. The second is a flag indicating whether the program should be started once for each log message or if it should be started once and then fed each log message as it comes in .

Listing 11.5. An appender that sends log messages to a program

package com.awl.toolbook.chapter11;
import java.io.InputStream;
import java.io.OutputStream;
import org.apache.log4j.*;
import org.apache.log4j.spi.LoggingEvent;
public class ExecAppender extends AppenderSkeleton {
public ExecAppender() {}
private String programName = null;
public String getProgramName() {return programName;}
public void setProgramName(String programName) {
this.programName = programName;
}
private boolean openEachTime = false;
public boolean getOpenEachTime() {return openEachTime; }
public void setOpenEachTime(boolean openEachTime) {
this.openEachTime = openEachTime;
}
private Process process;
private InputStream instream;
private OutputStream outstream;
public void activateOptions() {
if(programName == null) {
errorHandler.error(
"No program specified for appender named [" +
name + "].");
return;
}
if(!openEachTime) {
openProgram();
}
}
public void append(LoggingEvent event) {
event.getThreadName();
event.getNDC();
event.getLocationInformation();
if(openEachTime) {
openProgram();
}
String formatted = layout.format(event);
try {
outstream.write(formatted.getBytes());
outstream.flush();
} catch (Exception e) {
errorHandler.error(
"Unable to write log event to "  +
programName + ":  " + e);
}
int count;
try {
while((count = instream.available())   > 0) {
byte data[] = new byte[count];
instream.read(data);
}
} catch (Exception e) {
errorHandler.error(
"Unable to consume input from"  +
programName + ":  " + e);
}
if(openEachTime) {
closeProgram();
}
}
public boolean requiresLayout() {
return true;
}
public void close() {
if(!openEachTime) {
closeProgram();
}
}
private void openProgram() {
try {
Runtime r = Runtime.getRuntime();
process   = r.exec(programName);
instream = process.getInputStream();
outstream = process.getOutputStream();
} catch (Throwable t) {
errorHandler.error("Unable to exec "   +
programName +
": "   + t);
}
}
private void closeProgram() {
try {
instream.close();
outstream.close();
process.destroy();
} catch (Exception e) {
}
}
}

The program starts with an empty constructor, which is needed by the log4j configurator. Then there are two beanlike properties for the programName and the openEachTime flag. No special code is needed for these properties to be set from standard configuration files; this is handled by introspection in the configurator.

The activateOptions() method does not have to be provided because there is a do-nothing implementation in the base class. activateOptions() is a useful place to ensure that attributes are set up properly, as is done here. Note the use of the errorHandler, which is essentially a special instance of a logger. This can be used to report errors from within the logging system itself, avoiding the kind of potential infinite loop that was encountered when writing a handler for Java logging.

The real action happens in append(), which is an abstract method that must be provided. This method starts by calling methods in the event that fill it in with auxiliary values that may or may not be needed. Then the program is opened if necessary. Next the event is formatted using a layout that is defined in the base class, and the formatted string is sent to the program. Anything printed by the program is read in and discarded. This has nothing to do with logging per se, but failure to do this might cause the program to block.

The requiresLayout() method is used by the configurator to determine whether a layout object must be provided. Here, true is returned, so if no layout is provided in the configuration file, an error will occur when log4j first starts up.

close() is another abstract method that must be implemented. It is used to clean up any resources allocated by the appender, which in this case means closing the program if it is still open.

The code ends with methods that invoke and shut down the program.
Configuring this appender is done just like any other appender seen so far:


<appender name="appender1"
>
<param name="programName"    value="alert.sh"/>
<param name="openEachTime"   value="true"/>
<layout>
<param name="ConversionPattern"
value="[%p] %d{HH:mm:ss} - %m (%l)\n"/>
</layout>
</appender>

One thing that must be pointed out is that ExecAppender sends log messages to the external program through the program's input. Some programs need to take their arguments on the command line. While it would be easy enough in principal to modify ExecAppender to handle these cases, another option is to use a wrapper script. For example "alert.sh" used in the preceding example invokes xmessage as follows:

#!/bin/sh
read message
xmessage $message &

A similar short VB script program could be used to invoke net send on Windows.