Производительность java приложений
Опишем структурированный подход к выявлению узких мест в производительности, рассмотрим основные моменты на которые следует обратить внимание. Пост возник после презентации jClarity на Devoxx UK видео
Структурированный подход к решению проблем производительности
Когда случаются провалы производительности, нет необходимости изменять параметры JVM без точного понимания, к чему приведут ваши действия. Не стоит добавлять просто магические ключи JVM. Следуя структурированному подходу можно избегать неверных гипотез о причинах проблем с производительностью. Подход визуализирован на схеме ниже.
Kernel dominant, user dominant or no dominator?
На схеме выделено три секции. На первом шаге необходимо определить какую работу выполняет процессор. Для этого используем консольную утилиту Linux vmstat. Запускаем vmstat с параметром 5, что выполнит вывод в консоль каждые 5 сек.
$ vmstat 5
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
5 0 0 3261272 96056 1042868 0 0 1579 519 20 3626 45 9 34 13 0
0 0 0 3261264 96064 1042832 0 0 0 2 19 423 6 2 91 2 0
0 0 0 3261264 96064 1042832 0 0 0 0 19 429 6 2 92 0 0
0 0 0 3261140 96064 1042832 0 0 0 0 19 311 4 1 95 0 0
Если CPU находится в режиме ядра более 10%
Когда вывод vmstat показывает преобладание режима ядра, возможна одна из нескольких причин:
- Переключение контекста: два или более приложения борятся за время CPU
- Диск I/O: инструментарий для проверки vmstat и iostat
- Виртуализация: KVM CLI (virsh), Docker CLI, Kubernetes CLI
- Сеть I/O: инструментарий netstat и Wireshark
Как посмотреть переключение контекста приложения и потока?
С помощью утилиты jps или ps узнаем pid процесса мониторинга напр. так:
kirill@kirill-pc:~/next-blog$ jps -lmv
5712 org.jetbrains.idea.maven.server.RemoteMavenServer -Djava.awt.headless=true -Didea.version==2018.1.8 -Xmx768m -Didea.maven.embedder.version=3.3.9 -Dfile.encoding=UTF-8
Смотрим общую статистику по процессу
kirill@kirill-pc:~/next-blog$ pidstat -w -p 5712
Linux 5.8.0-50-generic (kirill-pc) 12.08.21 _x86_64_ (24 CPU)
22:07:02 UID PID cswch/s nvcswch/s Command
22:07:02 1000 5712 0,00 0,00 java
или по каждому потоку
kirill@kirill-pc:~/next-blog$ pidstat -w -t -p 5712
Linux 5.8.0-50-generic (kirill-pc) 12.08.21 _x86_64_ (24 CPU)
22:08:55 UID TGID TID cswch/s nvcswch/s Command
22:08:55 1000 5712 - 0,00 0,00 java
22:08:55 1000 - 5712 0,00 0,00 |__java
22:08:55 1000 - 5714 0,23 0,01 |__java
22:08:55 1000 - 5717 0,00 0,00 |__java
22:08:55 1000 - 5718 0,00 0,00 |__java
22:08:55 1000 - 5719 0,00 0,00 |__java
22:08:55 1000 - 5720 0,00 0,00 |__java
22:08:55 1000 - 5721 0,00 0,00 |__java
22:08:55 1000 - 5722 0,00 0,00 |__java
22:08:55 1000 - 5723 0,00 0,00 |__java
22:08:55 1000 - 5724 0,00 0,00 |__java
22:08:55 1000 - 5725 0,00 0,00 |__java
22:08:55 1000 - 5726 0,00 0,00 |__java
22:08:55 1000 - 5727 0,00 0,00 |__java
22:08:55 1000 - 5728 0,00 0,00 |__java
22:08:55 1000 - 5729 0,00 0,00 |__java
22:08:55 1000 - 5730 0,00 0,00 |__java
22:08:55 1000 - 5731 0,00 0,00 |__java
22:08:55 1000 - 5732 0,00 0,00 |__java
...
TID (идентификатор потока) поможет найти поток в дампе потоков с помощью jstat.
Использование диска I/O
Утилита показывает статистику по нагрузке на систему ввода вывода:
kirill@kirill-pc:~/next-blog$ iostat
Linux 5.8.0-50-generic (kirill-pc) 12.08.21 _x86_64_ (24 CPU)
avg-cpu: %user %nice %system %iowait %steal %idle
4,03 0,03 0,73 0,06 0,00 95,14
Device tps kB_read/s kB_wrtn/s kB_dscd/s kB_read kB_wrtn kB_dscd
sda 2,14 152,45 1,80 0,00 528996 6256 0
sdb 45,53 892,21 797,40 0,00 3096026 2767013 0
Сеть I/O: инструментарий netstat
# netstat -nap
покажет какой процесс какие порты открыл, если надо проверить, скажем, какой процесс занял порт, который требуется вашему приложению.
CPU пользовательского режима приближается к 100%
Когда вывод vmstat показывает преобладание использования CPU в режиме пользователя, это причина посмотреть на JVM и на GC детально. Первое что необходимо сделать это включить GC логгинг. Для java от 1.4 до 1.8, должны добавить следующие аргументы JVM:
-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:<file-path>
Для Java 9 и выше:
-Xlog:gc*:file=<file-path>
Есть несколько бесплатных инструментов для графического представления GC логов. Рассмотрим вывод GCViewver:

