java - 这怎么可能，3 个线程处于阻塞状态等待同一个监视器，并且没有线程拥有该监视器

Question

在我们的生产环境中，weblogic server 挂了半个小时，看起来是线程死锁了。但是在调查线程转储后，3 个线程被同一个锁阻塞，但没有其他线程拥有这个锁。这是 stacktrace ..

您对这种情况有什么合理的解释吗？

这里是被阻塞的线程；

"pool-1013-thread-5" prio=7 tid=600000000842be00 nid=17280 lwp_id=518677 waiting for monitor entry [9fffffffe6aff000..9fffffffe6b00bd0] java.lang.Thread.State: BLOCKED (on object monitor) at org.apache.log4j.Category.callAppenders(Category.java:201) - waiting to lock <9ffffffde1e7ec88> (a org.apache.log4j.spi.RootLogger) at org.apache.log4j.Category.forcedLog(Category.java:388) at org.apache.log4j.Category.log(Category.java:853) at org.slf4j.impl.Log4jLoggerAdapter.debug(Log4jLoggerAdapter.java:173) at org.hibernate.jdbc.AbstractBatcher.logOpenResults(AbstractBatcher.java:426) at org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:210) at org.hibernate.loader.Loader.getResultSet(Loader.java:1808)

"pool-1013-thread-4" prio=7 tid=6000000008413400 nid=17279 lwp_id=518676 waiting for monitor entry [9fffffffe6eff000..9fffffffe6f00b50] java.lang.Thread.State: BLOCKED (on object monitor) at org.apache.log4j.Category.callAppenders(Category.java:201) - waiting to lock <9ffffffde1e7ec88> (a org.apache.log4j.spi.RootLogger) at org.apache.log4j.Category.forcedLog(Category.java:388) at org.apache.log4j.Category.log(Category.java:853) at org.slf4j.impl.Log4jLoggerAdapter.debug(Log4jLoggerAdapter.java:173) at org.hibernate.loader.Loader.getRow(Loader.java:1197) at org.hibernate.loader.Loader.getRowFromResultSet(Loader.java:603) at org.hibernate.loader.Loader.doQuery(Loader.java:724) at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:259) at org.hibernate.loader.Loader.loadEntity(Loader.java:1881) at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:71) at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:65) at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:3072) at org.hibernate.event.def.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:434) at org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:415) at org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:165) at org.hibernate.event.def.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:223) at org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:126) at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:905)

"pool-1013-thread-3" prio=7 tid=6000000008411c00 nid=17278 lwp_id=518675 waiting for monitor entry [9fffffffe70ff000..9fffffffe7100ad0] java.lang.Thread.State: BLOCKED (on object monitor) at org.apache.log4j.Category.callAppenders(Category.java:201) - waiting to lock <9ffffffde1e7ec88> (a org.apache.log4j.spi.RootLogger) at org.apache.log4j.Category.forcedLog(Category.java:388) at org.apache.log4j.Category.log(Category.java:853) at org.slf4j.impl.Log4jLoggerAdapter.debug(Log4jLoggerAdapter.java:173) at org.hibernate.jdbc.AbstractBatcher.logOpenResults(AbstractBatcher.java:426) at org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:210) at org.hibernate.loader.Loader.getResultSet(Loader.java:1808) at org.hibernate.loader.Loader.doQuery(Loader.java:697)

Answer 1

起初我怀疑 Lock 对象最终没有被解锁。但后来我查看了您提供的两个线程转储。

确实有3个线程阻塞在同一个锁上，即Log4J，Category类(class)。根据线程转储，这是他们都被阻止的代码:

for(Category c = this; c != null; c=c.parent) {
  synchronized(c) {  // LOCKED HERE
    if(c.aai != null) {
      writes += c.aai.appendLoopOnAppenders(event);
    }
    if(!c.additive) {
      break;
    }
  }
}

TDA确认没有其他线程拥有此锁，但也提供了非常有用的提示:

This monitor doesn't have a thread locking it. This means a VM Thread is holding it. If you see many monitors having no locking thread, this usually means, the garbage collector is running. In this case you should consider analyzing the Garbage Collector output. If the dump has many monitors with no locking thread a click on the dump node will give you additional information.

还有:

This thread dump contains monitors without a locking thread information. This means, the monitor is hold by a system thread or some external resource. You should check the monitors without locking threads for more information.

结论:您应该启用垃圾收集日志记录，看看这是否不是根本原因。还要检查您或某些图书馆是否没有使用 Log4J(循环类别？)做一些奇怪的事情 - 只是一个疯狂的猜测。有用的选项:

-XX:+PrintGCDetails
-XX:+PrintGCTimeStamps
-XX:+PrintHeapAtGC
-Xloggc:gc.log