logging-log4j-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Curt Arnold <carn...@apache.org>
Subject Formatting benchmarking tests in sandbox
Date Fri, 13 Jan 2006 23:57:03 GMT
I've just committed some formatting benchmark tests to the sandbox.   
These test attempt to measure the cost of format evaluation when  
logging is enabled.  The tests set up a FileAppender, then write  
"Hello, World" 50000 times where "World" was a pattern substitution.

The test names, key statements and ratio to benchmark (lower is  
better) are:

	public void testMessageBaseline() {
			logger.debug("Hello, World");


	public void testMessageFormatArray() {
			logger.debug(java.text.MessageFormat.format("Hello, {0}", vals));
                         Win32 JDK 1.5=1.3, Win JDK 1.4.2=1.4, Mac  
JDK 1.4.2=1.5

	public void testSLF4JFormatter() {
			logger.debug(org.slf4j.impl.MessageFormatter.format("Hello, {}",  
"World"));
                         Win32 JDK 1.5=1.0, Win JDK 1.4.2=1.0, Mac  
JDK 1.4.2=1.2

	public void testSLF4JFormatterArray() {
			logger.debug(org.slf4j.impl.MessageFormatter.format("Hello, {}",  
vals));
                         Win32 JDK 1.5=1.25, Win JDK 1.4.2=1.24, Mac  
JDK 1.4.2=1.27

	public void testSLF4JFormatterArrayCreation() {
			logger.debug(org.slf4j.impl.MessageFormatter.format("Hello, {}",
			    new Object[] { "World" }));
                         Win32 JDK 1.5=1.44, Win32 JDK 1.4.2: 1.35,  
Mac JDK 1.4.2=1.3

	public void testLogSF() {
			LogSF.debug(logger, "Hello, {}", "World");
                         Win32 JDK 1.5=1.0, Win32 JDK 1.4.2=1.0, Mac  
JDK 1.4.2=1.1

	public void testLogMF() {
			LogMF.debug(logger, "Hello, {0}", "World");
                         Win32 JDK 1.5=1.25, Win32 JDK 1.4.2=1.3, Mac  
JDK 1.4.2=1.47

	public void testMessageFormat() {
			logger.debug(MessageFormat.format("Hello, {0}", "World"));
                         Win32 JDK 1.5=1.7

	public void testUtilFormatter() {
			logger.debug(String.format("Hello, %s", "World"));
                         Win32 JDK 1.5=2.312

	public void testUtilFormatter() {
			LogF.debug(logger, "Hello, %s", "World");
                         Win32 JDK 1.5=2.13


Observations:

1) Message formatting time can be a significant portion of the  
overall processing time.  That surprised me as I thought it would be  
swamped by the cost of LoggingEvent creation et al, but that is why  
you do benchmarking and profiling.

2) Array creation can be a significant portion of the overall  
processing time.

3) java.util.Formatter is substantially slower that  
java.text.MessageFormatter for simple substitution.

4) org.slf4j.impl.format(String, Object) is substantially faster than  
org.slf4j.impl.format(String, Object[]).  There calls reach  
independent implementations of the formatting logic which allows  
bypassing unnecessary Object[] creation.  Object[] creation does  
account for some, but not all of the performance difference.

5) java.text.Formatter is the other way round which suggest  
that .format(String, Object) just creates an array and delegates  
to .format(String, Object[]).

6) LogF and LogMF seem to add negligible overhead to the equivalent  
inline statements.

7) org.slf4j.impl.MessageFormatter.format(String, Object[]) has  
similar performance to java.text.MessageFormat.format(String, Object[]).


These suggest some fairly simple optimizations to LogMF and LogF  
which I'll take a shot at next.











---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Mime
View raw message