Request IDをログとレスポンスに通す — Laravelでの実装と伝播
この記事で扱う問題
障害を切り分ける手順では、「Request ID で1件のリクエストを端から端まで追う」ことを中心に置きました。ただ、実際のアプリでは、ID を振っていても次のようなところで途切れがちです。
- アプリのログには ID が出ているが、利用者に返すレスポンスには出ていない。問い合わせを受けても、どのログの話か分からない
- Web のリクエストのログには出ているが、そこからディスパッチしたキューのジョブのログには出ていない。「注文は確定したのに、出荷依頼が飛んでいない」ときに、ジョブのログを時刻で探すことになる
- 外部 API の相手に調査を頼みたいが、こちらの呼び出しと相手のログを結びつける値がない
- クライアントが送ってきた
X-Request-Idをそのまま使っていて、改行を含む長い文字列や、他人のリクエストと同じ値がログに入る
Request ID は、障害が起きてから足しても、過去のログには戻ってきません。どこで生成し、どこまで通すかを先に決めておく必要があります。
判断
入口で1回だけ決め、ログのコンテキストに入れる
Request ID はミドルウェアで1回だけ決め、Laravel 11 以降の Context に入れます。Context に入れた値は、そのリクエストの中で出すすべてのログに自動で付き、ディスパッチしたキューのジョブにも引き継がれます。
use Closure;
use Illuminate\Contracts\Config\Repository as Config;
use Illuminate\Http\Request;
use Illuminate\Support\Facades\Context;
use Illuminate\Support\Str;
use Symfony\Component\HttpFoundation\Response;
final class AssignRequestId
{
private const HEADER = 'X-Request-Id';
public function __construct(private Config $config)
{
}
public function handle(Request $request, Closure $next): Response
{
$incoming = $request->headers->get(self::HEADER);
$trusted = (bool) $this->config->get('logging.trust_incoming_request_id', false);
if ($trusted && $this->isValid($incoming)) {
// 自分たちのロードバランサや Nginx が付けた ID なら、そのまま使ってログをつなぐ
$requestId = $incoming;
} else {
$requestId = (string) Str::ulid();
if ($this->isValid($incoming)) {
// 信頼しない経路から来た ID は、使わずに別の項目として残す
Context::add('client_request_id', $incoming);
}
}
Context::add('request_id', $requestId);
$response = $next($request);
$response->headers->set(self::HEADER, $requestId);
return $response;
}
private function isValid(?string $value): bool
{
return $value !== null && preg_match('/\A[A-Za-z0-9._-]{8,64}\z/', $value) === 1;
}
}
このミドルウェアは、グローバルミドルウェアの先頭に置きます（bootstrap/app.php の withMiddleware() で $middleware->prepend(AssignRequestId::class)）。後ろのミドルウェアが出すログにも ID を付けるためです。
$next($request) の中で例外が投げられても、Laravel はそれを 500 などのレスポンスに変換してからミドルウェアに返すので、エラーのレスポンスにもヘッダーは付きます。画面を返すアプリなら、エラー画面にも Context::get('request_id') を表示しておくと、利用者から問い合わせを受けたときに、その値でログを検索できます。
ID を ULID にしているのは、先頭が時刻なので、値だけでおおよその発生時刻が分かり、並べたときに時刻順になるからです。UUID v4 でも追跡には困りません。
受け取った ID は、自分たちの上流が付けたものだけ信頼する
ロードバランサや Nginx で ID を付け、それをアプリに渡す構成なら、アクセスログとアプリのログが同じ ID でつながります。このときだけ、設定で trust_incoming_request_id を有効にします。その前提として、上流では、クライアントから届いた同じ名前のヘッダーを捨てて、必ず付け直すようにしておきます。
アプリが直接インターネットに面していて、ヘッダーをクライアントが自由に送れるなら、受け取った ID は使いません。使うと、別のリクエストと同じ ID を送られてログが混ざったり、形式を確かめていなければ、改行を含む値でログの行を偽装されたりします。モバイルアプリが自分で振った ID を送ってくるなら、上の例の client_request_id のように別の項目で残せば、アプリ側のログと突き合わせる手がかりとしては使えます。
外部 API には ID を付けて送り、相手の ID を受け取って残す
外部 API を呼ぶときは、同じ ID をヘッダーに付けます。Gateway ごとに書くと付け忘れるので、HTTP クライアント全体に付けます。
use Illuminate\Support\Facades\Context;
use Illuminate\Support\Facades\Http;
use Illuminate\Support\ServiceProvider;
use Psr\Http\Message\RequestInterface;
final class AppServiceProvider extends ServiceProvider
{
public function boot(): void
{
Http::globalRequestMiddleware(function (RequestInterface $request): RequestInterface {
$requestId = Context::get('request_id');
return is_string($requestId) ? $request->withHeader('X-Request-Id', $requestId) : $request;
});
}
}
Http::globalRequestMiddleware() は、Http Facade と、コンテナから受け取る Factory のどちらで作ったリクエストにも効くので、外部 API の記事の HttpShippingGateway のようにコンストラクタで Factory を受け取る Gateway にも付きます。
相手がこのヘッダーを読むとは限りません。それでも、相手に調査を頼むときに「この時刻に、この ID で送った」と伝えられます。逆に、相手がレスポンスに自分の Request ID を返してくるなら、それを Gateway のログに残します。相手のサポートが求めるのは、たいてい相手側の ID だからです。
キューのジョブには引き継ぎ、ジョブ自身の情報を足す
Context の値は、ディスパッチした時点でジョブのペイロードに保存され、ワーカーがジョブを処理するときに戻されます。ジョブの中で出すログには、ディスパッチした元のリクエストの request_id が付きます。
ただ、同じジョブがリトライされると、どの試行のログか区別できません。ワーカー側で、ジョブの UUID と試行回数を足します。
use Illuminate\Queue\Events\JobProcessing;
use Illuminate\Support\Facades\Context;
use Illuminate\Support\Facades\Queue;
use Illuminate\Support\ServiceProvider;
final class QueueLogContextServiceProvider extends ServiceProvider
{
public function boot(): void
{
Queue::before(function (JobProcessing $event): void {
Context::add([
'job_uuid' => $event->job->uuid(),
'job_name' => $event->job->resolveName(),
'job_attempt' => $event->job->attempts(),
]);
});
}
}
Laravel は JobProcessing のタイミングで、前のジョブの Context を消してからペイロードの値を戻します。値を戻すリスナーは、Laravel 本体が最初に登録するサービスプロバイダ（ContextServiceProvider）が登録しています。アプリのサービスプロバイダで登録した上のリスナーはその後に動くので、戻された値に足す形になります。
HTTP のリクエストを経ない処理（スケジューラから動くコマンドなど）には、入口がありません。コマンドの開始時に同じように ID を振って Context に入れておけば、そこからディスパッチしたジョブにも引き継がれます。
なぜそう判断したか
ID をあちこちで作らず、入口で1回だけ決める理由
ログを出す箇所ごとに $request->header('X-Request-Id') を読んでいると、ヘッダーがない場合の扱いが箇所ごとに変わり、同じリクエストのログに違う ID が付くことがあります。入口で1回だけ決めて、あとは Context から読むだけにすれば、ID の決め方は1か所にしか書かれません。
Laravel 10 以前なら、Log::withContext()（すべてのチャンネルに付けるなら Log::shareContext()）でリクエスト内のログには付けられます。ただ、ジョブへの引き継ぎは自動では行われないので、ID をジョブのコンストラクタで渡して、handle() の最初でコンテキストに入れ直す、といった仕組みを自分で作ることになります。Context を選んだのは、この引き継ぎをジョブごとに書かずに済むからです。
Request ID を Idempotency Key に使わない理由
Request ID とIdempotency Keyは、どちらもヘッダーで送る一意な値ですが、役割が違います。Request ID は「どのリクエストか」を追うための値で、クライアントが再送すれば新しい ID になるのが正しい振る舞いです。Idempotency Key は「どの操作か」を表し、再送しても同じでなければいけません。Request ID を重複の判定に使うと、再送のたびに別の操作として扱われ、二重に実行されます。逆に、外部 API へのリトライで同じ Request ID が何度も送られても、それは追跡の値なので問題ありません。
分散トレーシングの基盤から入らなかった理由
OpenTelemetry のような分散トレーシングでは、W3C Trace Context（traceparent ヘッダー）でトレースの ID を伝播し、どの処理にどれだけ時間を使ったかまで記録できます。複数のサービスをまたぐ呼び出しが多いなら、こちらのほうが得られる情報は多いです。
ただ、私自身まだ深めている途中の領域で、導入には収集先の基盤や、計測のためのコードの設計が要ります。1つの Laravel アプリとキュー、いくつかの外部 API という構成なら、まずは ID をログとレスポンスに通すだけで、調査で一番時間を使う「どのログが同じリクエストか」を探す作業はなくなります。あとからトレーシングを入れる場合も、トレースの ID をログのコンテキストに入れる形にすれば、ここで作った「入口で1回決めて、ログとジョブに通す」構造はそのまま使えます。
どこから設計過剰になるか
- ログの出力先が1か所で、キューも外部 API もない小さなアプリなら、ミドルウェアでログに ID を付けてレスポンスヘッダーに返すだけで十分です。ジョブや外部 API への伝播は、それらを使い始めてから足します
- Request ID を業務のテーブルの列に保存する必要は、基本的にありません。ログから追えれば足ります。監査のために「この変更はどのリクエストによるものか」を DB に残す要件があるテーブルに限ります
- 社外に公開する API で、利用者に ID を返すのは有用ですが、ID に利用者 ID や時刻以外の内部情報を埋め込む形式にはしません。ランダムな値なら、外に出ても困りません
- 呼び出す外部 API の中に、未知のヘッダーを拒否するものがあるなら、全体に付けるのをやめ、その Gateway だけ除外するか、付ける Gateway を個別に選びます。全体に付けると、ID を渡す相手がすべての外部 API に広がります。ULID は発生時刻を含むので、それも外に出したくない相手がいるなら、同じように付ける先を選びます
まとめ
- Request ID はミドルウェアで1回だけ決め、
Contextに入れて、すべてのログとレスポンスヘッダーに通す - 受け取った ID は、自分たちの上流が付け直したものだけ信頼し、形式を必ず確かめる
- 外部 API には ID を付けて送って相手の ID を残し、キューのジョブにはジョブの UUID と試行回数を足す