log4j的性能瓶颈定位与性能优化（org.apache.log4j.spi.RootLogger）

log4j的性能瓶颈定位与性能优化（org.apache.log4j.spi.RootLogger）

转自：http://hi.baidu.com/higkoo/item/70770834426247483075a1ce

最近执行一个项目调优，发现使用第三方的Json库导致性能差。原以为问题就这么定位到了，结果去掉Json操作后，性能也不见好转。

     现象非常诡异：CPU、内存、网络、磁盘使用率均有剩余，而且压力也是足够的。即使施加更大压力，吞吐量也不见好转。

     于是监控了一下Java进程状态，发现几乎所有进程都处在

状态：BLOCKED 在 org.apache.log4j.spi.RootLogger@6b2b48e5 上，拥有者： http-0.0.0.0-8080-2010

阻塞总数：188,661 等待总数： 2,699

堆栈追踪： 
org.apache.log4j.Category.callAppenders(Unknown Source)
org.apache.log4j.Category.forcedLog(Unknown Source)
org.apache.log4j.Category.log(Unknown Source)
org.apache.commons.logging.impl.Log4JLogger.debug(Log4JLogger.java:110)

……

     写日志这么影响性能？初步怀疑代码或配置问题。请教了一下使用log4j的类似项目的朋友，确定是配置问题：未给log4j配置写缓冲。

     修改log4j配置文件 /usr/local/jboss/server/default/deploy/higkoo.war/WEB-INF/log4j.xml ，红色部分为添加缓冲的配置项：

<appendername="MyLog"class="org.apache.log4j.DailyRollingFileAppender">
<paramname="File"value="/data/logs/higkoo/MyLog.log"/>
<paramname="encoding"value="UTF-8"/>
<paramname="DatePattern"value="'.'yyyy.MM.dd"/>
<paramname="Append"value="true"/>
<paramname="BufferSize"value="8192"/>
<paramname="ImmediateFlush"value="false"/>
<paramname="BufferedIO"value="true"/>
<layoutclass="org.apache.log4j.PatternLayout">
         <paramname="ConversionPattern"value="%-d{yyyy-MM-ddHH:mm:ss,SSS}%m[%c]%n"/>
</layout>
<filterclass="org.apache.log4j.varia.LevelRangeFilter">
         <paramname="levelMin"value="debug"/>
         <paramname="levelMax"value="debug"/>
         <paramname="AcceptOnMatch"value="true"/>
</filter>
</appender>

OK，添加缓冲后，阻塞现象立马消失。性能达到最佳，CPU全部耗尽。

2010-11-16： 今天专门针对log4j的配置做了一次测试，没有发现这个问题。上述问题应该于程序代码有关。