Building Utimate Logging solutiong(from Itpub) - 达人(小新)

2004/10/22 | Building Utimate Logging solutiong(from Itpub)
类别(文档转载) | 评论(13) | 阅读(138) | 发表于 09:30: Building the Ultimate Logging Solution
...and solving common interoperability issues
May 5, 2004
Summary
Anyone who has dealt with complex enterprise applications knows the value of a good logging solution. Features such as consolidating log files, separating events, and turning debugging on or off all come free with a good logging API.
By Jerason Banes

Advertisement

Anyone who has dealt with complex enterprise applications knows the value of a good logging solution. Features such as consolidating log files, separating events, and turning debugging on or off all come free with a good logging API. As a result, developers have been converting their existing System.out logging to many of the advanced solutions that have appeared on the Java scene.

This article attempts to demonstrate how to convert your System.out logging to the new Java 1.4 logging APIs. Along the way, new concepts and algorithms will be introduced to solve common interoperability issues.

Using the 1.4 Logger API
The key to Java 1.4 logging is the java.util.logging.Logger class. Instances of this class get created on demand and may be statically referenced for the life of the application.

While many applications will only deal with a single Logger instance, it may make sense for some applications to have multiple loggers. An example of this is a job scheduling server that creates a separate log file for each task (see Figure 1). To split log messages between files, the server assigns a new Logger instance when the task is created. The result is a much cleaner separation of events - something that can be invaluable when tracing a problem.

To obtain a Logger instance, we need a unique name. Keep in mind that loggers exist for the life of the application, so it's very important to choose a unique name. Failure to do so can result in strange or unexpected behavior. Since class names must be unique, a common solution is to use the primary class name. Thus a Logger for the class com.example.MyServer might be obtained via the following code:

Logger logger = Logger.getLogger("com.example.MyServer");

Log Records Explained
Sending a message is a little different than printing to an OutputStream. Each logging message needs to contain the text of the message and the "error level" of the message. The "level" is used by the Logger to decide if the message should be discarded. This feature is often used to turn debugging information off in production environments.

To log a message, we need to create a new instance of the java.util.LogRecord class. This class encompasses all the necessary information about the message, including the text and the "level." Once created, the object can be passed to the Logger's log() method, which will either output the message or discard it.

The following example prints "This is an informational message." to the log:

LogRecord record = new LogRecord(Level.INFO, "This is an informational message.");
logger.log(record);

Levels of Logging
As previously mentioned, each LogRecord has a "level." While you might be tempted to think that this equates to the "type" of the message, it doesn't. In fact, individual logging levels cannot be turned on or off. A Logger instance can instead be configured to only print messages above a certain level. All messages below that level are ignored.

Logging levels are defined by the java.util.logging.Level class. This class wraps an integer that defines the current level. While you can create new instances of Level class, it's generally much easier to use one of the predefined levels.

The predefined levels (from highest to lowest) are as follows:

Level.SEVERE
Level.WARNING
Level.INFO
Level.CONFIG
Level.FINE
Level.FINER
Level.FINEST

FINE, FINER, and FINEST are usually for various levels of debugging information and would normally be turned off in a production environment. CONFIG is for printing information on the current server configuration; INFO is for informational messages such as those usually emitted via System.out; WARNING is for possible problems; and SEVERE is for outright program errors. Custom levels are usually higher than SEVERE.

The default is to log Level.INFO or higher. This can be changed by making a call to Logger.setLevel(), or by modifying the "lib/ logging.properties" file in the JRE directory. Look up java.util.logging. Log Manager in the Javadocs for more information on modifying the logging.properties file.

Here's an example of using the FINEST level to log debugging info:

Logger logger = Logger.getLogger("com.example.MyServer");
LogRecord record = new LogRecord(Level.FINEST, "value of 'myvar' is "+myvar);
logger.log(record);

Redirecting to a File
While the ability to control which text gets logged is a useful feature unto itself, no logging solution would be complete without a straightforward method for logging to a file. Java 1.4 logging is no exception.

