Статьи

Как анализировать дампы потоков: IBM VM

Эта статья является частью 4 нашей серии анализов дампов потоков, которая предоставит вам обзор того, что представляет собой дамп потоков JVM для IBM VM и различные потоки и точки данных, которые вы найдете. Как вы увидите и узнаете, формат IBM VM Thread Dump отличается, но предоставляет еще больше готовых данных для устранения неполадок.

На этом этапе вы должны знать, как потоки взаимодействуют с контейнером Java EE и что такое дамп потока. Прежде чем мы углубимся в паттерны глубокого анализа погружений, вам также необходимо понять формат IBM VM Thread Dump, поскольку это типичные данные Thread Dump, которые следует ожидать при использовании IBM WAS на IBM VM.

Обзор разбивки дампов IBM VM Thread Dump

Чтобы вы лучше поняли, найдите ниже схему, на которой показана визуальная разбивка дампа потоков виртуальных машин IBM 1.6 и его общих найденных точек данных:


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

В остальной части статьи будет подробно описана каждая часть Thread Dump.

# Событие создания дампа потока

Первая часть содержит подробные сведения о том, как был создан этот дамп потока. IBM Thread Dump может быть сгенерирован в результате «сигнала 3» или «пользователя», например kill -3 <Java pid>, или автоматически в результате серьезных условий JVM, таких как OutOfMemoryError.

0SECTION       TITLE subcomponent dump routine
NULL           ===============================
1TISIGINFO     Dump Event "user" (00004000) received
1TIDATETIME    Date:                 2012/03/12 at 20:52:13
1TIFILENAME    Javacore filename:    /apps/wl11g/domains/app/javacore.20120312.205205.1949928.0004.txt
1TIREQFLAGS    Request Flags: 0x81 (exclusive+preempt)
1TIPREPSTATE   Prep State: 0x4 (exclusive_vm_access)
0SECTION       TITLE subcomponent dump routine
NULL           ===============================
1TISIGINFO     OUTOFMEMORY received
1TIDATETIME    Date:                 2012/06/01 at 09:52:12
1TIFILENAME    Javacore filename:    /usr/WebSphere/AppServer/javacore311328.1338524532.txt
# HW и детали среды ОС

В следующем разделе представлены некоторые подробности о текущем оборудовании и ОС, с которых работает эта виртуальная машина IBM:

0SECTION       GPINFO subcomponent dump routine
NULL           ================================
2XHOSLEVEL     OS Level         : AIX 5.3
2XHCPUS        Processors -
3XHCPUARCH       Architecture   : ppc64
3XHNUMCPUS       How Many       : 6
3XHNUMASUP       NUMA is either not supported or has been disabled by user

# JRE подробно и аргументы запуска Java

Этот раздел очень полезен, поскольку он дает вам полное представление о вашей основной версии JRE и уровне исправления, а также обо всех аргументах запуска JVM.

0SECTION       ENVINFO subcomponent dump routine
NULL           =================================
1CIJAVAVERSION JRE 1.6.0 IBM J9 2.4 AIX ppc64-64 build jvmap6460sr9-20101124_69295
1CIVMVERSION   VM build 20101124_069295
1CIJITVERSION  JIT enabled, AOT enabled - r9_20101028_17488ifx2
1CIGCVERSION   GC - 20101027_AA
1CIRUNNINGAS   Running as a standalone JVM
…………………………………………………………………………………………

# Пользователь и переменные среды

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

1CIUSERLIMITS  User Limits (in bytes except for NOFILE and NPROC)
NULL           ------------------------------------------------------------------------
NULL           type                            soft limit           hard limit
2CIUSERLIMIT   RLIMIT_AS                        unlimited            unlimited
2CIUSERLIMIT   RLIMIT_CORE                     1073741312            unlimited
2CIUSERLIMIT   RLIMIT_CPU                       unlimited            unlimited
2CIUSERLIMIT   RLIMIT_DATA                      unlimited            unlimited
2CIUSERLIMIT   RLIMIT_FSIZE                     unlimited            unlimited
2CIUSERLIMIT   RLIMIT_NOFILE                         4096                 4096
2CIUSERLIMIT   RLIMIT_RSS                        33554432            unlimited
2CIUSERLIMIT   RLIMIT_STACK                      33554432           4294967296

