JDK 21에서 JFR의 신 기능– JFR View

JMC(Java Mission Control)과 JFR(Java Flight Recorder) 모두 Java VM/어플리케이션 분석에 빼 놓을 수 없는 도구입니다. 그 중 JFR은 GC pause나 custom JFR 이벤트들을 필터링하고 얼마나 많은 이벤트들이 발생하는지 확인할 수 있는 좋은 도구입니다. 그러나, JFR 자체적으로 전체 기록을 확인하는 방법이 없기 때문에, JMC ( Java Mission Control)과 같은 다른 툴을 사용해야만 했습니다.

JMC도 좋은 툴이긴 하지만, JFR 파일을 다운로드하고 JMC를 통해 열어야 읽어야 하는 부담이 있었습니다.

이번에 JDK 21에서 JFR에 몇몇 변화들이 있다는 반가운 뉴스를 듣고 내용을 정리해 보았습니다. 그 중에는 JFR 단독으로 데이터를 확인할 수 있는 JFR View에 대해 알아보겠습니다. 이번 블로그에서는 JDK 21에서의 JFR에 포함되는 변화를 Early Access버전을 통해서 확인해 보도록 하겠습니다.

우선, JFR을 테스트하는데 사용하기 위한 어플을 고민해 보았습니다.

이런 저런 어플을 고려해 보다, JFR의 단짝인 JMC를 테스트용 어플로 사용하기로 결정하였습니다.

JMC 실행

우선 어플에 사용할 JDK 21 ea(early access) 버전을 SDKMAN을 이용하여, 다운로드 하였습니다.

Java.net | | 22.ea.9  | open |           | 22.ea.9-open
         | | 22.ea.8  | open |           | 22.ea.8-open
         | | 22.ea.7  | open |           | 22.ea.7-open
         | | 22.ea.6  | open |           | 22.ea.6-open
         | | 22.ea.5  | open |           | 22.ea.5-open
         | | 22.ea.4  | open |           | 22.ea.4-open
         | | 22.ea.3  | open |           | 22.ea.3-open
         | | 21.ea.34 | open |           | 21.ea.34-open
         | | 21.ea.33 | open |           | 21.ea.33-open
         | | 21.ea.32 | open | installed | 21.ea.32-open
         | | 21.ea.31 | open |           | 21.ea.31-open

Java -version 명령으로 21 ea버전이 동작하는 지, 확인합니다.

$ java -version
openjdk version "21-ea" 2023–09–19
OpenJDK Runtime Environment (build 21-ea+32–2482)
OpenJDK 64-Bit Server VM (build 21-ea+32–2482, mixed mode, sharing)

다음은 JMC를 아래 링크의 JMC 다운로드 사이트를 방문하여 다운로드 하였습니다.

JDK Mission Control (JMC) Downloads

다운로드 한 JMC의 압축을 풀어주고, 실행해 주었습니다.

저의 경우에는 Mac에서 실행이 실패하였고, 아래와 같이 Info.plist를 수정하여, JDK가 설치된 폴더에 대한 정보를 전달한 이후에 실행이 가능하게 되었습니다.

<string>-keyring</string>
<string>~/.eclipse_keyring</string>
<string>-vm</string>
<string>/Users/marvin/.sdkman/candidates/java/current/bin/java</string>

이렇게 실행한 JMC 화면이고, 오른쪽 아래에 JVM 버전도 확인할 수 있습니다.

JFR View 옵션

JFR View 옵션을 사용하기 위해서는 jcmd(J Command) 명령어를 사용하고, pid와 view를 입력해야 합니다. 아래는 JFR View 옵션에 대한 명령입니다.

$ jcmd <pid> JFR.view <views>

pid를 확인해가 위해 jcmd 명령을 실행합니다.

$ jcmd
8980 JMC
7660 jdk.jcmd/sun.tools.jcmd.JCmd

jcmd의 결과로 JMC의 pid가 8980인 것을 확인하였습니다.

이제 JFR.View의 view 옵션에 대해 확인해 보기 위해, 아래 명령을 실행합니다.

$ jcmd 8980 JFR.view
8980:
The argument 'view' is mandatory

