제리의 배움 기록

[Java] JVM 성능 모니터링을 제공하는 JDK 기본 툴 본문

자바

[Java] JVM 성능 모니터링을 제공하는 JDK 기본 툴

제리92 2021. 12. 7. 18:01

JDK에서는 개발 및 운영을 위해 기본 툴을 제공합니다.
Java 홈디렉토리의 bin에 툴이 포함되어있습니다.

1.java home path 찾기

root@ureasolution:~# echo $JAVA_HOME
/usr/lib/jvm/java-1.11.0-openjdk-amd64

2.Java 홈디렉토리의 bin 경로로 이동

root@ureasolution:~# cd /usr/lib/jvm/java-1.11.0-openjdk-amd64
root@ureasolution:/usr/lib/jvm/java-1.11.0-openjdk-amd64# cd bin

3.bin 안의 도구들 확인 (JDK 11 기준)

root@ureasolution:/usr/lib/jvm/java-1.11.0-openjdk-amd64/bin# ls -al
total 500
drwxr-xr-x 2 root root   4096 Nov 22 20:30 .
drwxr-xr-x 9 root root   4096 Nov 22 20:30 ..
-rwxr-xr-x 1 root root  10376 Apr 21  2021 jaotc
-rwxr-xr-x 1 root root  10320 Apr 21  2021 jar
-rwxr-xr-x 1 root root  10320 Apr 21  2021 jarsigner
-rwxr-xr-x 1 root root  10304 Apr 21  2021 java
-rwxr-xr-x 1 root root  10352 Apr 21  2021 javac
-rwxr-xr-x 1 root root  10352 Apr 21  2021 javadoc
-rwxr-xr-x 1 root root  10320 Apr 21  2021 javap
-rwxr-xr-x 1 root root  10320 Apr 21  2021 jcmd
-rwxr-xr-x 1 root root  10368 Apr 21  2021 jconsole
-rwxr-xr-x 1 root root  10320 Apr 21  2021 jdb
-rwxr-xr-x 1 root root  10320 Apr 21  2021 jdeprscan
-rwxr-xr-x 1 root root  10320 Apr 21  2021 jdeps
-rwxr-xr-x 1 root root  10320 Apr 21  2021 jfr
-rwxr-xr-x 1 root root  10320 Apr 21  2021 jhsdb
-rwxr-xr-x 1 root root  10320 Apr 21  2021 jimage
-rwxr-xr-x 1 root root  10352 Apr 21  2021 jinfo
-rwxr-xr-x 1 root root  10352 Apr 21  2021 jjs
-rwxr-xr-x 1 root root  10352 Apr 21  2021 jlink
-rwxr-xr-x 1 root root  10352 Apr 21  2021 jmap
-rwxr-xr-x 1 root root  10320 Apr 21  2021 jmod
-rwxr-xr-x 1 root root  10320 Apr 21  2021 jps
-rwxr-xr-x 1 root root  10352 Apr 21  2021 jrunscript
-rwxr-xr-x 1 root root  10320 Apr 21  2021 jshell
-rwxr-xr-x 1 root root  10352 Apr 21  2021 jstack
-rwxr-xr-x 1 root root  10320 Apr 21  2021 jstat
-rwxr-xr-x 1 root root  10320 Apr 21  2021 jstatd
-rwxr-xr-x 1 root root  10320 Apr 21  2021 keytool
-rwxr-xr-x 1 root root  10320 Apr 21  2021 pack200
-rwxr-xr-x 1 root root  10320 Apr 21  2021 rmic
-rwxr-xr-x 1 root root  10320 Apr 21  2021 rmid
-rwxr-xr-x 1 root root  10320 Apr 21  2021 rmiregistry
-rwxr-xr-x 1 root root  10320 Apr 21  2021 serialver
-rwxr-xr-x 1 root root 107408 Apr 21  2021 unpack200

사용 해보기

최근 개발한 요소수소문 서비스를 대상으로 툴을 사용해 보았습니다.

메모리 측정 관련 도구

jps

현재 실행되고 있는 JVM 프로세스 확인

  • 28140 pid로 요소수소문 서비스가 구동중인 것을 확인
  • root@ureasolution:/usr/lib/jvm/java-1.11.0-openjdk-amd64/bin# jps 6483 Jps 28140 ureasolution-0.0.1-main.jar

[옵션]

  • q : main 메서드로 전달된 class, jar, 파라미터들을 출력하지 않음 => pid만 출력
root@ureasolution:/usr/lib/jvm/java-1.11.0-openjdk-amd64/bin# jps -q
9001
28140
  • m : main 메서드로 전달된 파라미터를 포함하여 출력
root@ureasolution:/usr/lib/jvm/java-1.11.0-openjdk-amd64/bin# jps -m
9024 Jps -m
28140 ureasolution-0.0.1-main.jar --spring.config.name=application-prod
  • l : main class 혹은 jar의 full name 출력 => 실행파일의 경로를 포함하여 출력
