SIer だけど技術やりたいブログ

Kprobes の概要と使い方

linux

Kprobes とは

Kprobes は実行中のカーネルに処理を差し込むための仕組み。おもにカーネルのデバッグやパフォーマンス解析に利用される。カーネル内のデータをいじれるため、テストのために障害注入するという使い方もできる。Kprobes を直接利用することは少ないが、SystemTap や bpftrace などのトレーシングツールの内部で利用されているので、知らず知らず使っている人も多いはず。自分はカーネルのコードリーディング中に、この関数ってどういうデータが来るの？とかコールスタックは？というのを眺めるために使うことが多い。

細かくいうと任意のアドレスに処理を差し込むものを kprobe 、関数の実行後に処理を差し込むものを kretprobe という。

検証環境

CentOS 8 を利用する。

]# cat /etc/redhat-release
CentOS Linux release 8.1.1911 (Core)
]# uname -a
Linux localhost.localdomain 4.18.0-147.3.1.el8_1.x86_64 #1 SMP Fri Jan 3 23:55:26 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux

使い方

register_kprobe

register_kprobe を利用すると kprobe が利用できる。カーネル関数のため、直接呼び出すにはカーネルモジュールを作成する必要がある。利用方法は、カーネルのサンプルコード(samples/kprobes/kprobe_example.c)が参考になる。

今回はファイルをオープンする openat システムコールが内部で利用している long do_sys_open(int dfd, const char __user *filename, int flags, umode_t mode) 関数をフックして、ファイルがオープンされる様子をトレーシングする。

hello-kprobe-world.c

#include <linux/module.h>
#include <linux/ptrace.h>
#include <linux/kprobes.h>

MODULE_AUTHOR("john doe");
MODULE_LICENSE("GPL v2");

// ファイル名を表示する
static int handler_pre (struct kprobe *p, struct pt_regs *regs) {
        pr_info("<%s> pre_handler: filename = %s \n",
                        p->symbol_name, (const char *)regs->si);
        return 0;
}

static void handler_post (struct kprobe *p, struct pt_regs *regs, unsigned long flags) {
        pr_info("<%s> post_handler\n", p->symbol_name);
}

static struct kprobe kp = {
        .symbol_name    = "do_sys_open",
        .pre_handler = handler_pre,
        .post_handler = handler_post
};

static int __init kprobe_init(void) {
        int ret = register_kprobe(&kp);
        if (ret < 0) {
                pr_err("register_kprobe failed, returned %d\n", ret);
                return ret;
        }
        return 0;
}

static void __exit kprobe_exit(void) {
        unregister_kprobe(&kp);
}

module_init(kprobe_init);
module_exit(kprobe_exit);

上記を見てわかるとおり、struct pt_regs という構造体に引数などの情報が詰め込まれている。これらの操作には CPU アーキテクチャごとのレジスタ操作の知識が必要になる。x86_64 は arch/x86/entry/entry_64.S に次のように書かれている。今回は第二引数の filename を取り出したいので、 rsi を利用した。

* Registers on entry:
* rax  system call number
* rcx  return address
* r11  saved rflags (note: r11 is callee-clobbered register in C ABI)
* rdi  arg0
* rsi  arg1
* rdx  arg2
* r10  arg3 (needs to be moved to rcx to conform to C ABI)
* r8   arg4
* r9   arg5
* (note: r12-r15, rbp, rbx are callee-preserved in C ABI)
*
* Only called from user space.

このソースコードをビルドし、カーネルモジュール(ko ファイル)を作成する。

]# cat Makefile
obj-m := hello-kprobe-world.o
KDIR    := /lib/modules/$(shell uname -r)/build
VERBOSE = 0

all:
        $(MAKE) -C $(KDIR) M=$(PWD) KBUILD_VERBOSE=$(VERBOSE) CONFIG_DEBUG_INFO=y modules
clean:
        rm -f *.o *.ko *.mod.c Module.symvers modules.order

]# make
make -C /lib/modules/4.18.0-147.3.1.el8_1.x86_64/build M=/root/work/kprobe KBUILD_VERBOSE=0 CONFIG_DEBUG_INFO=y modules
make[1]: ディレクトリ '/usr/src/kernels/4.18.0-147.3.1.el8_1.x86_64' に入ります
  Building modules, stage 2.
  MODPOST 1 modules
make[1]: ディレクトリ '/usr/src/kernels/4.18.0-147.3.1.el8_1.x86_64' から出ます

