LoginSignup
39
39

More than 5 years have passed since last update.

@nuuuuume

Laravelでログのフォーマットを変えたい

Posted at

Laravelのログをいじる

一日調べてしまったのでせっかくなのでおまとめ。
まだ全部はわかっていないけど、このあたりの仕組みがわかれば、Laravelでログ設定する上では参考になりそう。

コードにヘッダコメントなどなくてスミマセン。

環境

  • Laravel 5.7 On GentooLinux
  • 昨日Laravelを初めてインストールした人
  • Monologという言葉を昨日初めて聞いた人

実現したい機能

Laravelのログに実行クラス名やメソッド名、行番号を追加したい

手順概略

Laravelのプロジェクト名をappとして、名前空間をAppとしています。

  1. カスタムフォーマッタを接続するクラスを作る（App\Logging\CustomFormatterConnect.php）
  2. カスタムプロセッサを接続するクラスを作る（App\Logging\CustomProcessorConnect.php）
  3. カスタムフォーマッタを作る。今回はMonolog\Formatter\LineFormatter.phpを継承して App\Logging\LineExFormatter.phpを作る
  4. logging.php の設定（今回はdailyを使用）に tap 要素を追加し、その値として、作成したCustomFormatterConnectとCustomProcessorConnectを定義する

Monolog

LaravelのログはMonologというものを使っているらしいので、まずはそちらの知識が無いと話にならないみたい。
詳細は -> https://github.com/Seldaek/monolog
と、これだけ貼っても仕方がないので。。。

Monologの仕組み

別のサイトの紹介で申し訳ないけど、以下のサイトに簡素にまとまってた。非常に助かった。
https://tech.quartetcom.co.jp/2018/05/31/monolog/

掻い摘むと以下のようなことになる。

  • ロガーは複数のハンドラを持つ
  • ハンドラは一つのフォーマッタと複数のプロセッサを持つ
  • ハンドラは実際にログを出力する実装
  • フォーマッタは文字通りログを整形する実装
  • プロセッサはログに対してその他の付帯情報を挿入する実装

Laravelログ設定のdailyさんはRotatingFileHandlerベースと書いてあるので、これに関して言えば、

  • Monolog\Handler\AbstractProcessingHandler.php がProcessableHandlerInterfaceとFormattableHandlerInterfaceを実装していて
  • 実際はProcessableHandlerTraitとFormattableHandlerTraitが実装している
  • StreamHandlerがAbstractProcessingHandlerをextendsしており
  • RotatingFileHandlerがStreamHandlerをextendsしている

RotatingFileHandler の実装

では、RotatingFileHandlerがどんなフォーマットでどんなプロセッサを使っているかというと、基本的には何も設定されていない。
つまり、ProcessableHandlerTraitによると、プロセッサは無し、FormattableHandlerTraitによるとLineFomatterを既定で使う、となっていた。

LineFormatter

Monolog\Formatter\LineFormatter.php については、コンストラクタでフォーマットを指定できる。
が、RotatingFileHandler周りではコンストラクタでは何もしておらず、結果的にLineFomatterの既定フォーマットである

Monolog\Formatter\LineFormatter.php
const SIMPLE_FORMAT = "[%datetime%] %channel%.%level_name%: %message% %context% %extra%\n";

が採用される。

プレースホルダ

%datetime%や%channel%など、プレースホルダのようなものが出てきた。
ここから、（当たり前だけど）フォーマッタに渡される時点ではログは配列、もしくはオブジェクトになっていると考えられる。

LineFormatter.phpにあるformat(array $record) を見ると、arrayのタイプヒントがあることから、ログ情報は配列になっていることが分かる。

$record の中身

調べるのが面倒なのでソースを追った。

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

と、なっていた。
残念ながら、ここにメソッド名や行番号がいない。

IntrospectionProcessor

ここで、付帯情報を追加する ProcessableHandlerInterface が登場する。
Monolog\Processor の中を覗いていると、IntrospectionProcessor.phpを発見。
これによるとメソッド名などが取れるらしい。

Monolog\Processor\IntrospectionProcessor.php
        $record['extra'] = array_merge(
            $record['extra'],
            [
                'file'      => isset($trace[$i - 1]['file']) ? $trace[$i - 1]['file'] : null,
                'line'      => isset($trace[$i - 1]['line']) ? $trace[$i - 1]['line'] : null,
                'class'     => isset($trace[$i]['class']) ? $trace[$i]['class'] : null,
                'function'  => isset($trace[$i]['function']) ? $trace[$i]['function'] : null,
            ]
        );

これでフォーマットの指定場所と行番号など付帯情報の取得方法がわかった。

Monologで行番号などを出したい場合

Laravelに戻る前に、まずはMonologとして付帯情報をつけたカスタムフォーマットのログを出力する場合のことを考えてみる。

  • LineFomatter.phpのコンストラクタにカスタムしたフォーマットを入れる
  • RotatingFileHanlder.phpにカスタムフォーマットしたLineFomatterとIntrospectionProcessorを突っ込む

これで行けそうな予感がする。

実際はLineFormatterについては以下のようにLineExFormatter.phpを作って、これをRotatingFileHandlerにsetFormatter()した。
IntrospectionProcessorについてはそのまま利用する。

