커널 안에 이미 있는 계측기를 켠다

이 실습은 VM 에서 돕니다

우분투 24.04 VM 한 대입니다. tracefs 에 쓰고 perf 로 커널 심볼까지 보는 일은 root 와 커널 권한이 필요합니다. 실습 파드에서는 tracefs 가 아예 보이지 않습니다.

목표

커널에 처음부터 들어 있는 계측기 ftrace 를 두 가지 손잡이로 씁니다. 하나는 trace-cmd 이고 하나는 tracefs 파일에 직접 쓰는 것입니다. 함수 호출 그래프, 고정된 tracepoint, 아무 함수에나 거는 kprobe 이벤트를 차례로 켭니다. 그다음 perf stat 과 perf record 로 프로그램이 시간을 어디에 쓰는지 잽니다. 마지막으로 켠 것을 전부 원래대로 돌려 놓습니다.

왜 중요한가

eBPF 이전에도 커널은 스스로를 들여다볼 장치를 갖고 있었습니다. 그리고 eBPF 프로그램이 붙는 자리(tracepoint, kprobe, perf 이벤트)가 바로 여기서 배우는 그 자리입니다. tracepoint 는 커널 개발자가 "여기는 앞으로도 유지한다" 고 약속한 자리라 판이 바뀌어도 그대로 있고, kprobe 는 아무 함수에나 걸 수 있는 대신 판이 바뀌면 사라질 수 있습니다. 이 차이를 알면 eBPF 도구를 고를 때와 운영에 올릴 때의 판단이 달라집니다. 그리고 tracefs 의 스위치는 켜 둔 채 잊으면 아무도 모르게 비용을 냅니다. 마지막 정리 단계가 그 습관을 위한 것입니다.

단계

쓸 수 있는 tracer 목록을 /root/kx/trace/01-tracers.txt 에 저장하세요.
trace-cmd 로 cat /etc/hostname 이 파일을 여는 함수 호출 그래프를 받아 /root/kx/trace/02-graph.txt 에 저장하세요.
tracefs 에 직접 써서 sched_process_exec tracepoint 를 켜고, 기록을 /root/kx/trace/03-exec.txt 에 저장한 뒤 끄세요.
do_sys_openat2 에 파일 이름을 꺼내는 kprobe 이벤트를 만들어 기록을 /root/kx/trace/04-kprobe.txt 에 저장하세요.
perf stat 으로 kx-hot 의 기본 지표를 /root/kx/trace/05-stat.txt 에 저장하세요.
perf record -g 로 kx-hot 을 표본 추출하고 보고서를 /root/kx/trace/06-report.txt 에 저장하세요.
켠 것을 전부 원래대로 돌려 놓으세요.
정리를 /root/kx/trace/08-report.md 에 쓰세요.

참고

tracefs 는 /sys/kernel/tracing 입니다. current_tracer·tracing_on·trace·events/<분류>/<이름>/enable·kprobe_events 가 주요 파일입니다.
trace-cmd record 는 trace.dat 을 만들고 trace-cmd report 가 그것을 글로 풉니다.
kprobe 이벤트에서 사용자 공간 문자열을 꺼낼 때는 +0($arg2):ustring 처럼 씁니다. $argN 은 함수의 N번째 인자입니다.
흔한 실수: tracing_on 이 0 인 채로 이벤트만 켜는 것. 아무것도 쌓이지 않습니다.

어떤 tracer 가 있나

/sys/kernel/tracing/available_tracers 의 내용을 /root/kx/trace/01-tracers.txt 에 그대로 저장하세요.

tracefs 의 파일은 평범한 텍스트 파일처럼 읽힙니다. 목록에 function_graph 가 있는지 보세요. 다음 단계에서 그것을 씁니다.

함수 호출 그래프

trace-cmd record 로 function_graph tracer 를 켜되 그래프의 뿌리를 do_sys_openat2 로 좁히고, cat /etc/hostname 만 추적하세요. trace-cmd report 의 결과를 /root/kx/trace/02-graph.txt 에 저장하세요.