作成したカーネルモジュール(ko ファイル)をインストールし dmesg でメッセージを確認すると、トレーシングできているのがわかる。

]# insmod hello-kprobe-world.ko
]# rmmod hello-kprobe-world
]# dmesg
...
[395833.414541] <do_sys_open> pre_handler: filename = /proc/cmdline
[395833.414541] <do_sys_open> post_handler
[395833.414565] <do_sys_open> pre_handler: filename = /lib/modules/4.18.0-147.3.1.el8_1.x86_64/modules.builtin.bin
[395833.414565] <do_sys_open> post_handler
[395833.414579] <do_sys_open> pre_handler: filename = /sys/module/hello_kprobe_world/initstate
[395833.414580] <do_sys_open> post_handler
[395833.414685] <do_sys_open> pre_handler: filename = /sys/module/hello_kprobe_world/holders
[395833.414685] <do_sys_open> post_handler
[395833.414696] <do_sys_open> pre_handler: filename = /sys/module/hello_kprobe_world/refcnt
[395833.414697] <do_sys_open> post_handler

register_kretprobe

さきほどの register_kprobe の kretprobe 版。利用方法は、カーネルのサンプルコード(samples/kprobes/kretprobe_example.c)が参考になる。

今回はプロセスを生成する fork システムコールが内部で利用している long _do_fork(unsigned long clone_flags, unsigned long stack_start, unsigned long stack_size, int __user *parent_tidptr, int __user *child_tidptr, unsigned long tls) 関数をフックして、実行にかかった時間をトレーシングする。

hello-kprobe-world.c

#include <linux/module.h>
#include <linux/ptrace.h>
#include <linux/kprobes.h>

#include <linux/ktime.h>
#include <linux/limits.h>
#include <linux/sched.h>

MODULE_AUTHOR("john doe");
MODULE_LICENSE("GPL v2");

static int entry_handler(struct kretprobe_instance *ri, struct pt_regs *regs);
static int ret_handler(struct kretprobe_instance *ri, struct pt_regs *regs);

struct my_data {
        ktime_t entry_stamp;
};

static struct kretprobe kretp = {
        .kp = {
                .symbol_name    = "_do_fork",
        },
        .handler = entry_handler,
        .entry_handler = ret_handler,
        .data_size              = sizeof(struct my_data),
        .maxactive              = 20,
};

// 関数実行前の時間を記録する
static int entry_handler(struct kretprobe_instance *ri, struct pt_regs *regs)
{
        struct my_data *data;

        if (!current->mm)
                return 1;       /* Skip kernel threads */

        data = (struct my_data *)ri->data;
        data->entry_stamp = ktime_get();
        return 0;
}

// 関数実行後の時間を記録する
static int ret_handler(struct kretprobe_instance *ri, struct pt_regs *regs)
{
        struct my_data *data = (struct my_data *)ri->data;
        s64 delta;
        ktime_t now;

        now = ktime_get();
        delta = ktime_to_ns(ktime_sub(now, data->entry_stamp));
        pr_info("%s returned %lu and took %lld ns to execute\n",
                        kretp.kp.symbol_name, regs_return_value(regs), (long long)delta);
        return 0;
}

static int __init kretprobe_init(void) {
        int ret = register_kretprobe(&kretp);
        if (ret < 0) {
                pr_err("register_kprobe failed, returned %d\n", ret);
                return ret;
        }
        return 0;
}

static void __exit kretprobe_exit(void) {
        unregister_kretprobe(&kretp);
}

module_init(kretprobe_init);
module_exit(kretprobe_exit);

このソースコードをビルドし、カーネルモジュール(ko ファイル)を作成する。

]# cat Makefile
obj-m := hello-kprobe-world.o
KDIR    := /lib/modules/$(shell uname -r)/build
VERBOSE = 0

all:
        $(MAKE) -C $(KDIR) M=$(PWD) KBUILD_VERBOSE=$(VERBOSE) CONFIG_DEBUG_INFO=y modules
clean:
        rm -f *.o *.ko *.mod.c Module.symvers modules.order

]# make
make -C /lib/modules/4.18.0-147.3.1.el8_1.x86_64/build M=/root/work/kprobe KBUILD_VERBOSE=0 CONFIG_DEBUG_INFO=y modules
make[1]: ディレクトリ '/usr/src/kernels/4.18.0-147.3.1.el8_1.x86_64' に入ります
  CC [M]  /root/work/kprobe/hello-kprobe-world.o
  Building modules, stage 2.
  MODPOST 1 modules
  CC      /root/work/kprobe/hello-kprobe-world.mod.o
  LD [M]  /root/work/kprobe/hello-kprobe-world.ko
