To illustrate, this is what I'm talking about as motivation to get order into log files.
I don't know about you, but looking at that is not my idea of a good time, especially if it happens to be 4:00AM. All I'm asking for is a little order in my chaos.
Formatting the message body
I'm not going to go into the detail surrounding Log4J message formatting. You can get that information from here.
What I am referring to is how to use the formatting instructions presented at the above link to help accomplish a more formatted message body.
*NOTE*
The example log-files presented below will not be properly formatted if you are using Internet Explorer. However, when using Firefox the formatting is presented properly. (You're missing out if you're using I.E.)
Limiting the message body to a certain length so as to maintain a degree of uniformity serves to help the ol' Mark-IV eyeball make sense out of the log entries. To illustrate, shown below is the log-file layout that tries to maintain a certain place for each logging element and where the message body is limited to say- - - 80-bytes.
.... ....1.... ....2.... ....3.... ....4.... ....5.... ....6.... ....7.... ....8
2007-08-24 13:39:06 [DEBUG] Implementation title : log4j at line [ 62] of class [Log4JTest.run()] [Logger:log4j.test.Log4JTest]
2007-08-24 13:39:06 [DEBUG] Implementation vendor : "Apache Software Foundation" at line [ 63] of class [Log4JTest.run()] [Logger:log4j.test.Log4JTest]
2007-08-24 13:39:06 [DEBUG] Implementation version : 1.2.14 at line [ 64] of class [Log4JTest.run()] [Logger:log4j.test.Log4JTest]
But what about when the message body is more than 80-bytes? That would hork-up the "pretty factor", huh? Now it was apparent that when a message body is more than 80 bytes, it should be wrapped to the next line, BUT, maintain the same information about where the logging event (line number, mainly) took place AND the developer should not have to deal with that issue. All the developer should do is what they were used to doing in the first place... mainly this:
log.info(theReallyLongMessage);
The whole solution
Extend the ConsoleAppender class in log4j. The idea being pursued here is to intercept the message, testing the message body length and if greater than 80-bytes, breaking up the message body into 80-byte segments and reconstituting the message segment into a new LoggingEvent object. Simple, really.
/*
* History of modification
*
* History of modification
*
* Date Project By Description
* -------- ----------- ----------- -----------------------------------------------
*
*
*/
package com.log4j.extensions;
/**
* This class provides the means for wrapping an arbitrary logging event-line, so
* that the body of the message - this is, "%m" - is wrapped to the next line(s).
*
* Keep in mind we aren't interested in formatting or altering the pattern layout
* as the logging event has already been formatted. The only aspect this class
* deals with is the actual length of the message; if it's greater than 80 bytes,
* the message will be broken up into 80-byte segments and sent to the ConsoleAppender.
*
*
*
*/
import java.util.ArrayList;
import org.apache.log4j.ConsoleAppender;
import org.apache.log4j.Layout;
import org.apache.log4j.Level;
import org.apache.log4j.Logger;
import org.apache.log4j.spi.LoggingEvent;
public class FoldingConsoleAppender extends ConsoleAppender {
private final static int LINE_LIMIT = 80;
private final static String HEADER = "THE FOLLOWING LINES WERE SPLIT INTO " +
LINE_LIMIT + " BYTE SEGMENTS TO FIT INTO THIS SPACE.";
private final static String FOOTER = "FOLDING COMPLETED";
private final static String NULL_MESSAGE = "The initial message value of null has been replaced with this message.";
/**
*
* Overrides the parent class method 'subAppend()' so that the Logging event can
* be intercepted to inspect the lenght of the message (%m).
*
*/
protected void subAppend(LoggingEvent event) {
//Take the logging event and inspect the message. If greater than 80-bytes
//create a CustomLoggingEvent with the 80-byte portion and send to the
//parent class subAppend() method. Repeat for the succeeding lines required
//to complete the process.
if ((String)event.getMessage() == null) {
String catClass = event.fqnOfCategoryClass;
Logger logger = Logger.getLogger(event.getLoggerName());
long ts = event.timeStamp;
Level level = event.getLevel();
Object message = NULL_MESSAGE;
LoggingEvent cle = new LoggingEvent(catClass, logger, ts, level, message, null);
super.subAppend(cle);
return;
}
if (((String)event.getMessage()).length() > LINE_LIMIT) {
Object m = event.getMessage();
String line = (String) event.getMessage();
if (line.length() > LINE_LIMIT) {
//Call foldLine to break up the message into 80-byte segments which
//have been placed into the array list.
ArrayList al = this.foldLine(line, LINE_LIMIT);
//For every 80-byte segment in the ArrayList, create a CustomLoggingEvent
//object using information from the original LoggingEvent but put the
//80-byte line into the new CustomLoggingEvent
for (int i = 0; i < al.size(); i++) {
Object o = al.get(i);
String catClass = event.fqnOfCategoryClass;
Logger logger = Logger.getLogger(event.getLoggerName());
long ts = event.timeStamp;
Level level = event.getLevel();
Object message = al.get(i);
LoggingEvent cle = new LoggingEvent(catClass, logger, ts, level, message, null);
super.subAppend(cle);
}
}
} else {
//Prints any log entry <= LINE_LIMIT bytes in length
super.subAppend(event);
}
}
/**
*
* Take the message body (%m) and divide it into 80-byte line-segments placing
* each segment (with preseding and ending note) into an ArrayList to be returned.
*
* @param line
* @param maxLen
* @return
*/
public ArrayList foldLine(String line, int maxLen) {
String foldedLine = null;
StringBuffer sb = new StringBuffer();
ArrayList al = new ArrayList();
int index = 0;
int lineLength = line.length();
int endIndex = index + maxLen;
al.add(HEADER);
while (index < lineLength) {
al.add(line.substring(index, endIndex));
index = index + maxLen;
endIndex = index + maxLen;
if (endIndex > lineLength) {
endIndex = lineLength;
}
}
al.add(FOOTER);
foldedLine = sb.toString();
return al;
}
}
Now that the class is created, place it into any package of your project. Next, modify your log4j.xml segment that describes the use of the ConsoleAppender as shown below.
Now, whenever the developer logs a message longer than 80-bytes:
//This demonstrates the idea of "folding" a line to ensure it fits inside the
//message space defined in the layout ( %-80m ) of the appender
String line = ".... ....1.... ....2.... ....3.... ....4.... ....5.... ....6.... ....7.... ....8.... ....9.... ....0";
log.info(line);
Instead of this message formatting .... (some messages appear before and after)
2007-08-24 10:26:19 [ERROR] 3. ERROR error message at line [ 39] of class [ArbitraryAppenderReference.log()] [Logger:Example_Logger]
2007-08-24 10:26:19 [FATAL] 4. FATAL error message at line [ 40] of class [ArbitraryAppenderReference.log()] [Logger:Example_Logger]
2007-08-24 10:26:19 [INFO ] .... ....1.... ....2.... ....3.... ....4.... ....5.... ....6.... ....7.... ....8.... ....9.... ....0 at line [ 43] of class [ArbitraryAppenderReference.log()] [Logger:Example_Logger]
2007-08-24 10:28:56 [INFO ] This logging entry is attached to appender 'Example_Logger'. at line [ 21] of class [ArbitraryAppenderReference.log()] [Logger:Example_Logger]
2007-08-24 10:28:56 [INFO ] and originated from class ArbitraryAppenderReference at line [ 22] of class [ArbitraryAppenderReference.log()] [Logger:Example_Logger]
... the message is formatted like this.
2007-08-24 10:26:19 [ERROR] 3. ERROR error message at line [ 39] of class [ArbitraryAppenderReference.log()] [Logger:Example_Logger]
2007-08-24 10:26:19 [FATAL] 4. FATAL error message at line [ 40] of class [ArbitraryAppenderReference.log()] [Logger:Example_Logger]
2007-08-24 13:39:06 [INFO ] THE FOLLOWING LINES WERE SPLIT INTO 80 BYTE SEGMENTS TO FIT INTO THIS SPACE. at line [ 33] of class [Log4JTest.run()] [Logger:log4j.test.Log4JTest]
2007-08-24 13:39:06 [INFO ] .... ....1.... ....2.... ....3.... ....4.... ....5.... ....6.... ....7.... ....8 at line [ 33] of class [Log4JTest.run()] [Logger:log4j.test.Log4JTest]
2007-08-24 13:39:06 [INFO ] .... ....9.... ....0 at line [ 33] of class [Log4JTest.run()] [Logger:log4j.test.Log4JTest]
2007-08-24 13:39:06 [INFO ] FOLDING COMPLETED at line [ 33] of class [Log4JTest.run()] [Logger:log4j.test.Log4JTest]
2007-08-24 10:28:56 [INFO ] This logging entry is attached to appender 'Example_Logger'. at line [ 21] of class [ArbitraryAppenderReference.log()] [Logger:Example_Logger]
2007-08-24 10:28:56 [INFO ] and originated from class ArbitraryAppenderReference at line [ 22] of class [ArbitraryAppenderReference.log()] [Logger:Example_Logger]
You can take the same FoldingConsoleAppender class above and use it as the basis to extend Log4J's FileAppender and DailyRollingFileAppender.
Thanks to Log4J's open source position !
