Почему этот Java-процесс не завершается?

Question

У меня периодически возникает проблема на сервере сборки, когда Java-процесс в сборке как-то не завершается и, кажется, продолжает работать (используя 100% ЦП) вечно (я видел, что он работает более 2 дней в течение выходные, где обычно это занимает около 10 минут). kill -9 pid кажется единственным способом остановить процесс.

Я попытался вызвать kill -QUIT pid в процессе, но, похоже, он не производит трассировку стека в STDOUT (может быть, он не отвечает на сигнал?). Jstack без опции -F force, кажется, не может подключиться к работающей JVM, но с опцией force он производит вывод, включенный ниже.

К сожалению, даже с этой трассировкой стека я не вижу никакого очевидного пути для дальнейшего исследования.

Насколько я могу судить, он показывает два «BLOCKED» потока, которые запустили Object.wait (их стеки, по-видимому, содержат только основной код Java, но не наш), а третий - IN_VM без вывода стека.

Какие шаги я должен предпринять, чтобы собрать больше информации о причине проблемы (или еще лучше, как я могу ее решить)?

$ /opt/jdk1.6.0_29/bin/jstack -l -F 5546
Attaching to process ID 5546, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 20.4-b02
Deadlock Detection:

No deadlocks found.

Finding object size using Printezis bits and skipping over...
Thread 5555: (state = BLOCKED)

Locked ownable synchronizers:
    - None

Thread 5554: (state = BLOCKED)
 - java.lang.Object.wait(long) @bci=0 (Interpreted frame)
 - java.lang.ref.ReferenceQueue.remove(long) @bci=44, line=118 (Interpreted frame)
 - java.lang.ref.ReferenceQueue.remove() @bci=2, line=134 (Interpreted frame)
 - java.lang.ref.Finalizer$FinalizerThread.run() @bci=3, line=159 (Interpreted frame)

Locked ownable synchronizers:
    - None

Thread 5553: (state = BLOCKED)
 - java.lang.Object.wait(long) @bci=0 (Interpreted frame)
 - java.lang.Object.wait() @bci=2, line=485 (Interpreted frame)
 - java.lang.ref.Reference$ReferenceHandler.run() @bci=46, line=116 (Interpreted frame)

Locked ownable synchronizers:
    - None

Thread 5548: (state = IN_VM)

Locked ownable synchronizers:
    - None

(Java версии 1.6.0, обновление 29, работает в Scientific Linux выпуск 6.0)

Обновление:

Запуск strace -f -p 894 создает, казалось бы, бесконечный поток ...

[pid   900] sched_yield()               = 0
[pid   900] sched_yield()               = 0
...

и затем, когда Ctrl-Cd

Process 894 detached
...
Process 900 detached
...
Process 909 detached

jmap -histo 894 не подключается, но jmap -F -histo 894 возвращает ...

Attaching to process ID 894, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 20.4-b02
Iterating over heap. This may take a while...
Finding object size using Printezis bits and skipping over...
Finding object size using Printezis bits and skipping over...
Object Histogram:

num       #instances    #bytes  Class description
--------------------------------------------------------------------------
1:      11356   1551744 * MethodKlass
2:      11356   1435944 * ConstMethodKlass
3:      914 973488  * ConstantPoolKlass
4:      6717    849032  char[]
5:      16987   820072  * SymbolKlass
6:      2305    686048  byte[]
7:      914 672792  * InstanceKlassKlass
8:      857 650312  * ConstantPoolCacheKlass
9:      5243    167776  java.lang.String
10:     1046    108784  java.lang.Class
11:     1400    87576   short[]
12:     1556    84040   * System ObjArray
13:     1037    64584   int[]
14:     103 60152   * ObjArrayKlassKlass
15:     622 54736   java.lang.reflect.Method
16:     1102    49760   java.lang.Object[]
17:     937 37480   java.util.TreeMap$Entry
18:     332 27960   java.util.HashMap$Entry[]
19:     579 27792   java.nio.HeapByteBuffer
20:     578 27744   java.nio.HeapCharBuffer
21:     1021    24504   java.lang.StringBuilder
22:     1158    24176   java.lang.Class[]
23:     721 23072   java.util.HashMap$Entry
24:     434 20832   java.util.TreeMap
25:     689 18936   java.lang.String[]
26:     238 17440   java.lang.reflect.Method[]
27:     29  16800   * MethodDataKlass
28:     204 14688   java.lang.reflect.Field
29:     330 13200   java.util.LinkedHashMap$Entry
30:     264 12672   java.util.HashMap
...
585:        1   16  java.util.LinkedHashSet
586:        1   16  sun.rmi.runtime.NewThreadAction$2
587:        1   16  java.util.Hashtable$EmptyIterator
588:        1   16  java.util.Collections$EmptySet
Total :     79700   8894800
Heap traversal took 1.288 seconds.

