コールスタックレベルで Java ファイル I/O をデバッグするとは、native の write() システムコール一回一回を、それを引き起こした Java のビジネスメソッドまで遡ってつなぐことです —— IDE のブレークポイントでは届かず、coredump にも残らない情報です。本記事ではタイムトラベル再生でその方法を示します:実行中の Java プロセスを録画し、write() でブレークし、JNI から Files.write の呼び出し元まで、Java スタック全体を再構築します。

IDE のブレークポイントと coredump が Java ファイル I/O で届かないところ

Java 開発者が最初に手を伸ばす二つのツールは、「このファイル書き込みを引き起こしたビジネスメソッドはどれか」という問いに答えられません:

  • IDE のブレークポイントは JVM の境界で止まる。 Java メソッドで一時停止することはできますが、libc の中の write() システムコール —— ファイル書き込みが実際にプログラムから離れる場所 —— にブレークポイントを打つことはできません。
  • Native コールスタックは JNI 層で途切れる。 C 層のデバッガをアタッチしてファイル書き込みで bt を実行しても、Java_sun_nio_ch_FileDispatcherImpl_write0 までしか辿れず、どの Java メソッドが引き起こしたかは分かりません。
  • coredump は一瞬のスナップショットにすぎない。 coredump はある一時点の状態を捕捉するもので、そこに至るまでの実行経路を再現できません。過去の各 write や、それぞれの時点での Java スタックを遡って確認することはできないのです。

タイムトラベル再生はこの両方の穴を埋めます:実行全体を記録して時間軸を自由に移動でき、native システムコールでブレークして各停止時点で完全な Java スタックを再構築できます。

Native write() システムコールから完全な Java コールスタックを再構築する

再構築は次の 2 つの要素で成り立ちます:

  1. UDB は JVM プロセスの実行全体を記録するので、libc の write() を含むあらゆるシステムコールで一時停止し、時間軸を前後に移動できます。

  2. OpenResty XRay は Y 言語スクリプト java-udb.y.py を提供します。UDB 内で読み込むと java_bt コマンドが追加されます。java_bt は任意のブレークポイントで完全な Java コールスタックを表示します —— C:__libc_write から JNI 層を経てビジネスメソッドまで —— ネイティブの bt では C 層のバックトレースしか得られない状況を、エンドツーエンドの完全なパスへと変換します。

以降では、実際の Java プロセス上で記録・ブレーク・再構築を順に実演します。

タイムトラベル再生で Java ファイル I/O を段階的にデバッグする

以下の 5 ステップでは、実行中の Java プロセスを記録し、native の write() システムコールにブレークポイントを打ち、各 write の背後にある Java コールスタックを再構築します:

ステップ 1:アプリケーション実行トレースの記録

まず、UDB の Live Record ツールを使用して、Java アプリケーションの実行プロセスを記録します。

  1. Live Record ツールを使用し、実行中の Java アプリケーションのサンプルを記録します。

  2. UDB ツールで記録されたサンプルをロードし、デバッグ環境を設定します:

udb -ex "set pagination off" -ex "set python print-stack full" java.rec

ステップ 2:ファイル操作のブレークポイント設定

UDB 環境にて、ファイル書き込み操作をキャプチャするためのブレークポイントを設定します。

start 1> break write
start 1> c
Continuing.
[Switching to Thread 3923049.3923068]

Thread 20 "Thread-0" hit Breakpoint 1.768, 0x00007ffff7cfdb40 in write () from /tmp/undodb.3976686.1747987405.935444.61ae9aec99c4629b/debuggee-1-bus1z2h5/symbol-files/lib64/libc.so.6

ステップ 3:下位層 C コールスタックの分析

bt コマンドを使用して、現在の C 層のコールスタックを確認します:

4% 7,955> bt
#0  0x00007ffff7cfdb40 in write () from /tmp/undodb.3976686.1747987405.935444.61ae9aec99c4629b/debuggee-1-bus1z2h5/symbol-files/lib64/libc.so.6
#1  0x00007ffff7e32c5f in Java_sun_nio_ch_FileDispatcherImpl_write0 (env=0x7ffff0181290, clazz=<optimized out>, fdo=<optimized out>, address=140733730265536, len=81)
    at src/java.base/unix/native/libnio/ch/FileDispatcherImpl.c:118
#2  0x00007fffe0baacf6 in ?? ()
#3  0x000000062a39ed70 in ?? ()

C のコールスタックからは、システム下位層の write システムコールがトリガーされていることが確認できます。しかし、これは JNI 層の情報のみが表示されており、Java のビジネスロジックコードの完全な呼び出しパスを直接確認することはできません。

ステップ 4:Java の完全なコールスタックの分析

  1. OpenResty XRay が提供する Java コールスタック分析ツールをロードします:
4% 7,955> source java-udb.y.py
  1. java_bt コマンドを用いて、完全な Java コールスタックを取得します:
