ftrace / Tracepoints 심화

Linux 커널 트레이싱 심화: ftrace, tracepoints, kprobes/kretprobes, perf, trace-cmd, 커널 관측성 도구 종합 분석.

커널 트레이싱 개요

커널 트레이싱은 실행 중인 커널의 내부 동작을 관찰하는 기술입니다. 커널 개발자와 시스템 엔지니어는 트레이싱을 통해 성능 병목, 레이턴시 원인, 함수 호출 경로, 스케줄링 이벤트 등을 분석할 수 있습니다. 유저 공간의 strace가 시스템 콜만 추적하는 것과 달리, 커널 트레이싱은 커널 내부의 모든 함수와 이벤트를 대상으로 합니다.

관측성(Observability) 계층

Linux 커널의 관측성 도구는 크게 세 가지 계층으로 구분됩니다. 각 계층은 서로 다른 수준의 상세도와 오버헤드를 제공합니다.

정적 계측 vs 동적 계측

커널 트레이싱의 두 가지 근본적인 접근법은 정적 계측(static instrumentation)과 동적 계측(dynamic instrumentation)입니다.

ftrace 아키텍처

ftrace(Function Tracer)는 Linux 커널에 내장된 트레이싱 프레임워크입니다. Steven Rostedt가 개발하여 커널 2.6.27에 도입되었으며, 이후 Linux 트레이싱의 핵심 인프라로 자리잡았습니다. ftrace는 단순한 함수 트레이서를 넘어 다양한 트레이서 플러그인을 지원하는 프레임워크입니다.

mcount/fentry 메커니즘

ftrace의 함수 트레이싱은 컴파일러가 삽입하는 프로파일링 훅에 의존합니다. GCC의 -pg 옵션은 모든 함수 진입점에 mcount() 호출을 삽입합니다. 최신 커널은 -pg -mfentry 옵션을 사용하여 함수 프롤로그 이전에 __fentry__()를 호출합니다.

/* 컴파일러가 삽입하는 코드 (개념적) */
void some_kernel_function(int arg)
{
    __fentry__();       /* 컴파일러가 자동 삽입 */
    /* 원래 함수 코드 ... */
}

/*
 * 부팅 시 __fentry__() 호출은 NOP으로 패치됨 (dynamic ftrace).
 * ftrace가 활성화되면 해당 NOP이 ftrace trampoline으로 다시 패치됨.
 *
 * x86_64에서:
 *   비활성: 0f 1f 44 00 00   (5-byte NOP)
 *   활성:   e8 xx xx xx xx   (CALL ftrace_caller)
 */

ftrace_ops 구조체

ftrace 클라이언트(tracer, kprobe 등)는 ftrace_ops 구조체를 통해 콜백을 등록합니다. 여러 클라이언트가 동시에 등록될 수 있으며, ftrace는 등록된 모든 콜백을 순회합니다.

/* include/linux/ftrace.h */
struct ftrace_ops {
    ftrace_func_t             func;           /* 콜백 함수 */
    struct ftrace_ops        *next;           /* 연결 리스트 */
    unsigned long             flags;          /* FTRACE_OPS_FL_* */
    struct ftrace_ops_hash    local_hash;     /* 함수 필터 해시 */
    struct ftrace_ops_hash   *func_hash;     /* 필터 해시 포인터 */
    /* ... */
};

/* 콜백 함수 시그니처 */
typedef void (*ftrace_func_t)(unsigned long ip,
                               unsigned long parent_ip,
                               struct ftrace_ops *op,
                               struct ftrace_regs *regs);

Ring Buffer

ftrace의 이벤트 데이터는 per-CPU 링 버퍼에 저장됩니다. 이 링 버퍼는 lockless 설계로 트레이싱 오버헤드를 최소화합니다. 각 CPU는 독립적인 버퍼 페이지를 가지며, 생산자(트레이서)와 소비자(reader)가 동시에 접근해도 lock 없이 안전하게 동작합니다.

/* kernel/trace/ring_buffer.c - 링 버퍼 핵심 구조 (단순화) */
struct ring_buffer_per_cpu {
    int                        cpu;
    struct ring_buffer        *buffer;
    struct list_head           pages;       /* 버퍼 페이지 리스트 */
    struct buffer_page        *head_page;  /* reader용 */
    struct buffer_page        *tail_page;  /* writer용 */
    struct buffer_page        *commit_page;/* 커밋 완료 페이지 */
    unsigned long              entries;     /* 엔트리 수 */
    unsigned long              overrun;     /* 오버런 카운트 */
    /* ... */
};

/* 링 버퍼 크기 조절 (tracefs) */
/* echo 8192 > /sys/kernel/tracing/buffer_size_kb */

tracefs 인터페이스

ftrace는 tracefs 파일시스템을 통해 사용자 공간과 상호작용합니다. 커널 4.1 이전에는 debugfs(/sys/kernel/debug/tracing/) 아래에 있었으나, 이후 독립된 tracefs(/sys/kernel/tracing/)로 분리되었습니다. 대부분의 시스템에서 두 경로 모두 사용 가능합니다.

# tracefs 마운트 확인
mount | grep tracefs
# tracefs on /sys/kernel/tracing type tracefs (rw,nosuid,nodev,noexec,relatime)

# 마운트되지 않은 경우 수동 마운트
mount -t tracefs nodev /sys/kernel/tracing

핵심 제어 파일

tracefs의 주요 파일들과 역할을 정리하면 다음과 같습니다.

기본 워크플로우

# 변수 정의 (편의)
T=/sys/kernel/tracing

# 1. 사용 가능한 트레이서 확인
cat $T/available_tracers
# blk function_graph function nop

# 2. 트레이싱 비활성화 (설정 변경 전)
echo 0 > $T/tracing_on

# 3. 트레이서 설정
echo function > $T/current_tracer

# 4. 필터 설정 (선택)
echo 'schedule*' > $T/set_ftrace_filter

# 5. 버퍼 초기화
echo > $T/trace

# 6. 트레이싱 시작
echo 1 > $T/tracing_on

# 7. 워크로드 실행
sleep 1

# 8. 트레이싱 중지
echo 0 > $T/tracing_on

# 9. 결과 확인
cat $T/trace | head -30

# 10. 정리 (nop 트레이서로 복원)
echo nop > $T/current_tracer
echo > $T/set_ftrace_filter

Function Tracer

function 트레이서는 ftrace의 가장 기본적인 트레이서로, 커널 함수 호출을 기록합니다. 각 엔트리에는 타임스탬프, CPU 번호, 프로세스명, PID, 호출 함수명, 부모 함수명이 포함됩니다.

# function tracer 활성화
echo function > /sys/kernel/tracing/current_tracer
echo 1 > /sys/kernel/tracing/tracing_on

# 출력 예시
cat /sys/kernel/tracing/trace
#           TASK-PID    CPU#  |||||  TIMESTAMP  FUNCTION
#              | |        |   |||||     |         |
#        <idle>-0     [003] d..1  1234.567890: tick_nohz_idle_exit <-do_idle
#        <idle>-0     [003] d..1  1234.567892: ktime_get <-tick_nohz_idle_exit
#        <idle>-0     [003] d..1  1234.567893: update_ts_time_stats <-...

function_graph 트레이서

function_graph 트레이서는 함수의 진입과 반환을 모두 기록하여 C 코드와 유사한 계층적 호출 구조를 보여줍니다. 각 함수의 실행 시간도 표시됩니다.

echo function_graph > /sys/kernel/tracing/current_tracer
echo 1 > /sys/kernel/tracing/tracing_on
sleep 0.1
echo 0 > /sys/kernel/tracing/tracing_on
cat /sys/kernel/tracing/trace

# 출력 예시 (들여쓰기로 호출 깊이 표현)
# CPU  DURATION                  FUNCTION CALLS
#  |     |   |                     |   |   |   |
#  3)               |  schedule() {
#  3)               |    __schedule() {
#  3)   0.120 us    |      rcu_note_context_switch();
#  3)               |      pick_next_task_fair() {
#  3)   0.085 us    |        update_curr();
#  3)   0.071 us    |        __pick_next_entity();
#  3)   0.712 us    |      }
#  3)               |      finish_task_switch.isra.0() {
#  3)   0.089 us    |        __perf_event_task_sched_in();
#  3)   0.341 us    |      }
#  3)   2.154 us    |    }
#  3)   2.483 us    |  }

함수 필터링

커널에는 수만 개의 함수가 있으므로 모든 함수를 트레이싱하면 오버헤드가 극심합니다. set_ftrace_filter와 set_ftrace_notrace를 사용하여 관심 있는 함수만 선택적으로 트레이싱합니다.

T=/sys/kernel/tracing

# 와일드카드로 함수 필터링
echo 'schedule*' > $T/set_ftrace_filter
echo '*_schedule' > $T/set_ftrace_filter      # 덮어쓰기
echo 'tcp_*' >> $T/set_ftrace_filter           # 추가 (>>)

# 특정 모듈의 함수만 필터링
echo ':mod:e1000e' > $T/set_ftrace_filter

# 함수 제외 (블랙리스트)
echo 'rcu_*' > $T/set_ftrace_notrace

# 현재 필터 확인
cat $T/set_ftrace_filter

# 필터 초기화 (모든 함수 트레이싱)
echo > $T/set_ftrace_filter

# 필터 가능한 함수 수 확인
wc -l $T/available_filter_functions
# 약 50000~80000개 (커널 빌드 옵션에 따라 다름)

# 특정 PID만 트레이싱
echo 1234 > $T/set_ftrace_pid

# function_graph의 호출 깊이 제한
echo 3 > $T/max_graph_depth

Tracepoints

Tracepoint는 커널 소스 코드에 미리 정의된 정적 계측점입니다. 개발자가 의미 있는 지점에 삽입하며, 활성화되지 않은 상태에서는 사실상 오버헤드가 없습니다(static key/jump label 메커니즘). tracepoint가 활성화되면 등록된 프로브 함수가 호출됩니다.

TRACE_EVENT 매크로

TRACE_EVENT()는 tracepoint를 정의하는 핵심 매크로입니다. 하나의 매크로 호출로 tracepoint 선언, 레코드 구조체, 포맷 문자열, ftrace 출력 등을 모두 생성합니다.

/* include/trace/events/sched.h 에서 발췌 (단순화) */
#include <linux/tracepoint.h>

TRACE_EVENT(sched_switch,

    /* 프로토타입: tracepoint 콜백의 인자 */
    TP_PROTO(bool preempt,
             struct task_struct *prev,
             struct task_struct *next,
             unsigned int prev_state),

    /* 호출 시 전달할 인자 */
    TP_ARGS(preempt, prev, next, prev_state),

    /* 링 버퍼에 저장할 구조체 필드 */
    TP_STRUCT__entry(
        __array(  char, prev_comm, TASK_COMM_LEN )
        __field(  pid_t, prev_pid               )
        __field(  int,   prev_prio               )
        __field(  long,  prev_state              )
        __array(  char, next_comm, TASK_COMM_LEN )
        __field(  pid_t, next_pid               )
        __field(  int,   next_prio               )
    ),

    /* 링 버퍼에 데이터 기록 방법 */
    TP_fast_assign(
        memcpy(__entry->prev_comm, prev->comm, TASK_COMM_LEN);
        __entry->prev_pid   = prev->pid;
        __entry->prev_prio  = prev->prio;
        __entry->prev_state = prev_state;
        memcpy(__entry->next_comm, next->comm, TASK_COMM_LEN);
        __entry->next_pid   = next->pid;
        __entry->next_prio  = next->prio;
    ),

    /* 텍스트 출력 포맷 */
    TP_printk("prev_comm=%s prev_pid=%d prev_prio=%d prev_state=%s%s ==> next_comm=%s next_pid=%d next_prio=%d",
        __entry->prev_comm, __entry->prev_pid, __entry->prev_prio,
        (__entry->prev_state & (TASK_REPORT_MAX - 1)) ?
            __print_flags(__entry->prev_state & (TASK_REPORT_MAX - 1), "|",
                { TASK_INTERRUPTIBLE, "S" },
                { TASK_UNINTERRUPTIBLE, "D" }) : "R",
        __entry->prev_state & TASK_REPORT_MAX ? "+" : "",
        __entry->next_comm, __entry->next_pid, __entry->next_prio)
);

tracefs를 통한 이벤트 제어

T=/sys/kernel/tracing

# 사용 가능한 이벤트 카테고리 확인
ls $T/events/
# block  ext4  irq  kmem  net  power  sched  signal  skb  tcp  timer  ...

# 스케줄러 이벤트 목록
ls $T/events/sched/
# sched_switch  sched_wakeup  sched_migrate_task  ...

# 특정 이벤트 활성화
echo 1 > $T/events/sched/sched_switch/enable

# 카테고리 전체 활성화
echo 1 > $T/events/sched/enable

# 모든 이벤트 활성화 (주의: 대량 데이터)
echo 1 > $T/events/enable

# 이벤트 format 확인 (필드 구조)
cat $T/events/sched/sched_switch/format
# name: sched_switch
# ID: 316
# format:
#   field:unsigned short common_type;    offset:0; size:2; signed:0;
#   field:char prev_comm[16];            offset:8; size:16; signed:0;
#   field:pid_t prev_pid;                offset:24; size:4; signed:1;
#   ...

# 이벤트 필터링 (특정 조건만 기록)
echo 'next_pid == 0' > $T/events/sched/sched_switch/filter
echo 'prev_state == 1' > $T/events/sched/sched_switch/filter

# 필터 해제
echo 0 > $T/events/sched/sched_switch/filter

커널 코드에서 tracepoint 호출

/* kernel/sched/core.c - 스케줄러에서 tracepoint 호출 */
static void __sched __schedule(unsigned int sched_mode)
{
    struct task_struct *prev, *next;
    /* ... */

    /* tracepoint 호출 - 비활성 시 static key로 건너뜀 */
    trace_sched_switch(sched_mode & SM_MASK_PREEMPT, prev, next,
                       prev_state);
    /* ... */
}

kprobes

kprobes(Kernel Probes)는 거의 모든 커널 주소에 동적으로 프로브를 삽입할 수 있는 디버깅/트레이싱 메커니즘입니다. 2004년 커널 2.6.9에서 IBM의 Prasanna S Panchamukhi 등이 도입했으며, 소스 코드 수정이나 재컴파일 없이 런타임에 커널 내부 동작을 관찰할 수 있습니다. kprobes는 대상 주소의 명령어를 breakpoint 명령어(x86에서 int3, ARM64에서 BRK #0x004)로 교체하고, 프로브가 적중하면 등록된 핸들러를 호출합니다. ftrace, perf, BPF, SystemTap 등 상위 트레이싱 도구들이 내부적으로 kprobes를 활용합니다.

kprobe 유형

내부 동작 메커니즘

kprobe의 동작은 등록 → 트랩(int3) → pre_handler → 단일 스텝 실행 → post_handler → 복귀의 6단계로 구성됩니다. x86_64 아키텍처를 기준으로 핵심 흐름을 설명합니다.

/* arch/x86/kernel/kprobes/core.c — kprobe 등록 시 핵심 로직 (단순화) */
int arch_prepare_kprobe(struct kprobe *p)
{
    /* 1. 프로브 대상 주소의 원래 명령어를 백업 */
    p->opcode = *p->addr;

    /* 2. out-of-line(OOL) 실행 슬롯 할당 — single-step 실행에 사용 */
    p->ainsn.insn = get_insn_slot();
    memcpy(p->ainsn.insn, p->addr, MAX_INSN_SIZE);

    /* 3. 대상 주소를 int3(0xCC)로 교체 — text_poke는 SMP-safe 코드 패칭 */
    text_poke(p->addr, &int3, 1);
    return 0;
}

/* int3 예외 발생 시 호출되는 핸들러 (단순화) */
int kprobe_int3_handler(struct pt_regs *regs)
{
    struct kprobe *p;
    struct kprobe_ctlblk *kcb = get_kprobe_ctlblk();

    /* int3이 1바이트이므로 IP-1이 원래 프로브 주소 */
    p = get_kprobe((kprobe_opcode_t *)regs->ip - 1);
    if (!p)
        return 0;   /* 우리 kprobe가 아님 */

    /* pre_handler 콜백 실행 */
    if (p->pre_handler && p->pre_handler(p, regs))
        return 1;   /* 핸들러가 실행을 변경함 */

    /* single-step 준비: IP를 OOL 슬롯으로, TF 설정 */
    regs->ip = (unsigned long)p->ainsn.insn;
    regs->flags |= X86_EFLAGS_TF;   /* Trap Flag → debug 예외 발생 */
    regs->flags &= ~X86_EFLAGS_IF;  /* 인터럽트 비활성화 */
    kcb->kprobe_status = KPROBE_HIT_SS;
    return 1;
}

/* debug 예외(single-step 완료) 시 — post_handler 실행 후 원래 흐름으로 복귀 */
int kprobe_debug_handler(struct pt_regs *regs)
{
    struct kprobe_ctlblk *kcb = get_kprobe_ctlblk();
    struct kprobe *p = kcb->kprobe_saved;

    /* post_handler 콜백 실행 */
    if (p->post_handler)
        p->post_handler(p, regs, 0);

    /* IP를 원래 명령어 다음 주소로 복원 */
    resume_execution(p, regs, kcb);
    return 1;
}

kprobe 구조체 상세

/* include/linux/kprobes.h */
struct kprobe {
    struct hlist_node  hlist;         /* kprobe 해시 테이블 연결 */
    struct list_head   list;          /* 동일 주소 다중 프로브 리스트 (aggregate) */
    unsigned long      nmissed;       /* 재진입으로 놓친 프로브 수 */
    kprobe_opcode_t   *addr;         /* 프로브 대상 주소 (자동 해석) */
    const char        *symbol_name;  /* 심볼 이름 (addr 대신 사용 가능) */
    unsigned int       offset;        /* 심볼 시작점으로부터의 오프셋 */

    /* 콜백 핸들러 */
    kprobe_pre_handler_t    pre_handler;   /* 명령어 실행 전 */
    kprobe_post_handler_t   post_handler;  /* 명령어 실행 후 */

    /* 내부 관리용 */
    struct arch_specific_insn ainsn;   /* OOL 슬롯, 명령어 디코딩 정보 */
    u32               flags;         /* KPROBE_FLAG_* */
    kprobe_opcode_t   opcode;        /* 백업된 원래 opcode */
};

/* 주요 플래그 */
#define KPROBE_FLAG_GONE       1   /* 모듈 언로드 등으로 프로브 무효화 */
#define KPROBE_FLAG_DISABLED   2   /* disable_kprobe()로 일시 비활성화 */
#define KPROBE_FLAG_OPTIMIZED  4   /* jump 최적화 적용됨 (OPTPROBES) */
#define KPROBE_FLAG_FTRACE     8   /* ftrace 기반 프로브 (함수 진입점) */

kretprobe 내부 구조

kretprobe는 함수의 반환 시점을 캡처합니다. 등록 시 대상 함수 진입점에 kprobe를 설치하고, 함수 진입 시 스택의 리턴 주소를 kretprobe_trampoline으로 교체합니다. 함수가 반환하면 trampoline이 실행되어 ret_handler를 호출한 뒤, 원래 caller 주소로 복귀합니다.

/* include/linux/kprobes.h */
struct kretprobe {
    struct kprobe    kp;              /* 내장 kprobe (함수 진입점에 설치) */
    kretprobe_handler_t handler;     /* 반환 시 콜백 */
    kretprobe_handler_t entry_handler;/* 진입 시 콜백 (데이터 수집용) */
    int             maxactive;       /* 동시 인스턴스 최대 수 */
    int             nmissed;         /* 인스턴스 부족으로 놓친 수 */
    size_t          data_size;       /* 인스턴스별 private 데이터 크기 */
    struct freelist_head freelist;    /* 사용 가능한 인스턴스 pool */
};

/* 각 활성 호출마다 하나씩 할당되는 인스턴스 */
struct kretprobe_instance {
    union {
        struct freelist_node freelist;
        struct rcu_head      rcu;
    };
    struct llist_node   llist;
    struct kretprobe   *rp;             /* 소속 kretprobe */
    kprobe_opcode_t    *ret_addr;       /* 원래 리턴 주소 (백업) */
    struct task_struct *task;           /* 연관 태스크 */
    char               data[];          /* private 데이터 (flexible array) */
};

/*
 * maxactive 가이드:
 *   0         → num_possible_cpus()로 자동 설정
 *   N > 0     → 동시에 N개의 호출만 추적
 *   nmissed가 증가하면 maxactive 증가 필요
 *   재귀/고빈도 함수: 2 * num_possible_cpus() 이상 권장
 */

커널 API로 kprobe 등록

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

/* pre_handler: 프로브 지점 도달 시 호출 */
static int handler_pre(struct kprobe *p, struct pt_regs *regs)
{
    /* x86_64: 첫 번째 인자 = rdi 레지스터 */
    pr_info("kprobe hit: %s, ip=%pS, arg0=0x%lx\n",
            p->symbol_name,
            (void *)regs->ip,
            regs->di);
    return 0;
}

/* post_handler: 프로브 지점의 원래 명령어 실행 후 호출 */
static void handler_post(struct kprobe *p, struct pt_regs *regs,
                         unsigned long flags)
{
    pr_info("kprobe post: ip=%pS, flags=0x%lx\n",
            (void *)regs->ip, regs->flags);
}

static struct kprobe my_kp = {
    .symbol_name = "do_sys_openat2",
    .pre_handler = handler_pre,
    .post_handler = handler_post,
};

static int __init kp_init(void)
{
    int ret = register_kprobe(&my_kp);
    if (ret < 0) {
        pr_err("register_kprobe 실패: %d\n", ret);
        return ret;
    }
    pr_info("kprobe 등록: %s at %pS\n",
            my_kp.symbol_name, my_kp.addr);
    return 0;
}

static void __exit kp_exit(void)
{
    unregister_kprobe(&my_kp);
    pr_info("kprobe 해제: missed=%lu\n", my_kp.nmissed);
}

module_init(kp_init);
module_exit(kp_exit);
MODULE_LICENSE("GPL");

kretprobe 사용

#include <linux/kprobes.h>

/* kretprobe 인스턴스별 데이터 */
struct my_data {
    ktime_t entry_stamp;
};

/* 함수 진입 시 호출 */
static int entry_handler(struct kretprobe_instance *ri,
                          struct pt_regs *regs)
{
    struct my_data *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_to_ns(ktime_sub(ktime_get(), data->entry_stamp));
    unsigned long retval = regs_return_value(regs);

    pr_info("함수 %s 반환: retval=%lu, 소요시간=%lldns\n",
            ri->rp->kp.symbol_name, retval, delta);
    return 0;
}

static struct kretprobe my_kretprobe = {
    .handler         = ret_handler,
    .entry_handler   = entry_handler,
    .data_size       = sizeof(struct my_data),
    .maxactive       = 20,    /* 동시 프로브 인스턴스 수 */
    .kp.symbol_name  = "vfs_read",
};

static int __init krp_init(void)
{
    return register_kretprobe(&my_kretprobe);
}

static void __exit krp_exit(void)
{
    unregister_kretprobe(&my_kretprobe);
    pr_info("missed=%lu\n", my_kretprobe.nmissed);
}

kprobe 최적화 (OPTPROBES)

기본 kprobe는 int3 예외를 사용하므로 trap 처리 비용이 발생합니다. CONFIG_OPTPROBES=y(x86 기본 활성)를 사용하면, 커널은 적격한 kprobe를 jump 최적화합니다. int3(1바이트) 대신 JMP rel32(5바이트)로 패치하여 detour buffer(trampoline)로 직접 점프합니다. 이로써 trap 오버헤드가 사라지고, 단순 함수 호출 수준의 비용만 남습니다.

/* 최적화 전: int3 기반 (느림) */
/*   probe point:  CC (int3)           → 예외 발생 → 핸들러 */

/* 최적화 후: jump 기반 (빠름) */
/*   probe point:  E9 xx xx xx xx (JMP) → detour buffer → 핸들러 */

/*
 * 최적화 조건 (x86_64):
 *   1. 프로브 주소부터 5바이트 이내에 다른 프로브나 점프 대상이 없어야 함
 *   2. 프로브 대상 명령어가 RIP-relative가 아니어야 함 (또는 보정 가능해야 함)
 *   3. pre_handler만 사용하는 경우 (post_handler 미등록)
 *   4. 함수 진입점의 경우 ftrace 기반 최적화도 가능 (KPROBE_FLAG_FTRACE)
 */

/* ftrace 기반 kprobe: 함수 진입점에 프로브를 설치하면
 * int3 대신 ftrace의 __fentry__ 메커니즘을 재사용합니다.
 * CONFIG_KPROBES_ON_FTRACE=y일 때 자동 적용. */

kprobe 블랙리스트와 안전성

모든 커널 함수에 kprobe를 설치할 수 있는 것은 아닙니다. 커널은 블랙리스트를 유지하여 프로브 설치 시 안전하지 않은 함수를 거부합니다.

# 블랙리스트 확인
cat /sys/kernel/debug/kprobes/blacklist | head -20
# 0xffffffff81000000-0xffffffff81000100 .text.head
# 0xffffffff8100e000-0xffffffff8100e200 kprobe_handler

# 등록된 모든 kprobe 확인
cat /sys/kernel/debug/kprobes/list
# ffffffff812a5f60  k  do_sys_openat2+0x0  [OPTIMIZED]
# ffffffff8130b2a0  r  vfs_read+0x0        [FTRACE]
# (k=kprobe, r=kretprobe)

# kprobe 전체 비활성화/재활성화 (디버깅 시 유용)
echo 0 > /sys/kernel/debug/kprobes/enabled   # 모든 kprobe 비활성화
echo 1 > /sys/kernel/debug/kprobes/enabled   # 재활성화

tracefs를 통한 kprobe 이벤트

커널 모듈 작성 없이 tracefs 인터페이스만으로도 kprobe 이벤트를 정의하고 사용할 수 있습니다.

T=/sys/kernel/tracing

# kprobe 이벤트 정의: do_sys_openat2 진입 시 첫 번째 인자(dfd)와 두 번째 인자(filename) 기록
echo 'p:myprobe do_sys_openat2 dfd=%di:s32 filename=+0(%si):string' > $T/kprobe_events

# kretprobe 이벤트 정의: vfs_read 반환값 기록
echo 'r:myretprobe vfs_read ret=$retval:s64' >> $T/kprobe_events

# 정의된 이벤트 확인
cat $T/kprobe_events

# 이벤트 활성화
echo 1 > $T/events/kprobes/myprobe/enable
echo 1 > $T/events/kprobes/myretprobe/enable

# 트레이싱 결과 확인
cat $T/trace_pipe
#  bash-1234 [002] .... 5678.901234: myprobe: (do_sys_openat2+0x0/0x...) dfd=-100 filename="/etc/passwd"
#  bash-1234 [002] d... 5678.901345: myretprobe: (SyS_read+0x../0x..) func=vfs_read ret=4096

# 이벤트 비활성화 및 제거
echo 0 > $T/events/kprobes/myprobe/enable
echo '-:myprobe' >> $T/kprobe_events
echo > $T/kprobe_events  # 모든 kprobe 이벤트 제거

Fetch 인자 구문 참조

tracefs kprobe 이벤트에서 인자를 캡처할 때 사용하는 fetch-arg 구문의 전체 참조입니다.

캡처된 값의 타입을 지정할 수 있습니다:

아키텍처별 레지스터 매핑

BTF 기반 kprobe (커널 5.8+)

커널 5.8부터 BTF(BPF Type Format) 정보를 활용하여 구조체 필드에 이름으로 접근할 수 있습니다. 레지스터 오프셋을 수동으로 계산할 필요 없이, 커널 데이터 구조를 타입 안전하게 탐색합니다.

T=/sys/kernel/tracing

# BTF 활성화 여부 확인
ls /sys/kernel/btf/vmlinux
# /sys/kernel/btf/vmlinux  (존재하면 BTF 활성)

# BTF 기반 kprobe: 구조체 필드를 이름으로 접근
# do_filp_open()의 pathname 인자에서 name 필드 추적
echo 'p:myprobe do_filp_open pathname=+0(%si):string' > $T/kprobe_events

# BPF 프로그램에서 BTF를 활용한 kprobe (bpftrace 예시)
# 구조체 필드에 직접 접근 가능 (오프셋 계산 불필요)
bpftrace -e '
kprobe:tcp_sendmsg {
    $sk = (struct sock *)arg0;
    $inet = (struct inet_sock *)$sk;
    printf("pid=%d dport=%d\n", pid,
           $inet->inet_dport);
}'

# BTF 기반 kprobe (커널 모듈에서 BPF 프로그램 사용)
# SEC("kprobe/tcp_sendmsg")를 사용하면
# BPF CO-RE (Compile Once, Run Everywhere)로
# 커널 버전 간 호환성 확보 가능

kprobe multi-attach (BPF, 커널 5.18+)

커널 5.18에서 도입된 BPF_LINK_TYPE_KPROBE_MULTI는 하나의 BPF 프로그램을 수천 개의 함수에 동시에 연결할 수 있습니다. 기존에는 함수마다 개별 kprobe를 등록해야 했으나, multi-attach는 fprobe(ftrace 기반 고속 프로브) 인프라를 사용하여 대량 프로브를 효율적으로 처리합니다.

# bpftrace에서 와일드카드로 다중 kprobe 사용
bpftrace -e 'kprobe:vfs_* { @[func] = count(); }'

# libbpf C 코드에서 kprobe.multi 사용 예시
# LIBBPF_OPTS(bpf_kprobe_multi_opts, opts);
# opts.syms = (const char *[]){"vfs_read", "vfs_write", ...};
# opts.cnt = n_syms;
# bpf_program__attach_kprobe_multi_opts(prog, NULL, &opts);

uprobes

uprobes(User-space Probes)는 유저 공간 프로그램의 함수나 임의 주소에 동적으로 프로브를 삽입하는 메커니즘입니다. 커널 3.5에서 Srikar Dronamraju 등이 도입했으며, kprobes와 유사한 원리로 동작하지만 대상이 유저 공간 바이너리입니다. 커널이 ELF 바이너리의 지정된 오프셋에 breakpoint를 삽입하고, 프로브가 적중하면 커널 내에서 핸들러를 실행합니다. 유저 공간 코드 수정 없이 애플리케이션 성능 분석, 함수 호출 추적, 메모리 할당 패턴 분석 등이 가능합니다.

내부 동작 메커니즘

uprobe의 동작은 kprobe와 유사하지만, 유저 공간 특유의 메커니즘이 추가됩니다. 핵심은 페이지 캐시 조작과 XOL(eXecute Out of Line) 영역입니다.

/* kernel/events/uprobes.c — 핵심 구조 (단순화) */
struct uprobe {
    struct rb_node       rb_node;     /* inode별 RB 트리 */
    struct inode        *inode;       /* 대상 ELF 파일 inode */
    loff_t               offset;      /* 파일 내 오프셋 */
    struct uprobe_consumer *consumers; /* 등록된 consumer 리스트 */
    struct arch_uprobe    arch;        /* 아키텍처별 정보 */
    refcount_t           ref;
    unsigned long        flags;
};

/*
 * XOL(eXecute Out of Line) 영역:
 * - 각 프로세스의 주소 공간에 할당되는 특수 페이지
 * - uprobe가 교체한 원래 명령어의 복사본을 저장
 * - single-step 실행 시 이 영역에서 원래 명령어를 실행
 * - 유저 공간에 매핑되지만 프로세스가 직접 접근할 수 없음
 */
struct xol_area {
    wait_queue_head_t   wq;          /* 슬롯 대기 큐 */
    unsigned long       *bitmap;     /* 슬롯 할당 비트맵 */
    struct page        *page;        /* XOL 페이지 */
    unsigned long        vaddr;       /* 프로세스 주소 공간의 가상 주소 */
};

tracefs를 통한 uprobe 사용

T=/sys/kernel/tracing

# 1. 심볼 오프셋 확인 — uprobe는 파일 오프셋을 사용 (가상 주소 아님)
# 방법 A: objdump
objdump -tT /bin/bash | grep readline
# 방법 B: readelf
readelf -s /bin/bash | grep readline
# 방법 C: nm (디버그 심볼 있는 경우)
nm /usr/bin/python3 | grep PyObject_Call

# 2. uprobe 이벤트 정의 (p=진입, r=반환)
echo 'p:bash_readline /bin/bash:0x4a2e0' > $T/uprobe_events

# 3. 인자 캡처 — 유저 공간 레지스터 접근
# x86_64: %di=arg1, %si=arg2 (C ABI와 동일)
echo 'p:malloc_call /usr/lib/x86_64-linux-gnu/libc.so.6:0x9d460 size=%di:u64' >> $T/uprobe_events

# 4. uretprobe: 반환값 캡처
echo 'r:malloc_ret /usr/lib/x86_64-linux-gnu/libc.so.6:0x9d460 ret=$retval:x64' >> $T/uprobe_events

# 5. 활성화 및 트레이싱
echo 1 > $T/events/uprobes/bash_readline/enable
echo 1 > $T/events/uprobes/malloc_call/enable
echo 1 > $T/events/uprobes/malloc_ret/enable
echo 1 > $T/tracing_on
cat $T/trace_pipe
#  bash-1234 [002] d... 5678.901: bash_readline: (0x55a0004a2e0)
#  bash-1234 [002] d... 5678.902: malloc_call: (0x7f...) size=128
#  bash-1234 [002] d... 5678.902: malloc_ret: (0x7f...) ret=0x55a0012f450

# 6. 정리
echo 0 > $T/events/uprobes/enable   # 모든 uprobe 이벤트 비활성화
echo > $T/uprobe_events              # 모든 uprobe 이벤트 제거

커널 API: uprobe_register

#include <linux/uprobes.h>

/* uprobe consumer — 프로브 적중 시 호출되는 콜백 */
struct uprobe_consumer {
    /* 프로브 진입 시 호출 (return 0 = 계속, return UPROBE_HANDLER_REMOVE = 제거) */
    int (*handler)(struct uprobe_consumer *self,
                   struct pt_regs *regs);
    /* 프로브 반환 시 호출 (uretprobe) */
    int (*ret_handler)(struct uprobe_consumer *self,
                        unsigned long func,
                        struct pt_regs *regs);
    /* 프로세스 필터 — true를 반환하는 프로세스만 추적 */
    bool (*filter)(struct uprobe_consumer *self,
                   struct mm_struct *mm);
};

/*
 * uprobe 등록
 * inode: 대상 ELF 파일의 inode (파일시스템 수준)
 * offset: 파일 내 오프셋 (가상 주소가 아님!)
 *         가상 주소 → 파일 오프셋 변환: objdump 또는 /proc/pid/maps 활용
 * uc: consumer 콜백 구조체
 */
int uprobe_register(struct inode *inode,
                    loff_t offset,
                    struct uprobe_consumer *uc);
void uprobe_unregister(struct inode *inode,
                      loff_t offset,
                      struct uprobe_consumer *uc);

/* uprobe_register_refctr: 세마포어 기반 uprobe (USDT용)
 * ref_ctr_offset: ELF .note.stapsdt 섹션의 참조 카운터 오프셋 */
int uprobe_register_refctr(struct inode *inode,
                          loff_t offset,
                          loff_t ref_ctr_offset,
                          struct uprobe_consumer *uc);

uretprobe 상세

uretprobe는 유저 공간 함수의 반환 시점을 캡처합니다. kretprobe와 유사하게 함수 진입 시 스택의 리턴 주소를 trampoline으로 교체하여 반환을 가로챕니다. tracefs에서는 r: 접두사로 정의합니다.

T=/sys/kernel/tracing

# uretprobe 활용 예시: 함수 실행 시간 측정
# SSL_read 진입/반환 추적으로 SSL 복호화 레이턴시 분석
echo 'p:ssl_read_entry /usr/lib/x86_64-linux-gnu/libssl.so.3:SSL_read' > $T/uprobe_events
echo 'r:ssl_read_ret /usr/lib/x86_64-linux-gnu/libssl.so.3:SSL_read ret=$retval:s32' >> $T/uprobe_events

# bpftrace로 uretprobe 사용 — 더 유연한 분석 가능
bpftrace -e '
uprobe:/usr/lib/x86_64-linux-gnu/libc.so.6:malloc {
    @start[tid] = nsecs;
    @size[tid] = arg0;
}
uretprobe:/usr/lib/x86_64-linux-gnu/libc.so.6:malloc /@start[tid]/ {
    $dur = nsecs - @start[tid];
    printf("malloc(%d) = %p [%d ns]\n", @size[tid], retval, $dur);
    delete(@start[tid]); delete(@size[tid]);
}'

USDT (User Statically Defined Tracing)

USDT는 유저 공간 프로그램에 미리 정의된 정적 트레이스포인트입니다. 커널의 tracepoints에 대응하는 유저 공간 버전으로, 개발자가 소스 코드에 프로브 포인트를 명시적으로 삽입합니다. USDT는 ELF .note.stapsdt 섹션에 메타데이터를 저장하며, uprobe 인프라 위에서 동작합니다.

# USDT 프로브가 포함된 바이너리 확인
readelf -n /usr/lib/x86_64-linux-gnu/libc.so.6 | grep -A4 stapsdt
# stapsdt    0x00000039    NT_STAPSDT (SystemTap probe descriptors)
#     Provider: libc
#     Name: memory_malloc_retry
#     Location: 0x00000000000973a0, Base: 0x..., Semaphore: 0x...

# Python USDT 프로브 확인
bpftrace -l 'usdt:/usr/bin/python3:*'
# usdt:/usr/bin/python3:python:function__entry
# usdt:/usr/bin/python3:python:function__return
# usdt:/usr/bin/python3:python:gc__start
# usdt:/usr/bin/python3:python:gc__done

# Python 함수 호출 추적 (USDT)
bpftrace -e '
usdt:/usr/bin/python3:python:function__entry {
    printf("%s %s:%d\n", str(arg0), str(arg1), arg2);
}' -p $(pidof python3)

# MySQL/MariaDB 쿼리 추적 (USDT)
bpftrace -e '
usdt:/usr/sbin/mysqld:mysql:query__start {
    printf("query: %s\n", str(arg0));
}'

/* USDT 프로브 정의 (C 소스에서) — SystemTap SDT 헤더 사용 */
#include <sys/sdt.h>

void process_request(struct request *req)
{
    /* USDT 프로브: provider=myapp, name=request_start */
    DTRACE_PROBE2(myapp, request_start, req->id, req->size);

    /* ... 실제 처리 ... */

    DTRACE_PROBE1(myapp, request_done, req->id);
}

/*
 * 빌드: gcc -o myapp myapp.c (SDT NOP이 자동 삽입)
 * 프로브 비활성 시: NOP 명령어로 오버헤드 거의 0
 * 프로브 활성 시: NOP → int3 교체 (uprobe 메커니즘)
 *
 * USDT 세마포어:
 * - .note.stapsdt에 Semaphore 필드가 있으면
 *   uprobe 등록 시 세마포어 카운터를 증가
 *   프로그램이 세마포어를 확인하여 추가 데이터를 수집할 수 있음
 *   uprobe_register_refctr()로 세마포어 지원 등록
 */

perf probe를 이용한 uprobe

perf probe는 tracefs를 직접 조작하지 않고도 uprobe를 편리하게 등록/관리할 수 있는 도구입니다. DWARF 디버그 정보가 있으면 함수 이름과 변수 이름으로 직접 접근할 수 있습니다.

# 디버그 심볼이 있는 바이너리에서 사용 가능한 프로브 포인트 확인
perf probe -x /usr/lib/x86_64-linux-gnu/libc.so.6 -F | grep malloc
# __libc_malloc
# __libc_calloc

# uprobe 등록 (perf probe)
perf probe -x /usr/lib/x86_64-linux-gnu/libc.so.6 --add 'malloc_entry=__libc_malloc size'

# DWARF 변수 접근 — 디버그 심볼 필요 (-dbg 패키지 설치)
perf probe -x /usr/bin/python3 --add 'pymain=Py_Main argc'

# 등록된 프로브로 레코딩
perf record -e probe_libc:malloc_entry -aR -- sleep 5
perf script
#  python3  1234 [001]  5678.901: probe_libc:malloc_entry: (7f...+0x9d460) size=128

# 프로브 목록 확인 및 삭제
perf probe --list
perf probe --del malloc_entry

uprobe와 BPF

BPF 프로그램을 uprobe에 연결하면, 유저 공간 함수의 인자/반환값을 안전하게 캡처하고 BPF 맵으로 집계할 수 있습니다. bpf_probe_read_user() 헬퍼로 유저 공간 메모리를 안전하게 읽으며, 커널 5.5+에서는 bpf_probe_read_user_str()로 유저 공간 문자열도 읽을 수 있습니다.

/* BPF 프로그램 (libbpf CO-RE 스타일) */
SEC("uprobe//usr/lib/x86_64-linux-gnu/libc.so.6:malloc")
int BPF_KPROBE(malloc_enter, size_t size)
{
    u32 pid = bpf_get_current_pid_tgid() >> 32;
    bpf_printk("pid=%d malloc(%zu)\n", pid, size);

    /* BPF 맵에 할당 크기 히스토그램 기록 */
    u64 slot = bpf_log2l(size);
    bpf_map_update_elem(&alloc_hist, &slot, &(u64){1}, BPF_ANY);
    return 0;
}

SEC("uretprobe//usr/lib/x86_64-linux-gnu/libc.so.6:malloc")
int BPF_KRETPROBE(malloc_exit, void *ret)
{
    /* 반환된 포인터 (할당된 메모리 주소) 기록 */
    u32 pid = bpf_get_current_pid_tgid() >> 32;
    bpf_printk("pid=%d malloc returned %p\n", pid, ret);
    return 0;
}

/*
 * uprobe.multi (커널 6.6+):
 * - kprobe.multi와 유사하게 하나의 BPF 프로그램을
 *   여러 uprobe에 동시 연결
 * - SEC("uprobe.multi") 사용
 * - 대량의 함수를 추적할 때 효율적
 */

제약사항과 고려사항

perf 이벤트

perf는 Linux 커널에 내장된 성능 분석 도구입니다. perf_event_open(2) 시스템 콜을 기반으로 하드웨어 PMU(Performance Monitoring Unit), 소프트웨어 이벤트, tracepoints, kprobes 등 다양한 이벤트 소스를 통합적으로 활용합니다.

perf_event_open 시스템 콜

#include <linux/perf_event.h>
#include <sys/syscall.h>

/* perf_event_attr: 이벤트 설정 구조체 */
struct perf_event_attr attr = {
    .type           = PERF_TYPE_HARDWARE,        /* 이벤트 유형 */
    .size           = sizeof(struct perf_event_attr),
    .config         = PERF_COUNT_HW_CPU_CYCLES,  /* CPU 사이클 카운트 */
    .disabled       = 1,                          /* 생성 시 비활성 */
    .exclude_kernel = 0,                          /* 커널 포함 */
    .exclude_hv     = 1,                          /* 하이퍼바이저 제외 */
    .sample_period  = 100000,                     /* 샘플 주기 */
    .sample_type    = PERF_SAMPLE_IP |
                      PERF_SAMPLE_TID |
                      PERF_SAMPLE_CALLCHAIN,
};

/* 시스템 콜로 perf 이벤트 생성 */
int fd = syscall(__NR_perf_event_open, &attr,
                 pid,     /* 대상 PID (-1 = 모든 프로세스) */
                 cpu,     /* 대상 CPU (-1 = 모든 CPU) */
                 group_fd,/* 그룹 리더 fd (-1 = 새 그룹) */
                 flags);  /* PERF_FLAG_FD_CLOEXEC 등 */

/* 이벤트 활성화/비활성화 */
ioctl(fd, PERF_EVENT_IOC_ENABLE, 0);
ioctl(fd, PERF_EVENT_IOC_DISABLE, 0);

/* 카운터 읽기 */
long long count;
read(fd, &count, sizeof(count));

이벤트 유형

perf 커맨드라인 도구

# === perf stat: 성능 카운터 요약 ===

# 기본 통계
perf stat ls
# Performance counter stats for 'ls':
#        1.23 msec  task-clock                #    0.723 CPUs utilized
#            3      context-switches           #    2.439 K/sec
#            0      cpu-migrations             #    0.000 /sec
#          112      page-faults                #   91.057 K/sec
#    3,456,789      cycles                     #    2.811 GHz
#    2,345,678      instructions               #    0.68  insn per cycle
#      456,789      branches                   #  371.373 M/sec
#       12,345      branch-misses              #    2.70% of all branches

# 특정 이벤트 지정
perf stat -e cycles,instructions,cache-misses,LLC-load-misses ./workload

# 시스템 전체 10초간 수집
perf stat -a -d sleep 10

# 특정 CPU에서 수집
perf stat -C 0,1,2,3 -e instructions sleep 5


# === perf record / perf report: 샘플링 프로파일링 ===

# CPU 사이클 기반 프로파일링 (콜스택 포함)
perf record -g ./workload

# 결과 분석
perf report
# Overhead  Command  Shared Object      Symbol
#  25.30%   workload [kernel.vmlinux]  [k] __schedule
#  12.45%   workload libc.so.6         [.] __memmove_avx_unaligned
#   8.90%   workload [kernel.vmlinux]  [k] copy_user_enhanced_fast_string

# 커널 전체 프로파일링 (30초)
perf record -a -g -- sleep 30

# 특정 이벤트로 프로파일링
perf record -e cache-misses -c 10000 -g ./workload

# tracepoint 이벤트 기록
perf record -e sched:sched_switch -a -- sleep 5


# === perf top: 실시간 프로파일링 ===

# 시스템 전체 실시간 모니터링 (top과 유사)
perf top
perf top -e cache-misses
perf top -p 1234  # 특정 프로세스

trace-cmd

trace-cmd는 ftrace의 tracefs 인터페이스를 추상화한 커맨드라인 프론트엔드입니다. tracefs 파일을 직접 조작하는 것보다 훨씬 편리하게 트레이싱을 수행할 수 있습니다. Steven Rostedt(ftrace 개발자)가 만들었습니다.

기본 사용법

# === trace-cmd record: 트레이싱 데이터 수집 ===

# 스케줄러 이벤트 기록
trace-cmd record -e sched_switch -e sched_wakeup sleep 5

# function_graph 트레이서로 특정 함수 추적
trace-cmd record -p function_graph -g do_sys_openat2 ls

# 여러 이벤트와 함수 필터 조합
trace-cmd record -p function \
    -l 'tcp_*' \
    -e net:net_dev_xmit \
    -e tcp:tcp_retransmit_skb \
    -- curl -s https://example.com > /dev/null

# 특정 PID만 트레이싱
trace-cmd record -P 1234 -e sched_switch

# 시스템 전체 이벤트 수집 (5초)
trace-cmd record -e all sleep 5


# === trace-cmd report: 결과 분석 ===

# 기본 출력
trace-cmd report
#      <idle>-0   [003] 12345.678: sched_switch: prev_comm=swapper ...
#        bash-1234 [001] 12345.679: sched_wakeup: comm=kworker ...

# 특정 이벤트만 필터링
trace-cmd report -F 'sched_switch'

# 특정 CPU만 출력
trace-cmd report --cpu 0

# 타임스탬프 범위 필터
trace-cmd report -t --ts-offset=12345.000

# 다른 파일 지정
trace-cmd report -i trace.dat


# === trace-cmd 기타 서브커맨드 ===

# 사용 가능한 이벤트 목록
trace-cmd list -e

# 사용 가능한 트레이서 목록
trace-cmd list -t

# 사용 가능한 필터 함수
trace-cmd list -f

# 실시간 스트리밍 (trace_pipe와 유사)
trace-cmd stream -e sched_switch

# ftrace 설정 초기화
trace-cmd reset

KernelShark

KernelShark는 trace-cmd의 데이터를 시각화하는 GUI 도구입니다. 타임라인 기반으로 이벤트, CPU 활용, 프로세스 스케줄링을 그래픽으로 분석할 수 있습니다.

# trace-cmd로 데이터 수집 후 KernelShark로 시각화
trace-cmd record -e sched_switch -e sched_wakeup -e irq -a sleep 10
kernelshark trace.dat

# KernelShark 설치 (Ubuntu/Debian)
apt install kernelshark

# KernelShark 주요 기능:
# - CPU별 타임라인 뷰
# - 프로세스별 색상 구분
# - 이벤트 필터링 (정규식, 이벤트 유형)
# - 두 이벤트 간 시간 차이 측정 (마커)
# - 이벤트 그래프, 히스토그램

perf ftrace

perf ftrace는 perf 도구 내에서 ftrace 기능을 사용할 수 있게 하는 서브커맨드입니다. tracefs를 직접 조작하지 않고 perf의 통합된 인터페이스로 ftrace를 사용할 수 있습니다.

# 기본 function trace (현재 실행중인 시스템)
perf ftrace -T schedule sleep 1

# function_graph tracer
perf ftrace --graph -G do_sys_openat2 ls

# 특정 함수만 필터
perf ftrace -T 'tcp_sendmsg' -T 'tcp_recvmsg' -- curl -s https://example.com

# 특정 함수 제외
perf ftrace -N 'rcu_*' -T 'schedule*' sleep 1

# 호출 깊이 제한
perf ftrace --graph --graph-depth 3 -G __x64_sys_read cat /dev/null

# perf ftrace latency: 함수 레이턴시 히스토그램
perf ftrace latency -T do_sys_openat2 -a sleep 5
#                  DURATION     |  COUNT | GRAPH
#    0 - 1    us   |      0 |
#    1 - 2    us   |     15 | ###
#    2 - 4    us   |    124 | ##########################
#    4 - 8    us   |     89 | ###################
#    8 - 16   us   |     23 | #####
#   16 - 32   us   |      3 | #
#   32 - 64   us   |      1 |

이벤트 트리거

이벤트 트리거(Event Triggers)는 tracepoint 이벤트가 발생할 때 자동으로 특정 동작을 수행하는 메커니즘입니다. 조건부 트레이싱, 스냅샷 캡처, 히스토그램 생성 등에 활용됩니다.

기본 트리거

T=/sys/kernel/tracing

# traceon/traceoff 트리거: 특정 이벤트 발생 시 트레이싱 on/off
# sched_switch에서 next_pid가 0이면 트레이싱 중지
echo 'traceoff if next_pid == 0' > $T/events/sched/sched_switch/trigger

# snapshot 트리거: 이벤트 발생 시 버퍼 스냅샷 저장
echo 'snapshot if prev_state == 2' > $T/events/sched/sched_switch/trigger
cat $T/snapshot  # 스냅샷 확인

# stacktrace 트리거: 이벤트 발생 시 스택 트레이스 기록
echo 'stacktrace' > $T/events/kmem/kmalloc/trigger

# 특정 횟수만 트리거 (count:N)
echo 'traceoff:1' > $T/events/sched/sched_switch/trigger  # 한 번만

# 트리거 확인
cat $T/events/sched/sched_switch/trigger

# 트리거 제거 (앞에 ! 추가)
echo '!traceoff' > $T/events/sched/sched_switch/trigger

hist 트리거 (히스토그램)

hist 트리거는 이벤트 데이터의 분포를 히스토그램으로 집계합니다. 커널 4.7에서 도입되었으며, 커널 내에서 실시간으로 데이터를 집계하므로 대량의 이벤트 데이터를 효율적으로 분석할 수 있습니다.

T=/sys/kernel/tracing

# 시스템 콜별 호출 빈도 히스토그램
echo 'hist:key=id:sort=hitcount:size=64' > \
    $T/events/raw_syscalls/sys_enter/trigger
sleep 5
cat $T/events/raw_syscalls/sys_enter/hist
# { id:   0 } hitcount:     12345
# { id:   1 } hitcount:      6789
# { id: 262 } hitcount:      3456

# 프로세스별 스케줄링 횟수
echo 'hist:key=next_comm:sort=hitcount.descending' > \
    $T/events/sched/sched_switch/trigger
sleep 10
cat $T/events/sched/sched_switch/hist

# 복합 키: CPU + 이전 프로세스별 컨텍스트 스위치
echo 'hist:keys=common_cpu,prev_comm:sort=hitcount' > \
    $T/events/sched/sched_switch/trigger

# 레이턴시 히스토그램 (값 필드 사용)
echo 'hist:key=common_pid.execname:val=bytes_req:sort=bytes_req.descending' > \
    $T/events/kmem/kmalloc/trigger

# 히스토그램 초기화
echo 'hist:key=id:clear' > $T/events/raw_syscalls/sys_enter/trigger

# 히스토그램 트리거 제거
echo '!hist:key=id' > $T/events/raw_syscalls/sys_enter/trigger

Synthetic Events

Synthetic events(합성 이벤트)는 여러 이벤트를 결합하여 새로운 이벤트를 생성합니다. 예를 들어, 함수 진입과 반환 이벤트를 결합하여 실행 시간을 계산할 수 있습니다.

T=/sys/kernel/tracing

# 합성 이벤트 정의: 스케줄링 레이턴시 (wakeup → switch 시간 차이)
echo 'wakeup_lat u64 lat; pid_t pid; char comm[16]' > $T/synthetic_events

# sched_wakeup에서 타임스탬프 저장
echo 'hist:keys=pid:ts0=common_timestamp.usecs' > \
    $T/events/sched/sched_wakeup/trigger

# sched_switch에서 레이턴시 계산 및 합성 이벤트 생성
echo 'hist:keys=next_pid:lat=common_timestamp.usecs-$ts0:onmatch(sched.sched_wakeup).trace(wakeup_lat,$lat,next_pid,next_comm)' > \
    $T/events/sched/sched_switch/trigger

# 합성 이벤트 히스토그램
echo 'hist:keys=comm:vals=lat:sort=lat.descending' > \
    $T/events/synthetic/wakeup_lat/trigger

# 결과 확인
sleep 10
cat $T/events/synthetic/wakeup_lat/hist

bpftrace

bpftrace는 BPF(eBPF)를 기반으로 한 고수준 동적 트레이싱 언어입니다. AWK에서 영감을 받은 간결한 문법으로 복잡한 트레이싱 작업을 한 줄로 수행할 수 있습니다. 내부적으로 LLVM을 사용하여 BPF 바이트코드로 컴파일합니다.

프로브 유형

원라이너 예제

# 시스템 콜별 호출 빈도 (Ctrl+C로 종료 시 출력)
bpftrace -e 'tracepoint:raw_syscalls:sys_enter { @[comm] = count(); }'

# 프로세스별 read() 바이트 히스토그램
bpftrace -e 'kretprobe:vfs_read /retval > 0/ { @bytes[comm] = hist(retval); }'

# 스케줄링 레이턴시 (wakeup → on-cpu)
bpftrace -e '
tracepoint:sched:sched_wakeup {
    @qtime[args->pid] = nsecs;
}
tracepoint:sched:sched_switch /args->next_pid/ {
    $ns = @qtime[args->next_pid];
    if ($ns) {
        @usecs = hist((nsecs - $ns) / 1000);
    }
    delete(@qtime[args->next_pid]);
}'

# open() 시스템 콜로 열리는 파일 추적
bpftrace -e 'tracepoint:syscalls:sys_enter_openat { printf("%s %s\n", comm, str(args->filename)); }'

# 블록 I/O 레이턴시 히스토그램
bpftrace -e '
kprobe:blk_account_io_start { @start[arg0] = nsecs; }
kprobe:blk_account_io_done /@start[arg0]/ {
    @usecs = hist((nsecs - @start[arg0]) / 1000);
    delete(@start[arg0]);
}'

# TCP retransmit 추적
bpftrace -e 'kprobe:tcp_retransmit_skb {
    @[kstack] = count();
}'

# 1초마다 컨텍스트 스위치 수 출력
bpftrace -e 'tracepoint:sched:sched_switch { @++; }
interval:s:1 { print(@); clear(@); }'

# 커널 메모리 할당 (kmalloc) 크기 분포
bpftrace -e 'tracepoint:kmem:kmalloc { @size = hist(args->bytes_alloc); }'

# 특정 프로세스의 페이지 폴트 스택 트레이스
bpftrace -e 'software:page-faults:1 /comm == "myapp"/ { @[kstack, ustack] = count(); }'

커널 새니타이저 연동

커널 새니타이저(KASAN, KCSAN, UBSAN, KMSAN)는 메모리 오류, 데이터 레이스, 정의되지 않은 동작, 초기화되지 않은 메모리 사용을 탐지합니다. 이 새니타이저들은 ftrace 이벤트를 통해 탐지 결과를 보고하며, 트레이싱 도구와 결합하여 더 상세한 분석이 가능합니다.

KASAN (Kernel Address Sanitizer)

# KASAN 활성화를 위한 커널 CONFIG
CONFIG_KASAN=y
CONFIG_KASAN_GENERIC=y          # 소프트웨어 기반 (느리지만 범용)
# CONFIG_KASAN_SW_TAGS=y        # ARM64 MTE 기반
# CONFIG_KASAN_HW_TAGS=y        # ARM64 하드웨어 MTE 기반
CONFIG_KASAN_INLINE=y           # 인라인 계측 (더 빠름)
CONFIG_STACKTRACE=y

# KASAN 오류 보고 예시 (dmesg)
# BUG: KASAN: slab-out-of-bounds in kmalloc_oob_right+0x6c/0x94
# Write of size 1 at addr ffff8881234abcde by task test/1234
# Call Trace:
#  dump_stack_lvl+0x34/0x48
#  print_report+0x170/0x4a0
#  kasan_report+0xc0/0x100
#  kmalloc_oob_right+0x6c/0x94

# ftrace와 KASAN 결합: KASAN 보고 직전 함수 호출 추적
echo 'stacktrace' > /sys/kernel/tracing/events/kasan/kasan_report/trigger
echo 1 > /sys/kernel/tracing/events/kasan/kasan_report/enable

KCSAN (Kernel Concurrency Sanitizer)

# KCSAN: 데이터 레이스 탐지
CONFIG_KCSAN=y
CONFIG_KCSAN_STRICT=y           # 엄격 모드
CONFIG_KCSAN_REPORT_ONCE_IN_MS=3000
CONFIG_KCSAN_VERBOSE=y

# KCSAN 오류 보고 예시
# BUG: KCSAN: data-race in process_one_work / schedule_work
# write to 0xffff88810abcdef0 of 8 bytes by task 1234 on cpu 2:
#  process_one_work+0x1a3/0x5d0
# read to 0xffff88810abcdef0 of 8 bytes by task 5678 on cpu 5:
#  schedule_work+0x56/0x90

# perf로 KCSAN 이벤트 기록
perf record -e kcsan:kcsan_report -a -- sleep 60
perf report

UBSAN (Undefined Behavior Sanitizer)

# UBSAN: 정의되지 않은 동작 탐지
CONFIG_UBSAN=y
CONFIG_UBSAN_BOUNDS=y           # 배열 범위 검사
CONFIG_UBSAN_SHIFT=y            # 시프트 오버플로우
CONFIG_UBSAN_DIV_ZERO=y         # 0으로 나누기
CONFIG_UBSAN_SIGNED_OVERFLOW=y  # 부호 있는 정수 오버플로우

# UBSAN 오류 예시
# UBSAN: shift-out-of-bounds in drivers/xxx/yyy.c:123:4
# shift exponent 64 is too large for 64-bit type 'unsigned long'

KMSAN (Kernel Memory Sanitizer)

# KMSAN: 초기화되지 않은 메모리 사용 탐지 (커널 6.1+)
CONFIG_KMSAN=y

# KMSAN은 KASAN과 동시 사용 불가
# Clang 컴파일러 필수 (GCC 미지원)

# 트레이싱과 새니타이저 결합 활용
# bpftrace로 KASAN 오류 발생 시 컨텍스트 정보 수집
bpftrace -e 'kprobe:kasan_report {
    printf("KASAN report by %s (pid=%d) on CPU %d\n",
           comm, pid, cpu);
    print(kstack);
}'

실전 디버깅 시나리오

실제 커널 디버깅 상황에서 트레이싱 도구를 어떻게 활용하는지 구체적인 시나리오를 통해 살펴봅니다.

시나리오 1: 스케줄링 레이턴시 추적

프로세스가 깨어난 후 실제 CPU에서 실행되기까지의 지연 시간이 비정상적으로 긴 경우를 분석합니다.

# 방법 1: ftrace의 wakeup_rt 트레이서
T=/sys/kernel/tracing
echo 0 > $T/tracing_on
echo wakeup_rt > $T/current_tracer
echo 1 > $T/tracing_on
# 워크로드 실행 후...
echo 0 > $T/tracing_on
cat $T/trace
# 최대 레이턴시를 유발한 스케줄링 경로가 출력됨

# 방법 2: perf sched 서브커맨드
perf sched record -- sleep 10
perf sched latency
# -------------------------------------------------
#  Task              |   Runtime   |  Switches  |  Avg delay
# -------------------------------------------------
#  myapp:1234        |  2345.678ms |       567  |  avg:  0.45ms max: 12.3ms
#  kworker/2:1:89    |   123.456ms |       234  |  avg:  0.12ms max:  3.4ms

perf sched timehist
# 타임라인 기반 스케줄링 이력

# 방법 3: bpftrace 원라이너
bpftrace -e '
tracepoint:sched:sched_wakeup /args->comm == "myapp"/ {
    @ts[args->pid] = nsecs;
}
tracepoint:sched:sched_switch /args->next_comm == "myapp" && @ts[args->next_pid]/ {
    $lat = (nsecs - @ts[args->next_pid]) / 1000;
    printf("myapp wakeup latency: %d us\n", $lat);
    if ($lat > 1000) {
        printf("  HIGH LATENCY! stack:\n");
        print(kstack);
    }
    delete(@ts[args->next_pid]);
}'

시나리오 2: 함수 호출 경로 분석

특정 시스템 콜이 커널 내부에서 어떤 경로로 실행되는지 상세히 추적합니다.

# function_graph로 sys_read의 전체 호출 트리 추적
T=/sys/kernel/tracing

echo 0 > $T/tracing_on
echo function_graph > $T/current_tracer
echo '__x64_sys_read' > $T/set_graph_function
echo 5 > $T/max_graph_depth       # 깊이 제한
echo $$ > $T/set_ftrace_pid       # 현재 셸만 추적
echo > $T/trace
echo 1 > $T/tracing_on
cat /dev/null                          # read 시스템 콜 트리거
echo 0 > $T/tracing_on
cat $T/trace

# trace-cmd 사용 (더 편리)
trace-cmd record -p function_graph \
    -g __x64_sys_read \
    --max-graph-depth 5 \
    -P $$ \
    -- cat /dev/null

trace-cmd report

시나리오 3: Flame Graph 생성

Flame graph는 Brendan Gregg가 고안한 시각화 기법으로, CPU 프로파일 데이터를 직관적으로 표현합니다. perf와 결합하여 커널과 유저 공간의 병목을 한눈에 파악할 수 있습니다.

# 1단계: perf로 프로파일 데이터 수집
perf record -F 99 -a -g -- sleep 30
# -F 99: 99Hz 샘플링 (lockstep 방지를 위해 100이 아닌 99 사용)
# -a: 모든 CPU
# -g: 콜 그래프 (스택 트레이스)

# 2단계: perf script로 텍스트 변환
perf script > out.perf

# 3단계: FlameGraph 도구로 변환
# (https://github.com/brendangregg/FlameGraph)
./stackcollapse-perf.pl out.perf > out.folded
./flamegraph.pl out.folded > flamegraph.svg

# Off-CPU flame graph (I/O 대기 시간 분석)
# bpftrace로 off-cpu 스택 수집
bpftrace -e '
tracepoint:sched:sched_switch {
    @start[tid] = nsecs;
}
tracepoint:sched:sched_switch /@start[args->next_pid]/ {
    $delta = nsecs - @start[args->next_pid];
    @off[kstack(args->prev_pid), comm] = sum($delta);
    delete(@start[args->next_pid]);
}
END { print(@off); }' > offcpu.txt

# 또는 perf의 offcpu 프로파일링 (커널 6.7+)
perf record --off-cpu -a -g -- sleep 30

시나리오 4: I/O 레이턴시 분석

# 블록 I/O 이벤트 추적
trace-cmd record -e block:block_rq_issue -e block:block_rq_complete \
    -e block:block_bio_queue sleep 10
trace-cmd report

# bpftrace로 I/O 레이턴시 히스토그램
bpftrace -e '
tracepoint:block:block_rq_issue {
    @start[args->dev, args->sector] = nsecs;
}
tracepoint:block:block_rq_complete /@start[args->dev, args->sector]/ {
    $lat = (nsecs - @start[args->dev, args->sector]) / 1000;
    @us_hist = hist($lat);
    if ($lat > 10000) {
        printf("slow I/O: %d us, dev=%d, sector=%lu, comm=%s\n",
               $lat, args->dev, args->sector, comm);
    }
    delete(@start[args->dev, args->sector]);
}'

# perf로 I/O 이벤트 기반 프로파일링
perf record -e block:block_rq_issue -e block:block_rq_complete \
    -a -g -- sleep 30
perf script | head -50

시나리오 5: 네트워크 패킷 경로 추적

# 네트워크 스택의 주요 함수 호출 추적
trace-cmd record -p function_graph \
    -g ip_rcv \
    -g tcp_v4_rcv \
    -g __dev_queue_xmit \
    --max-graph-depth 4 \
    -- ping -c 3 8.8.8.8
trace-cmd report

# TCP 재전송 추적 및 원인 분석
bpftrace -e 'kprobe:tcp_retransmit_skb {
    $sk = (struct sock *)arg0;
    $inet = (struct inet_sock *)arg0;
    printf("retransmit: pid=%d comm=%s saddr=%s sport=%d\n",
           pid, comm,
           ntop($inet->inet_saddr),
           $inet->inet_sport);
    print(kstack);
}'

# 네트워크 이벤트 종합 트레이싱
perf record -e net:net_dev_xmit \
    -e net:netif_receive_skb \
    -e tcp:tcp_retransmit_skb \
    -e tcp:tcp_send_reset \
    -a -- sleep 60

도구 선택 가이드

상황에 따라 적절한 트레이싱 도구를 선택하는 것이 중요합니다.

CONFIG 옵션 종합

트레이싱 관련 커널 CONFIG 옵션을 정리합니다.

# ===== ftrace 기본 =====
CONFIG_FTRACE=y                     # ftrace 프레임워크
CONFIG_FUNCTION_TRACER=y            # function 트레이서
CONFIG_FUNCTION_GRAPH_TRACER=y      # function_graph 트레이서
CONFIG_DYNAMIC_FTRACE=y             # 동적 ftrace (NOP 패칭)
CONFIG_FPROBE=y                     # fprobe (ftrace 기반 kprobe 대체)

# ===== tracepoints / 이벤트 =====
CONFIG_TRACEPOINTS=y                # tracepoint 지원
CONFIG_EVENT_TRACING=y              # 이벤트 트레이싱
CONFIG_HIST_TRIGGERS=y              # hist 트리거

# ===== kprobes / uprobes =====
CONFIG_KPROBES=y                    # kprobe 지원
CONFIG_KRETPROBES=y                 # kretprobe 지원
CONFIG_HAVE_KPROBES=y               # 아키텍처 지원
CONFIG_KPROBE_EVENTS=y              # tracefs kprobe 이벤트
CONFIG_UPROBES=y                    # uprobe 지원
CONFIG_UPROBE_EVENTS=y              # tracefs uprobe 이벤트

# ===== perf =====
CONFIG_PERF_EVENTS=y                # perf 이벤트 시스템
CONFIG_HW_PERF_EVENTS=y             # 하드웨어 PMU

# ===== BPF (bpftrace용) =====
CONFIG_BPF=y                        # BPF 시스템
CONFIG_BPF_SYSCALL=y                # bpf() 시스템 콜
CONFIG_BPF_JIT=y                    # BPF JIT 컴파일
CONFIG_BPF_EVENTS=y                 # BPF 이벤트 연결

# ===== 디버그 정보 =====
CONFIG_DEBUG_INFO=y                 # DWARF 디버그 심볼
CONFIG_DEBUG_INFO_BTF=y             # BTF (BPF Type Format)
CONFIG_FRAME_POINTER=y              # 정확한 스택 트레이스
CONFIG_STACKTRACE=y                 # 스택 트레이스 지원