IIS と log4net の組み合わせでログローテが行われない

ブログを始めて3日目で更新が途絶えており、リアルに3日坊主になっておりました…。
今回は log4net で不思議な現象に遭遇したので、その現象と解決策について書いていきます。

環境
log4net の設定値
<appendToFile value="true" />
<rollingStyle value="date" />
<staticLogFileName value="true" />

ログ監視のソフトを使う都合上、ログファイル名は固定しており、ログローテの方式は日付にしておりました。

現象
  • 日付でのログローテが行われない
  • 日付をまたいでも、同一のファイルにログが追記されてしまう
原因

結論から書くと、IIS のアプリケーションプールのリサイクルが原因でした。
IIS のリサイクルのタイミングは、夜中の1時に設定しており、なぜかそのタイミングで、ログファイルの更新日付のみが更新されるという
現象が起きることが確認できました。
つまり、

  1. 20xx年yy月01日 ログ出力 -> ap.log
  2. 20xx年yy月02日 リサイクル -> ap.log の更新日付を更新(IIS からの処理なのでログローテしない)
  3. 20xx年yy月02日 ログ出力 -> ap.log に追記(更新日付は 02日で同日なのでログローテしない)

という流れの処理になっていたのだと思われます。

解決策

おそらく、log4net のプロセスがログファイルを常に掴んでおり、解放するタイミングでログファイルの更新日付を更新しているのかと予想し、log4net のコンフィグに以下の設定値を追記しました。

<lockingModel type="log4net.Appender.FileAppender+MinimalLock" />

これにより、ログファイルに追記する時のみ log4net のプロセスがファイルを掴むようになるため、無事にログローテが行えることが確認できました。