Answer 1

Вы всегда можете сделать strace -f -p pid, чтобы увидеть, что делает процесс Java.На первый взгляд (вы не можете получить jstack без -F, а поток 5548 не показывает стек вызовов и является IN_VM), похоже, что поток 5548 слишком много для чего-то делает или, возможно, находится в каком-то бесконечном цикле.

Answer 2

Сделайте снимок, когда процесс работает нормально через jstack -F (должен присутствовать -F, он производит другой снимок, чем просто jstack).Номера потоков - не Thread.id, а системный.5548, кажется, был создан до Finalizer и RefCounter (они не являются источником проблемы), поэтому это должен быть поток GC или какой-то компилятор.

100%, вероятно, означает некоторую ошибку в мониторе.Java (hotspot) мониторы используют очень простой механизм блокировки вращения для обеспечения владения.

И, конечно, подключите отладчик - GDB, чтобы проверить, где именно застрял процесс.

Answer 3

Я бы заподозрил проблему с памятью. Возможно, вы захотите наблюдать за процессом с помощью jstat и делать дамп кучи с помощью jmap примерно в то время, когда вам нужно убить процесс. Посмотрите, указывает ли jstat непрерывный GC. Кроме того, вы можете проверить состояние системы в целом (дескрипторы открытых файлов, сеть и т. Д.). Память будет самой простой, поэтому я настоятельно рекомендую начать с нее.

Answer 4

это также может быть вызвано нехваткой памяти.Я бы попробовал две вещи:

• Включить автоматический дамп кучи в OutOfMemory, добавив параметры JVM

  -XX: + HeapDumpOnOutOfMemoryError XX: HeapDumpPath = / tmp

• Попробуйте подключиться к JVM с помощью JConsole и посмотрите, нет ли здесь необычного шаблона

Answer 5

Я сталкиваюсь с подобной проблемой, мой JBOSS jvm получает бесконечный цикл, в конце концов он получает OutOfMemory, я не могу убить процесс, но Kill -9. Я подозреваю, что проблема с памятью в большинстве случаев.

Answer 6

Поток 5554 может указывать на то, что у вас много Объектов с методами финализации и / или некоторые проблемы с методом финализации.Возможно, стоит взглянуть на это.

Я не был знаком с jstack, но похоже, что он выводит меньше информации, которую создает дамп потока, с которой я более знаком.Может быть полезно попытаться получить дамп потока: kill -QUIT java_pid.Обратите внимание, что дамп отправляется в стандартный вывод, который может быть консольным или в лог-файл, в зависимости от ваших настроек.

Если вам трудно определить, куда направляется стандартный вывод и предполагается, что он идет в файл, выможет использовать find по времени последнего изменения для идентификации файлов-кандидатов.Это предлагается в комментарии к этой записи блога :

. Вы можете запустить команду find [2] в своем корневом каталоге и узнать, что изменилось за последние x секунд.Я обычно использовал find, чтобы помочь мне получить доступ ко всем журналам, которые изменились за последние 10 минут, например: find / var / tomcat -mmin -3 -print (распечатывает все файлы, измененные в / var / tomcat в последние 3минут).

Обратите внимание, что если вы используете JVM с -Xrs, это означает, что обработчик сигнала SIGQUIT не будет установлен, и вы не сможете использовать это средство запросадамп потока.

Answer 7

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

• perf / oprofile, особенно opannotate - отлично подходит для просмотра того, что адский код потребляет циклы
• strace, gstack / gdb (как упомянуто другими)
• systemtap чрезвычайно мощен, но ограничен некоторыми из тех же способов, что и инструменты на основе ptrace (если ваша проблема не связана с системным вызовом, он намного менее эффективен).