Linuxカーネル内の関数のコールグラフを表示したり、ソースコードの行指定をして変数の値を出力したりするといったようなトレーシングをするために、トレーサーを利用する。 Linuxカーネルのトレーサーには、ftraceやperf、eBPFなどがある。Choosing a Linux Tracer (2015)
今回は、ftrace(trace-cmd)とperf probeを動作させるために環境構築したときのログをメモしておく。 ここでは、さくらのクラウドのUbuntu Server 18.04.2 LTS 64bitのISOイメージを基に構築したインスタンス上で、ftraceとperfの環境を構築する。
ftrace(trace-cmd)
まず、はじめに、必要なパッケージをインストールする。
# apt install trace-cmd
次に、trace-cmd listで利用可能なトレーサーにfunctionとfunction_graphがあることを確認する。
# trace-cmd list -t hwlat blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nop
trace-cmdの動作確認のために、関数コールグラフの出力を ss コマンドを利用して確認する。
# trace-cmd record -p function_graph -l tcp_diag_dump -l tcp_diag_get_info ss -tanp 1>/dev/null
plugin 'function_graph'
CPU0 data recorded at offset=0x448000
4096 bytes in size
# trace-cmd report
cpus=1
ss-12700 [000] 2219157.460551: funcgraph_entry: | tcp_diag_dump() {
ss-12700 [000] 2219157.460563: funcgraph_entry: 0.105 us | tcp_diag_get_info();
ss-12700 [000] 2219157.460565: funcgraph_entry: 0.061 us | tcp_diag_get_info();
ss-12700 [000] 2219157.460567: funcgraph_entry: 0.056 us | tcp_diag_get_info();
ss-12700 [000] 2219157.460601: funcgraph_entry: 0.451 us | tcp_diag_get_info();
ss-12700 [000] 2219157.460611: funcgraph_exit: + 51.468 us | }
ss-12700 [000] 2219157.460618: funcgraph_entry: 0.211 us | tcp_diag_dump();
ss-12700 [000] 2219157.460720: funcgraph_entry: | tcp_diag_dump() {
ss-12700 [000] 2219157.460722: funcgraph_entry: 0.102 us | tcp_diag_get_info();
ss-12700 [000] 2219157.460771: funcgraph_exit: + 50.640 us | }
ss-12700 [000] 2219157.460774: funcgraph_entry: 0.265 us | tcp_diag_dump();
perf probe
次に、perf probeを動作させる。まずはパッケージのインストールから。
# apt install linux-tools-$(uname -r)
ここでは、sock_alloc_fileという関数の35行目の時点でのname.name変数の値を表示させることを目指す。 普通に実行すると、次のようなカーネルイメージを読み込めないエラーがでる。
# perf probe --add "sock_alloc_file:35 name.name:string" Failed to find the path for kernel: Invalid ELF file Error: Failed to show lines.
straceを挟んで実行すると、カーネルの実行バイナリをvmlinuxを読み込もうとしていることわかったが、/boot以下にはvmlinuzファイルしかない。
perfは圧縮されたカーネルイメージであるvmlinuzからはシンボルを読み取れない*1ため、vmlinuxファイルを用意する。
デバッグシンボル付きのカーネルイメージを取得するため、Debug Symbol Packages - Ubuntu Wiki にしたがい、デバッグシンボルパッケージ用のaptリポジトリを追加する。
次に、次のコマンドでカーネルイメージパッケージをインストールすると、/usr/lib/debug/boot/vmlinux-4.15.0-45-genericにvmlinuxファイルがインストールされる。
# apt install linux-image-$(uname -r)-dbgsym
その後、再度perf probeを実行すると、今度は次のようなソースコードを発見できていないエラーがでる。
# sudo perf probe --add "sock_alloc_file:35 name.name:string" Specified source line is not found. Error: Failed to show lines.
Linuxカーネルのソースコードを落としてくる必要がある。 ここでは、パッケージからソースコードをインストールする。
# apt install linux-source-4.15.0 # mkdir -p /usr/src/linux-4.15.0 # tar xjf /usr/src/linux-source-4.15.0/linux-source-4.15.0.tar.bz2 -C /usr/src/linux-4.15.0/ --strip 1
その後、perf probe -sオプションでソースコードのディレクトリを指定すると、イベントの追加に成功する。
# perf probe -s /usr/src/linux-4.15.0/ --add "sock_alloc_file:35 name.name:string"
Added new event:
probe:sock_alloc_file (on sock_alloc_file:35 with name=name.name:string)
You can now use it in all perf tools, such as:
perf record -e probe:sock_alloc_file -aR sleep 1
sock_alloc_file関数から、socket作成処理をキャプチャするために、次のコマンドでnginxプロセスを指定して記録処理を待ち受けておき、別ホストからabコマンドでHTTPリクエストを投げる。
perfはイベントをサンプリングして記録するため、abコマンドなどで複数回投げてやるとよい。*2
# perf record -e probe:sock_alloc_file -aR -p function_graph --pid 21326 Warning: PID/TID switch overriding SYSTEM^C[ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.021 MB perf.data (104 samples) ]
最後に、次のように、perf reportで結果を出力する。name変数の値として、'TCP'と表示されていることがわかる。
# perf report | cat # To display the perf.data header info, please use --header/--header-only options. # # # Total Lost Samples: 0 # # Samples: 104 of event 'probe:sock_alloc_file' # Event count (approx.): 104 # # Overhead Trace output # ........ ............................. # 100.00% (ffffffff8182ed93) name="TCP" # # (Cannot load tips.txt file, please install perf!) #
ここまで動かすのに意外とハマってしまった。
