Log4j blocked 线程阻塞问题
我的zoa项目中,一直使用的是log4j 1.x版本,由于简单,一直没更换,也没怀疑过它的问题。
偶尔有两次,zoa在使用过程中假死的情况,不能响应任何请求,包括正常的关闭都无法进行。
于是我使用 jvm工具分析了JVM的情况,最终定位为 log4j引起的线程 blocked,不算是死锁,但是所以请求都会调用log4j,而log4j又无法正常执行,所以 所有请求都会 block。线程堆栈信息片段 形如:
"qtp1056944384-232" prio=10 tid=0x00007f54900d0800 nid=0x63b3 waiting for monitor entry [0x00007f54492d0000] java.lang.Thread.State: BLOCKED (on object monitor) at org.apache.log4j.Category.callAppenders(Category.java:205) - waiting to lock <0x00000007e81c4830> (a org.apache.log4j.spi.RootLogger) at org.apache.log4j.Category.forcedLog(Category.java:391) at org.apache.log4j.Category.log(Category.java:856) at org.slf4j.impl.Log4jLoggerAdapter.info(Log4jLoggerAdapter.java:368)
主要是下面这个类中的这段代码造成的:
/** * Call the appenders in the hierrachy starting at <code>this</code>. If no * appenders could be found, emit a warning. */ public void callAppenders(LoggingEvent event) { int writes = 0; for (Category c = this; c != null; c = c.parent) { // Protected against simultaneous call to addAppender, // removeAppender,... synchronized (c) { if (c.aai != null) { writes += c.aai.appendLoopOnAppenders(event); } if (!c.additive) { break; } } } if (writes == 0) { repository.emitNoAppenderWarning(this); } }
它使用了synchronized(this),所有线程共用一个Category,而它通过log4j.properties指定。 同一个Category下的线程打log时,需要进行全局同步,因此它的效率会很低,不适合高并发的场景。
详细分析参见:
https://dzone.com/articles/log4j-thread-deadlock-case