Что необходимо учитывать:
- Полный GC блокирует приложение;
- Когда наблюдается полный GC без освобождения памяти, возможна утечка памяти;
- Приложение при нормальной работе должно показывать график формы "пилы" потребления кучи;
Как определить утечку памяти?
Запустим приложение с заложенной утечкой памяти код:
public class MemoryLeak {
public static final long timeToWait = 10;
public static final double NUMBER_OF_OBJECTS_TO_CREATE = 1000;
public static void main(String[] args) {
System.out.println("Start app ");
Map m = new HashMap();
while (true) {
for (int i = 0; i < NUMBER_OF_OBJECTS_TO_CREATE; i++) {
if (!m.containsKey(i)) {
m.put(new MapKey(i), new MapValue());
}
}
System.out.println("Created leaking objects");
// Wait for the given amount of time
try {
Thread.sleep(timeToWait);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}
}
public class MapKey {
Integer id;
MapKey(Integer id) {
this.id = id;
}
@Override
public int hashCode() {
return id.hashCode();
}
}
В классе MapKey не переопределен метод equals() и не происходит замещения элемента в Map<> новым объектом MapValue. Смотрим на работу сборщика мусора, чтобы удостовериться что память не очищается после Full GC.

Узнаем id процесса.
kirill@kirill-pc:~/Downloads$ jps
26816 Jps
23524 Launcher
7718 Main
23527 MemoryLeak
С помощью утилиты jmap смотрим количество созданных объектов и занимаемый размер.
kirill@kirill-pc:~/Downloads$ jmap -histo:live 23527
num #instances #bytes class name
----------------------------------------------
1: 7947149 445040344 java.util.HashMap$TreeNode
2: 7947150 127154400 MapKey
3: 7947150 127154400 MapValue
4: 6930062 110880992 java.lang.Integer
5: 14 67110176 [Ljava.util.HashMap$Node;
Видим преобладание TreeNode, MapKey, MapValue
Процессор в ожидании
Если процессор не показывает преобладания в режиме ядра или пользовательском, но пользователи наблюдают проблему производительности, то скорее всего потоки ожидают внешней системы или блокированы.
Материалы
- "Java: оптимизация программ" Бенджамин Эванс, Джеймс Гоф и Kpuc Ньюланд.
- "PDM" (https://github.com/rajendrapenumalli/PerformanceEngineeringNotes/wiki/Performance-Diagnostic-Methodology)