본문 바로가기
Java/Advanced

JAVA 스레드 덤프와 VisualVM (1) / Thread Dump, VisualVM, Sampler/Profiler, FastThread.io

by BestUgi 2020. 6. 17.

이 글은 자바로 작성된 프로그램(프로세스)에 대해서 아래의 질문에 대한 힌트를 찾기 위한 방법을 설명하고자 작성되었다.

프로그램이 잘 실행되고 있는 것인가?
왜 프로그램의 특정 기능이 응답이 없지?
왜 프로그램이 멈춰 있지?
왜 프로그램의 성능(응답)이 느리지?
왜 프로그램이 CPU를 많이 사용할까?
프로그램의 성능을 향상할 수 있는 방법이 있을까?
프로그램의 CPU 자원 사용량이 많은 코드를 찾을 수 있을까?

자바의 스레드와 관련된 이슈를 해결하거나 모니터링을 위해서는 자바 스레드의 동작 방식을 이해하고 다양한 분석 툴을 손쉽게 다룰 줄 알아야 한다. 스레드 모니터링을 위해서 알아야 할 스레드의 기본적인 개념들과 모니터링 툴을 사용하여 분석하는 방법에 대해서 공유하고자 한다.

  •  자바 기본 스레드의 종류와 역할
  • 스레드의 상태 변화
  • VisualVMThread 탭과 Smapling, Profiling
  • 스레드 덤프 방법 및 분석
  • FastThread.io를 활용한 분석

참고로 JDK 1.8(Java 8, Oracle Hotspot)을 기준으로 설명한다.

 

자바 기본(Core) 스레드의 종류와 역할

자바 스레드는 데몬(Daemon) 스레드와 일반 스레드로 분류된다. 데몬 스레드는 일반 스레드가 모두 종료할 경우 사라지는 스레드이다. 즉, 일반 스레드가 하나 이상 존재할 경우 JVM은 종료하지 않지만, 일반 스레드가 모두 종료한 경우(데몬스 레드가 동작 중이어도) JVM은 종료한다. 개발자가 스레드를 생성할 당시에는 일반 스레드이며, 간단한 스레드 속성 변경을 통해서 데몬 스레드로 변경 가능하다.

...
Thread t = new Thread(new MyRunnable());
t.setDaemon(true);
t.start();
...

JVM(Oracle Hotspot)을 실행하면 기본적으로 수행되는 자바 스레드가 있는데 각각의 역할에 대해서 알아보도록 하자.

기본 스레드 역할
Compiler Thread 실시간에 바이트코드를 바이너리 코드로 컴파일(JIT) 수행하는 스레드이다.
Attach Listner 모니터링 혹은 디버깅을 위해 외부 접속을 대기하는 스레드
Signal Dispatcher 외부에서 JVM 프로세스로 전달되는 시그널을 처리하기 위한 스레드이다.
Finalizer 인스턴스들이 회수되기 전에 finalize() 함수를 호출하는 스레드.
Reference Handler Garbage Collector에 의해서 발견되는 weak, soft, phantom reference들을 ReferenceQueue에 추가하는 스레드.
main main() 함수를 실행하는 스레드.
VM Thread JVM이 safe한 상태가 되기를 기다리는 스레드이다. Garbage collection이나 스레드 덤프와 같은 작업을 하기 전에 "Stop the world" 상태를 기다리는 스레드가 VM Thread인 것이다.
GC Thread 실제 Garbage Collection을 수행하는 스레드이다.
VM Periodic Task Thread 주기적으로 수행되는 실행들을 위한 타이머 이벤트를 담당한다. Samping과 Profiling 수행시에 가장 많이 사용된다고 한다.

 

