- Today
- Total
Byeo
BCC : Lesson 1 ~ 6 본문
이 포스트는 [iovisor-bcc tutorial]을 참고하였습니다.
목차
Lesson 1. Hello world
bcc를 빌드 하면, examples/hello_world.py가 존재합니다.
sudo ./examples/hello_world.py
위와 같이 실행하고 다른 session에서 process를 생성하는 명령어를 수행하면 아래와 같이 출력되는 것을 확인할 수 있습니다.
./a.out 은 간단히 fork를 하나 실행하는 프로그램입니다. 이 때 역시 프로세스를 생성하기 때문에 출력된 것을 알 수 있습니다.
from bcc import BPF
BPF(text='int kprobe__sys_clone(void *ctx) { bpf_trace_printk("Hello, World!\\n"); return 0; }').trace_print()
- BPF(text='...') : C언어 형태의 BPF 프로그램이 적힙니다.
- kprobe__: kernel을 tracing하기 위한 short-cut입니다.
- sys_clone: 추적할 커널 함수 명입니다. 지원하지 않는 system call을 추적할 경우 컴파일 에러가 발생합니다.
- bpf_trace_printk(): (/sys/kernel/debug/tracing/trace_pipe)에 있는 내용을 출력합니다. 여기서는 괜찮지만, 3개의 argument 제한, 1개의 string, 그리고 globally shared되고 있는 trace_pipe에 의해 concurrent 프로그램은 output이 깨질 수 있습니다.
- return 0: kernel에서 bpf 프로그램을 수행한 뒤에 바로 종료합니다.
- .trace_print(): trace_pipe에서 내용을 읽고 출력하는 bcc routine입니다.
Lesson 2. sys_sync()
sync는 메모리에 존재하는 데이터를 디스크에 내리는 명령어입니다. 문서에서 간단히 연습겸으로 짜보라고 주어진 문제입니다.
간단히 hello world 프로그램에서 sys_clone을 sys_sync로 바꾸면 동작합니다.
from bcc import BPF
# This may not work for 4.17 on x64, you need replace kprobe__sys_clone with kprobe____x64_sys_clone
BPF(text='int kprobe__sys_sync(void *ctx) { bpf_trace_printk("Hello, World!\\n"); return 0; }').trace_print()
아래는 출력 화면입니다.
Lesson 3. hello_fields.py
from bcc import BPF
# define BPF program
prog = """
int hello(void *ctx) {
bpf_trace_printk("Hello, World!\\n");
return 0;
}
"""
# load BPF program
b = BPF(text=prog)
b.attach_kprobe(event=b.get_syscall_fnname("clone"), fn_name="hello")
# header
print("%-18s %-16s %-6s %s" % ("TIME(s)", "COMM", "PID", "MESSAGE"))
# format output
while 1:
try:
(task, pid, cpu, flags, ts, msg) = b.trace_fields()
except ValueError:
continue
print("%-18.9f %-16s %-6d %s" % (ts, task, pid, msg))
kernel의 clone이 불릴 때 tracing 하는 프로그램입니다.
- prog: 마찬가지로 C프로그램을 작성한 변수입니다.
- hello(): C 함수입니다. 차이점은 kprobe__가 빠져 있습니다. 모든 BPF 프로그램을 위해 작성된 C 프로그램은 probe를 위해 실행될 것이기에 pt_reg* ctx를 첫 인자로 넣어야 합니다. 만약 probe를 위한 코드가 아닌 경우, static inline이나 _alywas_inline으로 작성해야 합니다.
- b.attach_kprobe(event=b.get_syscall_fnname("clone"), fn_name="hello"): clone 함수에 대해 hello() 함수를 실행할 kprobe를 생성합니다. 다양한 kernel 함수를 probe하기 위해 attack_kprobe를 여러번 부를 수 있습니다.
- b.trace_fields(): trace_pipe에 있는 내용을 가져옵니다. trace_fields의 attribute는 고정되어 있습니다.
위는 실행 화면입니다.
Lesson 4. sync_timing.py
Lesson4에서는 sync_timeing.py와 관련된 이야기입니다. 일화로 옛날에 reboot 하기 직전, sync를 timing issue를 해결하기 위해 sync를 세 번 날렸다고 하네요. 비효율적인 방법임에도 불구하고 industry에서는 관습적으로 썼다고 합니다.
from __future__ import print_function
from bcc import BPF
# load BPF program
b = BPF(text="""
#include <uapi/linux/ptrace.h>
BPF_HASH(last);
int do_trace(struct pt_regs *ctx) {
u64 ts, *tsp, delta, key = 0;
// attempt to read stored timestamp
tsp = last.lookup(&key);
if (tsp != NULL) {
delta = bpf_ktime_get_ns() - *tsp;
if (delta < 1000000000) {
// output if time is less than 1 second
bpf_trace_printk("%d\\n", delta / 1000000);
}
last.delete(&key);
}
// update stored timestamp
ts = bpf_ktime_get_ns();
last.update(&key, &ts);
return 0;
}
""")
b.attach_kprobe(event=b.get_syscall_fnname("sync"), fn_name="do_trace")
print("Tracing for quick sync's... Ctrl-C to end")
# format output
start = 0
while 1:
(task, pid, cpu, flags, ts, ms) = b.trace_fields()
if start == 0:
start = ts
ts = ts - start
print("At time %.2f s: multiple syncs detected, last %s ms ago" % (ts, ms))
- bpf_ktime_get_ns(): 나노 seconds단위의 시간을 얻어옵니다.
- BPF_HASH(last): "last"라고 불리는 BPF map object를 생성합니다. 아무것도 명시하지 않으면 u64 type의 key와 u64 type의 value를 갖습니다.
- key=0: 오로지 하나의 key=0 / value pair만 hash에 저장하고자 합니다.
- last.lookup(&key): "last" 해쉬에서 key 0의 value의 pointer를 얻어옵니다. 없다면 NULL을 반환합니다. (key의 주소를 넘겨줘야 합니다.)
- if(tsp != NULL): "last" 해쉬 lookup을 했을 때, 값이 있는지를 검사합니다.
- last.delete(&key): 해쉬에서 key / value apir를 제거합니다.
- last.update(&key, &ts): 해쉬를 update합니다. ts는 현재 nano second scale의 timestamp입니다.
실행 결과입니다!
Lesson 5. sync_count.py
Lesson 4에서는 1초 안에 발생한 중복 sync에 대해서 출력하게 했다면, 이번에는 sync 함수가 몇 번 불렸는지를 출력하는 코드를 작성해보는 실습입니다.
from __future__ import print_function
from bcc import BPF
from bcc.utils import printb
# load BPF program
b = BPF(text="""
#include <uapi/linux/ptrace.h>
BPF_HASH(last);
int do_trace(struct pt_regs *ctx) {
u64 ts, *tsp, count = 1, key = 0;
// attempt to read stored timestamp
tsp = last.lookup(&key);
if (tsp != NULL) {
count = *tsp ;
count += 1;
last.delete(&key);
}
// update stored timestamp
last.update(&key, &count);
bpf_trace_printk("%d\\n", count);
return 0;
}
""")
b.attach_kprobe(event=b.get_syscall_fnname("sync"), fn_name="do_trace")
print("Tracing for quick sync's... Ctrl-C to end")
# format output
start = 0
while 1:
try:
(task, pid, cpu, flags, ts, msg) = b.trace_fields()
if start == 0:
start = ts
ts = ts - start
printb(b"At time %.2f s: multiple syncs detected, %s times" % (ts, msg))
except KeyboardInterrupt:
exit()
여기서 BPF에서 실행하는 bpf_trace_printk가 b.trace_fields()에서의 msg에 해당하는데 자세한 내용은 뒤에 나오면 다뤄보도록 하겠습니다.
Lesson 6. disksnoop.py
[...]
REQ_WRITE = 1 # from include/linux/blk_types.h
# load BPF program
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_done", fn_name="trace_completion")
[...]
이번에는 disksnoop.py 파일입니다.
- REQ_WRITE: kernel constant를 python에서 정의할 수 있습니다. REQ_WRITE를 BPF에서 사용하면, 적절한 #include와 함께 실행됩니다.
- trace_start(struct pt_regs *ctx, struct request *req): kprobe에 attach될 함수입니다. ctx는 BPF를 위해서 기본적으로 필요한 인자입니다. struct request *req는 blk_start_request()에서 사용되는 첫 번째 인자입니다.
- start.update(&req, &ts): "start" hash를 update합니다. 여기서 &req는 struct request* 입니다. struct request*는 두 블럭이 같은 값을 가질 수 없기때문에 유일하므로, key로서 적절합니다.
- req->__data_len: struct reqeust를 참조합니다. struct request에는 아래와 같은 변수들이 있고, 이들을 활용할 수 있습니다. 실제로 kernel의 데이터를 참고하는 코드를 작성하면 bcc가 bpf_probe_read_kernel로 치환한다고 합니다. 만약 너무 복잡해서 bcc가 handling하지 못하는 경우, 직접 bpf_probe_read_kernel을 불러야 할 수도 있다고 합니다.
struct request {
struct request_queue *q;
struct blk_mq_ctx *mq_ctx;
struct blk_mq_hw_ctx *mq_hctx;
unsigned int cmd_flags; /* op and common flags */
req_flags_t rq_flags;
int tag;
int internal_tag;
/* the following two fields are internal, NEVER access directly */
unsigned int __data_len; /* total data len */
sector_t __sector; /* sector cursor */
struct bio *bio;
struct bio *biotail;
struct list_head queuelist;
[...]
위는 struct request의 구조체입니다.
위는 실행화면입니다! 근데 BYTES가 왜 0이 나오는지는 살펴봐야 할 것 같네요.