-p 로 tracer 를, -g 로 그래프의 뿌리 함수를, -F 로 추적할 명령을 고릅니다. 이 셋을 빼면 몇 초 만에 수십만 줄이 쌓입니다. 결과에서 do_sys_openat2() { 아래로 중괄호가 들여 쓰여 있으면 호출 그래프입니다.

tracepoint 를 손으로 켠다

tracefs 파일에 직접 써서 sched:sched_process_exec 이벤트를 켜고, 기록을 비운 뒤 /usr/bin/true 를 한 번 실행하고, trace 의 내용을 /root/kx/trace/03-exec.txt 에 저장한 다음 그 이벤트를 다시 끄세요.

이벤트마다 events/<분류>/<이름>/enable 파일이 있고 1 을 쓰면 켜집니다. trace 에 빈 줄을 쓰면 기록이 비워집니다. 저장한 기록에 filename=/usr/bin/true 가 있어야 하고, 끝나면 그 enable 은 0 이어야 합니다.

아무 함수에나 거는 kprobe

kprobe_events 에 do_sys_openat2 를 잡는 이벤트 kx_open 을 만들어 두 번째 인자(파일 이름)를 filename 으로 꺼내게 하세요. comm == "cat" 필터를 걸고 켠 뒤 cat /etc/hostname 을 실행하고, kx_open 줄만 골라 /root/kx/trace/04-kprobe.txt 에 저장하세요.

꼴은 p:<이름> <함수> <필드>=<값> 입니다. 파일 이름은 사용자 공간 포인터라 +0($arg2):ustring 으로 읽습니다. 만들면 events/kprobes/kx_open/ 이 생기고, 거기에 filter 와 enable 이 있습니다. 저장한 줄에 filename="/etc/hostname" 이 보여야 합니다.

perf stat 으로 큰 그림을 잰다

perf stat 으로 task-clock·context-switches·cpu-migrations·page-faults 네 이벤트를 골라 /usr/local/bin/kx-hot 을 재고, 결과를 -o 로 /root/kx/trace/05-stat.txt 에 저장하세요.

perf stat -e 이벤트,이벤트 -o 파일 -- 명령 꼴입니다. 이 VM 은 가상 머신이라 하드웨어 카운터(cycles·instructions)가 안 보일 수 있습니다. 그래서 소프트웨어 이벤트만 고릅니다.

시간을 어디에 쓰는가

perf record -g 로 /usr/local/bin/kx-hot 을 표본 추출해 /root/kx/trace/perf.data 에 저장하고, perf report --stdio --no-children --sort symbol 의 결과를 /root/kx/trace/06-report.txt 에 저장하세요. 가장 위의 함수가 무엇인지 보세요.

-o 로 perf.data 의 자리를 정하고 perf report -i 로 같은 파일을 읽습니다. --no-children 은 '자기 몸에서 쓴 시간' 만 세어 줍니다. kx-hot 은 프레임 포인터를 남겨 컴파일해서 -g 로 호출 사슬이 이어집니다.

켠 것을 끈다

tracefs 를 처음 상태로 돌려 놓으세요. current_tracer 는 nop, tracing_on 은 1, 켜진 이벤트(set_event)는 없고, kprobe_events 에 kx_open 이 남아 있지 않아야 합니다.

kprobe 이벤트는 -:<이름> 을 kprobe_events 에 덧붙여 지웁니다. 켜져 있으면 지워지지 않으니 먼저 enable 을 0 으로 씁니다. trace-cmd reset 은 tracer 를 돌려 놓지만 tracing_on 을 0 으로 남길 수 있으니 마지막에 직접 확인하세요.

계측기를 고르는 기준

/root/kx/trace/08-report.md 에 ## tracepoint 와 kprobe·## perf 가 본 것·## 운영에서 켜고 끄는 법 세 절을 쓰세요. 6단계 보고서의 맨 위 함수 이름과 그 비율을 그대로 인용해야 합니다.

맨 위 함수와 비율은 06-report.txt 의 첫 데이터 줄에 있습니다. 첫 절에는 3단계와 4단계의 차이(약속된 자리와 아무 자리)를, 셋째 절에는 7단계에서 무엇을 돌려 놓았는지와 그 이유를 적습니다.