利用ftrace跟踪内核static tracepoint——实例writeback event

 

摘要：和很多linux内核子系统一样，static tracepoint有很多层次，其中某个层次都展示给不同层次的开发者来满足他们的不同需求。关于linux tracepoint的详细信息，我们可以在linux内核文档Documentation/trace/tracepoints.txt和 samples/tracepoints这两个地方找到。大致来说，对tracepoints本身的定义是第一个层次，一般只有内核开发者才会定义这些tracepoints；trace event是第二个层次，用于debug；第三个层次就是perf这些内核测试工具，他们调用底层的trace events来监控系统内核的某些特性。

一个tracepoint可以理解为一个linux内核中的占位符函数，内核子系统的开发者常常用它们来debug。static表明这些tracepoint的位置是固定的，你可以把它理解位传统C程序中的 #if DEBUG部分。如果在运行时没有开启，它们是不占用任何系统开销的。本文主要为你讲解如何用ftrace来使用这些tracepoint，当然，你也可以使用perf来使用这些tracepoints。

本文来源：http://blog.csdn.net/trochiluses/article/details/10185951

1.什么是linux static tracepoint

        linux利用Kprobes进行动态跟踪内核调度已经有很长时间了。 Kprobe机制是内核提供的一种调试机制，它提供了一种方法，能够在不修改现有代码的基础上，灵活的跟踪内核函数的执行。它的基本工作原理是：用户指定一个探测点，并把一个用户定义的处理函数关联到该探测点，当内核执行到该探测点时，相应的关联函数被执行，然后继续执行正常的代码路径。动态tracing有很多优点：当disabled的时候是零负载的；probe可以放置在内核中任何一条指令的地方而不是内核开发者所认为的地方。

       所有这些灵活性也有一定的缺点。一个可执行的kprobe有一个显著的负载——因为它利用了breakpoints和exception hadlers。另一个方面是probe的放置地点：kprobes可以很方便的放置在函数入口或者出口，但是如果你需要把probe放置在函数内部或者需要probe局部变量，那么你就需要systemtap和配置了 CONFIG_DEBUG_INFO的自己编译的内核。 从这个角度上看，静态tracepoints可以被放置在函数的任意地方，而且可以越过任意重要的局部变量。linux 2.6.32的主线以后已经实现了比较多的静态tracepoint。

        增加一个静态tracepoint是非常简单的，你可以参考这个例子。在这个例子中，我给已经存在的trace组（irq）增加tracepoint，所以我仅仅需要定义tracepoint和这些tracepoints。你可以在内核的文档linux/samples/trace_events/trace-events-sample.h中找到一个tracepoint定义的五个部分的解释。针对更加复杂的例子，可以参考linux/samples/trace_events/。

2.使用linux static tracepoint

2.1挂载debug文件系统

mount  -t  debugfs  nodev  /debug  

2.2查看可供使用的tracepoints

# cat /sys/kernel/debug/tracing/available_events

skb:skb_copy_datagram_iovec
skb:kfree_skb
block:block_rq_remap
block:block_remap
block:block_split
block:block_unplug_io
block:block_unplug_timer

Since we added our tracepoints to the irq group, we can find them in tracing/events/irq:

# ls /sys/kernel/debug/tracing/events/irq/

enable  irq_handler_entry  softirq_entry  tasklet_entry
filter  irq_handler_exit   softirq_exit   tasklet_exit

Enable the tasklet tracepoints:

# echo 1 >  /sys/kernel/debug/tracing/events/irq/tasklet_entry/enable
# echo 1 >  /sys/kernel/debug/tracing/events/irq/tasklet_exit/enable

And the output is available in the trace buffer:

# cat /sys/kernel/debug/tracing/trace

# tracer: nop
#
#           TASK-PID    CPU#    TIMESTAMP  FUNCTION
#              | |       |          |         |
-0     [000]   327.349213: tasklet_entry: func=.rpavscsi_task
-0     [000]   327.349217: tasklet_exit: func=.rpavscsi_task

When finished, we can disable the tracepoints. There are enable files at all levels of the hierarchy, so we can disable all tracepoints in one go:

# echo 0 > /sys/kernel/debug/tracing/events/enable

3.在内核模块中使用静态tracepoints

Kernel modules can also make use of static tracepoints. A simple module that hooks the tasklet_entry tracepoint and printks the function name of the tasklet might look like (I’ve called it tracepoint-example.c):

