문서 편집 권한이 없습니다. 다음 이유를 확인해주세요: 요청한 명령은 다음 권한을 가진 사용자에게 제한됩니다: 사용자. 문서의 원본을 보거나 복사할 수 있습니다. [[분류: 리눅스 커널]] == 개요 == 리눅스 커널에서 커널 내부의 Latency와 Function call을 확인하기 위하여 제공하는 Tracing Tool 이다. == 사용법 == 우선 debugfs을 적절한 위치 (여기서는 default인 /sys/kernel/debug)에 마운트 시킨다. mount -t debugfs nodev /sys/kernel/debug 또한 ftrace를 사용하려면, 커널에 다음과 같은 configuration을 주어야 한다. (menuconfig 혹은 kconfig 파일) CONFIG_FUNCTION_TRACER CONFIG_FUNCTION_GRAPH_TRACER CONFIG_STACK_TRACER CONFIG_DYNAMIC_FTRACE 현재 사용할 수 있는 traces들의 종류를 보기 위해선, available_tracers에 어떤 내용이 있는지 확인하면 된다. cat /sys/kernel/debug/tracing/available_tracers 또한 여기서 확인한 trace중에서 사용할 trace는 current_tracer에 적용시키면 된다. echo function(한 예시) > current_tracer 마지막으로 사용된 tracer에 대해서 tracing된 결과는 trace 파일에 포함되게 된다. cat /sys/kernel/debug/tracing/trace 또한 trace를 시작하고 멈추는 것은 tracing_on에 1 (트레이싱 함), 혹은 0 (트레이싱 안함)을 표시시켜서 조절하게 된다. echo 1 > tracing_on 만약 trace 하고 싶은 함수가 따로 있을 경우, cat available_filter_functions 로 가능한 함수를 확인한후 echo "*vfs*" > set_ftrace_filter echo "*write*" >> set_ftrace_filter 다음과 같이 regx를 이용하여 설정한 후 트레이싱하면 된다. 여기서 만약 초기화 하기 위해서는 echo " " > set_ftrace_filter 다음과 같이 설정하면 된다. === NOP tracing === echo nop > current_tracer NOP은 인스트럭션중 아무 일도 하지 않는 인스트럭션을 말한다. 이 상황에서는 tracer는 아무 output도 만들지 않는다. <nowiki> # tracer: nop # # entries-in-buffer/entries-written: 0/0 #P:4 # # _-----=> irqs-off # / _----=> need-resched # | / _---=> hardirq/softirq # || / _--=> preempt-depth # ||| / delay # TASK-PID CPU# |||| TIMESTAMP FUNCTION # | | | |||| | | </nowiki> === Function tracing === echo function > current_tracer gcc의 -pg (gprof를 통해서 시스템 분석을 가능하게 하는 옵션임)옵션을 통해서 이루어 지는데, 모든 커널의 함수의 시작 부분에 mcount라는 함수를 호출하게 된다. 이 함수는 C [[ABI]]를 따르지 않기 때문에 어셈블리로 구현되게 된다. 커널에 이미 구현되에 있는 mcount라는 함수의 콜을 통해서 ftrace로그를 가지게 된다. 이때 만약 CONFIG_DYNAMIC_FTRACE를 enable하게 되면, 부팅 시간에는 모든 mcount들이 NOP으로 변환되게 되며, NOP을 처리하는 것은 거의 무시할 수 있는 system overhead를 가져오기 때문에, 시스템의 영향을 거의 미치지 않게 할 수 있다. 또한 CONFIG_DYNMAMIC_FTRACE를 통한다면, 어떤 함수에서 벤치를 돌리 것인지 설정할 수 있다. <nowiki> # tracer: function # # TASK-PID CPU# TIMESTAMP FUNCTION # | | | | | bash-16939 [000] 6075.461561: mutex_unlock <-tracing_set_tracer <idle>-0 [001] 6075.461561: _spin_unlock_irqrestore <-hrtimer_get_next_event <idle>-0 [001] 6075.461562: rcu_needs_cpu <-tick_nohz_stop_sched_tick bash-16939 [000] 6075.461563: inotify_inode_queue_event <-vfs_write <idle>-0 [001] 6075.461563: mwait_idle <-cpu_idle bash-16939 [000] 6075.461563: __fsnotify_parent <-vfs_write </nowiki> === Function graph === echo function_graph > current_tracer 이 옵션은 함수의 콜 관계를 C의 Annotation을 사용해서 표현한다. Duration에 표시되는 annotation인 + 와 !는 각각 10마이크로 세커드 보다 duration이 김을, 100마이크로 세컨드보다 duration이 김을 표시한다. Function graph로 표시하기 위해서 ftrace유틸은 함수의 종료 주소를 hijack하는데, 이는 cpu의 branch prediction을 방해하기 때문에 실제 실행시간보다 약간이지만 조금 길어질 수 있다. <nowiki> # tracer: function_graph # # CPU DURATION FUNCTION CALLS # | | | | | | | 1) 1.015 us | _spin_lock_irqsave(); 1) 0.476 us | internal_add_timer(); 1) 0.423 us | wake_up_idle_cpu(); 1) 0.461 us | _spin_unlock_irqrestore(); 1) 4.770 us | } 1) 5.725 us | } 1) 0.450 us | mutex_unlock(); 1) + 24.243 us | } 1) 0.483 us | _spin_lock_irq(); 1) 0.517 us | _spin_unlock_irq(); 1) | prepare_to_wait() { 1) 0.468 us | _spin_lock_irqsave(); 1) 0.502 us | _spin_unlock_irqrestore(); 1) 2.411 us | } 1) 0.449 us | kthread_should_stop(); 1) | schedule() { </nowiki> === trace_printk === [[printk]]를 통해서 대부분의 커널 디버깅을 진행 할 수는 있지만, interrupt context나 timer처럼 많은 로그가 남거나 stack overflow가 날 수 있는 문제의 환경에서 사용할 수 없다는 문제가 있다. 이때 ftrace의 ring buffer를 그대로 활용하여, trace에 로그가 남도록 하는 방법이 있는데, 이 방법이 바로 trace_printk이다. printk처럼 trace_printk를 써서 로그를 남기면 trace에 표출되게 된다. <nowiki> function mode... # TASK-PID CPU# TIMESTAMP FUNCTION # | | | | | <...>-10690 [003] 17279.332920: : read foo 10 out of bar ffff880013a5bef8 function_graph mode... 3) | do_one_initcall() { 3) | /* read foo 10 out of bar ffff88001191bef8 */ 3) 4.221 us | } </nowiki> == 참고 == # https://lwn.net/Articles/365835/ # https://medium.com/@hyoje420/linux-ftrace-%EC%82%AC%EC%9A%A9%EB%B2%95-31b4dc7ac93c Ftrace 문서로 돌아갑니다.