Options:

 cell-height   (Optional) Maximum number of rows in a table cell. (INTEGER, no default value)

 maxage        (Optional) Length of time for the view to span. (INTEGER followed by
               's' for seconds 'm' for minutes or 'h' for hours, default value is 10m)

 maxsize       (Optional) Maximum size for the view to span in bytes if one of
               the following suffixes is not used: 'm' or 'M' for megabytes OR
               'g' or 'G' for gigabytes. (STRING, default value is 32MB)

 truncate      (Optional) How to truncate content that exceeds space in a table cell.
               Mode can be 'beginning' or 'end'. (STRING, default value 'end')

 verbose       (Optional) Displays the query that makes up the view.
               (BOOLEAN, default value false)

 <view>        (Mandatory) Name of the view or event type to display.
               See list below for available views. (STRING, no default value)

 width         (Optional) The width of the view in characters
               (INTEGER, no default value)

Java virtual machine views:
 class-modifications       gc-concurrent-phases longest-compilations
 compiler-configuration    gc-configuration     native-memory-committed
 compiler-phases           gc-cpu-time          native-memory-reserved
 compiler-statistics       gc-pause-phases      safepoints
 deoptimizations-by-reason gc-pauses            tlabs
 deoptimizations-by-site   gc-references        vm-operations
 gc                        heap-configuration

Environment views:
 active-recordings        cpu-information       jvm-flags
 active-settings          cpu-load              native-libraries
 container-configuration  cpu-load-samples      network-utilization
 container-cpu-throttling cpu-tsc               recording
 container-cpu-usage      environment-variables system-information
 container-io-usage       events-by-count       system-processes
 container-memory-usage   events-by-name        system-properties

Application views:
 allocation-by-class   exception-count       native-methods
 allocation-by-site    file-reads-by-path    object-statistics
 allocation-by-thread  file-writes-by-path   pinned-threads
 class-loaders         finalizers            socket-reads-by-host
 contention-by-address hot-methods           socket-writes-by-host
 contention-by-class   latencies-by-type     thread-allocation
 contention-by-site    longest-class-loading thread-count
 contention-by-thread  memory-leaks-by-class thread-cpu-load
 exception-by-message  memory-leaks-by-site  thread-start
 exception-by-site     modules


 The <view> parameter can be an event type name. Use the 'JFR.view types'
 to see a list. To display all views, use 'JFR.view all-views'. To display
 all events, use 'JFR.view all-events'.

Example usage:

 $ jcmd <pid> JFR.view gc

 $ jcmd <pid< JFR.view width=160 hot-methods

 $ jcmd <pid> JFR.view verbose=true allocation-by-class

 $ jcmd <pid> JFR.view contention-by-site

 $ jcmd <pid> JFR.view jdk.GarbageCollection

 $ jcmd <pid> JFR.view cell-height=5 ThreadStart

 $ jcmd <pid> JFR.view truncate=beginning SystemProcess                                                                                                      ─╯

JFR.view 옵션을 사용해서 볼 수 있는 view 종류들과 보기 옵션들을 확인해 볼 수 있습니다.

또한 Event type을 확인하기 위해서 아래 명령을 실행합니다.

$ jcmd 8980 JFR.view types
8980:
Event Types (number of events):

 ActiveRecording (1)             JavaMonitorInflate
 ActiveSetting (359)             JavaMonitorWait (81)
 AllocationRequiringGC           JavaThreadStatistics (326)
 BooleanFlag (635)               LongFlag (180)
 BooleanFlagChanged              LongFlagChanged
 CPUInformation (1)              MetaspaceAllocationFailure (3)
 CPULoad (325)                   MetaspaceChunkFreeListSummary (44)
 CPUTimeStampCounter (1)         MetaspaceGCThreshold (5)
 ClassDefine                     MetaspaceOOM
 ClassLoad                       MetaspaceSummary (22)
 ClassLoaderStatistics (3)       ModuleExport
 ClassLoadingStatistics (326)    ModuleRequire
 ClassRedefinition               NativeAgent
 ClassUnload                     NativeLibrary (327)
 CodeCacheConfiguration (1)      NativeMemoryUsage
 CodeCacheFull                   NativeMemoryUsageTotal
 CodeCacheStatistics (3)         NativeMethodSample (14015)
 Compilation                     NetworkUtilization (65)
 CompilationFailure              OSInformation (1)
 CompilerConfiguration (1)       ObjectAllocationInNewTLAB
 CompilerInlining                ObjectAllocationOutsideTLAB
 CompilerPhase                   ObjectAllocationSample (907)
 CompilerStatistics (326)        ObjectCount
 ConcurrentModeFailure           ObjectCountAfterGC
 ContainerCPUThrottling          OldGarbageCollection (2)
 ContainerCPUUsage               OldObjectSample
 ContainerConfiguration          PSHeapSummary
 ContainerIOUsage                ParallelOldGarbageCollection
 ContainerMemoryUsage            PhysicalMemory (1)
 DataLoss

