ASP.NET デッドロック 検知機能について (1)


こんにちは d99 です。
今回は、トラブルシューティング ネタを取り上げます。今回のネタは、お問い合わせ頂く事も多い デッドロック です。

デッドロックといっても、実際には 「以下のイベントログが記録されたんだけどどうすればいいの?」 というものがほとんどですね。

 
IIS 5.x (Windows 2000, XP) の場合

種類 : エラー
ソース : ASP.NET <バージョン>
分類 : なし
イベント ID : 1003
日付 : yyyy/MM/dd
時刻 : HH:mm:ss
ユーザー : N/A
コンピュータ : <コンピュータ名>
説明 :
デッドロック状態である可能性があるため、aspnet_wp.exe (PID: xxx) が繰り返されました。この 180 秒間に保留中の要求に対して応答は何も送信されていません。

IIS 6.0 (Windows Server 2003) 以降の場合

種類 : 警告
ソース : W3SVC-WP
分類 : なし
イベント ID : 2262
日付 : yyyy/MM/dd
時刻 : HH:mm:ss
ユーザー : N/A
コンピュータ : <コンピュータ名>
説明 :
次の理由のため、ISAPI ‘C:\Windows\Microsoft.net\Framework\<バージョン>\aspnet_isapi.dll’ は自身が危険な状況であると報告しました: ‘デッドロックが検出されました’。

現象の詳細

このイベントログは、ASP.NET のデッドロック検知機能が動作した事を示しています。つまり、このイベントログを ASP.NET 君になったつもりで意訳すると、「ASP.NET アプリケーションが長時間無応答になってるよ?たぶんデッドロックだと思うから再起動しとくね~」 という感じです。ですので、このイベントログが記録されたら、その aspnet_wp.exe や w3wp.exe はもう再起動されています。

また、このデッドロック検知機能は、何かのリソースに対するロックを監視していて 「おっとデッドロック発生!」 と具体的な何かを見つけて検知しているわけではありません。ある条件に従ってデッドロックの疑いを感知しているに過ぎません。その条件は以下の二つです。

  1. responseDeadlockInterval (既定値3分) 以上、ASP.NET アプリケーションが要求を受け取っているのに応答を返していない
  2. リクエストの同時実行処理数が上限 (ASP.NET 2.0 での既定値は 12 x CPU数) に達している

これは、例えば以下のようなシナリオを想定しています(下記は IIS 6.0 での場合です)。

  1. あるリクエスト処理でデータベースへコマンドを実行するが、データベース側のなんらかの要因(デッドロック等)によってハングアップしてしまう
  2. 後続のリクエスト処理でも同じデータベースへのコマンドを実行して、1. の完了を待ってハングアップする。これがどんどん溜まっていく
  3. そのまま誰も応答を返せず 3分が経過、かつ、ハングアップしたリクエスト数が 12xCPU数 を超えた時点で ASP.NET はデッドロックを検知した旨を W3SVC に知らせ、イベントログに記録する
  4. W3SVC は w3wp.exe が不健康とマークされた事を確認して、そのプロセスに対して終了依頼する
  5. また W3SVC は(古いプロセスの終了完了を待たずに)新しい w3wp.exe を起動し、それ以降に到着したリクエストを新しいプロセスへルーティングする
  6. 終了依頼に応じない場合、アプリケーションプールの [ワーカープロセスをシャットダウンする時間] の設定値だけ待機した後、強制終了する。その際、強制終了した事をイベントログに記録する

IIS 6.0 では W3SVC が w3wp.exe を監視する、という仕組みになっているので上記のような動きになります。IIS 5.x でもこれに “準じた” 動きになっていると考えてください。ちなみに 5. は 「オーバーラップド リサイクル」 と呼ばれる、なるべくアプリケーションのダウンタイムを短くする動作ですね。これは w3wp.exe でも aspnet_wp.exe でも観測できます。

現象に関連する設定値

設定値 responseDeadlockInterval は、machine.config、processModel 要素の属性です。同時実行数の最大値も同要素の maxWorkerThreads とかで調整できるのですが、ちょっとややこしいので、一応その事が記載されているサポート技術情報だけご紹介しておきます (ASP.NET のスレッド制御についてはまた日を改めて書きたいと思います)。

.NET Framework 一般リファレンス – processModel 要素 (ASP.NET 設定スキーマ)
http://msdn.microsoft.com/ja-jp/library/7w2sway1.aspx

ASP.NET アプリケーションから Web サービス要求を行うと、競合、パフォーマンスの低下、およびデッドロックが発生する
http://support.microsoft.com/kb/821268/ja
——————-
ASP.NET では、次の個数を超える要求は同時に実行されません。
(maxWorkerThreads*number of CPUs)-minFreeThreads
——————-

もう一つ関連する設定値は、web.config の compilation 要素、debug 属性です。

.NET Framework 一般リファレンス – compilation 要素 (ASP.NET 設定スキーマ)
http://msdn.microsoft.com/ja-jp/library/s10awwz0.aspx

この要素が true だと、所謂スクリプトタイムアウトがおきません。ASP.NET のスクリプトタイムアウトは web.config ファイル、httpRuntime 要素の executionTimeout 属性で設定されていて、既定値は 90秒です。ですから、通常、処理に 90秒以上かかっていれば、これによってプロセスではなくスレッド(処理)が強制終了されて、プロセスが再起動する事は避けられます。

.NET Framework 一般リファレンス – httpRuntime 要素 (ASP.NET 設定スキーマ)
http://msdn.microsoft.com/ja-jp/library/e1f13641.aspx

ただし、この executionTimeout は、ASP.NET のページの処理、例えば TextBox に値を入れたり取り出したりといった処理中には発生し得るのですが、データベースにアクセス中とか、Web サービスや他のコンポーネントを呼び出し中、といった外部処理の完了を待っている最中には発生しません。ですので先ほどのようなシナリオでは executionTimeout が発生せず、結局デッドロック検知が作動してしまう事になります。

ただ、Visual Studio.NET 2003 ですと、自動的に生成される web.config で debug 属性が true なので、パフォーマンスが出なかったり、メモリ使用量が多めになってしまったりといったトラブルが起きるので、できれば false にして頂く事をおすすめしています。

次のアクション

ASP.NET 1.0 の初期には 「デッドロック誤検知」 の障害があったのですが(サポート技術情報 321792)、わりと早い段階で修正されてしまったので、このイベントログが出てるという事は即ち、アプリケーションがどこかの処理でハング(応答停止)してしまっていると言える場合が多いですね。

エラーに至る仕組みはわかったけど、で、どうすんだ?、という事になるかと思うのですが、基本的にはデバッグで 「詰まった処理」 を特定する必要があります。アプリケーションのログ機能等から特定していく、というのが一般的なようですが、ログ機能がない、カスタムログから特定できない、なぜか本番運用中にしか出ない等々の事情がある場合には、それも難しいかと。

というわけでそんな場合は運用デバッグの出番になるわけですが、まずは次回のエントリで意図的にデッドロック検知を起こさせる方法をご紹介しようかと思います。そして、それを使って次々回に実際にデバッグしてみる、といった感じで進めましょう。ご期待ください。

 

ではまた。
d99 でした。

Skip to main content