Synchronized로 검색한 결과 :: 시소커뮤니티[SSISO Community]
 
SSISO 카페 SSISO Source SSISO 구직 SSISO 쇼핑몰 SSISO 맛집
추천검색어 : JUnit   Log4j   ajax   spring   struts   struts-config.xml   Synchronized   책정보   Ajax 마스터하기   우측부분

회원가입 I 비밀번호 찾기


SSISO Community검색
SSISO Community메뉴
[카페목록보기]
[블로그등록하기]  
[블로그리스트]  
SSISO Community카페
블로그 카테고리
정치 경제
문화 칼럼
비디오게임 스포츠
핫이슈 TV
포토 온라인게임
PC게임 에뮬게임
라이프 사람들
유머 만화애니
방송 1
1 1
1 1
1 1
1 1
1

Synchronized로 검색한 결과
등록일:2018-09-12 19:56:40
작성자:
제목:Thread dump 분석 - Hang 상태의 원인을 찾아내자 !


안녕하십니까? 이번 시간에는 Thread dump로 분석할 수 있는 경우인 Hang 상태의 원인을 찾는 방법에 대한 알아보도록 하겠습니다.

Java 프로세스에서 Hang 상태는 다양한 원인이 있습니다. 그 중 대표적인 경우가 Object Locking입니다.

그럼 Java의 Object Lock  이란 무엇일까요 ?

Java 기반의 프로그램에서 Shared Resource의 접근할 경우 Lock을 획득하며, 또한 이러한 Lock을 다른 Thread들이 이미 획득하고 있을 경우 Lock을 획득하기 위해 대기하게 됩니다.

Java에서의 Lock은 내부 Monitor를 통해 구현되고 관리됩니다. 즉 Monitor 획득이 Lock 획득을 의미합니다.

이렇게 Lock을 획득하기 위해 대기하는 Thread들이 많아지고, 대기 시간이 길어지면 Hang 인것처럼 보여지게 됩니다.

 

Java 프로그램에서 Lock을 획득하기 위해서는 Synchronized구문을 이용하여 method 또는 block을 단위로 lock을 획득 할 수 있습니다.

 

다음 그림은 Lock Monitor를 통한 공유자원 접근에 대한 그림입니다.

 

 

실제 Java 프로그램에서 동기화가 어떻게 구현되는지 코드레벨에서 알아보겠습니다.

 

 

위의 그림과 같이 Synchronized 구문을 사용할때 어느 부분에 사용하느냐에 따라 lock의 범위와 lock의 대상 object들이 다르게 됩니다.

메소드에 대해 Synchronized를 구현하면 메소드가 수행되는 동안 해당 object에 대해 lock을 점유하게 됩니다. block에 대해 synchronize를 구현하면 해당 block이 수행되는 동안 object에 대해 lock을 점유하게 됩니다.

여기서 Synchronized가 object에 대한 lock을 점유하다고 말씀드렸는데 이는 Java에서 lock 정보는 object의 Header 부분에 flag로 저장 되기 때문입니다.

 

그럼 이 부분에 대해 자세히 설명을 드리도록 하겠습니다.

위의 그림에서 메소드에 대한 Synchronized 구문은 해당 메소드가 속한 class를 통해 생성된 object에 대해 lock이 설정됩니다. 즉 해당 class에 대한 object의 header정보에 lock flag가 설정된다는 것입니다.

그럼 block에 대한 Synchronized 구문은 위의 코드와 같이 지정한 lock object에 대해 lock이 설정됩니다. 즉 해당 object에 대한 header정보에 lock flag가 설정됩니다.

object별로 lock에 대한 정보가 저장되기 때문에 보통 lock을 설정하기 위해서는 object를 singleton으로 생성하여 사용하게 됩니다.

만약 singleton이 아니면 위의 Synchronized가 구현되어 있는 object를 하나 생성하고 계속 참조할 수 있도록해야 하는 어려움이 있습니다.

아래의 그림은 이러한 singleton을 통한 동기화에 대한 내용입니다.

 

 

이해를 쉽게 하기위해 다음과 같은 상황에 대해 생각해 보도록 하겠습니다.

Thread가 10개가 있는 Java 프로그램이 있습니다. 그리고 동기화가 필요한 로직(메소드)이 있어 Synchronized를 구현하였습니다.

