2013-01-02 42 views
0

在将日志记录包装到单独的类中时,我们遇到了性能提高,这是我们无法解释的。Log4J意外的性能增加

如果有人可以发表评论来帮助我们理解这一点吗?

这里是主线程:

package myapp; 

import myapp.logging.Log; 

import org.apache.log4j.Logger; 

public class ApplicationMain extends Thread { 
private static Logger LOG = Logger.getLogger(ApplicationMain.class); 

@Override 
public void run() { 
for (int i = 0; i < 50; i++) { 
    try { 
    Thread.sleep(500); 

    //traditional plain log4j 
    long startTime = System.nanoTime(); 
    LOG.info("Hello World Log4j"); 
    long endTime = System.nanoTime(); 
    System.out.println(endTime - startTime); 

    //logging in wrapper 
    long startTime2 = System.nanoTime(); 
    Log.Info("Hello World Log4J from within wrapper"); 
    long endTime2 = System.nanoTime(); 
    System.out.println(endTime2 - startTime2); 

    } catch (InterruptedException ex) { 
    Log.Info(ex.getMessage()); 
    } 
} 
} 

}

日志包装类:

package myapp.logging; 

import org.apache.log4j.Logger; 

public class Log { 


private static Logger LOG; 

public static synchronized void Info(String LogMessage) { 

Throwable throwable = new Throwable(); 
StackTraceElement[] stackTraceElements = throwable.getStackTrace(); 
LOG = Logger.getLogger(stackTraceElements[1].getClassName()); 
LOG.info(LogMessage); 
} 
} 

Thread.start()我们得到以下类型的输出:

2013-01-02 10:42:25,359 INFO [ApplicationMain] Hello World Log4j 

191478 

2013-01-02 10:42:25,359 INFO [ApplicationMain] Hello World Log4J from within wrapper 

163852 

2013-01-02 10:42:25,859 INFO [ApplicationMain] Hello World Log4j 

166165 

2013-01-02 10:42:25,859 INFO [ApplicationMain] Hello World Log4J from within wrapper 

85361 

2013-01-02 10:42:26,359 INFO [ApplicationMain] Hello World Log4j 

188694 

2013-01-02 10:42:26,359 INFO [ApplicationMain] Hello World Log4J from within wrapper 

82709 

..... 

为什么包装表现不佳?尽管增加了检索调用方类名称的额外开销

回答

0

我强烈建议阅读微基准。这是一个非常有趣的问题,我发现这个问题为出发点有用:

How do I write a correct micro-benchmark in Java?

本质上讲,这是不是性能的有效措施,因为有其他事情一大堆考虑到主要是围绕编译器优化