Thread Dump

동기

• 사내에서 사용하는 Confluence 애플리케이션의 갑작스런 다운
• 사내 영업정보 시스템 성능 저하 이슈

---

스레드 덤프를 한 번만 획득하면 될 줄 알았는데 스레드 상태 변화를 확인하기 위해 5초 정도의 간격으로 여러 번(5~10회) 획득하는 것이 좋다고 한다. 필자는 스레드 덤프 한 번 획득 후, 애플리케이션 재기동을 했다...명심하도록 하자.

필자는 jstack을 이용하여 스레드 덤프를 획득했는데 리더님께서 kill도 가능하다고 말씀하셨다. 그래서 해당 방법을 정리하였다.

1. jstack 사용 먼저 OS 내에서 실행 중인 Java 애플리케이션 프로세스를 확인한다.

jps -v

필자는 Confluence 프로세스만 확인하면 됐기에 다음과 같이 입력하였다.

jps -v | grep confluence

이를 통해 프로세스 ID를 확인하고 jstack 인수로 PID(프로세스 ID)를 넣어 스레드 덤프를 획득한다. PID가 10975라면 아래와 같이 입력한다.

jstack 10975

여기서 주의할 점은 "thread dump가 어디에 생성되는가?" 이다. 위 명령어만 입력했을 경우 STDOUT(표준 출력)으로 출력된다. 그렇기에 명령어만 입력한다고 현재 경로에 떡하니 스레드 덤프가 생성되는건 아니다. 필자의 경우 WAS(Web Application Server)이기에 로그 파일(catlina.out)에 남게 된다.

따라서 이를 로그 파일로 관리하고자 할 때는 다음과 같이 입력한다.

jstack 10975 > thread_dump_20200730.log

2. kill 사용 위 방법 그대로 PID를 확인한다. (여기선 jps 말고 ps 명령어를 사용하였다. ps 명령어가 옵션을 모두 보여주는 것 같다.)

ps -ef | grep confluence

PID가 10975라면 아래와 같이 입력한다.

kill -3 10975

여기서 옵션 -3에서 3은 SIGQUIT이나 SIGOUT으로 "kill -l"을 통해 확인할 수 있다. 물론 이 명령어도 STDOUT으로 출력되어 (필자의 경우) 로그 파일에 남게된다.

이렇게 획득한 스레드 덤프를 보게되면...특히 처음 보게 된다면 겁먹지 말자. 데이터를 읽는 방법만 알면 어렵지 않다.

2020-07-23 12:54:00
Full thread dump OpenJDK 64-Bit Server VM (25.181-b13 mixed mode):

"Attach Listener" #10081 daemon prio=9 os_prio=0 tid=0x00007fff842a4800 nid=0x163ad waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"Structure-Jobs6087270f Queue-Thread#1170" #10080 daemon prio=5 os_prio=0 tid=0x00007fff28153000 nid=0x162e0 waiting on condition [0x00007ffe7c0d1000]
   java.lang.Thread.State: TIMED_WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000006d362b858> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
	at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
	at com.almworks.structure.commons.job.PooledStructureJobManager$JobThread.run(PooledStructureJobManager.java:502)

   Locked ownable synchronizers:
	- None

"mondrian.rolap.agg.SegmentCacheManager$sqlExecutor_14" #9642 daemon prio=5 os_prio=0 tid=0x00007fff0c3a8800 nid=0x9d1a waiting on condition [0x00007ffe7b8cb000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000006fa7fe0e8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
	at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

   Locked ownable synchronizers:
	- None

"pool-84-thread-1" #1869 prio=5 os_prio=0 tid=0x00007ffed067e800 nid=0x313ea runnable [0x00007ffe8accc000]
   java.lang.Thread.State: RUNNABLE
	at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
	at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
	at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
	at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
	- locked <0x0000000707e84b10> (a sun.nio.ch.Util$3)
	- locked <0x0000000707e84b00> (a java.util.Collections$UnmodifiableSet)
	- locked <0x0000000707e84918> (a sun.nio.ch.EPollSelectorImpl)
	at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
	at org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor.execute(Unknown Source)
	at org.apache.http.impl.nio.conn.PoolingNHttpClientConnectionManager.execute(Unknown Source)
	at org.apache.http.impl.nio.client.CloseableHttpAsyncClientBase$1.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)

   Locked ownable synchronizers:
	- None

"Thread-805" #1868 daemon prio=5 os_prio=0 tid=0x00007ffed065c800 nid=0x313e9 in Object.wait() [0x00007ffe96e3b000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	at com.c.a.a.d.e.run(Unknown Source)
	- locked <0x0000000707e82620> (a com.c.a.a.d.e)

   Locked ownable synchronizers:
	- None

"JRubyWorker-8" #1519 daemon prio=5 os_prio=0 tid=0x00007fff5004a000 nid=0x16c3 waiting on condition [0x00007ffe8ccce000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000006edf6eb10> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1081)
	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

   Locked ownable synchronizers:
	- None

• 읽는 법
• 스레드 상태
• 락

참고0