• ftrace工具的介绍及使用

    1.什么是ftrace

    ftrace (Function Tracer)是一个针对Linux内核的跟踪框架。虽然它最初的名字是Function Tracer，来自于ftrace记录内核运行时执行的各种函数调用相关信息的能力，但ftrace的跟踪能力覆盖了更广泛的内核内部操作。

    通过各种跟踪插件，ftrace可以针对不同的静态跟踪点，例如调度事件、中断、内存映射I/O、CPU电源状态转换，以及与文件系统和虚拟化相关的操作。此外，还可以动态跟踪内核函数调用，可以通过使用globs将其限制在函数子集内，还可以生成调用图并提供堆栈使用报告。同时，ftrace可以用来测量Linux内核中的各种延迟，比如禁用中断或抢占的时间。

    通过启用CONFIG_FUNCTION_TRACER内核配置选项，可以构建一个启用了ftrace的Linux内核。与ftrace的整个运行时交互是通过包含在特定挂载的debugfs文件系统中的可读和可写的虚拟文件来执行的;因此，ftrace不需要专门的用户空间实用程序来操作。然而，还有额外的用户空间实用工具，为数据记录、分析和可视化提供了更高级的功能;

    2.内核配置

    由于ftrace 工具已经移植到Linux系统中，内核一般会默认配置debugfs,但是所需要的tracer追踪器默认可能只提供nop, 如果需要其他的tracer ， 需要额外配置menuconfig,如下所示：

    我目前只配置 function , function_graph这两个tracer供测试所需。如果需要其他tracer,可自行研究使用。

    Kernel Hacking -> Compile-time checks and compiler options —>Debug Filesystem
    Kernel Hacking -> Tracers:
    Kernel Function Tracer (FUNCTION_TRACER)
    Enable/disable ftrace dynamically (DYNAMIC_FTRACE)
    Trace max stack (STACK_TRACER）
    在这里插入图片描述

    3.ftrace的使用

    3.1trancer命令序列

    当内核启动的时候，用户可以进入/sys/kernel/debug/tracing 目录查看当前支持的trance 命令。README文件提供了一个简短的使用说明，展示了 ftrace 的操作命令序列。

    roo@arm:/sys/kernel/debug/tracing# ls  
available_events            printk_formats       stack_trace_filter  
available_filter_functions  README               timestamp_mode  
available_tracers           saved_cmdlines       trace  
buffer_size_kb              saved_cmdlines_size  trace_clock  
buffer_total_size_kb        saved_tgids          trace_marker  
current_tracer              set_event            trace_marker_raw  
dyn_ftrace_total_info       set_event_pid        trace_options  
enabled_functions           set_ftrace_filter    trace_pipe  
events                      set_ftrace_notrace   tracing_cpumask  
free_buffer                 set_ftrace_pid       tracing_on  
instances                   set_graph_function   tracing_thresh  
max_graph_depth             set_graph_notrace    uprobe_events  
options                     stack_max_size       uprobe_profile  
per_cpu                     stack_trace  

    • 1
    • 2
    • 3
    • 4
    • 5
    • 6
    • 7
    • 8
    • 9
    • 10
    • 11
    • 12
    • 13
    • 14
    • 15
    • current_tracer:
      这用于设置或显示已配置的当前tracer。
    • available_tracers:
      用于获取内核已配的支持的tracer。这里列出的tracer可以通过将它们的名称回显到current_tracer来配置。
    • tracing_on:
      这将设置或显示是否启用对tracer环缓冲区的写入。 在此文件中echo 0以禁用tracer，或echo 1以启用tracer。 注意，这只禁用写入循环缓冲区，跟踪开销仍然可能发生。
    • trace:
      该文件以对人有好的方式将追踪的log保存下来。注意，在读取(打开)这个文件时，跟踪是暂时禁用的。
      -set_ftrace_filter/set_ftrace_notrace:
      在编译内核时配置了动态 ftrace （选中 CONFIG_DYNAMIC_FTRACE 选项）后使用。前者用于显示指定要跟踪的函数，后者则作用相反，用于指定不跟踪的函数。如果一个函数名同时出现在这两个文件中，则这个函数的执行状况不会 被跟踪。这些文件还支持简单形式的含有通配符的表达式，这样可以用一个表达式一次指定多个目标函数；具体使用在后续文章中会有描述。注意，要写入这两个文 件的函数名必须可以在文件 available_filter_functions 中看到。缺省为可以跟踪所有内核函数，文件 set_ftrace_notrace 的值则为空。
    • set_graph_function：
      设置要清晰显示调用关系的函数，显示的信息结构类似于 C 语言代码，这样在分析内核运作流程时会更加直观一些。在使用function_graph 跟踪器时使用；缺省为对所有函数都生成调用关系序列，可以通过写该文件来指定需要特别关注的函数。
    • Other:
      以上只介绍几个常用的tracer, 如果有需要可以查看相关文档。
    1. ftrace使用手册：kernel-src/Documentation/trace/ftrace.txt
    2. ftrace设计文档：kernel-src/Documentation/trace/ftrace-design.txt

    3.2查看当前支持的tracer

    root@Superman:/sys/kernel/debug/tracing# cat available_tracers   
hwlt blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nop

    • 1
    • 2

    3.3 查看/设置当前运行的tracer

    root@Superman:/sys/kernel/debug/tracing# cat current_tracer   
nop  

默认是nop,我们可通过回显命令进行设置当前运行的tracer。如下
root@Superman:/sys/kernel/debug/tracing# cat current_tracer   
nop  
root@Superman:/sys/kernel/debug/tracing# echo function_graph > current_tracer   
root@Superman:/sys/kernel/debug/tracing# cat current_tracer   
function_graph

    • 1
    • 2
    • 3
    • 4
    • 5
    • 6
    • 7
    • 8
    • 9

    3.4开启/关闭tracer

    sysctl kernel.ftrace_enabled=1  
sysctl kernel.ftrace_enabled=0  

    • 1
    • 2

    3.5暂停/继续

    echo 0 > tracing_on  
echo 1 > tracing_on  

    • 1
    • 2

    3.6查看已经收集的结果

    cat trace  

    • 1

    这里会将结果以文本的形式显示到终端，我个人喜欢将其用重定向的方式保存至文件，然后用其他编辑工具，如UE来查看分析。

    cat trace >> MyTracer.txt

    • 1

    也可以通过管道的形式，或者正则表达式等方式捕获自己想要的信息。

    4.调用实例

    使用前，先将debugfs 挂载至用户文件夹下。

    mkdir /debug   
mount -t debugfs nodev /debug  
cd /debug/tracing 

    • 1
    • 2
    • 3

    4.1 function

    **#查看当前支持的traceer
# cat available_tracers   
hwlat blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nop  
# 显示当前运行的tracer
# cat current_tracer   
nop  
# 设置tracer:function
# echo function > current_tracer   
# cat current_tracer   
function  
# 停止tacer 并清空trace
# echo 0 > tracing_on   
# echo 0 > trace  
# cat trace  






 tracer: function  
  
 entries-in-buffer/entries-written: 0/0   #P:2  
  
                              _-----=> irqs-off  
                             / _----=> need-resched  
                            | / _---=> hardirq/softirq  
                            || / _--=> preempt-depth  
                            ||| /     delay  
           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION  
              | |       |   ||||       |         |  
# 执行tracer，捕获sleep 内核动作， 停止tracer
# echo 1 > tracing_on && sleep 1 && echo 0 > tracing_on  
# 读取trcer, 只显示前50行
# cat trace | head -n 50  
 tracer: function  
  
#entries-in-buffer/entries-written: 84487/98407   #P:2  
  
                              _-----=> irqs-off  
                             / _----=> need-resched  
                            | / _---=> hardirq/softirq  
                            || / _--=> preempt-depth  
                            ||| /     delay  
           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION  
              | |       |   ||||       |         |  
          <idle>-0     [000] dn..  6715.669331: smp_reschedule_interrupt <-reschedule_interrupt  
          <idle>-0     [000] dn..  6715.669331: scheduler_ipi <-smp_reschedule_interrupt  
          <idle>-0     [000] .N..  6715.669332: rcu_idle_exit <-do_idle  
          <idle>-0     [000] dN..  6715.669332: rcu_dynticks_eqs_exit <-rcu_idle_exit  
          <idle>-0     [000] .N..  6715.669332: arch_cpu_idle_exit <-do_idle  
          <idle>-0     [000] .N..  6715.669332: tick_nohz_idle_exit <-do_idle  
          <idle>-0     [000] dN..  6715.669332: ktime_get <-tick_nohz_idle_exit  
          <idle>-0     [000] dN..  6715.669333: update_ts_time_stats <-tick_nohz_idle_exit  
          <idle>-0     [000] dN..  6715.669333: nr_iowait_cpu <-update_ts_time_stats  
          <idle>-0     [000] dN..  6715.669333: cpu_load_update_nohz_stop <-tick_nohz_idle_exit  
          <idle>-0     [000] dN..  6715.669333: _raw_spin_lock <-cpu_load_update_nohz_stop  
          <idle>-0     [000] dN..  6715.669333: update_rq_clock <-cpu_load_update_nohz_stop  
          <idle>-0     [000] dN..  6715.669333: cpu_load_update <-cpu_load_update_nohz_stop  
          <idle>-0     [000] dN..  6715.669333: sched_avg_update <-cpu_load_update  
          <idle>-0     [000] dN..  6715.669334: timer_clear_idle <-tick_nohz_idle_exit  
          <idle>-0     [000] dN..  6715.669334: calc_load_nohz_stop <-tick_nohz_idle_exit  
          <idle>-0     [000] dN..  6715.669334: hrtimer_cancel <-tick_nohz_idle_exit  
          <idle>-0     [000] dN..  6715.669334: hrtimer_try_to_cancel <-hrtimer_cancel  
          <idle>-0     [000] dN..  6715.669334: hrtimer_active <-hrtimer_try_to_cancel  
          <idle>-0     [000] dN..  6715.669334: lock_hrtimer_base.isra.19 <-hrtimer_try_to_cancel  
          <idle>-0     [000] dN..  6715.669334: _raw_spin_lock_irqsave <-lock_hrtimer_base.isra.19  
          <idle>-0     [000] dN..  6715.669334: __remove_hrtimer <-hrtimer_try_to_cancel  
          <idle>-0     [000] dN..  6715.669335: _raw_spin_unlock_irqrestore <-hrtimer_try_to_cancel  
          <idle>-0     [000] dN..  6715.669335: hrtimer_forward <-tick_nohz_idle_exit  
          <idle>-0     [000] dN..  6715.669335: hrtimer_start_range_ns <-tick_nohz_idle_exit  
          <idle>-0     [000] dN..  6715.669335: lock_hrtimer_base.isra.19 <-hrtimer_start_range_ns  
          <idle>-0     [000] dN..  6715.669335: _raw_spin_lock_irqsave <-lock_hrtimer_base.isra.19  
          <idle>-0     [000] dN..  6715.669335: enqueue_hrtimer <-hrtimer_start_range_ns  
          <idle>-0     [000] dN..  6715.669336: tick_program_event <-hrtimer_start_range_ns  
          <idle>-0     [000] dN..  6715.669336: clockevents_program_event <-tick_program_event  
          <idle>-0     [000] dN..  6715.669336: ktime_get <-clockevents_program_event  
          <idle>-0     [000] dN..  6715.669336: lapic_next_deadline <-clockevents_program_event  
          <idle>-0     [000] dN..  6715.669339: _raw_spin_unlock_irqrestore <-hrtimer_start_range_ns  
          <idle>-0     [000] dN..  6715.669339: account_idle_ticks <-tick_nohz_idle_exit  
          <idle>-0     [000] .N..  6715.669339: sched_ttwu_pending <-do_idle  
          <idle>-0     [000] .N..  6715.669340: schedule_idle <-do_idle  
          <idle>-0     [000] dN..  6715.669340: rcu_note_context_switch <-__schedule  
          <idle>-0     [000] dN..  6715.669340: _raw_spin_lock <-__schedule  
          <idle>-0     [000] dN..  6715.669340: update_rq_clock <-__schedule  
# **

    • 1
    • 2
    • 3
    • 4
    • 5
    • 6
    • 7
    • 8
    • 9
    • 10
    • 11
    • 12
    • 13
    • 14
    • 15
    • 16
    • 17
    • 18
    • 19
    • 20
    • 21
    • 22
    • 23
    • 24
    • 25
    • 26
    • 27
    • 28
    • 29
    • 30
    • 31
    • 32
    • 33
    • 34
    • 35
    • 36
    • 37
    • 38
    • 39
    • 40
    • 41
    • 42
    • 43
    • 44
    • 45
    • 46
    • 47
    • 48
    • 49
    • 50
    • 51
    • 52
    • 53
    • 54
    • 55
    • 56
    • 57
    • 58
    • 59
    • 60
    • 61
    • 62
    • 63
    • 64
    • 65
    • 66
    • 67
    • 68
    • 69
    • 70
    • 71
    • 72
    • 73
    • 74
    • 75
    • 76
    • 77
    • 78
    • 79
    • 80
    • 81
    • 82
    • 83
    • 84
    • 85
    • 86

    trace 文件给出的信息格式很清晰。
    首先，字段“tracer:”给出了当前所使用的跟踪器的名字，这里为 function 跟踪器。然后是跟踪信息记录的格式，TASK 字段对应任务的名字，PID 字段则给出了任务的进程 ID，字段 CPU# 表示运行被跟踪函数的 CPU 号，这里可以看到 idle 进程运行在 0 号 CPU 上，其进程 ID 是 0 ；字段 TIMESTAMP 是时间戳，其格式为“.”，表示执行该函数时对应的时间戳；FUNCTION 一列则给出了被跟踪的函数，函数的调用者通过符号 “<-” 标明，这样可以观察到函数的调用关系。

    4.2 function_graph

    # echo function_graph > current_tracer  
# echo 0 > tracing_on && echo 0 > trace  
# echo 1 > tracing_on && sleep 1 && echo 0 > tracing_on  
# cat trace | head -n 500  
 tracer: function_graph  
  
 CPU  DURATION                  FUNCTION CALLS  
 |     |   |                     |   |   |   |  
   0)               |                      _cond_resched() {  
   0)   0.118 us    |                        rcu_all_qs();  
   0)   0.488 us    |                      }  
   0)   0.707 us    |                    } /* wait_for_unix_gc */  
   0)               |                    security_socket_getpeersec_dgram() {  
   0)   0.104 us    |                      apparmor_socket_getpeersec_dgram();  
   0)   0.351 us    |                    }  
   0)               |                    sock_alloc_send_pskb() {  
   0)               |                      alloc_skb_with_frags() {  
   0)               |                        __alloc_skb() {  
   0)               |                          kmem_cache_alloc_node() {  
   0)               |                            _cond_resched() {  
   0)   0.110 us    |                              rcu_all_qs();  
   0)   0.314 us    |                            }  
   0)   0.537 us    |                          }  
   0)               |                          __kmalloc_reserve.isra.43() {  
   0)               |                            __kmalloc_node_track_caller() {  
   0)   0.108 us    |                              kmalloc_slab();  
   0)               |                              _cond_resched() {  
   0)   0.119 us    |                                rcu_all_qs();  
   0)   0.325 us    |                              }  
   0)   0.766 us    |                            }  
   0)   0.980 us    |                          }  
   0)   0.119 us    |                          ksize();  
   0)   2.068 us    |                        }  
   0)   2.302 us    |                      }  
   0)   0.118 us    |                      skb_set_owner_w();  
   0)   2.734 us    |                    }  
   0)   0.110 us    |                    unix_scm_to_skb();  
   0)   0.105 us    |                    skb_put();  
   0)               |                    skb_copy_datagram_from_iter() {  
   0)               |                      __check_object_size() {  
   0)   0.114 us    |                        check_stack_object();  
   0)   0.126 us    |                        __virt_addr_valid();  
   0)   0.122 us    |                        __check_heap_object();  
   0)   0.783 us    |                      }  
   0)   1.040 us    |                    }  
   0)   0.109 us    |                    _raw_spin_lock();  
   0)   0.116 us    |                    maybe_add_creds();  
   0)               |                    skb_queue_tail() {  
   0)   0.118 us    |                      _raw_spin_lock_irqsave();  
   0)   0.125 us    |                      _raw_spin_unlock_irqrestore();  
   0)   0.563 us    |                    }  
   0)               |                    sock_def_readable() {  
   0)               |                      __wake_up_sync_key() {  
   0)               |                        __wake_up_common_lock() {  
   0)   0.118 us    |                          _raw_spin_lock_irqsave();  
   0)               |                          __wake_up_common() {  
   0)               |                            ep_poll_callback() {  
   0)   0.113 us    |                              _raw_spin_lock_irqsave();  
   0)   0.118 us    |                              _raw_spin_unlock_irqrestore();  
   0)   0.601 us    |                            }  
   0)   0.856 us    |                          }  
   0)   0.118 us    |                          _raw_spin_unlock_irqrestore();  
   0)   1.521 us    |                        }  
   0)   1.723 us    |                      }  
   0)   1.935 us    |                    }  
   0)   0.110 us    |                    put_pid();  
   0)   9.173 us    |                  } /* unix_stream_sendmsg */  
   0) + 10.304 us   |                } /* sock_sendmsg */  
   0) + 10.535 us   |              } /* sock_write_iter */  
   0) + 10.781 us   |            } /* do_iter_readv_writev */  
   0)   0.110 us    |            __fsnotify_parent();  
   0)   0.122 us    |            fsnotify();  
   0) + 12.727 us   |          } /* do_iter_write */  
   0)   0.112 us    |          kfree();  
   0) + 13.928 us   |        } /* vfs_writev */  
   0)   0.105 us    |        fput();  
   0) + 15.088 us   |      } /* do_writev */  
   0) + 15.307 us   |    } /* SyS_writev */  
   0) + 15.573 us   |  } /* do_syscall_64 */  
   0)               |  do_syscall_64() {  
   0)               |    SyS_poll() {  
   0)               |      do_sys_poll() {  
   0)               |        __check_object_size() {  
   0)   0.122 us    |          check_stack_object();  
   0)   0.344 us    |        }  
   0)               |        __fdget() {  
   0)               |          __fget_light() {  
   0)   0.117 us    |            __fget();  
   0)   0.330 us    |          }  
   0)   0.547 us    |        }  
   0)               |        sock_poll() {  
   0)               |          unix_poll() {  
   0)               |            __pollwait() {  
   0)               |              add_wait_queue() {  
   0)   0.117 us    |                _raw_spin_lock_irqsave();  
   0)   0.114 us    |                _raw_spin_unlock_irqrestore();  
   0)   0.779 us    |              }  
   0)   0.989 us    |            }  
   0)   1.230 us    |          }  
   0)   1.475 us    |        }  
   0)   0.111 us    |        fput();  
   0)               |        poll_schedule_timeout() {  
   0)               |          schedule_hrtimeout_range() {  
   0)               |            schedule_hrtimeout_range_clock() {  
   0)               |              schedule() {  
   0)   0.107 us    |                rcu_note_context_switch();  
   0)   0.110 us    |                _raw_spin_lock();  
   0)   0.121 us    |                update_rq_clock();  
   0)               |                deactivate_task() {  
   0)               |                  dequeue_task_fair() {  
   0)               |                    dequeue_entity() {  
   0)               |                      update_curr() {  
   0)   0.119 us    |                        update_min_vruntime();  
   0)   0.140 us    |                        cpuacct_charge();  
   0)   0.617 us    |                      }  
   0)   0.108 us    |                      __update_load_avg_se.isra.38();  
   0)   0.114 us    |                      clear_buddies();  
   0)   0.111 us    |                      account_entity_dequeue();  
   0)   0.107 us    |                      update_cfs_group();  
   0)   0.108 us    |                      update_min_vruntime();  
   0)   1.930 us    |                    }  
   0)               |                    dequeue_entity() {  
   0)               |                      update_curr() {  
   0)   0.123 us    |                        __calc_delta();  
   0)   0.110 us    |                        update_min_vruntime();  
   0)   0.581 us    |                      }  
   0)   0.129 us    |                      __update_load_avg_se.isra.38();  
   0)   0.108 us    |                      clear_buddies();  
   0)   0.119 us    |                      account_entity_dequeue();  
   0)               |                      update_cfs_group() {  
   0)   0.128 us    |                        reweight_entity();  
   0)   0.375 us    |                      }  
   0)   0.119 us    |                      update_min_vruntime();  
   0)   2.189 us    |                    }  
   0)   0.111 us    |                    hrtick_update();  
   0)   4.680 us    |                  }  
   0)   4.934 us    |                }  
   0)               |                pick_next_task_fair() {  
   0)   0.110 us    |                  check_cfs_rq_runtime();  
   0)               |                  pick_next_entity() {  
   0)   0.109 us    |                    clear_buddies();  
   0)   0.345 us    |                  }  
   0)               |                  pick_next_entity() {  
   0)   0.110 us    |                    clear_buddies();  
   0)   0.315 us    |                  }  
   0)               |                  put_prev_entity() {  
   0)   0.108 us    |                    check_cfs_rq_runtime();  
   0)   0.332 us    |                  }  
   0)               |                  set_next_entity() {  
   0)   0.126 us    |                    __update_load_avg_se.isra.38();  
   0)   0.349 us    |                  }  
   0)               |                  put_prev_entity() {  
   0)   0.104 us    |                    check_cfs_rq_runtime();  
   0)   0.319 us    |                  }  
   0)               |                  set_next_entity() {  
   0)   0.131 us    |                    __update_load_avg_se.isra.38();  
   0)   0.353 us    |                  }  
   0)   3.002 us    |                }  
   0)               |                switch_mm_irqs_off() {  
   0)   0.207 us    |                  load_new_mm_cr3();  
   0)   0.500 us    |                }  

    • 1
    • 2
    • 3
    • 4
    • 5
    • 6
    • 7
    • 8
    • 9
    • 10
    • 11
    • 12
    • 13
    • 14
    • 15
    • 16
    • 17
    • 18
    • 19
    • 20
    • 21
    • 22
    • 23
    • 24
    • 25
    • 26
    • 27
    • 28
    • 29
    • 30
    • 31
    • 32
    • 33
    • 34
    • 35
    • 36
    • 37
    • 38
    • 39
    • 40
    • 41
    • 42
    • 43
    • 44
    • 45
    • 46
    • 47
    • 48
    • 49
    • 50
    • 51
    • 52
    • 53
    • 54
    • 55
    • 56
    • 57
    • 58
    • 59
    • 60
    • 61
    • 62
    • 63
    • 64
    • 65
    • 66
    • 67
    • 68
    • 69
    • 70
    • 71
    • 72
    • 73
    • 74
    • 75
    • 76
    • 77
    • 78
    • 79
    • 80
    • 81
    • 82
    • 83
    • 84
    • 85
    • 86
    • 87
    • 88
    • 89
    • 90
    • 91
    • 92
    • 93
    • 94
    • 95
    • 96
    • 97
    • 98
    • 99
    • 100
    • 101
    • 102
    • 103
    • 104
    • 105
    • 106
    • 107
    • 108
    • 109
    • 110
    • 111
    • 112
    • 113
    • 114
    • 115
    • 116
    • 117
    • 118
    • 119
    • 120
    • 121
    • 122
    • 123
    • 124
    • 125
    • 126
    • 127
    • 128
    • 129
    • 130
    • 131
    • 132
    • 133
    • 134
    • 135
    • 136
    • 137
    • 138
    • 139
    • 140
    • 141
    • 142
    • 143
    • 144
    • 145
    • 146
    • 147
    • 148
    • 149
    • 150
    • 151
    • 152
    • 153
    • 154
    • 155
    • 156
    • 157
    • 158
    • 159
    • 160
    • 161

    function_graph 跟踪器则可以提供类似 C 代码的函数调用关系信息。通过写文件 set_graph_function 可以显示指定要生成调用关系的函数，缺省会对所有可跟踪的内核函数生成函数调用关系图。
    函数图跟踪器对函数的进入与退出进行跟踪，这对于跟踪它的执行时间很有用。函数执行时间超过10微秒的标记一个“+”号，超过1000微秒的标记为一个“！”号。通过echo function_graph > current_tracer可以启用函数图跟踪器。
    CPU 字段给出了执行函数的 CPU 号，本例中都为 1 号 CPU。
    DURATION 字段给出了函数执行的时间长度，以 us 为单位。
    FUNCTION CALLS 则给出了调用的函数，并显示了调用流程。注意，
    对于不调用其它函数的函数，其对应行以“;”结尾，而且对应的 DURATION 字段给出其运行时长.
    对于调用其它函数的函数，则在其“}”对应行给出了运行时长，该时间是一个累加值，包括了其内部调用的函数的执行时长。DURATION 字段给出的时长并不是精确的，它还包含了执行 ftrace 自身的代码所耗费的时间，所以示例中将内部函数时长累加得到的结果会与对应的外围调用函数的执行时长并不一致；不过通过该字段还是可以大致了解函数在时间上的运行开销的。

    4.脚本示例

    #!/bin/sh  
