Linux 追踪技术 ftrace的使用（二）_ftrace跟踪线程(1)

最新推荐文章于 2024-05-20 17:15:16 发布

m0_74918915

最新推荐文章于 2024-05-20 17:15:16 发布

阅读量683

点赞数 10

文章标签： linux 运维服务器

本文链接：https://blog.csdn.net/m0_74918915/article/details/138230654

版权

echo 0 > tracing_on
echo nop > current_tracer
echo > trace

追踪 pid = 411870 的任务：

 echo 411870 > set_ftrace_pid
 echo function > current_tracer
 echo 1 > tracing_on
 cat trace | more

在这里插入图片描述

二、Ftrace function_graph

2.1 Graph Tracing

此跟踪器类似于函数跟踪器，只是它在函数的入口和出口处探测函数。这是通过在每个 task_struct 中使用动态分配的返回地址堆栈来完成的。在函数进入时，跟踪器会覆盖每个跟踪函数的返回地址以设置自定义探针。因此原始返回地址存储在task_struct中的返回地址堆栈中。

在函数的两端进行探测会导致特殊功能，例如：
（1）衡量函数执行时间。
（2）有一个可靠的调用栈来绘制函数调用图。

这个跟踪器在以下几种情况下是有用的:
（1）想找到内核异常行为的原因，需要详细了解在任何区域(或特定区域)发生了什么。
（2）正在经历不寻常的延迟，但很难找到它的起源。
（3）快速找到特定功能所采用的路径
（4）查看运行中的内核，看看那里发生了什么。

有几列可以动态启用/禁用。您可以根据需要使用所需的每种选项组合：

function_graph 跟踪器打印函数的调用图，展示其代码流。
在这里插入图片描述
只跟踪一个函数及其所有子函数，将其名称echo 到 set_graph_function 中：

echo do_nanosleep > set_graph_function

下面使用 do_nanosleep() 函数上的 function_graph 跟踪器来显示其子函数调用：

echo do_nanosleep > set_graph_function
echo function_graph > current_tracer

在这里插入图片描述

 echo nop > current_tracer
 echo > set_graph_function

输出显示子调用和代码流：do_nanosleep() 调用 hrtimer_start_range_ns().左侧的列显示了 CPU（在此输出中，主要是 CPU 3）和函数的持续时间，以便可以识别延迟.高延迟包括一个字符符号以帮助您注意它们，在此输出中，延迟为 1000337 微秒（1.0 秒）旁边的“$”。
在这里插入图片描述

$: Greater than 1 second
@: Greater than 100 ms
\*: Greater than 10 ms
#: Greater than 1 ms
!: Greater than 100 μs
+: Greater than 10 μs

这个例子特意没有设置函数过滤器（set_ftrace_filter），这样所有子调用都可以看到。但是，这确实会产生一些开销，从而夸大了报告的持续时间。它通常对于定位高延迟的来源仍然很有用，这会使增加的开销相形见绌。当您希望给定函数的时间更准确时，可以使用函数过滤器来减少跟踪的函数。例如，仅跟踪 do_nanosleep()：

echo do_nanosleep > set_ftrace_filter

以 do_sys_open 函数为例子来测试function_graph：

echo do_sys_open > set_graph_function
echo function_graph > current_tracer
echo funcgraph-proc > trace_options

在这里插入图片描述
CPU 字段给出了执行函数的 CPU 号，本例中为2 号 CPU
TASK/PID 地段给出进程名称和进程PID号
DURATION 字段给出了函数执行的时间长度，以 us 为单位。
FUNCTION CALLS 则给出了调用的函数，并显示了调用流程。
需要注意：

对于不调用其它函数的函数，其对应行以“;”结尾，而且对应的 DURATION 字段给出其运行时长；

对于调用其它函数的函数，则在其“}”对应行给出了运行时长，该时间是一个累加值，包括了其内部调用的函数的执行时长。DURATION 字段给出的时长并不是精确的，它还包含了执行 ftrace 自身的代码所耗费的时间，所以示例中将内部函数时长累加得到的结果会与对应的外围调用函数的执行时长并不一致；不过通过该字段还是可以大致了解函数在时间上的运行开销的。