각 Thread들이 해당 Synchronized가 구현된 객체를 각각 생성하고 수행한다면 해당 Synchronized가 처리된 메소드는 동기화가 이루어 지지 않습니다.

각 Thread들이 Synchronized가 구현된 객체를 각각 생성하게 되면 lock flag가 각각 생성되게 됩니다. 그렇게 되면 각 Thread들이 Synchronized 메소드를 수행할 때 각각의 lock을 가지게 되어 동기화가 이루어지지 않게 됩니다.

 

그럼 위에서 계속 언급했던 object header의 lock flag에 대해 설명드리도록 하겠습니다.

이 lock flag를 알기 위해서는 object에 대한 header 정보를 설명드려야 될 것 같으데요. Sun 계열과 IBM 계열이 object에 대한 header 정보가 다릅니다.

먼저 Sun 계열 JVM의 Lock 정보는 어디에 저장되는지 알아보겠습니다.

다음 그림은 Sun 계열 JVM의 object header에 대한 구성입니다.

 

 

위의 그림과 같이 두개의 header 부분이 있으며, 그 중 MarkWord 부분에 lock에 관련된 내용들이 저장됩니다.

그 중 Age와 Tag 부분은 GC(Garbage Collector)가 사용하는 정보이며, 나머지가 모두 Synchronized와 관련된 부분입니다.

특히 Baised와 Tag의 정보 조합을 통해 lock의 설정 여부를 확인할 수 있습니다.

 

다음 그림은 IBM 계열 JVM의 object header에 대한 구성입니다.

 

 

IBM 계열도 Sun 계열과 같이 두개의 header 부분이 있으며, 그 중 Lockword 부분에 lock에 관련된 내용들이 저장됩니다.

VTable 부분은 Object에 대한 정보가 저장됩니다. Lockword에는 Contention Bit 및 Thread ID, Monitor index등의 Lock에 관련된 정보가 저장됩니다.

 

자 그럼 Locking으로 인한 Hang 상태를 Thread dump를 통해 분석하는 방법에 대해 알아 보겠습니다.

첫번째로 Sun 계열의 Locking으로 인한 Hang에 대한 Thread dump 분석 예입니다.

해당 예제는 사용자 로그아웃 수행 시 DB Insert 처리 지연으로 인해 세션저장객체에 대한 Locking으로 다른 사용자들의 세션객체접근 시Lock 대기로 인해 Hang이 발생한 경우입니다.

 

 

위의 그림과 같이 총 3단계에서 Locking이 발생하고 있는 것을 확인할 수 있습니다. 물론 첫번째 Thread와 같이 block된 Thread가 많이 있지만 편의상 하나만 기술한 것입니다.

우선 lock waiting thread를 찾아 보면 "9fffffff454dc008" object에 대한 lock waiting thread가 무수히 많은 것을 알 수 있습니다.

(TIP : waiting to lock 구문으로 찾기를 하시면 쉽게 확인이 가능합니다.)

그럼 "9fffffff454dc008" object에 대해 lock을 소유하고 있는 thread를 찾아 어느 thread에 stack인지를 확인해보니

jeus.servlet.session2.SessionContainer.checkSessions(SessionContainer.java:191) 에서 해당 object를 lock한 것을 알 수 있습니다.
원인을 파악하기 위해서는 위와 같은 메소드에 대한 로직을 어느 정도 알고 있어야 하는데요.

위의 메소드는 WAS가 주기적으로 사용자 세션을 확인하여 설정된 시간보다 오래동안 사용하지 않은 세션에 대해 삭제 처리하는 로직입니다. 따라서 세션들의 시간을 확인하기 위해 전체 세션의 저장 객체인 Hashtable에 대해 lock을 걸고 세션 삭제 작업을 수행하는 것입니다.

문제는 이러한 작업을 수행할 때 시간이 만료된 삭제대상 세션을 삭제하는 과정에서 다시 lock이 대기가 발생한 것입니다.

 

아래와 같이 SessionListener를 수행 시 lock 대기가 발생했습니다.

 

at .......listener.SessionListener.sessionDestroyed(SessionListener.java)

waiting to lock <9fffffff455e0dd8> (a .....listener.SessionListener)

 

SessionListener는 사용자 세션에 대한 event를 구현하기 위한 객체로 세션의 생성, 수정, 삭제등에 발생할 대  등록된 event에 대한 처리를 수행주는 것입니다.

