LaravelでwithContextを使用して同一スレッドのログを識別させる

なぜログが必要なのか?

Laravelに限らず、Webアプリケーションにおいてログは不可欠な存在です。ログは、アプリケーションの実行状況を記録することで、以下のようなメリットをもたらします。

  1. エラーの特定とデバッグ
  2. パフォーマンスの分析
  3. セキュリティの監査
  4. システムの監視

エラーの特定とデバッグ

いつ、どこで、どのようなエラーが発生したのかを特定し、問題の原因究明に役立ちます。例えば、特定の機能が正常に動作しない場合、その機能に関するログを調べ、エラーが発生した箇所を特定することができます。

パフォーマンスの分析

各処理の実行時間やリソース消費量を計測することで、システムのボトルネックを特定し、パフォーマンス改善に繋げることができます。例えば、特定のAPIリクエストが非常に遅い場合、そのリクエストに関するログを分析することで、遅い原因となっている処理を特定することができます。

セキュリティの監査

不正アクセスやセキュリティ侵害の痕跡を検出することができます。例えば、不正なログイン試行やSQLインジェクション攻撃が発生した場合、そのログを分析することで、攻撃の詳細を特定し、対策を講じることができます。

システムの監視

アプリケーションの稼働状況を監視し、異常を検知することができます。例えば、サーバーがダウンした場合や、データベースに接続できない場合、そのログを分析することで、問題の原因を特定し、復旧することができます。

なぜ同一スレッドのログを識別する必要があるのか?

同一スレッドのログを識別する最大の理由は「リクエスト単位での処理の追跡を可能にすること」です。

Webアプリケーションでは、1つのリクエストに対して複数の処理が実行されることが一般的で、同一スレッドのログを辿ることで、1つのリクエストに対する処理の流れを詳細に追跡することができます。

例えば、あるリクエストに対して、データベースへのアクセス、外部APIへの呼び出し、メール送信など、複数の処理が実行された場合、これらの処理がどのような順序で行われたのかをログから確認することができます。

同一スレッドのログを識別する方法

結論から言うと、LogファサードのwithContextを利用して以降のログ出力に同じ情報を付与するやり方になります。

Laravelのドキュメントでも触れられているように、withContextを使用することで後続のすべてのログエントリに追加の情報を付与するようになります。

withContextとMiddlewareを利用することで、同一スレッドのログを冒頭から追跡可能にすることができます。

Middlewareの作成

php artisan make:middleware AddTraceId

AddTraceIdの実装

app/Http/Middleware/AddTraceId.php

<?php

namespace App\Http\Middleware;

use Closure;
use Illuminate\Http\Request;
use Illuminate\Support\Facades\Log;
use Illuminate\Support\Str;
use Symfony\Component\HttpFoundation\Response;

class AddTraceId
{
    /**
     * Handle an incoming request.
     *
     * @param Closure(Request): (Response) $next
     */
    public function handle(Request $request, Closure $next): Response
    {
       // withContextを利用するだけ
        Log::withContext([
            'trace_id' => Str::uuid()->toString(),
        ]);

        return $next($request);
    }
}

app/Http/Kernel.phpに設定を追加する

app/Http/Kernel.php

protected $middleware = [
    \App\Http\Middleware\AddTraceId::class, // 一番先頭に追加
    \App\Http\Middleware\TrustProxies::class,
    \Illuminate\Http\Middleware\HandleCors::class,
    \App\Http\Middleware\PreventRequestsDuringMaintenance::class,
    \Illuminate\Foundation\Http\Middleware\ValidatePostSize::class,
    \App\Http\Middleware\TrimStrings::class,
    \Illuminate\Foundation\Http\Middleware\ConvertEmptyStringsToNull::class,
];

kernel.phpのmiddlewareプロパティの先頭に追加することで、その他のmiddlewareよりも先に適応することが可能です。

ログを処理の冒頭から追跡可能にするには先頭にmiddlewareを追加すると良いかと思います。

まとめ

どのような方法で同一スレッドのログを識別するかは、アプリケーションの規模や複雑さ、ログの利用目的によって異なります。

ミドルウェアやwithContextを利用して識別子を付与する方法はLaravelにおいて、最も手っ取り早く簡単な方法だと考えます。

最後になりましたが、上記の方法で出力されるログの一例を下記に添付しておきます。

[2024-09-26 10:27:36] local.INFO: [Start] コントローラーログ出力 {"thread_id":"33c99c87-1aef-43e6-80da-b7edee816417","method":"App\\Http\\Controllers\\LoginController::login"} 
[2024-09-26 10:27:36] local.INFO: [Start] ログイン処理 {"thread_id":"33c99c87-1aef-43e6-80da-b7edee816417","method":"App\\Http\\Actions\\Login\\LoginAction::execute"} 
[2024-09-26 10:27:36] local.INFO: [End] ログイン処理 {"thread_id":"33c99c87-1aef-43e6-80da-b7edee816417","method":"App\\Http\\Actions\\Login\\LoginAction::execute"} 
[2024-09-26 10:27:36] local.INFO: [End] コントローラーログ出力 {"thread_id":"33c99c87-1aef-43e6-80da-b7edee816417","method":"App\\Http\\Controllers\\LoginController::login"}
最新情報をチェックしよう!