4% 7,955> java_bt
Start tracing...
C:__libc_write
sun.nio.ch.FileDispatcherImpl:write0(Native Method)
@FileDispatcherImpl.java:62
sun.nio.ch.FileDispatcherImpl:write
@IOUtil.java:114
sun.nio.ch.IOUtil:writeFromNativeBuffer
@IOUtil.java:75
sun.nio.ch.IOUtil:write
@IOUtil.java:67
sun.nio.ch.IOUtil:write
@FileChannelImpl.java:288
sun.nio.ch.FileChannelImpl:write
@Channels.java:89
java.nio.channels.Channels:writeFully
@Channels.java:158
java.nio.channels.Channels$1:write
@StreamEncoder.java:223
sun.nio.cs.StreamEncoder:writeBytes
@StreamEncoder.java:325
sun.nio.cs.StreamEncoder:implClose
@StreamEncoder.java:165
sun.nio.cs.StreamEncoder:close
@OutputStreamWriter.java:252
java.io.OutputStreamWriter:close
@BufferedWriter.java:263
java.io.BufferedWriter:close
@Files.java:3579
java.nio.file.Files:write
@Processor.java:42
FileWriterTask:run
@Thread.java:840
java.lang.Thread:run

この完全な Java コールスタックを通じて、ビジネスロジックの FileWriterTask:run メソッドから始まり、Java 標準ライブラリの Files.write メソッドを経て、基盤となるシステムコールに至るまでの完全なパスを明確に確認することができます。これは、アプリケーションのファイル操作の挙動を理解し、パフォーマンスのボトルネックを特定し、あるいはファイル操作関連の問題を調査する上で、極めて重要な価値を持ちます。触発したビジネスメソッドが判明したら、OpenResty XRay を使ってこのメソッドに渡された引数を実行時に取得することもできます。Java エージェントもバイトコード計装も不要です。

時間軸を跨いだファイル書き込みコールスタックの比較

UDB のタイムトラベルデバッグ機能は、その最も強力な特長の一つです。この機能を利用することで、記録された実行トレース内を自由に前進または巻き戻し、異なるファイル操作の時点を正確に特定し、各書き込み操作の完全なコンテキストとコールスタックを包括的に分析することが可能になります。この能力は、複雑なファイル操作の問題を調査する際に特に重要となります。

この点を検証するため、プログラムの実行を継続し、次のファイル書き込み操作を捕捉します:

8% 16,337> c
Continuing.

Thread 20 "Thread-0" hit Breakpoint 1.768, 0x00007ffff7cfdb40 in write () from /tmp/undodb.3976686.1747987405.935444.61ae9aec99c4629b/debuggee-1-bus1z2h5/symbol-files/lib64/libc.so.6

8% 16,337> java_bt
Start tracing...
C:__libc_write
sun.nio.ch.FileDispatcherImpl:write0(Native Method)
@FileDispatcherImpl.java:62
sun.nio.ch.FileDispatcherImpl:write
@IOUtil.java:114
sun.nio.ch.IOUtil:writeFromNativeBuffer
@IOUtil.java:75
sun.nio.ch.IOUtil:write
@IOUtil.java:67
sun.nio.ch.IOUtil:write
@FileChannelImpl.java:288
sun.nio.ch.FileChannelImpl:write
@Channels.java:89
java.nio.channels.Channels:writeFully
@Channels.java:158
java.nio.channels.Channels$1:write
@StreamEncoder.java:223
sun.nio.cs.StreamEncoder:writeBytes
@StreamEncoder.java:325
sun.nio.cs.StreamEncoder:implClose
@StreamEncoder.java:165
sun.nio.cs.StreamEncoder:close
@OutputStreamWriter.java:252
java.io.OutputStreamWriter:close
@BufferedWriter.java:263
java.io.BufferedWriter:close
@Files.java:3579
java.nio.file.Files:write
@Processor.java:203
CoreWriterTask:run
@Thread.java:840
java.lang.Thread:run

2 回のキャプチャで取得したコールスタックを比較することで、以下の点が明確になります。

  1. 1 回目の書き込み操作は、FileWriterTask:run メソッド(Processor.java の 42 行目)に起因します。
  2. 2 回目の書き込み操作は、CoreWriterTask:run メソッド(Processor.java の 203 行目)に起因します。

この分析手法は、ファイル書き込み操作のみならず、ファイル読み取りやネットワーク通信といった、あらゆる I/O 経路のデバッグ分析にも適用可能です。より広範なプロファイリングの観点では、OpenResty XRay は JVM セーフポイントなしでJava アプリケーションの CPU、off-CPU、ディスク I/O 使用状況を分析することも可能です。

OpenResty XRay と UDB を組み合わせた動的分析機能は、アプリケーションにおけるファイル操作の挙動パターンを全面的に洞察することを可能にし、単一時点の状態しかキャプチャできない従来のデバッグ手法の限界を打破します。特に、プロセスが既に終了している、あるいは存在しない状況において、従来の GDB による coredump 分析と比較して、UDB のリバースデバッグ(巻き戻し分析)能力は、その独自の優位性を発揮します。

