【ITニュース解説】Notes from a 2 AM On-Call: Why Our vLLM Semantic Router Dropped 40% of Requests Under Load

あるITシステムで、深夜2時に突然、不可解な問題が発生した。システムは、ユーザーからのリクエストを処理して適切なAIモデルに振り分ける「セマンティックルーター」と呼ばれる部分を持っていた。このルーターは、PythonのFastAPIというWebフレームワークを使って構築され、AIモデルの呼び出しにはvLLMというライブラリを使用していた。深夜のトラフィックが急増した際、このセマンティックルーターが、受信したリクエストの約40%を何の応答もなく消失させてしまった。これはシステムエンジニアにとって非常に厄介な状況である。通常、システムがエラーを起こせば「5xx」のようなエラーコードが返されたり、メモリ不足でプログラムが強制終了する（OOM Kill）といった兆候が見られるものだ。しかし、今回はそのような明示的なエラーは一切なく、ただリクエストが「虚空に消えた」ように見えた。

システム監視ツールであるPrometheusのデータを見ると、異常が明らかになった。普段は80ミリ秒程度で完了するはずのルーティング決定処理にかかる時間が、突然4.8秒にまで跳ね上がっていた。その後、リクエストはログにも記録されなくなり、完全に姿を消した。その結果、1秒あたりに処理できるリクエスト数（QPS：Queries Per Second）は、普段の240件から140件へと大幅に減少し、システムの性能が41%も劣化したことを示していた。これは、多くのリクエストが処理されずに捨てられていることを意味する。

最初の段階では、何が問題なのか正確にはわからなかった。セマンティックルーターのライブラリ（semantic-router）の公式ドキュメントには、シンプルな利用例が示されていた。この例は、リクエストを受けてからルーターがどのAIモデルを使うかを決めるという一連の処理が、同期的に、つまり一つずつ順番に実行されることを前提にしているように見えた。私たちの開発チームは、このルーターをFastAPIの「async def」という非同期処理用の関数でラップして使用していた。非同期関数であれば、複数のリクエストが同時に来ても、適切に処理を切り替えながらスムーズに動くと考えていたため、ルーター自身も並行処理を問題なくこなしてくれると期待していたのだ。

ローカル環境で200件の並行リクエストをシミュレートする負荷テストを行った際には、特に問題は見られなかった。しかし、本番環境での実際のトラフィックパターンは、もっと複雑で予測不能なものだった。特に、10秒間に300件以上のリクエストが集中するような瞬間的な「バースト」が発生すると、状況は一変した。根本的な原因は、router()関数の中で行われる「エンベディング計算」が同期的に実行されていたことにあった。エンベディングとは、テキストデータをAIが理解できる数値のベクトル表現に変換する処理のことだが、この計算が完了するまで、プログラムは次の処理に進めない「ブロッキング」状態になっていた。

PythonのAsyncIOという非同期処理の仕組みは、本来、I/O処理（ファイル読み書きやネットワーク通信など、完了までに時間がかかる処理）中にCPUがアイドル状態になる時間を活用して、別のタスクに処理を切り替えることで効率を高める。しかし、CPUを占有し続けるような計算処理が同期的に実行されると、AsyncIOのイベントループ（タスクを管理・実行する中心的な役割）がこの計算処理にブロックされてしまい、他のタスクにコンテキストを切り替えることができなくなる。結果として、新しいリクエストが来ても処理を開始できず、キューにどんどん溜まっていく状態になった。そして、内部で設定されていた5秒というタイムアウト時間を超えたリクエストは、何もエラーを返さずにサイレントに破棄されてしまっていたのだ。

この問題の元凶は、semantic-routerライブラリがエンベディング生成にsentence-transformersというライブラリを使用しており、これがデフォルトでCPU上で同期的に動作することだった。高い並行性でリクエストが集中すると、最初に受け付けたリクエストのエンベディング計算が長時間CPUを占有し、後続のリクエストが全く処理されない「ヘッド・オブ・ライン・ブロッキング」という状態を引き起こしていた。これは、行列の先頭の人が動かないと、後ろの人がどれだけ準備できていても進めない状況に似ている。

この根本原因に対し、私たちは実行可能な解決策を見つけた。それは、ブロッキングを引き起こすエンベディング計算を、メインのイベントループから別のスレッドに「オフロード」することだった。具体的には、Pythonの非同期処理ライブラリであるasyncioが提供するasyncio.to_thread()という関数を使用する。この関数は、指定された同期的な処理を、バックグラウンドのスレッドプールで実行してくれる。これにより、CPUを長時間占有するエンベディング計算がメインのイベントループから切り離され、イベントループは解放された状態で、次々と新しいリクエストを受け付けたり、他の非同期タスクを処理したりできるようになる。

このスレッドプールへのオフロード修正を適用した後、システムは劇的に改善した。同じ負荷条件下でテストしたところ、以前は4800ミリ秒だったP95レイテンシ（全リクエストの95%が完了するまでの時間）が、わずか320ミリ秒にまで短縮された。そして、リクエストがドロップする現象は完全に解消された。

この経験から、私たちは重要な教訓を得た。「AsyncラッピングはAsync実行を意味しない」という不変のルールである。つまり、たとえasync defで非同期ハンドラを記述したとしても、そのハンドラ内で呼び出す外部ライブラリや関数が同期的な処理を含んでいれば、それはメインのイベントループをブロックしてしまう可能性がある、ということだ。sentence-transformersやトークナイザー、あるいは同期的なAIモデルの推論を行うようなライブラリを使用する場合、それらを非同期ハンドラから呼び出す際には、必ずasyncio.to_thread()でラップするか、あるいは別のプロセスプールで実行する必要がある。

特にsemantic-routerのようなライブラリでCPU上でエンベディングを実行し、1秒あたり50件を超えるような並行リクエストを期待するならば、必ずスレッドに処理をオフロードすべきである。もしGPUを主な処理に使う場合は、リクエストをまとめて一括で処理する「バッチ処理」を検討するか、あるいはエンベディング専用のサービスを設けることで、ブロッキングを完全に回避できる。

今回経験したような、リクエストがタイムアウトして5xxエラーも出さずに消えてしまう「サイレント障害モード」は、問題の特定とデバッグを極めて困難にするため、最も避けるべき状況である。非同期処理のボトルネックをデバッグする際には、常に明示的なタイムアウトに関するメトリクス（測定値）を発行し、リクエストのライフサイクルを最初から最後まで追跡する（エンドツーエンドのトレース）ことが非常に重要になる。これにより、問題発生時にどこで何が起きているのかを正確に把握し、迅速な解決につなげられる。