- PR -

スレッドステータス "waiting on condition"

投稿者投稿内容
カーニー
ぬし
会議室デビュー日: 2003/09/04
投稿数: 358
お住まい・勤務地: 東京
投稿日時: 2005-04-20 12:18
Javaのスレッドのステータスについて教えて下さい。

環境
OS: Linux(Red Hat 9)
JVM: Sun J2SE 1.4.2-b28

Tomcatアプリがハングしたので、kill -3でスレッドダンプを取得してみました。

ハングの原因になっているスレッドのアタリはつきました。あるスレッドが、バックエンドのPostgreSQLにアクセスする際、JDBCドライバのコードの中で処理が止まっているようです。そのスレッドがホールドしているオブジェクトのロックを、他のスレッドが待ってしまっている状態です。

さて、問題のスレッドのステータスは "waiting on condition" となっているのですが、これは何を意味するのでしょうか? 時間を置いて数回ダンプしても状態が変わらないのですが、コールスタックのトップに表示されている部分のコード(JDBCドライバの中)を見ても、Stringオブジェクトをnewしているだけで、なぜ waiting となるのかが理解できません。

以下はスレッドダンプの該当部分です。

コード:
"Thread-239" daemon prio=1 tid=0x0816aa20 nid=0x3812 waiting on condition [547fe000..547fec98]
        at org.postgresql.core.Encoding.decode(Encoding.java:167)
        at org.postgresql.PG_Stream.ReceiveString(PG_Stream.java:255)
        at org.postgresql.core.QueryExecutor.receiveCommandStatus(QueryExecutor.java:190)
        at org.postgresql.core.QueryExecutor.execute(QueryExecutor.java:89)
        - locked <0x4743cf40> (a org.postgresql.PG_Stream)
        at org.postgresql.jdbc1.AbstractJdbc1Connection.ExecSQL(AbstractJdbc1Connection.java:482)
        at org.postgresql.jdbc1.AbstractJdbc1Connection.ExecSQL(AbstractJdbc1Connection.java:461)
        at org.postgresql.jdbc1.AbstractJdbc1Connection.openConnection(AbstractJdbc1Connection.java:375)
        at org.postgresql.Driver.connect(Driver.java:122)
        at java.sql.DriverManager.getConnection(DriverManager.java:512)
        - locked <0x4e16bac0> (a java.lang.Class)
        at java.sql.DriverManager.getConnection(DriverManager.java:193)
        - locked <0x4e16bac0> (a java.lang.Class)
        at org.apache.commons.dbcp.DriverManagerConnectionFactory.createConnection(DriverManagerConnectionFactory.java:46)
        at org.apache.commons.dbcp.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:290)
        - locked <0x46b9bf58> (a org.apache.commons.dbcp.PoolableConnectionFactory)
        at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:771)
        at org.apache.commons.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:95)
 :
 : (以下省略)



スレッドのステータス "waiting on condition" について何かご存知の方、または上記問題の解決に役立ちそうな情報をお持ちの方、ぜひ教えて下さい。よろしくお願いします。
かつのり
ぬし
会議室デビュー日: 2004/03/18
投稿数: 2015
お住まい・勤務地: 札幌
投稿日時: 2005-04-20 12:45
私もあまり詳しくないですが、参考までに。
http://www1.jpn.hp.com/products/software/development/java/tips/tune/p23.html
シュン
ぬし
会議室デビュー日: 2004/01/06
投稿数: 328
お住まい・勤務地: 東京都
投稿日時: 2005-04-20 13:56
もしかして、waiting for conditionってデッドロックでは
なくて、単なるコンテキストスイッチ待ちだったりしませんか?

何度スタックをとっても、停止位置が同じ場所になります?
カーニー
ぬし
会議室デビュー日: 2003/09/04
投稿数: 358
お住まい・勤務地: 東京
投稿日時: 2005-04-20 14:32
かつのりさん、シュンさん、コメントどうもありがとうございます。

引用:

シュンさんの書き込み (2005-04-20 13:56) より:
もしかして、waiting for conditionってデッドロックでは
なくて、単なるコンテキストスイッチ待ちだったりしませんか?

何度スタックをとっても、停止位置が同じ場所になります?



今回の現象はデッドロックではないと思います。ダンプを見る限りは。
停止位置は常に同じで、完全にスレッドの処理がストップしているように見えます。

コンテキストスイッチかどうかは分かりませんが、JVMの外側のリソースを待っている可能性はありそうですね。

といっても、そこから先の調査方法が思い浮かばないのですが、何か良いアイディアはありますか?
シュン
ぬし
会議室デビュー日: 2004/01/06
投稿数: 328
お住まい・勤務地: 東京都
投稿日時: 2005-04-20 15:21
知見のある人が見つかるならその人に聞くのが早いですよね^^;

それが期待できないなら、わたしの場合自分で追いますね。
デバッグモードでTomcatを動かして、再現するまで待って、再現
したらスタックから見える変数をインスペクトしてみる(場合に
よってはJDBCドライバのソースコードを改変してみて動作チェッ
クとか)という。

ネイティブライブラリ内部での問題でなければ、結構見えるもの
だったりします。幸い再現が簡単な様子ですので、意外と簡単に
分かるかもしれませんよ。
カーニー
ぬし
会議室デビュー日: 2003/09/04
投稿数: 358
お住まい・勤務地: 東京
投稿日時: 2005-04-20 18:20
引用:

シュンさんの書き込み (2005-04-20 15:21) より:
幸い再現が簡単な様子ですので、意外と簡単に分かるかもしれませんよ。



残念ながら「稀に」起こるのです。

再現ケースが特定できていないのですが、幸いにも手元のVMware環境で問題が発生していますので、この状況をスナップショットとして保存することができました。

デバッグモードでの問題再現を試みる他にも、この状態でコアを吐かせて解析するなどの方法も検討してみます。
とんび
常連さん
会議室デビュー日: 2003/07/11
投稿数: 32
投稿日時: 2005-05-26 18:22
自分も似たような現象がおきました。
http://www.blackdown.org/java-linux/java-linux@java.blackdown.org/java-linux-msg00092.html
ここら辺はどうでしょう。
カーニー
ぬし
会議室デビュー日: 2003/09/04
投稿数: 358
お住まい・勤務地: 東京
投稿日時: 2005-05-27 13:10
とんびさん、情報どうもありがとうございます。

非常に興味深い情報ですね。すぐにでも試してみたいのですが、取得したVMwareスナップショットを既にDVDに退避してしまいまして、環境を復活させてテストする時間がありません。

いつになるか分かりませんが、必ず結果は報告しますので、しばらくお待ち下さい。

スキルアップ/キャリアアップ(JOB@IT)