coredump はプログラムがクラッシュした瞬間の静的なスナップショットしか提供できず、クラッシュ前の一定期間における完全な実行パスを再現することはできません。一方、UDB はその記録機能を通じて、元のプロセスがもはや実行されていない場合でも、OpenResty XRay にプログラムの完全な実行履歴を自在に探索する能力を付与します。これにより、任意の時点におけるプログラムの状態と挙動の詳細を精密に調査でき、真に時間軸上での全方位的なデバッグを実現します。

よくある質問

Java のファイル書き込みの完全なコールスタックを見るには?

記録された JVM 実行中で native の write() システムコールにブレークポイントを打ち(UDB の break write)、java_bt を実行します。これは source java-udb.y.py で OpenResty XRay の Y 言語スクリプトをロードすると追加されるコマンドです。最下部の C:__libc_write から書き込みを起こしたビジネスメソッドまで、完全な Java スタックが出力されます。

タイムトラベルデバッグと coredump 分析の違いは?

coredump はクラッシュ時点の一瞬のスナップショットで、状態は見えますが、そこに至った経路を再生することはできません。タイムトラベルデバッグは実行全体を記録するので、前後に移動でき、任意のシステムコールで一時停止でき、実行中の過去のあらゆる時点でコールスタックを再構築できます。

なぜ C 層の bt は JNI までしか見えず、Java のビジネスメソッドが見えないのか?

C 層デバッガの bt コマンドは C のスタックフレームを辿ります。Java コードがファイル書き込みを行うと、C 層のトレースは JNI エントリポイント Java_sun_nio_ch_FileDispatcherImpl_write0 に到達してそこで終わります。JVM のインタプリタフレームや JIT フレームは標準的な C フレームではないためです。それらを展開するには JVM を理解したツールが必要で、OpenResty XRay の java_bt コマンドがそれを行います。

まとめ

UDB と OpenResty XRay が提供する Java コールスタック分析機能を組み合わせることで、開発者はこれまでにないレベルでアプリケーションの挙動に対する洞察力を得ることができます。タイムトラベルデバッグと完全なコールスタック分析を通じて、開発者は以下のことが可能になります。

  1. ファイル操作の発生源とコンテキストを正確に特定
  2. I/O パフォーマンスのボトルネックを詳細に分析
  3. ファイル操作に関連する問題を効率的にトラブルシューティング
  4. ファイル操作のセキュリティと正確性を全面的に検証

このような詳細な分析能力は、Java アプリケーションの開発において極めて重要です。特に、マイクロサービスが主流となった現代において、この能力は開発の成否を分ける鍵となります。

本稿の実践的なデモンストレーションが、UDB と OpenResty XRay の応用シーンとその強力さをご理解いただく一助となれば幸いです。もし貴社でも複雑なデバッグ問題にお悩みのようでしたら、ぜひこの強力な組み合わせをお試しください。

OpenResty XRay について

OpenResty XRay動的トレーシング製品であり、実行中のアプリケーションを自動的に分析して、パフォーマンスの問題、動作の問題、セキュリティの脆弱性を解決し、実行可能な提案を提供いたします。基盤となる実装において、OpenResty XRay は弊社の Y 言語によって駆動され、Stap+、eBPF+、GDB、ODB など、様々な環境下で複数の異なるランタイムをサポートしております。

著者について

章亦春(Zhang Yichun)は、オープンソースの OpenResty® プロジェクトの創始者であり、OpenResty Inc. の CEO および創業者です。

章亦春(GitHub ID: agentzh)は中国江蘇省生まれで、現在は米国ベイエリアに在住しております。彼は中国における初期のオープンソース技術と文化の提唱者およびリーダーの一人であり、Cloudflare、Yahoo!、Alibaba など、国際的に有名なハイテク企業に勤務した経験があります。「エッジコンピューティング」、「動的トレーシング」、「機械プログラミング」 の先駆者であり、22 年以上のプログラミング経験と 16 年以上のオープンソース経験を持っております。世界中で 4000 万以上のドメイン名を持つユーザーを抱えるオープンソースプロジェクトのリーダーとして、彼は OpenResty® オープンソースプロジェクトをベースに、米国シリコンバレーの中心部にハイテク企業 OpenResty Inc. を設立いたしました。同社の主力製品である OpenResty XRay動的トレーシング技術を利用した非侵襲的な障害分析および排除ツール)と OpenResty XRay(マイクロサービスおよび分散トラフィックに最適化された多機能ゲートウェイソフトウェア)は、世界中の多くの上場企業および大企業から高い評価を得ております。OpenResty 以外にも、章亦春は Linux カーネル、Nginx、LuaJITGDBSystemTapLLVM、Perl など、複数のオープンソースプロジェクトに累計 100 万行以上のコードを寄与し、60 以上のオープンソースソフトウェアライブラリを執筆しております。

翻訳

英語版の原文と日本語訳版(本文)をご用意しております。読者の皆様による他の言語への翻訳版も歓迎いたします。全文翻訳で省略がなければ、採用を検討させていただきます。心より感謝申し上げます!