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_tracersblk 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_atomic
cat-19588 [000] .... 141284.960228: up_read <-__do_page_fault
cat-19588 [000] d... 141284.960230: __do_page_fault <-do_page_fault
cat-19588 [000] .... 141284.960230: down_read_trylock <-__do_page_fault
cat-19588 [000] .... 141284.960231: _cond_resched <-__do_page_fault
cat-19588 [000] .... 141284.960231: find_vma <-__do_page_fault
cat-19588 [000] .... 141284.960231: vmacache_find <-find_vma
cat-19588 [000] .... 141284.960231: handle_mm_fault <-__do_page_fault
cat-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/0xb0
1) 2640 64 update_curr+0x90/0x1e0
2) 2576 20 update_cfs_shares+0xb7/0xc0
3) 2556 92 task_tick_fair+0x106/0x7e0
4) 2464 24 scheduler_tick+0x4c/0xc0
5) 2440 16 update_process_times+0x49/0x60
6) 2424 16 tick_sched_handle.isra.14+0x26/0x60
7) 2408 32 tick_sched_timer+0x37/0x80
8) 2376 48 __run_hrtimer+0x6f/0x200
9) 2328 100 hrtimer_interrupt+0x210/0x2d0
10) 2228 20 local_apic_timer_interrupt+0x32/0x60
11) 2208 12 smp_apic_timer_interrupt+0x33/0x50
12) 2196 72 apic_timer_interrupt+0x34/0x3c
13) 2124 8 trace_clock_local+0x8/0x10
14) 2116 104 rb_reserve_next_event+0x3e/0x470
15) 2012 16 ring_buffer_lock_reserve+0x74/0xd0
16) 1996 20 trace_buffer_lock_reserve+0xf/0x40
17) 1976 32 trace_function+0x39/0x90
18) 1944 36 function_trace_call+0x10b/0x140
19) 1908 40 ftrace_ops_list_func+0x8d/0x150
20) 1868 84 ftrace_call+0x5/0xb
21) 1784 140 fib_create_info+0x962/0xb70
22) 1644 96 fib_table_insert+0x68/0x920
23) 1548 100 fib_magic.isra.16+0xb5/0xd0
24) 1448 44 fib_add_ifaddr+0x114/0x1b0
25) 1404 20 fib_inetaddr_event+0x67/0xa0
26) 1384 32 notifier_call_chain+0x4e/0x70
27) 1352 28 __blocking_notifier_call_chain+0x39/0x60
28) 1324 16 blocking_notifier_call_chain+0x1f/0x30
29) 1308 80 inet_rtm_newaddr+0x141/0x350
30) 1228 52 rtnetlink_rcv_msg+0x84/0x1f0
31) 1176 20 netlink_rcv_skb+0x8e/0xb0
32) 1156 12 rtnetlink_rcv+0x21/0x30
33) 1144 32 netlink_unicast+0xee/0x190
34) 1112 96 netlink_sendmsg+0x249/0x610
35) 1016 156 do_sock_sendmsg+0xbd/0xe0
36) 860 272 ___sys_sendmsg+0x20f/0x250
37) 588 76 __sys_sendmsg+0x38/0x70
38) 512 424 SYSC_socketcall+0x7f6/0x9c0
39) 88 8 SyS_socketcall+0x13/0x20
40) 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