eBPF 실전 (3) — kprobe·fentry·tracepoint·uprobe 훅 오버헤드 비교

같은 vfs_read()를 관측하더라도 BPF 프로그램을 붙일 수 있는 훅은 kprobe, fentry, tracepoint, raw tracepoint 등 여러 가지다. 훅마다 인자에 접근하는 방법, 커널 버전이 바뀔 때의 안정성, 이벤트당 비용이 다르다. 고빈도 경로에 무거운 훅을 달면 관측 도구가 곧 성능 문제의 원인이 된다.

이 글에서는 훅 종류를 정리하고, 같은 read 경로에 훅을 하나씩 붙여 이벤트당 오버헤드를 측정한다. 이어서 fentry/fexit로 파일시스템별 read 지연 히스토그램을 만들고, uprobe로 libc malloc() 크기 분포를 수집한다.

이 시리즈의 다른 글

훅 종류

훅SEC 예대상인자 접근안정성
tracepointtp/syscalls/sys_enter_read커널이 정의한 정적 이벤트이벤트 레코드 구조체ABI로 유지
BTF tracepointtp_btf/sys_enter같은 정적 이벤트(raw)타입 있는 원본 인자ABI로 유지
kprobe / kretprobekprobe/vfs_read거의 모든 커널 함수레지스터(PT_REGS_PARM1 등)함수가 바뀌면 깨짐
fentry / fexitfentry/vfs_readBTF가 있는 커널 함수(5.5+)타입 있는 인자, fexit는 반환값까지함수가 바뀌면 깨짐
uprobe / uretprobeuprobe/libc.so.6:malloc유저 공간 함수레지스터대상 바이너리에 의존

kprobe와 fentry는 모든 함수에 붙을 수 있지만 커널 내부 구현에 묶여 있고, tracepoint는 붙일 곳이 정해져 있는 대신 버전이 바뀌어도 유지된다.

같은 경로에 훅별 오버헤드 측정

/dev/zero에서 1바이트씩 200만 번 read()하면서 훅을 하나씩 붙인다. BPF 프로그램은 PID를 확인하고 전역 카운터 하나를 올리는 일만 한다.

#include "vmlinux.h"
#include <bpf/bpf_helpers.h>
#include <bpf/bpf_tracing.h>

char LICENSE[] SEC("license") = "GPL";

const volatile __u32 target_tgid = 0;
__u64 hits = 0;

static __always_inline void hit(void)
{
	if ((bpf_get_current_pid_tgid() >> 32) == target_tgid)
		__sync_fetch_and_add(&hits, 1);
}

SEC("tp/syscalls/sys_enter_read")
int on_tp(void *ctx) { hit(); return 0; }

SEC("tp_btf/sys_enter")
int BPF_PROG(on_tp_btf, struct pt_regs *regs, long id) { hit(); return 0; }

SEC("kprobe/vfs_read")
int BPF_KPROBE(on_kprobe, struct file *file) { hit(); return 0; }

SEC("kretprobe/vfs_read")
int BPF_KRETPROBE(on_kretprobe, ssize_t ret) { hit(); return 0; }

SEC("fentry/vfs_read")
int BPF_PROG(on_fentry, struct file *file) { hit(); return 0; }

SEC("fexit/vfs_read")
int BPF_PROG(on_fexit, struct file *file, char *buf, size_t count, loff_t *pos, ssize_t ret) { hit(); return 0; }

SEC("uprobe")
int BPF_UPROBE(on_uprobe) { hit(); return 0; }

SEC("uretprobe")
int BPF_URETPROBE(on_uretprobe) { hit(); return 0; }

BPF_KPROBE는 레지스터에서 인자를 꺼내 주는 매크로이고, BPF_PROG는 fentry·tp_btf가 받는 타입 있는 인자 배열을 풀어 주는 매크로다. fexit는 원래 인자 뒤에 반환값을 추가로 받는다.

#include <stdio.h>
#include <string.h>
#include <fcntl.h>
#include <time.h>
#include <unistd.h>
#include <bpf/libbpf.h>
#include "hookbench.skel.h"

#define N 2000000

__attribute__((noinline)) int work(int x)
{
	asm volatile("" ::: "memory");
	return x + 1;
}

static double now(void)
{
	struct timespec t;
	clock_gettime(CLOCK_MONOTONIC, &t);
	return t.tv_sec + t.tv_nsec / 1e9;
}

