Laravel(monolog)で構造化ログを実装する

# 構造化ログ
JSON形式でログを出力しちゃおう、という話です。
[構造化ロギング](https://cloud.google.com/logging/docs/structured-logging)

## 例
人間にわかりやすいログ

```
[2019-05-23 10:42:51] local.ERROR: Division by zero in /var/www/hoge.jp/app/Dummy.php:81
```

構造化ログ

```
{"level":"ERROR","datetime":"2019-06-04 04:54:32","env":"local","message":"Division by zero","file":"\/var\/www\/hoge.jp\/app\/Dummy.php","line":81,"extra":[]}
```

## なにがいいのか
例えば本番環境のログを調べたいときに、サーバ８台分のログ全部をgrepして、tailして、catして…とかは正直うんざりです。場合によってはawkが必要だったり、perlあたりでなにかコマンド書く必要があるかもしれません。

ならば最初からJSONで出力し、かつ大枠のフォーマットを決めておけばどうでしょう。
ログをElasticsearchなどに投入しておけば、あとでKIBANAを用いていくらでも検索が可能で、目的のログをいち早く分析できます。**2019-01-01 00:00:00〜2019-03-31 23:59:59までのAWS S3に関するエラーコード「ERR-００１」のログ一覧**を表示、なんてことも容易になります。

# Laravelで構造化ログを出力する
Laravelで、と書いてますが [Laravelはmonologを使っています](https://laravel.com/docs/5.8/logging#introduction) ので、[monolog](https://github.com/Seldaek/monolog) で、ということになります。

## monolog

詳細は省いて概要だけまとめます。
### Handler
monologの物理的な出力を管理するのがHandlerです。
例えばRedisにログを吐き出すHandlerや、ログローテートをしてくれるHandlerなどがあります。

### Formatter
読んで字のごとく、ログのフォーマットを管理します。Handlerに設定できます。


## 構造化ログに変換するには
上記から察するに Formatter でごにょごにょすればよさそうです。

### 受け渡す情報はどうするか
しかし、ログメッセージからどのように情報を取得すればいいでしょうか。
**2019-01-01 00:00:00〜2019-03-31 23:59:59までのAWS S3に関するエラーコード「ERR-００１」のログ一覧**を出すためには、少なくとも「AWS S3に関するログだよ」＆「エラーコードはERR-001だよ」を渡したいですが

```
Log::error('ERROR!');
```

上記のようなLaravelのログファサードを使って情報を詰めるにはちょっと限界がありそうです。

### context
しかし、ログファサードには第２引数を記述することができます。配列で指定するcontextは、好きなものを詰めてログにわたすことができます。

```
Log::error('ERROR！', ['genre' => 'AWS-S3', 'code' => 'ERR-001']);
```

こんな感じで情報は引き渡せます。

### Formatterの記述
じつに簡単です。サンプルプログラムを見てもらうと分かる通り、ただの配列操作です。最後にjsonにしてreturnします。
今回はNormalizerFormatterを継承し、それをオーバーライドする形で記述してみました。

```php5
<?php
declare(strict_types=1);

namespace App\Logging\Formatters;

use Carbon\Carbon;
use Illuminate\Hashing\HashManager;
use Monolog\Formatter\NormalizerFormatter;

/**
 * Class ApplicationLogFormatter
 * @package App\Logging\Formatters
 */
class ApplicationLogFormatter extends NormalizerFormatter
{
    /**
     * @var array
     */
    private $keys = [
        'code',
        'genre',
    ];

    /**
     * ログフォーマッタ
     * @param array $record
     * @return string
     */
    public function format(array $record): string
    {
        $formatted = parent::format($record);
        $segments = [
            'level' => $formatted['level_name'],
            'datetime' => $formatted['datetime'],
            'env' => $formatted['channel'],
            'message' => $formatted['message'],
            'extra' => $formatted['extra'],
        ];

        foreach ($this->keys as $key) {
            if (isset($formatted['context'][$key])) {
                $segments[$key] = $formatted['context'][$key];
            }
        }
        return json_encode($segments) . PHP_EOL;
    }
}
```

## Formatterを設定する
[Laravelのマニュアル](https://laravel.com/docs/5.8/logging#advanced-monolog-channel-customization)にあるように、独自のFormatterを設定するには、ロガーインスタンスのカスタマイズが必要です。
しかし難しいことはなにひとつなく、なんとconfigに書くだけです。

```php5
'single' => [
    'driver' => 'single',
    'tap' => [App\Logging\Customizer::class],
    'path' => storage_path('logs/laravel.log'),
    'level' => 'debug',
],
```

```php5
<?php

namespace App\Logging;

use App\Logging\Formatters\ApplicationLogFormatter;

class Customizer
{
    /**
     * Customize the given logger instance.
     *
     * @param  \Illuminate\Log\Logger  $logger
     * @return void
     */
    public function __invoke($logger)
    {
        foreach ($logger->getHandlers() as $handler) {
            $handler->setFormatter(app()->make(ApplicationLogFormatter::class));
        }
    }
}
```

### サンプル

```
{"level":"ERROR","datetime":"2019-06-04 04:54:32","env":"local","message":"ERROR!","genre":"AWS-S3","code":"ERR-001","extra":[]}
```

この形でElasticsearchなどに登録されていれば、ログは一気に見つけやすく、分析しやすくなります。

# まとめ
上記は簡単なサンプルだけですので、例えばException発生時のtrace情報はどうしよう、とかいろいろ設定の余地があります。
しかし、大体は配列と文字列操作だけの話なので、特段難しいことはないと思います。

自分の環境ではlocal環境では通常のログ、dev環境以降は構造化ログにしてみたり、contextのキーをいちいち書くのが面倒なので、オリジナルのLoggerファサードを作り、

```
AppLog::genre('AWS-S3')->code('ERR-001')->error('ERROR!);
```

みたいな記述ができるようにしています。