RotatingFileHandlerを継承して適当なクラスを作って使ってもいいかも。

App\Logging\LineExFormatter.php
<?php

namespace App\Logging;

use Monolog\Formatter\LineFormatter;

class LineExFormatter extends LineFormatter
{
    public function __construct()
    {
        // このフォーマットでログが出力される。
        // 2018/11/01 10:00:10 [local.DEBUG] Class@Method(10) - Hello!
        // みたいな表記を期待。
        $format = "%datetime% [%channel%.%level_name%] %extra.class%@%extra.function%(%extra.line%) - %message%" . PHP_EOL;
        // 既定だと 2018-11-01 みたいになるので日本人的にしてみた（がiso8601に則れば変えないほうが良い）
        $dateFormat = "Y/m/d H:i:s";

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

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

        // context に入ってきた配列を vsprintfするとLog::debugなどでprintfの構文ライクにできるが
        // outputに対してやると余計なとこまで%構文に引っかかる可能性があるので、本来はここでやるよりハンドラ側でやったほうがいいよねもちろん。
        // ここでは、こんなこともできそうかな？という例として。。。
        // Log::debug("私は %s あなたは %d", ["あなた", 5]) などとすると
        // 私は あなた あなたは 5 
        // などとなる。
        if(is_array($record['context'])) 
        {
            $output = vsprintf($output, $record['context']);
        }

        return $output;
    }
}

※extraについてはキーの中がまた配列になっており、こういうのはドット記法で行けると書いてあったので、%extra.line% ($record['extra']['line'])などとなっている。
※ついでに日付フォーマットを日本人的に変更している。

Laravelとの合体

ここまで来てようやくLaravelに話が戻る。
Laravel(5.7)はconfig/logging.php にてログの設定を行う。
オフィシャルのドキュメントを見ていると、tap という属性でMonologのHandlerに横槍を入れられるらしいことが分かる。
つまり、この機能を使ってProcessorやFormatterをHandlerに入れてやれば良いことになる。
ので、ドキュメントにある通り、tapに入れる、横槍用のオブジェクトを以下のように定義した。
念の為、フォーマッタとプロセッサで2つに分けたけど一つでもいいのかも。。。
（余談だけど、オフィシャルのドキュメントが、この接続用のクラスに CustomizeFormatter なんて名前をつけるので、このクラス自体がカスタムされたフォーマッタなのか、と数時間ハマった。）

App\Logging\CustomProcessorConnect.php
<?php

namespace App\Logging;

use App\Logging\LineExFormatter;

/**
 * LineFormaterを継承してフォーマットを変更したLineExFormatterをハンドラにツッコミます。
 */
class CustomFormatterApply
{
    public function __invoke($logging)
    {
        $exFormatter = new LineExFormatter();

        foreach($logging->getHandlers() as $handler) {
            $handler->setFormatter($exFormatter);
        }
    }
}
App\Logging\CustomProcessorConnect.php
<?php

namespace App\Logging;

use Monolog\Processor\IntrospectionProcessor;
use Monolog\Logger;

/**
 * 行番号とかファイル名をとってくれる IntrospectionProcessorをハンドラに突っ込みます。
 */
class CustomProcessorConnect
{
    public function __invoke($logging)
    {
        // 4つくらい上にframeを遡るとちょうど良いやつが取れた。
        $introspectionProcessor = new IntrospectionProcessor(
            Logger::DEBUG,
            [],
            4);

        foreach($logging->getHandlers() as $handler) {
            $handler->pushProcessor($introspectionProcessor);
        }
    }
}

この2つのクラスをlogging.phpに記載する。

config/logging.php
        'daily' => [
            'driver' => 'daily',
            'path' => storage_path('logs/laravel.log'),
            'level' => 'debug',
            'tap' => [App\Logging\CustomFormatterConnect::class, App\Logging\CustomProcessorConnect::class],
            'days' => 14,
        ],

これでログのフォーマットが変更される。

実行結果

こんな感じに普通にログ出力

App\Http\Controllers\API\AppController.php
    /**
     * Store a newly created resource in storage.
     *
     * @param  \Illuminate\Http\Request  $request
     * @return \Illuminate\Http\Response
     */
    public function store(Request $request)
    {
        Log::info('>>>');

        $ret = array('key' => 'value');

        Log::info('<<<');

        return response()->json($ret);

    }

2018/11/08 01:26:33 [local.INFO] App\Http\Controllers\API\AppController@store(20) - >>>
2018/11/08 01:26:33 [local.INFO] App\Http\Controllers\API\AppController@store(24) - <<<

のようになる。

ちなみにIntrospectionProcsssorのコンストラクタの最後のパラメータを0にすると、
Illuminate\Log\Logger みたいのが取れてしまって、お前えじゃねえよ、、、みたいになってしまった。

まとめ

  • Monologがわかっていれば何のことはないカスタムかもしれないけど、せっかくFacadeだInjectionだいうならもうちょっとMonologを知らなくてもなんとかなんないのかなと思うこの頃。
  • traitという仕組みを今更ながらに知ったのだけどこれがなかなか便利そう。
  • たまには人様が作ったフレームワークを見ると刺激になる。
39
39
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
Sign upLogin
39
39