0
0

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

@keniooi(keniooi)inIBM

Javaプログラムを変えずにsleepさせる

0
Posted at

目的

自分で作成したコードではない場合、sleepを追加したりするのは手間がかかります。プログラムを変更なくsleepできる方法をためして見ます。

OpenJ9のJavaVM(IBM Java, Semeru Runtime)で指定できます。

以下の環境で試しました。

$ java -version
openjdk version "1.8.0_432"
IBM Semeru Runtime Open Edition (build 1.8.0_432-b06)
Eclipse OpenJ9 VM (build openj9-0.48.0, JRE 1.8.0 Linux amd64-64-Bit Compressed References 20241107_1079 (JIT enabled, AOT enabled)
OpenJ9   - 1d5831436e
OMR      - d10a4d553
JCL      - 306866566f based on jdk8u432-b06)

ソースコード

mainメソッドだけでは分かり辛いかもしれないので、packageあり、別のメソッドを設定します。

package pdprof.xtrace;

public class Main {
	public static void main(String args[]) {
		printHello();
	}
	
	public static void printHello() {
		System.out.println("Hello!!");
	}
}

コンパイル

パッケージのトップディレクトリで以下を実行します。（IDEでコンパイルしても良いです）

$ javac pdprof/xtrace/Main.java

実行

オプションなしで実行します。

$ java pdprof.xtrace.Main
Hello!!

Xtrace オプション

Xtrace オプションを調整します。

（オプションなしのリンク）

これに

  • stderr に出力（メソッド）
  • Trace initially stopped はチェックしない
  • pdprof/xtrace/Main.* メソッドをトレース
  • pdprof/xtrace/Main.printHello 開始時に sleep (30000ms)
  • pdprof/xtrace/Main.printHello 開始後 5000ms で javacore 出力

のオプションは以下になります。

"-Xtrace:print=mt,methods=pdprof/xtrace/Main.*(),trigger=method{pdprof/xtrace/Main.printHello,sleep},sleeptime=30000"

（オプション設定後のリンク）

image.png

ここで出した例を参考に設定したないようにカスタマイズしましょう。

Xtrace オプションで実行

オプションをつけて実行します。