자바 스레드의 상태(Thread's State)

스레드가 현재 어떠한 동작을 취하고 있느냐에 따라서 스레드의 상태를 구분할 수 있는데 java.lang.Thread.State에서 열거형 타입(Enum, Java 5부터)으로 정의되어 있으며, 자바 스레드는 한순간에 오직 하나의 상태만을 가질 수 있다. 아래의 Java 코드에서처럼 getState() API를 사용하여 현재 스레드의 상태를 확인할 수 있다.

    Thread t = new Thread(new MyRunnable());
    t.start();
	
    ...
    
    State s = t.getState();
    
    switch (s) {
      case NEW:
      ...
        break;
      case RUNNABLE:
      ...
        break;
      case BLOCKED:
      ...
        break;
      case WAITING:
      ...
        break;
      case TIMED_WAITING:
      ...
        break;
      case TERMINATED:
      ...
        break;
    }

위의 코드에서 처럼 getState() API를 사용해 현재 스레드의 상태를 알고 그에 맞게 적절한 처리를 할 수 있는 코드(SWITCH 문)를 작성할 수 있을 것이다. 그렇다면, Switch 문에서 나열하고 있는 스레드의 각 상태의 의미에 대해서 알아보도록 하자.

State 설명
NEW new Thread()로 새롭게 생성된 스레드이며 아직 시작되지 않은 상태(Thread.start() 호출 전)를 의미한다.
RUNNABLE CPU를 점유하여 동작 할 수 있는 상태이다.

이는 두 가지 의미를 지니는데, CPU를 점유하여 이미 동작하고 있는 상태(Running)이거나 CPU를 할당 받기 위해서 대기하고 있는 상태(Runnable)를 의미한다.  Runnable을 쉽게 표현하면 CPU가 부족(다른 스레드가 모두 선점(사용) 중)해서 CPU를 할당 받기 위해 대기하고 있는 스레드일 것이다. 우리 눈에는 스레드가 항상 동작하고 있는것처럼 보이겠지만 실제로는 CPU는 한정된 자원이고 매우 짧은 간격으로 스레드들이 번갈아가며 사용하는 것이기 때문이다.

파일이나 네트워크 IO 등을 위해 시스템 콜을 호출할때 모니터를 사용하지 않는 상황이라면 RUNNABLE 상태이다. TCP Blocking 읽기를 수행할 떄에도 RUNNABLE 상태라는 것이 아이러니하기도 한데, 이는 JVM이 Navtive Call 수행시 내부에서 어떤 작업을 하는지 파악할 수 없어서 발생하는 현상이다.
BLOCKED 스레드가 객체의 모니터(Synchronized keyword, intrinsic lock, built-in lock)를 획득하기 위해서 대기하는 상태이다. 또한, Object.wait()와 같은 동기화 함수에서 반환될때도 객체의 모니터를 획득해야 하는데 이때의 상태도 포함한다.
WAITING 다른 스레드의 의해 생성된 이벤트를 대기하는 상태이며 아래의 목록을 확인하자.
  - Object.wait() : 다른 스레드가 Object.notify(), Object.notifyAll() 호출할 때까지 대기한다.
  - Thread.join() : 다른 사르드가 종료될 때까지 대기한다.
  - LockSupport.park() : 다른 스레드가 LockSupport.unpark()를 호출할 때까지 대기한다.
TIMED_WAITING 스레드가 지정된 시간만큼(까지) 대기하고 있는 상태인데 Thread.slepp(timeout), Object.wait(timeout), Thread.join(timeout), LockSupport.parkNano(nanos), LockSupport.parkUtil(deadline) API에 의해서 발생할 수 있다.
TERMINATED 스레드의 메인 함수(call() in Callable, run() in Runnable)가 완료 된 상태이다. 이는 의도한바에 의해 종료되거나 예외나 에러에 의해서 종료된 상태일 수 있다.

각 스레드 상태별 전이를 그래프로 표현하면 아래와 같다. (출처)

[그림 1] 스레드 상태의 변환

[그림 1]에서 TERMINATED 된 스레드는 다른 상태로의 전이가 될 수 없는데 이는 TERMINATED 스레드를 재사용할 수 없음을 의미한다. 스레드를 재사용하기 위해서는 Runnable, Callable 인터페이스를 구현하여 스레드 풀을 사용하는 방향으로 작성해야 할 것이다.

 

BLOCKED와 WAITING(TIMED_WAITING)의 차이는 Monitor를 획득하기 위해서 기다리는 것인지 아닌지에 따라서 구분된다. 다른 스레드가 notify()를 호출할 경우, WAITING(Object.wait()) 상태에서  바로 RUNNABLE이 되는 것이 아니라 다시 모니터를 획득해야 하는데 이때 다른 스레드가 먼저 모니터를 획득한 경우라면 다시 BLOCKED 상태가 된다.

 

[그림 2] BLOCKED와 WAITING(TIMED_WAITING)의 관계

위의 [그림 2]는 두 개의 Producer(Producer-1, Producer-2) 스레드와 하나의 Consumer(Consumer-1) 스레드가 waiter 오브젝트에 대해서 모니터를 획득하고 동작하는 과정에서의 발생할 수 있는 상태 변화를 보여준다. 빨간색 점선 박스에서 Consumer가 waiter.notify()로 깨어나는 즉시 monitor를 반환(Release monitor)하는데 이때 운영체제의 스케줄링 여건에 따라서 Producer-2가 먼저 waiter 객체의 monitor를 획득 할 수 있는 상황이 발생할 수 있다. 이 경우, Producer-1은 WAITING상태에서 notify()에 의해 깨어나지만 여전히 monitor를 획득할 수 없어서(Producer-2가 선점 하였으므로) BLOCKED 상태로 변경된다.

스택 덤프(Stack Dump) 방법

자바 스레드의 종류와 상태에 대해서 어느 정도 알게 되었으니, 이제는 JVM에서 동작중인 모든 스레드에 대한 Stack Trace를 확인하기 위해 Stack Dump 방법에 대해서 알아보자.

 

JDK의 Utility를 사용하는 방법

JDK가 설치된 경우엔 스택 덤프를 매우 다양한 방법으로 확인 가능하다.

 

우선 현재 스택 덤프를 확인하기 위한 자바 프로세스의 PID를 조회하자.

jps -v

 

[방법 1] jcmd CLI를 사용하여 스레드의 스택 덤프를 확인할 수 있다.

jcmd [PID] Thread.print > thread.dump

lock과 관련된 추가 정보를 얻기 위해서는 '-l' 옵션을 사용하면 된다.

jcmd [PID] Thread.print -l > thread.dump

 

[방법 2] jstack CLI를 사용하여 스레드의 스택 덤프를 확인할 수 있다.

jstack [PID] >> thread.dump

lock과 관련된 추가 정보를 얻기 위해서는 '-l' 옵션을 사용하면 된다.

jstack -l [PID] > thread.dump

 

[방법 3] jconsole GUI를 사용하여 각 스레드의 스택 덤프를 확인할 수 있다.

[방법 4] jvisualvm GUI를 사용하여 스택 덤프를 확인할 수 있다. 'Thread Dump' 버튼을 누르면 전체 스레드에 대한 스택 덤프가 출력된다.

 

JDK의 Utility를 사용하지 않는 방법

JRE만 설치되어 있거나 JDK의 Utility를 사용하지 않고도 스택 덤프를 확인할 수 있다.

 

LINUX, UNIX 계열에서는 'kill' 명령어를 사용하여 확인 가능하다.

kill -3 [PID]

자바 프로그램을 실행한 터미널에서 stdout으로 출력될 것이고, stdout이 리다이렉트 된 경우엔 해당 파일을 확인하면 된다.

 

Windows에서는 자바를 실행한 cmd나 powershell 창에서 'Ctrl' + 'Break' 키를 입력하면 스택 덤프를 확인할 수 있다. 다만, 해당 자바 프로그램이 백그라운드로 동작할 경우에는 동작하지 않으니 사용에는 약간의 제약 사항이 따를 수밖에 없다.

 

자바 스택 덤프 분석 (With FastThread.io)

이제 위에서 언급한 방식으로 스택 덤프의 출력 결과를 확인해보자.

5424:
2020-06-16 22:01:00
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.251-b08 mixed mode):

