OpenResty または Nginx における最も CPU を消費するリクエストの分析
OpenResty や Nginx のようなノンブロッキング Web サーバーが多くの CPU リソースを消費することは一般的です。これは、epoll や kqueue のようなオペレーティングシステムの機能による I/O マルチプレキシング機能のおかげです。DevOps や SRE の担当者にとって、オンラインサーバーまたは複数のサーバーで、どのリクエスト URI やどのリクエストホスト名が最も多くの CPU 時間 を消費しているかを迅速に特定することが有用な場合があります。この記事では、OpenResty XRay の動的トレーシングツールを使用して、変更を加えていない OpenResty および Nginx Web サーバーをリアルタイムでこのような統計を分析する方法をご紹介します。
標準の動的トレーシングツールと、SQL に似た言語（YSQL と呼ばれる）で作成されたカスタムツールの両方を使用して、OpenResty XRay によって自動生成されたデータとグラフィックを含む実際の例をお示しします。
システム環境
ここでは例として Red Hat Enterprise Linux 7 システムを使用します。Ubuntu、Debian、Fedora、Rocky、Alpine など、OpenResty XRay がサポートする Linux ディストリビューションであれば、同様に動作するはずです。
対象アプリケーションとして、変更を加えていないオープンソースの OpenResty バイナリビルドを使用します。自分でコンパイルしたものを含め、任意の OpenResty または Nginx バイナリを使用できます。既存のサーバーインストールやプロセスに特別なビルドオプション、プラグイン、ライブラリは必要ありません。これが 動的トレーシング 技術の美しさです。真に非侵襲的なのです。
また、同じシステム上で OpenResty XRay の Agent デーモンを実行し、openresty-xray-cli パッケージからコマンドラインユーティリティを インストールして設定 しています。
CPU 使用率が最も高いリクエストのホスト名
標準ツールの使用
最も便利な方法は、標準ツール ngx-cpu-hottest-hosts を実行することです。
まず、OpenResty または Nginx サーバーインスタンスのマスタープロセスの PID を特定します。
$ ps aux | grep nginx:
root 1691450 0.0 0.0 28868 4140 ? Ss Jul05 0:00 nginx: master process /usr/local/openresty/nginx/sbin/nginx
nobody 3055159 1.5 0.0 40868 4096 ? S 14:38 4:58 nginx: worker process
マスタープロセスの PID は 1059 です。これを使用して、Nginx ワーカープロセスを含む、このプロセスグループ内のすべてのプロセスを追跡します。
$ orxray analyzer run ngx-cpu-hottest-hosts -p -1691450 -t 10
Start tracing...
Go to https://x5vrki.xray.openresty.com/targets/68/history/582346 for charts
ここでは、orxray コマンドラインユーティリティを使用して、標準ツールの ngx-cpu-hottest-hosts をマスタープロセスの PID である 1059 で指定されたプロセスグループに対して実行します。これは -p オプションを通じて行います。PID の前にあるマイナス記号に注意してください。これは、そのプロセスの全プロセスグループをリアルタイムで追跡したいことを示しています。また、-t オプションは追跡したい秒数を指定します。一般的な経験則として、対象アプリケーションの負荷が低い場合はより長いサンプリング時間ウィンドウを使用し、負荷が高い場合はより短いウィンドウを使用すべきです。
上記の出力には、OpenResty XRay の Web コンソールへのリンクが表示されており、この度で生成された美しいチャートを見ることができます。ユーザーの Web コンソールの URI は異なるものになります。
最もホットなのは openresty.org ホスト名であることがわかります。次に openresty.com が続きます。ここでカウントしているのは、オペレーティングシステムの CPU プロファイラ にヒットしたリクエストのみであり、すべてのリクエストをカウントしているわけではないことに注意してください。したがって、相対的な数値のみが意味を持ちます。例えば、openresty.org は openresty.com と比較して、サンプル数（733 対 612）から見て約 19% 多くの CPU 時間を消費しています。
時には、単一の Nginx ワーカープロセスのみを分析したい場合があります。これは、1つのワーカープロセスが他のプロセスよりも多くの CPU 時間を消費している場合や、導入されるトレーシングのオーバーヘッドを最小限に抑えたい場合に有用です。そのような場合、orxray コマンドの -p オプションの値として、そのワーカープロセスの PID を使用することができます。
$ orxray analyzer run ngx-cpu-hottest-hosts -p 3055159 -t 10
今回は、PIDの前にマイナス記号（-）を省略することが重要です。
デフォルトでは、このツールは現在のマシン上のプロセスを分析します。他のサーバー上のプロセスを分析したい場合は、-a agent_ID オプションを追加して、実行したいサーバーを指定することができます。OpenResty XRay Web コンソールで表示可能なエージェント ID のリストを取得するには、orxray agent list コマンドを使用してください。
YSQL を使用したカスタムツールの作成
最大限の柔軟性を得るために、YSQL と呼ばれる SQL ライクな言語を使用してカスタムの動的トレーシングツールを作成するのは、より楽の方法です。 YSQL 言語は、リレーショナルデータベースの照会には使用されません。代わりに、常に 動的トレーシング ツールにコンパイルされ、実行中のプロセスやアプリケーションに対してリアルタイムの検査と分析を行います。
以下の内容で my-cpu-hottest-hosts.ysql という名前のプレーンテキストファイルを作成しましょう。お好みのコードエディタを使用してください。
select count(*) count, host
from cpu.profile inner join ngx.reqs
group by host
order by count desc
limit 10;
この SQL クエリはほとんど自明です。最も興味深い部分は from 句で、inner join を使用して Nginx リクエストとオペレーティングシステムの CPU プロファイラーを照合しています。CPU プロファイラーは仮想テーブル cpu.profile に対応します。host 列は HTTP ホストヘッダーの値です。上位 10 件のみに関心があるため、limit 10 句を追加しました。
では、この YSQL ツールを実行してみましょう。ワーカープロセスの PID が 3055159 であると仮定すると、以下のコマンドになります。
$ run-ysql -p 3055159 ./my-cpu-hottest-hosts.ysql -t 10
Start tracing...
Go to https://x5vrki.xray.openresty.com/targets/68/history/583188 for charts
今回は run-ysql コマンドラインユーティリティを使用していることに注意してください。
上記の標準ツールと同様の出力チャートを Web リンクで閲覧することができます。
ワンライナー YSQL
ローカルファイルを作成せずに、YSQL をワンライナーとして実行することもできます。
$ run-ysql -p 3055159 -t 10 -e 'select count(*) count, host from cpu.profile inner join ngx.reqs group by host order by count desc limit 10;'
CPU 使用率が最も高いリクエスト URI
対象プロセスにおいて CPU 使用率が最も高いリクエスト URI をトレースすることもできます。
標準ツールの使用
標準ツール ngx-cpu-hottest-uris を実行できます：
$ orxray analyzer run ngx-cpu-hottest-uris -p 3055159 -t 10
Start tracing...
Go to https://x5vrki.xray.openresty.com/targets/68/history/622478 for charts
CPU 使用率が最も高い上位 2 つのリクエスト URI が、openresty.org の / と openresty.com の /en であることがわかります。
カスタム YSQL ツールの作成
今回の YSQL クエリは少し異なります。uri カラムを代わりに使用します。
select count(*) count, host, uri
from cpu.profile inner join ngx.reqs
group by host, uri
order by count desc
limit 10
では、この YSQL ツールを実行してみましょう。ワーカープロセスの PID が 3055159 であると仮定すると、以下のコマンドになります。
$ run-ysql -p 3055159 ./my-cpu-hottest-uris.ysql -t 10
Start tracing...
Go to https://x5vrki.xray.openresty.com/targets/68/history/622204 for charts
上記のカスタムツールと同様の出力チャートをウェブリンクで閲覧することができます。
さらに深く掘り下げる
ホスト名や URI によって CPU リソースの消費量が異なる自然な原因の一つは、リクエスト数が他と比べて多いことです。これを確認するために、一定の時間枠内でホスト名や URI ごとにグループ化されたすべてのリクエストを数えることができます。
最もリクエストの多い最繁忙ホスト名
標準ツールの使用
標準ツール ngx-req-counts-by-hosts を使用してカウントを行うことができます。
$ orxray analyzer run ngx-req-counts-by-hosts -p 3055159
Start tracing...
Go to https://x5vrki.xray.openresty.com/targets/68/history/584324 for charts
指示に従ってウェブページを閲覧することができます：
トップドメインの openresty.org が最もリクエスト数が多いことがわかります。しかし、2位は openresty.com ではなく doc.openresty.com です。これは、平均して openresty.com の各リクエストが doc.openresty.com よりも多くの CPU 時間を消費している可能性があることを意味します。
YSQL を使用したカスタムツールの作成
デモンストレーションの目的で、標準ツール ngx-req-counts-by-hosts をエミュレートするシンプルな YSQL ツールファイルを作成することができます：
select count(*) count, host
from ngx.reqs
group by host
order by count desc
limit 10;
from 句に注目してください。もはや仮想テーブル cpu.profile との inner join は行っていません。そのため、サンプリング時間枠内に Nginx または OpenResty が処理したすべてのリクエストをカウントするようになりました。
では、PID 3055159 の Nginx ワーカープロセスに対して、この YSQL ツールを実行してみましょう。
$ run-ysql -p 3055159 ./top-10-hosts-req.ysql
Start tracing...
Go to https://x5vrki.xray.openresty.com/targets/68/history/584615 for charts
すると、上記の棒グラフと同様のチャートが得られるはずです。
最もネットワークデータ量の多い、最も忙しいホスト名
また、ngx-req-size-by-hosts という標準ツールを使用して、大量の累積ネットワークトラフィックデータ量（またはリクエストサイズ、リクエストヘッダーとリクエストボディの両方を含む）を持つ最も忙しいリクエストホスト名をサンプリングすることができます。
$ orxray analyzer run ngx-req-size-by-hosts -p 3055159
Start tracing...
Go to https://x5vrki.xray.openresty.com/targets/68/history/584675 for charts
openresty.org と doc.openresty.com が、リクエスト数と同様に、ネットワークデータ量の大部分を占めていることがわかります。
カスタム YSQL ツールは以下のようになります：
select sum(req_size) request_size, host
from ngx.reqs
group by host
order by request_size desc
limit 10;
ngx.reqs 仮想テーブルの req_size カラムは、総リクエストサイズ（リクエストヘッダー + リクエストボディ）を表します。ただし、TLS/SSL ハンドシェイクトラフィックは含まれません。
ボトルネックの発見と最適化
具体的なパフォーマンスのボトルネックを分析し、最適化の提案を得るために、C 言語と Lua 言語それぞれの CPU フレームグラフツールをさらに使用することができます。
OpenResty XRay は、忙しいアプリケーション（OpenResty や Nginx アプリケーションだけでなく！）を自動的にプロファイリングすることができ、また人間の専門家が実行可能な提案を含む豊富な分析レポートを提供することもできます。このようにして、一般のユーザーは、いつ、どこで、どのツールを実行すべきかを知る必要さえありません。また、アナライザーの出力を解釈する必要もありません。
Web コンソールで直接実行
ユーザーは、このチュートリアルで紹介したツールのいずれかを OpenResty XRay の Web コンソールで直接実行することを選択できます。高い CPU 使用率などの興味深いイベントが発生した際に自動的にトリガーすることも可能です。openresty-xray-cli のコマンドラインユーティリティはデモンストレーション目的に便利です。また、DevOps や SRE の担当者にとっては、他のシステムへの自動化や統合が容易です。
コンテナ内のアプリケーションのトレース
OpenResty XRay ツールは、コンテナ化されたアプリケーションを透過的にトレースすることをサポートしています。Docker と Kubernetes（K8s）コンテナの両方が透過的に動作します。通常のアプリケーションプロセスと同様に、対象のコンテナにはアプリケーションや追加の特権は必要ありません。OpenResty XRay エージェントデーモンは、対象のコンテナの外部（ホストオペレーティングシステム直接か、または独自の特権コンテナ内）で実行する必要があります。
例を見てみましょう。まず、docker ps コマンドでコンテナ名またはコンテナ ID を確認します。
$ docker ps
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
4465297209d9 openresty/openresty:1.19.3.1-2-alpine-fat "/usr/local/openrest…" 18 months ago Up 11 minutes angry_mclaren
ここでは、コンテナ名は angry_mclaren です。次に、このコンテナ内の対象プロセスの PID を見つけます。
$ docker top angry_mclaren
UID PID PPID C STIME TTY TIME CMD
root 3310154 3310133 0 14:22 ? 00:00:00 nginx: master process /usr/local/openresty/bin/openresty -g daemon off;
nobody 3310209 3310154 0 14:22 ? 00:00:00 nginx: worker process
openresty ワーカープロセスの PID は 3310209 です。そして、通常通りこの PID に対して OpenResty XRay アナライザーを実行します。
$ orxray analyzer run ngx-cpu-hottest-hosts -p 3310209 -t 10
Start tracing...
...
Go to https://x5vrki.xray.openresty.com/targets/68/history/600752 for charts
OpenResty XRay は、長時間実行されているプロセスを特定のタイプ（「OpenResty」、「Python」など）の「アプリケーション」として自動的に検出することもできます。
ツールの実装方法
すべてのツールは Y 言語で実装されています。
OpenResty XRay は、OpenResty XRay の Stap+1 または eBPF2 バックエンドを使用してこれらを実行します。両方とも、Linux カーネルの uprobes および kprobes 機能に基づく 100% 非侵襲的な動的トレーシング技術を使用しています。
YSQL クエリはまず Y 言語にコンパイルされ、その後実行可能な動的トレーシングツールにコンパイルされます。
対象となるアプリケーションやプロセスとの連携は一切必要ありません。ログデータやメトリクスデータも使用せず、必要ありません。実行中のプロセスのプロセス空間を厳密に読み取り専用の方法で直接分析します。また、対象プロセスにバイトコードやその他の実行可能コードを一切注入しません。100% クリーンで安全です。
ツールのオーバーヘッド
このチュートリアルで紹介する動的トレーシングツールは非常に効率的で、オンライン実行に適しています。
ツールが実行されておらず、アクティブにサンプリングしていない場合、システムおよび対象プロセスへのオーバーヘッドは厳密にゼロです。対象アプリケーションやプロセスに追加のコードやプラグインを一切注入しないため、固有のオーバーヘッドはありません。
サンプリング中、典型的なサーバーハードウェアにおいて、リクエストのレイテンシは平均で1マイクロ秒（μs）未満しか増加しません。また、各 CPU コアで毎秒数万のリクエストを処理する最速の OpenResty/Nginx サーバーにおいても、最大リクエストスループットの低下はわずか約 4% です。
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 XRay（マイクロサービスおよび分散トラフィックに最適化された多機能
翻訳
英語版の原文と日本語訳版（本文）をご用意しております。読者の皆様による他の言語への翻訳版も歓迎いたします。全文翻訳で省略がなければ、採用を検討させていただきます。心より感謝申し上げます！
-
これは実際には、OpenResty Inc が大幅に強化した eBPF 実装である ORBPF です。 ↩︎
関連記事
OpenResty XRay Jul 19, 2023
OpenResty XRay Jul 15, 2023
OpenResty XRay Jun 23, 2023
OpenResty XRay Sep 7, 2020
OpenResty XRay Jul 14, 2022
