Laravel ミドルウェアを使って、処理が遅い時にログを取る

はじめに

以前、処理の遅い時にログを取るという事をやった時がありました。その時は、public/index.php に直に書きましたが、今回敢えて、より汎用性のある？ミドルウェアに書き換えてみました。

以前のやり方

public/index.php の上には、

define('LARAVEL_START', microtime(true));

みたいな記述がありますので、同ファイルの一番下に、以下を追加しました。
（実際に使った書き方とは少し変えてありますが、基本は同じです）

$kernel->terminate($request, $response);

// 以下、追加
$processTime = microtime(true) - LARAVEL_START;

if ($processTime > 3) {
    $context = [
        'process_time' => number_format($processTime, 2),
        'url' => request()->url(),
        'method' => request()->method()
    ];

    info("Too slow", $context); // ログを取る
}

これで処理に3秒以上掛かった際にログを取るという事をします。
以下みたいなログが取れます。

[2021-06-17 14:28:43] local.INFO: Too slow {"process_time":"4.05","url":"http://temp.abc","method":"GET"}
[2021-06-17 14:29:25] local.INFO: Too slow {"process_time":"3.07","url":"http://temp.abc","method":"POST"}

こちらは、処理の全体の時間を計測するという感じですが、以下のミドルウェアを使った版では、どちらかと言うと、コントローラーの処理での時間の計測という感じになりますので、予めご了承下さい。

ミドルウェア版

適当な名前でミドルウェアを作ります。

php artisan make:middleware LogSlowAction

該当のミドルウェアは、以下のようにします。

    public function handle(Request $request, Closure $next)
    {
        $startTime = microtime(true);

        $response = $next($request);

        $processTime = microtime(true) - $startTime;

        if ($processTime > 3) {
            $context = [
                'process_time' => number_format($processTime, 2),
                'url' => request()->url(),
                'method' => request()->method()
            ];

            info("Too slow", $context); // ログを取る
        }

        return $response;
    }

こんな感じです。まぁ、基本的には、public/index.php に書いた時と同じですね。後は、これを web.php などで仕掛ければOKです。

敢えて書くと、Befofe と After のミドルウェアが1つのクラスに同居しているタイプは、あまり書かないですかね。

雑感

これでログがガシガシ取られるようであれば、サーバが遅いか、コードに問題があるかでしょうか…。

おかしな箇所等ありましたらコメント下さい。