root@ureasolution:/usr/lib/jvm/java-1.11.0-openjdk-amd64/bin# jps -l
9042 jdk.jcmd/sun.tools.jps.Jps
28140 /[경로]/ureasolution-0.0.1-main.jar
  • v : 프로세스 실행시 JVM으로 전달한 파라미터를 포함하여 출력
root@ureasolution:/usr/lib/jvm/java-1.11.0-openjdk-amd64/bin# jps -v
9072 Jps -Dapplication.home=/usr/lib/jvm/java-11-openjdk-amd64 -Xms8m -Djdk.module.main=jdk.jcmd
28140 ureasolution-0.0.1-main.jar

jstack

Thread의 스택 정보를 보기 위해 주로 사용

[옵션]

  • l : 추가적인 lock 정보를 포함하여 출력
  • m : mixed mode. java stack 정보뿐 아니라 JNI를 통해 실행하는 C/C++ 네이티브 메서드의 stack까지 포함하여 출력
root@ureasolution:/usr/lib/jvm/java-1.11.0-openjdk-amd64/bin# jstack -l 28140
2021-12-07 17:54:19
Full thread dump OpenJDK 64-Bit Server VM (11.0.11+9-Ubuntu-0ubuntu2.18.04 mixed mode, sharing):

Threads class SMR info:
_java_thread_list=0x00007fd1f000e870, length=39, elements=ä
0x00007fd23011f000, 0x00007fd230121000, 0x00007fd230126800, 0x00007fd230128800,
0x00007fd23012a800, 0x00007fd23012d000, 0x00007fd23012f000, 0x00007fd23016a000,
0x00007fd23079c800, 0x00007fd230a13800, 0x00007fd230a32800, 0x00007fd230a34800,
0x00007fd230a44800, 0x00007fd231405800, 0x00007fd2317c0000, 0x00007fd2317c1800,
0x00007fd23135e000, 0x00007fd230016800, 0x00007fd1fc004800, 0x00007fd1fc005800,
0x00007fd1fc007000, 0x00007fd1fc009000, 0x00007fd1fc00b000, 0x00007fd1fc00c000,
0x00007fd1fc00d800, 0x00007fd1fc00f800, 0x00007fd1fc011800, 0x00007fd1fc013000,
0x00007fd20400b800, 0x00007fd20400d000, 0x00007fd20400e000, 0x00007fd20400f800,
0x00007fd204011800, 0x00007fd204013000, 0x00007fd204014000, 0x00007fd204015800,
0x00007fd204017000, 0x00007fd204019000, 0x00007fd1e8025800
å

"Reference Handler" #2 daemon prio=10 os_prio=0 cpu=7.65ms elapsed=422027.01s tid=0x00007fd23011f000 nid=0x6df4 waiting on condition  Ä0x00007fd21013e000Å
   java.lang.Thread.State: RUNNABLE
    at java.lang.ref.Reference.waitForReferencePendingList(java.base@11.0.11/Native Method)
    at java.lang.ref.Reference.processPendingReferences(java.base@11.0.11/Reference.java:241)
    at java.lang.ref.Reference$ReferenceHandler.run(java.base@11.0.11/Reference.java:213)

   Locked ownable synchronizers:
    - None

"Finalizer" #3 daemon prio=8 os_prio=0 cpu=0.74ms elapsed=422027.01s tid=0x00007fd230121000 nid=0x6df5 in Object.wait()  Ä0x00007fd2037fe000Å
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(java.base@11.0.11/Native Method)
    - waiting on <0x00000000c29c1418> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(java.base@11.0.11/ReferenceQueue.java:155)
    - waiting to re-lock in wait() <0x00000000c29c1418> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(java.base@11.0.11/ReferenceQueue.java:176)
    at java.lang.ref.Finalizer$FinalizerThread.run(java.base@11.0.11/Finalizer.java:170)

   Locked ownable synchronizers:
    - None

"Signal Dispatcher" #4 daemon prio=9 os_prio=0 cpu=0.43ms elapsed=422027.01s tid=0x00007fd230126800 nid=0x6df6 runnable  Ä0x0000000000000000Å
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
    - None

"Service Thread" #5 daemon prio=9 os_prio=0 cpu=0.15ms elapsed=422027.01s tid=0x00007fd230128800 nid=0x6df7 runnable  Ä0x0000000000000000Å
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
    - None

jstat

JVM 성능을 통계내는 툴 입니다.

[옵션]

  • class
    클래스 로더 수행내역 분석
  • compiler
    HotSpot(JIT) 컴파일러 수행내역 분석
  • gc
    heap에서 gc를 수행한 내역 분석
  • printcompilation
    HotSpot 컴파일러가 컴파일한 메서드 내역 분석

jmap

현재 실행중인 프로세스의 JVM 메모리 맵을 보여주는 분석 도구

[옵션]

  • jmap -clstats
    • 프로세스의 클래스 로더를 분석
