本コラムの対象：

「JavaVMが発行しているシステムコールを見てみよう！」という気になる方。
ネイティブな世界に足を踏み入れている方、または踏み入れようとしている方。

０．はじめに

　ある程度の規模を持ったJavaアプリケーションを作成すると、あるときパフォーマンス問題が眼前に立ちはだかることがあります。 さて、どう料理しましょうか。
　hprofなどのプロファイラを使用することがまず考えられますが、場合によってはJavaVMが発行しているシステムコールの種類や数をOS側から観察することが最短経路であることもあります。
後者の道を選んだとき、さらに次の問題が立ちはだかります。「JavaVMプロセス内でCPUリソースを浪費しているスレッドは特定 できた。ではこのスレッドは、どのJavaスレッドに対応するのか？」

　このコラムでは、オペレーティングシステムからJavaアプリケーションおよびJavaVMの動作を観察するために必要となる「Javaスレッド に対応したネイティブスレッドを見つける方法」を紹介します。

　このコラムの構成は以下の通りです。

今回の内容

◆　１．SolarisとJavaVMのスレッドモデル Solarisオペレーティングシステム（以下、Solaris）マルチスレッド・プロセス・アーキテクチャ とJavaVMスレッドモデルの基本的な知識をおさらいします。 ◆　２．ネイティブスレッドからJavaスレッドを見つける方法 特定のネイティブスレッドに対応するJavaスレッドを見つける方法を紹介します。

１．SolarisとJavaVMのスレッドモデル

　まずこの章では、Solarisのマルチスレッド・プロセス・アーキテクチャとJavaVMのスレッドモデルについておさらいします。
　網羅的な説明はそのボリューム上不可能ですので、最低限知っていなければならないことにとどめていることに注意してください。
　

１－１．Solarisマルチスレッド・プロセス・アーキテクチャ


　Solarisのスレッドモデルはカーネルレベルとユーザレベルの２段階で構成されており、おおよそ下の図のようになっています。




　カーネルスレッドとはカーネルがスケジューリング対象とする唯一のスレッドであり、逆に言うとユーザスレッドはカーネルからは見ることができません。 　ユーザプロセスはLWP（ライトウェイトプロセス：軽量プロセス）によりカーネルスレッドとリンクされることで、カーネルのスレッドスケジューリングに その身を委ねます。(※)

　ここでLWPとユーザスレッドはn対nの関係でリンクしており、ユーザスレッドはカーネルスレッドのスケジューリング とは独立した優先度メカニズムを持っています。つまりユーザスレッドのスケジューリングは（カーネルレベルではなく）スレッドライブラリのレベルで行われます。
　このLWPをはさんだ２層スレッドモデルにより、カーネルは数百～数千のユーザスレッドを持つプロセスをスケジューリングするという過重労働 から開放され、ほどよい並列実行性を保つことができるようになります。

　さて、上の議論によりユーザスレッドはLWPを経由してカーネルからCPUリソースを割り当てられることが分かったわけですが、これはつまり ユーザスレッドがシステムコールの実行をカーネルに要求したときにそのシステムコールを実行するのはLWPであることを意味します。
psコマンドやprstatコマンド、trussコマンドでCPUリソースの消費率やシステムコールの実行ログを調べたとき、その最小単位がLWP単位である理由がここにあります。

　OS側からパフォーマンスの計測をするということはつまり高い負荷をもつLWPを特定するということであり、こうして我々の関心は「このLWPに対応するJavaスレッドは誰か？」 というものに移っていきます。

　(※) 中にはLWPと対応しないカーネルスレッドが存在しますが、これはカーネル自身もマルチスレッドで動作しているためであり、LWPを持たないカーネルスレッド はカーネル自身の処理を行なうスレッドだと言うことができます。

１－２．JavaVMスレッドモデル


　前節のSolarisスレッドモデルを理解しさえすれば、JavaVMのスレッドモデルは非常に簡単です（下図）。




