ftrace追踪内核函数调⽤
前⾔:在追踪内核的⽹络栈时,经常会出现复杂的条件分⽀,导致分不清报⽂处理的重要流程,本⽂介绍的ftrace则能够追踪记录函数的调⽤流程,⾮常⽅便的⽤以分析代码。
⼀. ftrace简单介绍
ftrace是内核提供的⼀种调试⼯具,可以对内核发⽣的事件进⾏记录,⽐如函数调⽤,进程切换,中断开关等。他使⽤debugfs与⽂本进⾏交互,显⽰的结果⾮常直观。更多的ftrace是什么的主题,以及如何实现的,可以参考wiki或者kernel⾃带的Docement/⽂档。本篇主要介绍其中的⼀个tracer:function graph tracer,他可以勾勒出函数的调⽤过程,花费的时间等。
This tracer is useful in several situations:
you want to find the reason of a strange kernel behavior and
need to see what happens in detail on any areas (or specific
ones).
you are experiencing weird latencies but it's difficult to
find its origin.
you want to find quickly which path is taken by a specific
function
you just want to peek inside a working kernel and want to see
what happens there.
这个tracer适⽤但不局限于以上⼏种场景。更多的tracer可以⾃⾏扩展。毕竟,这⾥主要是想追踪内核函数调⽤不是?
⼆. 如何使⽤ftrace
在使⽤ftrace之前,需要内核进⾏⽀持,也就是内核需要打开编译中的ftrace相关选项,关于怎么激活ftrace选项的问题,可以google之,下⾯只说明重要的设置步骤:
1. mkdir /debug;mount -t debugs nodev /debug; /*挂载debugfs到创建的⽬录中去*/
2. cd /debug; cd tracing; /*如果没有tracing⽬录,则内核⽬前还没有⽀持ftrace,需要配置参数,重新编
译*/。
3. echo nop > current_tracer;//清空tracer
4. echo function_graph > current_tracer;//使⽤图形显⽰调⽤关系
5. echo ip_rcv > set_graph_function;//设置过滤函数,可以设置多个
6. echo 1 > tracing_enabled开始追踪
追踪的结果在⽂件trace中,可以使⽤cat,vim等⼯具进⾏查看,如下图就是在追踪ip_rcv()的调⽤栈的结果:
34) | ip_rcv() {
34) | ip_rcv_finish() {
34) 0.513 us | ip_route_input();
34) | ip_local_deliver() {
34) | nf_hook_slow() {
34) | nf_iterate() {
34) | ipt_local_in_hook() {
34) | ipt_do_table() {
34) 0.192 us | local_bh_disable();
34) 0.191 us | _spin_lock();
34) 0.237 us | local_bh_enable();
34) 1.651 us | }
34) 2.214 us | }
34) 3.173 us | }
34) 3.667 us | }
34) | ip_local_deliver_finish() {
34) 0.180 us | raw_local_deliver();
34) | tcp_v4_rcv() {
34) 0.391 us | __inet_lookup_established();
34) 0.367 us | xfrm4_policy_check.clone.0();
34) | sk_filter() {
34) | security_sock_rcv_skb() {
34) | selinux_socket_sock_rcv_skb() {
34) 0.195 us | netlbl_enabled();
34) 0.655 us | }
34) 1.061 us | }
34) 0.176 us | local_bh_disable();
34) 0.193 us | local_bh_enable();
34) 2.176 us | }
34) 0.230 us | _spin_lock();
34) | tcp_v4_do_rcv() {
34) 0.200 us | tcp_parse_md5sig_option();
34) | tcp_rcv_established() {
34) 0.359 us | tcp_ack();
34) 0.240 us | tcp_urg();
34) | tcp_data_queue() {
34) | tcp_try_rmem_schedule() {
34) 0.334 us | __sk_mem_schedule();
34) 0.765 us | }
34) 0.212 us | skb_set_owner_r();
34) 0.350 us | tcp_event_data_recv();
34) 0.184 us | tcp_fast_path_on();
34) 0.176 us | sock_flag();
34) | sock_def_readable() {
34) 0.332 us | _read_lock();
34) | __wake_up_sync_key() {
34) 0.346 us | _spin_lock_irqsave();
34) | __wake_up_common() {
34) | pollwake() {
34) | default_wake_function() {
34) | try_to_wake_up() {
34) | task_rq_lock() {
34) 0.302 us | _spin_lock();
34) 0.796 us | }
34) 0.242 us | task_waking_fair();
34) | select_task_rq_fair() {
34) 0.232 us | select_idle_sibling();
34) 1.522 us | }
34) 0.183 us | _spin_lock();
34) | activate_task() {
34) | enqueue_task() {
34) 0.270 us | update_rq_clock();
34) | enqueue_task_fair() {
recv函数34) | enqueue_entity() {
34) 0.262 us | update_curr();
34) 0.252 us | update_cfs_load();
34) 0.548 us | account_entity_enqueue();
34) 0.189 us | update_cfs_shares();
34) 0.187 us | place_entity();
34) 0.254 us | task_of();
34) 3.405 us | }
34) 3.841 us | }
34) 4.972 us | }
34) 5.364 us | }
34) | check_preempt_curr() {
34) 0.216 us | resched_task();
34) 0.654 us | }
34) 0.189 us | _spin_unlock_irqrestore();
34) + 11.333 us | }
34) + 11.703 us | }
34) + 12.088 us | }
34) + 12.552 us | }
34) 0.219 us | _spin_unlock_irqrestore();
34) + 14.216 us | }
34) + 15.209 us | }
34) + 18.700 us | }
34) | tcp_data_snd_check() {
34) | tcp_current_mss() {
34) | tcp_established_options() {
34) 0.221 us | tcp_v4_md5_lookup();
34) 0.632 us | }
34) 1.028 us | }
34) 0.182 us | __tcp_push_pending_frames();
34) 1.771 us | }
34) | __tcp_ack_snd_check() {
34) | tcp_send_delayed_ack() {
34) | sk_reset_timer() {
34) | mod_timer() {
34) | lock_timer_base() {
34) 0.217 us | _spin_lock_irqsave();
34) 0.624 us | }
34) 0.247 us | idle_cpu();
34) 0.499 us | get_nohz_timer_target();
34) 0.274 us | internal_add_timer();
34) 0.188 us | _spin_unlock_irqrestore();
34) 3.189 us | }
34) 3.580 us | }
34) 3.985 us | }
34) 4.423 us | }
34) + 26.870 us | }
34) + 27.707 us | }
34) + 32.742 us | }
34) + 33.685 us | }
34) + 38.217 us | }
34) + 40.056 us | }
34) + 41.393 us | }
版权声明:本站内容均来自互联网,仅供演示用,请勿用于商业和其他非法用途。如果侵犯了您的权益请与我们联系QQ:729038198,我们将在24小时内删除。
发表评论