linux内核调试器ftrace使用

本文的实验是在ubuntu（内核版本3.19.0）上运行的。

ftrace原理

ftrace是一个追踪器框架，其中一个强大的追踪器就是函数追踪器（即函数的调用过程）。它使用gcc的-pg选项让内核中的每个函数在执行前都调用一个特殊的函数mcount()。该函数本来是在c库中实现，用于prof跟踪调试性能。内核不链接C库，所以就利用了这个gcc特性。mcount函数必现在汇编中实现，因为调用不遵循正常的C ABI。

如果每个函数都调用这个函数，势必会影响性能，所以内核支持动态开启函数跟踪。配置选项为CONFIG_DYNAMIC_FTRACE。在编译期间，使用了一个脚本将所有的mcount调用都替换为NOP指令，并把位置点记录在一个表里面。当用户通过proc开启函数跟踪功能后，再把NOP替换为mcount调用。听起来就很高大上，有没有。

设置ftrace

我们可以先看一下内核是否支持ftrace,
# ls /sys/kernel/debug/tracing/。
如果有东西则表示支持。
为了方便，我们先进入这个目录
# cd /sys/kernel/debug/tracing/
current_tracer表示当前的追踪器是哪个，我们可以先设置追踪器。先可以查看目前支持哪些追踪器。
# cat available_tracers
blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nop
function就是函数追踪器。

函数追踪器

设置fucntion为当前追踪器
# echo function> current_tracer

查看追踪结果，因为内容非常多，所以我们使用head参数只查看头20行
# cat trace | head -20

# tracer: function
#
# entries-in-buffer/entries-written: 72213/32836651   #P:1
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |cat-19588 [000] ...1 141284.960228: native_flush_tlb_single <-__kunmap_atomiccat-19588 [000] .... 141284.960228: up_read <-__do_page_faultcat-19588 [000] d... 141284.960230: __do_page_fault <-do_page_faultcat-19588 [000] .... 141284.960230: down_read_trylock <-__do_page_faultcat-19588 [000] .... 141284.960231: _cond_resched <-__do_page_faultcat-19588 [000] .... 141284.960231: find_vma <-__do_page_faultcat-19588 [000] .... 141284.960231: vmacache_find <-find_vmacat-19588 [000] .... 141284.960231: handle_mm_fault <-__do_page_faultcat-19588 [000] .... 141284.960231: __mem_cgroup_count_vm_event <-handle_mm_fault

从这个可以看到进程名，PID，执行的CPU，调用时间戳等信息。调用过程要倒着看，A <- B，表示B函数调用了A函数。即便这样还是难以理解调用过程。我们可以使用函数流图追踪器。

函数流图追踪器

打开函数流图追踪器
# echo function_graph> current_tracer
# cat trace | head -20

# tracer: function_graph
#
# CPU  DURATION                  FUNCTION CALLS
# |     |   |                     |   |   |   |0)   0.878 us    |          } /* do_set_pte */0)               |          unlock_page() {0)   0.041 us    |            __wake_up_bit();0)   0.249 us    |          }0)               |          do_set_pte() {0)   0.026 us    |            add_mm_counter_fast();0)               |            page_add_file_rmap() {0)   0.026 us    |              mem_cgroup_begin_page_stat();0)   0.023 us    |              mem_cgroup_end_page_stat();0)   0.435 us    |            }0)   0.852 us    |          }0)               |          unlock_page() {0)   0.029 us    |            __wake_up_bit();0)   0.238 us    |          }0)               |          do_set_pte() {0)   0.026 us    |            add_mm_counter_fast();

这个读起来就很方便了，就如同C代码一样。如果时间栏显示+表示执行时间大于10微妙，如果显示！表示执行时间大于100微妙。

trace_printk

相比较于printk和trace_printk。printk会将内容直接输入到console，这会有非常大的cpu消耗（可能需要几毫秒），trace_printk写入环形缓冲区，消耗CPU很小（大约1/10微妙），对系统影响很小。trace_printk的打印将写入追踪器（任何追踪器里面都会写入），cat trace时就会看到。

启用和停止跟踪

关闭跟踪
# echo 0 > tracing_on
打开跟踪
#echo 1 > tracing_on
一般情况下这样用，先关闭，先后设置一个跟踪器，然后打开跟踪，运行某个想要跟踪的程序，一段时候后关闭跟踪。
#echo 1 > tracing_on; RUN_TEST; echo 0 > tracing_on

