LoginSignup
5
2

More than 3 years have passed since last update.

@charoninTIS株式会社

IBM Javaのjavacoreを解析するには、TMDAを使おう

Posted at

TL;DR

  • IBM Javaは、スレッドダンプがHotSpotとは違う、独自の形式（javacore）になっている
  • *inux環境であればkill -3でjavacoreは取得できるが、こちらを読むにはTMDAを使うのがよさそう

javacoreとTMDA

IBM Javaでスレッドダンプを取得する場合、以下のような手順で行うようです。

javacore の収集

*inux環境であれば、kill -3ですね。

ここで取得できるのがjavacore、ですと。

ただ、ここで取得できるjavacoreはHotSpotとだいぶ形式が異なるようで、ちょっと読みづらい感じが…。

そこで、IBM Thread and Monitor Dump Analyzer for Java (TMDA)を使ってjavacoreを解析すると、より見やすくなるようです。

IBMおよびSAPがJVM診断ツールをオープンソース化

IBM Thread and Monitor Dump Analyzer for Java (TMDA)

javacoreを取得してみる

試しに取得してみましょう。IBM JavaのDockerイメージがあるので、こちらを使用してみます。

ibmjava

コンテナを起動。

$ docker container run -it --rm --name ibmjava ibmjava:8 bash

# java -version
java version "1.8.0_241"
Java(TM) SE Runtime Environment (build 8.0.6.5 - pxa6480sr6fp5-20200111_02(SR6 FP5))
IBM J9 VM (build 2.9, JRE 1.8.0 Linux amd64-64-Bit Compressed References 20200108_436782 (JIT enabled, AOT enabled)
OpenJ9   - 7d1059c
OMR      - d059105
IBM      - c8aee39)
JCL - 20200110_01 based on Oracle jdk8u241-b07

javacoreを取得する対象としては、Apache Tomcatを利用しましょう。

# cd
# wget http://ftp.yz.yamagata-u.ac.jp/pub/network/apache/tomcat/tomcat-9/v9.0.31/bin/apache-tomcat-9.0.31.tar.gz
# tar xf apache-tomcat-9.0.31.tar.gz 
# cd apache-tomcat-9.0.31
root@fbb2898f4717:~/apache-tomcat-9.0.31# bin/startup.sh 
Using CATALINA_BASE:   /root/apache-tomcat-9.0.31
Using CATALINA_HOME:   /root/apache-tomcat-9.0.31
Using CATALINA_TMPDIR: /root/apache-tomcat-9.0.31/temp
Using JRE_HOME:        /opt/ibm/java/jre
Using CLASSPATH:       /root/apache-tomcat-9.0.31/bin/bootstrap.jar:/root/apache-tomcat-9.0.31/bin/tomcat-juli.jar
Tomcat started.

Tomcatが起動しました。

Tomcatプロセスに、-3（SIGQUIT）シグナルを送ります。

# kill -3 [PID]

javacoreが出力されました。

# ls -l
total 608
-rw-r----- 1 root root  18982 Feb  5 19:36 BUILDING.txt
-rw-r----- 1 root root   5409 Feb  5 19:36 CONTRIBUTING.md
-rw-r----- 1 root root  57092 Feb  5 19:36 LICENSE
-rw-r----- 1 root root   2333 Feb  5 19:36 NOTICE
-rw-r----- 1 root root   3255 Feb  5 19:36 README.md
-rw-r----- 1 root root   6898 Feb  5 19:36 RELEASE-NOTES
-rw-r----- 1 root root  16262 Feb  5 19:36 RUNNING.txt
drwxr-x--- 2 root root   4096 Feb 17 03:40 bin
drwx------ 3 root root   4096 Feb 17 03:40 conf
-rw-r----- 1 root root 472769 Feb 17 03:41 javacore.20200217.034113.22.0001.txt
drwxr-x--- 2 root root   4096 Feb 17 03:40 lib
drwxr-x--- 2 root root   4096 Feb 17 03:40 logs
drwxr-x--- 2 root root   4096 Feb 17 03:40 temp
drwxr-x--- 7 root root   4096 Feb  5 19:34 webapps
drwxr-x--- 3 root root   4096 Feb 17 03:40 work

