[Java]Log4Jのパフォーマンス


logger.debug("name=" + value);
って書くより

if(logger.isDebugEnabled()){
logger.debug("name=" + value");
}
って書くほうが速い*1っていうけど、ほんとかな?と試してみた。

理由

「"name" + value 」ってのが


String tmp1 = new String("name");
Stirng tmp2 = new String("name"+value.toString());
logger.debug(tmp2);
ってコードと同じ実行だと思ってたら、最近のコンパイラの最適化機能により

StringBuffer tmp1 = new StringBuffer("name");
tmp1.append(value.toString());
logger.debug(tmp1);
ってコードと同じ実行になるらしい。

環境

CPU ... 1.4 GHz pemtiumM
MEM ... 1GB
JVM ... WebSphere 5.0 ランタイムJVM (JVM 1.3)

結果

logger.debug()に渡す引数のタイプによってこんな結果になったよん
数字は、10回実行の平均値(ms)

  • Stringのみloggerを1万回出力した場合             :1001
  • Stringのみloggerを1万回出力した場合(if文あり)        :980
  • String + String loggerを1万回出力した場合          :996
  • String + String loggerを1万回出力した場合(if文あり)     :997
  • String + int loggerを1万回出力した場合            :1005
  • String + int loggerを1万回出力した場合(if文あり)       :998
  • String + int + String loggerを1万回出力した場合       :1012
  • String + int + String loggerを1万回出力した場合(if文あり)  :1005

とまあ、やってみたけど、1万回出力で0.01〜0.02秒ぐらいの差しかでないのなら、そこまでこだわらなくてもいいんじゃないのかな??って思ってきた。。。遅いところももっと遅いんだし。
じゃあ、なんであんなif文で囲む文章をマニュアルでは薦めてるんだろう??

結果2

ためしに、JVM をWebSphere 5.1 ランタイムJVM (JVM 1.4)にしてみた。
数字は、10回実行の平均値(ms)

  • Stringのみloggerを1万回出力した場合             :1612
  • Stringのみloggerを1万回出力した場合(if文あり)        :1589
  • String + String loggerを1万回出力した場合          :1594
  • String + String loggerを1万回出力した場合(if文あり)     :1599
  • String + int loggerを1万回出力した場合            :1597
  • String + int loggerを1万回出力した場合(if文あり)       :1609
  • String + int + String loggerを1万回出力した場合       :1609
  • String + int + String loggerを1万回出力した場合(if文あり)  :1613

あれれ?IBMはWebSphere 5.1 のほうが1.5倍ぐらい早くなるって言ってるのに、逆に1.5倍遅くなってるよー。

><