Статьи

Мониторинг OpenJDK из CLI

В настоящее время я довольно много работаю в виртуальной машине Java (JVM) и вокруг нее, большую часть времени в Linux.

Когда дела идут плохо, и я пытаюсь выяснить, почему, я берусь за инструменты анализа производительности Java. Эти инструменты имеют две формы: замечательный графический интерфейс, известный как visualvm , который я использую, когда работаю на своей локальной машине, и инструменты cli, поставляемые с Java Development Kit (JDK), которые я использую при удаленной работе.

Инструменты CLI, на которые я ссылаюсь:

Инструменты, которые я использую чаще всего, это jps, jstat и jstack, инструмент jhat также очень удобен, но ему действительно нужен целый пост, так как это безумие, что вы можете с ним сделать. В этом посте я собрал несколько советов, наблюдений и примеров, чтобы проиллюстрировать, как я их использую.

Поскольку я использую Ubuntu 11.10, которая устанавливает только среду выполнения Java (JRE), мне нужно будет установить JDK. В моем случае я решил дать openjdk 7 шанс, но версия 6 будет работать очень хорошо.

1
root@oneric:~# apt-get install openjdk-7-jdk

Чтобы опробовать эти команды, я установил tomcat7, это можно сделать через apt в Ubuntu, опять же, предыдущая версия tomcat 6 будет в порядке.

1
root@oneric:~# apt-get install tomcat7

Теперь, когда у меня установлен tomcat, я хочу перечислить процессы Java, обратите внимание, что при этом лучше всего использовать ту же учетную запись пользователя, что и у службы. В Ubuntu я бы использовал su для учетной записи пользователя, так как пользователь tomcat7 является системной учетной записью, я должен переопределить оболочку, так как по умолчанию это / bin / nologin , я могу затем запустить jps от имени этого пользователя.

Команда jps выводит PID процесса java вместе с именем основного класса и аргументом, переданным ему при запуске.

1
2
3
4
5
root@oneric:~# su - tomcat7 -s /bin/bash
tomcat7@oneric:~$ jps -ml
12728 org.apache.catalina.startup.Bootstrap start
13926 sun.tools.jps.Jps -ml
tomcat7@oneric:~$

Теперь, когда у нас есть PID этих процессов, мы можем запустить jstat, первый ключ, который я использую — -gcutil, это дает мне обзор использования кучи в jvm. В тех случаях, когда есть паузы или снижение производительности, я посмотрю на последние два столбца. Они содержат время сбора мусора (GCT) и время полного сбора мусора (FGCT). Если столбец FGCT увеличивается каждую секунду, то, скорее всего, у нас есть проблема.

В следующем примере я запускаю jstat против PID tomcat. Я также дал команду команде отображать заголовки таблиц каждые 20 строк и печатать статистику непрерывно с интервалом в 1000 миллисекунд, как нормальное управление C с завершением вывода.

В этом примере показан недавно запущенный tomcat 7 с очень небольшим количеством событий, это видно из значений в столбцах полного времени сбора мусора (FGCT) и времени сбора мусора (GCT).

Также следует отметить, что пространство permgen (P) в настоящее время находится на уровне 70%. Пространство permgen является важной областью кучи, поскольку оно содержит пользовательские классы, имена методов и внутренние объекты jvm. Если вы некоторое время использовали tomcat, вы увидите ошибку пространства java.lang.OutOfMemoryError: PermGen, которая указывает, когда это пространство заполняется и не может быть собрано мусором. Это часто случалось при повторном развертывании больших веб-приложений.

Также в примере мы видим, что в пространствах Survivor 0 (S0), Survivor 1 (S1), Eden и Old достаточно свободного места, что хорошо.

1
2
3
4
5
tomcat7@oneric:~$ jstat -gcutil -h20 12728 1000
  S0     S1     E      O      P     YGC     YGCT    FGC    FGCT     GCT  
  0.00  17.90  32.12   4.81  71.41      5    0.009     1    0.023    0.032
  0.00  17.90  32.12   4.81  71.41      5    0.009     1    0.023    0.032
  0.00  17.90  32.12   4.81  71.41      5    0.009     1    0.023    0.032

Чтобы проиллюстрировать, как выглядит кот под нагрузкой, мы можем установить инструмент Apache bench.

