ftrace 는 커널 소스들의 실행을 추척하는 도구이다. ftrace 는 커널에서 제공하는 tracefs 파일 시스템을 활용하여 동작하기 때문에 커널 소스코드를 수정하지 않고도 디버깅할 수 있다는 장점이 있다. 해당 글에서는 ftrace 에 대한 간략한 소개와 사용법만을 다룬다. 자세한 내용은 ftrace 커널 공식 문서를 확인하기 바란다.
1. 파일 확인
앞서 말했듯이 ftrace 는 파일 시스템을 통해 동작하기 때문에 파일을 읽고 쓰는 것으로 ftrace 를 핸들링 가능하다. /sys/kernel/debug/tracing 경로에서 관련 파일들을 확인할 수 있다.
중요한 것은 반드시 root 권한으로 파일 시스템에 접근해야 한다. su 명령어를 통해 root 계정으로 로그인하여 작업하는 것이 훨씬 수월하므로 필자는 이후의 모든 내용을 root 계정으로 진행하겠다.
만약 다음의 파일들이 보이지 않는다면 menuconfig 을 통해 Kernel hacking > Tracers 값을 수정한 후 다시 빌드해야 한다.
다음과 같이 수정하면 되지만 기본적으로 다 설정되어 있기 때문에 설정을 건드린 것이 아니라면 바로 사용 가능할 것이다.
2. 추적 가능 항목
추적 가능 항목은 크게 두 가지로 나뉜다: 이벤트(Event), 그리고 함수(Function).
이벤트 (event)
추적 가능한 이벤트는 available_events 파일에서 확인이 가능하다.
cat availabile_events
그리고 위 이벤트들은 다음과 같이 events/ 하위 경로에 있는 파일을 통해 제어 가능하다: 
함수 (function)
추적 가능한 함수의 목록은 available_filter_functions 파일 안에서 확인 가능하다:
cat available_filter_functions
마지막으로 추적 가능 항목은 available_tracers 파일 내용들 중 하나를 택할 수 있다.
5.12.2 기준으로 다음의 항목들을 추적할 수 있다.
3. 추적 설정 살피기
현재 추적하는 항목은 current_tracer 파일에 저장되어 있다.
가장 기본으론 nop 이 설정되어 있고 이는 ftrace 가 이벤트 단위로 추적한다는 것을 의미한다.
ftrace 의 동작은 tracing_on 파일을 통해서 활성화/비활성화를 결정할 수 있다. tracing_on 파일 내용이 1 이라면 ftrace 는 활성화되고, 0 이라면 ftrace 는 비활성화된다.
다음의 내용은 ftrace 를 활성화/비활성화 시키는 일련의 명령어이다.
현재 추적하는 함수 필터는 set_ftrace_filter 파일을 통해 확인할 수 있다.
현재는 모든 함수가 활성화된 상태인데 이후에 함수 추적에 대해 설명하면서 더 자세히 다뤄볼 것이다.
4. 이벤트 추적
가장 먼저 current_tracer 값을 nop 으로 변경해서 ftrace 가 이벤트를 추적할 수 있도록 변경한다.
echo nop > current_tracer`
커널 이벤트들 중에서 스케쥴러와 관련된 sched_wakeup 을 추적해보도록 하겠다. 앞에서 설명한 것처럼 events/ 의 하위 경로에 있는 파일을 제어하여 설정 가능하다고 했다. 해당 파일은 /sys/kernel/debug/tracing/events/sched/sched_wakeup/ 에 저장되어 있고 이는 아래와 같이 활성화할 수 있다.
echo 1 > events/sched/sched_wakeup/enable
이제 ftrace 는 sched_wakeup 이벤트를 추적하게 된다.
echo 1 > tracing_on
위 명령어를 통해 ftrace 를 활성화하고아래의 명령어로 실행 결과를 확인한다.
cat trace or vi trace
필자는 vi 를 통해 확인하는게 편해서 보통 vi 를 통해 그 결과를 확인한다. 독자는 둘 중 편한 방법을 선택하면 될 것 같다. 필자가 확인한 결과는 아래와 같다:
위에서 각 항목이 무엇을 의미하는지는 아래와 같다:
| 이름 | 설명 |
|---|---|
TASK | 프로세스 이름 |
PID | 프로세스 ID |
CPU | CPU 번호 |
TIMESTAMP | <sec>.<usec> |
FUNCTION | 함수 이름 |
보는 것과 같이 sched_wakeup 에 대해 동작하도록 ftrace 를 설정했기에 모든 함수가 전부 sched_wakeup 이벤트로 나타난다.
확인이 끝났다면 아래의 명령어를 입력해서 trace 를 비우고 활성화한 이벤트를 비활성화 시킨다.
cat /dev/null > trace echo 1 > events/sched/sched_wakeup/enable
5. 함수 추적
위에서 확인했던 것은 이벤트를 통한(nop) 추적이였고, 이번에는 함수를 추적해보도록 하겠다.
아래의 명령어를 순서대로 입력(괄호친 내용은 설명이므로 입력할 필요없다)한다:
sysctl kernel.ftrace_enabled=1 (ftrace 를 사용 가능하도록 변경) echo function > current_tracer (ftrace 가 함수를 추적하도록 설정) echo 1 > tracing_on (ftrace 시작) (잠시 대기...) echo 0 > tracing_on (ftrace 종료) cat or vi trace (결과 확인)
보는 것과 같이 맨 위의 tracer 항목이 nop 에서 function 으로 바뀌고 함수 이름이 sched_wakeup 에서 여러 다른 이름의 함수로 바뀐 것을 확인할 수 있다.
특정 함수 추적
이번에는 여러 함수가 아닌 하나의 함수를 추적하도록 ftrace 를 설정해보겠다.
sysctl kernel.ftrace_enabled=1 (ftrace 를 사용 가능하도록 변경) echo function > current_trace (ftrace 가 함수를 추적하도록 설정) echo hrtimer_interrupt > set_ftrace_filter (hrtimer_interrupt 함수를 추적하도록 설정) echo 1 > tracing_on (ftrace 시작) (잠시 대기...) echo 0 > tracing_on (ftrace 종료) cat or vi trace (결과 확인)
앞서 말했던 것처럼 set_ftrace_filter 를 통해 원하는 함수를 선택할 수 있고 다음의 명령어를 실행하면 ftrace 가 오직 hrtimer_interrupt 함수에 대해서만 추적을 진행한다. 필자의 실행결과는 아래와 같다:
보는 것과 같이 함수 이름이 전부 hrtimer_interrupt 임을 확인할 수 있다. 확인이 끝났다면 위에서 했던 것처럼 각 항목(trace, set_ftrace_filter, current_tracer) 을 위에서 했던 것처럼 기본 값으로 초기화하길 바란다.
6. 함수 그래프 추적
위에서 이벤트와 함수를 어떻게 추적하는지 간단하게 살펴봤다. 이번에는 새로운 항목인 함수 그래프(function graph) 를 추적해보겠다. 함수 그래프는 available_tracers 파일에서 확인 가능하다.
sysctl kernel.ftrace_enabled=1 (ftrace 를 사용 가능하도록 변경) echo function_graph > current_tracer (ftrace 가 함수를 추적하도록 설정) echo 1 > tracing_on (ftrace 시작) (잠시 대기...) echo 0 > tracing_on (ftrace 종료) cat or vi trace (결과 확인)
특별한 설정 없이 간단하게 ftrace 가 function_graph 항목에 대해 추적하도록 변경하고 실행시켜 보았다:
보는 것과 같이 맨 위의 tracer 항목이 function_graph 로 바뀌었고 세부 항목이 줄었다.
CPU 는 앞서 말했듯이 CPU 번호 를 의미하고 DURATION 은 실행시간, FUNCTION CALL 은 함수 호출이 어떤 순서로 이뤄졌는지를 나타낸다.
특정 함수 추적
다시 한번 특정 함수에 대해 추적하도록 옵션을 설정하고 함수 그래프(function graph) 의 결과를 확인 해보겠다. 이번에는 set_ftrace_filter 가 아닌 set_graph_function 파일 내용을 변경해야 한다.
sysctl kernel.ftrace_enabled=1 (ftrace 를 사용 가능하도록 변경) echo function_graph > current_tracer (ftrace 가 함수를 추적하도록 설정) echo scheduler_tick > set_graph_function (ftrace 가 `scheduler_tick` 함수를 추적하도록 설정) echo 1 > tracing_on (ftrace 시작) (잠시 대기...) echo 0 > tracing_on (ftrace 종료) cat or vi trace (결과 확인)
위 결과는 scheduler_tick 함수가 CPU 에서 얼마나 오랫동안 실행되었는지 그 과정을 추적해서 보여준다.
확인이 끝났다면 각 파일의 항목 값을 기본 값으로 초기화한다.
출처
[사이트] https://www.kernel.org/doc/Documentation/trace/ftrace.rst
[책] 리눅스 커널 소스 해설: 기초입문 (정재준 저)