간략히 정리하면

• 약 60개 이상의 view 지원
• view 화면 포맷을 지정하는 width, cell-height 등의 6가지 옵션들
• ‘JFR.view all-views’, ‘JFR.view all-events’를 이용해 모든 view, event 확인 가능

JFR View 사용법

JFR View를 통해 JVM/어플의 상태를 확인해 보기 위해서, JFR을 Jcmd를 이용해서 시작합니다.

$ jcmd 8980JFR.start
8980:
Started recording 2. No limit specified, using maxsize=250MB as default.

Use jcmd 64698 JFR.dump name=2 filename=FILEPATH to copy recording data to file.

view 중의 하나인 hot-methods의 경우, 아래와 같은 결과를 보여줍니다.

$ jcmd 8980 JFR.view hot-methods
8980:

                                  Java Methods that Executes the Most

Method                                                                                 Samples Percent
-------------------------------------------------------------------------------------- ------- -------
java.util.concurrent.locks.AbstractOwnableSynchronizer.setExclusiveOwnerThread(Thread)       8  22.22%
java.util.concurrent.locks.ReentrantLock$Sync.lock()                                         7  19.44%
jdk.internal.misc.InternalLock.lock()                                                        2   5.56%
jdk.jfr.internal.PlatformRecorder.periodicTask()                                             1   2.78%
sun.security.util.ManifestDigester.findSection(int, ManifestDigester$Position)               1   2.78%
java.util.HashMap.resize()                                                                   1   2.78%
sun.jvmstat.perfdata.monitor.AliasFileParser.parse(Map)                                      1   2.78%
java.lang.Object.wait(long)                                                                  1   2.78%
java.math.BigInteger.implSquareToLen(int[], int, int[], int)                                 1   2.78%
sun.jvmstat.monitor.MonitoredHost.getMonitoredHost(HostIdentifier)                           1   2.78%
java.lang.Integer.toString()                                                                 1   2.78%
java.lang.StringCoding.countPositives(byte[], int, int)                                      1   2.78%
java.net.URI.hashCode()                                                                      1   2.78%
java.util.jar.Attributes.read(Manifest$FastInputStream, byte[], String, int)                 1   2.78%
sun.jvmstat.perfdata.monitor.protocol.local.LocalVmManager.activeVms()                       1   2.78%
sun.jvmstat.perfdata.monitor.AliasFileParser.nextToken()                                     1   2.78%
java.util.concurrent.locks.AbstractQueuedSynchronizer.compareAndSetState(int, int)           1   2.78%
java.io.BufferedReader.read()                                                                1   2.78%
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker)                 1   2.78%
org.openjdk.jmc.browser.attach.LocalJVMToolkit.populateAttachableVMs(Map)                    1   2.78%
java.lang.StringLatin1.inflate(byte[], int, char[], int, int)                                1   2.78%
jdk.jfr.internal.periodic.PeriodicEvents.doPeriodic()                                        1   2.78%

Timespan: 20:41:30 - 20:51:30

디폴트로 10분과 32MB 중에 먼저 도달하는 데이터가 제공이 되고, 옵션으로 최대 시간과 최대 기록 크기는 지정하여 사용할 수 있습니다.

이상으로 JFR View에 대해서 간단히 알아보았습니다.

JDK 21 정식 릴리스에서는 좀 더 많은 view를 지원할 예정이라고 합니다.

JMC 없이 명령어로 상태를 확인 할 수 있고, 스크립트 형태로 구성이 가능하다는 점에서 활용도가 높을 것 같습니다.