【linux】kernel-trace

linux kernel trace

配置

源码路径： kernel/trace

trace内核配置

CONFIG_TRACING=y
CONFIG_IRQSOFF_TRACER=y
CONFIG_PREEMPT_TRACER=y
CONFIG_FUNCTION_TRACER=y
CONFIG_PREEMPTIRQ_TRACEPOINTS=y
CONFIG_FUNCTION_GRAPH_TRACER=y

trace接口使用

/sys/kernel/debug/tracing目录下提供了ftrace的设置和属性接口，对ftrace的配置可以通过echo

通用配置

available_tracers-------------当前编译及内核的跟踪器列表，current_tracer必须是这里面支持的跟踪器。
current_tracer----------------用于设置或者显示当前使用的跟踪器列表。系统启动缺省值为nop，使用echo将跟踪器名字写入即可打开。可以通过写入nop重置跟踪器。
buffer_size_kb----------------用于设置单个CPU所使用的跟踪缓存的大小。跟踪缓存为RingBuffer形式，如果跟踪太多，旧的信息会被新的跟踪信息覆盖掉。需要先将current_trace设置为nop才可以。
buffer_total_size_kb----------显示所有的跟踪缓存大小，不同之处在于buffer_size_kb是单个CPU的，buffer_total_size_kb是所有CPU的和。free_buffer-------------------此文件用于在一个进程被关闭后，同时释放RingBuffer内存，并将调整大小到最小值。
hwlat_detector/--------------Hardware Latency Detector文件夹
instances/--------------------创建不同的trace buffer实例，可以在不同的trace buffers中分开记录。
tracing_cpumask-------------可以通过此文件设置允许跟踪特定CPU，二进制格式。
per_cpu-----------------------CPU相关的trace信息，包括stats、trace、trace_pipe和trace_pipe_raw。stats：当前CPU的trace统计信息trace：当前CPU的trace文件。trace_pipe：当前CPU的trace_pipe文件。
printk_formats----------------提供给工具读取原始格式trace的文件。
saved_cmdlines---------------存放pid对应的comm名称作为ftrace的cache，这样ftrace中不光能显示pid还能显示comm。
saved_cmdlines_size----------saved_cmdlines的数目
snapshot----------------------是对trace的snapshot。echo 0 清空缓存，并释放对应内存。echo 1 进行对当前trace进行snapshot，如没有内存则分配。echo 2 清空缓存，不释放也不分配内存。
trace--------------------------查看获取到的跟踪信息的接口，echo > trace可以清空当前RingBuffer。
trace_pipe--------------------输出和trace一样的内容，但是此文件输出Trace同时将RingBuffer中的内容删除，这样就避免了RingBuffer的溢出。可以通过cat trace_pipe > trace.txt &保存文件。
trace_clock-------------------显示当前Trace的timestamp所基于的时钟，默认使用local时钟。local：默认时钟；可能无法在不同CPU间同步；global：不同CUP间同步，但是可能比local慢；counter：这是一个跨CPU计数器，需要分析不同CPU间event顺序比较有效。
trace_marker-----------------从用户空间写入标记到trace中，用于用户空间行为和内核时间同步。
trace_marker_raw------------以二进制格式写入到trace中。
trace_options----------------控制Trace打印内容或者操作跟踪器，可以通过trace_options添加很多附加信息。
options----------------------trace选项的一系列文件，和trace_options对应。
trace_stat/-------------------每个CPU的Trace统计信息
tracing_max_latency--------记录Tracer的最大延时。例如，最大中断disable时间。最大时间被记录到本文件，对应的trace被记录到“trace”文件。新的trace最有大于现在的max latency胡，才会被记录。echo xxx > tracing_max_latency // 手工设置一个门限，只有大于门限才会被记录。
tracing_on-------------------用于控制跟踪打开或停止，0停止跟踪，1继续跟踪。
tracing_thresh---------------延时记录Trace的阈值，当延时超过此值时才开始记录Trace。单位是ms，只有非0才起作用。

Events配置

available_events-------------列出系统中所有可用的Trace events，分两个层级，用冒号隔开。
events/-----------------------系统Trace events目录，在每个events下面都有enable、filter和fotmat。enable是开关；format是events的格式，然后根据格式设置 filter。
set_event---------------------将Trace events名称直接写入set_event就可以打开。
set_event_pid----------------指定追踪特定进程的events。

Function配置

vailable_filter_functions------记录了当前可以跟踪的内核函数，不在该文件中列出的函数，无法跟踪其活动。
dyn_ftrace_total_info---------显示available_filter_functins中跟中函数的数目，两者一致。
enabled_functions------------显示有回调附着的函数名称。
function_profile_enabled-----打开此选项，在trace_stat中就会显示function的统计信息。
set_ftrace_filter----------------用于显示指定要跟踪的函数
set_ftrace_notrace-------------用于指定不跟踪的函数，缺省为空。
set_ftrace_pid------------------用于指定要追踪特定进程的函数。

Function graph配置

max_graph_depth-------------函数嵌套的最大深度。
set_graph_function------------设置要清晰显示调用关系的函数，在使用function_graph跟踪器是使用，缺省对所有函数都生成调用关系。
set_graph_notrace-------------不跟踪特定的函数嵌套调用。

Stack trace设置

stack_max_size---------------当使用stack跟踪器时，记录产生过的最大stack size
stack_trace-------------------显示stack的back trace
stack_trace_filter-------------设置stack tracer不检查的函数名称

跟踪器tracer功能描述

cat /sys/kernel/debug/tracing/available_tracers