"Service Thread" #10 daemon prio=9 os_prio=0 tid=0x000000001ef3d000 nid=0x3788 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C1 CompilerThread3" #9 daemon prio=9 os_prio=2 tid=0x000000001eea5000 nid=0x3b88 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread2" #8 daemon prio=9 os_prio=2 tid=0x000000001ee9f000 nid=0x1284 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" #7 daemon prio=9 os_prio=2 tid=0x000000001ee9b000 nid=0x3b1c waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #6 daemon prio=9 os_prio=2 tid=0x000000001ee49000 nid=0x2e70 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Attach Listener" #5 daemon prio=5 os_prio=2 tid=0x000000001ee47000 nid=0x196c waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" #4 daemon prio=9 os_prio=2 tid=0x000000001ee94800 nid=0x23e0 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" #3 daemon prio=8 os_prio=1 tid=0x0000000003679000 nid=0x1788 in Object.wait() [0x000000001f30e000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x000000076c408ee0> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(Unknown Source)
	- locked <0x000000076c408ee0> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(Unknown Source)
	at java.lang.ref.Finalizer$FinalizerThread.run(Unknown Source)

"Reference Handler" #2 daemon prio=10 os_prio=2 tid=0x0000000003678000 nid=0xeec in Object.wait() [0x000000001ee0f000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x000000076c406c00> (a java.lang.ref.Reference$Lock)
	at java.lang.Object.wait(Unknown Source)
	at java.lang.ref.Reference.tryHandlePending(Unknown Source)
	- locked <0x000000076c406c00> (a java.lang.ref.Reference$Lock)
	at java.lang.ref.Reference$ReferenceHandler.run(Unknown Source)

