宋宝华:关于Ftrace的一个完整案例
2018-01-25 10:04
281 查看
Ftrace简介
Ftrace是Linux进行代码级实践分析最有效的工具之一,比如我们进行一个系统调用,出来的时间过长,我们想知道时间花哪里去了,利用Ftrace就可以追踪到一级级的时间分布。Ftrace案例
写一个proc模块,包含一个proc的读和写的入口。test_proc_show()故意调用了一个kill_time()的函数,而kill_time()的函数,又调用了mdelay(2)和kill_moretime()的函数,该函数体内调用mdelay(2)。kill_time()的函数和kill_moretime()函数前面都加了noinline以避免被编译器inline优化掉。
[cpp] view plain copy
#include <linux/module.h>
#include <linux/kernel.h>
#include <linux/init.h>
#include <linux/version.h>
#include <linux/proc_fs.h>
#include <linux/seq_file.h>
#include <linux/delay.h>
#include <linux/uaccess.h>
static unsigned int variable;
static struct proc_dir_entry *test_dir, *test_entry;
static noinline void kill_moretime(void)
{
mdelay(2);
}
static noinline void kill_time(void)
{
mdelay(2);
kill_moretime();
}
static int test_proc_show(struct seq_file *seq, void *v)
{
unsigned int *ptr_var = seq->private;
kill_time();
seq_printf(seq, "%u\n", *ptr_var);
return 0;
}
static ssize_t test_proc_write(struct file *file, const char __user *buffer,
size_t count, loff_t *ppos)
{
...
}
static int test_proc_open(struct inode *inode, struct file *file)
{
return single_open(file, test_proc_show, PDE_DATA(inode));
}
static const struct file_operations test_proc_fops =
{
.owner = THIS_MODULE,
.open = test_proc_open,
.read = seq_read,
.write = test_proc_write,
.llseek = seq_lseek,
.release = single_release,
};
static __init int test_proc_init(void)
{
test_dir = proc_mkdir("test_dir", NULL);
if (test_dir) {
test_entry = proc_create_data("test_rw",0666, test_dir, &test_proc_fops, &variable);
if (test_entry)
return 0;
}
return -ENOMEM;
}
module_init(test_proc_init);
static __exit void test_proc_cleanup(void)
{
remove_proc_entry("test_rw", test_dir);
remove_proc_entry("test_dir", NULL);
}
module_exit(test_proc_cleanup);
MODULE_AUTHOR("Barry Song <baohua@kernel.org>");
MODULE_DESCRIPTION("proc exmaple");
MODULE_LICENSE("GPL v2");
模块对应的Makefile如下:
[plain] view plain copy
KVERS = $(shell uname -r)
# Kernel modules
obj-m += proc.o
# Specify flags for the module compilation.
#EXTRA_CFLAGS=-g -O0
build: kernel_modules
kernel_modules:
make -C /lib/modules/$(KVERS)/build M=$(CURDIR) modules
clean:
make -C /lib/modules/$(KVERS)/build M=$(CURDIR) clean
编译并且加载:
$ makebaohua@baohua-perf:~/develop/training/debug/ftrace/proc$ $ sudo insmod proc.ko[sudo] password for baohua: 之后/proc目录下/proc/test_dir/test_rw文件可被读写。下面我们用Ftrace来跟踪test_proc_show()这个函数。我们把启动ftrace的所有命令写到一个脚本function.sh里面:
[plain] view plain copy
#!/bin/bash
debugfs=/sys/kernel/debug
echo nop > $debugfs/tracing/current_tracer
echo 0 > $debugfs/tracing/tracing_on
echo $$ > $debugfs/tracing/set_ftrace_pid
echo function_graph > $debugfs/tracing/current_tracer
#replace test_proc_show by your function name
echo test_proc_show > $debugfs/tracing/set_graph_function</span>
echo 1 > $debugfs/tracing/tracing_on
exec "$@"
然后用这个脚本去启动cat /proc/test_dir/test_rw,这样ftrace下面test_proc_show()函数就被trace了。
# ./function.sh cat /proc/test_dir/test_rw0读取trace的结果:# cat /sys/kernel/debug/tracing/trace > 1接着用vim打开这个文件1,发现这个文件有600多行:
天了撸,长到看不清!!
Ftrace结果怎么读?
Ftrace结果怎么读?答案非常简单:如果是叶子函数,就直接在这个函数的前面显示它占用的时间,如果是非叶子,要等到 }的时候,再显示时间,如下图:延迟比较大的部分,会有+、#等特殊标号: '$' - greater than 1 second
'@' - greater than 100 milisecond
'*' - greater than 10 milisecond
'#' - greater than 1000 microsecond
'!' - greater than 100 microsecond
'+' - greater than 10 microsecond
' ' - less than or equal to 10 microsecond.
vim对Ftrace进行折叠
上面那个Ftrace文件太大了,大到看不清。我们可以用vim来折叠之,不过需要一个vim的特别配置,我把它存放在了我的~目录,名字叫.fungraph-vim:" Enable folding for ftrace function_graph traces."" To use, :source this file while viewing a function_graph trace, or use vim's" -S option to load from the command-line together with a trace. You can then" use the usual vim fold commands, such as "za", to open and close nested" functions. While closed, a fold will show the total time taken for a call," as would normally appear on the line with the closing brace. Folded" functions will not include finish_task_switch(), so folding should remain" relatively sane even through a context switch."" Note that this will almost certainly only work well with a" single-CPU trace (e.g. trace-cmd report --cpu 1).function! FunctionGraphFoldExpr(lnum) let line = getline(a:lnum) if line[-1:] == '{' if line =~ 'finish_task_switch() {$' return '>1' endif return 'a1' elseif line[-1:] == '}' return 's1' else return '=' endifendfunction
function! FunctionGraphFoldText() let s = split(getline(v:foldstart), '|', 1) if getline(v:foldend+1) =~ 'finish_task_switch() {$' let s[2] = ' task switch ' else let e = split(getline(v:foldend), '|', 1) let s[2] = e[2] endif return join(s, '|')endfunction
setlocal foldexpr=FunctionGraphFoldExpr(v:lnum)setlocal foldtext=FunctionGraphFoldText()setlocal foldcolumn=12setlocal foldmethod=expr之后我们配置vim为这个模板来打开前面那个600多行的文件1: vim -S ~/.fungraph-vim 1这样我们看到的样子是:
我们可以把光标移动到第5行,键盘敲打za,则展开为:
继续展开第6行的kill_time(),按za:
我们可以用z、a两个按键,搜索或者展开Ftrace的结果。
最后,https://github.com/brendangregg/perf-tools对Ftrace的功能进行了很好的封装和集成,建议大家用perf-tools来使用Ftrace,则效果更佳更简单。
有空再聊perf-tools。
相关文章推荐
- 宋宝华:关于Ftrace的一个完整案例
- 宋宝华:关于Ftrace的一个完整案例
- 宋宝华:关于Ftrace的一个完整案例
- 【阅读笔记】关于Direct3D初始化的一个完整工程及介绍
- 开发一个简单的JSP标签完整案例的步骤
- SpringBoot系列之三_一个完整的MVC案例
- 关于DG配置备库无法Real-Time Apply,无法实时查询的一个案例
- 关于IE首页被恶意修改的一个处理案例
- [原创]java WEB学习笔记22:MVC案例完整实践(part 3)---多个请求对应一个Servlet解析
- 关于Excel操作编写的一个软件设计构思案例[连载] --保存条件设定的另一种方式:更新与插入方法
- 关于Excel操作编写的一个软件设计构思案例[连载] --辅助功能:补全缺少数据、树定位、文本读与保存
- urlretrieve关于循环下载的一个案例
- 关于《Java编程思想》注解篇的一个案例所遇到的疑惑-apt参数的问题
- 故障案例--binlog_format不为row模式下关于时区设置的一个坑
- 关于Promise的一个案例
- openfire:openfire插件开发案例——testpulg.jar插件(功能:演示一个插件的完整开发过程)
- 通过一个案例彻底读懂10046 trace--字节级深入破解
- helloworld:一个完整的WCF案例
- CICS中关于map的操作,教你如何创建一个完整的map
- 一个关于类的案例