备注：function graph trace 实际是在要跟踪函数的入口处和返回处分别放置了钩子函数，在要跟踪函数的入口处插入钩子函数ftrace_caller，在要跟踪函数的返回处插入钩子函数return_to_handler。因此function_graph tracer即可以跟踪到函数的入口还可以跟踪到函数的返回

2.2 Options

选项可用于更改输出，可以在选项options目录中列出：

ls options/funcgraph-\*

在这里插入图片描述
这些调整输出并且可以包括或排除详细信息，例如 CPU ID (funcgraph-cpu)、进程名称 (funcgraph-proc)、函数持续时间 (funcgraph-duration) 和延迟标记 (funcgraph-overhead)。

（1）
执行函数的 CPU 编号默认启用。有时最好只跟踪一个 cpu，或者您有时可能会在 cpu 跟踪切换时看到无序的函数调用。

hide: echo nofuncgraph-cpu > trace_options
show: echo funcgraph-cpu > trace_options

（2）
持续时间（函数的执行时间）显示在函数的右括号行上，或者在叶子函数的情况下显示在与当前函数相同的行上。它是默认启用的。

hide: echo nofuncgraph-duration > trace_options
show: echo funcgraph-duration > trace_options

在这里插入图片描述
叶子函数：没有调用其他的函数。

（3）
task/pid 字段显示执行该函数的线程 cmdline 和 pid。默认禁用。

hide: echo nofuncgraph-proc > trace_options
show: echo funcgraph-proc > trace_options

比如：

# tracer: function\_graph
#
# CPU TASK/PID DURATION FUNCTION CALLS
# |    |    |           |   |                     |   |   |   |
0)    sh-4802     |               |                  d\_free() {
0)    sh-4802     |               |                    call\_rcu() {
0)    sh-4802     |               |                      \_\_call\_rcu() {
0)    sh-4802     |   0.616 us    |                        rcu\_process\_gp\_end();
0)    sh-4802     |   0.586 us    |                        check\_for\_new\_grace\_period();
0)    sh-4802     |   2.899 us    |                      }
0)    sh-4802     |   4.040 us    |                    }
0)    sh-4802     |   5.151 us    |                  }
0)    sh-4802     | + 49.370 us   |                }

(4)
在达到持续时间阈值的情况下，开销字段在持续时间字段之前。

hide: echo nofuncgraph-overhead > trace_options
show: echo funcgraph-overhead > trace_options
depends on: funcgraph-duration

比如：

3) # 1837.709 us |          } /\* \_\_switch\_to \*/
3)               |          finish\_task\_switch() {
3)   0.313 us    |            \_raw\_spin\_unlock\_irq();
3)   3.177 us    |          }
3) # 1889.063 us |        } /\* \_\_schedule \*/
3) ! 140.417 us  |      } /\* \_\_schedule \*/
3) # 2034.948 us |    } /\* schedule \*/
3) \* 33998.59 us |  } /\* schedule\_preempt\_disabled \*/

[...]

1)   0.260 us    |              msecs\_to\_jiffies();
1)   0.313 us    |              \_\_rcu\_read\_unlock();
1) + 61.770 us   |            }
1) + 64.479 us   |          }
1)   0.313 us    |          rcu\_bh\_qs();
1)   0.313 us    |          \_\_local\_bh\_enable();
1) ! 217.240 us  |        }
1)   0.365 us    |        idle\_cpu();
1)               |        rcu\_irq\_exit() {
1)   0.417 us    |          rcu_eqs_enter_common.isra.47();
1)   3.125 us    |        }
1) ! 227.812 us  |      }
1) ! 457.395 us  |    }
1) @ 119760.2 us |  }

[...]

2)               |    handle\_IPI() {
1)   6.979 us    |                  }
2)   0.417 us    |      scheduler\_ipi();
1)   9.791 us    |                }
1) + 12.917 us   |              }
2)   3.490 us    |    }
1) + 15.729 us   |            }
1) + 18.542 us   |          }
2) $ 3594274 us  |  }

+ means that the function exceeded 10 usecs.
! means that the function exceeded 100 usecs.
# means that the function exceeded 1000 usecs.
\* means that the function exceeded 10 msecs.
@ means that the function exceeded 100 msecs.
$ means that the function exceeded 1 sec.

（5）

