Linux Kernel(4.19) Hacks

rousalome.egloos.com

포토로그 Kernel Crash


통계 위젯 (화이트)

8200
629
98815


[Linux][Kernel] ftrace: stack tracer [Debugging] Tips

리눅스 커널에서 제공하는 여러 profile tool 중에 ftrace가 있어요. 매우 강력해요. 
잠깐 기억하는게, 저번 리눅스 커널 세미나에 갔었을 때 리눅스 커널 고수들이 ftrace로 벌이는 향연을 보고 참 라이브 공연에 있는 듯한 착각을 받았어요. ftrace 기능 중 stack tracer 기능을 잠깐 소개하고자 해요.

리눅스 커널 고수들 ftrace 로그를 밥 먹듯이 본다고 하네요. 저도 밥 먹듯이 보고는 있지만, 영 실력이 느는 것 같지 않아 짜증이 나지만요. 우선 stack tracer 기능을 좀 소개하려고 해요. 기능도 참 강력해요.

아래와 같이 커널 Config를 설정합니다.
--- a/arch/arm/configs/pompeii_com_defconfig
+++ b/arch/arm/configs/pompeii_com_defconfig
@@ -778,6 +777,14 @@ CONFIG_DEBUG_SET_MODULE_RONX=y
 CONFIG_SECURITY_PERF_EVENTS_RESTRICT=y
 CONFIG_SECURITY=y
 CONFIG_SECURITY_NETWORK=y
+CONFIG_DYNAMIC_FTRACE=y
+CONFIG_FUNCTION_TRACER=y
+CONFIG_FUNCTION_GRAPH_TRACER=y
+CONFIG_IRQSOFF_TRACER=y
+CONFIG_SCHED_TRACER=y
+CONFIG_BLK_DEV_IO_TRACER=y
+CONFIG_FUNCTION_PROFILER=y
+CONFIG_STACK_TRACER=y
+CONFIG_TRACER_SNAPSHOT=y
 CONFIG_LSM_MMAP_MIN_ADDR=4096
 CONFIG_HARDENED_USERCOPY=y
 CONFIG_SECURITY_SELINUX=y

컴파일 후 아래 available_tracers를 확인하면 끝이죠.
cat /sys/kernel/debug/tracing/available_tracers

blk function_graph wakeup_dl wakeup_rt wakeup irqsoff function nop

자, 이제 ftrace를 설정해볼까요?
__insert_vmap_area  함수가 어떤 콜스택으로 호출되는지 알고 싶거든요.

/d/tracing/buffer_size_kb ftrace 버퍼 사이즈 좀 늘려주시고,
d/tracing/set_ftrace_filter에 __insert_vmap_area 추가하고, 
 d/tracing/options/func_stack_trace을 1로 설정하면 끝이죠.
adb shell "echo  > d/tracing/set_event"
adb shell "sleep 1"

adb shell "echo 0 > d/tracing/tracing_on"
adb shell "sleep 1"

adb shell " echo 50000 > /d/tracing/buffer_size_kb"

adb shell "echo function > d/tracing/current_tracer"
adb shell "sleep 1"

adb shell "echo 1 > /d/tracing/events/sched/sched_switch/enable"
adb shell "sleep 1"

adb shell "echo __insert_vmap_area  > d/tracing/set_ftrace_filter"
adb shell "sleep 1"

adb shell "echo 1 > d/tracing/options/func_stack_trace"
adb shell "sleep 1"

adb shell "echo 1 > d/tracing/tracing_on"
adb shell "sleep 1"

여기서 중요한 건 ftrace를 설정할 때 잠깐 d/tracing/tracing_on을 0으로 
세팅하여 주시고, 각각 ftrace 설정 시 sleep을 줄 필요가 있어요.

왜냐면, ftrace 옵션을 다 설정하고 ftrace가 돌면 시스템 과부하로 시스템이 와치독 리셋으로 죽어버리는 수가 있거든요.
아래 리눅스 커널 커뮤니티에서도 제가 업데이트한 로그가 있는데요. 
https://lkml.org/lkml/2017/8/6/153

위 메일링 리스트에서 논의한 내용은, (기억이 가물 가물 하네요) 
ftrace를 graph_tracer로 설정하면 엄청난 ftrace 로그가 찍히는데, Daniel Lezcano이 분은 CPU clock을 높혔더니 stall현상이 안 나왔다는 군요.

아무튼 다른 개발자들도 위 설정으로 ftrace을 키면 다른 사이드 이팩트는 없다고 동의했어요.(다른 메일이 날라왔죠.)

자, 그럼 위와 같이 설정하고, 5분 후, d/tracing/tracing_on을 0으로 다시 바꿔서 ftrace를 동작을 잠깐 멈추고, 
"d/tracing/trace" 로그를 보면 아래 정보를 볼 수 있어요.
            adbd-5414  [000] ...2   246.224086: __insert_vmap_area <-alloc_vmap_area
            adbd-5414  [000] ...2   246.224118: <stack trace>
 => __insert_vmap_area
 => alloc_vmap_area
 => __get_vm_area_node
 => __vmalloc_node_range
 => __vmalloc_node
 => vmalloc
 => n_tty_open
 => tty_ldisc_open
 => tty_ldisc_hangup
 => __tty_hangup
 => tty_vhangup
 => pty_close
 => tty_release
 => __fput
 => ____fput
 => task_work_run
 => do_work_pending
 => work_pending
// ...생략...

            adbd-5414  [000] ...2   247.567047: __insert_vmap_area <-alloc_vmap_area
            adbd-5414  [000] ...2   247.567071: <stack trace>
 => __insert_vmap_area
 => alloc_vmap_area
 => __get_vm_area_node
 => __vmalloc_node_range
 => __vmalloc_node
 => vmalloc
 => n_tty_open
 => tty_ldisc_open
 => tty_ldisc_hangup
 => __tty_hangup
 => tty_vhangup
 => pty_close
 => tty_release
 => __fput
 => ____fput
 => task_work_run
 => do_work_pending
 => work_pending
// ... 생략...
           <...>-5568  [002] ...2   247.572389: __insert_vmap_area <-alloc_vmap_area
           <...>-5568  [002] ...2   247.572407: <stack trace>
 => __insert_vmap_area
 => alloc_vmap_area
 => __get_vm_area_node
 => get_vm_area
 => binder_alloc_mmap_handler
 => binder_mmap
 => mmap_region
 => do_mmap_pgoff
 => vm_mmap_pgoff
 => SyS_mmap_pgoff
 => ret_fast_syscall


#Reference 시스템 콜


Reference(워크큐)
워크큐(Workqueue) Overview


덧글

댓글 입력 영역