Утилиту jcmd добавили в Java 7, и с тех пор она считается главной утилитой, с помощью которой вы отныне будете заглядывать внутрь JVM и замерять все параметры ее работы. Все остальные утилиты типа jps, jstack, jinfo и проч. считаются теперь устаревшими и скоро в каком-то из будущих релизов JDK будут удалены. Предполагается, что jcmd заменит их всех.
Давайте посмотрим, как работает утилита, и что полезного с ее помощью можно узнать о работающем приложении и как эта информация может нам пригодиться для настройки JVM и самого приложения с целью достижения low-latency.
Стоит отметить, что информация, которую выдает jcmd может заметно отличаться по полноте и структуре от того, что выдают старые утилиты. В JDK17 (сент. 2021) старые утилиты еще поставляются, но ничто не гарантирует, что они там останутся в следующих релизах.
Формат команд jcmd простой и прекрасно описан в документации на сайте Oracle, например вот вариант для Java 8 LTS, Java11 LTS, и для свеженькой Java18.
$jcmd <команда>
Для начала давайте запустим простое приложение. Для этого подойдет простой скрипт на Groovy, который имитирует web-приложение. Этот скрипт hello.groovy мы запустим с помощью Spring CLI.
@RestController
class WebApplication {
@RequestMapping("/")
String home() {
"Hello World!"
}
}
Скрипт запускается из командной строки:
# spring run hello.groovy -- --server.port=8888
Spring Boot запустит веб-сервер, ожидающий http-запросы на локальном порту 8888. Наберите в браузере http://localhost:8888/ и вы увидите ответ «Hello World!». Разумеется, данный пример элементарен, и low-latency от него не требуется, но для демонстрации возможностей jcmd — вполне подойдет.
Список запущенных java-программ
Простой запуск jcmd из командной строки даст список запущенных java-программ и их pid. Раньше такой список мы могли получить с помощью утилиты jps.
# jcmd 16528 jdk.jcmd/sun.tools.jcmd.JCmd 17316 org.springframework.boot.loader.JarLauncher run hello.groovy -- --server.port=8888
pid нашего web-приложения — 17316. Теперь все остальные команды jcmd мы будем адресовывать нашей программе, используя pid в качестве первого параметра.
Список команд, поддерживаемых JVM
Вполне может быть, что на вашей машине работают Java-приложения на JVM разных версий. Например, одна программа работает на Java8, а вторая — на чем-то более свежем — скажем, на Java15. JVM разных версий Java поддерживают разный набор команд, и на некоторые команды Java8 может сказать «Not supported». Поэтому с помощью jcmd мы можем узнать, какие команды есть в нашем распоряжении:
# jcmd 17316 help
Список выглядит так:
17316: The following commands are available: Compiler.CodeHeap_Analytics Compiler.codecache Compiler.codelist Compiler.directives_add Compiler.directives_clear Compiler.directives_print Compiler.directives_remove Compiler.queue GC.class_histogram GC.finalizer_info GC.heap_dump GC.heap_info GC.run GC.run_finalization JFR.check JFR.configure JFR.dump JFR.start JFR.stop JVMTI.agent_load JVMTI.data_dump ManagementAgent.start ManagementAgent.start_local ManagementAgent.status ManagementAgent.stop Thread.print VM.class_hierarchy VM.classloader_stats VM.classloaders VM.command_line VM.dynlibs VM.events VM.flags VM.info VM.log VM.metaspace VM.native_memory VM.print_touched_methods VM.set_flag VM.stringtable VM.symboltable VM.system_properties VM.systemdictionary VM.uptime VM.version help For more information about a specific command use 'help '.
Команды сгруппированы в группы:
- Compiler — информация о JIT-компиляторе
- GC — информация о сборщике мусора,
- JFR — информация о модуле Flight Recorder, встреонном в JVM
- JVMTI — информация об Java-агентах
- ManagementAgent — информация о jmx-агентах
- Thread — информация о потоках
- и VM — информация о состоянии виртуальной машины
Если help вызвать с параметром -all, под каждой командой появится еще и объяснение, что она делает.
# jcmd <pid> help -all
Например, так выглядит фрагмент с описанием команды VM.version:
VM.version Print JVM version information.
Счетчики производительности
В списке отсутствует одна специальная команда PerfCounter.print, которая может очень пригодиться при настройке JVM для low-latency:
# jcmd <pid> PerfCounter.print
Эта команда выдает значения внутренних счетчиков производительности JVM, многие из которых расскажут вам, что и как происходит внутри вашего приложения и JVM, на которой оно работает. Так выглядит сокращенный листинг этих счетчиков:
17316: java.ci.totalTime=125699679 java.cls.loadedClasses=6201 java.cls.sharedLoadedClasses=1149 java.cls.sharedUnloadedClasses=0 java.cls.unloadedClasses=0 java.property.java.class.path="D:\tools\spring-cli\bin\..\lib\spring-boot-cli-2.3.3.RELEASE.jar" java.property.java.home="C:\java\java15" ... java.property.java.version="15" java.property.java.vm.info="mixed mode, sharing" java.property.java.vm.name="Java HotSpot(TM) 64-Bit Server VM" java.property.java.vm.specification.name="Java Virtual Machine Specification" java.property.java.vm.specification.vendor="Oracle Corporation" java.property.java.vm.specification.version="15" java.property.java.vm.vendor="Oracle Corporation" java.property.java.vm.version="15+36-1562" java.property.jdk.debug="release" java.rt.vmArgs="" java.rt.vmFlags="" java.threads.daemon=19 java.threads.live=23 java.threads.livePeak=24 java.threads.started=28 sun.ci.lastFailedMethod="java/util/HashSet add" sun.ci.lastFailedType=1 sun.ci.lastInvalidatedMethod="" sun.ci.lastInvalidatedType=0 sun.ci.lastMethod="org/apache/catalina/core/ContainerBase findChildren" sun.ci.lastSize=47 sun.ci.lastType=1 sun.ci.nmethodBucketsAllocated=2765 sun.ci.nmethodBucketsDeallocated=681 sun.ci.nmethodBucketsStale=0 sun.ci.nmethodBucketsStaleAccumulated=0 sun.ci.nmethodCodeSize=7164384 sun.ci.nmethodSize=10352904 sun.ci.osrBytes=19684 sun.ci.osrCompiles=37 sun.ci.osrTime=2942894 sun.ci.standardBytes=723577 sun.ci.standardCompiles=4842 sun.ci.standardTime=122756785 sun.ci.threads=3 sun.ci.totalBailouts=1 sun.ci.totalCompiles=4879 sun.ci.totalInvalidates=0 sun.classloader.findClassTime=2332746900 sun.classloader.findClasses=4461 sun.classloader.parentDelegationTime=436135800 sun.cls.appClassBytes=22248897 sun.cls.appClassLoadCount=9414 sun.cls.appClassLoadTime=28732474 sun.cls.appClassLoadTime.self=20780323 sun.cls.classInitTime=14895959 sun.cls.classInitTime.self=8521571 sun.cls.classLinkedTime=12289318 sun.cls.classLinkedTime.self=1216344 sun.cls.classVerifyTime=11068233 sun.cls.classVerifyTime.self=3509266 sun.cls.defineAppClassTime=10253424 sun.cls.defineAppClassTime.self=7970339 sun.cls.defineAppClasses=4619 sun.cls.initializedClasses=5338 sun.cls.jniDefineClassNoLockCalls=0 sun.cls.jvmDefineClassNoLockCalls=1794 sun.cls.jvmFindLoadedClassNoLockCalls=18203 sun.cls.linkedClasses=6048 sun.cls.loadedBytes=11890424 sun.cls.lookupSysClassTime=0 sun.cls.methodBytes=5312960 sun.cls.nonSystemLoaderLockContentionRate=392 sun.cls.sharedClassLoadTime=214537 sun.cls.sharedLoadedBytes=2813104 sun.cls.sharedUnloadedBytes=0 sun.cls.sysClassBytes=3238173 sun.cls.sysClassLoadTime=1057911 sun.cls.systemLoaderLockContentionRate=1 sun.cls.time=41997312 sun.cls.unloadedBytes=0 sun.cls.unsafeDefineClassCalls=0 sun.cls.verifiedClasses=3903 sun.gc.cause="No GC" sun.gc.collector.0.invocations=12 sun.gc.collector.0.lastEntryTime=84340969 sun.gc.collector.0.lastExitTime=84370245 sun.gc.collector.0.name="G1 young collection pauses" sun.gc.collector.0.time=621407 sun.gc.collector.1.invocations=0 sun.gc.collector.1.lastEntryTime=0 sun.gc.collector.1.lastExitTime=0 sun.gc.collector.1.name="G1 full collection pauses" sun.gc.collector.1.time=0 sun.gc.collector.2.invocations=4 sun.gc.collector.2.lastEntryTime=81517971 sun.gc.collector.2.lastExitTime=81518369 sun.gc.collector.2.name="G1 concurrent cycle pauses" sun.gc.collector.2.time=153333 sun.gc.compressedclassspace.capacity=4456448 sun.gc.compressedclassspace.maxCapacity=1073741824 sun.gc.compressedclassspace.minCapacity=0 sun.gc.compressedclassspace.used=4222096 sun.gc.generation.0.agetable.bytes.00=0 sun.gc.generation.0.agetable.bytes.01=527312 sun.gc.generation.0.agetable.bytes.02=866968 sun.gc.generation.0.agetable.bytes.03=0 sun.gc.generation.0.agetable.bytes.04=0 sun.gc.generation.0.agetable.bytes.05=0 sun.gc.generation.0.agetable.bytes.06=0 sun.gc.generation.0.agetable.bytes.07=0 sun.gc.generation.0.agetable.bytes.08=0 sun.gc.generation.0.agetable.bytes.09=0 sun.gc.generation.0.agetable.bytes.10=0 sun.gc.generation.0.agetable.bytes.11=0 sun.gc.generation.0.agetable.bytes.12=0 sun.gc.generation.0.agetable.bytes.13=0 sun.gc.generation.0.agetable.bytes.14=0 sun.gc.generation.0.agetable.bytes.15=0 sun.gc.generation.0.agetable.size=16 sun.gc.generation.0.capacity=23068696 sun.gc.generation.0.maxCapacity=4259315736 sun.gc.generation.0.minCapacity=24 sun.gc.generation.0.name="young" sun.gc.generation.0.space.0.capacity=20971528 sun.gc.generation.0.space.0.initCapacity=14680072 sun.gc.generation.0.space.0.maxCapacity=4259315720 sun.gc.generation.0.space.0.name="eden" sun.gc.generation.0.space.0.used=10485760 sun.gc.generation.0.space.1.capacity=8 sun.gc.generation.0.space.1.initCapacity=8 sun.gc.generation.0.space.1.maxCapacity=8 sun.gc.generation.0.space.1.name="s0" sun.gc.generation.0.space.1.used=0 sun.gc.generation.0.space.2.capacity=2097160 sun.gc.generation.0.space.2.initCapacity=8 sun.gc.generation.0.space.2.maxCapacity=4259315720 sun.gc.generation.0.space.2.name="s1" sun.gc.generation.0.space.2.used=1530984 sun.gc.generation.0.spaces=3 sun.gc.generation.1.capacity=27262984 sun.gc.generation.1.maxCapacity=4259315720 sun.gc.generation.1.minCapacity=8 sun.gc.generation.1.name="old" sun.gc.generation.1.space.0.capacity=27262984 sun.gc.generation.1.space.0.initCapacity=251658248 sun.gc.generation.1.space.0.maxCapacity=4259315720 sun.gc.generation.1.space.0.name="space" sun.gc.generation.1.space.0.used=16948224 sun.gc.generation.1.spaces=1 sun.gc.lastCause="G1 Evacuation Pause" sun.gc.metaspace.capacity=38715392 sun.gc.metaspace.maxCapacity=1109393408 sun.gc.metaspace.minCapacity=0 sun.gc.metaspace.used=38065224 sun.gc.policy.collectors=1 sun.gc.policy.desiredSurvivorSize=2097152 sun.gc.policy.gcTimeLimitExceeded=0 sun.gc.policy.generations=2 sun.gc.policy.maxTenuringThreshold=15 sun.gc.policy.name="GarbageFirst" sun.gc.policy.tenuringThreshold=2 sun.gc.tlab.alloc=2338782 sun.gc.tlab.allocThreads=2 sun.gc.tlab.fastWaste=0 sun.gc.tlab.fills=70 sun.gc.tlab.gcWaste=485 sun.gc.tlab.maxFastWaste=0 sun.gc.tlab.maxFills=69 sun.gc.tlab.maxGcWaste=485 sun.gc.tlab.maxSlowAlloc=0 sun.gc.tlab.maxSlowWaste=5738 sun.gc.tlab.slowAlloc=0 sun.gc.tlab.slowWaste=5738 sun.os.hrt.frequency=10000000 sun.os.hrt.ticks=5052883243 sun.perfdata.majorVersion=2 sun.perfdata.minorVersion=0 sun.perfdata.overflow=0 sun.perfdata.size=65536 sun.perfdata.timestamp=637560 sun.perfdata.used=13968 sun.property.sun.boot.library.path="C:\java\java15\bin" sun.rt._sync_ContendedLockAttempts=411 sun.rt._sync_Deflations=22 sun.rt._sync_FutileWakeups=167 sun.rt._sync_Inflations=24 sun.rt._sync_MonExtant=2 sun.rt._sync_Notifications=16 sun.rt._sync_Parks=570 sun.rt.applicationTime=318442617000 sun.rt.createVmBeginTime=1601599482552 sun.rt.createVmEndTime=1601599482604 sun.rt.internalVersion="Java HotSpot(TM) 64-Bit Server VM (15+36-1562) for windows-amd64 JRE (15+36-1562), built on Aug 11 2020 22:38:02 by "mach5one" with unknown MS VC++:1925" sun.rt.javaCommand="org.springframework.boot.loader.JarLauncher run hello.groovy -- --server.port=8888" sun.rt.jvmCapabilities="1100000000000000000000000000000000000000000000000000000000000000" sun.rt.jvmVersion=251658276 sun.rt.safepointSyncTime=948600 sun.rt.safepointTime=83370900 sun.rt.safepoints=32 sun.rt.vmInitDoneTime=1601599482583 sun.threads.vmOperationTime=864168 sun.urlClassLoader.readClassBytesTime=464820000 sun.zip.zipFile.openTime=2215169600 sun.zip.zipFiles=12173
Как видите, много счетчиков, рассказывающих о поведении JIT-компилятора (sun.ci), загрузчика классов (sun.cls), сборщика мусора (sun.gc), среды исполнения (sun.rt) и прочее.
Остальные команды
Пройдемся по остальным важным командам:
VM.version — выдаст сигнатуру версии JVM
# jcmd 17316 VM.version 17316: Java HotSpot(TM) 64-Bit Server VM version 15+36-1562 JDK 15.0.0
VM.flags — выдаст список параметров с которыми была запущена JVM
$jcmd 17316 VM.flags 17316: -XX:CICompilerCount=3 -XX:ConcGCThreads=1 -XX:G1ConcRefinementThreads=4 -XX:G1HeapRegionSize=2097152 -XX:GCDrainStackTargetSize=64 -XX:InitialHeapSize=266338304 -XX:MarkStackSize=4194304 -XX:MaxHeapSize=4259315712 -XX:MaxNewSize=2554331136 -XX:MinHeapDeltaBytes=2097152 -XX:MinHeapSize=8388608 -XX:NonNMethodCodeHeapSize=5832780 -XX:NonProfiledCodeHeapSize=122912730 -XX:ProfiledCodeHeapSize=122912730 -XX:ReservedCodeCacheSize=251658240 -XX:+SegmentedCodeCache -XX:SoftMaxHeapSize=4259315712 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseFastUnorderedTimeStamps -XX:+UseG1GC -XX:-UseLargePagesIndividualAllocation
VM.info — замена утилиты jinfo. Выдаст обширнейшую информацию о JVM-процессе: карту памяти, загруженные библиотеки, характеристики процессора, процесса и heap, переменные среды окружения, и прочее.
VM.command_line — выдаст список параметров командной строки, с которыми была запущена JVM:
# jcmd 4244 VM.command_line 4244: VM Arguments: java_command: org.springframework.boot.loader.JarLauncher run hello.groovy -- --server.port=8888 java_class_path (initial): D:\tools\spring-cli\bin\..\lib\spring-boot-cli-2.3.3.RELEASE.jar Launcher Type: SUN_STANDARD
VM.flags — выдаст всех флагов, с которыми запущена JVM. Помогает определить, точно ли переданы JVM все значения из командной строки, которые вы задали.
# jcmd 4244 VM.flags 4244: -XX:CICompilerCount=3 -XX:ConcGCThreads=1 -XX:G1ConcRefinementThreads=4 -XX:G1HeapRegionSize=2097152 -XX:GCDrainStackTargetSize=64 -XX:InitialHeapSize=266338304 -XX:MarkStackSize=4194304 -XX:MaxHeapSize=4259315712 -XX:MaxNewSize=2554331136 -XX:MinHeapDeltaBytes=2097152 -XX:MinHeapSize=8388608 -XX:NonNMethodCodeHeapSize=5832780 -XX:NonProfiledCodeHeapSize=122912730 -XX:ProfiledCodeHeapSize=122912730 -XX:ReservedCodeCacheSize=251658240 -XX:+SegmentedCodeCache -XX:SoftMaxHeapSize=4259315712 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseFastUnorderedTimeStamps -XX:+UseG1GC -XX:-UseLargePagesIndividualAllocation
VM.uptime — время прошедшее с момента запуска приложения в секундах:
# jcmd 4244 VM.uptime 4244: 273.204 s
VM.system_properties — выведет полный список всех системных свойств окружения JVM:
# jcmd 4244 VM.system_properties 4244: Fri Oct 02 19:46:54 GMT+09:00 2020 java.specification.version=15 sun.cpu.isalist=amd64 sun.jnu.encoding=Cp1252 java.class.path=D\:\tools\spring-cli\bin\\..\lib\spring-boot-cli-2.3.3.RELEASE.jar java.vm.vendor=Oracle Corporation sun.arch.data.model=64 user.variant= catalina.useNaming=false java.vendor.url=https\://java.oracle.com/ user.timezone=GMT+09\:00 os.name=Windows 10 java.vm.specification.version=15 sun.java.launcher=SUN_STANDARD user.country=US ... java.vm.info=mixed mode, sharing java.vendor=Oracle Corporation java.vm.version=15+36-1562 sun.io.unicode.encoding=UnicodeLittle java.class.version=59.0
GC.heap_info — выдаст текущие размеры heap, заодно покажет и какой сборщик мусора включен в JVM:
# jcmd 4244 GC.heap_info 4244: garbage-first heap total 69632K, used 30555K [0x0000000702200000, 0x0000000800000000) region size 2048K, 8 young (16384K), 1 survivors (2048K) Metaspace used 38091K, capacity 38629K, committed 38704K, reserved 1083392K class space used 4219K, capacity 4406K, committed 4480K, reserved 1048576K
Flight Recorder
Flight Recorder — это мощный инструмент встроенный в JVM, позовляющий вести запись всех параметров работы JVM в реальном времени и сохранять их в файл точно так же, как это делает настоящий «черный ящик» в самолете, записывающий все параметры полета. Раньше этот инструмент был коммерческим и включался параметром-ключом:
-XX:+UnlockCommercialFeatures
Но теперь этот модуль является бесплатным, и ключ не требуется. Запускать Flight Recorder можно сразу с запуском приложения с помощью параметра:
# java -XX:+FlightRecorder MyApp
а можно просто запустить приложение и включить Flight Recorder позже с помощью jcmd, причем его можно включать и выключать с помощью jcmd несколько раз, например, для снятия замеров в какие-то наиболее интересные моменты работы приложения.
JFR.start — запускает запись, а JFR.stop — останавливает ее. JFR.dump — позволяет сделать дамп записи в файл, который затем можно просмотреть утилитой Java Mission Control.
Выводы
Утилита jcmd является главным и незаменимым инструментом в jdk для снятия всех замеров с работающего Java-приложения. Эту утилиту можно вызывать из командной строки с различными параметрами с помощью, например, cron через определенные промежутки времени и получать «снимки» работающего Java-приложения, по которым можно потом судить, как ведет себя Java-приложение в различные моменты времени.