#include <linux/module.h>
#include <trace/events/irq.h>

static void probe_tasklet_entry(struct tasklet_struct *t)
{
        printk("tasklet_entry %pf
", t->func);
}

static int __init trace_init(void)
{
        WARN_ON(register_trace_tasklet_entry(probe_tasklet_entry));
        return 0;
}

static void __exit trace_exit(void)
{
        unregister_trace_tasklet_entry(probe_tasklet_entry);
}

module_init(trace_init)
module_exit(trace_exit)
MODULE_LICENSE("GPL");

If you are wondering, %pf is a printk formatter trick to pretty print a function name so you don’t have to go searching for the address in System.map.

Here is a Makefile to go with it:

obj-m := tracepoint-example.o
KDIR := /lib/modules/$(shell uname -r)/build
PWD := $(shell pwd)
default:
        $(MAKE) -C $(KDIR) SUBDIRS=$(PWD) modules

4 利用ftrace跟踪static tracepoints

以下所有操作均在/debug/tracing目录下进行

大致的步骤为：设定要监控的event，实际上也就是要监控的一系列的tracepoints；设定tracer成nop；开启tracing_on；查看结果。

4.1 使用event有两种方式

i) 通过set_event文件

1. #echo sched_wakeup >> set_event
2. #echo '!sched_wakeup' >> set_event
3. #echo > set_event

events被组织成一个个子系统，如ext4,irq,sched等待，一个完整的event name是这样的：<subsystem>:<event>，其中subsystem是可选的，一个子系统中所有的events可以通过<subsystem>:*指定。

1. #echo *:* > set_event
2. #echo 'irq:*' > set_event

ii) 通过'enable' toggle

1. #echo 1 > /sys/kernel/debug/tracing/events/sched/sched_wakeup/enable
2. #echo 1 > /sys/kernel/debug/tracing/events/sched/enable
3. #echo 1 > /sys/kernel/debug/tracing/events/enable

实例：我们需要监控writeback子系统，那么需要进行如下设定

$:echo writeback > set_event

4.2开启监控

$:echo nop > current_tracer

$:echo 1 > tracing_on

(wait for a moment......)

4.3结果查看：event trace的意义

$:cat trace | head -20 

输出结果如下：

关于输出结果的意义，可以到对应events下面，利用cat fromat查看输出格式和意义

这里，不以common_开头的filed是每个event特有的。每一个event对应的有一个TRACE_EVENT定义一个record，这里offset为field在record中的偏移，size为其大小。下载一个内核，在samples/trace_events目录下有一个例子，可以查看TRACE_EVENT的定义方法。

4.4event filter

语法：

1. field-name relation-operatior value                           //一个predicate

可以通过'&&', '||',以及圆括号将几个predicate组合起来。对于数字域，可以使用操作符==, !=, < , > , <=, >=，对于字符串域，可以使用==, !=。目前字符串只支持完全匹配，且最多可以组合16个predicate。

例子：

1. #cd /sys/kernel/debug/tracing/events/signal/signal_generate
2. #echo "((sig >= 10 && sig < 15) || sig == 17) && comm != bash" > filter

每个子系统都有独立的filter文件支持，如：

1. #cd /sys/kernel/debug/tracing/events/sched
2. #echo 0 > filter
3. #cat sched_switch/filter
4. none
5. #cat sched_wakeup/filter
6. #echo common_pid == 0 > filter
7. #cat sched_switch/filter
8. common_pid == 0
9. #cat sched_wakeup/filter
10. common_pid == 0
11. #echo prev_pid == 0 > filter
12. #cat sched_switch/filter
13. prev_pid == 0
14. #cat sched_wakeup/filter
15. common_pid == 0

可以看到，虽然将sched子系统的filter设为prev_pid == 0，但由于只有sched_switch事件存在prev_pid域，所以对sched的filter文件的设置只影响了sched_switch。

4.5定义一个event-enabled tracepoint

定义tracepoint不在本文讨论范围之内

参考文档：

【1】Linux Static Tracepoints   http://anton.ozlabs.org/blog/2009/10/07/linux-static-tracepoints/

【2】 linux/Documentation/trace/ftrace.txt

【3】ftrace 学习笔记：http://biancheng.dnbcw.info/linux/340057.html

【4】tracing on linux  http://netsplit.com/2011/03/07/tracing-on-linux/