int main(int argc, char **argv)
{
	const char *hook = argc > 1 ? argv[1] : "none";
	int user = !strncmp(hook, "uprobe", 6) || !strncmp(hook, "uretprobe", 9) || !strcmp(hook, "none-user");
	struct hookbench_bpf *skel = hookbench_bpf__open();
	struct bpf_program *prog;
	char name[32], buf[1];
	int fd = open("/dev/zero", O_RDONLY), sum = 0;
	double t0, t1;

	snprintf(name, sizeof(name), "on_%s", hook);
	bpf_object__for_each_program(prog, skel->obj)	/* 고른 훅 하나만 로드 */
		bpf_program__set_autoload(prog, !strcmp(bpf_program__name(prog), name));
	skel->rodata->target_tgid = getpid();
	if (hookbench_bpf__load(skel))
		return 1;

	if (!strcmp(hook, "uprobe") || !strcmp(hook, "uretprobe")) {
		LIBBPF_OPTS(bpf_uprobe_opts, uo, .func_name = "work",
			    .retprobe = !strcmp(hook, "uretprobe"));
		prog = !strcmp(hook, "uprobe") ? skel->progs.on_uprobe : skel->progs.on_uretprobe;
		if (!bpf_program__attach_uprobe_opts(prog, 0, "/proc/self/exe", 0, &uo))
			return 1;
	} else if (hookbench_bpf__attach(skel)) {
		return 1;
	}

	t0 = now();
	for (int i = 0; i < N; i++) {
		if (user)
			sum = work(sum);
		else
			sum += read(fd, buf, 1);
	}
	t1 = now();
	printf("%-10s %7.1f ns/op  hits=%llu\n", hook, (t1 - t0) * 1e9 / N,
	       (unsigned long long)skel->bss->hits);
	hookbench_bpf__destroy(skel);
	return 0;
}

bpf_program__set_autoload()로 원하는 훅 하나만 로드한다. uprobe는 섹션 이름에 대상이 없어서 bpf_program__attach_uprobe_opts()로 자기 자신의 work() 함수에 직접 붙인다.

$ for h in none tp tp_btf kprobe kretprobe fentry fexit none-user uprobe uretprobe; do sudo ./hookbench $h; done
none         236.0 ns/op  hits=0
tp           401.8 ns/op  hits=2000000
tp_btf       332.0 ns/op  hits=2000000
kprobe       354.3 ns/op  hits=2000000
kretprobe    499.4 ns/op  hits=2000000
fentry       325.9 ns/op  hits=2000000
fexit        377.4 ns/op  hits=2000000
none-user      1.1 ns/op  hits=0
uprobe     62494.0 ns/op  hits=2000000
uretprobe  85463.9 ns/op  hits=2000000

같은 명령을 세 번 돌린 평균이다. VirtualBox VM(6 vCPU)에서 측정했으므로 절대값보다 훅 사이의 상대 차이를 보면 된다.

훅평균 ns/op훅 비용(ns)
없음259.7—
fentry318.1+58
tp_btf321.2+62
fexit356.8+97
kprobe358.5+99
tp (syscalls)399.1+139
kretprobe495.0+235
uprobe60,898+60,897
uretprobe89,579+89,578

fentry는 ftrace 자리에서 BPF 트램펄린을 바로 부르고, kprobe는 같은 자리를 쓰더라도 pt_regs를 저장하고 kprobe 핸들러를 한 단계 더 거친다. tp/syscalls/*는 시스템 콜 인자를 레코드로 채운 뒤 BPF를 부르는 perf 경로라서 raw 인자를 바로 받는 tp_btf보다 두 배 이상 비쌌다.

uprobe는 호출마다 int3 트랩으로 커널에 들어갔다 나오므로 이 VM에서 호출당 60µs(uretprobe 90µs)가 걸렸다. 절대값은 환경마다 다르지만 커널 훅과 자릿수가 다르므로, 초당 수백만 번 불리는 유저 함수에는 uprobe를 붙이지 않는다.

kprobe와 fentry의 구조체 접근 차이

kprobe가 받는 인자는 레지스터 값일 뿐이라 verifier 입장에서는 타입 없는 숫자다. 같은 file->f_inode->i_sb->s_type->name을 세 가지 방식으로 읽어 본다.

#include "vmlinux.h"
#include <bpf/bpf_helpers.h>
#include <bpf/bpf_tracing.h>
#include <bpf/bpf_core_read.h>

char LICENSE[] SEC("license") = "GPL";
char fsname[16];

#ifdef KPROBE_DIRECT
SEC("kprobe/vfs_read")
int BPF_KPROBE(kp, struct file *file)
{
	/* kprobe 인자는 타입 정보가 없는 스칼라라 직접 역참조 불가 */
	bpf_probe_read_kernel_str(fsname, sizeof(fsname), file->f_inode->i_sb->s_type->name);
	return 0;
}
#endif