　この図のとおり、Javaスレッド(java.lang.Thread）はユーザスレッドと1対1対応をなします。

　問題はユーザスレッドとLWPの関係ですが、これはSolarisのバージョンとJavaVMのバージョン、JavaVMのオプションにより変化します。 Solaris8上でJava1.4をデフォルトオプションで使用した場合、ユーザスレッドとLWPとの関係は多対多となり、 その比率は1対1となります（ユーザスレッドが直接LWPに結び付けられるわけではなく、各ユーザスレッドはLWPを渡り歩くかもしれません）。

　他のSolaris／JavaVMのバージョン、オプション指定時の動作については、Sunが発行しているドキュメント を参照してください。

２．ネイティブスレッドからJavaスレッドを見つける方法

　前置きが長くなりました。本題です。
　実際に特定のネイティブスレッド、つまりLWPに関連するJavaスレッドを見つける方法を紹介します。
２－１．高負荷をもつLWPの特定


　負荷の高いLWPを特定する方法を解説しきることは本コラムの趣旨から外れますので、説明に最低限必要なことのみを説明します。

　負荷の高いLWPを特定する最も簡単な方法は、prstatコマンドを使うことです。prstatコマンドを「-L」オプション付きで実行すると、LWP単位でプロセス情報 を参照することができます。

> prstat -L
   PID USERNAME  SIZE   RSS STATE  PRI NICE      TIME  CPU PROCESS/LWPID
   542 nozaki    128M   34M sleep   58    0   0:00.03 6.8% java/27
    95 root     7728K 6768K sleep   58    0   0:00.25 0.5% picld/8
    95 root     7728K 6768K sleep   58    0   0:00.12 0.2% picld/10
   547 nozaki    132M   42M sleep   58    0   0:00.06 0.2% java/4
   545 nozaki     71M   31M sleep   58    0   0:00.04 0.2% java/4

  ～略～

　第1カラムがプロセスID、第10カラムが、プロセス名とLWP番号です。上の例では、プロセスID=542であるjavaプロセスのLWP27が、 CPUを6.8%使用していることが分かります。
　以降、このLWP番号に注目して、ネイティブスレッドとJavaスレッドを追いかけることになります。

２－２．ネイティブレベルのスタックトレース取得

　prstatコマンドで得たプロセスIDを使用し、pstackコマンドによりLWPのスタックトレースを取得します。

> pstack 542
542:    /usr/j2sdk1.4.1_01/bin/java -Xms64m -Xmx128m -Duser.tmp=/export/home/s
-----------------  lwp# 1 / thread# 1  --------------------
 ff29f008 lwp_cond_wait (2cff0, 2cfd8, 0)
 ff29654c _lwp_cond_wait (2cff0, 2cfd8, 351294, 1, 1bb9c, fe18ba14) + c
 fe0d30a0 __1cHMonitorEwait6Mil_i_ (2cfa8, 0, 0, 0, fe438d7c, 0) + 364

  ～略～

-----------------  lwp# 27 / thread# 26  --------------------
 ff29f008 lwp_cond_wait (2f3c78, 2f3c60, 0)
 ff29654c _lwp_cond_wait (2f3c78, 2f3c60, 0, fa414480, 0, 0) + c
 fe0e7ac8 __1cNObjectMonitorEwait6MxipnGThread__v_ (2f3c28, 0, 5400, 57f0, 2f3a58, 5270) + 61c
 fe0e70b8 __1cSObjectSynchronizerEwait6FnGHandle_xpnGThread__v_ (ebc815fc, 0, 0, 2f3a58, ee6d0000, 0) + 180
 fe0e6db8 JVM_MonitorWait (2f3ae4, ebc816f4, 0, 0, 0, 0) + 130
 fa40bbc8 ???????? (ee2c5590, 0, ebc8176c, fa4141e8, 0, ebc81690)
 fa405c64 ???????? (ee2c5590, 3, ebc817fc, fa415064, 0, ebc81710)
 fa405c64 ???????? (ee2c5590, f63b72c8, ebc8188c, fa415030, 0, ebc81798)
 fa405fd8 ???????? (ee2e0230, ebc81900, ebc81904, fa4154b0, 0, ebc81830)
 fa405c64 ???????? (ebc81908, 0, 0, fa415030, 35d1c8, ebc818a8)
 fa400118 ???????? (ebc81994, ebc81c08, a, f63e7a58, fa40aae0, ebc81b28)
 fe0d4c10 __1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_ (ebc81c00, ebc81a60, ebc81b20, 2f3a58, 2f3a58, ebc81a74) + 25c
 fe0e695c __1cJJavaCallsMcall_virtual6FpnJJavaValue_nLKlassHandle_nMsymbolHandle_4pnRJavaCallArguments_pnGThread__v_(fe424000, 3293a0, ebc81b14, ebc81b10, ebc81b20, 2f3a58) + 190
 fe0e67bc __1cJJavaCallsMcall_virtual6FpnJJavaValue_nGHandle_nLKlassHandle_nMsymbolHandle_5pnGThread__v_ (ebc81c00, ebc81bfc, ebc81bf0, ebc81be8, ebc81be0, 2f3a58) + 60
 fe0e6744 __1cMthread_entry6FpnKJavaThread_pnGThread__v_ (2f3a58, 2f3a58, 672930, 3293a0, 33dabc, fe0e642c) + 1d8
 fe0e6454 __1cKJavaThreadDrun6M_v_ (2f3a58, 0, 0, 0, 0, 0) + 254
 fe0d33e4 _start   (2f3a58, ff37f688, 1, 1, ff37e000, 0) + 20
 ff36b728 _thread_start (2f3a58, 0, 0, 0, 0, 0) + 40

　各スタックフレームの一行目に注目します。「lwp# ○○」となっている数字（10進数）が、先ほどprstatコマンドで取得したLWP番号にあたります。
　prstatコマンドによりCPU負荷の面から着目したいLWPが特定できている場合はネイティブレベルのスタックトレース情報は必須なものではありませんが、 特定のシステムコールを発行しているLWPに着目したい場合などはpstackで得られるスタックトレースが有用な情報源となります。

２－３．Java言語レベルのスタックトレース取得


　prstatコマンド、あるいはpstackコマンドにより、注目すべきLWPとその番号が分かりました。さてこのLWPに対応するjavaスレッドは誰でしょうか。 javaのスタックトレース情報を取得し、LWPとjavaスレッドとのマッピングを取ります。

　JavaVMプロセスにSIGQUITシグナルを送信すると、JavaVMはスタックトレースを標準出力に出力します。
　このときJavaVMの起動オプションに、シグナルハンドラを無効化する「-rs」オプションが指定されていると、 スタックトレースを出力せずにcoreダンプを行ないますので注意してください。

Full thread dump Java HotSpot(TM) Client VM (1.4.1_01-b01 mixed mode):

"ED_receive_2" daemon prio=5 tid=0x303e58 nid=0x1d in Object.wait() [eb981000..eb981994]
    at java.lang.Object.wait(Native Method)
    - waiting on  (a jp.co.smg.gms.event.io.buffering.PriorityFileBufferedIOStream)
    at java.lang.Object.wait(Object.java:426)
    
  ～略～
    
"ED_receive_1" daemon prio=5 tid=0x2f3dd8 nid=0x1b in Object.wait() [ebb81000..ebb81994]
    at java.lang.Object.wait(Native Method)
    - waiting on  (a jp.co.smg.gms.event.io.buffering.PriorityFileBufferedIOStream)
    at java.lang.Object.wait(Object.java:426)
    at jp.co.smg.gms.event.io.buffering.PriorityFileBufferedIOStream.read(PriorityFileBufferedIOStream.java:142)
    - locked  (a jp.co.smg.gms.event.io.buffering.PriorityFileBufferedIOStream)
    at jp.co.smg.gms.event.io.BufferedContentsDispatcher$DispatchThread.readLoop(BufferedContentsDispatcher.java:237)
    at jp.co.smg.gms.event.io.BufferedContentsDispatcher$DispatchThread.run(BufferedContentsDispatcher.java:302)

"ED_send_1" daemon prio=5 tid=0x2f3a58 nid=0x1a in Object.wait() [ebc81000..ebc81994]
    at java.lang.Object.wait(Native Method)
    - waiting on  (a jp.co.smg.gms.event.io.buffering.PriorityFileBufferedIOStream)

　取得したスタックトレースから、各スレッドの先頭行にある「nid=0xXX」という16進数に注目します。 　この16進数が、prstatコマンドやpstackコマンドで取得したLWP番号（10進数）の16進数表現となります。 今回の例では、CPUを6.8%消費しているLWP番号27のスレッドは、Javaの世界では○○メソッドを実行しているスレッドであることが分かります。

　あとは実際のJavaコードを調査することになります。メソッド内にネストしたループ構造があったり、パフォーマンス上 ご法度とされているコードを見つけることができればしめたもの。あとは料理するだけです。
　そこまで上手くいかなくとも、少なくともOSに高い負荷をかけているスレッドは特定できます。 パフォーマンス解析を行う上で、これは非常に大きな収穫です。
４．まとめ

　さて、これでJavaの世界とネイティブの世界とをつなぐことができました。ここから本番、あなたの腕の見せ所です。
　ネイティブワールドで得られた膨大なパフォーマンス解析情報を元に、JavaVM内でくすぶっているJavaスレッドににカツをいれてやりましょう！