위와 같은 경우는 SessionListener의 sessionDestroyed() 메소드에 Synchronized가 걸려 있어 lock 대기가 발생한 것입니다.

그럼 "9fffffff455e0dd8" 주소 객체에 대한 lock을 소유한 Thread와 stack을 확인해 보아야 합니다.

 

"9fffffff455e0dd8" 주소 객체를 lock하고 있는 Thread는 위의 그림에서 맨아래의 Thread이며 해당 Thread는 SessionListener의 Synchronized로 구현된 sessionDestroyed() 메소드를 수행 시 Sybase DB에 Insert 처리(사용자 세션 소멸 시간 입력등..)를 수행중에 처리가 완료되지 못하고 socket read 상태인 것을 알 수 있습니다.

 

상황이 조금 복잡한 경우인데요. 정리해서 말씀드리자면 다음과 같습니다.

사용자들이 로그인을 정상적으로 수행하고 세션을 저장하기 위해 WAS에서 관리하는 세션저장객체(Hashtable)에 입력할 때 세션저장객체가 lock이 걸려있어 로그인을 하는 사용자들이 대기상태에 빠진게 됩니다.

그럼 세션저장객체는 WAS가 기간이 만료되는 세션을 정리하기 위해 주기적으로 확인 작업을 수행하는데 이때 세션 중 삭제 대상이 발견되어 삭제를 수행하자 세션에 대한 SessionListener가 등록되어 있어 sessionDestroyed() 메소드가 호출되며 이 메소드가 Synchronized가 되어 있어 SessionListener객체에 대한 lock을 걸려하자 다른 Thread가 해당 객체에 대해 이미 lock을 걸어둔 상태여서 대기 상태로 빠지게됩니다.

그럼 실제 SessionListener에 대해 lock을 건 Thread는 특정 사용자가 logout을 직접 수행하여 사용자의 session이 invalidate될때 SessionListener의 sessionDestroyed() 메소드가 호출되며 lock을 수행했으며, sessionDestroyed() 메소드에서 DB Insert 작업 지연으로 인해 lock 점유 시간이 지연되어 전체적으로 Hang된 것입니다.

 

다음은 위의 상황에 대한 그림입니다.

 

 

이 사례는 실제로 Hang이 길게 발생하지는 않고 짧게 주기적으로 발생하는 경우여서 실제 시스템 운영자들도 정확한 현상은 모르고 있었던 경우입니다.

 

물론 이 경우 DB에 문제가 있어 Insert가 지연되어 전체적으로 Hang이 발생한 것입니다.

그러나 이 예제는 동기화 구간을 너무 크게 잡았고 그리고 불필요한 동기화를 구현한것에 대한 문제점도 있었습니다.

실제로 문제 해결은 동기화 부분(SessionListener의 sessionDestroyed() 부분)을 삭제하는 것으로 해결하였습니다.

 

두번째로 Sun 계열의 Deadlock에 대한 Thread dump 분석 예입니다.

왠 deadlock이라고 하시는 분이 계실텐데요. java에서도 lock 메카니즘이 있기 때문에 deadlock도 발생할 수 있습니다.

각기 다른 lock을 상호 참조하면 deadlock이 발생하겠죠. Database의 deadlock과 비슷하다고 보시면 됩니다.

deadlock이 발생하려면 최소 2개 이상의 thread와 lock object가 있어야 성립합니다.

오라클에서 deadlock이 발생할 경우 alert 로그로 메시지를 출력하듯 java도 deadlock이 발생한 경우 thread dump를 수행하면 해당 deadlock이 발생한 메시지가 출력됩니다.

 

다음은 Netscape LDAP API와 관련된 deadlock 발생한 사례입니다.

 

 

우선 deadlock이 발생한 경우 thread dump 상에 위와 같이 deadlock detection 메시지가 출력됩니다.

그리고 그 아래에 deadlock이 발생한 thread와 상호 대기하고 있는 lock object에 대한 내용이 기록되어 있습니다.

그 아래로 deadlock 발생한 thread들의 stack들이 기록되어 있습니다.

stack을 보게되면 "LDAPConnThread" thread에서 LDAPConnThread object를 lock을 걸고 LDAPConnection object에 대해 lock waiting 상태이며, 다른 thread(TCPListener)는 LDAPConnection object에 대해 lock을 걸고 LDAPConnThread object에 대해 lock waiting 상태인것을 알 수 있습니다.