After checking the logging level, the Logger class calls a subclass of java.util. logging.Handler. The Handler is responsible for writing the LogRecord to the console, a file, or even a network stream. For the purposes of this article, we'll be using the java.util.logging.FileHandler class to log to a file.

To use the FileHandler class, we need to create a new instance and call Logger- .setHandler(). The name of the log file can be specified by passing a string to the FileHandler constructor. Here is an example of logging to a file named "test.log":

Logger logger = Logger.getLogger("com.example.MyServer");
Handler handler = new FileHandler("test.log");
LogRecord record = new LogRecord(Level.FINEST, "value of 'myvar' is "+myvar);

logger.setHandler(handler);
logger.log(record);

Formatting for Nicer Output
If you tried the examples above, you probably noticed that the logging output isn't the cleanest. Sun built many of the default settings for the logger to be as situation independent as possible. While I'm sure that Sun had everyone's best interests in mind, most situations call for a more condensed format. The most common choice is a single-line format that allows for quick browsing and easy log analysis with common tools like "grep."

To demonstrate what I mean, here's the output from an earlier example:

Jan 26, 2004 12:04:34 AM JavaLoggerTest main
FINEST: value of 'myvar' is ABC123

Using this format, we end up with two lines in the log for every one line we output! In theory, there might be circumstances where we write multiple lines in a single logging message (such as Stack Traces). In practice, most of our log records will be no more than one line.

To correct this, we'll configure the logger so that each line of the log message is prefixed with the message info. Since my preferred format is [yyyy-MM-dd HH:mm:ss.S] <LEVEL>: <Message>, our example will use that as the format.

Formatting is handled by subclasses of the java.util.logging.Formatter class. By overriding the format(LogRecord) method, we can develop a custom look to our logs. Formatters are attached to Handlers so that the format can be customized based on the destination. See Listing 1 for our example format.

After adding in our new formatting class, we now have the following example code:

Logger logger = Logger.getLogger("com.example.MyServer");
Handler handler = new FileHandler("test.log");
Formatter formatter = new SingleLineFormatter();
LogRecord record = new LogRecord(Level.FINEST, "value of 'myvar' is "+myvar);

handler.setFormatter(formatter);
logger.setHandler(handler);
logger.log(record);

The output has now changed to look like the following:

[2004-01-29 20:36:53.705] FINEST: value of 'myvar' is ABC123

As you can see, the output is now much cleaner and easier to read. It also sets the stage for sending multiline output one line at a time. This will be important later when we attempt to redirect OutputStreams to our log.

Converting Old Code
Our examples so far have assumed that we're only logging a single message, and as a result have performed various steps that would be redundant in a real application. I'm going to show a more "normal" approach by demonstrating how to convert code that uses System.out and System.err into code that uses the logger.

The secret to adding proper logging to your application is configuring the Logger ahead of time. Once the configuration is out of the way, System.out statements can be easily replaced with similar one-line code statements. Let's take the lessons from above and add the proper setup code to a main() method:

public static void main(String[] args)
{
...
Logger logger = Logger.getLogger("com.example.MyServer");
Handler handler = new FileHandler("test.log");
Formatter formatter = new SingleLineFormatter();

handler.setFormatter(formatter);
logger.setHandler(handler);

...
}

An alternative is to modify the "lib/logging.properties" file. In fact, the logging.properties file is how most "real" applications commonly handle the setup of the Loggers. I won't cover the format of the file in this article, but it's well documented in the Javadocs for the LogManager class.

Now that we've configured our logger, we can convert some code. Here's a typical example of the type of code we'll be converting:

try
{
System.out.println("This is a debug statement.");
System.err.println("This is an error statement.");
}
catch(Exception e)
{
e.printStackTrace();
}

The first output statement is pretty easy to convert based on what we know:

Logger.getLogger("com.example.MyServer").log(new LogRecord(Level.FINEST, "This is a debug statement."));

The second output statement is more of the same, with the primary difference of a higher logging level:

Logger.getLogger("com.example.MyServer").log(new LogRecord(Level.SEVERE, "This is an error statement."));

The third and final output statement is far more interesting. Many programmers would be tempted to log the message of the exception but continue to send the stack trace to the standard error stream. Thankfully there's a better way.

