PHPのWebアプリケーションフレームワークであるLaravelは、ログファイルを日別で分けて出力する仕組みが用意されており、一緒にログローテートも設定できます。
それを用いて、週1回実行するバッチ処理のログを2週間保持する設定をしたのですが、想定していた挙動と異なる動きだったため調査を行いました。
想定していた挙動と実際の挙動
想定では常に2週間分の2ファイルのみ保持されていて、その他のファイルは削除される想定でした。
しかし、実際にはファイルはたまり続け、動作確認をしてみたところ14回分のファイルが保持されるようです。
具体的には下記のような状態です。
想定していた挙動
2022年1月1日・1月8日に実行したあとの状態
$ ls
laravel-2022-01-01.log laravel-2022-01-08.log
2022年1月15日に実行したあとの状態
$ ls
laravel-2022-01-08.log laravel-2022-01-15.log
実際の挙動
2022年1月1日・1月8日に実行したあとの状態
$ ls
laravel-2022-01-01.log laravel-2022-01-08.log
2022年1月15日に実行したあとの状態
$ ls
laravel-2022-01-01.log laravel-2022-01-08.log laravel-2022-01-15.log
違う、そうじゃない…
ということで、実際の挙動を検証したところ「日数=ファイル数」ということはほぼほぼ確信できたのですが、念の為ソースレベルで調査してみました。
行っていた設定
Laravelではログの設定を下記のように設定できます。
'channels' => [
'batch' => [
'driver' => 'daily',
'path' => storage_path('logs/laravel.log'),
'level' => env('LOG_LEVEL', 'debug'),
'days' => 14,
]
]
'driver' => 'daily'でログファイルを日別にして、ログローテートを'days'で指定できます。
しかし、この設定は「毎日吐き出されるLaravelのログを日別にして、ログローテートを設定する」ということのようです。
設定項目の'days'は毎日吐き出される前提の値で、「保持日数を超えているログファイルは削除する」というための設定ではありませんでした。
具体的にどのような処理になっているか
Laravelの実装
Laravelのログは内部的にMonologライブラリが利用されています。
'driver' => 'daily'の設定を行った際のLaravel内の処理を抜粋して見てみると
use Monolog\Handler\RotatingFileHandler;
/**
* @mixin \Illuminate\Log\Logger
*/
class LogManager implements LoggerInterface
{
...
/**
* Create an instance of the daily file log driver.
*
* @param array $config
* @return \Psr\Log\LoggerInterface
*/
protected function createDailyDriver(array $config)
{
return new Monolog($this->parseChannel($config), [
$this->prepareHandler(new RotatingFileHandler(
$config['path'], $config['days'] ?? 7, $this->level($config),
$config['bubble'] ?? true, $config['permission'] ?? null, $config['locking'] ?? false
), $config),
]);
}
...
}
という風になっています。
RotatingFileHandlerインスタンスを生成する際に、引数の2項目目で設定値のdaysまたはデフォルト値の7で日数を指定しています。
Monologの実装
ではMonologのRotatingFileHandlerはどのような実装になっているでしょうか？
class RotatingFileHandler extends StreamHandler
{
...
/**
* @param int $maxFiles The maximal amount of files to keep (0 means unlimited)
* @param int|null $filePermission Optional file permissions (default (0644) are only for owner read/write)
* @param bool $useLocking Try to lock log file before doing any writes
*/
public function __construct(string $filename, int $maxFiles = 0, int|string|Level $level = Level::Debug, bool $bubble = true, ?int $filePermission = null, bool $useLocking = false)
{
$this->filename = Utils::canonicalizePath($filename);
$this->maxFiles = $maxFiles;
$this->nextRotation = new \DateTimeImmutable('tomorrow');
$this->filenameFormat = '{filename}-{date}';
$this->dateFormat = static::FILE_PER_DAY;
parent::__construct($this->getTimedFilename(), $level, $bubble, $filePermission, $useLocking);
}
...
}
引数 $maxFiles になっているではないですか！
ということで、Laravelのログローテートで設定するdaysは毎日吐き出されるログであればイコール日数となりますが、週1回・月1回などの毎日ではない処理に対しては決してイコール日数にならないのです。
daysという名前ややこしいなー…
まとめ： 日次以外のログはログローテートの設定に要注意
Laravelのログファイルを日別に分解したいということは多々あると思います。
その中で、合わせてログローテートも設定した際にdaysを日数と勘違いすると、日次以外で吐き出されるログは想定以上にログファイルを溜め込むことになります。
勘違いしやすいところのように思えたので、みなさんもお気をつけください！