$ java "-Xtrace:print=mt,methods=pdprof/xtrace/Main.*(),trigger=method{pdprof/xtrace/Main.printHello,sleep},sleeptime=30000" pdprof.xtrace.Main
14:05:19.642*0x1aa00              mt.3        > pdprof/xtrace/Main.main([Ljava/lang/String;)V bytecode static method
14:05:19.642 0x1aa00              mt.19       - method arguments: ([L@00000007FFF43CD0)
14:05:19.642 0x1aa00              mt.3        > pdprof/xtrace/Main.printHello()V bytecode static method
14:05:19.642 0x1aa00              mt.19       - method arguments: ()
TRCx289: Trace sleep action triggered. Sleeping for 30000 ms.
TRCx290: Finished sleeping.
Hello!!
14:05:49.643 0x1aa00              mt.9        < pdprof/xtrace/Main.printHello()V bytecode static method
14:05:49.643 0x1aa00              mt.9        < pdprof/xtrace/Main.main([Ljava/lang/String;)V bytecode static method

実行時の注意点

  • 引数は ”” で囲む （シェルの動作で正しくわたせなかった）
  • trigger で sleep 中の javacore 取得はできず

Xtrace sleep 中の kill -3 javacore 取得

sleep 中に kill -3 で javacore を取得します。

$ java "-Xtrace:print=mt,methods=pdprof/xtrace/Main.*(),trigger=method{pdprof/xtrace/Main.printHello,sleep},sleeptime=30000" pdprof.xtrace.Main &
[1] 301747
$ 14:10:25.259*0x1aa00              mt.3        > pdprof/xtrace/Main.main([Ljava/lang/String;)V bytecode static method
14:10:25.259 0x1aa00              mt.19       - method arguments: ([L@00000007FFF43CD0)
14:10:25.259 0x1aa00              mt.3        > pdprof/xtrace/Main.printHello()V bytecode static method
14:10:25.259 0x1aa00              mt.19       - method arguments: ()
TRCx289: Trace sleep action triggered. Sleeping for 30000 ms.

$ kill -3 %1
JVMDUMP039I Processing dump event "user", detail "" at 2026/02/27 23:10:30 - please wait.
drwxr-xr-x. 3 keniooi keniooi 20 Feb 27 23:10 .
drwxr-xr-x. 5 keniooi keniooi 79 Feb 27 22:38 ..
drwxr-xr-x. 3 keniooi keniooi 20 Feb 27 22:40 pdprof
$ TRCx290: Finished sleeping.
JVMDUMP032I JVM requested Java dump using '/home/keniooi/eclipse/XtraceTest/XtraceTest/src/javacore.20260227.231030.301747.0001.txt' in response to an event
JVMDUMP010I Java dump written to /home/keniooi/eclipse/XtraceTest/XtraceTest/src/javacore.20260227.231030.301747.0001.txt
Hello!!
14:10:55.274 0x1aa00              mt.9        < pdprof/xtrace/Main.printHello()V bytecode static method
14:10:55.274 0x1aa00              mt.9        < pdprof/xtrace/Main.main([Ljava/lang/String;)V bytecode static method

ためしたところ sleep 完了直後 に javacore を出力していたので、動作中の取得は別の方法が必要ではないかと思われる。

Xtrace のオプションで javacore 取得

先ほどのオプションに追加でメソッド終了時の条件で javacore を出力させます。

実行結果が以下、メソッドトレースではメソッド終了後に Java dump が実行されてました。

$ java "-Xtrace:print=mt,methods=pdprof/xtrace/Main.*(),trigger=method{pdprof/xtrace/Main.printHello,sleep,javadump},sleeptime=30000" pdprof.xtrace.Main &
[3] 304956
[1]   Done                    ~/java/jdk8u432-b06/bin/java "-Xtrace:print=mt,methods=pdprof/xtrace/Main.*(),trigger=method{pdprof/xtrace/Main.printHello,sleep},sleeptime=30000" pdprof.xtrace.Main
[2]   Done                    ~/java/jdk8u432-b06/bin/java "-Xtrace:print=mt,methods=pdprof/xtrace/Main.*(),trigger=method{pdprof/xtrace/Main.printHello,sleep},sleeptime=30000" pdprof.xtrace.Main
$ 14:20:38.965*0x1aa00              mt.3        > pdprof/xtrace/Main.main([Ljava/lang/String;)V bytecode static method
14:20:38.965 0x1aa00              mt.19       - method arguments: ([L@00000007FFF43CD0)
14:20:38.965 0x1aa00              mt.3        > pdprof/xtrace/Main.printHello()V bytecode static method
14:20:38.965 0x1aa00              mt.19       - method arguments: ()
TRCx289: Trace sleep action triggered. Sleeping for 30000 ms.
TRCx290: Finished sleeping.
Hello!!
14:21:08.966 0x1aa00              mt.9        < pdprof/xtrace/Main.printHello()V bytecode static method
JVMDUMP034I User requested Java dump using '/home/keniooi/eclipse/XtraceTest/XtraceTest/src/javacore.20260227.232108.304956.0001.txt' through -Xtrace:trigger
JVMDUMP010I Java dump written to /home/keniooi/eclipse/XtraceTest/XtraceTest/src/javacore.20260227.232108.304956.0001.txt
14:21:09.008 0x1aa00              mt.9        < pdprof/xtrace/Main.main([Ljava/lang/String;)V bytecode static method

取得できた javacore では printHello 実行が確認できたのでログはタイミングの問題かもしれません。

1XMCURTHDINFO  Current thread
3XMTHREADINFO      "main" J9VMThread:0x000000000001AA00, omrthread_t:0x00007F3B7401C260, java/lang/Thread:0x00000007FFF044E0, state:R, prio=5
3XMJAVALTHREAD            (java/lang/Thread getId:0x1, isDaemon:false)
3XMJAVALTHRCCL            sun/misc/Launcher$AppClassLoader(0x00000007FFF33210)
3XMTHREADINFO1            (native thread ID:0x4A740, native priority:0x5, native policy:UNKNOWN, vmstate:R, vm thread flags:0x00041020)
3XMTHREADINFO2            (native stack address range from:0x00007F3B7B71C000, to:0x00007F3B7B75C000, size:0x40000)
3XMCPUTIME               CPU usage total: 0.082525312 secs, current category="Application"
3XMHEAPALLOC             Heap bytes allocated since last GC cycle=368600 (0x59FD8)
3XMTHREADINFO3           Java callstack:
4XESTACKTRACE                at pdprof/xtrace/Main.printHello(Main.java:10)
4XESTACKTRACE                at pdprof/xtrace/Main.main(Main.java:5)
3XMTHREADINFO3           Native callstack:
4XENATIVESTACK               protectedBacktrace+0x12 (0x00007F3B7B64EE02 [libj9prt29.so+0x25e02])
4XENATIVESTACK               omrsig_protect+0x239 (0x00007F3B7B6533D9 [libj9prt29.so+0x2a3d9])
4XENATIVESTACK               omrintrospect_backtrace_thread_raw+0xbe (0x00007F3B7B64F2DE [libj9prt29.so+0x262de])
4XENATIVESTACK               omrsig_protect+0x239 (0x00007F3B7B6533D9 [libj9prt29.so+0x2a3d9])
4XENATIVESTACK               omrintrospect_backtrace_thread+0x87 (0x00007F3B7B64EC87 [libj9prt29.so+0x25c87])
4XENATIVESTACK               setup_native_thread+0x1e3 (0x00007F3B7B64FC53 [libj9prt29.so+0x26c53])
4XENATIVESTACK               omrintrospect_threads_startDo_with_signal+0x41f (0x00007F3B7B650DAF [libj9prt29.so+0x27daf])
4XENATIVESTACK               omrsig_protect+0x239 (0x00007F3B7B6533D9 [libj9prt29.so+0x2a3d9])
4XENATIVESTACK               _ZN18JavaCoreDumpWriter28writeThreadsWithNativeStacksEv+0x430 (0x00007F3B7B267220 [libj9dmp29.so+0x1a220])
4XENATIVESTACK               protectedWriteThreadsWithNativeStacks+0xd (0x00007F3B7B267ACD [libj9dmp29.so+0x1aacd])
4XENATIVESTACK               omrsig_protect+0x239 (0x00007F3B7B6533D9 [libj9prt29.so+0x2a3d9])
4XENATIVESTACK               _ZN18JavaCoreDumpWriter18writeThreadSectionEv+0x14b (0x00007F3B7B263EBB [libj9dmp29.so+0x16ebb])
4XENATIVESTACK               protectedWriteSection+0x1d (0x00007F3B7B25E9DD [libj9dmp29.so+0x119dd])
4XENATIVESTACK               omrsig_protect+0x239 (0x00007F3B7B6533D9 [libj9prt29.so+0x2a3d9])
4XENATIVESTACK               _ZN18JavaCoreDumpWriterC2EPKcP16J9RASdumpContextP14J9RASdumpAgent+0x3f5 (0x00007F3B7B25FEC5 [libj9dmp29.so+0x12ec5])
4XENATIVESTACK               runJavadump+0x1c (0x00007F3B7B26A3FC [libj9dmp29.so+0x1d3fc])
4XENATIVESTACK               doJavaDump+0x42 (0x00007F3B7B252192 [libj9dmp29.so+0x5192])
4XENATIVESTACK               protectedDumpFunction+0x15 (0x00007F3B7B2517D5 [libj9dmp29.so+0x47d5])
4XENATIVESTACK               omrsig_protect+0x239 (0x00007F3B7B6533D9 [libj9prt29.so+0x2a3d9])
4XENATIVESTACK               runDumpFunction+0x62 (0x00007F3B7B254FD2 [libj9dmp29.so+0x7fd2])
4XENATIVESTACK               runDumpAgent+0x15d (0x00007F3B7B25515D [libj9dmp29.so+0x815d])
4XENATIVESTACK               createAndRunOneOffDumpAgent+0x184 (0x00007F3B7B255824 [libj9dmp29.so+0x8824])
4XENATIVESTACK               triggerOneOffDump+0xb5 (0x00007F3B7B26C555 [libj9dmp29.so+0x1f555])
4XENATIVESTACK               rasTriggerMethod+0x1ba (0x00007F3B7AF0A1AA [libj9trc29.so+0x51aa])
4XENATIVESTACK               _ZN37VM_DebugBytecodeInterpreterCompressed3runEP10J9VMThread+0x286c2 (0x00007F3B7ACEFFA2 [libj9vm29.so+0xeffa2])
4XENATIVESTACK               debugBytecodeLoopCompressed+0xd2 (0x00007F3B7ACC78D2 [libj9vm29.so+0xc78d2])
4XENATIVESTACK                (0x00007F3B7AD3DEE2 [libj9vm29.so+0x13dee2])

まとめ

今回は Liberty や docker は使いませんでしたが、動きを停止させたい処理に指定して動作を確認することができます。この処理実行中に障害発生したときはどうなるのかなどのタイミングを確定させるのもできます(sleep中にサーバーをkillで停止させるなど）。

この様なオプションがあることを覚えておくといつか使えるかもしれません。

0
0
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
0
0

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?