The Sun developers recognized the need to log exceptions and thus added a special Logger.log() method. This method takes the standard LogRecord parameter, but adds a new parameter of type Throwable. Since all exceptions and errors extend the Throwable class, all exceptions can be logged with this method.

The final converted code looks like Listing 2.

What Are Thread Locals?
The MultiOutputStream class uses a new instance of java.lang.ThreadLocal to associate each OutputStream with a thread. But how does it work? The answer is hash tables. Consider the following code:

public class ThreadLocalHashtable extends Hashtable
{
public void set(Object value)
{
Thread thread = Thread.currentThread();

super.put(thread, value);
}

public Object get()
{
Thread thread = Thread.currentThread();

return super.get(thread);
}
}

Notice how the "set" method is passed a value Object, but no key Object? That's because the the Thread.currentThread() method is used to find the current thread. That Thread object is then used as a key to the hash table. This allows a thread to store an object that cannot be changed or accessed by any other thread.

Tip: InheritableThreadLocal
ThreadLocal has a subclass called InheritableThreadLocal. This subclass enables a child thread to inherit a local from its parent thread. When dealing with pluggable code like servlets, it's often desirable to assign the Logger to any child threads created by pluggable code. Without this precaution, a System-.out call may result in a NullPointerException.

Dealing with Libraries
Now that we've converted all of our code to using a logger, we're still left with the difficulty of code that isn't owned by our project, i.e., Libraries.

In a perfect world, there would be an easy way to make all libraries use our logger. There are a few things we can do, though. In the following sections I'll cover a way to interface System.out and System.err with our logger.

Redirecting the Standard Output Streams
To accomplish our goal, we'll need a custom OutputStream that creates a new LogRecord object every time a line break is received. We can then wrap the OutputStream in a PrintWriter object, and call System.setOut() and System. setErr() to replace the standard output streams.

While you may feel free to write your own solution, I think you'll find that the class in Listing 3 will meet your needs quite nicely. Despite its size, the class is actually rather robust and will work for replacing both System.out and Systemerr. This class only needs to be installed once at the beginning of your program.

The code below demonstrates its usage. You'll note that I've assigned System.out to the Level.INFO level and System.err to the Level.SEVERE level. This allows the two streams to be easily distinguishable in the log file.

public static void main(String[] args)
{
...

System.setOut(new PrintWriter(new LoggerOutputStream("com.example.MyServer")));
System.setErr(new PrintWriter(new LoggerOutputStream("com.example.MyServer",
Level.SEVERE)));

...
}

Assigning Multiple Loggers to the Standard Streams
Now that we've solved the problem of integrating the standard output streams with our logger, we've managed to create a new problem. For most applications, a single logger is sufficient. However, comprehensive servers (such as a Web application server) are usually configured with a separate logger for each application the server deploys. Our solution above would require you to choose a single log file for the standard streams, and stick with it.

One way of solving this is to use a ThreadLocal object. By associating a thread to its Logger, we can effectively create a lookup table of the output streams to be used.

Let's take our previous example of a job scheduling server. If we assume that each task is run inside its own thread, we can assign a LoggerOutputStream to the task when it's created. Obviously, this solution wouldn't work if we decided not to use multithreading, but it should be workable under most circumstances.

While not a perfect solution, it solves 90% of the cases where we use multiple loggers. See Listing 4 for code that demonstrates this concept. (Listings 4 and 5 can be downloaded from www.sys-con.com/java/sourcec.cfm.)

Listing 5 shows how our fictional job scheduling server might use the MultiOutputStream class to associate Loggers with tasks. It's important that the code to associate the OutputStream happens as soon as the Thread is created. If you wait, you may run the risk of a NullPointerException.

Final Thoughts
While this article has (hopefully) served as a good introduction to logging, it is in no way comprehensive. Many extremely useful features have been either omitted or glossed over for the sake of simplicity. To obtain more information on these features, I would highly recommend that you read the Javadocs or pick up a good book on logging.; 0

http://bluelover.5d.cn/

评论Comments