軽く、中を見てみます。

# cat javacore.20200217.034113.22.0001.txt 
0SECTION       TITLE subcomponent dump routine
NULL           ===============================
1TICHARSET     ANSI_X3.4-1968
1TISIGINFO     Dump Event "user" (00004000) received 
1TIDATETIME    Date: 2020/02/17 at 03:41:13:542
1TINANOTIME    System nanotime: 13446928231692
1TIFILENAME    Javacore filename:    /root/apache-tomcat-9.0.31/javacore.20200217.034113.22.0001.txt
1TIREQFLAGS    Request Flags: 0x81 (exclusive+preempt)
1TIPREPSTATE   Prep State: 0x104 (exclusive_vm_access+trace_disabled)
NULL           ------------------------------------------------------------------------
0SECTION       GPINFO subcomponent dump routine
NULL           ================================
2XHOSLEVEL     OS Level         : Linux 4.15.0-76-generic
2XHCPUS        Processors -
3XHCPUARCH       Architecture   : amd64
3XHNUMCPUS       How Many       : 4
3XHNUMASUP       NUMA is either not supported or has been disabled by user
NULL           
1XHERROR2      Register dump section only produced for SIGSEGV, SIGILL or SIGFPE.
NULL           
NULL           ------------------------------------------------------------------------
0SECTION       ENVINFO subcomponent dump routine
NULL           =================================
1CIJAVAVERSION JRE 1.8.0 Linux amd64-64 (build 8.0.6.5 - pxa6480sr6fp5-20200111_02(SR6 FP5))
1CIVMVERSION   20200108_436782
1CIJ9VMVERSION 7d1059c
1CIJITVERSION  tr.open_20200107_095049_7d1059c
1CIOMRVERSION  d059105_CMPRSS
1CIIBMVERSION  c8aee39
1CIJITMODES    JIT enabled, AOT enabled, FSD disabled, HCR enabled
1CIRUNNINGAS   Running as a standalone JVM
1CIVMIDLESTATE VM Idle State: ACTIVE
1CICONTINFO    Running in container : TRUE
1CICGRPINFO    JVM support for cgroups enabled : TRUE
1CISTARTTIME   JVM start time: 2020/02/17 at 03:40:38:297
1CISTARTNANO   JVM start nanotime: 13411683675953
1CIPROCESSID   Process ID: 22 (0x16)
1CICMDLINE     /opt/ibm/java/jre/bin/java -Djava.util.logging.config.file=/root/apache-tomcat-9.0.31/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djdk.tls.ephemeralDHKeySize=2048 -Djava.protocol.handler.pkgs=org.apache.catalina.webresources -Dorg.apache.catalina.security.SecurityListener.UMASK=0027 -Dignore.endorsed.dirs= -classpath /root/apache-tomcat-9.0.31/bin/bootstrap.jar:/root/apache-tomcat-9.0.31/bin/tomcat-juli.jar -Dcatalina.base=/root/apache-tomcat-9.0.31 -Dcatalina.home=/root/apache-tomcat-9.0.31 -Djava.io.tmpdir=/root/apache-tomcat-9.0.31/temp org.apache.catalina.startup.Bootstrap start
1CIJAVAHOMEDIR Java Home Dir:   /opt/ibm/java/jre
1CIJAVADLLDIR  Java DLL Dir:    /opt/ibm/java/jre/bin
1CISYSCP       Sys Classpath:   /opt/ibm/java/jre/lib/amd64/compressedrefs/jclSC180/vm.jar;/opt/ibm/java/jre/lib/se-service.jar;/opt/ibm/java/jre/lib/math.jar;/opt/ibm/java/jre/lib/ibmorb.jar;/opt/ibm/java/jre/lib/ibmorbapi.jar;/opt/ibm/java/jre/lib/ibmcfw.jar;/opt/ibm/java/jre/lib/ibmpkcs.jar;/opt/ibm/java/jre/lib/ibmcertpathfw.jar;/opt/ibm/java/jre/lib/ibmjgssfw.jar;/opt/ibm/java/jre/lib/ibmjssefw.jar;/opt/ibm/java/jre/lib/ibmsaslfw.jar;/opt/ibm/java/jre/lib/ibmjcefw.jar;/opt/ibm/java/jre/lib/ibmjgssprovider.jar;/opt/ibm/java/jre/lib/ibmjsseprovider2.jar;/opt/ibm/java/jre/lib/ibmcertpathprovider.jar;/opt/ibm/java/jre/lib/xmldsigfw.jar;/opt/ibm/java/jre/lib/xml.jar;/opt/ibm/java/jre/lib/charsets.jar;/opt/ibm/java/jre/lib/resources.jar;/opt/ibm/java/jre/lib/rt.jar;/opt/ibm/java/jre/lib/dataaccess.jar;
1CIUSERARGS    UserArgs:
2CIUSERARG               -Xoptionsfile=/opt/ibm/java/jre/lib/amd64/compressedrefs/options.default
2CIUSERARG               -Xlockword:mode=default,noLockword=java/lang/String,noLockword=java/util/MapEntry,noLockword=java/util/HashMap$Entry,noLockword=org/apache/harmony/luni/util/ModifiedMap$Entry,noLockword=java/util/Hashtable$Entry,noLockword=java/lang/invoke/MethodType,noLockword=java/lang/invoke/MethodHandle,noLockword=java/lang/invoke/CollectHandle,noLockword=java/lang/invoke/ConstructorHandle,noLockword=java/lang/invoke/ConvertHandle,noLockword=java/lang/invoke/ArgumentConversionHandle,noLockword=java/lang/invoke/AsTypeHandle,noLockword=java/lang/invoke/ExplicitCastHandle,noLockword=java/lang/invoke/FilterReturnHandle,noLockword=java/lang/invoke/DirectHandle,noLockword=java/lang/invoke/ReceiverBoundHandle,noLockword=java/lang/invoke/DynamicInvokerHandle,noLockword=java/lang/invoke/FieldHandle,noLockword=java/lang/invoke/FieldGetterHandle,noLockword=java/lang/invoke/FieldSetterHandle,noLockword=java/lang/invoke/StaticFieldGetterHandle,noLockword=java/lang/invoke/StaticFieldSetterHandle,noLockword=java/lang/invoke/IndirectHandle,noLockword=java/lang/invoke/InterfaceHandle,noLockword=java/lang/invoke/VirtualHandle,noLockword=java/lang/invoke/PrimitiveHandle,noLockword=java/lang/invoke/InvokeExactHandle,noLockword=java/lang/invoke/InvokeGenericHandle,noLockword=java/lang/invoke/VarargsCollectorHandle,noLockword=java/lang/invoke/ThunkTuple
2CIUSERARG               -Xjcl:jclse29
2CIUSERARG               -Dcom.ibm.oti.vm.bootstrap.library.path=/opt/ibm/java/jre/lib/amd64/compressedrefs:/opt/ibm/java/jre/lib/amd64
2CIUSERARG               -Dsun.boot.library.path=/opt/ibm/java/jre/lib/amd64/compressedrefs:/opt/ibm/java/jre/lib/amd64
2CIUSERARG               -Djava.library.path=/opt/ibm/java/jre/lib/amd64/compressedrefs:/opt/ibm/java/jre/lib/amd64:/usr/lib64:/usr/lib
2CIUSERARG               -Djava.home=/opt/ibm/java/jre
2CIUSERARG               -Djava.ext.dirs=/opt/ibm/java/jre/lib/ext
2CIUSERARG               -Duser.dir=/root/apache-tomcat-9.0.31
2CIUSERARG               -XX:+UseContainerSupport
2CIUSERARG               -Djava.class.path=.

