実行中のシステムの挙動を詳細にトレースする仕組みは、特に「よくわからない問題」に遭遇している時に重要です。今回はLinux向けのトレーシングツールの本命とも言えるeBPFを利用した各種ツールを紹介します。
eBPFに関する記事が今回以降、数回にわたって解説されています。あわせてご覧ください。
eBPFとBPF Compiler Collection
改めて言うまでもなく、Linuxカーネルもしくはカーネル上で動いている各種タスクのパフォーマンスや挙動を調べなくてはならないケースはよくあります。たとえば単なる不具合の調査から、予期せぬ挙動に対する原因の特定、セキュリティ対応、高速化のための計測などが考えられるでしょう。この手の調査は「動いているカーネルをそのまま使う」ことがポイントでもあります。
第584回の「SystemTapでカーネルの挙動を確認する 」や第585回の「SystemTapを活用してネットワークの動作を確認する 」で紹介したSystemTapは、そんな「カーネルをそのまま使う」ことが可能な調査ツールでした。SystemTapは調査用のコードをカーネルモジュールとしてビルドしてロードするため、厳密な意味での「カーネルをそのまま」ではないのですが、それでもカーネルを再コンパイルしなくても調べられるのは強力な利点となります。
それに対して、より新しいカーネルで使えるようになった「eBPF」は任意の外部プログラムをカーネルの中で、より安全に実行できる仕組みです。カーネルモジュールを作る代わりに、独自のバイトコードをコンパイラーで生成し、それをカーネル内部にロード・実行することになります。よって独自のコンパイラーと新しいカーネルがあれば、比較的簡単に導入できます。SystemTapで必要だったデバッグシンボル付きのイメージも不要です。
気をつけなければいけないのは「新しいカーネル」の部分です。パケットフィルターとしてのBPF自体は古くから存在する機能ではあるものの、eBPFに向けてLinux 3.15で大きな対応が入り、仕組みやその周辺ツールについてはその後のカーネルのリリースごとに拡充されていった という経緯があります。よって「やりたいこと」に合わせてカーネルのバージョンがどうなっているかを調べる必要があります。たとえば現在サポートされているUbuntuのバージョンは次のとおりです。
Ubuntu 14.04 LTS(ESM) :3.13から4.4
Ubuntu 16.04 LTS(ESM) :4.4から4.15
Ubuntu 18.04 LTS:4.15から5.4
Ubuntu 20.04 LTS:5.4から5.13以降
Ubuntu 21.04:5.11
Ubuntu 21.10:5.13
ここで「ESM」と書いているものはExtended Security Maintenance に入っているものを示します。つまりすでにサポート期間は終了し、追加の有償サポート期間に入っているものです。よって「不具合やパフォーマンスの調査」が必要になるであろう、活発に保守されているサーバーはおそらく18.04以降にはなっていると期待できそうですし、そうすると古くとも4.15以降のカーネルが使われていることになります。
4.15ぐらいであれば、eBPFの基本的な機能なら問題なく使えます。今回はUbuntu 20.04 LTSを前提に話を進めましょう。
eBPFを使うツールはいろいろ存在しますが、その中でも基本的なツールであり広く使われているのが「BPF Compiler Collection(BCC) 」です。コンパイラーと名前のついているとおり、バイトコードを生成するコンパイラーを提供しているのですが、それ以上に便利なのが「eBPFを使ってよく作られるツール」をサンプルコマンドとしてまとめている点でしょう。つまりBCCを導入すれば、コードを書かなくてもeBPFを利用した各種トレーシングが行えるというわけです。
BCCのインストール方法
Ubuntuの場合、BCCはaptとsnapの2種類のインストール方法が存在します。
apt版は普通にDebianパッケージとしてインストールする方法です。シンブルな方法ではあるものの、他のaptパッケージと同じく「バージョンが古くなりがち」という問題を抱えています。たとえばBCCの2021年10月時点での最新版は0.22.0ですが、apt版のBCCは次のようなバージョンになっています。
Ubuntu 18.04 LTS: 0.5.0
Ubuntu 20.04 LTS: 0.12.0
Ubuntu 21.04: 0.18.0
Ubuntu 21.10: 0.18.0
それに対してsnap版のBCCは、0.21.0をインストール可能です。snap版はCanonicalがメンテナンスしているため、Ubuntuでも5.14カーネルが使えるようになるまでには、0.22.0以降のsnapパッケージも用意されることでしょう。
特にBCCの場合は、新しいカーネルの機能を使いたいなら、BCC側も新しくしなくてはなりません。使いたい機能を満たせるならapt版でも問題ないですが、より新しいカーネルでより新しい機能を使いたいならsnap版を使いましょう。またapt/snapともに名前や使い方に若干のクセが存在します。ここでは両方のインストール方法を紹介します。
apt版のインストール
apt版のパッケージ名は「bpfcc-tools 」です。これはDebianも同じです。bpfcc-toolsには前述の各種ツールが含まれます(※訂正 ) 。またPython 3バインディング等も一緒にインストールされます。
$ sudo apt instal bpfcc-tools
各種ツールにはすべて「-bpfcc
」という接尾辞が付きます。たとえば「execsnoop」コマンドのapt版での名前は「execsnoop-bpfcc」です。少しわかりにくいですが、タブ補完を活用すればそこまで気にならないでしょう。
ちなみにDebianの場合は、bpfc-toolsパッケージだけでなく「linux-headers-amd64」パッケージも一緒にインストールしておいてください。Debianのカーネルは「CONFIG_KHEADERS
」が有効化されておらず、/sys/kernel/kheaders.tar.xz
からカーネルのヘッダーファイルを取得できないためです。
snap版のインストール
snap版のパッケージ名はそのまま「bcc 」です。Canonicalがビルド・公開していますが、パッケージングのメタデータ(snapcraft.yaml)は公式プロジェクトに取り込まれています 。
$ sudo snap install bcc --devmode
現状のbccパッケージは「--devmode
」付きでインストールしないと、いくつかのツールが動作しません。bccを動かす時点で特権が必要なため、ここは諦めるしかないでしょう。また、上記BCCのページでは「snap connect
」を使う説明がありますが、ストアサイトからインストールする場合は自動的に設定されるため、あらためて対応する必要はありません。
各種ツールにはすべて「bcc.
」という接頭辞が付きます。たとえば「execsnoop」コマンドのsnap版での名前は「bcc.execsnoop」です。もしよく使うもので、オリジナルと同じ名前にしたい場合は「snap alias bcc.execsnoop execsnoop
」とエイリアスの設定をすると良いでしょう。元に戻すのは「snap unalias bcc.execsnoop
」です。
Linuxカーネルのフレーバーに注意
BCCはeBPFだけでなくツールに応じてdebugfsやkprobesなどといった、カーネルコンフィグを必要としています。しかしながら、Ubuntuのカーネルフレーバーによっては、これらのカーネルコンフィグが有効化されていません。
たとえばUbuntu Cloud Images から提供され、VM版のLXDインスタンスで使われるKVMフレーバーはCONFIG_KPROBES
が有効になっていないため、BCCの大半のツールが使えません。具体的には次のようなエラーメッセージが表示されてしまいます。
$ sudo bcc.execsnoop
create_probe_event: open(/sys/kernel/debug/tracing/kprobe_events): No such file or directory
Traceback (most recent call last):
File "/snap/bcc/159/usr/share/bcc/tools/execsnoop", line 229, in <module>
b.attach_kprobe(event=execve_fnname, fn_name="syscall__execve")
File "/snap/bcc/159/usr/lib/python3/dist-packages/bcc/__init__.py", line 834, in attach_kprobe
(fn_name, event))
Exception: Failed to attach BPF program b'syscall__execve' to kprobe b'sys_execve'
よってKVMフレーバーを使っている環境でどうしてもBCCを使いたい場合は、genericフレーバーに切り替えてしまいましょう。
$ sudo apt install -y linux-generic
$ sudo apt remove -y --purge '~nlinux-.*kvm ~i'
2行目でKVMフレーバーを削除しているのは、genericフレーバーのみで起動するようにしたいためです。generic/KVMを併用する場合はそのまま残しても問題ありません。その場合、grub-rebootコマンドで設定するかGRUBメニューから手動で「Ubuntu, with Linux 5.4.0-88-generic
」と末尾に「generic」と書かれたメニューを選択してください。
なお、KVMカーネルで起動している状態でKVMカーネルを削除しようとすると、「 起動中のカーネルを削除しようとしているが、きちんと別のカーネルで起動してから削除することを強く推奨する。よって削除を中止して良いか? 」と聞かれます。削除したい場合は、きちんと「No 」を選びましょう。
ちなみに今のところ問題になりそうなのは、KVMフレーバーのみです。AWS・GCP・GKE・Azureフレーバーについてはざっと見た限り問題なさそうです。
BCCの便利なツールたち
現状のBCCには、100個以上のツールが用意されています。これをすべて網羅するのは難しいのですが、よく使いそうな便利なものをいくつかピックアップして紹介しましょう。ちなみに公式サイトのREADME.md に掲載されているレイヤーごとの担当ツール一覧 の図を見るだけで、おおよその関係がつかめるはずです。
なお、これらのツールのほとんどはPythonプログラムです。よってその中身を見れば、容易にカスタマイズ可能になっています。
特定のイベントを監視するsnoop系ツール
特定のイベントが発生したときに順次記録していくツールは「なんとかsnoop」という名前がつけられています。
その中でもexecsnoopやopensnoop、bindsnoop、mountsnoop、shmsnoop、statsnoop、syncsnoop、threadsnoopなどは、特定のシステムコールの呼び出しを記録するツールです。
たとえばexecsnoopは、その名の通りexec()
システムコールの呼び出しを検知します。いわゆるpsコマンドは「実行した時点で動いているプロセス」しか確認できません。基本的なコマンドでプロセスが起動していく流れを確認しようと思ったら、psを定期的に実行するなりtopを眺めるなりする必要があります。execsnoopを使うと、瞬間的に起動したプログラムも含めてすべてのプロセスの起動の流れが把握できます。「 特定の期間において何が起きているか」を知るためには強力なツールです。
コマンド自体は引数なしで起動するだけでも十分に使えます。「 -T
」で時刻情報を、「 -U
」でUIDを、「 -x
」でexec()
が失敗した場合も記録してくれます。
$ sudo execsnoop-bpfcc -UTx
TIME UID PCOMM PID PPID RET ARGS
01:07:55 1000 sh 2109659 4089 0 /bin/sh -c byobu-status tmux_left
01:07:55 1000 byobu-status 2109660 2109659 0 /usr/bin/byobu-status tmux_left
01:07:55 1000 sed 2109662 2109660 0 /usr/bin/sed --follow-symlinks s/// /dev/null
01:07:55 1000 sh 2109661 4089 0 /bin/sh -c byobu-status tmux_right
逆にプロセスの終了を検知したい場合はexitsnoopやkillsnoopが使えます。
もうひとつよく使う可能性があるのがopen()
システムコールを検知する、opensnoopでしょう。ただしLinuxシステムではいろいろなプロセスがいろいろなファイルを開きながら動いているため、単に出力すると膨大なログになってしまいます。適宜PIDやプロセス名でフィルタリングすると良いでしょう。
$ sudo opensnoop-bpfcc -U -u 1000
UID PID COMM FD ERR PATH
1000 572612 chrome 179 0 /dev/shm/.com.google.Chrome.jX9pnM
1000 4089 tmux: server 19 0 /proc/2113318/cmdline
1000 3449 gnome-shell 91 0 /proc/self/stat
1000 3694 multipass.gui 20 0 /home/shibata/snap/multipass/5309/config/multipass/multipass.conf
1000 3694 multipass.gui 20 0 /home/shibata/snap/multipass/5309/config/multipass/multipass.conf
他にもbiosnoopやdcsnoopはブロックデバイスのI/Oやキャッシュイベントを監視できますし、カーネルのレイヤーに合わせていくつかのsnoop系ツールが用意されています。
定期的に描画を更新するtop系ツール
snoopが発生したイベントをそのままシーケンシャルに表示し続けるのに対して、topコマンドのように整形した上で表示したり、画面内の表示を更新するツールは「なんとかtop」という名前がつけられています。
biotop:ブロックI/Oのイベントを表示
filetop:ファイルのI/Oとそれを行うプロセスを表示
dirtop:特定のディレクトリ以下のI/Oを表示
cachetop:ページキャッシュのヒット/ミスなど統計情報を表示
slabratetop:Kernelのメモリアロケーションの情報を表示
netqtop:指定したNICのキューの情報を表示
tcptop:プロセスごとのTCPの送受信のスループットを表示
期間中に取得した情報の統計を表示するdist系ツール
perfコマンドのように一定期間情報を取得し、期間終了時にヒストグラムのように統計を図として表示するツールは「なんとかdist」という名前がつけられています。
argdist:指定した関数の呼び出しとその引数に応じたヒストグラムの表示
cpudist:タスクごとにCPUがオンになった期間に応じたヒストグラムの表示
ext4dist/btrfsdist/nfsdis/xfsdist/zfsdist:ファイルシステムのレイテンシーのヒストグラムの表示
たとえばkmalloc()
に渡されたサイズごとのヒストグラムは次のように表示します。これは「argdist --help
」に載っている例です。
$ sudo argdist-bpfcc -H 'p::__kmalloc(u64 size):u64:size'
[02:08:08]
size : count distribution
0 -> 1 : 0 | |
2 -> 3 : 0 | |
4 -> 7 : 0 | |
8 -> 15 : 74 |*********** |
16 -> 31 : 30 |**** |
32 -> 63 : 65 |********** |
64 -> 127 : 13 |** |
128 -> 255 : 88 |************* |
256 -> 511 : 260 |****************************************|
512 -> 1023 : 57 |******** |
1024 -> 2047 : 3 | |
ext4distなどのファイルシステム系のツールは操作ごとに整形して表示してくれます。
$ sudo ext4dist-bpfcc
operation = open
usecs : count distribution
0 -> 1 : 2038 |****************************************|
2 -> 3 : 95 |* |
4 -> 7 : 30 | |
8 -> 15 : 1 | |
16 -> 31 : 1 | |
operation = fsync
usecs : count distribution
0 -> 1 : 0 | |
2 -> 3 : 0 | |
4 -> 7 : 0 | |
8 -> 15 : 0 | |
16 -> 31 : 0 | |
32 -> 63 : 0 | |
64 -> 127 : 0 | |
128 -> 255 : 0 | |
256 -> 511 : 0 | |
512 -> 1023 : 1 |****************************************|
1024 -> 2047 : 1 |****************************************|
2048 -> 4095 : 0 | |
4096 -> 8191 : 0 | |
8192 -> 16383 : 1 |****************************************|
operation = write
usecs : count distribution
0 -> 1 : 0 | |
2 -> 3 : 282 |************************ |
4 -> 7 : 463 |****************************************|
8 -> 15 : 27 |** |
16 -> 31 : 14 |* |
32 -> 63 : 37 |*** |
64 -> 127 : 9 | |
128 -> 255 : 0 | |
256 -> 511 : 0 | |
512 -> 1023 : 0 | |
1024 -> 2047 : 0 | |
2048 -> 4095 : 0 | |
4096 -> 8191 : 0 | |
8192 -> 16383 : 0 | |
16384 -> 32767 : 0 | |
32768 -> 65535 : 1 | |
operation = read
usecs : count distribution
0 -> 1 : 3714 |****************************************|
2 -> 3 : 170 |* |
4 -> 7 : 32 | |
8 -> 15 : 9 | |
16 -> 31 : 5 | |
またfilelatencyやbiolatencyのように、レイテンシーをヒストグラム表示するツールも存在します。
時間がかかっている処理だけを見つけるslower系ツール
特定のしきい値よりも時間のかかっている処理を見つけるためのツールは「なんとかslower」という名前が付いています。
こちらはdistのようにファイルシステムだけでなく、mysqld_qslower
やdbslower
のように、データベース向けのツールも用意されているのが特徴です。
特にfuncslowerはカーネル上の特定の関数で時間がかかっているものを見つける際に、役に立ちます。
特定の言語に特化したツール
uflowやucallsなど、「 uなんとか」なツールは特定の高級言語向けのトレーシングに特化した機能を備えています。
たとえばuflowは言語ごとのメソッド呼び出しのトレースを表示してくれます。
$ sudo uflow -l python 2168801
CPU PID TID TIME(us) METHOD
1 2168801 2168801 18.819 <- /usr/lib/python3/dist-packages/dbus/connection.py.msg_reply_handler
1 2168801 2168801 18.820 -> /usr/lib/python3/dist-packages/dbus/connection.py.msg_reply_handler
1 2168801 2168801 18.820 -> /usr/lib/python3/dist-packages/dbus/proxies.py._introspect_reply_handler
1 2168801 2168801 18.820 -> /usr/lib/python3/dist-packages/dbus/_expat_introspect_parser.py.process_introspection_data
1 2168801 2168801 18.820 -> /usr/lib/python3/dist-packages/dbus/_expat_introspect_parser.py.__init__
1 2168801 2168801 18.820 <- /usr/lib/python3/dist-packages/dbus/_expat_introspect_parser.py.__init__
1 2168801 2168801 18.820 -> /usr/lib/python3/dist-packages/dbus/_expat_introspect_parser.py.parse
それに対してucallsは一定期間内におけるメソッドの呼び出し回数をまとめてくれます。
$ sudo ucalls -l python 2168801
METHOD # CALLS
/usr/lib/python3/dist-packages/UpdateManager/UpdatesAvailable.py.get_restart_icon 1
/usr/lib/python3/dist-packages/UpdateManager/Dialogs.py.on_settings_button_clicked 1
/usr/lib/python3/dist-packages/UpdateManager/Core/UpdateList.py._init_deps 1
/usr/lib/python3.9/re.py.compile 1
「-l
」に渡せるオプションはjava、perl、php、python、ruby、tcl、noneとなります。「 none」の場合、単にシステムコールを対象とするだけです。
ちなみに「pythoncalls」コマンドは「ucall -l python」を呼び出すだけとなっています。
その他のツール
ここまでは比較的同じ系統としてまとまっていそうなものを紹介してきましたが、正直な話、ここでは紹介しきれないツールがたくさん存在します。
たとえばネットワーク系は「tcpなんとか」という形でまとまっているものもあります。tcpconnectやtcpacceptはそのままconnect()
やaccept()
を検知しますし、tcpconnlatでconnect()
で時間がかかっているものを調べられます。tcplifeはTCPセッションの時間と送受信バイトを表示してくれます。セッションの状態遷移を表示してくれるtcpstatesなんてコマンドもあります。何ができるのかを把握するためにも、一通り試してみると良いでしょう。
$ sudo tcpstates-bpfcc
SKADDR C-PID C-COMM LADDR LPORT RADDR RPORT OLDSTATE -> NEWSTATE MS
ffff8c62d94d2bc0 0 swapper/7 192.168.0.59 39242 162.213.33.6 443 ESTABLISHED -> CLOSE_WAIT 0.000
ffff8c62d94d2bc0 1711445 Socket Thr 192.168.0.59 39242 162.213.33.6 443 CLOSE_WAIT -> LAST_ACK 0.086
ffff8c62d94d2bc0 56 ksoftirqd/ 192.168.0.59 39242 162.213.33.6 443 LAST_ACK -> CLOSE 234.077
memleakやoomkill、deadlockなどは問題の解析に役立つはずです。また従来perfが行っていた機能としては、funccountやprofileなどが用意されています。さらにtraceコマンドは、snoop系のコマンドのようなことをより細かな制御で実行できます。
ほとんどのコマンドが「--help
」オプションによって、より詳細な説明や実践的な例を表示してくれます。まずは気になるコマンドを見つけて、実際に試してみると良いでしょう。