【laravel 8.x】Logging の設定とログフォーマットの実装方法【基本編】

`laravel` のログにはPHPでよく使われているらしい `Monolog` が実装されている。
こいつをごにょごにょしていい感じにしたいのが本記事。
（簡潔に書きたかったがソースも書くと長くなるねぇ…）

Laravel は `ver8.9.0`。（v6くらいから同じだと思う）
目的はログのフォーマットの変更とカラーリング。

- ソース：[ログ 8\.x Laravel](https://readouble.com/laravel/8.x/ja/logging.html)
- monolog：[Seldaek/monolog: Sends your logs to files, sockets, inboxes, databases and various web services](https://github.com/Seldaek/monolog)
- カラーリング： [bramus/monolog\-colored\-line\-formatter: Colored/ANSI Line Formatter for Monolog](https://github.com/bramus/monolog-colored-line-formatter)
- 大いに参考：[Laravelでログのフォーマットを変えたい \- Qiita](https://qiita.com/nuuuuume/items/a6bcf340c50f18cfb71c)

## 1. ログの出力方法

Laravel のログは RFC5424 ってので定義されている8つのレベルが扱える。
`emergency` > `alert` > `critical` > `error` > `warning` > `notice` > `info` > `debug`

ログを出力する方法は facade を使う方法と helper を使う方法の2種類（たぶん）。
デフォルトでは `storage/logs/laravel.log` に出力される。

#### Log Facade でログを出力する。

```php
use Illuminate\Support\Facades\Log;

$name = 'sample kunn';
Log::info('Showing user: '.$name);
// => [2020-10-13 19:27:04] local.INFO Showing user: sample kunn

Log::notice('User failed to login.', ['id' => 3]);
// => [2020-10-13 19:32:38] local.INFO User failed to login. {"id":3}
```

第２引数(context) に渡したデータはシリアライズされて出力される（デフォルト）。

#### Logger Helper でログを出力する

```php
logger()->info('sample text');
// => [2020-10-13 19:35:43] local.INFO sample text
```

どちらとも `LogManager` を内部で呼び出しているので使い方は同じっぽい。
RFC5424 の 8 つのレベルの関数が定義されているので使い分けるべし。
Facade と Helper、決めた方に統一して使うのが賢そう。
参考：[Illuminate\\Log\\LogManager \| Laravel API](https://laravel.com/api/8.x/Illuminate/Log/LogManager.html)

`local.xxx` は `.env` の `APP_ENV` の値かな？
`production` とか `local` といった実行環境の値となる。

> 他のロガーでいうカテゴリやタイプといった塊は存在しない。（ほんとぉ？）
> 必要ならラッパーを作るなりする必要がありそう。
> 
> - [Laravel ConsoleとHttpのログファイルを分ける \- Qiita](https://qiita.com/ucan-lab/items/4dd7b5f7a3eb57a3ef1f)
>   - この辺りを参考に `processor` にフィールドを追加させるのが最適解だと思う。


#### Exception ログ

```php
use Exception;

logger()->error(new Exception('Reigai'));
```

![スクリーンショット 2020-10-13 210104.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/105139/4801869a-3a6c-5acb-c519-116ce7901b82.png)

Exception 系列を渡せば stackTrace も出力される。



## 2. ログの設定ファイル

基本的には `app/config/logging.php` に設定を書き込むだけで使える。


```app/config/logging.php
'default' => env('LOG_CHANNEL', 'stack'),

'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,
    ],

    'stderr' => [
        'driver' => 'monolog',
        'handler' => StreamHandler::class,
        'formatter' => env('LOG_STDERR_FORMATTER'),
        'with' => [
            'stream' => 'php://stderr',
        ],
    ],

    ...
]
```

`channel` というのはログの出力方法を指したもので、これを使ってログを出力する。
TVのチャンネルみたいに電波を分ける役割（でいいのかな？）。
デフォルトでは `stack` というものが指定されている。

`stack` だけは特殊で、プロパティの `channels` で指定した複数のチャンネルに処理を渡すことができる。
TVでいう多チャンネル同時視聴。
デフォルトでは `['single']` が指定されているので、`single` というチャンネル1つにログの出力を渡している。
`single` は `logs/laravel.log` に書き込むチャンネルなので、logファイルに追記されるわけだ。

初めから定義されていたチャンネルを以下にまとめる。

|channel名|説明|
|:--:|:--|
|stack|複数のチャンネルへログを渡す|
|single|指定したファイルにログを書き出す|
|daily|指定したファイルにログを書き出す（所謂ローテート）<br>一日ごとにファイルを区切り、一定の日数が経過したら削除する(任意)|
|slack|[Slack](https://slack.com/intl/ja-jp/) に出力する|
|papertrail|[Papertrail](https://www.papertrail.com/) に出力する|
|stderr|標準エラー出力に出力する|
|syslog|Linux 等の syslog に出力する|
|errorlog|PHPの [error\_log()](http://docs.php.net/manual/en/function.error-log.php) に出力する|
|null|何もしない|
|emergency|（emergency ログだけ出力？）|

他にも SNS に送ったり DB に送ったりと、大抵のやりたいことは誰かがライブラリを実装してくれてる。

## 3. stdout channel の追加

log を使ってて思ったのが、cli を操作している時は標準出力にも出力して欲しい点。
`stderr` チャンネルは存在するので、それをベースに `stdout` チャンネルを作成してみる。

```app/config/logging.php
'stdout' => [
    'driver' => 'monolog',
    'handler' => StreamHandler::class,
    'with' => [
        'stream' => 'php://stdout',
    ],
    'level' => 'debug', // all log
],
```

`StreamHandler` の `stream` パラメータにPHPの標準出力(stdout)を指定した。
`level` によって出力するログレベルを制限できるが、最低値の `debug` にすることにより、全てのログを対象としている。
試しに `channels.stack.channels` に `stdout` を追加すると標準出力にも出力されるようになるはず。

> `Handler` は monolog 側のシステムなので今回は省く。
> 詳しくはこのあたり。
> 
> - [ログ 8\.x/ Laravel](https://readouble.com/laravel/8.x/ja/logging.html)
>     - の下の方の「Monologハンドラチャンネルの作成」
> - [monolog/02\-handlers\-formatters\-processors\.md at master · Seldaek/monolog](https://github.com/Seldaek/monolog/blob/master/doc/02-handlers-formatters-processors.md)
> - [Third Party Packages · Seldaek/monolog Wiki](https://github.com/Seldaek/monolog/wiki/Third-Party-Packages)


#### [オプション] CLI実行時(php artisan)のみ標準出力にも出力する

このまま `stack` に追記でもいいのだが、CLIを操作していない時に標準出力に出力されるのはあまり好みではない。
（schedule 処理、http のアクセス時等にも出力されてしまう（握りつぶされるが））
なので CLI で実行したときに限って出力するようにしてみる。

```App\Providers\AppServideProvider.php
class AppServiceProvider extends ServiceProvider
{
    public function boot()
    {
        ...
        // logger cli mode
        if(strpos(strtolower(php_sapi_name()), 'cli') !== false) {
            $path = 'logging.channels.stack.channels';
            $stacks = collect(config($path, []))
                ->push('stdout')
                ->unique();
            config([$path => $stacks]);
        }
    }
}
```

[php\_sapi\_name()](https://www.php.net/manual/ja/function.php-sapi-name.php) という関数を実行すると、`apache` や `cli`、`cgi` といった文字列が帰ってくる。
これを利用して、名前にCLIが含まれていたら stack に `stdout` を追加する仕組み。
collection の unique() を使うことで重複実装を防いでいる。

とりあえず `AppServiceProvider` に実装したが、 `LoggerServideProvider` とかを作って実装したほうが賢い。

参考：[php \- Detect if running from the command line in Laravel 5 \- Stack Overflow](https://stackoverflow.com/questions/29130664/detect-if-running-from-the-command-line-in-laravel-5)



## 4. ログ文字列のフォーマット

さて本題。
デフォルトの出力文字列は以下のような形式だった。

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/105139/44ae20c5-3b4d-2b6f-40c7-7327bcc62356.png)

これは monolog のデフォルトの `Formatter\LineFormatter` で以下が適用されているためである。
```[%datetime%] %channel%.%level_name%: %message% %context% %extra%\n```
参照：[monolog/LineFormatter\.php at master · Seldaek/monolog](https://github.com/Seldaek/monolog/blob/master/src/Monolog/Formatter/LineFormatter.php#L26)

こいつを変更したいので `LineFormatter` を拡張した class を作成する。

```App\Logging\Formatters\CustomLineFormatter.php
<?php

namespace App\Logging\Formatters;

use Monolog\Formatter\LineFormatter;

class CustomLineFormatter extends LineFormatter
{
    public function __construct()
    {
        // 2020-10-13 17:12:15.375 [local.INFO] log message という形式で出力
        $lineFormat = "%datetime% [%channel%.%level_name%] %message%" . PHP_EOL;
        $dateFormat = "Y-m-d H:i:s.v"; // PHP: DateTime::format

        parent::__construct($lineFormat, $dateFormat, true, true);
    }

    public function format(array $record): string
    {
        // var_dump($record);
        $output = parent::format($record);
        // var_dump($output);

        return $output;
    }
}
```

`LineFormatter` のコンストラクタは以下を引数に取る。

|引数|説明|
|:--|:--|
|$format|フォーマット文字列|
|$dateFormat|日付(%datetime%)のフォーマット文字列<br>参考：[PHP: DateTime::format \- Manual](https://www.php.net/manual/ja/datetime.format.php)|
|$allowInlineLineBreaks|ログの改行を許すか|
|$ignoreEmptyContextAndExtra|context と extra の値が空のときに [] を削除するかどうか|

参照：[monolog/LineFormatter\.php at master · Seldaek/monolog](https://github.com/Seldaek/monolog/blob/master/src/Monolog/Formatter/LineFormatter.php#L39)


`format()` は今回は親のものを呼び出しているだけだが、ここでフォーマットのやり方を定義することができる。
引数の `record` 配列は以下の通り。

```php
$record = [
    'message' => $message,
    'context' => $context,
    'level' => $level,
    'level_name' => $levelName,
    'channel' => $this->name,
    'datetime' => new DateTimeImmutable($this->microsecondTimestamps, $this->timezone),
    'extra' => [],
];
```

参照：[monolog/Logger\.php at master · Seldaek/monolog](https://github.com/Seldaek/monolog/blob/master/src/Monolog/Logger.php#L303)

ここで `level` や `message` を加工して `parent::format($record)` を呼べば、かなり自由度の高いことが可能だ。
`context` はログ関数実行時の第２引数（配列？オブジェクト？）。
今のままだと context は握りつぶされているので、
`$record['message] .= json_encode($record['context']);`みたいな実装が要るかも。

ここで DB に保存をかけたりしても面白そう。
参考にした文献だと context を `vsprintf()` に突っ込むことで `printf()` like な実装を示してた。
Levelに応じた絵文字とかタイマーとか実装できたら楽しそう。

> `extra` は実行された行番号やIPアドレスなどを取得できるが、今回は扱わない。
> `processor` という仕組みを使うのだが、この辺りが参考になるかも。
>
> - [Laravelのログにファイル名やメソッド名を出力する \- Qiita](https://qiita.com/iakio/items/7b8539db928d2b419921)
> - [Laravelでログのフォーマットを変えたい \- Qiita](https://qiita.com/nuuuuume/items/a6bcf340c50f18cfb71c)


#### Laravel にフォーマットを適用する

laravel に適用するには `tap` という配列パラメータに `__invoke()` が実装されているクラスを指定してあげる必要がある。

参考：[ログ 8\.x/ Laravel](https://readouble.com/laravel/8.x/ja/logging.html)
　　　の下の方の「チャンネル用Monologカスタマイズ」

```App\Logging\LineFormatterApply.php
<?php

namespace App\Logging;

use App\Logging\Formatters\CustomLineFormatter;

class LineFormatterApply
{
    public function __invoke($logging)
    {
        $customLineFormatter = new CustomLineFormatter();

        foreach($logging->getHandlers() as $handler) {
            $handler->setFormatter($customLineFormatter);
        }
    }
}
```

おそらく `CustomLineFormatter` を指定があった handler 全てに渡すのだと思う。
（extend とか implements とかが無い暗黙実装は嫌いだぁ…）

これを `config/logging` の使わせたいチャンネルに指定してあげる。
今は `stdout` と `single` に。
（`stack` に渡すと全チャンネルに適用できるが、子で指定していた場合上書きされた）
（formatter は一つしか追加できない？）

```app/config/logging.php
use App\Logging\LineFormatterApply;

'stdout' => [
    'driver' => 'monolog',
    'handler' => StreamHandler::class,
    'with' => [
        'stream' => 'php://stdout',
    ],
    'level' => 'debug',
    'tap' => [ColorFormatterApply::class], // <-- これ
],
```

こんな感じの出力に変えられた。

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/105139/a88d9de8-61cd-511e-f6b1-574d75882b36.png)


## 5. ログをカラフルに出力する

標準出力のログはやっぱり色が欲しい。
視認性も上がるし、なによりログの把握速度が圧倒的である。

調べると monolog 側に良さそうなライブラリがあった。
[bramus/monolog\-colored\-line\-formatter: Colored/ANSI Line Formatter for Monolog](https://github.com/bramus/monolog-colored-line-formatter)

```console:console
composer require bramus/monolog-colored-line-formatter ~3.0
```

これをそのまま `formatter` 扱いで定義すると色が付くのだが、それでは先程作成した文字列のフォーマットが適用されない。
なので、`CustomLineFormatter` を拡張して色を付けることにする。

```App\Logging\Formatters\ColorLineFormatter.php
<?php

namespace App\Logging\Formatters;

use Bramus\Monolog\Formatter\ColorSchemes\DefaultScheme;

// quote by:
// https://github.com/bramus/monolog-colored-line-formatter/blob/master/src/Formatter/ColoredLineFormatter.php
class ColorLineFormatter extends CustomLineFormatter
{
    private $colorScheme = null;

    public function getColorScheme()
    {
        if (!$this->colorScheme) {
            $this->colorScheme = new DefaultScheme();
        }

        return $this->colorScheme;
    }

    public function format(array $record) : string
    {
        $output = parent::format($record);

        $colorScheme = $this->getColorScheme();
        return $colorScheme->getColorizeString($record['level']).trim($output).$colorScheme->getResetString()."\n";
    }
}
```

`parent::format($record)` した後に、その文字列に level に応じた色を付ける。
ライブラリのフォーマット部分を参考に必要な処理を移植した形だ。
参考：[monolog\-colored\-line\-formatter/ColoredLineFormatter\.php at master · bramus/monolog\-colored\-line\-formatter](https://github.com/bramus/monolog-colored-line-formatter/blob/master/src/Formatter/ColoredLineFormatter.php/)

```App\Logging\ColorFormatterApply.php
<?php

namespace App\Logging;

use App\Logging\Formatters\ColorLineFormatter;

class ColorFormatterApply
{
    public function __invoke($logging)
    {
        $coloredLineFormattetr = new ColorLineFormatter();

        foreach($logging->getHandlers() as $handler) {
            $handler->setFormatter($coloredLineFormattetr);
        }
    }
}
```

で、これを `stdout` のチャンネルの `tap` に指定すればOK。
**※制御文字を使用しているので、ファイル出力には使わないように。**

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/105139/a8185aad-15ee-2439-957c-850bd8ea185e.png)

とてもいい感じになった。
ログのメッセージ部は白のままにしたい時は、正規表現でその部分だけ抜き取って色を付けると良いかも。


## 6. サンプル

自分が使用したいログの仕様をまとめて、それを実装したサンプルを置いておく。

- NOTICE 以上のログが1日毎に別のファイルに保存される `daily` チャンネル
  - 保存期間（`days`）は7日
- ERROR 以上のログが1つのファイルに保存される `singleError` チャンネル
- CLIで実行した際、全てのログが標準出力に色付きで出力される `stdout` チャンネル
  - これは `AppServiceProvide` で追加するので `stack` では触らない

```App\Config\logging.php
use Monolog\Handler\StreamHandler;
use App\Logging\LineFormatterApply;
use App\Logging\ColorFormatterApply;

...

'channels' => [
    'stack' => [
        'driver' => 'stack',
        'channels' => ['dailyNotice', 'singleError'],
        'ignore_exceptions' => false,
    ],

    'singleError' => [
        'driver' => 'single',
        'path' => storage_path('logs/laravel_error.log'),
        'level' => 'error', // upper error log
        'tap' => [LineFormatterApply::class],
    ],

    'dailyNotice' => [
        'driver' => 'daily',
        'path' => storage_path('logs/laravel.log'),
        'level' => 'notice', // upper notice log
        'days' => 7,
        'tap' => [LineFormatterApply::class],
    ],

    'stdout' => [
        'driver' => 'monolog',
        'handler' => StreamHandler::class,
        'with' => [
            'stream' => 'php://stdout',
        ],
        'level' => 'debug', // all log
        'tap' => [ColorFormatterApply::class],
    ],
],
```

出力は以下の感じ。
log ファイルのカラーリングは VSCode の [Log File Highlighter](https://marketplace.visualstudio.com/items?itemName=emilast.LogFileHighlighter) を使用している。

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/105139/c7b96771-0be4-6b2f-26e5-a1bb87f2b52f.png)
![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/105139/fdd2cc8f-813c-87ae-a922-78545c516c03.png)
![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/105139/b9d2d9dc-2dbe-e69c-5d01-90dba036f837.png)



## おわりに

monolog の `handler`と`processor` 周りをまだ理解しきれてないので、とりあえず基本をまとめた。
あと laravel の Exception 周りも知らないといけないかも。

これ `node-log4js` より楽かもしれぬ。
個人的にタイマーは実装してみたい。
綺麗なログを吐けると開発が捗る捗る…。

続きは、今のログに手を入れるとき（書くとは言っていない）。