"main" #1 prio=5 os_prio=0 tid=0x000000000357d800 nid=0x16e4 waiting on condition [0x000000000354f000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
	at java.lang.Thread.sleep(Native Method)
	at my.self.test.Main.main(Main.java:7)

"VM Thread" os_prio=2 tid=0x000000001cf19800 nid=0x3684 runnable 

"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x0000000003597000 nid=0x3998 runnable 

"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x0000000003598800 nid=0x1d9c runnable 

"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x000000000359a000 nid=0x257c runnable 

"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x000000000359c800 nid=0x2c80 runnable 

"GC task thread#4 (ParallelGC)" os_prio=0 tid=0x000000000359e000 nid=0x3770 runnable 

"GC task thread#5 (ParallelGC)" os_prio=0 tid=0x00000000035a0000 nid=0x484 runnable 

"GC task thread#6 (ParallelGC)" os_prio=0 tid=0x00000000035a3000 nid=0x3934 runnable 

"GC task thread#7 (ParallelGC)" os_prio=0 tid=0x00000000035a4800 nid=0xa58 runnable 

"VM Periodic Task Thread" os_prio=2 tid=0x000000001ef54800 nid=0x23cc waiting on condition 

JNI global references: 5

대부분이 JVM의 기본 스레드들로 구성된 스택 덤프이다. 이제 main 스레드에 대해서 각 필드가 의미하는 바에 대해서 살펴보도록 하자.

 

항목 의미
Thread Name 스레드의 이름이며, Thread.setName() 을 사용하여 이름을 변경할 경우 스택 덤프에도 반영된다.
ID JVM내의 각 스레드에 할당된 고유 ID (1부터 시작). Thread.getId()에서 반환하는 값과 동일 하다.
Thread Priority Java 스레드의 우선순위이며 Thread.getPriority()에서 반환하는 값과 동일하다. Thread.setPriority()로 우선순위 조정도 가능하다.
OS Thread Priority 자바의 스레드는 운영체제(OS)의 스레드와 매핑이 되는데(적어도 Oracle Hotspot의 경우), 매핑된 운영체제 스레드의 우선순위이다.
Java-Level Thread ID JVM 내부(JNI 코드)에서 관리하는 Native Thread 구조체의 포인터 주소이다.
Native Thread ID 자바 스레드에 매핑된 OS 스레드의 ID이다. Windows에서는 OS Level의 스레드 ID이며, Linux에서는 LWP(Light Weight Process)의 ID를 의미한다.
Thread State 위의 '스레드 상태'에서 언급한 스레드의 상태이다.
Last Known Java Stack Pointer 스레드의 현재 Stack Pointer(SP)의 주소를 의미한다.
Call Stack 현재 스레드가 수행되는 함수들의 호출 관계(콜 스택)를 표현한다.

 

지금까지 자바의 스레드 스택 덤프를 분석하기 위해 알아야 할 스레드의 개념들과 스택 덤프를 분석하는 방법에 대해서 알아보았다.

 

다음 글에서는 스택 트레이스를 조금 더 쉽게 분석할 수 있는 방법과 VisualVM, Sampler, Profiler에 대한 이야기를 하고자 한다.

 

댓글