概要
「ひとつのリクエストにつき数千件分のデータを加工し、最終的にファイルとして出力する。
この処理には10時間程度かかる見込みで、途中で予期せぬエラーが発生した場合の調査をしやすくするため、リクエストごとにログファイルを生成し、処理の経過を記録したい。」
という仕様に対応するため、現在時刻(年月日時分秒ミリ秒)を名前に含むログを動的に出力する方法を探して実装した。ログのファイル名を動的に変えたい、という趣旨の記事が見つからなかったので、備忘録として残す。
時刻を含めるのは、一意性を保つためと、いつリクエストされたのか分かりやすくするため。時刻でなくとも、例えばユーザ名などを指定することも可能なので、用途によって置き換えること。
動作環境
PHP 7.4.
Laravel 6.20
結論
各バージョンのconfigファイルを確認した限りだと、Laravel5.6以降、 config/logging.php とカスタムMonologインスタンスを使ってログレベルなどの設定を行えるようになった。そちらが主流だと思うので、その方法に従う。
まず、カスタムMonologインスタンスを生成するクラスを追加する。
<?php
namespace App\Logging;
use Monolog\Formatter\LineFormatter;
use Monolog\Handler\StreamHandler;
use Monolog\Logger;
class SampleLoggerCreator
{
public function __invoke(array $config): Logger
{
$logLineFormat = '%datetime% %level_name% %message%'. PHP_EOL;
$datetimeFormat = 'Y年m月d日 H時i分s.v秒';
$lineFormatter = new LineFormatter($logLineFormat, $datetimeFormat);
// スタックトレースを出すか出さないかの設定があるが、出ないパターンもあり違いは不明
$lineFormatter->includeStacktraces(true);
// Handlerにログの保存先パスを渡すことで出力したいログのファイル名を指定できる。
// 同じファイル名なら同じファイルに出力するため、日時の代わりにログイン中のユーザ名などを指定すればユーザごとにログを出すことも可能。
$currentTimeWithMillisecond = now()->format('YmdHisv');
$logPath = storage_path(sprintf('logs/%s.log', $currentTimeWithMillisecond));
// 今回は1リクエスト中のログを1ファイルに収めたいので、StreamHandlerを使う。
$handler = (new StreamHandler($logPath))
->setFormatter($lineFormatter);
return new Logger('sample', [$handler]);
}
}
次に、configファイルに今回出力したいログの設定を追加する。
ログの設定や内容をカスタマイズしたいので、 driver にはcustom を指定する。
via には先ほど追加した SampleLoggerCreatorを指定する。こうすることで、 SampleLoggerCreatorで設定した内容を基にログを生成できる。
'channels' => [
'stack' => [
'driver' => 'stack',
'channels' => ['single'],
'ignore_exceptions' => false,
],
'single' => [
'driver' => 'single',
'path' => storage_path('logs/laravel.log'),
'level' => 'debug',
],
'daily' => [
'driver' => 'daily',
'path' => storage_path('logs/laravel.log'),
'level' => 'debug',
'days' => 14,
],
// 追加
'sample' => [
'driver' => 'custom',
'via' => App\Logging\SampleLoggerCreator::class,
],
// 以下略
],
ControllerやCommandなどで Log::setDefaultDriver() を呼び出し、どのチャンネルを利用するのか指定した後、通常通りにLogファサードを使ってログを出力できる。
このとき、ログを1回出力するたびに新しくログファイルが生成されることはなく、1プロセス内で出力したログはすべて1ファイルに出力される。
最初にファイルが生成されるのは、一番初めにログを出力しようとした時点だと思われる。(下記の例でいうと「処理を開始します」の時点)
<?php
namespace App\Http\Controllers;
class SampleController extend Controller
{
public function sample()
{
// config/logging.phpで追加したチャンネル名を指定する。
Log::setDefaultDriver('sample');
Log::info('処理を開始します');
Log::error('エラーが発生しました');
Log::info('処理を終了します');
}
}
他、考えたことなど
- 初めは、dailyのチャンネルと同じようにファイル名に時分秒ミリ秒まで出してくれるチャンネルはないか？と考えたが、できなかった。
dailyチャンネルで利用されるRotatingFileHandlerは、N日ごとにローテーションすることで日付を指定しているようなので、ファイル名に現在時刻を渡すことはできない。 - LaravelのログはMonologという別のライブラリを利用しているため、Laravelのログについて調べるよりもMonologについて検索したほうが情報が見つかりやすいかもしれない。
参考記事
-
[Laravel] ログの扱い方 [5.8]
この記事を読んだおかげでconfig/logging.phpを経由しなくてもログ出力が可能であることがわかったので、一度Controller内で現在時刻をファイル名に指定してログを出せるかどうか試す→config/logging.phpとカスタムMonologインスタンスを生成する方法にリファクタリングする、ということができた。 -
PHPのロギングmonologを理解する
デフォルトの行フォーマットを最初に見たとき、それぞれが何に相当するのか分からなかったが、その説明が詳細で分かりやすかった。[%datetime%] %channel%.%level_name%: %message% %context% %extra%\n