즉 서로 LDAPConnThread object와 LDAPConnection object에 대해 상호 lock 대기로 인해 deadlock이 발생한 경우입니다.

 

세번째로 IBM 계열의 Locking으로 인한 Hang 대한 Thread dump 분석 예입니다.

해당 예제는 log4j에서 lock이 발생하여 Hang 발생한 경우입니다.

참고로 log4j는 많이 사용하는 log 출력용 모듈입니다. 이 log4j의 일부 버전들에서 Hang이 발생하는 문제가 있습니다. 사용하는 버전에 대해 한번 확인해 보는것이 좋을 것 같습니다. 

 

아래는 log4j에 대한 lock으로 인한 Hang인 시점의 IBM javacore의 Lock 부분에 대한 정보입니다.

 

 

이전 포스트에서 IBM JVM building block의 subcomponent에 대한 설명과 그에 상응하는 javacore의 section에 대해 설명드렸습니다.

이 예제의 부분은 javacore의 Lock section으로 section 약자인 "LK" 에 대한 부분입니다.

Lock object인 "org.apache.log4j.Logger ....." object를 "RMI TCP Connection..." thread가 lock을 획득한 상태이며, 이 lock에 대해 대기중인 Thread들이 아래에 쭉 나열되어 있습니다.

먼저 lock을 점유한 thread의 stack을 확인해 보겠습니다.

 

 

위와 같이 ISO8601과 관련한 로그 포맷을 수행중인 것을 알 수 있습니다.


아래는 lock을 대기하고 있는 thread에 대한 stack입니다.


 

위와 같이 log4j.Category.callAppenders() 메소드를 수행중에 lock 대기가 발생하였습니다.

이것으로 보았을때는 log4j의 특성 상 로그의 순서를 맞추기 위한 처리로 보여집니다(왜 이렇게 하는지는 솔직히 이해가 안가긴 합니다만..ㅠ.ㅠ).

그러나 이 사이트의 경우 이러한 중지 현상이 한번 씩 길게 나타는 것이 문제였습니다.

 

그래서 lock을 잡고 있는 thread가 혹시 lock 대기하고 있지는 않는지 확인해 보았습니다.

 

 

위와 같이 log4j의 lock을 잡고 있는 thread가 Heap lock에서 대기중인 것을 알 수 있습니다. 이 Heap lock의 owner가 Signal Dispatcher인 것을 알 수 있습니다. Signal Dispatchr는 javacore 생성을 위해 수행한 SIGQUIT signal에 대한 처리를 위해 실행되는 thread입니다.

따라서 위의 Heap lock은 javacore를 수행에 따른 Heap lock인 것을 알 수 있습니다.

 

이 사례의 Locking Hang 현상은 log4j를 통한 과도한 로깅으로 인해 log4j의 모듈에 대한 lock으로 인해 발생한 문제였습니다.

 

네번째로 IBM 계열의 deadlock에 대한 Thread dump 분석 예입니다.

 

아래의 그림은 IBM JVM에서 deadlock이 발생할 경우 javacore를 생성하였을때 출력되는 메시지입니다.

javacore 의 LOCK 세션 부분에 다음과 같은 메시지 출력됩니다.

 

먼저 lock monitor 정보가 출력되며 그 아래로 "Deadlock detected !!!" 메시지와 함께 해당 thread와 lock object 에 대한 정보가 출력됩니다.

Sun 계열과 다르게 해당 thread에 대한 stack 정보는 해당 thread에 대한 XE 섹션(thread stack 정보)을 찾아 보아야 합니다.

 

지금까지 Java에서의 lock 메카니즘과 lock으로 인한 hang에 대한 thread dump를 통한 분석 방법에 대해 알아 보았습니다.

다음 시간에는 나머지 thread dump로 분석가능한 문제와 분석방법등에 대해 알아보도록 하겠습니다.

 

요즘 문득 시간이 참 빨리 간다는 것을 느끼게 되는 나날들입니다.

이제 백일된 아들래미, 7살난 딸래미와 저녁마다 같이 놀아주다 보니 시간이 팽~~ 하고 가는군요.

참 지금이 행복하다는 생각이 드는 나날들입니다. ^^

그럼 모두들 저와 같이 행복한 날들 되십시요. ^^