对于开始在跟踪缓冲区中的函数，可以在右括号（the closing bracket）后显示函数名称，从而可以更轻松地使用 grep 搜索函数持续时间。默认禁用。

hide: echo nofuncgraph-tail > trace_options
show: echo funcgraph-tail > trace_options

nofuncgraph-tail 示例（默认）：

0)               |      putname() {
0)               |        kmem\_cache\_free() {
0)   0.518 us    |          \_\_phys\_addr();
0)   1.757 us    |        }
0)   2.861 us    |      }

funcgraph-tail 示例：

0)               |      putname() {
0)               |        kmem\_cache\_free() {
0)   0.518 us    |          \_\_phys\_addr();
0)   1.757 us    |        } /\* kmem\_cache\_free() \*/	 右括号（代表函数结束）显示函数名称
0)   2.861 us    |      } /\* putname() \*/	 --右括号（代表函数结束）显示函数名称

（6）

可以使用 trace_printk() 对特定函数 function() 添加一些注释例如，如果您想在 function() 函数中添加注释，您只需包含 <linux/ftrace.h> 并在 function() 中调用 trace_printk() ：

trace\_printk("I'm a comment!\n")

将产生：

1)               |              function()  {
1)               |                /\* I'm a comment! \*/
1)   1.449 us    |             }

三、tracepoint

3.1 tracepoint简介

参考：Event Tracing
tracepoint是内核静态检测，跟踪点在技术上只是放置在内核源代码中的跟踪函数；它们从定义和格式化它们的参数的跟踪事件接口中使用。跟踪事件在 tracefs 中可见，并与 Ftrace 共享输出和控制文件

无需创建自定义内核模块即可使用tracepoint来使用 event tracing infrastructure 注册探测功能。

并非所有tracepoint都可以使用 event tracing system 进行跟踪；内核开发人员必须提供代码片段，这些代码片段定义了如何将跟踪信息保存到跟踪缓冲区中，以及应该如何打印跟踪信息。

基于 ftrace 跟踪内核静态跟踪点，包括全部可用于跟踪的静态跟踪点，可跟踪的完整列表可通过 available_events 查看：
在这里插入图片描述
events 目录下查看到各分类的子目录：

ls -F events

在这里插入图片描述
例如，以下启用 block:block_rq_issue 跟踪点并实时监视事件。此示例通过禁用跟踪点完成：

echo 1 > events/block/block_rq_issue/enable
cat trace_pipe | more

前五列是：进程名称“-”PID、CPU ID、标志、时间戳（秒）和事件名称。其余的是跟踪点的格式字符串。
在这里插入图片描述

echo 0 > events/block/block_rq_issue/enable

从这个例子中可以看出，跟踪点在事件下的目录结构中有控制文件。每个跟踪系统都有一个目录（例如，“block”）和每个事件的子目录（例如，“block_rq_issue”）：
在这里插入图片描述
这些控制文件记录在 Linux 源代码的 Documentation/trace/events.rst 下，在此示例中，启用文件用于打开和关闭跟踪点。其他文件提供过滤和触发功能。

3.2 Filter

可以包含过滤器以仅在满足布尔表达式时记录事件。它有一个受限制的语法：

field operator value

（1）数字运算符是以下之一：==、!=、<、<=、>、>=、&；

（2）对于字符串：==、!=、~。

（3）“~”运算符执行 shell glob 样式的匹配，带有通配符：*、?、[]。

这些布尔表达式可以用括号分组并使用：&&、|| 组合。

备注：
通配符*：表示字符在匹配模式的文本中出现0次或多次
通配符?：表示字符在匹配模式的文本中出现0次或1次
通配符[]: []表示字符组，可以定义用来匹配文本模式中某个位置的一组字符。如果字符组中某个字符出现在了数据流中，就匹配该模式。

例如，以下对已启用的 block:block_rq_insert 跟踪点设置过滤器以仅跟踪字节字段大于 64 KB 的事件：

echo 'bytes > 65536' > events/block/block_rq_insert/filter

输出现在只包含较大的 I/O。

echo 0 > events/block/block_rq_insert/filter //echo 0 重置过滤器

3.3 Trigger

