brunch

You can make anything
by writing

C.S.Lewis

by 에디의 기술블로그 Dec 10. 2018

Thread Dump 분석하기

- 쓰레드 덤프 분석하기

쓰레드 기본 개념을 간단하게 정리하고, 간단한 예시를 통해서 쓰레드 덤프를 분석하는 방법에 대해서 공유한다.

쓰레드 개념 정리


쓰레드 기본 개념을 정리한다. 


쓰레드란?


생략한다. 알아서 찾아보길 바란다. 


쓰레드 종류


쓰레드는 데몬 쓰레드(Daemon Thread)와 비데몬 쓰레드(Non-daemon Thread)로 나눌 수 있다. 데몬 쓰레드는 일반적인 Thread 가 아닌, 작업을 돕는 보조적인 역항르 수행하는 Thread 이다. 자세한 내용은 네이버 기술블로그를 참고하길 바란다.

https://d2.naver.com/helloworld/10963


쓰레드 상태


쓰레드 상태는 아래와 같이 정의할 수 있다. 

NEW : Thread 가 생성된 상태, 아직 start() 되지 않음

RUNNABLE : start()가 호출되어 실행 되기 상태로 언제든지 실행 상태로 갈 수 있다. run() 하면 RUNNING이 된다. 

WAITING : 다른 Thread의 통지를 기다리는 일시정지 상태

TIMED_WAITING: 주어진 시간동안 기다리는 일시 정지 상태

BLOCKED : 사용하고자 하는 객체의 락이 풀릴 때 까지 기다리는 일시 정지 상태

TERMINATED : 실행을 마친 상태


참고로, java.lang 패키지의 Thread 클래스에서 State라는 이름의 enum 으로 정의되어 있다.


NEW


RUNNABLE


BLOCKED


WAITING


TIMED_WAITING


TERMINATED



쓰레드 Life Cycle


쓰레드 라이프사이클은 아래와 같다. 

http://www.ntu.edu.sg/home/ehchua/programming/java/j5e_multithreading.html

정리


쓰레드 기본 개념에 대해서 간단하게 정리하였다. 국내 블로그 중에서는 네이버 기술블로그의 글이 가장 읽을 만하다. 꼭 참고하길 바란다. 

https://d2.naver.com/helloworld/10963



가상의 시나리오 1


매우 느린 Slow Query 를 실행하는 애플리케이션을 만들어보자. 스프링 부트 2.1.1.RELEASE 환경에 Spring Data JDBC 를 사용해서 mySql 를 연동해보자. 


애플리케이션 구현


build.gradle에 아래와 같이 디펜던시를 추가한다. 

필자는 starter-data-jdbc를 디펜던시로 추가했다. 참고로, starter-data-jdbc 는 starter-jdbc 와 다르다. 그리고, 부트 2.0 부터는 기본 데이터베이스 커넥션풀로 Hikari 가 디폴트로 된다. 필자는 톰캣 커넥션 풀을 사용할 것이다. 그래서 datasource.type 을 아래와 같이 명시적으로 선언하였다. 또한 테스트 환경을 만들기 위해서 max-active 를 아주 작게 설정하였다. 필자는 2로 설정하였다. 

필자의 MySql 에 city 라는 테이블을 미리 생성하였다. 코드에서 Entity 정의는 아래와 같이 한다. 

이제 가장 중요한 Slow Query 구문을 Repository 에 추가한다. 테스트를 위해서 sleep(1000) 구문을 추가하였다.

Repository 를 사용하는 @Service, @Controller 를 정의한다.


해당 애플리케이션은 매우 느린 Slow Query 를 실행하며, 커넥션 풀 카운트 또한  매우 작기 때문에 트래픽이 몰리는 경우에는 애플리케이션이 먹통이 될 것이다. 


테스트


서버에서는 Nginx 를 앞단에 두고 애플리케이션을 Reverse-Proxy 하였다. Nginx 는 기본으로 Time-Out 설정이 되어있는데, 장시간동안 애플리케이션에서 응답이 오지 않는다면 Nginx 는 HTTP 커넥션을 끊어버릴 것이다. 즉, 클라이언트에서 Close 요청을 보낸다. 아래와 같은 시나리오이다. 

조금 더 자세한 내용은 필자의 예전 글을 참고하기를 바란다.

https://brunch.co.kr/@springboot/98

클라이언트에서 CLOSE 요청을 보내면, 서버에서는 CLOSE_WAIT 상태가 되고, 애플리케이션이 정상적으로 종료가 되어야 서버의 CLOSE_WAIT 상태는 소멸된다. 하지만, 애플리케이션은 매우 느린 SQL 쿼리를 사용하하면서, 매우 작게 설정 되어있는 데이터베이스 커넥션 풀을 사용하기 떄문에, CLOSE_WAIT 상태는 계속 쌓이기만 할 것이다. 결국 시스템이 완전 먹통상태가 될 것이다. 필자가 트래픽을 많이 발생시켜봤다. 아래와 같이 CLOSE_WAIT 가 엄청나게 많이 쌓여있다.


쓰레드 덤프 분석


필자는 jstack 명령어를 사용하여 쓰레드 덤프 파일을 생성하였고, 해당 파일을 온라인 무료 분석 사이트에서 분석하였다. 파일을 생성하는 방법은 아주 간단하다.  jstack pid > 파일명 을 실행하자.

