BPF Tool: bpftool/bpftraceの紹介

2021.03.23

「BPF/eBPFとは？カーネルのBPFサンプルを使ってみよう」で簡単な使い方を紹介しました。

今回は、bpftoolやbpftraceというツールを紹介していきます。

bpftoolとは

bpftoolを使用すると、動作しているBPFの情報を取得できます。

デフォルトでは、オブジェクトのタイプが表示され、helpを追加するとそれぞれのオブジェクトに対するhelpページが表示されます。

# bpftool --version
bpftool v4.18.0-193.el8.x86_64

# bpftool 
Usage: bpftool [OPTIONS] OBJECT { COMMAND | help }
       bpftool batch file FILE
       bpftool version

       OBJECT := { prog | map | cgroup | perf | net | feature | btf }
       OPTIONS := { {-j|--json} [{-p|--pretty}] | {-f|--bpffs} |
	            {-m|--mapcompat} | {-n|--nomount} }

# bpftool prog help
Usage: bpftool prog { show | list } [PROG]
       bpftool prog dump xlated PROG [{ file FILE | opcodes | visual | linum }]
       bpftool prog dump jited  PROG [{ file FILE | opcodes | linum }]
       bpftool prog pin   PROG FILE
       bpftool prog { load | loadall } OBJ  PATH \
                         [type TYPE] [dev NAME] \
                         [map { idx IDX | name NAME } MAP]\
                         [pinmaps MAP_DIR]
       bpftool prog attach PROG ATTACH_TYPE [MAP]
       bpftool prog detach PROG ATTACH_TYPE [MAP]
       bpftool prog run PROG \
                         data_in FILE \
                         [data_out FILE [data_size_out L]] \
                         [ctx_in FILE [ctx_out FILE [ctx_size_out M]]] \
                         [repeat N]
       bpftool prog tracelog
       bpftool prog help

       MAP := { id MAP_ID | pinned FILE }
       PROG := { id PROG_ID | pinned FILE | tag PROG_TAG }
       TYPE := { socket | kprobe | kretprobe | classifier | action |
...

実際にサンプルを使って、どのような情報を取得できるか試してみましょう。

はじめにサンプルのhello_world.pyを実行してみます。

# git remote show origin
* remote origin
  Fetch URL: https://github.com/iovisor/bcc
  Push  URL: https://github.com/iovisor/bcc
  HEAD branch: master
...
# ./examples/hello_world.py

次に、別の端末でbpftoolを実行してみましょう。bpftraceプログラムのID4を利用して、アセンブリに変換されたBPFの命令をxlatedを使って表示させることができます。

# bpftool prog 
4: kprobe  name sys_clone  tag c514db71faba4034  gpl
	loaded_at 2021-03-23T14:35:53+0900  uid 0
	xlated 120B  jited 91B  memlock 4096B
	btf_id 4

# bpftool prog dump xlated id 4
int kprobe__sys_clone(void * ctx):
; int kprobe__sys_clone(void *ctx) {
   0: (b7) r1 = 2593
; ({ char _fmt[] = "Hello, World!\n"; bpf_trace_printk_(_fmt, sizeof(_fmt)); }); return 0; }
   1: (6b) *(u16 *)(r10 -4) = r1
   2: (b7) r1 = 1684828783
   3: (63) *(u32 *)(r10 -8) = r1
   4: (18) r1 = 0x57202c6f6c6c6548
   6: (7b) *(u64 *)(r10 -16) = r1
   7: (b7) r1 = 0
   8: (73) *(u8 *)(r10 -2) = r1
   9: (bf) r1 = r10
; 
  10: (07) r1 += -16
; ({ char _fmt[] = "Hello, World!\n"; bpf_trace_printk_(_fmt, sizeof(_fmt)); }); return 0; }
  11: (b7) r2 = 15
  12: (85) call bpf_trace_printk#-47680
; ({ char _fmt[] = "Hello, World!\n"; bpf_trace_printk_(_fmt, sizeof(_fmt)); }); return 0; }
  13: (b7) r0 = 0
  14: (95) exit

linumを追加するとソースファイルと行番号を表示することができます。