〜省略〜

3CLTEXTCLASS            org/apache/tomcat/util/IntrospectionUtils$SecurePropertySource(0x00000000019DEE00)
3CLTEXTCLASS            [Lorg/apache/tomcat/util/IntrospectionUtils$PropertySource;(0x00000000019DEC00)
3CLTEXTCLASS            org/apache/tomcat/util/IntrospectionUtils$PropertySource(0x00000000019DEA00)
3CLTEXTCLASS            org/apache/tomcat/util/digester/SetPropertiesRule(0x00000000019DE800)
3CLTEXTCLASS            org/apache/tomcat/util/digester/SetNextRule(0x00000000019DDF00)
3CLTEXTCLASS            org/apache/tomcat/util/digester/FactoryCreateRule(0x00000000019DDB00)
3CLTEXTCLASS            org/apache/tomcat/util/digester/CallParamRule(0x00000000019DD300)
3CLTEXTCLASS            org/apache/tomcat/util/digester/CallMethodRule(0x00000000019DCC00)
3CLTEXTCLASS            org/apache/tomcat/util/digester/Rules(0x00000000019DC500)
3CLTEXTCLASS            org/apache/tomcat/util/digester/Digester(0x00000000019DC000)
3CLTEXTCLASS            org/apache/catalina/Container(0x00000000019D1800)
3CLTEXTCLASS            org/apache/tomcat/util/file/ConfigFileLoader(0x00000000019D1000)
3CLTEXTCLASS            org/apache/tomcat/util/file/ConfigurationSource$1(0x00000000019D0D00)
3CLTEXTCLASS            org/apache/catalina/startup/CatalinaBaseConfigurationSource(0x00000000019D0700)
3CLTEXTCLASS            org/apache/tomcat/util/ExceptionUtils(0x00000000019D0000)
3CLTEXTCLASS            org/apache/catalina/security/SecurityConfig(0x00000000019CFE00)
3CLTEXTCLASS            org/apache/tomcat/util/res/StringManager$1(0x00000000019CF700)
3CLTEXTCLASS            org/apache/tomcat/util/res/StringManager(0x00000000019CF200)
3CLTEXTCLASS            org/apache/tomcat/util/log/SystemLogHandler(0x00000000019CE300)
3CLTEXTCLASS            org/apache/catalina/LifecycleState(0x00000000019CDF00)
3CLTEXTCLASS            org/apache/catalina/startup/Catalina$CatalinaShutdownHook(0x00000000019CB600)
3CLTEXTCLASS            org/apache/tomcat/util/file/ConfigurationSource(0x00000000019CB100)
3CLTEXTCLASS            org/apache/catalina/LifecycleException(0x00000000019CAE00)
3CLTEXTCLASS            org/apache/catalina/startup/SetParentClassLoaderRule(0x00000000019CAA00)
3CLTEXTCLASS            org/apache/tomcat/util/digester/RuleSet(0x00000000019CA800)
3CLTEXTCLASS            org/apache/catalina/startup/CertificateCreateRule(0x00000000019CA400)
3CLTEXTCLASS            org/apache/catalina/startup/AddPortOffsetRule(0x00000000019CA000)
3CLTEXTCLASS            org/apache/catalina/startup/SetAllPropertiesRule(0x00000000019C9D00)
3CLTEXTCLASS            org/apache/catalina/startup/ConnectorCreateRule(0x00000000019C9500)
3CLTEXTCLASS            org/apache/catalina/startup/ListenerCreateRule(0x00000000019C8D00)
3CLTEXTCLASS            org/apache/tomcat/util/digester/ObjectCreateRule(0x000000000197E300)
3CLTEXTCLASS            org/apache/tomcat/util/digester/Rule(0x000000000197D700)
3CLTEXTCLASS            org/apache/catalina/startup/Catalina(0x00000000019C0800)
2CLTEXTCLLOAD       Loader sun/reflect/DelegatingClassLoader(0x00000000E00DE640)
3CLTEXTCLASS            sun/reflect/GeneratedMethodAccessor2(0x00000000019CCA00)
2CLTEXTCLLOAD       Loader sun/reflect/DelegatingClassLoader(0x00000000E013B110)
3CLTEXTCLASS            sun/reflect/GeneratedMethodAccessor3(0x0000000001A52100)
2CLTEXTCLLOAD       Loader sun/reflect/DelegatingClassLoader(0x00000000E0261650)
3CLTEXTCLASS            sun/reflect/GeneratedConstructorAccessor1(0x00000000018A8700)
2CLTEXTCLLOAD       Loader sun/reflect/DelegatingClassLoader(0x00000000E0301418)
3CLTEXTCLASS            sun/reflect/GeneratedConstructorAccessor2(0x00000000018A8C00)
2CLTEXTCLLOAD       Loader sun/reflect/DelegatingClassLoader(0x00000000E0301460)
3CLTEXTCLASS            sun/reflect/GeneratedMethodAccessor4(0x00000000018A9100)
2CLTEXTCLLOAD       Loader sun/reflect/DelegatingClassLoader(0x00000000E03014A8)
3CLTEXTCLASS            sun/reflect/GeneratedMethodAccessor5(0x00000000018A9600)
2CLTEXTCLLOAD       Loader sun/reflect/DelegatingClassLoader(0x00000000E03014F0)
3CLTEXTCLASS            sun/reflect/GeneratedMethodAccessor6(0x00000000018A9A00)
2CLTEXTCLLOAD       Loader sun/reflect/DelegatingClassLoader(0x00000000E0301538)
3CLTEXTCLASS            sun/reflect/GeneratedMethodAccessor7(0x00000000018A9F00)
2CLTEXTCLLOAD       Loader sun/reflect/DelegatingClassLoader(0x00000000E0301580)
3CLTEXTCLASS            sun/reflect/GeneratedMethodAccessor8(0x0000000001C0ED00)
2CLTEXTCLLOAD       Loader sun/reflect/DelegatingClassLoader(0x00000000E03015C8)
3CLTEXTCLASS            sun/reflect/GeneratedConstructorAccessor3(0x0000000001C17700)
NULL           ------------------------------------------------------------------------
0SECTION       Javadump End section
NULL           ---------------------- END OF DUMP -------------------------------------

スレッドダンプも含まれているようです。

3XMTHREADINFO      "main" J9VMThread:0x000000000177C700, omrthread_t:0x00007F30D8007C70, java/lang/Thread:0x00000000E0036A98, state:R, prio=5
3XMJAVALTHREAD            (java/lang/Thread getId:0x1, isDaemon:false)
3XMTHREADINFO1            (native thread ID:0x17, native priority:0x5, native policy:UNKNOWN, vmstate:R, vm thread flags:0x000000a1)
3XMTHREADINFO2            (native stack address range from:0x00007F30DCC75000, to:0x00007F30DD475000, size:0x800000)
3XMCPUTIME               CPU usage total: 2.041586755 secs, current category="Application"
3XMHEAPALLOC             Heap bytes allocated since last GC cycle=1918344 (0x1D4588)
3XMTHREADINFO3           Java callstack:
4XESTACKTRACE                at java/net/PlainSocketImpl.socketAccept(Native Method)
4XESTACKTRACE                at java/net/AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:450)
4XESTACKTRACE                at java/net/ServerSocket.implAccept(ServerSocket.java:623)
4XESTACKTRACE                at java/net/ServerSocket.accept(ServerSocket.java:582)
4XESTACKTRACE                at org/apache/catalina/core/StandardServer.await(StandardServer.java:609)
4XESTACKTRACE                at org/apache/catalina/startup/Catalina.await(Catalina.java:721)
4XESTACKTRACE                at org/apache/catalina/startup/Catalina.start(Catalina.java:667)
4XESTACKTRACE                at sun/reflect/NativeMethodAccessorImpl.invoke0(Native Method)
4XESTACKTRACE                at sun/reflect/NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:90)
4XESTACKTRACE                at sun/reflect/DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55(Compiled Code))
4XESTACKTRACE                at java/lang/reflect/Method.invoke(Method.java:508(Compiled Code))
4XESTACKTRACE                at org/apache/catalina/startup/Bootstrap.start(Bootstrap.java:343)
4XESTACKTRACE                at org/apache/catalina/startup/Bootstrap.main(Bootstrap.java:474)
3XMTHREADINFO3           Native callstack:
4XENATIVESTACK               (0x00007F30D7DD3852 [libj9prt29.so+0x50852])
4XENATIVESTACK               (0x00007F30D7DA55E3 [libj9prt29.so+0x225e3])
4XENATIVESTACK               (0x00007F30D7DD38CE [libj9prt29.so+0x508ce])
4XENATIVESTACK               (0x00007F30D7DD39C4 [libj9prt29.so+0x509c4])
4XENATIVESTACK               (0x00007F30D7DA55E3 [libj9prt29.so+0x225e3])
4XENATIVESTACK               (0x00007F30D7DD372B [libj9prt29.so+0x5072b])
4XENATIVESTACK               (0x00007F30D7DCFB0F [libj9prt29.so+0x4cb0f])
4XENATIVESTACK               (0x00007F30DE456890 [libpthread.so.0+0x12890])
4XENATIVESTACK               __poll+0x49 (0x00007F30DDD41BF9 [libc.so.6+0x114bf9])
4XENATIVESTACK               JCL_Poll+0x5b (0x00007F30D27AB20B [libjava.so+0x1620b])
4XENATIVESTACK               (0x00007F30C1653321 [libnet.so+0x14321])
4XENATIVESTACK               Java_java_net_PlainSocketImpl_socketAccept+0x137 (0x00007F30C164D557 [libnet.so+0xe557])
4XENATIVESTACK               (0x00007F30DC5DEDA4 [libj9vm29.so+0x13bda4])
4XENATIVESTACK               (0x00007F30DC5DC4C7 [libj9vm29.so+0x1394c7])
4XENATIVESTACK               (0x00007F30DC4C8AFE [libj9vm29.so+0x25afe])
4XENATIVESTACK               (0x00007F30DC4B5930 [libj9vm29.so+0x12930])
4XENATIVESTACK               (0x00007F30DC5772E2 [libj9vm29.so+0xd42e2])
NULL