# Java Heap detail и история GC

Подобно HotSpot VM 1.6+, IBM VM Thread Dump также содержит информацию о емкости и использовании кучи Java, а также сегменты памяти, выделенные для каждого пространства памяти процесса Java.

Помните, что более глубокий анализ кучи Java потребует от вас анализа двоичного снимка памяти дампа кучи согласно приведенному ниже руководству.

http://javaeesupportpatterns.blogspot.com/2011/02/ibm-sdk-heap-dump-httpsession-footprint.htm

Наконец, история процесса сбора мусора также присутствует.

0SECTION       MEMINFO subcomponent dump routine
NULL           =================================
1STHEAPFREE    Bytes of Heap Space Free: 51104BC8
1STHEAPALLOC   Bytes of Heap Space Allocated: 80000000
1STSEGTYPE     Internal Memory
…………………………………………………………………………………………
1STSEGTYPE     Object Memory
…………………………………………………………………………………………
1STSEGTYPE     Class Memory
…………………………………………………………………………………………
1STSEGTYPE     JIT Code Cache
…………………………………………………………………………………………
1STSEGTYPE     JIT Data Cache
…………………………………………………………………………………………
STGCHTYPE     GC History 
3STHSTTYPE     00:52:07:523048405 GMT j9mm.51 -   SystemGC end: newspace=466136480/483183616 oldspace=899251600/1610612736 loa=80530432/80530432
3STHSTTYPE     00:52:07:523046694 GMT j9mm.139 -   Reference count end: weak=40149 soft=87504 phantom=33 threshold=17 maxThreshold=32
3STHSTTYPE     00:52:07:522164027 GMT j9mm.91 -   GlobalGC end: workstackoverflow=0 overflowcount=0 weakrefs=40149 soft=87504 threshold=17 phantom=33 finalizers=4947 newspace=466136480/483183616 oldspace=899251600/1610612736 loa=80530432/80530432
3STHSTTYPE     00:52:07:522152764 GMT j9mm.90 -   GlobalGC collect complete

# Детали блокировки и взаимоблокировки монитора объектов Java и JVM

Эта часть Thread Dump очень важна. Довольно часто проблемы с потоками связаны с тем, что потоки ожидают между собой из-за блокировок на определенных мониторах объектов, например, поток B, ожидающий получения блокировки на мониторе объектов, удерживаемом потоком A. Время от времени также могут возникать условия взаимоблокировки; особенно для не-потоковых реализаций.

IBM VM Thread Dump предоставляет отдельный раздел, в котором вы можете проанализировать блокировки, удерживаемые каждым потоком, включая цепочку ожидания, например, множество потоков, ожидающих получения одной и той же блокировки монитора объектов.

0SECTION       LOCKS subcomponent dump routine
NULL           ===============================
NULL          
1LKPOOLINFO    Monitor pool info:
2LKPOOLTOTAL     Current total number of monitors: 1034
NULL          
1LKMONPOOLDUMP Monitor Pool Dump (flat & inflated object-monitors):
2LKMONINUSE      sys_mon_t:0x0000000115B53060 infl_mon_t: 0x0000000115B530A0:
3LKMONOBJECT       java/util/Timer$TimerImpl@0x0700000000C92AA0/0x0700000000C92AB8: <unowned>
3LKNOTIFYQ            Waiting to be notified:
3LKWAITNOTIFY            "Thread-7" (0x0000000114CAB400)
…………………………………………………………………………
## Threads waiting chain
2LKMONINUSE      sys_mon_t:0x000000012462FE00 infl_mon_t: 0x000000012462FE40:
3LKMONOBJECT       com/inc/server/app/Request@0x07000000142ADF30/0x07000000142ADF48: owner "Thread-30" (0x000000012537F300), entry count 1
3LKNOTIFYQ            Waiting to be notified:
3LKWAITNOTIFY            "Thread-26" (0x0000000125221F00)
3LKWAITNOTIFY            "Thread-27" (0x0000000125252000)
3LKWAITNOTIFY            "Thread-28" (0x000000012527B800)
3LKWAITNOTIFY            "Thread-29" (0x00000001252DDA00)
3LKWAITNOTIFY            "Thread-31" (0x0000000125386200)
3LKWAITNOTIFY            "Thread-32" (0x0000000125423600)
3LKWAITNOTIFY            "Thread-33" (0x000000012548C500)
3LKWAITNOTIFY            "Thread-34" (0x00000001255D6000)
3LKWAITNOTIFY            "Thread-35" (0x00000001255F7900)
…………………………………………………………………………

