3 개의 스레드가 동일한 모니터를 기다리는 동안 차단 된 상태입니다. 해당 모니터를 소유 한 스레드가 없습니다.

Question

프로덕션 환경에서 30 분 동안 weblogic 서버가 멈 춥니 다. 스레드가 죽은 것처럼 보입니다. 그러나 스레드 덤프를 조사한 후에는 동일한 스레드에 대해 3 개의 스레드가 차단되지만 다른 스레드는이 스레드를 소유하지 않습니다. 여기에 stacktrace이 있습니다.

이 stiuation에 대한 합리적인 설명이 있습니까?

차단 된 스레드는 다음과 같습니다. ( 차단됨 :

"풀 1,013 스레드 -5-"프리 오 = 7 TID = 600000000842be00 NID = 17,280 = 518,677 lwp_id와 는 [9fffffffe6aff000..9fffffffe6b00bd0] java.lang.Thread.State에 모니터 입력 대기 org.apache.log4j.Category.callAppenders (Category.java:201) 에서 객체 모니터)에 - org.apache.log4j에서 < 9ffffffde1e7ec88> (A org.apache.log4j.spi.RootLogger)를 잠금 대기 .Category.forcedLog (Category.java:388) at org.apache.log4j.Category.log (Category.java:853) at org.slf4j.impl.Log4jLoggerAdapter.debug (Log4jLoggerAdapter.java:173) 01 org.hibernate.jdbc.AbstractBatcher.logOpenResults (AbstractBatcher.java:426) org.hibernate.jdbc.AbstractBatcher.getResultSet (AbstractBatcher.java:210)에서 org.hibernate.loader.Loader.getResultSet에서 에서 23,516,(모니터 입력 대기 Loader.java:1808)

"풀 - 1,013 - 스레드 4"프리 오 = 7 TID = 6000000008413400 NID = 17,279 = 518,676 lwp_id와 [9fffffffe6eff000..9fffffffe6f00b50]하는 java.lang.Thread.State : 블로킹 (객체 모니터에서) org.apache.log4j.Category.callAppenders (Category.java:201) - 대기 중 < 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)) org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections (Loader.java:259) org.hibernate.loader.Loader.loadEntity에서 에서 org.hibernate.loader.Loader.doQuery (Loader.java:724) (로더에 .java : 1881) at org.hibernate.loader.entity.AbstractEntityLoader.load (AbstractEntityLoader.java:71) at 또는 g.hibernate.loader.entity.AbstractEntityLoader.load org.hibernate.event.def에서 org.hibernate.persister.entity.AbstractEntityPersister.load (AbstractEntityPersister.java:3072) 에서 (AbstractEntityLoader.java:65) . DefaultLoadEventListener.loadFromDatasource org.hibernate.event.def.DefaultLoadEventListener.load에서 org.hibernate.event.def.DefaultLoadEventListener.doLoad (DefaultLoadEventListener.java:415)에서 (DefaultLoadEventListener.java:434) (DefaultLoadEventListener.java : 165) at org.hibernate.event.def.DefaultLoadEventListener.proxyOrLoad (DefaultLoadEventListener.java:223) at org.hibernate.event.def.DefaultLoadE ventListener.onLoad (DefaultLoadEventListener.java:126) at org.hibernate.impl.SessionImpl.fireLoad (SessionImpl.자바 : 905)

"풀 1,013 스레드 -3-"프리 오 = 7 TID = 6000000008411c00 NID = 17,278 = 518,675 lwp_id와 모니터 입력 대기 [9fffffffe70ff000..9fffffffe7100ad0]하는 java.lang.Thread.State : org.apache.log4j.Category.callAppenders (Category.java:201) 에서 (객체 모니터에) BLOCKED - org.apache에서 < 9ffffffde1e7ec88> (A org.apache.log4j.spi.RootLogger)를 잠금 대기 .log4j.Category.forcedLog (Category.java:388) at org.apache.log4j.Category.log (Category.java:853) at org.slf4j.impl.Log4jLoggerAdapter.debug (Log4jLoggerAdapter.java:173) 에 451,515,org.hibernate.jdbc.AbstractBatcher.logOpenResults (AbstractBatcher.java:426) org.hibernate.loader.Loader.getResultSet에서 org.hibernate.jdbc.AbstractBatcher.getResultSet (AbstractBatcher.java:210) (로더에 . 자바 : org.hibernate.loader.Loader.doQuery (Loader.java:697)에서 1808)

Answer 1

는 처음에 나는 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 

Answer 2

매우 비슷한 문제가 발생했습니다. 이것은 관련이 있다고 생각합니다 https://issues.apache.org/bugzilla/show_bug.cgi?id=50614

jstack -l을 사용하여 스택에서 실제로 잠긴 개체 (해당 주소가 모니터 주소와 다름)를 파싱하는 것이 좋습니다. - 따라서 모든 "대기 잠금" X "이면 일부 스레드의 스택에서"- locked X "를 찾을 수 있어야합니다 (jstack -l을 사용하여 인쇄 할 때).

필자의 경우 콘솔 잠금 장치의 쓰기 작업시 (콘솔 추적기가 실행 가능한 상태라고하더라도) 잠금 장치를 가지고있는 범용 스레드가 실제로 차단 되었음이 발견되었습니다. 나는 교착 상태 루프를 찾을 수 없었다.

적어도이 문제에 도달하는 한 가지 방법은 콘솔 쓰기 플러시를 통해 트리거되는 OS 내부의 내부 잠금을 포함합니다. 따라서 간단한 수정은 콘솔 로그 appender를 제거하거나 레벨을 올리는 것입니다.

Answer 3

log4j SocketAppender를 사용하여 logstash에 소켓을 쓸 때이 비트가 표시됩니다.

SocketAppender가 차단되어 있고 반대쪽에있는 logstash에 이벤트가 전송되고 logstash가이를 처리 할 수없는 경우 (elasticsearch 호출을 차단하는 경우) 앱이 차단됩니다.

해당 appender를 사용하여 로그를 시도하는 다른 모든 스레드는 스레드 덤프에 붙여진 차단 된 상태로 앉아서 대기합니다.

이 문제를 해결하는 가장 좋은 방법은 비동기 애플릿을 사용하는 것입니다.

더 많은 정보를 원하시면 여기를 참조하십시오 : How SocketAppender works