スレッドダンプの森で覚えた死のロックへの違和感：現場から学ぶWebアプリ開発のトラブルハック（11）（2/3 ページ）

本連載は、現場でのエンジニアの経験から得られた、APサーバをベースとしたWebアプリ開発における注意点やノウハウについて解説するハック集である。現在起きているトラブルの解決や、今後の開発の参考として大いに活用していただきたい。（編集部）

[茂呂範，株式会社NTTデータ]

森の中で覚えた違和感

　違和感を覚えたのは、次の個所だ。

*** 一部省略されたコンテンツがあります。PC版でご覧ください。 ***

　なんと、ほかのスレッドが待たされている排他制御個所と、このスレッドが待ち状態になっている個所で、利用されているロック用のオブジェクトが異なるのだ。

■Javaで排他制御を必要とする際に見落としがちなもの

　Javaで排他制御を必要とするプログラムを書く際に見落としがちなものの1つに、waitメソッドを利用した際のスレッドの待機時での、ロックオブジェクトに対するロック状態がある。ここでいったん、次のサンプルプログラムを見てみよう。

*** 一部省略されたコンテンツがあります。PC版でご覧ください。 ***

　賢明な読者なら、このプログラムの問題点がすぐに分かったと思う。このサンプルプログラムは、2つのスレッドがlock1、lock2の順番でロックを獲得しながら、最後にlock2でwait状態へと遷移するプログラムだ。

　ロックを獲得する順番が、2つのスレッド間で同じであるため、このプログラムはデッドロックを引き起こさない。そのため直感的には、2つのスレッドはともにwait状態へと遷移してほしいところだ。

■ロックにかかわるJavaのObject.wait()メソッドの仕様

　さて、このプログラムのどこに問題が発生するかを説明しよう。

図2　2重ロックのシーケンス図

　ロックにかかわるJavaのObject.wait()メソッドの仕様を確認すると、次のような記述がある。

「現在のスレッドはこのオブジェクトのモニターのオーナでなければなりません。スレッドはこのモニターの所有権を解放し、別のスレッドが notify メソッドまたは notifyAll メソッドを呼び出してこのオブジェクトのモニター上で待機するスレッドに通知を出すまで待機します。そのあと、スレッドはモニターの所有権を再度取得するまで待機してから実行を再開します」（引用：ObjectクラスのwaitメソッドのAPIドキュメント）

　ここでは、Object.wait()呼び出し時には、Objectのロックを解放すると記載されている。逆にいえば、waitメソッドを呼び出したObject以外の取得済みロックについては解放しないことを意味している。そのため、上記プログラム1を実行すると、次のようなスレッドダンプを得ることになる。

*** 一部省略されたコンテンツがあります。PC版でご覧ください。 ***

　このスレッドダンプを読むと、Thread1が「lock2(0x238b5cd8)」でwait状態へと遷移するものの、「lock1(0x238b5cd0)」のロックを解放しないため、Thread2は、lock2でロック獲得待ちのためブロックされている。

　気を付けていれば、このようなミスが発生することは少ないと思われるかもしれない。

■そして、隠れ2重ロックも

　では、次のプログラムではどうだろうか。

*** 一部省略されたコンテンツがあります。PC版でご覧ください。 ***

　一見、何も問題がないように見えるだろう。しかし、多くのAPIドキュメントには、スレッドがロックを保持してwait状態へと遷移するか否かという記述はない。そのため、SomeClassクラスのsomeMethodメソッドのソースコードを確認せずに、同じような事象が発生しないと自信を持って答えることは難しい。

　このように、2重ロックは非常に気持ちの悪い違和感を覚える実装だ。しかし、必ずしも問題が発生する訳ではない。また、システムがレスポンスを返さなくなるという問題の原因特定には至っていない。

　そこで、さらに詳細にスレッドダンプを解析することにした。

■スタックトレースによるスレッドの分類と集計

　Javaアプリケーション内の動作状況の全貌（ぜんぼう）を把握するため、筆者はよくスタックトレースによるスレッドの分類と集計を行っている。すべてのスレッドを、その状態ごとに分類し、集計していく作業だ。今回は、Samuraiで赤く表示されているスタックトレースを1つ1つ確認することで、次のような分類と集計を得た。

表　スタックトレース集計表

	スタックトレース種別	1回目のスレッドダンプ	2回目	3回目
	DBCPにて待機	1	1	1
	DBConnectionPool.get	34	42	55
	DBConnectionPool.release	15	15	15

　これまで確認したスタックトレースとは異なるスレッドが存在した。「DBConnectionPool.release」である。この状態のスレッドは、事象発生後のスレッドダンプよりずっと同じ数だけ存在しており、次のスタックトレースを出力していた。

*** 一部省略されたコンテンツがあります。PC版でご覧ください。 ***

　このスタックトレースを確認した瞬間、さらなる違和感を体験することとなる。