1
root@oneric:~# apt-get install apache2-utils

И выполните следующую команду, чтобы одновременно попасть на базовую страницу с большим количеством запросов.

1
markw@oneric:~$ ab -n 1000000 -c 100 http://localhost:8080/

Ниже приведены результаты, полученные после того, как этот тест был запущен в течение некоторого времени, поскольку мы можем видеть, что произошел значительный рост оставшегося в живых 1, eden и старого пространства, однако сервер не провел много времени, выполняя полные сборщики мусора, как указано значение полного сбора мусора (FGC), которое составляет всего 10, большая часть работы принадлежит молодому поколению, что видно по увеличению количества сборок молодого поколения (YGC).

Также следует отметить, что в пермгенном пространстве не было больших изменений, оно фактически уменьшилось, это было связано с увеличением размера кучи.

1
2
3
4
5
6
tomcat7@oneric:~$ jstat -gcutil -h20 12728 1000
  S0     S1     E      O      P     YGC     YGCT    FGC    FGCT     GCT  
  0.00 100.00  52.02  81.84  59.62    117    1.176    10    0.074    1.250
  0.00 100.00  52.02  81.84  59.62    117    1.176    10    0.074    1.250
  0.00 100.00  52.02  81.84  59.62    117    1.176    10    0.074    1.250
  0.00 100.00  52.02  81.84  59.62    117    1.176    10    0.074    1.250

Чтобы глубже изучить причину сбора мусора, мы используем команду jstat с опцией -gccause , в ней отображаются те же столбцы, что и в предыдущей команде, но с двумя дополнительными функциями, которые указывают причины для GC.

В следующем примере мы можем увидеть пример ошибки выделения, это указывает на то, что выполняется полный сбор данных, потому что куча слишком мала.

1
2
3
4
5
6
7
tomcat7@oneric:~$ jstat -gccause -h20 12728 1000
100.00   0.00   0.00  78.91  59.67    168    1.680    14    0.083    1.763 unknown GCCause      No GC              
100.00   0.00  72.61  83.73  59.67    170    1.698    14    0.083    1.781 unknown GCCause      No GC              
  0.00 100.00  46.24  91.83  59.67    173    1.729    14    0.083    1.811 unknown GCCause      No GC              
100.00   0.00  11.39  29.80  59.67    176    1.759    16    0.086    1.846 unknown GCCause      No GC              
100.00   0.00  92.41  35.30  59.67    179    1.777    16    0.086    1.864 unknown GCCause      Allocation Failure 
  0.00 100.00  62.58  43.05  59.67    181    1.803    16    0.086    1.889 unknown GCCause      No GC              

Другая область, которую мне нравится изучать при диагностике проблем с производительностью, — это потоки, запущенные в vm. Это может помочь мне решить, перегружен ли какой-либо компонент и, следовательно, работает много потоков, пытаясь его догнать. Это в основном применимо только к асинхронным процессам, таким как обмен сообщениями или планирование процедур.

Чтобы получить дамп списка потоков и их текущего стека, используйте команду jstack, как показано в примере ниже, снова я обычно запускаю это как владелец процесса.

01
02
03
04
05
06
07
08
09
10
11
12
13
14
15
16
17
18
19
20
21
tomcat7@oneric:~$ jstack 12728
2011-10-16 14:53:58
Full thread dump OpenJDK 64-Bit Server VM (20.0-b11 mixed mode):
 
"Attach Listener" daemon prio=10 tid=0x00000000015be800 nid=0x4004 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
 
"http-bio-8080-exec-182" daemon prio=10 tid=0x00007f9d84274800 nid=0x3cd3 waiting on condition [0x00007f9d7a0df000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000000ef16da38> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject. await(AbstractQueuedSynchronizer.java:2043)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:386)
        at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104)
        at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:32)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1043)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1103)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
...

Я планирую немного поработать над некоторыми инструментами визуализации, конечно же, в jruby , но это может стать темой моего следующего поста. В процессе написания этого поста я нашел несколько интересных статей, ссылки на которые приведены ниже:



Ссылка: Мониторинг OpenJDK из CLI от нашего партнера JCG Марка Вулфа в блоге Марка Вулфа .

Статьи по Теме :