참고로 JDK 패키지가 설치가 되어있어야 한다. JRE 패키지만 설정된 서버라면 실행이 되지 않는다. 쓰레드 덤프 파일을 확인해보자. 하지만, 아래와 같이 덤프 파일을 사람의 눈으로 정확하게 전부 확인하는 일은 쉽지가 않다.

그래서, 보통 쓰레드 덤프를 분석할 수 있는 툴을 사용한다. 필자는 간단하게, 온라인에서 무료 분석이 바로 가능한 웹사이트(http://fastthread.io/)를 활용하였다. 분석을 해보면 아래와 같이 총 205개의 쓰레드가 실행 중이다. 

또한, TIMED_WAITING 쓰레드가 187개나 쌓여있는데, 대기하고 있는 쓰레드가 많은 것을 확인을 할 수 있다. 아마도 Slow Query 이후에 다른 요청이 실행을 하지 못하고 계속 대기하고 있는 것으로 추측된다. 

필자가 선언한 조회 기능은 Slow Query 를 발생하는 모든 데이터를 조회하는 findAll() 메서드와 특정 조건으로 조회하는 findByName() 메서드인데, 187건의 TIMED_WAITING 는 거의 대부분 findByName() 메서드를 실행하는 요청이다. 필자가 구현한 CityUseCase, CityController 등을 확인할 수 있다. 

사실 해당 요청은 평소에는 매우 빠르게 처리할 수 있는 기능이지만, 해당 시나리오에서는 이미 실행중인 Slow Query 가 끝나지 않고 있어서 계속 대기하고 있는 상황이다. 그렇다면 RUNNABLE 하는 쓰레드를 살펴보자. SlowQuery 를 실행하는 findAll() 메서드의 쓰레드를 확인할 수 있다. 

CityUseCase 의 findAll() 를 실행하는 쓰레드가 2 개 인 것을 확인할 수 있는데, findAll () 메서드를 해당 애플리케이션에서는 딱 2개만 동시에 실행 가능한 것이다.


시나리오 1 정리


쓰레드 덤프 분석을 통해서 SlowQuery 가 발생하는 소스가 어디인지 확인을 할 수 있었다. 일반적으로, 애플리케이션이 먹통이 되면 원인을 바로 찾기가 쉽지가 않지만, 쓰레드 덤프 를 분석하면 시스템이 왜 문제가 있는지 힌트를 찾을 수 있을 것이다. 


가상의 시나리오 2


이번에는 좀 더 짜증나는 상황을 만들어보자. 데드락(Dead-Lock) 현상을 재현하겠다. 


구현


겁나 간단한 Controller 를 아래와 같이 구현하였다. 

개별 요청은 5초의 딜레이 시간을 갖는다. 또한 Dead-Lock(데드락) 을 재현시키기 위해서 synchronized 를 사용하였다. 단일 요청을 하고 5초를 기다리는 경우에는 데드락이 발생하지 않는다. 하지만, 5초가 지나기 전에 동시에 localhost:8080/left 와 localhost:8080/right 를 요청하게 되면, 데드락 현상이 발생하게 된다. 


테스트


localhost:8080/left 와 localhost:8080/right 를 빠르게 동시에 요청을 하게 되면 Dead-Lock(데드락) 현상을 재현할 수 있는데, 아래와 같이 BLOCKED 상태의 쓰레드가 두 개인 것을 확인 할 수 있다. 

BLOCKED 상태인 쓰레드를 자세히 보자. 

http-nio-8098-exec-4 는 0c28 락이 풀리기를 기다리고 있고 0c28 이 끝나면 0c18 을 실행할 것이다.

http-nio-8098-exec-3 은 0c18 락이 풀리기를 기다리고 있고 0c18 이 끝나면 0c28 를 실행할 것이다. 

두 개의 쓰레드에서 각자 작업을 완료하기 위해서 상대의 작업이 끝나기를 서로 기다리는 상황이다.  


시나리오 2 정리


데드락 상태가 해결되지 못하면 애플리케이션 먹통 상태가 오랜시간 지속 될 수 있다. 

필자가 최근에 MySql Connector Driver 의 특정 버전에서 데드락 현상이 발생하는 버그를 경험하였다. 애플리케이션이 먹통이 되는 원인을 찾지 못해서 오랜시간동안 고생하였는데, 쓰레드 덤프를 분석해보니 아주 쉽게 원인을 찾을 수 있었다. 해결방법은... MySql Connector Driver 를 데드락 현상이 해결된 패치 버전으로 적용해서 심플하게 해결하였다.



글 마무리


이번 글에서는 쓰레드 덤프 분석에 대해서 공부했다. 사실 쓰레드는 너무 중요한 개념이기 때문에 해당 글로 모든 내용을 담기에는 무리가 있다. 나중에 시간이 된다면 쓰레드에 대해서 더 상세하게 글을 남길 예정이다. 또한 JVM, 힙덤프 분석, GC 등 중요한 개념들에 대해서도 반드시 정리를 할 예정이다.  끝!@


http://www.ntu.edu.sg/home/ehchua/programming/java/j5e_multithreading.html

https://d2.naver.com/helloworld/10963

https://www.journaldev.com/1053/java-thread-dump-visualvm-jstack-kill-3-jcmd

keyword
매거진의 이전글 Elastic APM
브런치는 최신 브라우저에 최적화 되어있습니다. IE chrome safari