触发事件时，触发器会运行额外的跟踪命令。该命令可能是启用或禁用其他跟踪、打印堆栈跟踪或获取跟踪缓冲区的快照。当前未设置触发器时，可以从触发器文件中列出可用的触发器命令。例如：

cat events/block/block_rq_issue/trigger

在这里插入图片描述
触发器的一个用例是当您希望查看导致错误条件的事件时：可以将触发器放置在错误条件上，该条件可以禁用跟踪 (traceoff)，以便跟踪缓冲区仅包含先前的事件，或者获取一个快照（snapshot）来保存它。

触发器可以通过使用 if 关键字与上一节中显示的过滤器结合使用。这可能是匹配错误条件或有趣事件所必需的。例如，要在大于 64 KB 的块 I/O 排队时停止记录事件：

 echo 'traceoff if bytes > 65536' > events/block/block_rq_insert/trigger

四、kprobes

参考：Kprobe-based Event Tracing

这些事件类似于基于跟踪点的事件。它不是基于 Tracepoint，而是基于 kprobes（kprobe 和 kretprobe）。所以它可以探测 kprobes 可以探测的任何地方（这意味着，除了那些带有 __kprobes/nokprobe_inline 注释和那些标记为 NOKPROBE_SYMBOL 的函数之外的所有函数）。与基于 Tracepoint 的事件不同，它可以动态添加和删除.

要启用此功能，请使用 CONFIG_KPROBE_EVENTS=y 构建内核。

与events tracer（tracepoint）类似，这不需要通过 current_tracer 激活。取而代之的是，通过 /sys/kernel/debug/tracing/kprobe_events 添加探测点，并通过 /sys/kernel/debug/tracing/events/kprobes//enable 启用它。

您也可以使用 /sys/kernel/debug/tracing/dynamic_events 而不是 kprobe_events。该接口也将提供对其他动态事件的统一访问。

kprobes 是内核动态检测机制，允许我们跟踪函数任意位置，还可用于获取函数参数与结果返回值。kprobe 机制跟踪函数须是 available_filter_functions 列表中的子集。

kprobes 创建 kprobe 事件供跟踪器使用，它与 Ftrace 共享 tracefs 输出和控制文件。kprobes 类似于 Ftrace 函数跟踪器，因为它们跟踪核函数。然而，kprobes 可以进一步定制，可以放置在函数偏移量（单独的指令）上，并且可以报告函数参数和返回值。

4.1 Event Tracing

每个探针事件过滤功能允许您在每个探针上设置不同的过滤器，并为您提供将在跟踪缓冲区中显示的参数。如果在 kprobe_events 中的 ‘p:’ 或 ‘r:’ 之后指定了事件名称，它会在 tracking/events/kprobes/ 下添加一个事件，在该目录中您可以看到 id、enable、format 、filter 和 trigger。

例如，以下使用 kprobes 检测 do_nanosleep() 内核函数：

echo 'p:brendan do\_nanosleep' >> kprobe_events
echo 1 > events/kprobes/brendan/enable
cat trace | more

在这里插入图片描述

enable:
You can enable/disable the probe by writing 1 or 0 on it.

format:
This shows the format of this probe event.

filter:
You can write filtering rules of this event.

id:
This shows the id of this probe event.

trigger:
This allows to install trigger commands which are executed when the event is hit

在这里插入图片描述

echo 0 > events/kprobes/brendan/enable
echo '-:brendan' >> kprobe_events

通过将特殊语法附加到 kprobe_events 来创建和删除 kprobe。创建后，它会与跟踪点一起出现在 events 目录中，并且可以以类似的方式使用。kprobe 语法在 Documentation/trace/kprobetrace.rst 下的内核源代码中有完整说明。kprobes 能够跟踪内核函数的进入和返回以及函数偏移量。

kprobe_events 概要：

 p[:[GRP/]EVENT] [MOD:]SYM[+offs]|MEMADDR [FETCHARGS]  : Set a probe
 r[MAXACTIVE][:[GRP/]EVENT] [MOD:]SYM[+0] [FETCHARGS]  : Set a return probe
 p:[GRP/]EVENT] [MOD:]SYM[+0]%return [FETCHARGS]       : Set a return probe
 -:[GRP/]EVENT                                         : Clear a probe