#ifdef KPROBE_CORE
SEC("kprobe/vfs_read")
int BPF_KPROBE(kp, struct file *file)
{
	const char *name = BPF_CORE_READ(file, f_inode, i_sb, s_type, name);

	bpf_probe_read_kernel_str(fsname, sizeof(fsname), name);
	return 0;
}
#endif

#ifdef FENTRY_INLINED
SEC("fentry/new_sync_read")		/* 인라인돼 심볼이 없는 함수 */
int BPF_PROG(fe, struct file *filp)
{
	return 0;
}
#endif
===== KPROBE_DIRECT
0: R1=ctx() R10=fp0
; int BPF_KPROBE(kp, struct file *file)
0: (79) r1 = *(u64 *)(r1 +112)        ; R1_w=scalar()
; bpf_probe_read_kernel_str(fsname, sizeof(fsname), file->f_inode->i_sb->s_type->name);
1: (79) r1 = *(u64 *)(r1 +168)
R1 invalid mem access 'scalar'
===== KPROBE_CORE
loaded

kprobe에서는 BPF_CORE_READ()로 한 단계씩 bpf_probe_read_kernel()을 거쳐야 한다. fentry는 BTF로 인자 타입을 알고 있어서, 다음 절의 readlat처럼 포인터를 바로 따라갈 수 있다.

인라인된 함수에는 붙일 수 없다

===== FENTRY_INLINED
libbpf: prog 'fe': failed to find kernel BTF type ID of 'new_sync_read': -3
libbpf: prog 'fe': failed to prepare load attributes: -3
libbpf: prog 'fe': failed to load: -3
===== kprobe on inlined
$ echo "p:test_inl new_sync_read" >> /sys/kernel/tracing/kprobe_events
bash: line 1: echo: write error: Invalid argument

new_sync_read()는 vfs_read() 안에 인라인돼 심볼이 없다. 붙이기 전에 /proc/kallsyms와 available_filter_functions에 있는지 확인한다.

$ for f in new_sync_read rw_verify_area vfs_read ksys_read; do
    printf "%-16s kallsyms=%s ftrace=%s\n" $f $(grep -cw "$f" /proc/kallsyms) \
        $(grep -cw "^$f" /sys/kernel/tracing/available_filter_functions); done
new_sync_read    kallsyms=0 ftrace=0
rw_verify_area   kallsyms=1 ftrace=1
vfs_read         kallsyms=1 ftrace=1
ksys_read        kallsyms=1 ftrace=1

fentry/fexit로 파일시스템별 read 지연 측정

fentry에서 스레드별 진입 시각을 저장하고, fexit에서 경과 시간을 파일시스템 이름과 함께 log2 히스토그램에 넣는다.

#include "vmlinux.h"
#include <bpf/bpf_helpers.h>
#include <bpf/bpf_tracing.h>

char LICENSE[] SEC("license") = "GPL";

#define MAX_SLOTS 24

struct {
	__uint(type, BPF_MAP_TYPE_HASH);
	__uint(max_entries, 10240);
	__type(key, u32);			/* tid */
	__type(value, u64);			/* 진입 시각 */
} start SEC(".maps");

struct hist_key {
	char fs[16];
	u32 slot;
};

struct {
	__uint(type, BPF_MAP_TYPE_HASH);
	__uint(max_entries, 1024);
	__type(key, struct hist_key);
	__type(value, u64);
} hist SEC(".maps");

static __always_inline u32 log2l(u64 v)
{
	u32 r = 0;

	while (v > 1 && r < MAX_SLOTS - 1) {
		v >>= 1;
		r++;
	}
	return r;
}

SEC("fentry/vfs_read")
int BPF_PROG(read_enter, struct file *file)
{
	u32 tid = bpf_get_current_pid_tgid();
	u64 ts = bpf_ktime_get_ns();

	bpf_map_update_elem(&start, &tid, &ts, BPF_ANY);
	return 0;
}

SEC("fexit/vfs_read")
int BPF_PROG(read_exit, struct file *file, char *buf, size_t count, loff_t *pos, ssize_t ret)
{
	u32 tid = bpf_get_current_pid_tgid();
	struct hist_key key = {};
	u64 *tsp, one = 1, *cnt;

	tsp = bpf_map_lookup_elem(&start, &tid);
	if (!tsp)
		return 0;
	/* BTF 덕분에 포인터를 바로 따라간다 (bpf_probe_read 불필요) */
	bpf_probe_read_kernel_str(key.fs, sizeof(key.fs), file->f_inode->i_sb->s_type->name);
	key.slot = log2l((bpf_ktime_get_ns() - *tsp) / 1000);	/* us */
	bpf_map_delete_elem(&start, &tid);

	cnt = bpf_map_lookup_elem(&hist, &key);
	if (cnt)
		__sync_fetch_and_add(cnt, 1);
	else
		bpf_map_update_elem(&hist, &key, &one, BPF_NOEXIST);
	return 0;
}