# Промежуточное ПО Java EE, сторонние и пользовательские потоки приложений

Подобно формату HotSpot VM Thread Dump, эта часть является ядром Thread Dump и где вы обычно проводите большую часть времени на анализ. Количество найденных потоков будет зависеть от используемого вами программного обеспечения промежуточного программного обеспечения, сторонних библиотек (которые могут иметь свои собственные потоки) и вашего приложения ( если создается какой-либо пользовательский поток, что, как правило, не рекомендуется ).

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

3XMTHREADINFO      "[STUCK] ExecuteThread: '162' for queue: 'weblogic.kernel.Default (self-tuning)'" J9VMThread:0x000000013ACF0800, j9thread_t:0x000000013AC88B20, java/lang/Thread:0x070000001F945798, state:B, prio=1
3XMTHREADINFO1            (native thread ID:0x1AD0F3, native priority:0x1, native policy:UNKNOWN)
3XMTHREADINFO3           Java callstack:
4XESTACKTRACE                at org/springframework/jms/connection/SingleConnectionFactory.createConnection(SingleConnectionFactory.java:207(Compiled Code))
4XESTACKTRACE                at org/springframework/jms/connection/SingleConnectionFactory.createQueueConnection(SingleConnectionFactory.java:222(Compiled Code))
4XESTACKTRACE                at org/springframework/jms/core/JmsTemplate102.createConnection(JmsTemplate102.java:169(Compiled Code))
4XESTACKTRACE                at org/springframework/jms/core/JmsTemplate.execute(JmsTemplate.java:418(Compiled Code))
4XESTACKTRACE                at org/springframework/jms/core/JmsTemplate.send(JmsTemplate.java:475(Compiled Code))
4XESTACKTRACE                at org/springframework/jms/core/JmsTemplate.send(JmsTemplate.java:467(Compiled Code))
…………………………………………………………………………………………………………

# Сводка загрузчика классов JVM

Наконец, последний раздел IBM VM Thread Dump предоставляет вам подробную сводку загрузчика классов. Это очень важные данные, когда речь идет о проблемах и утечках, связанных с Class Loader. Вы найдете число и тип загруженных классов для каждого активного загрузчика классов в работающей JVM.

Я предлагаю вам ознакомиться со следующим примером для получения полного руководства о том, как точно определить основную причину проблем такого типа при использовании IBM VM.

http://javaeesupportpatterns.blogspot.com/2011/04/class-loader-memory-leak-debugging.html

0SECTION       CLASSES subcomponent dump routine
NULL           =================================
1CLTEXTCLLOS        Classloader summaries
1CLTEXTCLLSS               12345678: 1=primordial,2=extension,3=shareable,4=middleware,5=system,6=trusted,7=application,8=delegating
2CLTEXTCLLOADER            p---st-- Loader *System*(0x0700000000878898)
3CLNMBRLOADEDLIB           Number of loaded libraries 6
3CLNMBRLOADEDCL                  Number of loaded classes 3721
2CLTEXTCLLOADER            -x--st-- Loader sun/misc/Launcher$ExtClassLoader(0x0700000000AE8F40), Parent *none*(0x0000000000000000)
3CLNMBRLOADEDLIB           Number of loaded libraries 0
3CLNMBRLOADEDCL                  Number of loaded classes 91
2CLTEXTCLLOADER            -----ta- Loader sun/misc/Launcher$AppClassLoader(0x07000000008786D0), Parent sun/misc/Launcher$ExtClassLoader(0x0700000000AE8F40)
3CLNMBRLOADEDLIB           Number of loaded libraries 3
3CLNMBRLOADEDCL                  Number of loaded classes 15178
……………………………………………………………………………………………
Я надеюсь, что эта статья помогла понять базовый взгляд на IBM VM Thread Dump. Следующая статья (часть 5) предоставит вам руководство по анализу дампа потоков JVM с помощью пошагового руководства и методики, которую я использовал за последние 10 лет.

Пожалуйста, не стесняйтесь оставлять комментарии и вопросы.