LinuxのBPF : (5) eBPFによるLinux Kernel Tracing

eBPFによるカーネルトレース

一番最初に書いた通り,eBPFはLinuxのトレーサとして利用できます.

カーネルがeBPFプログラムを実行する場合,BPFインタプリタctxが渡されます(jit化されている場合も同様です).

https://github.com/torvalds/linux/blob/v4.12/kernel/bpf/core.c#L766

/* Named registers */
...
#define ARG1   regs[BPF_REG_ARG1]   // これは BPF_REG_R1
...

static unsigned int __bpf_prog_run(void *ctx, const struct bpf_insn *insn)
{
    ...
    ARG1 = (u64) (unsigned long) ctx;
    ...
    // インタプリタによる処理の実行

このctxはeBPFプログラムをどこにアタッチするかで異なります. BPFでパケットフィルタリングをする際は,パケットの受信or送信のタイミングでctxとしてskbuffのポインタが渡されてeBPFプログラムが実行されていました.

この構造を応用して,カーネル内の様々なイベントに対して,ユーザが作成したeBPFプログラムを適当なctxの下で実行することでトレースを実現します.

eBPF Program Type

eBPFプログラムの種類は,eBPF Program Typeで区別されます.このProgram TypeはbpfシステムコールでeBPFプログラムをロードする際に指定します.

Linux 4.12時点では以下のようなProgram Typeが存在します.

https://github.com/torvalds/linux/blob/v4.12/include/trace/events/bpf.h#L12

#define __PROG_TYPE_MAP(FN) \
   FN(SOCKET_FILTER)   \
   FN(KPROBE)      \
   FN(SCHED_CLS)       \
   FN(SCHED_ACT)       \
   FN(TRACEPOINT)      \
   FN(XDP)         \
   FN(PERF_EVENT)      \
   FN(CGROUP_SKB)      \
   FN(CGROUP_SOCK)     \
   FN(LWT_IN)      \
   FN(LWT_OUT)     \
   FN(LWT_XMIT)

今までSOCKET_FILTERとしてのeBPFをずっと見てきた訳ですが,実際にはこれだけの種類があります. どの用途としてeBPFプログラムを作成するかによって,eBPFプログラムの引数や,eBPFプログラムの戻り値の意味,eBPFプログラムから呼ぶことが可能なカーネル内の関数,さらにはeBPFプログラム作成のために使えるライブラリの種類も変わってきます.

特にカーネルトレース機能としてのeBPFを考える場合,kprobe, tracepoint, perf_event あたりが重要になります. kprobeやperfは元々eBPF以前からカーネルに存在したトレーシング機能ですが,それらの様々なフックポイントに対してeBPFプログラムがアタッチできるようになっています.

ちなみに,カーネルのどのバージョンでBPFのどの機能がサポートされているかというのは,以下のbccの資料がまとまっています. https://github.com/iovisor/bcc/blob/master/docs/kernel-versions.md

bccのトレースツール群

前回簡単に説明したbccには様々なトレーシングツールがデフォルトで含まれています

これらのツールで何がトレースできるのかというのは,以下のbccの図にまとまっています.

f:id:mm_i:20170904231602p:plain

公式のチュートリアルに一部のみですが機能の説明があります. おそらく,今後もツール群は増えていくものと思われます.

bccでkprobeを利用したトレースの例

bccでトレースプログラムを書く際は,以下の資料が参考になります.

実際にトレースプログラムを書く際は,bccのツール群の中で自分の目的にもっとも近いものを参考にするのがいいかと思います.

例えば,uprobeを利用してあるPIDのプロセスを監視し,strlen()を呼び出したときの文字列を表示するプログラムは以下のようになります.

https://github.com/iovisor/bcc/blob/master/examples/tracing/strlen_snoop.py

#!/usr/bin/python
#
# strlen_snoop  Trace strlen() library function for a given PID.
#               For Linux, uses BCC, eBPF. Embedded C.
#
# USAGE: strlensnoop PID
#
# Try running this on a separate bash shell.
#
# Written as a basic example of BCC and uprobes.
#
# Copyright 2016 Netflix, Inc.
# Licensed under the Apache License, Version 2.0 (the "License")

from __future__ import print_function
from bcc import BPF
from os import getpid
import sys

if len(sys.argv) < 2:
    print("USAGE: strlensnoop PID")
    exit()
pid = sys.argv[1]

# load BPF program
bpf_text = """
#include <uapi/linux/ptrace.h>
int printarg(struct pt_regs *ctx) {
    if (!PT_REGS_PARM1(ctx))
        return 0;
    u32 pid = bpf_get_current_pid_tgid();
    if (pid != PID)
        return 0;
    char str[80] = {};
    bpf_probe_read(&str, sizeof(str), (void *)PT_REGS_PARM1(ctx));
    bpf_trace_printk("%s\\n", &str);
    return 0;
};
"""
bpf_text = bpf_text.replace('PID', pid)
b = BPF(text=bpf_text)
b.attach_uprobe(name="c", sym="strlen", fn_name="printarg")

# header
print("%-18s %-16s %-6s %s" % ("TIME(s)", "COMM", "PID", "STRLEN"))

# format output
me = getpid()
while 1:
    try:
        (task, pid, cpu, flags, ts, msg) = b.trace_fields()
    except ValueError:
        continue
    if pid == me or msg == "":
        continue
    print("%-18.9f %-16s %-6d %s" % (ts, task, pid, msg))

b.attach_uprobe(name="c", sym="strlen", fn_name="printarg")strlen()が呼ばれたときにprintarg()を実行するようになります.uprobeのctxから関数の引数にアクセスすることができます.printarg()の中でbpf_probe_read()を使ってstrlenの引数の文字列をスタックにコピーし,bpf_trace_printk()を使ってそれを/sys/kernel/debug/tracing/trace_pipe出力します.ユーザランドのプログラム側でtrace_fields()をすることによってそれを読み出して出力しています(ここではconcurrentな利用は考えてないです).簡単ですね.bccで使える関数の詳細はreference guideをみてください.

他にも,kprobeを利用してblock deviceのI/Oのトレースするプログラムは以下のようになっています.

https://github.com/iovisor/bcc/blob/master/examples/tracing/disksnoop.py

b = BPF(text="""
#include <uapi/linux/ptrace.h>
#include <linux/blkdev.h>
BPF_HASH(start, struct request *);
void trace_start(struct pt_regs *ctx, struct request *req) {
  // stash start timestamp by request ptr
  u64 ts = bpf_ktime_get_ns();
  start.update(&req, &ts);
}
void trace_completion(struct pt_regs *ctx, struct request *req) {
  u64 *tsp, delta;
  tsp = start.lookup(&req);
  if (tsp != 0) {
      delta = bpf_ktime_get_ns() - *tsp;
      bpf_trace_printk("%d %x %d\\n", req->__data_len,
          req->cmd_flags, delta / 1000);
      start.delete(&req);
  }
}
""")

b.attach_kprobe(event="blk_start_request", fn_name="trace_start")
b.attach_kprobe(event="blk_mq_start_request", fn_name="trace_start")
b.attach_kprobe(event="blk_account_io_completion", fn_name="trace_completion")

ここではeBPF mapを利用して,block deviceの開始したときに開始時刻を保存,終了時にそれを読み出して出力しています.

他にもいろんなことができるので,いろいろと遊んでみると楽しいと思います.

ちなみにbccでプログラムを書く際は

  • bccはプログラムをeBPFにコンパイルする前に clang/llvm の力によってプログラムを書き換えて正しいeBPFプログラムになるようにしている

という点を知っておくといろいろと納得しやすいと思います.何故bccのプログラムで正しいeBPFプログラムが出力されるのかを追いかけると深みにはまります.