make[1]: ディレクトリ '/usr/src/kernels/4.18.0-147.3.1.el8_1.x86_64' から出ます

作成したカーネルモジュール(ko ファイル)をインストールし dmesg でメッセージを確認すると、実行時間がトレーシングできているのがわかる。

]# insmod hello-kprobe-world.ko
]# dmesg
...
[24791.633661] _do_fork returned 18446651783515783000 and took 665684100 ns to execute
[24793.290221] _do_fork returned 18446651783515783000 and took 1656292100 ns to execute

kprobe_events

kprobe_events は、カーネルモジュールを作成せずに kprobe を利用できる仕組み。Ftrace と同じインタフェースで probe を動的に作成できる。

]# echo 'p:myprobe do_sys_open arg1=+0(%si):string'  > /sys/kernel/debug/tracing/kprobe_events
]# ls /sys/kernel/debug/tracing/events/kprobes/myprobe
enable  filter  format  hist  id  trigger

]# echo 1 > /sys/kernel/debug/tracing/events/kprobes/myprobe/enable
]# cat /sys/kernel/debug/tracing/trace
...
           <...>-25677 [000] .... 76386.999348: myprobe: (do_sys_open+0x0/0x220) arg1="/etc/ld.so.cache"
           <...>-25677 [000] .... 76386.999390: myprobe: (do_sys_open+0x0/0x220) arg1="/lib64/libc.so.6"
           <...>-25677 [000] .... 76386.999982: myprobe: (do_sys_open+0x0/0x220) arg1="/usr/lib/locale/locale-archive"
           <...>-25677 [000] .... 76387.000040: myprobe: (do_sys_open+0x0/0x220) arg1="/usr/share/locale/locale.alias"
           <...>-25677 [000] .... 76387.000152: myprobe: (do_sys_open+0x0/0x220) arg1="/usr/lib/locale/ja_JP.UTF-8/LC_IDENTIFICAT

削除するには -:<id> を書き込む。

]# echo 0 > /sys/kernel/debug/tracing/events/kprobes/myprobe/enable
]# echo -:myprobe >> /sys/kernel/debug/tracing/kprobe_events

詳細は Documentation/trace/kprobetrace.rst が参考になる。

perf_event_open

perf_event_open システムコールで、BPF プログラムを kprobe のイベントにアタッチできる。BPF プログラムを直接書くのはつらいので bpftrace 経由で利用する。

 bpftrace -e 'kprobe:do_sys_open {printf("%s\n", str(arg1)); exit(); }'
Attaching 1 probe...
/etc/ld.so.cache

perf_event_open が利用されている様子も確認する。

]# strace -e 'bpf,perf_event_open' bpftrace -e 'kprobe:do_sys_open {printf("%s\n", str(arg1)); exit(); }'
bpf(BPF_MAP_CREATE, {map_type=BPF_MAP_TYPE_PERF_EVENT_ARRAY, key_size=4, value_size=4, max_entries=1, map_flags=0, inner_map_fd=0, map_name="printf", map_ifindex=0}, 112) = 3
Attaching 1 probe...
perf_event_open({type=PERF_TYPE_SOFTWARE, size=0 /* PERF_ATTR_SIZE_??? */, config=PERF_COUNT_SW_BPF_OUTPUT, ...}, -1, 0, -1, PERF_FLAG_FD_CLOEXEC) = 5
bpf(BPF_MAP_UPDATE_ELEM, {map_fd=3, key=0x7fffb6cf2f8c, value=0x7fffb6cf2f90, flags=BPF_ANY}, 112) = 0
bpf(BPF_PROG_LOAD, {prog_type=BPF_PROG_TYPE_KPROBE, insn_cnt=70, insns=0x7fcf644d4000, license="GPL", log_level=0, log_size=0, log_buf=NULL, kern_version=KERNEL_VERSION(4, 18, 0), prog_flags=0, prog_name="do_sys_open", prog_ifindex=0, expected_attach_type=BPF_CGROUP_INET_INGRESS}, 112) = 7
perf_event_open({type=0x6 /* PERF_TYPE_??? */, size=PERF_ATTR_SIZE_VER5, config=0, ...}, -1, 0, -1, PERF_FLAG_FD_CLOEXEC) = 6
/sys/fs/cgroup/systemd/system.slice/sysstat-collect.service/cgr
+++ exited with 0 +++

詳細は bpftraceが参考になる。