GRP            : Group name. If omitted, use "kprobes" for it.
EVENT          : Event name. If omitted, the event name is generated
                 based on SYM+offs or MEMADDR.
MOD            : Module name which has given SYM.
SYM[+offs]     : Symbol+offset where the probe is inserted.
SYM%return     : Return address of the symbol
MEMADDR        : Address where the probe is inserted.
MAXACTIVE      : Maximum number of instances of the specified function that
                 can be probed simultaneously, or 0 for the default value
                 as defined in Documentation/trace/kprobes.rst section 1.3.1.

FETCHARGS      : Arguments. Each probe can have up to 128 args.
 %REG          : Fetch register REG
 @ADDR         : Fetch memory at ADDR (ADDR should be in kernel)
 @SYM[+|-offs] : Fetch memory at SYM +|- offs (SYM should be a data symbol)
 $stackN       : Fetch Nth entry of stack (N >= 0)
 $stack        : Fetch stack address.
 $argN         : Fetch the Nth function argument. (N >= 1) (\\*1)
 $retval       : Fetch return value.(\\*2)
 $comm         : Fetch current task comm.
 +|-[u]OFFS(FETCHARG) : Fetch memory at FETCHARG +|- OFFS address.(\\*3)(\\*4)
 \IMM          : Store an immediate value to the argument.
 NAME=FETCHARG : Set NAME as the argument name of FETCHARG.
 FETCHARG:TYPE : Set TYPE as the type of FETCHARG. Currently, basic types
                 (u8/u16/u32/u64/s8/s16/s32/s64), hexadecimal types
                 (x8/x16/x32/x64), "string", "ustring" and bitfield
                 are supported.

 (\\*1) only for the probe on function entry (offs == 0).
 (\\*2) only for return probe.
 (\\*3) this is useful for fetching a field of data structures.
 (\\*4) "u" means user-space dereference. See :ref:`user_mem_access`.

在上面的示例中，字符串“p:brendan do_nanosleep”为内核符号 do_nanosleep() 创建了一个名为“brendan”的探针 (p:)。字符串“-:brendan”删除名称为“brendan”的探测。

4.2 Arguments

与函数跟踪不同，kprobes 可以检查函数参数和返回值。例如，这里是前面跟踪的 do_nanosleep() 函数的声明，来自 kernel/time/hrtimer.c，其中突出显示了参数变量类型：

static int __sched do\_nanosleep(struct hrtimer\_sleeper \*t, enum hrtimer\_mode mode)
{
	hrtimer\_init\_sleeper(t, current);

	do {
		set\_current\_state(TASK_INTERRUPTIBLE);
		hrtimer\_start\_expires(&t->timer, mode);

		if (likely(t->task))
			freezable\_schedule();

		hrtimer\_cancel(&t->timer);
		mode = HRTIMER_MODE_ABS;

	} while (t->task && !signal\_pending(current));

	\_\_set\_current\_state(TASK_RUNNING);

	return t->task == NULL;
}

跟踪 Intel x86_64 系统上的前两个参数并将它们打印为十六进制（默认值）：

echo 'p:brendan do_nanosleep hrtimer_sleeper=$arg1 hrtimer_mode=$arg2' >> kprobe_events

在这里插入图片描述

echo 0 > events/kprobes/brendan/enable
echo '-:brendan' >> kprobe_events

在第一行的事件描述中添加了额外的语法：例如，字符串“hrtimer_sleeper=$arg1”跟踪函数的第一个参数并使用自定义名称“hrtimer_sleeper”。这已在输出中突出显示。
在 Linux 4.20 中添加了访问

、

arg1、

arg1、arg2 等函数的参数。以前的 Linux 版本需要使用寄存器名称。这是使用寄存器名称的等效 kprobe 定义：

 echo 'p:brendan do_nanosleep hrtimer_sleeper=%di hrtimer_mode=%si' >> kprobe_events

要使用寄存器名称，您需要知道处理器类型和使用的函数调用约定。 x86_64 uses the AMD64 ABI，所以前两个参数在寄存器 rdi 和 rsi 中可用。

4.3 Return Values

返回值的特殊别名 $retval 可用于 kretprobes。以下示例使用它来显示 do_nanosleep() 的返回值：

echo 'r:brendan do_nanosleep ret=$retval' >> kprobe_events
echo 1 > events/kprobes/brendan/enable
cat trace_pipe

