리눅스 커널에서 제공하는 여러 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가 돌면 시스템 과부하로 시스템이 와치독 리셋으로 죽어버리는 수가 있거든요.
아래 리눅스 커널 커뮤니티에서도 제가 업데이트한 로그가 있는데요.
위 메일링 리스트에서 논의한 내용은, (기억이 가물 가물 하네요)
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(프로세스)
Reference(워크큐)
워크큐(Workqueue) Overview
'[Debugging] Tips' 카테고리의 다른 글
| [리눅스커널][디버깅] Red Hat Crash-Utility(크래시 유틸리티) 설치 (0) | 2023.05.04 |
|---|---|
| [Linux][Kernel][ARM] char buf[32]; vs char buf[32]={0}; (0) | 2023.05.04 |
| tombstone 시(시스템 크래시) - 커널 패닉 유발 (0) | 2023.05.04 |
| 특정 CPU를 끄는 패치(특정 CPU에서 커널 크래시) (0) | 2023.05.04 |
| Trace32 - Memory Class 메모리 클래스 (0) | 2023.05.04 |