🔍

IISのエラーログ「Request_Cancelled」を調べた結果

2022/12/30に公開約3,400字

背景

稼働中のWebサービスからエラー通知が来ていたため、その原因を調査した。稼働中のWebサービスはWindowsサーバーのため、WebサーバーはIISを利用していた。
私はこれまでNginxしか触ったことがなかったため、ログの場所や意味なども調べながら調査した。その辺りも含めて本記事にメモとして残す。

調査

Windowsサーバーにおけるcatコマンド

linuxで当たり前に使っているcatやlessコマンドは、DOSでは使えなかったためこちらも調べた。typeコマンドやmoreコマンドによりファイルの内容を表示できた。
よく使ったコマンド: type ファイル名 | more

https://learn.microsoft.com/ja-jp/windows-server/administration/windows-commands/type
https://windows.command-ref.com/cmd-more.html

IISのログ

アクセスログ

アクセスログの例
#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であれば正常。その他はエラーのよう。
https://learn.microsoft.com/ja-jp/windows/win32/debug/system-error-codes--0-499-

64のエラーケースの事例。

サーバーがデータを送ったのに、クライアントとの接続が切れたなどの理由からクライアントの応答がなかったからということだそうです。
https://social.msdn.microsoft.com/Forums/ja-JP/c10ef91b-cb32-4134-849f-aba9193e6e5b/iis12398125251246412395scwin32status12392123751239064123981251312483?forum=iis7ja

エラーログ

エラーログの例
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」から調査した結果

これらの記事が見つかった。データ送受信時の最大値や送受信の数が起因となってエラーが生じるよう。
https://stackoverflow.com/questions/27725258/httperr-log-request-cancelled-while-troubleshooting-wcf-service
https://www.appsloveworld.com/csharp/100/1735/getting-request-cancelled-in-windir-system32-logfiles-httperr-from-ios-device

上記ファイルを確認したが、問題なかった。
改めてエラーログの発生日時を確認すると、29時間おきに記録されていることがわかった。

結果

  • IISにおけるアプリケーションプールのリサイクルが原因となり「Request_Cancelled」というエラーログが生じていたと考えられる。
    アプリケーションプールのリサイクルはデフォルト設定(29時間間隔)となっており、エラーが生じていたのは必ずそのタイミングであったため。
  • アプリケーションプールを定期的にリサイクルする目的は、下記。

問題のあるアプリケーションがあり、問題の原因となっているコードを簡単に修正できない場合は、アプリケーションにサービスを提供するワーカー プロセスを定期的にリサイクルすることで、これらの問題の範囲を制限できます。
抜粋: アプリケーション プールのリサイクル設定の構成

  • 対策としては、リサイクル自体を実行しない。もしくはエラーしても良いタイミングでリサイクルを定期実行させることが有効。

Discussion

ログインするとコメントできます