https://github.com/iovisor/bpftrace/raw/master/images/bpftrace_internals_2018.png

ユーザ空間のツール

上記のようにカーネルモジュールを作成したりシステムコールを直接呼び出すほかに、ユーザ空間のツールを使う方法がある。むしろこれが一般的な使い方。

SystemTap

SystemTap は、D 言語に似たスクリプトからカーネルモジュールを作成してトレーシングするツール。これは register_kprobe/register_kretprobe を利用する。

]# stap -v -e 'probe kernel.function("do_sys_open") { println($filename$); exit(); }'
// 1. スクリプトの読み込み
// 2. スクリプトの妥当性の検証
// 3. C 言語のソースコードを作成
// 4. カーネルモジュールの作成
// 5. 実行
Pass 1: parsed user script and 484 library scripts using 186644virt/79808res/9024shr/70372data kb, in 150usr/20sys/163real ms.
Pass 2: analyzed script: 1 probe, 4 functions, 0 embeds, 0 globals using 240868virt/134720res/9924shr/124596data kb, in 740usr/60sys/812real ms.
Pass 3: translated to C into "/tmp/stapPZf5gB/stap_ee251210e76f478b13ba761f29dbb120_1861_src.c" using 240868virt/134912res/10116shr/124596data kb, in 10usr/50sys/62real ms.
Pass 4: compiled C into "stap_ee251210e76f478b13ba761f29dbb120_1861.ko" in 1750usr/490sys/2274real ms.
Pass 5: starting run.
"/var/log/journal/0f79fa0f28464df5aa110f42b3136dc1/system.journal"
Pass 5: run completed in 10usr/20sys/305real ms.

perf

イベントを記録して可視化するツール群。Tracepoints や PMU などの静的なイベントのほかに、kprobe を用いて動的にイベントを追加できる。内部で kprobe_events を利用する。

]# perf probe "do_sys_open filename:string"
Added new event:
  probe:do_sys_open    (on do_sys_open with filename:string)

You can now use it in all perf tools, such as:

        perf record -e probe:do_sys_open -aR sleep 1

]# perf record -e probe:do_sys_open -aR sleep 1
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.280 MB perf.data (31 samples) ]
]# perf script
            perf 26258 [000] 80143.523490: probe:do_sys_open: (ffffffffbc4b6040) filename_string="/proc/26259/status"
           sleep 26259 [000] 80143.523785: probe:do_sys_open: (ffffffffbc4b6040) filename_string="/etc/ld.so.cache"
           sleep 26259 [000] 80143.523795: probe:do_sys_open: (ffffffffbc4b6040) filename_string="/lib64/libc.so.6"
           sleep 26259 [000] 80143.523947: probe:do_sys_open: (ffffffffbc4b6040) filename_string=""
           sleep 26259 [000] 80143.523957: probe:do_sys_open: (ffffffffbc4b6040) filename_string="/usr/share/locale/locale.alias"
           sleep 26259 [000] 80143.523981: probe:do_sys_open: (ffffffffbc4b6040) filename_string="/usr/lib/locale/ja_JP.UTF-8/LC_IDENTIFICATION"
           sleep 26259 [000] 80143.523983: probe:do_sys_open: (ffffffffbc4b6040) filename_string="/usr/lib/locale/ja_JP.utf8/LC_IDENTIFICATION"
           sleep 26259 [000] 80143.523991: probe:do_sys_open: (ffffffffbc4b6040) filename_string="/usr/lib64/gconv/gconv-modules.cache"
           sleep 26259 [000] 80143.524020: probe:do_sys_open: (ffffffffbc4b6040) filename_string="/usr/lib/locale/ja_JP.UTF-8/LC_MEASUREMENT"
           sleep 26259 [000] 80143.524022: probe:do_sys_open: (ffffffffbc4b6040) filename_string="/usr/lib/locale/ja_JP.utf8/LC_MEASUREMENT"

削除するときは -d オプションを利用する。

]# perf probe -d '*'
Removed event: probe:do_sys_open

詳細は perf probe の man が参考になる。

bpftrace

bpftrace は、 DTrace に似たスクリプトをもとにトレーシングするツール。これは register_kprobe/register_kretprobe ではなく perf_event_open を利用する。kprobe に限らず uprobe や usdt や perf_event など、様々な箇所にフックできて多機能。

]# bpftrace -e 'kprobe:do_sys_open { printf("%s\n", str(arg1)); exit();}'
Attaching 1 probe...
/etc/ld.so.cache

