【Laravel】SQL をフォーマットしてログに残す

　主に使うのは jdorn/sql-formatterです。このライブラリは SQL 文字列をフォーマットするライブラリです。フレームワークに依存していないためどの PHP 環境でも使えます（composer.json の動作環境指定は PHP 5.2.4 以上）。
jdorn/sql-formatter： A lightweight php class for formatting sql statements. Handles automatic indentation and syntax highlighting.
　使い方は次です。

<?php
require_once('SqlFormatter.php');

$query = "SELECT count(*),`Column1`,`Testing`, `Testing Three` FROM `Table1`
    WHERE Column1 = 'testing' AND ( (`Column2` = `Column3` OR Column4 >= NOW()) )
    GROUP BY Column1 ORDER BY Column3 DESC LIMIT 5,10";

echo SqlFormatter::format($query);

SELECT
  count(*),
  `Column1`,
  `Testing`,
  `Testing Three`
FROM
  `Table1`
WHERE
  Column1 = 'testing'
  AND (
    (
      `Column2` = `Column3`
      OR Column4 >= NOW()
    )
  )
GROUP BY
  Column1
ORDER BY
  Column3 DESC
LIMIT
  5, 10

　こんな感じでSQL文を渡すとインデント等の体裁を整えてくれます。これを次の様に Laravel とつなげると SQL をフォーマットした状態でログに残せます。

<?php
// app/Providers/AppServiceProvider.php

namespace App\Providers;

use DB;
use Illuminate\Database\Events\QueryExecuted;
use Illuminate\Support\ServiceProvider;
use Log;
use SqlFormatter;

class AppServiceProvider extends ServiceProvider
{
    /**
     * Bootstrap any application services.
     *
     * Laravel 起動時に走る処理で SQL 実行時にフックを仕込みます
     * https://cpoint-lab.co.jp/article/201812/6924/
     *
     * @return void
     */
    public function boot(): void
    {
        if (config('app.debug') !== true || config('app.env') === config('app.in_production_env_name')) {
            return;
        }
        DB::connection()->enableQueryLog();
        DB::connection()->listen(static function (QueryExecuted $query) {
            if ($query->time < 1000) {
                // query_log チャンネルのログにフォーマット済み SQL を渡します。
                // 第二引数の false はハイライトなしを表す false です。これがないとコンソール用の修飾が付きます
                Log::channel('query_log')->debug(SqlFormatter::format($query->sql, false), [
                    'params'    => $query->bindings, // プレースホルダへのバインド値
                    'time_ms'   => $query->time, // 実行時間ミリ秒
                    'slow'      => false, // if 文で遅いか速いか分岐
                ]);
            } else {
                // 遅い場合は warning レベル
                Log::channel('query_log')->warning(SqlFormatter::format($query->sql, false), [
                    'params'    => $query->bindings,
                    'time_ms'   => $query->time,
                    'slow'      => true,
                ]);
            }
        });
    }
}

　クエリログ専用のログチャンネルとログフォーマッター（SQLとは別）を用意します。

<?php
// config/logging.php

use App\Logging\QueryLogFormatter;

try {
    $__current_process_user = trim(shell_exec('whoami'));
} catch (ErrorException $e) {
    $__current_process_user = '';
}

return [
    'channels' => [
        // 他ログチャンネルの記述を省略
        'query_log' => [
            'driver'     => 'daily',
            // whoami コマンドの結果でプロセスユーザ毎にログファイルを分けます。
            // これを行うとバッチのログと web サーバのログが分かれて読みやすいです。
            // 権限問題が起きにくい部分でも便利です。
            'path'       => storage_path('logs/query-'.$__current_process_user.'.log'),
            'channels'   => ['daily'],
            'tap'        => [QueryLogFormatter::class],// 後述のログフォーマッター
            'days'       => 30,
            'permission' => 0664,
        ],
        // 他ログチャンネルの記述を省略
    ],
];

【PHP】【Laravel】Monolog のログフォーマットを操作する – 株式会社シーポイントラボ ｜ 浜松のシステム・RTK-GNSS開発
　↑の様に Laravel 用のログフォーマッターを用意します。一メッセージの見栄え重視なので PHP_EOL を使って改行を増やします。

<?php
// app/Logging/QueryLogFormatter.php
namespace App\Logging;

use Monolog\Formatter\LineFormatter;
use Monolog\Handler\FormattableHandlerInterface;
use Monolog\Handler\ProcessableHandlerInterface;
use Monolog\Logger;
use Monolog\Processor\IntrospectionProcessor;
use Monolog\Processor\ProcessIdProcessor;
use Monolog\Processor\UidProcessor;
use Monolog\Processor\WebProcessor;

class QueryLogFormatter
{
    // メインとなるフォーマット定義。どの URL で起きたか、あるアクセスで発生した一連のクエリは何かわかるようにしています
    private const LOG_FORMAT = '[%datetime% %channel%.%level_name% url:%extra.url% ip:%extra.ip% uid:%extra.uid%]'.PHP_EOL.'%message%'.PHP_EOL.'%context%'.PHP_EOL;

    /**
     * 渡されたロガーインスタンス（Monolog インスタンス）のカスタマイズ
     *
     * @param  Logger $monolog
     * @return void
     */
    public function __invoke($monolog)
    {
        $formatter = new LineFormatter(self::LOG_FORMAT, 'Y/m/d H:i:s.v', true, true);

        $processors = [
            new IntrospectionProcessor(Logger::DEBUG, ['Illuminate\\']),
            new UidProcessor(),
            new WebProcessor(),
            new ProcessIdProcessor(),
        ];
        foreach ($monolog->getHandlers() as $handler) {
            if ($handler instanceof FormattableHandlerInterface) {
                $handler->setFormatter($formatter);
            }
            if ($handler instanceof ProcessableHandlerInterface) {
                foreach ($processors as $p) {
                    $handler->pushProcessor($p);
                }
            }
        }
    }
}

　これを入れると次の様に SQL 文が読みやすい形で storage/logs/query-ユーザ名-Y-m-d.log に保存され、プレースホルダにバインドされた値は何か、実行にかかった時間は何ミリ秒か、この SQL はどの URL にアクセスされた時に発行されたか人間の目ですぐ読める様になります。また uid でどの SQL らが一つの PHP プロセス内で実行されたかも検索できます。

[2021/01/20 09:10:46.217 local.DEBUG url:/api/coin/37710 ip:192.168.99.1 uid:afa6ce4]
select 
  * 
from 
  `coins` 
where 
  `coins`.`coin_id` = ? 
  and `coins`.`deleted_at` is null 
limit 
  1
{"params":["37710"],"time_ms":5.93,"slow":false}