Laravel 5.1 でログ出力、それから (ログメールドライバー動作不良対処、クエリ出力の調整) « LANCARD.LAB

Laravel 5.1 でログ出力、それから (ログメールドライバー動作不良対処、クエリ出力の調整)

2017/02/01
murave
Laravel

おひさしぶりです。運用していたら結構変わったので、またこのネタです。

一応以前の記事へのリンクおいときます。

『Laravel 5.1 で実行ユーザー毎にログ出力』

『Laravel 5.1 でログ出力、その後 (出力レベル設定、クエリ出力)』

が、以前の記事の方法だとログメールドライバーが動作しないという問題が発生したので参考にしちゃだめ。

というわけで、以下の要件と不具合対処のために改修した内容を紹介します。

ログファイルの権限絡みのエラー回避、何処から起動された処理かわかりやすくする等の目的で実行ユーザー名ベースでログファイルを作成。
動作環境(local, testing, production等のenvironment)でもログファイルを分ける。
バッチ処理やartisanのコマンド実行の場合はARTISAN_BINARYをログファイル名に挿入してWebアクセスとはログファイルを分ける。
デバッグフラグ(app.debug)を落とした状態ではINFO以上のログのみ出力。
.envでAPP_QUERY_LOGGINGにtrueを設定したら発行されたクエリをinfoログで専用ログファイルに出力(デバッグフラグでのコントロールを廃止し個別にコントロール可能とし、ファイルも分けた)
以前の実装ではログメールドライバー(メール送信内容をログ出力するドライバ)が正常動作しなかったためLoggerインスタンスを差し替える方法から既存Loggerインスタンスのhandlerを差し替える方法に実装を変更。

class AppServiceProvider extends ServiceProvider
{
    public function boot()
    {
        //登録されたloggerのhandlerを置き換える
        $monolog = \Log::getMonolog();
        $monolog->popHandler(); //既存のhandlerを削除
        $monolog->pushHandler(
                    (new \Monolog\Handler\RotatingFileHandler(
                        $this->app->storagePath() . '/logs/' 
                            . $this->app->environment() . '_'
                            . (defined('ARTISAN_BINARY') ? ARTISAN_BINARY . '_' : '')
                            . posix_getpwuid(posix_geteuid())['name'] 
                            . '.log',
                        \Config::get('app.log_max_files', 5),
                        (\Config::get('app.debug') || $this->app->environment('testing')) 
                            ? \Monolog\Logger::DEBUG 
                            : \Monolog\Logger::INFO //出力レベル制御のため追加
                    ))
                    ->setFormatter(new \Monolog\Formatter\LineFormatter(null, null, true))
                );
        $monolog->pushProcessor(
                    new \Monolog\Processor\IntrospectionProcessor(
                        \Monolog\Logger::NOTICE,    //DEBUG,INFOは発生場所の情報を付加しない
                        [
                            'Illuminate\\',
                            //他、呼び出し元としてはスキップしたい対象を設定,
                        ]
                    )
                );

        //.envのAPP_QUERY_LOGGINGがtrueの場合クエリを独自ログquery_{実行アカウント}.logに出力する。
        if(env('APP_QUERY_LOGGING', false)) {
            \DB::listen(function($query, $bindings, $time){
                $queryLogger = (new \Monolog\Logger(
                    $this->app->environment()
                ))->pushHandler(
                    new \Monolog\Handler\StreamHandler (
                        $this->app->storagePath() . '/logs/query_' . posix_getpwuid(posix_geteuid())['name'] . '.log')
                );

                $queryLogger->info('QUERY:[' . $query . '] BINDINGS:'
                        . json_encode($bindings), ['TIME' => $time]);
            });
        }
// 以下略

クエリ出力については他のログに混ざると見にくくなる、デバッグフラグに連動させていると本番環境での調査で使えない、クエリ出力のログファイルは日付でローテーションさせるより同じファイル名のログファイル一本に出力されるほうが扱いやすい(消して良いものだし)、ということで今の形におさまりました。

ログファイル名に関して、例えばnginxユーザーがphpunitを回したときなど testing_artisan_nginx-2017-01-31.log みたいになるので「なげぇな〜」とは思いますが、場合によってログファイルが別れているのは便利ですよ。