ですが、確かにHotSpotの形式に慣れていると、だいぶ戸惑いますね。

とりあえず、このjavacoreをホスト側に取り出しておきます。

$ docker container cp ibmjava:/root/apache-tomcat-9.0.31/javacore.20200217.034113.22.0001.txt ./.

TMDAを使う

では、TMDAを使って取得したjavacoreを見てみましょう。

TMDAをダウンロードします。

IBM Thread and Monitor Dump Analyzer for Java (TMDA)

$ wget https://public.dhe.ibm.com/software/websphere/appserv/support/tools/jca/jca464.jar

起動。

$ java -jar jca464.jar

こんな感じのツールが起動しました。

image.png

記載時点のバージョンは、こちら。メニューのHelp → About IBM Thread and Monitor Dump Analyzer for Java Technologyから確認できます。

image.png

では、javacoreを開きましょう。メニューのOpen → Open Thread Dumpsを選択して、先程取得したjavacoreを開きます。

image.png

すると、こんな感じで情報が表示されます。

image.png

スレッドの情報を見たい場合は、Thread Status AnalyticsやThread Detailを見るとよいでしょう。

image.png

image.png

image.png

こうすると、（HotSpotで）見慣れたスレッドダンプの形式になりますね。

その他、TMDAではこういった情報も見れそうなので、スレッドダンプ以外の情報からの解析もできそうですね。

image.png

たとえば、CPU Usage Analysisだと、スレッドごとのCPU使用率が見れそうです。

image.png

IBM Javaを使うことがあれば、TMDAのことは頭に入れておいた方が良さそうかなと。

5
2
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
Sign upLogin
5
2