wiki:LOGGING
Last modified 11 years ago Last modified on 01/12/09 19:45:18

Error: Macro BackLinksMenu(None) failed
compressed data is corrupt

Logging

For logging we use the log4j library. log4j

Logging levels

log4j has several levels for logging. They allow users to sort information according to its significance. Levels can be used for easy management of the amount and verbosity of the output information. The library can be easily configured to show only messages not less than a given level. That's why it is important to identify well the level of the information you are about to log.

Currently there are six logging levels:

  • FATAL - It is used to notify of an error that surely leads to application aborting.
    public static void checkAssertions() {
    	Logger.getLogger(Main.class).fatal(
    			"Assertions are disabled."
    			+ "Please enable them with the -ea option.");
    	throw new Error("Assertions are disabled."
    			+ "Please enable them with the -ea option.");
    }
    
  • ERROR - It is used when an operation fails to complete and is likely to cause the application to abort, but it may still survive.
    try {
    	bi = ImageIO.read(in);
    } catch (IOException e) {
    	logger.error("Cannot load icon",e);
    }
    
  • WARN - Used when a potentially harmful situation has occurred. Like in:
     public final void removeListener(PropertyListener<T> listener) {
           if(!getListereners().contains(listener)) {
               logger().warn("Property.removeListener(): removing not registered!");
           }
           assert getListereners().contains(listener);
           getListereners().remove(listener);
     }
    
  • INFO - Used to give information of major steps of the application life cycle. Like in:
    public PageView(final Page page) {
    		getBean().init(model(), page);
    		
    		logger().info("PageView created");
    	}
    
  • DEBUG - Gives information about the step by step progress of the application. For example entering/leaving a method:
    private void badLocationSafeRun() {
    	logger().debug("Chain " + this + " starts flushing");
    	try {
    		underFlow();
    		overFlow();
    	} catch (final BadLocationException e) {
    		throw new RuntimeException(e);
    	}
    	logger().debug("Chain " + this + " has been flushed");
    }
    
  • TRACE - The most verbose of levels. Used to watch the progress of a method. Also for variable output during debugs
    private void overFlow() throws BadLocationException {
    	logger().debug("Overflowing starts");
    	while (baseOverflows()) {
    		Element cur = this.base
    				.getCharacterElement(getBaseLength() - 1);
    		int startOffset = cur.getStartOffset();
    		int endOffset = cur.getEndOffset();
    
    		logger().trace("Overflowing from " + startOffset + " to " + endOffset);
    
    		String text = getText(this.base, startOffset, endOffset)
    				.substring(getBaseLength() - startOffset - 1,
    						getBaseLength() - startOffset);
                    ...
    		logger().trace("Following text was overflowed - " + text);
    	}
    }
    

Logging in instance methods

It should be performed using a method that looks like:

modifier Logger logger(){
		return Logger.getLogger(this.getClass());
	}

It is advisable that all mutable base classes implement such a method (with "protected" modifier) so that their successors can easily access the proper Logger for their class.

Classes that have a logger method:

  • BaseProObject
  • Property
  • Change

Logging in class methods

The correct Logger is obtained like this

public class Logic {
...
       Logger logger = Logger.getLogger(Logic.class);
...
}

Depending on the intensity of logging, the logger may be stored in a local variable( low intensity) or a class variable( used in several static methods).

Configuring log4j in Sophie 2.0

Log4j configuration is stored in "log4j.properties" files. It is read at application startup. The location of the files is in the /src/main/resources folder of org.sophie2.author, org.sophie2.server and org.sophie2.core modules.

In order to change the lowest logged level edit the following line:

log4j.rootLogger=all, ConsoleLogging

and replace "all" with the desired level (choose on from - off, fatal, error, warn, info, debug, trace).

Destination and format of logged messages can be changed by configuring the appropriate Appenders in "log4j.properties".

Logging overhead

In general log4j has been optimized in speed, but do take note that logging adds some performance overhead.

  • Computing of the arguments of logger methods is done before checking whether this message will be logged at all.
  • Also choosing whether to log or not takes some time.
  • And do not forget that the actual formating and output of the messages is also time-consuming.

Comments

  • It would be good to say what the current logging level is and how to change the logging level for a specific module/package/class. --boyan@2009-01-12