Byeo

BCC : Lesson 1 ~ 6 본문

프로그래밍 (Programming)/eBPF

BCC : Lesson 1 ~ 6

BKlee 2021. 8. 5. 18:23
반응형

이 포스트는 [iovisor-bcc tutorial]을 참고하였습니다.

 

목차

Lesson 1. Hello world

Lesson 2. sys_sync()

Lesson 3. hello_fields.py

Lesson 4. sync_timing.py

Lesson 5. sync_count.py

Lesson 6. disksnoop.py


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()
  1. BPF(text='...') : C언어 형태의 BPF 프로그램이 적힙니다.
  2. kprobe__: kernel을 tracing하기 위한 short-cut입니다.
  3. sys_clone: 추적할 커널 함수 명입니다. 지원하지 않는 system call을 추적할 경우 컴파일 에러가 발생합니다.
  4. bpf_trace_printk(): (/sys/kernel/debug/tracing/trace_pipe)에 있는 내용을 출력합니다. 여기서는 괜찮지만, 3개의 argument 제한, 1개의 string, 그리고 globally shared되고 있는 trace_pipe에 의해 concurrent 프로그램은 output이 깨질 수 있습니다.
  5. return 0: kernel에서 bpf 프로그램을 수행한 뒤에 바로 종료합니다.
  6. .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 하는 프로그램입니다.

  1. prog: 마찬가지로 C프로그램을 작성한 변수입니다.
  2. hello(): C 함수입니다. 차이점은 kprobe__가 빠져 있습니다. 모든 BPF 프로그램을 위해 작성된 C 프로그램은 probe를 위해 실행될 것이기에 pt_reg* ctx를 첫 인자로 넣어야 합니다. 만약 probe를 위한 코드가 아닌 경우, static inline이나 _alywas_inline으로 작성해야 합니다.
  3. b.attach_kprobe(event=b.get_syscall_fnname("clone"), fn_name="hello"): clone 함수에 대해 hello() 함수를 실행할 kprobe를 생성합니다. 다양한 kernel 함수를 probe하기 위해 attack_kprobe를 여러번 부를 수 있습니다.
  4. 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))
  1. bpf_ktime_get_ns(): 나노 seconds단위의 시간을 얻어옵니다.
  2. BPF_HASH(last): "last"라고 불리는 BPF map object를 생성합니다. 아무것도 명시하지 않으면 u64 type의 key와 u64 type의 value를 갖습니다.
  3. key=0: 오로지 하나의 key=0 / value pair만 hash에 저장하고자 합니다.
  4. last.lookup(&key): "last" 해쉬에서 key 0의 value의 pointer를 얻어옵니다. 없다면 NULL을 반환합니다. (key의 주소를 넘겨줘야 합니다.)
  5. if(tsp != NULL): "last" 해쉬 lookup을 했을 때, 값이 있는지를 검사합니다.
  6. last.delete(&key): 해쉬에서 key / value apir를 제거합니다.
  7. 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 파일입니다.

  1. REQ_WRITE: kernel constant를 python에서 정의할 수 있습니다. REQ_WRITE를 BPF에서 사용하면, 적절한 #include와 함께 실행됩니다.
  2. trace_start(struct pt_regs *ctx, struct request *req): kprobe에 attach될 함수입니다. ctx는 BPF를 위해서 기본적으로 필요한 인자입니다. struct request *req는 blk_start_request()에서 사용되는 첫 번째 인자입니다.
  3. start.update(&req, &ts): "start" hash를 update합니다. 여기서 &req는 struct request* 입니다. struct request*는 두 블럭이 같은 값을 가질 수 없기때문에 유일하므로, key로서 적절합니다.
  4. 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이 나오는지는 살펴봐야 할 것 같네요.

반응형
Comments