Thursday, October 30, 2008

Log4J tips.

An additonal log4j tip that I found today. %c is the class that is used to create the log4j class. It can be useful, if it is the actual class that is creating it. However, you probably do not need the entire class hierarchy. %c{1} will only show the classname itself without the heirarchy.

For example:
When you create your logger with
static Logger logger = Logger.getLogger(CustomerBusiness.class);

And CustomerBusiness is in package net.company.webservice.business
Then %c will write out
net.company.webservice.business.CustomerBusiness

%c{1} will write out CustomerBusiness

This may be considered small but the duplicated characters can add up to a lot.


The problem is even more pronounced if you have a separate log for a single purpose. We log all of our performance log information into a separate log file.
We do this by having a separate RollingFileAppender for performance logging and creating a 2nd Logger in the class with
private static Logger performancepaLogger=Logger.getLogger("net.comny.webservice.performancelogger");


As for the performance logger, I also think it's useful to format those in a standard way. That way slow operations can be tracked easily.

[DateTime] {ClassName}: {Function}: {Unique path} Call Time: {milliseconds}

One shortcoming of this is that in order to make the logging call itself faster you have to code each call to log.info to pass through the values that are in {}.

The bonus of {Unique path} which in most of my applications would be an account number, is that I could see calls that look something like this.
AccountDAO: saveAccount: 223 Call Time: 20
AccountDAO: saveEmail: 223 Call Time: 25
CallDAO: saveCallInfo: 223 Call Time: 120
AccountBusiness: saveAccount: 223 Call Time: 200
WebService: saveAccount: 223 Call Time: 500

I can look at that and even with other records mixed in, I can see at the DAO level which calls are higher and causing the webservice call for a single record to be high. If the same database level access class has high call times for all of the accounts then it will show where optimization needs to take place.

No comments: