eBPF 또는 perf를 사용하여 개별 추적 함수에서 소비 한 시간을 계산할 수 있습니까?

Question

현재 trace-cmd (ftrace 프런트 엔드)에 ftrace의 기능 그래프 인프라를 사용하여 지정된 작업을 추적 할 수 있습니다. 일부 추적 데이터 처리 도구를 사용하여 함수가 호출 된 빈도와 각 함수 호출의 해당 총 지속 기간을 볼 수 있습니다. 예 출력이 내 작업 부하에 의해 생성 된 ext4 함수 호출 추적 다음과 같이 보일 수 있습니다 : 나는 eBPF 생성 할 수있는 놀라운 flame graphs 본 적이

# trace-cmd post-processing example output 
# function name, frequency, total duration (us) 
ext4_alloc_inode(),1,35.567 
ext4_read_inode_bitmap(),1,12.076 
ext4_init_io_end(),2,41.216 
ext4_journal_check_start(),39,716.3 
ext4_da_write_end(),10,102.661 
ext4_da_get_block_prep(),9,257.46999999999997 
ext4_block_write_begin(),2,88.069 
ext4_bio_write_page(),1,33.016 

, systemtap, perf 등에 저를 인도하는 나는 perf 또는 eBPF을 사용하여 내 trace-cmd 출력과 비슷한 출력을 얻을 수 있어야한다고 생각합니다. 그러나, 몇 가지 장애물이 있습니다

1. 내 부하 내가 perf를 사용한다면 엄청난 로그를 생성 할 수있는 최대 15 분 동안 실행할 수 있습니다. 참고로, 더 짧은 시간 동안 bash를 추적 한 example output을 볼 수 있습니다.
2. 후불 출력 예 trace-cmd과 비슷한 데이터/출력을 얻을 수 있는지 여부를 확인하려면 충분히 익숙하지 않습니다. eBPFeBPF 또는 나보다 perf 더 잘 알고있는 분들을 위해

, 내가 알고 싶습니다 :

• 내 목표를 달성하기 위해 eBPF 또는 perf를 사용할 수 있습니까?
• 그렇다면 왜 가능합니까?

내 목표를 달성하는 데 도움이되는 샘플 코드/명령을 사용하면 만족할 것입니다.

Answer 1

물론 eBPF를 사용하여이를 수행 할 수 있습니다.

사실 the bcc tools과 비슷한 기능을하는 도구가 있습니다. funclatency 함수의 집합을 추적하고 그들의 대기 시간 (각 통화의 기능에 소요되는 시간)의 히스토그램 표시 :

# ./funclatency do_sys_open 
Tracing do_sys_open... Hit Ctrl-C to end. 
^C 
    nsecs   : count  distribution 
     0 -> 1  : 0  |          | 
     2 -> 3  : 0  |          | 
     4 -> 7  : 0  |          | 
     8 -> 15  : 0  |          | 
     16 -> 31  : 0  |          | 
     32 -> 63  : 0  |          | 
     64 -> 127  : 0  |          | 
    128 -> 255  : 0  |          | 
    256 -> 511  : 0  |          | 
    512 -> 1023  : 0  |          | 
    1024 -> 2047  : 0  |          | 
    2048 -> 4095  : 124  |****************      | 
    4096 -> 8191  : 291  |**************************************| 
    8192 -> 16383 : 36  |****         | 
    16384 -> 32767 : 16  |**         | 
    32768 -> 65535 : 8  |*          | 
    65536 -> 131071 : 0  |          | 
    131072 -> 262143 : 0  |          | 
    262144 -> 524287 : 0  |          | 
    524288 -> 1048575 : 0  |          | 
1048576 -> 2097151 : 0  |          | 
2097152 -> 4194303 : 1  |          | 
Detaching... 

이 funclatency에서 시작을, 당신이 무엇을 찾고 있는지 않는 도구를 유도하기 위해 오히려 쉽게 :

from __future__ import print_function 
from bcc import BPF 
from time import sleep, strftime 
import argparse 

parser = argparse.ArgumentParser(
    description="Time functions and print time spent in each function", 
    formatter_class=argparse.RawDescriptionHelpFormatter) 
parser.add_argument("-p", "--pid", type=int, help="trace this PID only") 
parser.add_argument("pattern", help="search expression for functions") 
args = parser.parse_args() 

# define BPF program 
bpf_text = """ 
#include <uapi/linux/ptrace.h> 

struct stats_t { 
    u64 time; 
    u64 freq; 
}; 
BPF_HASH(start, u32); 
BPF_HASH(ipaddr, u32); 
BPF_HASH(stats, u64, struct stats_t); 

int trace_func_entry(struct pt_regs *ctx) 
{ 
    u64 pid_tgid = bpf_get_current_pid_tgid(); 
    u32 pid = pid_tgid; 
    u64 ts = bpf_ktime_get_ns(); 

    u64 ip = PT_REGS_IP(ctx); 
    ipaddr.update(&pid, &ip); 
    start.update(&pid, &ts); 

    return 0; 
} 

int trace_func_return(struct pt_regs *ctx) 
{ 
    u64 *tsp, delta; 
    u64 pid_tgid = bpf_get_current_pid_tgid(); 
    u32 pid = pid_tgid; 

    // calculate delta time 
    tsp = start.lookup(&pid); 
    if (tsp == 0) { 
     return 0; // missed start 
    } 
    delta = bpf_ktime_get_ns() - *tsp; 
    start.delete(&pid); 

    // store as histogram 
    u64 ip, *ipp = ipaddr.lookup(&pid); 
    if (ipp) { 
     ip = *ipp; 
     struct stats_t *stat = stats.lookup(&ip); 
     if (stat) { 
      stat->time += delta; 
      stat->freq++; 
     } else { 
      struct stats_t s = {}; 
      s.time = delta; 
      s.freq = 1; 
      stats.update(&ip, &s); 
     } 
     ipaddr.delete(&pid); 
    } 

    return 0; 
} 
""" 

# load BPF program 
b = BPF(text=bpf_text) 
pattern = args.pattern.replace('*', '.*') 
pattern = '^' + pattern + '$' 
b.attach_kprobe(event_re=pattern, fn_name="trace_func_entry") 
b.attach_kretprobe(event_re=pattern, fn_name="trace_func_return") 
matched = b.num_open_kprobes() 

if matched == 0: 
    print("0 functions matched by \"%s\". Exiting." % args.pattern) 
    exit() 
# header 
print("Tracing %d functions for \"%s\"... Hit Ctrl-C to end." % 
    (matched/2, args.pattern)) 

while (1): 
    try: 
     sleep(99999999) 
    except KeyboardInterrupt: 
     break 

print() 
print("%-36s %8s %16s" % ("FUNC", "COUNT", "TIME (nsecs)")) 
stats = b.get_table("stats") 
for k, v in stats.items(): 
    print("%-36s %8s %16s" % (BPF.sym(k.value, -1), v.freq, v.time)) 

이 도구는 BPF를 사용하여 커널에서 각 함수 호출의 빈도와 총 지속 시간을 직접 계산합니다. 집계 된 값은 끝에 표시된 사용자 공간에 복사 된 후에 만 ​​표시됩니다. 출력 :

# ./time-spent do_sys_* 
Tracing 6 functions for "do_sys_*"... Hit Ctrl-C to end. 
^C 
FUNC         COUNT  TIME (nsecs) 
do_sys_poll        6783  213928440379 
do_sys_open        3127   43172656 
do_sys_ftruncate.constprop.15    39   189623 

---

이 솔루션은 BCC에 의존는 커널에서 BPF 프로그램을로드 할 수 있지만, 당신은 get started with bcc on the repository에 튜토리얼을 찾을 수 있습니다 C. 모든 것을 할 수도 있습니다.