函数类：function， function_graph， stack
延时类：irqsoff， preemptoff， preemptirqsoff， wakeup， wakeup_rt， waktup_dl
其他类：nop， mmiotrace， blk

function #追踪所有的内核函数
function_graph #和“function tracer比较类似，但它除了探测函数的入口还探测函数的出口。它可以画出一个图形化的函数调用，类似于c源代码风格
blk 	#块设备tracer
irqsoff #追踪最大关闭中断时间
preemptoff	#追踪最大关闭抢占时间
preemptirqsoff	#追踪 关闭中断 and/or 关闭抢占 的最大时间
wakeup	#追踪最高优先级普通任务从获得调度到被唤醒的最大延迟时间
wakeup_rt	#追踪RT类型的任务从获得调度到被唤醒的最大延迟时间
wakeup_dl	#追踪Deadline类型的任务从获得调度到被唤醒的最大延迟时间
mmiotrace	#追踪硬件IO
branch	#追踪likely/unlikely的分支预测情况
nop 	#空的tracer

使用示例

1.irqsoff

当中断关闭CPU不能响应任何外部的事件，将会阻止内核响应timer、鼠标中断，对应的结果就是响应延迟。

irqsoff tracer追踪关中断时间，当一个新的最大latency到来时，它会记住新的最大latency event，丢弃掉旧的最大latency event。”echo 0 >tracing_max_latency”会复位最大值。

cd /sys/kernel/debug/tracing
echo 0 > options/function-trace
echo irqsoff > current_tracer
echo 1 > tracing_on
echo 0 > tracing_max_latency
sleep 3
echo 0 > tracing_on
cat trace

 # tracer: irqsoff## irqsoff latency trace v1.1.5 on 5.10.160# --------------------------------------------------------------------# latency: 414 us, #4/4, CPU#1 | (M:desktop VP:0, KP:0, SP:0 HP:0 #P:8)#    -----------------#    | task: sh-1098 (uid:0 nice:0 policy:0 rt_prio:0)#    -----------------#  => started at: hvc_write#  => ended at:   n_tty_write---------------------------记录禁止中断时间最长的开始和结束函数###                    _------=> CPU#         #                   / _-----=> irqs-off-----------------d表示中断被disabled，'.'表示中断没有被关闭。      #                  | / _----=> need-resched-------------N-表示need_resched被设置；'.'-表示need_resched没有被设置，中断返回不会进行进程切换    #                  || / _---=> hardirq/softirq----------H-表示softirq中发生了硬件中断；h-硬件中断；s-softirq；'.'-不在中断上下文中#                  ||| / _--=> preempt-depth------------当抢占中断势能后，该域代表preempt_disabled的级别   #                  |||| /     delay            #  cmd     pid     ||||| time  |   caller---------------cmd-进程名，pid-进程id，time-表示trace从开始到当前的相对时间，delay-突出显示那些有高延迟的地方以便引起注意。！表示需要引起注意      #     \   /        |||||  \    |   /         sh-1098      1d...    0us!: __raw_spin_lock_irqsave <-hvc_writesh-1098      1d...  414us : hvc_write <-n_tty_writesh-1098      1d...  415us : tracer_hardirqs_on <-n_tty_writesh-1098      1d...  418us : <stack trace>=> n_tty_write=> file_tty_write.constprop.0=> redirected_tty_write=> new_sync_write=> vfs_write=> ksys_write=> __arm64_sys_write=> el0_svc_common.constprop.0=> do_el0_svc=> el0_svc=> el0_sync_handler=> el0_sync

2.preemptoff

当抢占关闭，我们除了接收中断，不能进行任务调度。

preemptoff tracer用来追踪抢占关闭时间，和irqsoff非常类似。

cd /sys/kernel/debug/tracing
echo 0 > options/function-trace
echo preemptoff > current_tracer
echo 1 > tracing_on
echo 0 > tracing_max_latency
sleep 3
echo 0 > tracing_on
cat trace

3.preemptirqsoff

关闭中断和抢占

preemptirqsoff tracer追踪抢占/中断任一被关闭的最大延迟时间

local_irq_disable();
call_function_with_irqs_off();
preempt_disable();
call_function_with_irqs_and_preemption_off();
local_irq_enable();
call_function_with_preemption_off();
preempt_enable();

• irqsoff tracer记录的时间 = call_function_with_irqs_off() + call_function_with_irqs_and_preemption_off()

• preemptoff tracer记录的时间 = call_function_with_irqs_and_preemption_off() + call_function_with_preemption_off()

• preemptirqsoff tracer记录的时间 = total时间

  相关函数
  spin_lock()会调用preempt_disable() 导致本核的抢占调度被关闭（preempt_disable函数实际增加preempt_count来达到此效果），spin_lock_irq()是local_irq_disable()+preempt_disable()的合体。

  local_irq_disable()/loca_irq_save()的disable和save版的唯一区别是，要不要保存CPU对中断的屏蔽状态。

  spin_lock_irq()/spin_lock_irqsave(lock, flags)的唯一区别是，要不要保存CPU对中断的屏蔽状态。

 cd /sys/kernel/debug/tracingecho 0 > options/function-traceecho preemptirqsoff > current_tracerecho 1 > tracing_onecho 0 > tracing_max_latencysleep 3echo 0 > tracing_oncat trace

参考：

https://blog.csdn.net/pwl999/article/details/80420905

https://www.kernel.org/doc/html/latest/trace/ftrace.html

https://www.cnblogs.com/arnoldlu/p/7211249.html