file->f_inode->i_sb->s_type->name을 BPF_CORE_READ() 없이 바로 썼다. fentry/fexit는 BTF 타입 포인터를 verifier가 추적하므로 직접 역참조가 허용된다.

#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <unistd.h>
#include <bpf/libbpf.h>
#include "readlat.skel.h"

struct hist_key { char fs[16]; unsigned int slot; };

int main(int argc, char **argv)
{
	struct readlat_bpf *skel = readlat_bpf__open_and_load();
	struct hist_key k, *prev = NULL, keys[1024];
	unsigned long long v;
	int n = 0;

	if (!skel || readlat_bpf__attach(skel))
		return 1;
	sleep(argc > 1 ? atoi(argv[1]) : 5);

	while (!bpf_map__get_next_key(skel->maps.hist, prev, &k, sizeof(k))) {
		keys[n++] = k;
		prev = &keys[n - 1];
	}
	for (const char *fs = NULL; ; fs = NULL) {	/* 파일시스템별로 모아 출력 */
		for (int i = 0; i < n; i++)
			if (keys[i].fs[0]) { fs = keys[i].fs; break; }
		if (!fs)
			break;
		char cur[16];
		strcpy(cur, fs);
		printf("\n%s\n", cur);
		for (unsigned int s = 0; s < 24; s++)
			for (int i = 0; i < n; i++)
				if (!strcmp(keys[i].fs, cur) && keys[i].slot == s) {
					bpf_map__lookup_elem(skel->maps.hist, &keys[i], sizeof(k), &v, sizeof(v), 0);
					printf("  %6llu - %-6llu us : %llu\n", s ? 1ULL << s : 0, (1ULL << (s + 1)) - 1, v);
				}
		for (int i = 0; i < n; i++)
			if (!strcmp(keys[i].fs, cur))
				keys[i].fs[0] = 0;
	}
	readlat_bpf__destroy(skel);
	return 0;
}
sync; echo 3 | sudo tee /proc/sys/vm/drop_caches
sudo ./readlat 30 &
for i in $(seq 200); do md5sum /proc/meminfo > /dev/null; done
seq 100000 | md5sum > /dev/null
find /usr/share/doc -type f | head -3000 | xargs -d '\n' md5sum > /dev/null
ext4
       0 - 1      us : 3595
       2 - 3      us : 482
       4 - 7      us : 19
       8 - 15     us : 3
      32 - 63     us : 6
      64 - 127    us : 37
     128 - 255    us : 4
     256 - 511    us : 1796
     512 - 1023   us : 227
    1024 - 2047   us : 34
    2048 - 4095   us : 34
    4096 - 8191   us : 105
    8192 - 16383  us : 611
   16384 - 32767  us : 262
   32768 - 65535  us : 5

proc
       0 - 1      us : 208
       2 - 3      us : 2
       4 - 7      us : 83
       8 - 15     us : 119
      16 - 31     us : 3
      32 - 63     us : 1

pipefs
       0 - 1      us : 255
       2 - 3      us : 35
       4 - 7      us : 13
      32 - 63     us : 1
      64 - 127    us : 2
     128 - 255    us : 1
     256 - 511    us : 2
     512 - 1023   us : 1
    1024 - 2047   us : 1
    8192 - 16383  us : 3
   16384 - 32767  us : 2
   32768 - 65535  us : 8
   65536 - 131071 us : 17
  131072 - 262143 us : 12
  262144 - 524287 us : 10
  524288 - 1048575 us : 1

ext4는 페이지 캐시에 있는 읽기(0~3µs)와 캐시를 비워 디스크까지 간 읽기(256µs~32ms)로 봉우리가 둘로 갈린다. pipefs의 긴 꼬리는 쓰는 쪽을 기다린 시간이라, fexit 기반 지연은 작업 시간이 아니라 호출이 블록된 시간까지 포함한다는 점을 기억해야 한다.

uprobe로 libc malloc 크기 분포 보기

uprobe는 섹션 이름에 라이브러리와 함수를 적으면 libbpf가 경로를 찾아 붙여 준다.

#include "vmlinux.h"
#include <bpf/bpf_helpers.h>
#include <bpf/bpf_tracing.h>