在这里插入图片描述

echo 0 > events/kprobes/brendan/enable
echo '-:brendan' >> kprobe_events

此输出表明，在跟踪时，do_nanosleep() 的返回值始终为“0”（成功）。

4.4 Filters and Triggers

Filters and triggers可以在 events/kprobes/… 目录中使用，就像 tracepoints一样。
这是带有参数的 do_nanosleep() 上早期 kprobe 的格式文件（来自小节 4.2 Arguments）：
在这里插入图片描述
请注意，我的自定义 hrtimer_sleeper 和 hrtimer_mode 变量名称作为可与过滤器一起使用的字段可见。例如：

echo 'hrtimer\_mode != 1' > events/kprobes/brendan/filter

这只会跟踪 hrtimer_mode 不等于 1 的 do_nanosleep() 调用。

4.5 kprobe Profiling

启用 kprobe 时，Ftrace 会计算它们的事件。这些计数可以打印在 kprobe_profile 文件中。例如：

echo 'p:brendan do\_nanosleep' >> kprobe_events
echo 1 > events/kprobes/brendan/enable
![](https://img-blog.csdnimg.cn/img_convert/9a8cb5f8c0ec69e6499adead0da6e95b.png)



最全的Linux教程，Linux从入门到精通

======================

1.  **linux从入门到精通(第2版)**

2.  **Linux系统移植**

3.  **Linux驱动开发入门与实战**

4.  **LINUX 系统移植 第2版**

5.  **Linux开源网络全栈详解 从DPDK到OpenFlow**



![华为18级工程师呕心沥血撰写3000页Linux学习笔记教程](https://img-blog.csdnimg.cn/img_convert/59742364bb1338737fe2d315a9e2ec54.png)



第一份《Linux从入门到精通》466页

====================

内容简介

====

本书是获得了很多读者好评的Linux经典畅销书**《Linux从入门到精通》的第2版**。本书第1版出版后曾经多次印刷，并被51CTO读书频道评为“最受读者喜爱的原创IT技术图书奖”。本书第﹖版以最新的Ubuntu 12.04为版本，循序渐进地向读者介绍了Linux 的基础应用、系统管理、网络应用、娱乐和办公、程序开发、服务器配置、系统安全等。本书附带1张光盘，内容为本书配套多媒体教学视频。另外,本书还为读者提供了大量的Linux学习资料和Ubuntu安装镜像文件，供读者免费下载。



![华为18级工程师呕心沥血撰写3000页Linux学习笔记教程](https://img-blog.csdnimg.cn/img_convert/9d4aefb6a92edea27b825e59aa1f2c54.png)



**本书适合广大Linux初中级用户、开源软件爱好者和大专院校的学生阅读，同时也非常适合准备从事Linux平台开发的各类人员。**

> 需要《Linux入门到精通》、《linux系统移植》、《Linux驱动开发入门实战》、《Linux开源网络全栈》电子书籍及教程的工程师朋友们劳烦您转发+评论




**网上学习资料一大堆，但如果学到的知识不成体系，遇到问题时只是浅尝辄止，不再深入研究，那么很难做到真正的技术提升。**

**[需要这份系统化的资料的朋友，可以点击这里获取！](https://bbs.csdn.net/topics/618542503)**

**一个人可以走的很快，但一群人才能走的更远！不论你是正从事IT行业的老鸟或是对IT行业感兴趣的新人，都欢迎加入我们的的圈子（技术交流、学习资源、职场吐槽、大厂内推、面试辅导），让我们一起学习成长！**

m0_74918915

关注

10
点赞
踩
24

收藏

觉得还不错? 一键收藏
0
评论
Linux 追踪技术 ftrace的使用（二）_ftrace跟踪线程(1)

tracepoint是内核静态检测，跟踪点在技术上只是放置在内核源代码中的跟踪函数；它们从定义和格式化它们的参数的跟踪事件接口中使用。跟踪事件在 tracefs 中可见，并与 Ftrace 共享输出和控制文件无需创建自定义内核模块即可使用tracepoint来使用 event tracing infrastructure 注册探测功能。并非所有tracepoint都可以使用 event tracing system 进行跟踪；
复制链接

扫一扫