장애 대응 (jstack·jmap·OOM killer·FD)

2. 핵심 원리

2.1 첫 10분 순서

1·2 는 03 레슨, 3 은 자원 확인, 4~6 이 이 레슨의 본문입니다. 덤프를 남기기 전에는 재시작하지 않는 것이 원칙입니다.

2.2 jps 와 jcmd 목록

JDK 도구는 대상 JVM 의 PID 가 필요합니다. jps -l 이 자바 프로세스만 클래스·jar 이름과 함께 보여 줍니다.

jps -l                          # 12345 /opt/myapp/current/app.jar
jcmd 12345 help                 # 그 JVM 이 받는 진단 명령 목록
jcmd 12345 VM.flags             # 실제 적용된 JVM 옵션

도구는 JVM 과 같은 사용자로 실행해야 붙습니다. myapp 계정으로 뜬 앱은 sudo -u myapp jstack PID 로 봅니다.

2.3 jstack 스레드 덤프

jstack PID 가 모든 스레드의 상태와 스택을 출력합니다. 한 장으로는 순간이고, 5초 간격으로 세 장을 찍어 같은 스택이 계속 보이는 스레드를 찾습니다.

for i in 1 2 3; do jstack 12345 > td$i.txt; sleep 5; done
grep -oE 'java.lang.Thread.State: [A-Z_]+' td1.txt | sort | uniq -c | sort -rn

BLOCKED 가 수십 개면 잠금 경합, RUNNABLE 이 많고 스택이 같은 코드면 그 코드가 CPU 를 먹는 것입니다. 덤프 뒤쪽의 Found one Java-level deadlock 은 데드락 자동 감지입니다.

2.4 잠금 관계 읽기

덤프의 - locked <주소> 와 - waiting to lock <주소> 로 누가 잡고 누가 기다리는지 이어집니다.

"lock-holder"  ... TIMED_WAITING
   - locked <0x00000000ffc57c30> (a java.lang.Object)
"lock-waiter"  ... BLOCKED (on object monitor)
   - waiting to lock <0x00000000ffc57c30> (a java.lang.Object)

같은 주소를 grep 하면 잡은 스레드 하나와 기다리는 스레드 여럿이 나옵니다. 잡은 스레드의 스택 맨 위가 원인 코드입니다. DB 커넥션 풀 고갈은 HikariPool 스택에서 WAITING 인 스레드가 많은 형태로 보입니다.

2.5 CPU 먹는 스레드 찾기

top -H -p PID 가 스레드별 CPU 를 보여 줍니다. 그 TID 를 16진수로 바꾸면 덤프의 nid 와 일치합니다.

top -H -p 12345 -b -n 1 | head -n 12     # TID 열, %CPU 순
printf '%x\n' 12389                      # 12389 -> 3065
grep -A10 'nid=0x3065' td1.txt           # 그 스레드의 스택

JDK 21 리눅스는 nid=0x3065 형식이고 Windows 는 10진수로 찍힙니다. 이 세 줄이 "CPU 100% 인데 어느 코드인가" 를 1분 안에 답합니다.

2.6 힙 상태 보기

jstat -gcutil PID 1초 횟수 가 영역별 사용률과 GC 횟수·시간을 주기적으로 찍습니다.

jstat -gcutil 12345 1000 5

O 가 90% 이상에서 안 내려오고 FGC 가 초마다 늘면 힙이 찬 것입니다. 앱은 살아 있지만 GC 만 돌아 응답이 없는 상태로, 곧 OutOfMemoryError 가 납니다.

2.7 무엇이 힙을 채우나

jmap -histo:live PID 가 클래스별 인스턴스 수와 바이트를 큰 순서로 보여 줍니다. :live 는 Full GC 를 먼저 돌려 살아 있는 객체만 셉니다.

jmap -histo:live 12345 | head -n 15

 num     #instances         #bytes  class name
   1:          2829       52588720  [B
   2:           138         160824  [C
   3:           780          97344  java.lang.Class

[B 는 byte[], [C 는 char[] 입니다. 상위에 앱 클래스나 HashMap$Node 가 수백만 개면 캐시나 컬렉션 누수입니다. 원인 클래스가 보이면 그 객체를 누가 잡고 있는지는 힙 덤프로 봅니다.

2.8 힙 덤프

힙 덤프는 힙 전체를 파일로 씁니다. 크기가 힙과 같고 쓰는 동안 앱이 멈추므로 운영에서는 신중히 찍습니다.

jcmd 12345 GC.heap_dump /var/log/myapp/heap.hprof
jmap -dump:live,format=b,file=heap.hprof 12345      # 같은 결과

분석은 서버가 아니라 PC 의 Eclipse MAT 이나 VisualVM 에서 합니다. scp 로 내려받아 "Leak Suspects" 보고서를 보면 가장 큰 객체 트리가 나옵니다. 04 레슨의 HeapDumpOnOutOfMemoryError 옵션이 OOM 순간에 이 파일을 자동으로 남깁니다.

2.9 JVM OOM 과 커널 OOM

같은 "메모리 부족" 이지만 둘은 전혀 다릅니다. 증거가 다르고 대책도 다릅니다.

-Xmx 를 RAM 에 가깝게 주면 힙 밖 메모리까지 합쳐 RAM 을 넘어 커널이 JVM 을 죽입니다. 04 레슨에서 RAM 의 50~70% 를 권한 이유입니다.

2.10 OOM killer 확인

dmesg -T | grep -iE 'killed process|out of memory'
journalctl -k --since '2 hours ago' | grep -i oom
systemctl status myapp | grep -E 'code=|status='

Killed process 12345 (java) total-vm:... anon-rss:... 줄이 증거입니다. anon-rss 가 그때 JVM 이 쓰던 실제 메모리입니다. journalctl -u myapp 에 Main process exited, code=killed, status=9/KILL 이 같이 보입니다.

2.11 파일 디스크립터

소켓, 파일, 파이프가 모두 FD 입니다. 한도를 넘으면 Too many open files 로 새 연결과 파일 열기가 실패합니다.

ls /proc/12345/fd | wc -l                    # 현재 열린 수
cat /proc/12345/limits | grep 'open files'   # 상한
lsof -p 12345 | awk '{print $NF}' | sort | uniq -c | sort -rn | head -n 5
ss -tnp | grep -c 'pid=12345'                # 소켓 수

상한은 systemd 유닛의 LimitNOFILE 이 정합니다. 03 레슨에서 65536 을 권한 이유입니다. 현재 수가 계속 늘면 닫지 않는 스트림이나 커넥션이 있는 것이고, lsof 의 파일 이름이 어느 코드인지 알려 줍니다.

2.12 기록과 재발 방지

덤프를 남겼으면 재시작하고, 그다음 기록합니다. 기록이 없으면 다음 장애에서 처음부터 다시 합니다.

덤프 파일은 날짜를 붙여 /var/log/myapp/incident/ 에 모으고, 06 레슨의 cron 으로 30일 뒤 지웁니다.