Эта статья является частью 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
В следующем разделе представлены некоторые подробности о текущем оборудовании и ОС, с которых работает эта виртуальная машина 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 ……………………………………………………………………………………………
Пожалуйста, не стесняйтесь оставлять комментарии и вопросы.