TL;DR
- IBM Javaは、スレッドダンプがHotSpotとは違う、独自の形式(javacore)になっている
- *inux環境であれば
kill -3
でjavacoreは取得できるが、こちらを読むにはTMDAを使うのがよさそう
javacoreとTMDA
IBM Javaでスレッドダンプを取得する場合、以下のような手順で行うようです。
*inux環境であれば、kill -3
ですね。
ここで取得できるのがjavacore、ですと。
ただ、ここで取得できるjavacoreはHotSpotとだいぶ形式が異なるようで、ちょっと読みづらい感じが…。
そこで、IBM Thread and Monitor Dump Analyzer for Java (TMDA)を使ってjavacoreを解析すると、より見やすくなるようです。
IBM Thread and Monitor Dump Analyzer for Java (TMDA)
javacoreを取得してみる
試しに取得してみましょう。IBM JavaのDockerイメージがあるので、こちらを使用してみます。
コンテナを起動。
$ 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
こんな感じのツールが起動しました。
記載時点のバージョンは、こちら。メニューのHelp → About IBM Thread and Monitor Dump Analyzer for Java Technologyから確認できます。
では、javacoreを開きましょう。メニューのOpen → Open Thread Dumpsを選択して、先程取得したjavacoreを開きます。
すると、こんな感じで情報が表示されます。
スレッドの情報を見たい場合は、Thread Status AnalyticsやThread Detailを見るとよいでしょう。
こうすると、(HotSpotで)見慣れたスレッドダンプの形式になりますね。
その他、TMDAではこういった情報も見れそうなので、スレッドダンプ以外の情報からの解析もできそうですね。
たとえば、CPU Usage Analysisだと、スレッドごとのCPU使用率が見れそうです。
IBM Javaを使うことがあれば、TMDAのことは頭に入れておいた方が良さそうかなと。