kprobe の内部動作

実行中のカーネル自身のプログラムを置き換えることで実現する(x86_64 だと text_poke)。すごい。

  1. 指定した位置に Breakpoint 命令を設定する(x86 なら int3 命令)
  2. Breakpoint 命令が実行されると例外が発生する
  3. 例外ハンドラがレジスタを pt_regs に保存する
  4. 例外ハンドラが pre_handler を実行する
  5. シングルステップ実行で指定した位置を実行する
  6. デバッグ例外が発生する
  7. 例外ハンドラが post_handler を実行する

詳細はDocumentation/kprobes.txt が参考になる。

kretprobe の内部動作

kretprobe は関数の戻りアドレスを書き換えることで実現する。(したがって関数にしか指定できない)

  1. 関数の戻りアドレスを書き換えて trampoline コードを埋め込む
  2. 指定した位置の命令を実行する
  3. trampoline コードが実行される
  4. trampoline コードの戻りアドレスを関数の戻りアドレスにする

詳細はDocumentation/kprobes.txt が参考になる。

最適化

あんまり理解できてない。詳細はDocumentation/kprobes.txt にいろいろ書いてあった。

blacklist

Kprobes はどこにでも処理を差し込めるわけではなく、実装上の都合で(致命的に壊れる状態を防ぐため。ダブルフォールトとか。)禁止区間がある。そういうものに対して kprobe を利用するとエラーになる。たとえば SystemTap の例は次のようになる。

]# stap -e 'probe kernel.function("do_int3") { exit(); }'
WARNING: function do_int3 is blacklisted: keyword at <input>:1:1
 source: probe kernel.function("do_int3") { exit(); }
         ^
semantic error: while resolving probe point: identifier 'kernel' at :1:7
        source: probe kernel.function("do_int3") { exit(); }
                      ^

semantic error: no match (similar functions: do_int3, dio_init, do_fcntl, do_idle, do_ioctl)

Pass 2: analysis failed.  [man error::pass2]
Number of similar warning messages suppressed: 1.
Rerun with -v to see them.

禁止区間は /sys/kernel/debug/kprobes/blacklist に記録されている。

]# cat /sys/kernel/debug/kprobes/blacklist
0xffffffff96a060a0-0xffffffff96a060f0   perf_event_nmi_handler
0xffffffff96a0a2e0-0xffffffff96a0a340   perf_ibs_nmi_handler
0xffffffff96a1d5a0-0xffffffff96a1d600   do_device_not_available
0xffffffff96a1d770-0xffffffff96a1d980   do_debug
0xffffffff96a1d550-0xffffffff96a1d5a0   fixup_bad_iret
0xffffffff96a1d520-0xffffffff96a1d550   sync_regs
0xffffffff96a1dca0-0xffffffff96a1ddb0   do_int3
0xffffffff96a1db70-0xffffffff96a1dca0   do_general_protectio
...

シンボル

インライン展開された関数などはシンボルが解決できないため指定できない。解決可能なシンボルは /proc/kallsyms にある。これをどのように作成しているのかは以前に調べた(linux /proc/kallsyms をコードから理解する - SIerだけど技術やりたいブログ)。

]# cat /proc/kallsyms
0000000000000000 A irq_stack_union
0000000000000000 A __per_cpu_start
0000000000004000 A cpu_debug_store
0000000000005000 A cpu_tss_rw
0000000000008000 A gdt_page
0000000000009000 A exception_stacks
000000000000e000 A entry_stack_storage
000000000000f000 A espfix_waddr
000000000000f008 A espfix_stack
000000000000f010 A cpu_llc_id

現在のプローブ

/sys/kernel/debug/kprobes/listファイルに記録されている。

]# cat  /sys/kernel/debug/kprobes/list
0000000076c68519  k  do_sys_open+0x0    [FTRACE]
00000000e6376767  k  create_trace_kprobe+0x0    [DISABLED]

最後に

Kprobes は拡張性の高い便利な仕組みだが、レジスタを操作できるので使い方を誤るとカーネルクラッシュを引き起こす危ない仕組みでもある(なお私はザコなのでこの記事中に 10 回くらいクラッシュさせました)。Documentation/kprobes.txt にも書いてあるとおり、『飲んだら乗るな、乗るなら飲むな』の精神でご利用ください。基本的にはSystemTap や bpftrace などの安全性を検証する仕組みを経由して利用するのが安全だと思います。

Kprobes, of course, has no way to distinguish the deliberately injected faults from the accidental ones. Don’t drink and probe.