2011-08-12 11 views
1

在我們的生產環境中,weblogic服務器掛起半個小時,看起來它有死鎖線程。但在調查線程轉儲後,3個線程被鎖定爲同一個鎖,但沒有其他線程擁有此鎖。以下是stacktrace ..怎麼可能,3個線程處於阻塞狀態,等待相同的監視器,並且沒有線程擁有該監視器

您是否對此評估有任何合理的解釋?

這裏是被阻塞的線程;

「池-1013線程-5」 PRIO = 7 TID = 600000000842be00 NID = 17280 lwp_id單= 518677等待監視器條目 [9fffffffe6aff000..9fffffffe6b00bd0] java.lang.Thread.State中: BLOCKED(上在 org.apache.log4j.Category.callAppenders(Category.java:201) 對象監視器) - 等待在 org.apache.log4j鎖定< 9ffffffde1e7ec88>(一個 org.apache.log4j.spi.RootLogger) .Category.forcedLog(Category.java:388)在 org.apache.log4j.Category.log(Category.java:853)在 org.slf4j.impl.Log4jLoggerAdapter.debug(Log4jLoggerAdapter.java:173) 在 org.hibernate.jdbc.AbstractBatcher.logOpenResults(AbstractBatcher.java:426) 在 org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:210) 在org.hibernate.loader.Loader.getResultSet( Loader.java:1808)

「池-1013線程4」 PRIO = 7 TID = 6000000008413400 NID = 17279 lwp_id單= 518676等待監視器條目 [9fffffffe6eff000..9fffffffe6f00b50] java.lang.Thread.State中: 在 org.apache.log4j.Category.callAppenders(Category.java:201) BLOCKED(對象監視器上) - 等待鎖定< 9ffffffde1e7ec88>(一個 org.apache.log4j.spi.RootLogger)在 org.apache.log4j.Category.forcedLog(Category.java:388)在 org.apache.log4j.Category.log(Category.java:853)在 組織.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)在 org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:71) 在 或g.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:65) 在 org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:3072) 在 org.hibernate.event.def。 DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:434) 在 org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:415) 在 org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java: 165) 在 org.hibernate.event.def.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:223) 在 org.hibernate.event.def.DefaultLoadE ventListener.onLoad(DefaultLoadEventListener.java:126) at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl。的java:905)

「池-1013線程3」 PRIO = 7 TID = 6000000008411c00 NID = 17278 lwp_id單= 518675等待監視器條目 [9fffffffe70ff000..9fffffffe7100ad0] java.lang.Thread.State中: 在 org.apache.log4j.Category.callAppenders(Category.java:201) BLOCKED(對象監視器上) - 等待在 org.apache鎖定< 9ffffffde1e7ec88>(一個 org.apache.log4j.spi.RootLogger) (Log4jLoggerAdapter.java:173) 在 個org.hibernate.jdbc.AbstractBatcher.logOpenResults(AbstractBatcher.java:426) 在 org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:210) 在org.hibernate.loader.Loader.getResultSet(裝載機。的java:1808)在 org.hibernate.loader.Loader.doQuery(Loader.java:697)

+1

爲什麼不張貼堆棧跟蹤?我們不會下載它。 – Jonas

+0

,因爲stackoverflow的限制... –

+0

你是否沒有'notify/notifyAll'調用'wait'? –

回答

7

起初我懷疑Lock對象不是在最後被解鎖。但後來我看了你提供的兩個線程轉儲。

實際上3個線程被鎖定在同一個鎖上,即它是Log4J,Category類。據線程轉儲,這是代碼,他們也都封鎖在:

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確認沒有其他線程擁有該鎖,但也提供了非常有用的技巧:

該顯示器沒有鎖定它的線程。這意味着VM線程正在持有它。 如果您看到很多顯示器沒有鎖定線程,這通常意味着垃圾收集器正在運行。在這種情況下,您應該考慮分析垃圾收集器輸出。如果轉儲具有多個不帶鎖定線程的監視器,則單擊轉儲節點將爲您提供附加信息。

並進一步:

這個線程轉儲包含顯示器無鎖定線程的信息。這意味着,監視器由系統線程或一些外部資源保存。 您應該檢查沒有鎖定線程的監視器以獲取更多信息。

結論:您應該啓用垃圾回收日誌記錄,看看這是不是根本原因。還要檢查你或某個圖書館是不是在用Log4J(圓形類別?)做一些奇怪的事情 - 這只是一個瘋狂的猜測。有用的選項:

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

或者它就像一個阻塞的Appender一樣簡單;) –

+0

感謝您的tda鏈接.. –

1

我遇到了一個非常類似的問題。我相信這是相關的https://issues.apache.org/bugzilla/show_bug.cgi?id=50614

在你的情況,我會建議使用jstack -l,然後從堆棧中解析出實際鎖定的對象(他們的地址不同於監視器地址) - 因此每個「等待鎖定X「,你應該能夠在某個線程堆棧中找到」 - locked X「(當使用jstack -l打印時)。

在我的情況下,我發現扼殺者線程(持有鎖)實際上在控制檯appender的寫入刷新時被阻塞(即使堆棧跟蹤表明它處於可運行狀態也是如此)。我無法找到死鎖循環。

所以至少有一種解決這個問題的方法涉及操作系統內的內部鎖 - 這是通過控制檯寫入刷新觸發的。因此,一個簡單的解決辦法是消除控制檯日誌appender(或增加其級別)。

0

當我使用log4j SocketAppender將套接字寫入logstash時,這會使我陷入困境。

SocketAppender處於阻塞狀態,當另一端發生logstash事件並且logstash無法處理它(即阻塞elasticsearch調用)時,您的應用將被阻塞。

任何其他嘗試使用該appender進行登錄的線程都將簡單地坐在並等待粘貼在線程轉儲中的阻塞狀態。

最好的解決方法是使用異步appender。

這裏看到更多的信息: How SocketAppender works