# bpftool prog dump xlated id 4 linum
int kprobe__sys_clone(void * ctx):
; int kprobe__sys_clone(void *ctx) { [file:/virtual/main.c line_num:12 line_col:0]
   0: (b7) r1 = 2593
; ({ char _fmt[] = "Hello, World!\n"; bpf_trace_printk_(_fmt, sizeof(_fmt)); }); return 0; } [file:/virtual/main.c line_num:13 line_col:10]
   1: (6b) *(u16 *)(r10 -4) = r1
   2: (b7) r1 = 1684828783
   3: (63) *(u32 *)(r10 -8) = r1
   4: (18) r1 = 0x57202c6f6c6c6548
   6: (7b) *(u64 *)(r10 -16) = r1
   7: (b7) r1 = 0
   8: (73) *(u8 *)(r10 -2) = r1
   9: (bf) r1 = r10
;  [file:/virtual/main.c line_num:0 line_col:0]
  10: (07) r1 += -16
; ({ char _fmt[] = "Hello, World!\n"; bpf_trace_printk_(_fmt, sizeof(_fmt)); }); return 0; } [file:/virtual/main.c line_num:13 line_col:38]
  11: (b7) r2 = 15
  12: (85) call bpf_trace_printk#-47680
; ({ char _fmt[] = "Hello, World!\n"; bpf_trace_printk_(_fmt, sizeof(_fmt)); }); return 0; } [file:/virtual/main.c line_num:13 line_col:81]
  13: (b7) r0 = 0
  14: (95) exit

また、visualを追加するとコントロール フロー グラフをDOT形式で出力できます。さらにDOTコマンドでpng形式に変換することによって、インストラクション フローの画像を見ることができます。

# bpftool prog dump xlated id 4 visual > hello.dot
# dot -Tpng -Elen=2.5 hello.dot -o hello.png

より複雑な例を使って、BPFインストラクション フローを視覚化するとこのようになります。

// Term 1
# ./biolatpcts.py
Block I/O latency percentile example. See tools/biolatpcts.py for the full utility.
p50=5us p75=5us p90=465us p99=535us 
p50=5us p75=5us p90=5us p99=1500us 

// Term 2
# bpftool prog
5: kprobe  name kprobe_blk_acco  tag b07846257f076ee9  gpl
	loaded_at 2021-03-24T10:48:13+0900  uid 0
	xlated 536B  jited 389B  memlock 4096B  map_ids 7,6,5
	btf_id 5
# bpftool prog dump xlated id 5 visual > biolatpcts.dot
# dot -Tpng -Elen=2.5 biolatpcts.dot -o biolatpcts.png

bpftraceとは

bpftraceはBPFのフロントエンドとして動作するトレーシングツールの1つです。特徴としては、トレーシング処理を専用の言語で記述でき、その場に応じたトレーシングが簡単にできることです。

早速、どんなことができるのかサンプルを使って見ていきましょう。その前に、ツールがインストールされていない場合は、インストールしておきましょう。

# yum install bpftrace
...
Package bpftrace-0.10.0-4.el8.x86_64 is already installed.

例えば、1秒ごとにREAD/s WRITE/s FSYNC/s OPEN/s CREATE/sのワークロードを出力するvfsstatというツールを実行したとします。

# /usr/share/bcc/tools/vfsstat
TIME         READ/s  WRITE/s  FSYNC/s   OPEN/s CREATE/s
11:28:47:        37       23        0        0        0
11:28:48:        22        8        0        0        0
11:28:49:       610     1118        0     1277        0
11:28:50:       232      393        0      481        0
11:28:51:         2        2        0        0        0
...

同時に別のターミナルで、どのプロセスがワークロードにもっとも影響を与えたのかを調べるために、bpftraceを使ってみましょう。

# date +%H:%M:%S; bpftrace -e 'kprobe:vfs_open { @[comm]= count(); }'; date +%H:%M:%S
11:28:34
Attaching 1 probe...
^C

@[sssd_kcm]: 4
@[irqbalance]: 4
@[bash]: 6
@[date]: 8
@[updatedb]: 1741

11:28:52

ここでは、意図的にワークロードを増やすために、別のターミナルで次のコマンドを実行してみました。

# date +%H:%M:%S; updatedb;date +%H:%M:%S; 
11:28:49
11:28:49

この結果からわかるように、updatedbがワークロードにもっとも影響を与え、vfs_open()を1741回実行したことが読み取れます。

コメント

タイトルとURLをコピーしました