Off-CPU 分析の実践:CPU 使用率が低いのにレイテンシが高い 4 つの根本原因と特定方法
Off-CPU 分析は、スレッドが CPU から離れている(ブロック・プリエンプト・待機)間の時間とコールスタックを測定する手法です。top では原因がわからない問題——CPU 使用率は明らかに低いのにレイテンシは高止まり、スループットも一向に上がらない——を解決します。リクエストは待っているだけで、計算はしていないのです。On-CPU プロファイリングと off-CPU 分析は相互に補完し合い、両者を合わせてスレッドの 100% の時間をカバーします。ある本番事例では、OpenResty XRay がプロセスの 99.8% の off-CPU 時間を io.popen とそのパイプハンドルに対する読み取り操作まで追跡し、修正後に単一コアのスループットは 126 RPS から 18,537 RPS へ——150 倍に向上しました。
Off-CPU 時間とは何か
スレッド(またはプロセス)が CPU 上で命令を実行している状態を on-CPU と呼びます。一方、何らかの理由で CPU から外される——ネットワーク I/O 待機、ロック競合、子プロセス待機、ファイル/パイプ I/O ブロック、さらにはスケジューラによるプリエンプション——と、off-CPU 状態に入ります。
上図は、スレッドが on-CPU と off-CPU を交互に切り替える様子を示しています。off-CPU 時間はすべての「暗い区間」の合計——スレッドが処理を進めたいのにブロックされている時間です。
イベント駆動型サーバー(Nginx/OpenResty など)の場合、ワーカースレッドが唯一「ブロックされてよい」箇所はイベントループ自体の待機操作(epoll_wait システムコールなど)です。それ以外の箇所での off-CPU 時間は、イベントループがブロックされていることを意味し、そのワーカー上のすべての同時接続が空待ちすることになります。
症状:CPU 使用率が上がらないのにリクエストが滞留
Off-CPU ボトルネックは、監視ダッシュボード上で典型的な 3 つの証拠を示します。
topで CPU 使用率が低位に張り付いている——プロセスは稼働し続けているが、CPU 欄は一向に上がらない。- アクセスログは増え続けている——リクエストは確かに流入しており、トラフィック不足ではない。
- 負荷をかけても上がらない——どれだけ負荷をかけても CPU は上がらない。
このパターンは言語を問わず繰り返し現れます。Perl プロセスが 13% で停滞、Go サービスが 2% で停滞、Python gunicorn ワーカーが 8% で停滞。CPU 使用率の具体的な数値は異なりますが、根本原因は同じです——スレッドが計算ではなく待機に時間を費やしています。
「CPU 使用率が低いのにレイテンシが高いのはなぜか」——この答えはほぼ確実に off-CPU にあります。あるコードパスが同期ブロッキング操作(ネットワーク呼び出し、子プロセス待機、ファイル読み取りなど)を実行しており、スレッドは一時停止し、CPU は空転し、リクエストはキューに溜まります。具体的にどのコード行でブロックしているかを特定するには、off-CPU 分析が必要です。
この種のブロッキングは、p99 テールレイテンシの周期的なスパイクとしても現れます。イベント駆動型サーバーでは、単一のワーカーがブロックされると、そのワーカー上のすべての同時接続が同時に影響を受けます。ただし、テールレイテンシのスパイクがすべて off-CPU 問題とは限りません。50 万 QPS の OpenResty ゲートウェイにおいて 244 ミリ秒のレイテンシスパイクを追跡した事例では、根本原因はブロッキング待機ではなく on-CPU 側にありました——正規表現の非効率なバックトラッキング処理が CPU 時間を消費し続けていたのです。外から見える症状は同じでも、時間が「待機」と「計算」のどちらに費やされたのかを見分けることこそ、off-CPU 分析と on-CPU プロファイリングそれぞれの役割です。
4 つの Off-CPU 根本原因の実例による因果チェーン
Off-CPU 時間の発生源は 4 つのカテゴリに分類できます。各カテゴリについてメカニズムの解説と実際の因果チェーン——システムコールから業務コードのファイル・行番号まで——を示します。
1. 同期ネットワーク I/O
メカニズム:スレッドがネットワークリクエストを発行した後に同期的にレスポンスを待機し、OS がデータ到着までスレッドを一時停止します。
実際の因果チェーン:Perl プロセスの CPU 使用率がわずか 13% だった事例では、off-CPU フレームグラフが示したブロッキングパスは以下の通りです。
selectシステムコール →Perl_pp_select→Net::HTTP::Methods::can_read→read_response_headers→ 業務関数remote_fetch
フレームグラフ上で remote_fetch 関数のフレームにマウスカーソルを合わせると、ツールチップにソースファイルパスと行番号が表示されます。66 行目にジャンプすると、HTTP GET リクエストを送信してレスポンスを同期的に待っているコードが確認できます。
2. 子プロセスとシェル呼び出し
メカニズム:プログラムが exec/subprocess 等で外部プロセスを起動し、waitpid でその終了を待ちます。待機中、呼び出し元のスレッドはブロックされます。
実際の因果チェーン 1(Go):Go サービスの CPU 使用率がわずか 2% だった事例では、off-CPU レポートが自動推定したブロッキングパスは以下の通りです。
Syscall6→Process.wait(内部はwaitpid)→exec.Cmd.Run→ 業務関数chat.RateLimit
ソースファイル chat/processor.go の 46 行目——RateLimit 関数が exec.Command("/usr/bin/sleep", "0.01") を呼び出し、cmd.Run() でシェルコマンドの完了を同期的に待っていました。
実際の因果チェーン 2(Python):Python gunicorn ワーカーの CPU 使用率がわずか 8% だった事例では、C レベルで最上位の off-CPU パスが 96%、Python レベルの #1 ブロッキングパスがブロッキング時間の 92.4% を占めていました。
pollシステムコール →subprocess.run→ 業務関数handle_by_script
ソースファイル processor.py の 12 行目——subprocess.run で外部 bash スクリプトを実行し、出力を待っていました。
3. 同期ファイル・パイプ I/O
メカニズム:標準ライブラリの同期ファイル/パイプ API(Lua の io.popen、file:read() など)は、I/O 操作が完了するまで現在のスレッドをブロックします。イベント駆動型フレームワークではこの影響は特に深刻です——ブロックされるのは 1 つのリクエストではなく、イベントループ全体です。
実際の因果チェーン:本番環境の OpenResty アプリケーションにおいて、OpenResty XRay は 2 つのブロッキング呼び出し箇所を検出しました——cfg-utils.lua 8 行目の io.popen 呼び出しと 14 行目の file:read() 呼び出し(後者は前者が開いたパイプハンドルからの読み取り)。OpenResty XRay は、対象プロセスの CPU 時間の 93.8% と off-CPU 時間の 99.8% をこの 2 箇所まで追跡しました。OpenResty のノンブロッキング lua-resty-shell ライブラリへの切り替えで、単一コアのスループットは 126 RPS から 859 RPS へ(7 倍)向上。さらにパイプをノンブロッキング cosocket API に置き換えることで 18,537 RPS へ(150 倍)向上しました。
また、ファイル I/O のレイテンシも無視できない場合があります。別の事例では、APR(Apache Portable Runtime)ライブラリ関数が ModSecurity モジュールを経由して Nginx プロセス内で呼び出された際、apr_generate_random_bytes の 1 回の読み取りレイテンシは最大 1,494 マイクロ秒(約 1.5 ミリ秒)、apr_sdbm_fetch は最大 953 マイクロ秒に達しました。同時接続数の多さと低レイテンシを特徴とする Nginx のようなプラットフォームでは、1 ミリ秒の同期ブロックでも深刻な問題となります。
4. CPU 争奪型:実行可能なのにコア未確保
メカニズム:多くの off-CPU 解説では「自発的な待機」——スレッドが I/O やロックにより一時停止するケースのみを取り上げます。しかし、見落とされがちな別のケースがあります。スレッドはすでに実行可能(runnable)状態で OS もそれを認識しているにもかかわらず、空き CPU コアがないためにランキューで待たされるのです。これは「能動的に停車した」のではなく「強制的に降ろされた」状態です。
実際の因果チェーン:Nginx ワーカープロセスの C レベル off-CPU 分析において、OpenResty XRay は、通常の epoll_wait 待機スタックに加え、mpi_mul_hlp や free といった純粋な CPU 計算関数にもかなりの off-CPU 時間が費やされていることを検出しました。
純粋な計算関数の実行中に off-CPU 時間が発生するということは、スレッドは I/O を待っているのではなく、すでに実行可能だが CPU タイムスライスを確保できていないことを意味します。これは CPU リソース争奪の典型的な症状です。さらに分析を進めると、Nginx 設定で worker_cpu_affinity ディレクティブが未指定であったことが根本原因であり、複数のワーカープロセスが Linux カーネルにより異なる CPU コア間で頻繁にスケジュールされ、不要なコンテキストスイッチのオーバーヘッドが発生していました。この事例では、単一ワーカーの RPS は 227–286 にとどまり、システム負荷はすでに 4(論理 CPU コア数と同等)に迫っていました。
この種の off-CPU 根本原因の識別方法は、前述の 3 つのカテゴリとは異なります。どの I/O システムコールでブロックしているかではなく、本来は純粋に on-CPU であるべき関数に off-CPU 時間が現れているかどうかを確認します。
Off-CPU 時間の定量化手法
Off-CPU ボトルネックの特定には、2 つのレイヤの計測手段が必要です。
2 層コールスタック分析:システムコールからソースファイル行番号まで
Off-CPU 分析の核心は、スレッドがブロックされている間のコールスタックをサンプリングすることです。効果的な分析には通常 2 つのレイヤを対照的に使用します。
- C/システムレイヤ:システムコールスタック(
select、poll、waitpid、readなど)を表示し、ブロックの種類を判別します。 - 言語レイヤ(Perl/Python/Go/Lua……):業務コードのコールスタックを表示し、システムコールを具体的な業務関数・ソースファイル・行番号にマッピングします。
C レイヤだけでは「poll でブロックしている」ことしかわかりません。しかし、具体的にどのコード行が poll を発生させているのか——それを明らかにするには言語レイヤのコールスタックが必要です。上記 3 つの事例では、off-CPU 分析の到達点はいずれも実際に開いて確認できるソースファイルの行でした。Perl ソースファイル 66 行目、Go processor.go 46 行目、Python processor.py 12 行目。このように「行番号まで追跡できる」具体性と対処可能性こそが、off-CPU 分析の核心的な価値です。
イベントループブロッキング遅延分布:影響範囲の定量化
イベント駆動型サーバーでは、「ブロックが存在する」ことを知るだけでは不十分で、ブロックの深刻度を定量化する必要があります。OpenResty XRay は、イベントループの各イテレーションにおけるブロッキング時間の分布をサンプリングできます。ある事例では、20 秒のサンプリングウィンドウ内に 43,952 個のブロッキングサンプルが取得され、1 回の最長ブロッキング時間は 75,165 マイクロ秒(75 ミリ秒) に達しました。イベントループが 75 ミリ秒ブロックされるたびに、そのワーカー上のすべての同時接続が空待ちすることになります——これこそがテールレイテンシスパイクの直接的な原因です。
On-CPU + Off-CPU = ウォールクロック時間:全体像とツールエコシステム
スレッドのウォールクロック時間 = on-CPU 時間 + off-CPU 時間。on-CPU 時間の最適化はスループット向上(単位時間あたりにより多くの有用な処理を実行)、off-CPU 時間の最適化はレイテンシ低減(無駄な待機の削減)に寄与します。2 つの視点は相互に補完し合い、どちらも欠かせません。
off-CPU 分析ツールは数多く存在しますが、本番環境で使用するには一定のハードルがあります。エージェントやカーネルモジュールのインストール、特定のカーネルバージョンの要件、アプリケーション起動パラメータの変更、特定の言語ランタイムのみのサポートなどです。
OpenResty XRay は自動化されたアプローチを提供します。Guided Analysis の「Low CPU usage and cannot go up」問題タイプを選択し、実行中のプロセスを直接分析できます。perf/eBPF ツールのインストール、コード変更、プロセス再起動は不要です。C レベルと言語レベル(Perl/Python/Go/Lua/Java……)の 2 層で off-CPU コールスタック分析を同時に生成し、最も顕著なブロッキングコードパスを自動的に推定します。Insights ページではオンラインプロセスを自動監視し、日次・週次レポートを生成して off-CPU の変化傾向を継続的に追跡します。
よくある質問
Off-CPU 時間とは何ですか?
Off-CPU 時間とは、スレッドが CPU から離れてから再び CPU に戻るまでの時間——この間、スレッドは一切の命令を実行できません。主な原因にはネットワーク I/O 待機、子プロセス待機、ファイル/パイプの読み書きブロック、ロック競合、CPU スケジューリング争奪などがあります。On-CPU 時間と off-CPU 時間の合計がスレッドのウォールクロック時間に等しくなります。
CPU 使用率が低いのにレイテンシが高いのはなぜですか?
スレッドが大部分の時間を待機に費やしており、CPU 上で有用な処理を実行していないためです。典型的な根本原因には、同期ネットワーク呼び出し(HTTP レスポンスの待機など)、同期子プロセス呼び出し(subprocess.run、exec.Cmd.Run など)、同期ファイル/パイプ I/O(io.popen など)、および CPU リソース争奪(実行可能なスレッドがコアを確保できない状態)が含まれます。Off-CPU 分析により、ブロッキングパスを具体的なソースファイルと行番号まで追跡できます。
コードを変更せずにプログラムが何を待っているか特定するには?
OpenResty XRay の Guided Analysis 機能で「Low CPU usage and cannot go up」問題タイプを選択し、実行中の未修正プロセスをそのまま分析できます。off-CPU コールスタック分析を自動生成し、最も顕著なブロッキングコードパスを推定します——フレームにマウスカーソルを合わせるだけでソースファイルと行番号が確認できます。追加ツールのインストール、コード変更、プロセス再起動は一切不要です。
Off-CPU 分析とウォールクロックプロファイリングの違いは?
ウォールクロック(wall-clock)プロファイリングはスレッドの全時間をサンプリングし、CPU 上で実行中か待機中かを区別しません。Off-CPU 分析はスレッドがブロックされている時間とそのコールスタックのみにフォーカスします——on-CPU プロファイリングと相互補完の関係にあります。「CPU が上がらない」「レイテンシが高いが CPU は低い」という問題であれば、off-CPU 分析が直接その原因に迫ります。
OpenResty XRay について
OpenResty XRay は動的トレーシング製品であり、実行中のアプリケーションを自動的に分析して、パフォーマンスの問題、動作の問題、セキュリティの脆弱性のトラブルシューティングを行い、実行可能な提案を提供いたします。基盤となる実装において、OpenResty XRay は弊社の Y 言語によって駆動され、Stap+、eBPF+、GDB、ODB など、様々な環境下で複数の異なるランタイムをサポートしております。
著者について
章亦春(Zhang Yichun)は、オープンソースの OpenResty® プロジェクトの創始者であり、OpenResty Inc. の CEO および創業者です。
章亦春(GitHub ID: agentzh)は中国江蘇省生まれで、現在は米国ベイエリアに在住しております。彼は中国における初期のオープンソース技術と文化の提唱者およびリーダーの一人であり、Cloudflare、Yahoo!、Alibaba など、国際的に有名なハイテク企業に勤務した経験があります。「エッジコンピューティング」、「動的トレーシング」、「機械プログラミング」 の先駆者であり、22 年以上のプログラミング経験と 16 年以上のオープンソース経験を持っております。世界中で 4000 万以上のドメイン名を持つユーザーを抱えるオープンソースプロジェクトのリーダーとして、彼は OpenResty® オープンソースプロジェクトをベースに、米国シリコンバレーの中心部にハイテク企業 OpenResty Inc. を設立いたしました。同社の主力製品である OpenResty XRay(動的トレーシング技術を利用した非侵入型の障害分析および排除ツール)と OpenResty Edge(マイクロサービスおよび分散トラフィックに最適化された多機能ゲートウェイソフトウェア)は、世界中の多くの上場企業および大企業から高い評価を得ております。OpenResty 以外にも、章亦春は Linux カーネル、Nginx、LuaJIT、GDB、SystemTap、LLVM、Perl など、複数のオープンソースプロジェクトに累計 100 万行以上のコードを寄与し、60 以上のオープンソースソフトウェアライブラリを執筆しております。
翻訳
英語版の原文と日本語訳版(本文)をご用意しております。読者の皆様による他の言語への翻訳版も歓迎いたします。全文翻訳で省略がなければ、採用を検討させていただきます。心より感謝申し上げます!


