更加精准的追踪

不论如何上面的函数追踪总是会输入很多东西，缓冲区可能一下就满了，看不到想要的东西。这时我们可以在代码在来关闭和开启追踪器，以满足我们的需求。

应用层追踪某个系统调用
先关闭追踪器，然后在执行这个函数时打开追踪器，函数退出时打开追踪器。这样就实现了只追踪单个函数的功能。应用层还可以使用trace_maker来在trace中产生输出，以便用户搜索或是其他用处。使用方法为：
echo hello world > trace_marker

内核追踪某个函数
方法和上面差不多，只是内核不用echo 0/1，有专门的开启关闭函数可以使用，
tracing_on(),
tracing_off(),内核还可以使用trace_printk来与输出产生对应的交互关系。

多核系统中显示某个核调用

cat per_cpu/cpu0/trace

栈跟踪

打开栈跟踪
# echo 1 ＞ /proc/sys/kernel/stack_tracer_enabled
查看结果
# cat stack_trace

        Depth    Size   Location    (41 entries)-----    ----   --------0)     2672      32   update_min_vruntime+0xe/0xb01)     2640      64   update_curr+0x90/0x1e02)     2576      20   update_cfs_shares+0xb7/0xc03)     2556      92   task_tick_fair+0x106/0x7e04)     2464      24   scheduler_tick+0x4c/0xc05)     2440      16   update_process_times+0x49/0x606)     2424      16   tick_sched_handle.isra.14+0x26/0x607)     2408      32   tick_sched_timer+0x37/0x808)     2376      48   __run_hrtimer+0x6f/0x2009)     2328     100   hrtimer_interrupt+0x210/0x2d010)     2228      20   local_apic_timer_interrupt+0x32/0x6011)     2208      12   smp_apic_timer_interrupt+0x33/0x5012)     2196      72   apic_timer_interrupt+0x34/0x3c13)     2124       8   trace_clock_local+0x8/0x1014)     2116     104   rb_reserve_next_event+0x3e/0x47015)     2012      16   ring_buffer_lock_reserve+0x74/0xd016)     1996      20   trace_buffer_lock_reserve+0xf/0x4017)     1976      32   trace_function+0x39/0x9018)     1944      36   function_trace_call+0x10b/0x14019)     1908      40   ftrace_ops_list_func+0x8d/0x15020)     1868      84   ftrace_call+0x5/0xb21)     1784     140   fib_create_info+0x962/0xb7022)     1644      96   fib_table_insert+0x68/0x92023)     1548     100   fib_magic.isra.16+0xb5/0xd024)     1448      44   fib_add_ifaddr+0x114/0x1b025)     1404      20   fib_inetaddr_event+0x67/0xa026)     1384      32   notifier_call_chain+0x4e/0x7027)     1352      28   __blocking_notifier_call_chain+0x39/0x6028)     1324      16   blocking_notifier_call_chain+0x1f/0x3029)     1308      80   inet_rtm_newaddr+0x141/0x35030)     1228      52   rtnetlink_rcv_msg+0x84/0x1f031)     1176      20   netlink_rcv_skb+0x8e/0xb032)     1156      12   rtnetlink_rcv+0x21/0x3033)     1144      32   netlink_unicast+0xee/0x19034)     1112      96   netlink_sendmsg+0x249/0x61035)     1016     156   do_sock_sendmsg+0xbd/0xe036)      860     272   ___sys_sendmsg+0x20f/0x25037)      588      76   __sys_sendmsg+0x38/0x7038)      512     424   SYSC_socketcall+0x7f6/0x9c039)       88       8   SyS_socketcall+0x13/0x2040)       80      80   sysenter_after_call+0x0/0x16

可以看到栈深度，以及栈大小。

查看最大的栈使用大小
# cat stack_max_size
如果要重新记录，那么往里面echo 0即可。

注意，如果内核有使用单独的栈，那么跟踪器将跟踪不到最大使用的栈大小。例如中断有自己的栈，跟踪器就无法跟踪到。

如果在当前的嵌入式工作中打开这些内核选项

目前还不知道-_-!

参考：
Debugging the kernel using Ftrace - part 1
Debugging the kernel using Ftrace - part 2

人生苦短，远离bug