dir=/sys/kernel/debug/tracing  
sysctl kernel.ftrace_enabled=1  
echo function_graph > ${dir}/current_tracer  
echo 1 > ${dir}/tracing_on#  
sleep 1  
echo 0 > ${dir}/tracing_on  
cat ${dir}/trace > ~/mytrace.txt  

    • 1
    • 2
    • 3
    • 4
    • 5
    • 6
    • 7
    • 8
    #!/bin/sh  
echo "format nvme..."  
mkfs.fat /dev/nvme0n1p1  
echo "mount nvme to /mnt"  
mount /dev/nvme0n1p1 /mnt/  
dir=/sys/kernel/debug/tracing  
sysctl kernel.ftrace_enabled=1  
echo "SSD Write..."  
echo nop > ${dir}/current_tracer  
echo function_graph > ${dir}/current_tracer  
echo 1 > ${dir}/tracing_on  
dd if=/dev/zero of=/mnt/zero.bin bs=1M count=512  
echo 0 > ${dir}/tracing_on  
cat ${dir}/trace > ~/SSD_Write.txt  
echo "SSD Read..."  
echo nop > ${dir}/current_tracer  
echo function_graph > ${dir}/current_tracer  
echo 1 > ${dir}/tracing_on  
dd if=/mnt/zero.bin of=/dev/null bs=1M count=512  
echo 0 > ${dir}/tracing_on  
cat ${dir}/trace > ~/SSD_Read.txt  

    • 1
    • 2
    • 3
    • 4
    • 5
    • 6
    • 7
    • 8
    • 9
    • 10
    • 11
    • 12
    • 13
    • 14
    • 15
    • 16
    • 17
    • 18
    • 19
    • 20
    • 21
  • 相关阅读:
    单个处理数据祖籍列表层级关系
    专享策略02 | 套利策略-自动换仓-出场加速
    viper读取配置文件
    安全防御拓扑1
    JDK13版本的环境变量的配置
    Docker--harbor私有仓库部署与管理
    Nuxt3第三篇【布局与组件】
    Java打包jar包的全部方式
    Python算法图解（一）数据结构的分类和基本运算
    111111111
  • 原文地址：https://blog.csdn.net/qq_38505858/article/details/125560945