This past week I ran into an interesting issue with Log4J. We had an appender in our log4j.xml file that used PatternLayout with the following pattern: "[%-5p] %d{DATE} %c {%F:%L} - %m%n". I was looking to reduce the amount of information being written to the log files as they are getting difficult to read. I was looking through the JavaDoc for the PatternLayout class when I noticed this warning:

WARNING Generating the caller class information is extremely slow. Thus, it’s use should be avoided unless execution speed is not an issue.

The warning is associated with the %C, %F, %L and %M format specifiers. These specifiers add the qualified class name, file name, line number and method name of the calling code to the output.

“Slow” is a relative term, but I figured it couldn’t hurt to go ahead and remove those specifiers from the conversion pattern. I ended up changing the pattern string to: "[%-5p] %d{ABSOLUTE} %c{1} - %m%n". When I restarted JBoss the startup time went from just over 1 minute to 40 seconds. I guess “extremely slow” is accurate. We haven’t performed any timing on the whole application to see what difference this made, but anecdotal evidence suggests that performance is slightly better.

As a parting thought, it may be inappropriate to use these format specifiers if the application doing the logging is a desktop app. If the application is obfuscated, as many desktop apps are likely to be, then the caller information will probably not make any sense. If the app is not obfuscated, you will be potentially exposing class, file and method names to end users. These format specifiers may make sense during development, but should probably be avoided when the application is released.

Tags: java, log4j, performance