root@ureasolution:/usr/lib/jvm/java-1.11.0-openjdk-amd64/bin# jmap -clstats 28140
Index Super InstBytes KlassBytes annotations    CpAll MethodCount Bytecodes MethodAll    ROAll    RWAll    Total ClassName
    1    -1   5997536        504           0        0           0         0         0       24      616      640 ÄB
    2    11   1771320        624         128    14272         109      4576     71248    20576    67440    88016 java.lang.String
    3    11   1675456        680           0    22120         139      5679     87664    28040    84896   112936 java.lang.Class
    4    11   1630784        600           0     1368           9       213      2880     1632     3592     5224 java.util.concurrent.ConcurrentHashMap$Node
    5    -1   1552848        504           0        0           0         0         0       24      616      640 ÄC
    6    -1   1046088        504           0        0           0         0         0       24      616      640 ÄI
    7  6837    987184       1200           0     6824          47      1117     27936     7024    29872    36896 java.lang.reflect.Method
    8    -1    734728        504           0        0           0         0         0       24      616      640 ÄLjava.lang.Object;
    9    13    514640        592           0      512           1        10       624      312     1656     1968 java.util.LinkedHashMap$Entry
   10    -1    486056        504           0        0           0         0         0       32      616      648 ÄLjava.util.concurrent.ConcurrentHashMap$Node;
   11    -1    474928        528           0     1280          14       109      4704     1624     5184     6808 java.lang.Object
   12    -1    450952        504           0        0           0         0         0       32      616      648 ÄLjava.util.HashMap$Node;
   13    11    432064        592           0     1392           7       149      2296     1200     3432     4632 java.util.HashMap$Node
   14    25    315504       1136           0     3816          26       879     14360     5048    14984    20032 java.util.LinkedHashMap
   15    -1    212496        504           0        0           0         0         0       56      616      672 ÄLjava.lang.Class;
   16  7422    131640        872           0     2992          10       259      4464     1768     6920     8688 org.springframework.boot.loader.jar.JarEntry
   17    11    126288        584           0    11528          89      4308     56216    16648    53400    70048 java.lang.invoke.MemberName
   18  6829    117520        568           0      696           3        56      1888      504     2848     3352 java.lang.ref.SoftReference
   19    11    109584        552          72     1512           6       242      4704     1296     5792     7088 org.springframework.core.MethodClassKey
   20  7185     96144       1448           0     7008          64      2677     39552    12392    36872    49264
  • jmap -finalizerinfo
    • 프로세스의 JVM 힙에서 finalization 대기중인 객체 정보 출력
  • jmap -histo[:live]
    • 프로세스의 JVM 힙에 있는 객체 정보를 히스토그램화 하여 출력(live 옵션이 붙으면 살아있는 객체만을 대상으로함)
    • 가장 많이 메모리를 점유한 객체부터 데이터를 출력
    • 특정 객체가 비정상적으로 많이 생성되어있고 숫자가 지속적으로 늘어난다면 메모리 누수를 유추해볼 수 있음
 root@ureasolution:/usr/lib/jvm/java-1.11.0-openjdk-amd64/bin# jmap -histo:live 28140
 num     #instances         #bytes  class name (module)
-------------------------------------------------------
   1:         82066        5988008  [B (java.base@11.0.11)
   2:         73846        1772304  java.lang.String (java.base@11.0.11)
   3:         14129        1674000  java.lang.Class (java.base@11.0.11)
   4:         51683        1653856  java.util.concurrent.ConcurrentHashMap$Node (java.base@11.0.11)
   5:          4836        1496072  [C (java.base@11.0.11)
   6:          6993        1045272  [I (java.base@11.0.11)
   7:         10878         957264  java.lang.reflect.Method (java.base@11.0.11)
   8:         11468         732896  [Ljava.lang.Object; (java.base@11.0.11)
   9:           402         485704  [Ljava.util.concurrent.ConcurrentHashMap$Node; (java.base@11.0.11)
  10:         29681         474896  java.lang.Object (java.base@11.0.11)
  ...
  • jmap -dump:
    • 프로세스의 JVM heap에 대해 덤프를 생성
    • root@ureasolution:/usr/lib/jvm/java-1.11.0-openjdk-amd64/bin# jmap -dump:format=b,file=heapdump.hprof 28140
    • 생성된 dump 파일은 외부 툴을 이용해서 분석해볼 수 있습니다.
      • jdk에 포함되어있던 jhat으로 분석할 수 있었는데 jdk 9 버전부터 jhat이 제외되었습니다.
      • (JEP 241 - jhat is an experimental, unsupported, and out-of-date tool.)
      • jhat은 jdk 6에 포함되었던 툴인데, 현재는 우수한 다른 툴들이 많이 나와서 거의 사용하지 않는 툴이 되었기에 제외되었다고 합니다.

VisualVM

  • dump 파일 분석 툴
  • jdk 기본 툴은 아니지만 생성한 dump 파일을 분석하기에 좋은 툴입니다.

VisualVM 다운로드

 

[참고]

programmer.help
oracle docs - jstat

Comments