IISのエラーログ「Request_Cancelled」を調べた結果
背景
稼働中のWebサービスからエラー通知が来ていたため、その原因を調査した。稼働中のWebサービスはWindowsサーバーのため、WebサーバーはIISを利用していた。
私はこれまでNginxしか触ったことがなかったため、ログの場所や意味なども調べながら調査した。その辺りも含めて本記事にメモとして残す。
調査
Windowsサーバーにおけるcatコマンド
linuxで当たり前に使っているcatやlessコマンドは、DOSでは使えなかったためこちらも調べた。typeコマンドやmoreコマンドによりファイルの内容を表示できた。
よく使ったコマンド: type ファイル名 | more
IISのログ
- IISにおいて必要となる、基本的なログ情報
個人的にはアクセスログ、エラーログ、ログの設定ファイルの三つを押さえれば問題なしと思った。
https://jpdsi.github.io/blog/web-apps/LogCollection1/
アクセスログ
-
場所
%SYSTEMDRIVE%\inetpub\logs\LogFiles
https://www.keicode.com/iis/iis-access-log.php -
意味
sc-statusがエラーコードとなっていれば、エラーログにも記録されているはず。
https://learn.microsoft.com/ja-jp/windows/win32/http/w3c-logging
#Fields: date time c-ip cs-username s-ip s-port cs-method cs-uri-stem cs-uri-query sc-status cs(User-Agent)
2002-05-02 17:42:15 172.22.255.255 - 172.30.255.255 80 GET /images/picture.jpg - 200 Mozilla/4.0+(compatible;MSIE+5.5;+Windows+2000+Server)
なおsc-win32-status(windowsステータスコード)は、0であれば正常。その他はエラーのよう。
64のエラーケースの事例。
サーバーがデータを送ったのに、クライアントとの接続が切れたなどの理由からクライアントの応答がなかったからということだそうです。
https://social.msdn.microsoft.com/Forums/ja-JP/c10ef91b-cb32-4134-849f-aba9193e6e5b/iis12398125251246412395scwin32status12392123751239064123981251312483?forum=iis7ja
エラーログ
-
場所
C:\Windows\System32\LogFiles\HTTPERR\httperr1.log
https://blog.putise.com/iisのエラーログはどこにあるのか？エラーログの/#IIS -
意味
下記を参照すれば問題なくおえるはず。
https://learn.microsoft.com/ja-jp/troubleshoot/developer/webapps/aspnet/site-behavior-performance/error-logging-http-apis#configure-http-api-error-logging
2002-07-05 18:45:09 172.31.77.6 2094 172.31.77.6 80 HTTP/1.1 GET /qos/1kbfile.txt 503 - ConnLimit
2002-07-05 19:51:59 127.0.0.1 2780 127.0.0.1 80 HTTP/1.1 GET /ThisIsMyUrl.htm 400 - Hostname
2002-07-05 19:53:00 127.0.0.1 2894 127.0.0.1 80 HTTP/2.0 GET / 505 - Version_N/S
2002-07-05 20:06:01 172.31.77.6 64388 127.0.0.1 80 - - - - - Timer_MinBytesPerSecond
エラーログ「Request_Cancelled」から調査した結果
これらの記事が見つかった。データ送受信時の最大値や送受信の数が起因となってエラーが生じるよう。
-
システム全体の設定ファイル: ApplicationHost?.config
https://techinfoofmicrosofttech.osscons.jp/index.php?IIS config#vd6fb25c -
アプリケーション固有の設定値: Web.config
https://techinfoofmicrosofttech.osscons.jp/index.php?.NET config#u3d1af27
上記ファイルを確認したが、問題なかった。
改めてエラーログの発生日時を確認すると、29時間おきに記録されていることがわかった。
結果
- IISにおけるアプリケーションプールのリサイクルが原因となり「Request_Cancelled」というエラーログが生じていたと考えられる。
アプリケーションプールのリサイクルはデフォルト設定（29時間間隔）となっており、エラーが生じていたのは必ずそのタイミングであったため。 - アプリケーションプールを定期的にリサイクルする目的は、下記。
問題のあるアプリケーションがあり、問題の原因となっているコードを簡単に修正できない場合は、アプリケーションにサービスを提供するワーカー プロセスを定期的にリサイクルすることで、これらの問題の範囲を制限できます。
抜粋: アプリケーション プールのリサイクル設定の構成
- 対策としては、リサイクル自体を実行しない。もしくはエラーしても良いタイミングでリサイクルを定期実行させることが有効。
Discussion