char LICENSE[] SEC("license") = "GPL";

const volatile char target_comm[16] = "";
__u64 sizes[32];

static __always_inline bool is_target(void)
{
	char comm[16];

	bpf_get_current_comm(comm, sizeof(comm));
	for (int i = 0; i < 16; i++) {
		if (comm[i] != target_comm[i])
			return false;
		if (!comm[i])
			break;
	}
	return true;
}

SEC("uprobe/libc.so.6:malloc")
int BPF_UPROBE(malloc_enter, size_t size)
{
	u32 slot = 0;

	if (!is_target())
		return 0;
	while (size > 1 && slot < 31) {
		size >>= 1;
		slot++;
	}
	__sync_fetch_and_add(&sizes[slot], 1);
	return 0;
}
#include <stdio.h>
#include <string.h>
#include <unistd.h>
#include <bpf/libbpf.h>
#include "ulat.skel.h"

int main(int argc, char **argv)
{
	struct ulat_bpf *skel = ulat_bpf__open();

	strncpy((char *)skel->rodata->target_comm, argv[1], 15);
	if (ulat_bpf__load(skel) || ulat_bpf__attach(skel))
		return 1;
	sleep(argc > 2 ? atoi(argv[2]) : 5);

	printf("malloc size histogram for '%s'\n", argv[1]);
	for (int s = 0; s < 32; s++)
		if (skel->bss->sizes[s])
			printf("  %8llu - %-8llu : %llu\n", s ? 1ULL << s : 0,
			       (1ULL << (s + 1)) - 1, skel->bss->sizes[s]);
	ulat_bpf__destroy(skel);
	return 0;
}
$ sudo ./ulat python3 6 &
$ python3 -c 'import json; d=[{"k": i, "v": str(i)*10} for i in range(20000)]; json.loads(json.dumps(d))'
malloc size histogram for 'python3'
         0 - 1        : 17
         2 - 3        : 1
         4 - 7        : 3
         8 - 15       : 35
        16 - 31       : 113
        32 - 63       : 2585
        64 - 127      : 97
       128 - 255      : 13
       256 - 511      : 24
       512 - 1023     : 739
      1024 - 2047     : 181
      2048 - 4095     : 59
      4096 - 8191     : 50
      8192 - 16383    : 31
     16384 - 32767    : 10
     32768 - 65535    : 16
     65536 - 131071   : 4

딕셔너리 2만 개를 만들고 직렬화했는데도 malloc()은 4천 번 정도만 불렸다. CPython은 512바이트 이하 객체를 자체 할당자(pymalloc)로 처리하므로, libc malloc()만 보면 파이썬 객체 할당 대부분을 놓친다.

주의사항

항목내용
훅 선택 순서원하는 이벤트에 tracepoint가 있으면 tracepoint(tp_btf)를, 없으면 fentry/fexit를, BTF가 없는 커널이면 kprobe를 쓴다.
kretprobe 비용반환 주소를 가로채는 방식이라 kprobe보다 훨씬 비싸다(측정에서 +235ns). 같은 목적이면 fexit가 낫다.
fexit 지연의 의미블록된 시간까지 포함한다. 파이프·소켓 read는 상대방을 기다린 시간이 그대로 지연으로 잡힌다.
인라인·notrace 함수심볼이 없거나 ftrace 대상에서 빠진 함수에는 kprobe·fentry 모두 붙지 않는다. 컴파일러 옵션에 따라 커널마다 인라인 여부가 다르다.
tp_btf/sys_enter 범위raw 시스템 콜 tracepoint는 모든 시스템 콜에서 호출되므로 ID로 걸러야 한다. 특정 시스템 콜만 보려면 비용을 감수하고 tp/syscalls/*를 쓰는 편이 단순하다.
uprobe 비용호출마다 트랩이 발생해 커널 훅보다 자릿수가 크다(이 VM에서 60µs). 고빈도 함수에는 붙이지 않는다.
uprobe와 할당자언어 런타임(CPython, Go, JVM)은 자체 할당자를 쓰므로 libc 함수만 보면 실제 할당을 놓친다.

마무리

같은 read 경로에서 훅 비용은 fentry·tp_btf가 약 60ns, kprobe·fexit가 약 100ns, kretprobe가 약 235ns였고 uprobe는 자릿수가 달랐다. 기본은 tracepoint나 fentry/fexit로 잡고, kprobe는 BTF가 없거나 tracepoint가 없는 경우의 대안으로 둔다. 다음 편에서는 이 훅들로 스케줄러를 관측해 런큐 대기 시간과 컨텍스트 스위치를 측정한다.

참고

답글 남기기