`systemtap-toolkit` と `stapxx`: データを使って難しい問題を解決する方法は？
API7.ai
December 22, 2022
前回の記事で紹介したように、サーバーサイド開発エンジニアとして、私たちは動的デバッグツールセットの深い学習は行わず、主に使用レベルに留まり、せいぜい簡単な定型スクリプトを書く程度です。CPUキャッシュ、アーキテクチャ、コンパイラなどの低レベルな部分は、パフォーマンスエンジニアの領域です。
OpenRestyには、openresty-systemtap-toolkitとstapxxという2つのオープンソースプロジェクトがあります。これらは、NGINXとOpenRestyのリアルタイム分析と診断のためのsystemtapベースのラップツールセットです。これらは、on-CPU、off-CPU、共有ディクショナリ、ガベージコレクション、リクエストレイテンシ、メモリプーリング、コネクションプーリング、ファイルアクセスなどの一般的な機能とデバッグシナリオをカバーしています。
この記事では、これらのツールとその使用方法を概観し、NGINXとOpenRestyのトラブルシューティング問題に遭遇した際に、問題を特定するためのツールを迅速に見つけるのに役立てます。OpenRestyの世界では、これらのツールの使用を学ぶことは、確実に先を行く方法であり、他の開発者とコミュニケーションを取る非常に効果的な方法です。なぜなら、ツールによって生成されるデータは、私たちが言葉で説明できるものよりも正確で詳細だからです。
ただし、OpenRestyバージョン1.15.8ではLuaJIT GC64モードがデフォルトで有効になっていますが、openresty-systemtap-toolkitとstapxxはそれに追随していないため、内部のツールが正しく動作しません。そのため、これらのツールを使用する際は、古い1.13バージョンのOpenRestyを使用することをお勧めします。
ほとんどのオープンソースプロジェクトの貢献者はパートタイムであり、ツールが動作し続けることを保証する義務はありません。これは、オープンソースプロジェクトを使用する際に注意する必要があります。
例: shared dict
今日の投稿を始めるにあたり、おそらく最も馴染みがあり、最も簡単に始められるツールであるngx-lua-shdictを例に取り上げます。
ngx-lua-shdictは、NGINXのshared dictを分析し、その操作を追跡するツールです。-fオプションを使用して、dictとkeyを指定し、shared dict内のデータを取得できます。--rawオプションを使用すると、指定したkeyの生の値をエクスポートできます。
以下は、shared dictからデータを取得するコマンドラインの例です。
# NGINX WorkerのPIDが5050と仮定
$ ./ngx-lua-shdict -p 5050 -f --dict dogs --key Jim --luajit20
Tracing 5050 (/opt/nginx/sbin/nginx)...
type: LUA_TBOOLEAN
value: true
expires: 1372719243270
flags: 0xa
同様に、-wオプションを使用して、指定したkeyに対するdictの書き込みを追跡できます:
$./ngx-lua-shdict -p 5050 -w --key Jim --luajit20
Tracing 5050 (/opt/nginx/sbin/nginx)...
Hit Ctrl-C to end
set Jim exptime=4626322717216342016
replace Jim exptime=4626322717216342016
^C
このツールがどのように実装されているかを見てみましょう。ngx-lua-shdictはPerlスクリプトですが、実装はPerlとは関係ありません。Perlは、stapスクリプトを生成して実行するために使用されています。
open my $in, "|stap $stap_args -x $pid -" or die "Cannot run stap: $!\n";
これをPython、PHP、Go、または好きな言語で書くこともできます。stapスクリプトのキーポイントは、以下のコード行です:
probe process("$nginx_path").function("ngx_http_lua_shdict_set_helper")
これは、前に説明したprobeで、ngx_http_lua_shdict_set_helper関数をプローブしています。この関数の呼び出しは、すべてlua-nginx-moduleモジュールのlua-nginx-module/src/ngx_http_lua_shdict.cファイルにあります。
static int
ngx_http_lua_shdict_add(lua_State *L)
{
return ngx_http_lua_shdict_set_helper(L, NGX_HTTP_LUA_SHDICT_ADD);
}
static int
ngx_http_lua_shdict_safe_add(lua_State *L)
{
return ngx_http_lua_shdict_set_helper(L, NGX_HTTP_LUA_SHDICT_ADD
|NGX_HTTP_LUA_SHDICT_SAFE_STORE);
}
static int
ngx_http_lua_shdict_replace(lua_State *L)
{
return ngx_http_lua_shdict_set_helper(L, NGX_HTTP_LUA_SHDICT_REPLACE);
}
このようにして、この関数をプローブすることで、共有ディクショナリのすべての操作を追跡できます。
on-CPU, off-CPU
OpenRestyを使用する際に最もよく遭遇する問題は、パフォーマンスに関するものです。パフォーマンスが低い、つまりQPSが低い場合、主に2つのタイプがあります。CPU使用率が高すぎる場合と、CPU使用率が低すぎる場合です。前者のボトルネックは、以前に紹介したパフォーマンス最適化手法を使用していないことが原因である可能性がありますが、後者はブロッキング関数が原因である可能性があります。対応するon-CPUとoff-CPUのフレームグラフは、根本的な原因を特定するのに役立ちます。
Cレベルのon-CPUフレームグラフを生成するには、systemtap-toolkitのsample-btを使用する必要があります。一方、Luaレベルのon-CPUフレームグラフは、stapxxのlj-lua-stacksによって生成されます。
sample-btの使用方法を例に取り上げます。sample-btは、指定した任意のユーザープロセス（NGINXとOpenRestyプロセスだけでなく）のコールスタックをサンプリングするスクリプトです。
たとえば、実行中のNGINX Workerプロセス（PIDが8736）を5秒間サンプリングするには、以下のコードを使用します:
$ ./sample-bt -p 8736 -t 5 -u > a.bt
WARNING: Tracing 8736 (/opt/nginx/sbin/nginx) in user-space only...
WARNING: Missing unwind data for module, rerun with 'stap -d stap_df60590ce8827444bfebaf5ea938b5a_11577'
WARNING: Time's up. Quitting now...(it may take a while)
WARNING: Number of errors: 0, skipped probes: 24
これにより、結果ファイルa.btが出力され、FlameGraphツールセットを使用してフレームグラフを生成できます:
stackcollapse-stap.pl a.bt > a.cbt
flamegraph.pl a.cbt > a.svg
a.svgは生成されたフレームグラフで、ブラウザで開いて表示できます。ただし、サンプリング期間中は、一定数のリクエストを維持する必要があります。そうでないと、サンプル数が0の場合、フレームグラフを生成できません。
次に、off-CPUのサンプリング方法を見てみましょう。systemtap-toolkitのsample-bt-off-cpuスクリプトを使用します。これはsample-btと似ています:
$ ./sample-bt-off-cpu -p 10901 -t 5 > a.bt
WARNING: Tracing 10901 (/opt/nginx/sbin/nginx)...
WARNING: _stp_read_address failed to access memory location
WARNING: Time's up. Quitting now...(it may take a while)
WARNING: Number of errors: 0, skipped probes: 23
stapxxでは、レイテンシを分析するツールはepoll-loop-blocking-distrで、指定したユーザープロセスをサンプリングし、連続するepoll_waitシステムコール間のレイテンシ分布を出力します。
$ ./samples/epoll-loop-blocking-distr.sxx -x 19647 --arg time=60
Start tracing 19647...
Please wait for 60 seconds.
Distribution of epoll loop blocking latencies (in milliseconds)
max/avg/min: 1097/0/0
value |-------------------------------------------------- count
0 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 18471
1 |@@@@@@@@ 3273
2 |@ 473
4 | 119
8 | 67
16 | 51
32 | 35
64 | 20
128 | 23
256 | 9
512 | 2
1024 | 2
2048 | 0
4096 | 0
この出力から、ほとんどの遅延は1ミリ秒未満ですが、200ミリ秒を超えるものもいくつかあり、これらに注意する必要があります。
アップストリームとフェーズの追跡
OpenRestyのコード自体で発生する可能性のあるパフォーマンス問題に加えて、OpenRestyがcosocketやproxy_passなどのアップストリームモジュールを通じてアップストリームサービスと通信する際に、アップストリームサービス自体に大きな遅延がある場合、全体のパフォーマンスに大きな影響を与える可能性があります。
この場合、ngx-lua-tcp-recv-time、ngx-lua-udp-recv-time、ngx-single-req-latencyなどのツールを使用して分析できます。以下はngx-single-req-latencyの例です。
このツールは、ツールセット内の他のほとんどのツールとは少し異なります。他のツールは、大量のサンプルと統計分析に基づいて、分布に関する数学的な結論を導き出します。一方、ngx-single-req-latencyは、個々のリクエストを分析し、OpenRestyの各フェーズ（rewrite、access、contentフェーズなど）およびアップストリームで個々のリクエストに費やされた時間を追跡します。
具体的な例を見てみましょう:
# ./stap++ツールをPATHに追加:
$ export PATH=$PWD:$PATH
# nginxワーカープロセスのpidが27327と仮定
$ ./samples/ngx-single-req-latency.sxx -x 27327
Start tracing process 27327 (/opt/nginx/sbin/nginx)...
POST /api_json
total: 143596us, accept() ~ header-read: 43048us, rewrite: 8us, pre-access: 7us, access: 6us, content: 100507us
upstream: connect=29us, time-to-first-byte=99157us, read=103us
$ ./samples/ngx-single-req-latency.sxx -x 27327
Start tracing process 27327 (/opt/nginx/sbin/nginx)...
GET /robots.txt
total: 61198us, accept() ~ header-read: 33410us, rewrite: 7us, pre-access: 7us, access: 5us, content: 27750us
upstream: connect=30us, time-to-first-byte=18955us, read=96us
このツールは、開始後に最初に遭遇したリクエストを追跡します。出力はopentracingに非常に似ており、systemtap-toolkitとstapxxを、OpenRestyにおける非侵入型のAPM（アプリケーションパフォーマンス管理）と考えることもできます。
まとめ
今日紹介した一般的なツールに加えて、OpenRestyには自然に多くのツールが提供されており、自分で探して学ぶことができます。
OpenRestyと他の開発言語やプラットフォームの間には、トレーシング技術に関して大きな違いがあります。これは、ゆっくりと理解していくことができます。
コードをクリーンで安定した状態に保ち、プローブを追加しないでください。代わりに、外部の動的トレーシング技術を通じてサンプリングしてください。
OpenRestyを使用している間、問題を追跡および分析するためにどのようなツールを使用しましたか？この記事を共有し、一緒に進歩しましょう。