イベントログに EventLogWebEventProvider のエラーが記録される現象について (2)

こんにちは d99 です。
前回に引き続き、以下のエラーについて取りあげます。

イベントの種類: エラー
イベントソース: ASP.NET 2.0.50727.0
イベントカテゴリ: Web イベント
イベント ID: 1301
System.Web.HttpException: EventLogWebEventProvider プロバイダでは、エラー コード 0x80070057 でイベントをログに記録できませんでした。

前回、このエラーは「エラーを記録するのに失敗したエラー」だと書きました。このエラーの直接的な原因については前回の記事を参照してください。今回はさらにその原因がなぜ起きたのか、という三段論法の二段目にあたるお話です :-)

前回の末尾でこれはほぼ ViewState のエラーが原因だと書きました。実は、他の一般的なプログラム上の例外等では、イベントログに記録される内容はスタックバックトレース(関数呼び出し履歴)などで、それほど長くはなりません。しかし、ViewState のエラーが起きた場合だけは、ASP.NET はエラーとなった ViewState を可能な限りイベントログに記録しようとします。その際にイベントログ文字列長上限に合わせて記録文字列を切り詰めてしまうため、この例外になり得ます。

ViewState とは ASP.NET Web フォームの状態を保存するための隠しフィールドです。ASP.NET でグリッドなどにデータを表示する簡単なページを作ってブラウザで表示し、HTML ソースを確認すると <input type="hidden" name="__VIEWSTATE" value="..."> という input タグが確認できます。ご存じの通り、ASP.NET はこの値を用いてページ状態を維持しています。ViewState 自体については以下の記事などが分かりやすいかと思います。

.NET TIPS [ASP.NET]ビューステートに保存されるものは?
https://www.atmarkit.co.jp/fdotnet/dotnettips/041viewstate/viewstate.html

.NETエンタープライズ Webアプリケーション開発技術大全 - Webアプリケーションの状態管理
https://www.atmarkit.co.jp/fdotnet/entwebapp/entwebapp03/entwebapp03_02.html

ASP.NET ビューステートの概要
https://msdn.microsoft.com/ja-jp/library/bb386448.aspx

では、ViewState でどういった問題があるとエラーになるか?ですが、ViewState は簡単に言うと、サーバーで生成してブラウザへ送った値と、ブラウザがサーバーへPOSTして送り返した値が一致する必要があります(それ以外にも負荷分散等で別のサーバーへ送り返された場合なども考えられますが、それらについては今回は割愛します)。

要するに、サーバーがブラウザへ "ABC" と送ったのに、ブラウザが "AB" しか送り返してこなかった場合、ViewState のエラーになります。そして、今回「エラーを記録するのに失敗したエラー」になるような ViewState は 32kB もしくはそれを超えるほど「大きな」ViewStateである必要があります。この条件を見たし、かつ、プログラムやネットワークに問題がないと仮定すると、最も考えられる理由は「ボタンの二度押し」かと思います。

非常に ViewState の大きいページでボタンを二度押しすると、ブラウザは途中までPOSTしたところで一旦RSTパケットを投げて送信を打ち切り、それからもう一回データをサーバーへ送り直します。この途中まで送って打ち切ったリクエストが ViewState のエラーを引き起こすわけです。ブラウザは後から送った要求の応答を正常に受け取るため、ブラウザ画面上にエラー等は発生しない事が一般的です。

他にも、送信中にブラウザを閉じてしまう、window.close() の JavaScript を ASP.NET のボタン Web コントロールに加えてしまう(サーバーへPostBackしようとしつつブラウザウィンドウが閉じられるため、同様の状況になります)、といったブラウザ側から途中で通信を切る可能性のある操作/実装が原因となる事が多いようです。

これら、「クライアント側から通信を切ってしまった」 事は、IIS ログから判断が可能です。IIS ログの sc-win32-status フィールドに 64 が記録されている場合、IIS よりもクライアント側(中間機器や通信ドライバを含む)で通信が切断された事を示しています。このログがイベントログと同時刻にあれば、こういったクライアントからの中途半端な ViewState の送信による可能性が高いと思います。

というわけでアプリケーションの動作に問題が起きていない場合、このエラーは無視できる可能性が高いのですが、それでもやっぱり目障りなので消したいと感じられる方はいらっしゃるかと思います。少し長くなってきましたので一旦区切り、次回は ViewState のエラーをイベントログに記録させない設定を紹介したいと思います。長くなってしまってすみません。もう少しお付き合いください。

ではまた。
d99 でした。