Skip to content

Latest commit

 

History

History
717 lines (527 loc) · 44.7 KB

File metadata and controls

717 lines (527 loc) · 44.7 KB

十四、Linux 内核调试提示和最佳实践

大多数情况下,作为开发的一部分,编写代码并不是最难的部分。 Linux 内核是位于操作系统最低层的独立软件,这一事实使事情变得更加困难。 这使得调试 Linux 内核变得具有挑战性。 但是,大多数情况下,我们不需要额外的工具来调试内核代码,因为大多数内核调试工具都是内核本身的一部分,这一事实弥补了这一点。 我们将从熟悉 Linux 内核发布模型开始,您将学习 Linux 内核发布过程和步骤。 然后,我们将研究与 Linux 内核调试相关的开发技巧(特别是通过打印进行调试),最后,我们将重点关注跟踪 Linux 内核,以非目标调试结束,并学习如何利用内核 OOP。

本章将介绍以下主题:

  • 了解 Linux 内核发布过程
  • Linux 内核开发技巧
  • Linux 内核跟踪与性能分析
  • Linux 内核调试技巧

技术要求

以下是本章的前提条件:

了解 Linux 内核发布过程

根据 Linux 内核发布模型,始终存在三种类型的活动内核版本:主线版本、稳定版本和长期支持(LTS)版本。 首先,错误修复和新特性由子系统维护人员收集和准备,然后提交给 Linus Torvalds,以便他可以将它们包括在自己的 Linux 树中,该树称为主线 Linux 树,也称为主 Git 存储库。 这就是每个稳定版本的发源地。

在每个新内核版本发布之前,都会通过Release Candidate标签提交给社区,以便开发人员可以测试和完善所有新功能,最重要的是,共享反馈。 在这个周期中,Linus 将依靠反馈来决定最终版本是否已经准备好发布。 当他确信新内核已经准备就绪时,他制作(实际上是标记它)最终版本,我们将这个版本称为稳定,以表明它不再是候选版本:这些版本是vX.Y版本。

发布版本没有严格的时间表。 然而,新的主线内核通常每 2-3 个月发布一次。 稳定的内核版本基于 Linus 的版本,即主线树版本。

一旦 LINUS 发布了主线内核,它也会出现在linux-Stability树中(可在https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux.git/获得),在那里它将成为一个分支,可以从这里接收稳定发布的错误修复。 Greg Kroah-Hartman负责维护此树,也称为稳定树,因为它用于跟踪以前发布的稳定内核。 也就是说,为了将修复程序应用于此树,必须首先将此修复程序合并到 Linus 树中。 因为修复必须在返回之前进行,所以据说此修复是向后移植的。 一旦修复了主线存储库中的错误,就可以将其应用于仍由内核开发社区维护的以前发布的内核。 所有移植到稳定版本的修复都必须满足一组强制性的验收标准--其中一个标准是它们必须已经存在于 Linus 的树中。

重要音符

修复内核版本被认为是稳定的。

例如,Linus 发布了4.9内核,然后基于该内核的稳定内核版本编号为4.9.14.9.24.9.3,依此类推。 这样的版本被称为错误修复内核版本,当提到它们在稳定内核版本树中的分支时,序列通常被缩写为数字4.9.y。 每个稳定的内核发布树由单个内核开发人员维护,该开发人员负责挑选发布所需的补丁,并执行审查/发布过程。 在下一个主线内核可用之前,通常只有几个修复内核版本,除非它被指定为长期维护内核

每个子系统和内核维护器库都驻留在这里:https://git.kernel.org/pub/scm/linux/kernel/git/。 在那里,我们还可以找到 Linus 树或马厩树。 在 Linus 树(https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/)中,Linus 树中只有一个分支,即主分支。 其中的标记要么是稳定版本,要么是候选版本。 在稳定树(https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux.git/)中,每个稳定内核版本都有一个分支(名为*<A.B>.y*,其中*<A.B>*是 Linus tree 中的发布版本),每个分支都包含其修复内核版本。

重要音符

为了跟踪 Linux 内核发行版,可以手头保留一些链接。 第一个是LTS,您可以从其中下载内核档案,然后是LTS,您可以从其中访问最新的 https://www.kernel.org/内核版本及其支持时间表。 您还可以参考此链接https://patchwork.kernel.org/,从这里您可以按子系统跟踪内核补丁提交。

既然我们已经熟悉了 Linux 内核发布模型,我们就可以深入研究一些开发技巧和最佳实践,它们有助于巩固和利用其他内核开发人员体验 NCES。

Linux 内核开发技巧

最佳的 Linux 内核开发实践受到现有内核代码的启发。 这样,你当然可以学到好的做法。 也就是说,我们不会重新发明轮子。 我们将重点介绍本章所需的内容,即调试。 最常用的调试方法涉及日志记录和打印。 为了利用这种经过时间测试的调试技术,Linux 内核提供了合适的日志记录 API,并公开了一个内核消息缓冲区来存储日志。 虽然这看起来似乎很明显,但我们将重点介绍内核日志 API,并学习如何从内核代码或用户空间管理消息缓冲区。

消息打印

消息打印和日志记录是开发固有的,无论我们是在内核空间还是在用户空间。 在内核中,printk()函数早已成为事实上的内核消息打印函数。 它类似于 C 库中的printf(),但具有日志级别的概念。

如果您查看实际驱动代码的示例,您会注意到它的用法如下:

printk(<LOG_LEVEL> "printf like formatted message\n");

这里,<LOG_LEVEL>include/linux/kern_levels.h中定义的八个不同日志级别之一,并指定错误消息的严重程度。 您还应该注意,日志级别和格式字符串之间没有逗号(因为预处理器会连接这两个字符串)。

内核日志级别

Linux 内核使用级别概念来确定消息的关键程度。 它们中有八个,每个都定义为一个字符串,它们的描述如下:

  • KERN_EMERG,定义为"0"。 它将用于紧急消息,这意味着系统即将崩溃或不稳定(不可用)。
  • KERN_ALERT,定义为"1",表示发生了不好的事情,必须立即采取行动。
  • KERN_CRIT,定义为"2",表示发生了严重情况,例如严重的硬件/软件故障。
  • KERN_ERR,定义为"3",在错误条件下使用,通常由驱动用来指示硬件故障或与子系统交互失败。
  • KERN_WARNING,定义为"4",用作警告,表示本身并不严重,但可能表示有问题。
  • KERN_NOTICE,定义为"5",意思是不严重,但仍然值得注意。 这通常用于报告安全事件。
  • KERN_INFO,定义为"6",用于信息性消息,例如驱动初始化时的启动信息。
  • KERN_DEBUG,定义为"7",用于调试,仅当DEBUG内核选项启用时才处于活动状态。 否则,其内容将被直接忽略。

如果您没有在消息中指定日志级别,它将默认为DEFAULT_MESSAGE_LOGLEVEL(通常为"4"=KERN_WARNING),这可以通过CONFIG_DEFAULT_MESSAGE_LOGLEVEL内核配置选项进行设置。

也就是说,对于新的驱动,我们鼓励您使用更方便的打印 API,这些 API 将日志级别嵌入到它们的名称中。 这些打印助手是pr_emergpr_alertpr_critpr_errpr_warningpr_warnpr_noticepr_infopr_debugpr_dbg。 除了比等效的printk()调用更简洁之外,它们还可以通过pr_fmt()宏对格式字符串使用通用定义;例如,在源文件的顶部(在任何#include指令之前)定义以下内容:

#define pr_fmt(fmt) "%s:%s: " fmt, KBUILD_MODNAME, __func__

这将为该文件中的每个pr_*()消息添加发起该消息的模块和函数名的前缀。 如果内核是用DEBUG编译的,则用printk(KERN_DEBUG …)替换pr_develpr_debug,否则用空语句替换它们。

pr_*()族宏将在核心代码中使用。 对于设备驱动,您应该使用与设备相关的帮助器,这些帮助器也接受相关的设备结构作为参数。 它们还以标准格式打印相关设备的名称,确保始终可以将消息与生成该消息的设备相关联:

dev_emerg(const struct device *dev, const char *fmt, ...);
dev_alert(const struct device *dev, const char *fmt, ...);
dev_crit(const struct device *dev, const char *fmt, ...);
dev_err(const struct device *dev, const char *fmt, ...);
dev_warn(const struct device *dev, const char *fmt, ...);
dev_notice(const struct device *dev, const char *fmt, ...);
dev_info(const struct device *dev, const char *fmt, ...);
dev_dbg(const struct device *dev, const char *fmt, ...);

虽然内核使用日志级别的概念来确定消息的重要性,但它也用于决定是否应该通过将消息打印到当前控制台(其中控制台也可以是串行线,甚至是打印机,而不是xterm)来立即向用户显示该消息。

为了做出决定,内核将消息的日志级别与console_loglevel内核变量进行比较,如果消息日志级别的重要性高于console_loglevel(即低于console_loglevel),则消息将打印到当前控制台。 由于默认内核日志级别通常为"4",这就是为什么您在控制台上看不到pr_info()pr_notice()甚至pr_warn()消息的原因,因为它们的值高于或等于默认值(这意味着优先级较低)。

要确定系统上的当前console_loglevel,只需键入以下命令:

$ cat /proc/sys/kernel/printk
4    4    1    7

第一个整数(4)是当前控制台日志级别,第二个数字(4)是默认的,第三个数字(1)是可以设置的最低控制台日志级别,第四个数字(7)是引导时的默认控制台日志级别。

要更改当前的console_loglevel,只需写入相同的文件,即/proc/sys/kernel/printk。 因此,要将所有消息打印到控制台,请执行以下简单命令:

# echo 8 > /proc/sys/kernel/printk

每条内核消息都会出现在您的控制台上。 然后,您将拥有以下内容:

# cat /proc/sys/kernel/printk
8    4    1    7

更改控制台日志级别的另一种方法是使用带有-n参数的dmesg

# dmesg -n 5

使用前面的命令,console_loglevel被设置为打印KERN_WARNING(4)或更严重的消息。 您还可以在引导时使用loglevel引导参数指定console_loglevel(有关详细信息,请参阅Documentation/kernel-parameters.txt)。

重要音符

还有KERN_CONTpr_cont,它们有些特殊,因为它们不指定紧急程度,而是指示继续的消息。 它们只能在早期启动期间由核心/ARCH 代码使用(否则,连续的行将不是 SMP 安全的)。 当要打印的消息行的一部分取决于计算结果时,这可能很有用,如下例所示:

[…]
pr_warn("your last operation was ");
if (success)
   pr_cont("successful\n");
else
   pr_cont("NOT successful\n");

您应该记住,只有最后的 print 语句才有尾随的\n字符。

内核日志缓冲区

无论它们是否立即在控制台上打印,每个内核消息都记录在一个缓冲区中。 这个内核消息缓冲区是一个固定大小的循环缓冲区,这意味着如果缓冲区填满,它会回绕,您可能会丢失一条消息。 因此,增加缓冲区大小可能会有所帮助。 要更改内核消息缓冲区大小,可以使用LOG_BUF_SHIFT选项,该选项的值用于左移 1,以获得最终大小,即内核日志缓冲区大小(例如,16=>1<<16=>64KB17=>1 << 17=>128KB)。 也就是说,它是在编译时定义的静态大小。 这个大小也可以通过内核引导参数来定义,方法是使用log_buf_len参数,换句话说就是log_buf_len=1M(只接受 2 的幂)。

添加定时信息

有时,将计时信息添加到打印的消息中很有用,这样您就可以看到特定事件发生的时间。 内核包含一个用于执行此操作的特性,称为printk times,可通过CONFIG_PRINTK_TIME选项启用。 在配置内核时,可以在内核破解菜单上找到此选项。 启用后,此计时信息会为每条日志消息添加如下前缀:

$ dmesg
[…]
[    1.260037] loop: module loaded
[    1.260194] libphy: Fixed MDIO Bus: probed
[    1.260195] tun: Universal TUN/TAP device driver, 1.6
[    1.260224] PPP generic driver version 2.4.2
[    1.260260] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    1.260262] ehci-pci: EHCI PCI platform driver
[    1.260775] ehci-pci 0000:00:1a.7: EHCI Host Controller
[    1.260780] ehci-pci 0000:00:1a.7: new USB bus registered, assigned bus number 1
[    1.260790] ehci-pci 0000:00:1a.7: debug port 1
[    1.264680] ehci-pci 0000:00:1a.7: cache line size of 64 is not supported
[    1.264695] ehci-pci 0000:00:1a.7: irq 22, io mem 0xf7ffa000
[    1.280103] ehci-pci 0000:00:1a.7: USB 2.0 started, EHCI 1.00
[    1.280146] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[    1.280147] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[…]

插入到内核消息输出中的时间戳由秒和微秒(实际上是seconds.microseconds)组成,它们是从机器操作开始(或从内核计时开始)的绝对值,它对应于引导加载程序将控制权移交给内核的时间(当您在控制台上看到类似[ 0.000000] Booting Linux on physical CPU 0x0的时候)。

通过写入/sys/module/printk/parameters/time以启用和禁用printk时间戳,可以在运行时控制打印时间。 以下是示例:

# echo 1 >/sys/module/printk/parameters/time
# cat /sys/module/printk/parameters/time
N
# echo 1 >/sys/module/printk/parameters/time
# cat /sys/module/printk/parameters/time
Y

它不控制是否记录时间戳。 它只控制是在转储内核消息缓冲区时、在引导时还是在使用dmesg时打印它。 这可能是引导时间优化的区域。 如果禁用,打印日志所需的时间会更短。

我们现在熟悉内核打印 API 及其日志缓冲区。 我们已经了解了如何调整消息缓冲区,并根据需要添加或删除信息。 这些技能可以用于打印调试。 但是,Linux 内核中附带了其他调试和跟踪工具,下一节将介绍其中的一些工具。

Linux 内核跟踪与性能分析

尽管通过打印进行的调试涵盖了大多数调试需求,但在某些情况下,我们需要在运行时监视 Linux 内核以跟踪奇怪的行为,包括延迟、CPU 占用、调度问题等等。 在 Linux 世界中,实现这一点最有用的工具是内核本身的一部分。 最重要的是ftrace,它是 Linux 内核内部跟踪工具,也是本节的主要主题。

使用 Ftrace 检测代码

函数跟踪,简写为ftrace,它做的比它的名字所说的要多得多。 例如,它可用于测量处理中断所需的时间、跟踪耗时的功能、计算激活高优先级任务的时间、跟踪上下文切换等。

Ftrace 由Steven Rostedt开发,从 2008 年的 2.6.27 版开始就包含在内核中。 这是为记录数据提供调试环形缓冲区的框架。 此数据由内核的集成跟踪程序收集。 Ftrace 在debugfs文件系统之上工作,并且在大多数情况下,当启用它时,它会挂载在名为tracing的自己的目录中。 在大多数现代 Linux 发行版中,它默认挂载在/sys/kernel/debug/目录中(这只对 root 用户可用),这意味着您可以从/sys/kernel/debug/tracing/中利用 ftrace。

以下是为在您的系统上支持 Ftrace 而要启用的内核选项:

CONFIG_FUNCTION_TRACER
CONFIG_FUNCTION_GRAPH_TRACER
CONFIG_STACK_TRACER
CONFIG_DYNAMIC_FTRACE

前面的选项取决于通过启用CONFIG_HAVE_FUNCTION_TRACERCONFIG_HAVE_DYNAMIC_FTRACECONFIG_HAVE_FUNCTION_GRAPH_TRACER选项来支持跟踪功能的体系结构。

要挂载tracefs目录,您可以将以下行添加到您的/etc/fstab文件:

tracefs   /sys/kernel/debug/tracing   tracefs defaults   0   0

或者,您可以在运行时借助以下命令挂载它:

mount -t tracefs nodev /sys/kernel/debug/tracing

目录的内容应如下所示:

# ls /sys/kernel/debug/tracing/
README                      set_event_pid
available_events            set_ftrace_filter
available_filter_functions  set_ftrace_notrace
available_tracers           set_ftrace_pid
buffer_size_kb              set_graph_function
buffer_total_size_kb        set_graph_notrace
current_tracer              snapshot
dyn_ftrace_total_info       stack_max_size
enabled_functions           stack_trace
events                      stack_trace_filter
free_buffer                 trace
function_profile_enabled    trace_clock
instances                   trace_marker
max_graph_depth             trace_options
options                     trace_pipe
per_cpu                     trace_stat
printk_formats              tracing_cpumask
saved_cmdlines              tracing_max_latency
saved_cmdlines_size         tracing_on
set_event                   tracing_thresh

我们不会描述所有这些文件和子目录,因为官方的文档中已经对此进行了介绍。 相反,我们只简要描述与我们的上下文相关的文件:

  • available_tracers:可用的跟踪程序。
  • tracing_cpumask:这允许跟踪选定的 CPU。 掩码应以十六进制字符串格式指定。 例如,要只跟踪核心0,您应该在此文件中包含一个1。 要跟踪核心1,应该在其中包括一个2。 对于核心3,应包括数字8
  • current_tracer:当前正在运行的跟踪程序。
  • tracing_on:负责启用或禁用向环形缓冲区写入数据的系统文件(要启用该文件,必须将编号1添加到该文件中;要禁用该文件,必须添加编号0)。
  • trace:以人类可读格式保存跟踪数据的文件。

现在我们已经介绍了 Ftrace 并描述了它的功能,我们可以深入研究它的用法,并了解它对于跟踪和调试有多有用。

可用的示踪剂

我们可以使用以下命令查看可用的跟踪器列表:

# cat /sys/kernel/debug/tracing/available_tracers 
blk function_graph wakeup_dl wakeup_rt wakeup irqsoff function nop

让我们快速了解一下每个跟踪器的功能:

  • function:不带参数的函数调用跟踪器。
  • function_graph:带子调用的函数调用跟踪器。
  • blk:与块设备 I/O 操作相关的调用和事件跟踪器(这是blktrace使用的)。
  • mmiotrace:内存映射 I/O 操作跟踪器。 它跟踪模块对硬件进行的所有调用。 它由CONFIG_ MMIOTRACE启用,这取决于CONFIG_HAVE_MMIOTRACE_SUPPORT
  • irqsoff:跟踪禁用中断的区域,并保存最长延迟的跟踪。 该示踪剂依赖于CONFIG_IRQSOFF_TRACER
  • preemptoff:取决于CONFIG_PREEMPT_TRACER。 它类似于irqsoff,但会跟踪和记录禁用抢占的时间量。
  • preemtirqsoff:类似于irqsoffpreemptoff,但它跟踪并记录 IRQS 和/或抢占被禁用的最长时间。
  • wakeupwakeup_rt,由CONFIG_SCHED_TRACER启用:前者跟踪并记录最高优先级任务在被唤醒后调度所需的最大延迟,而后者跟踪并记录仅实时(rt)任务所需的最大延迟(与当前的wakeup跟踪器相同)。
  • nop:最简单的跟踪器,顾名思义,它什么都不做。 nop跟踪器只显示trace_printk()调用的输出。

irqsoffpreemptoffpreemtirqsoff是所谓的延迟跟踪器。 它们测量中断被禁用多长时间、抢占被禁用多长时间以及中断和/或抢占被禁用多长时间。 唤醒延迟跟踪器测量进程在所有任务或仅针对 RT 任务被唤醒后运行所需的时间。

函数跟踪器

我们将从函数跟踪器开始介绍 Ftrace。 让我们看一个测试脚本:

# cd /sys/kernel/debug/tracing
# echo function > current_tracer
# echo 1 > tracing_on
# sleep 1
# echo 0 > tracing_on
# less trace

这个脚本相当简单,但有几点值得注意。 我们通过将当前跟踪程序的名称写入current_tracer文件来启用该跟踪程序。 接下来,我们将1写入tracing_on,这将启用环形缓冲区。 语法要求在1>符号之间留一个空格;echo1> tracing_on将不起作用。 一行之后,我们禁用它(如果将0写入tracing_on,缓冲区将不会清除,Ftrace 也不会被禁用)。

我们为什么要这么做? 在两个echo命令之间,我们可以看到sleep 1命令。 我们启用缓冲区,运行此命令,然后禁用它。 这使跟踪程序可以包括与命令运行时发生的所有系统调用相关的信息。 在脚本的最后一行,我们给出了在控制台中显示跟踪数据的命令。 运行脚本后,我们将看到以下打印输出(这只是一小段):

Figure 14.1 – Ftrace function tracer snapshot

图 14.1-Ftrace 函数跟踪器快照

打印输出以与缓冲区中的条目数和写入的条目总数有关的信息开始。 这两个数字之间的差异在于填充缓冲区时丢失的事件数。 然后,有一个函数列表,其中包括以下信息:

  • 进程名称(TASK)。
  • 进程标识符(PID)。
  • 进程在其上运行的 CPU(CPU#)。
  • 功能开始时间(TIMESTAMP)。 此时间戳是自启动以来的时间。
  • 被跟踪的函数的名称(FUNCTION)以及在<-符号之后调用的父函数。 例如,在输出的第一行中,handle_fasteoi_irq调用了irq_may_run函数。

现在我们已经熟悉了函数跟踪器及其特性,我们可以了解下一个跟踪器,它功能更丰富,提供了更多的跟踪信息,比如调用图。

函数图形跟踪器

function_graph跟踪器的工作方式与函数类似,但方式更详细:显示每个函数的入口点和出口点。 使用这个跟踪器,我们可以跟踪带子调用的函数,并测量每个函数的执行时间。

让我们编辑上一个示例中的脚本:

# cd /sys/kernel/debug/tracing
# echo function_graph > current_tracer
# echo 1 > tracing_on
# sleep 1
# echo 0 > tracing_on
# less trace

运行此脚本后,我们将获得以下打印输出:

# tracer: function_graph
#
# CPU  DURATION                  FUNCTION CALLS
# |     |   |                     |   |   |   |
 5)   0.400 us    |                } /* set_next_buddy */
 5)   0.305 us    |                __update_load_avg_se();
 5)   0.340 us    |                __update_load_avg_cfs_rq();
 5)               |                update_cfs_group() {
 5)               |                  reweight_entity() {
 5)               |                    update_curr() {
 5)   0.376 us    |                      __calc_delta();
 5)   0.308 us    |                      update_min_vruntime();
 5)   1.754 us    |                    }
 5)   0.317 us    |                   account_entity_dequeue();
 5)   0.260 us    |                   account_entity_enqueue();
 5)   3.537 us    |                  }
 5)   4.221 us    |                }
 5)   0.261 us    |                hrtick_update();
 5) + 16.852 us   |              } /* dequeue_task_fair */
 5) + 23.353 us   |            } /* deactivate_task */
 5)               |            pick_next_task_fair() {
 5)   0.286 us    |              update_curr();
 5)   0.271 us    |              check_cfs_rq_runtime();
 5)               |              pick_next_entity() {
 5)   0.441 us    |            wakeup_preempt_entity.isra.77();
 5)   0.306 us    |                clear_buddies();
 5)   1.645 us    |              }
 ------------------------------------------
 5) SCTP ti-27174  =>  Composi-2089 
 ------------------------------------------
 5)   0.632 us    |              __switch_to_xtra();
 5)   0.350 us    |              finish_task_switch();
 5) ! 271.440 us  |            } /* schedule */
 5)               |            _cond_resched() {
 5)   0.267 us    |              rcu_all_qs();
 5)   0.834 us    |            }
 5) ! 273.311 us  |          } /* futex_wait_queue_me */

在此图中,DURATION显示运行函数所花费的时间。 注意用+!符号标记的点。 加号(+)表示运行时间超过 10 微秒,而感叹号(!)表示运行时间超过 100 微秒。 在FUNCTION_CALLS下,我们找到与每个函数调用有关的信息。 用于表示每个函数的开始和结束的符号与 C 编程语言中的相同:大括号({})分隔函数,一个在开始,一个在结束;不调用任何其他函数的叶函数用分号(;)标记。

Ftrace 还允许使用tracing_thresh选项将跟踪限制在超过一定时间的函数上。 应该记录功能的时间阈值必须以微秒为单位写入该文件。 这可以用来查找在内核中花费很长时间的例程。 在内核启动时使用它来帮助优化启动时间可能很有趣。 要在启动时设置阈值,可以在内核命令行中设置,如下所示:

tracing_thresh=200 ftrace=function_graph

这将跟踪所有耗时超过 200 微秒(0.2 毫秒)的功能。 您可以使用任何您想要的持续时间阈值。

在运行时,您可以简单地执行echo 200 > tracing_thresh

函数过滤器

挑选并选择要跟踪的函数。 不用说,要跟踪的函数越少,开销就越小。 Ftrace 打印输出可能会很大,而且要准确找到您要找的内容可能非常困难。 但是,我们可以使用过滤器来简化搜索:打印输出将只显示有关我们感兴趣的函数的信息。 为此,我们只需在set_ftrace_filter文件中写入函数名称,如下所示:

# echo kfree > set_ftrace_filter

要禁用过滤器,我们在此文件中添加一个空行:

# echo  > set_ftrace_filter

我们运行以下命令:

# echo kfree > set_ftrace_notrace

结果正好相反:打印输出将给出除kfree()之外的每个函数的信息。 另一个有用的选项是set_ftrace_pid。 此工具用于跟踪可以代表特定进程调用的函数。

Ftrace 有更多的过滤选项。 要更详细地了解这些内容,您可以阅读https://www.kernel.org/doc/Documentation/trace/ftrace.txt上提供的官方文档。

跟踪事件

在介绍跟踪事件之前,让我们先来讨论一下个跟踪点。 跟踪点是触发系统事件的特殊代码插入。 跟踪点可以是动态的(意味着它们有几个附加的检查),也可以是静态的(没有附加检查)。

静态跟踪点不会以任何方式影响系统;它们只是在插入指令的函数的末尾为函数调用添加几个字节,并在单独的部分中添加数据结构。 动态跟踪点在执行相关代码段时调用跟踪函数。 跟踪数据被写入环形缓冲区。 跟踪点可以包含在代码中的任何位置。 事实上,它们已经可以在很多内核函数中找到。 让我们看一下摘自mm/slab.ckmem_cache_free函数:

void kmem_cache_free(struct kmem_cache *cachep, void *objp)
{
	[...]
	trace_kmem_cache_free(_RET_IP_, objp);
}

kmem_cache_free那么它本身就是一个跟踪点。 只需查看其他内核函数的源代码,我们就可以找到更多的例子。

Linux 内核有一个特殊的 API,用于从用户空间使用跟踪点。 在/sys/kernel/debug/tracing目录中,有一个保存系统事件的events目录。 这些可用于跟踪。 此上下文中的系统事件可以理解为内核中包含的跟踪点。

可以通过运行以下命令查看这些列表:

# cat /sys/kernel/debug/tracing/available_events
mac80211:drv_return_void
mac80211:drv_return_int
mac80211:drv_return_bool
mac80211:drv_return_u32
mac80211:drv_return_u64
mac80211:drv_start
mac80211:drv_get_et_strings
mac80211:drv_get_et_sset_count
mac80211:drv_get_et_stats
mac80211:drv_suspend
[...]

控制台中将打印出带有<subsystem>:<tracepoint>图案的长列表。 这有点不方便。 我们可以使用以下命令打印出更结构化的列表:

# ls /sys/kernel/debug/tracing/events
block         gpio          napi          regmap      syscalls
cfg80211      header_event  net           regulator   task
clk           header_page   oom           rpm         timer
compaction    i2c           pagemap       sched       udp
enable        irq           power         signal      vmscan
fib           kmem          printk        skb         workqueue
filelock      mac80211      random        sock        writeback
filemap       migrate       raw_syscalls  spi
ftrace        module        rcu           swiotlb

所有可能的事件按子系统组合在子目录中。 在开始跟踪事件之前,我们将确保已经启用了对环形缓冲区的写入。

第 1 章面向嵌入式开发人员的 Linux 内核概念中,我们介绍了hrtimers。 通过列出/sys/kernel/debug/tracing/events/timer的内容,我们将拥有与定时器相关的跟踪点,包括与hrtimer相关的跟踪点,如下所示:

# ls /sys/kernel/debug/tracing/events/timer
enable                hrtimer_init          timer_cancel
filter                hrtimer_start         timer_expire_entry
hrtimer_cancel        itimer_expire         timer_expire_exit
hrtimer_expire_entry  itimer_state          timer_init
hrtimer_expire_exit   tick_stop             timer_start
#

现在让我们跟踪对与hrtimer相关的内核函数的访问。 对于我们的跟踪器,我们将使用nop,因为functionfunction_graph记录了太多的信息,包括我们不感兴趣的事件信息。 以下是我们将使用的脚本:

# cd /sys/kernel/debug/tracing/
# echo 0 > tracing_on
# echo > trace
# echo nop > current_tracer 
# echo 1 > events/timer/enable 
# echo 1 > tracing_on;
# sleep 1;
# echo 0 > tracing_on; 
# echo 0 > events/timer/enable 
# less trace

我们首先禁用跟踪,以防它已经在运行。 然后,我们在将电流跟踪器设置为nop之前清除环形缓冲区数据。 接下来,我们启用与计时器相关的跟踪点,或者应该说,我们启用了计时器事件跟踪。 最后,我们启用跟踪并转储环形缓冲区内容,如下所示:

Figure 14.2 – Ftrace event tracing with the nop tracer snapshot

图 14.2-使用 NOP 跟踪程序快照进行 Ftrace 事件跟踪

在打印输出的末尾,我们将找到有关hrtimer函数调用的信息(这里是一小部分)。 有关配置事件跟踪的更多详细信息可以在此处找到:https://www.kernel.org/doc/Documentation/trace/events.txt

使用 Ftrace 接口跟踪特定进程

使用 Ftrace 作为可以让您拥有支持跟踪的内核跟踪点/函数,而不管这些函数代表哪个进程运行。 要只跟踪代表特定函数执行的内核函数,您应该将伪set_ftrace_pid变量设置为进程的进程 ID(PID),例如,可以使用pgrep获得。 如果进程尚未运行,则可以使用包装器外壳脚本和exec命令以已知 PID 执行命令,如下所示:

#!/bin/sh
echo $$ > /debug/tracing/set_ftrace_pid
# [can set other filtering here]
echo function_graph > /debug/tracing/current_tracer
exec $*

在前面的示例中,$$是当前执行的进程(shell 脚本本身)的 PID。 这是在set_ftrace_pid变量中设置的,然后启用function_graph跟踪器,之后该脚本执行命令(由脚本的第一个参数指定)。

假设脚本名称为trace_process.sh,用法示例如下:

sudo ./trace_command ls

现在我们熟悉跟踪事件和跟踪点。 我们能够跟踪和跟踪特定的内核事件或子系统。 虽然跟踪在内核开发方面是必须的,但不幸的是,有些情况会影响内核的稳定性。 这类情况可能需要脱离目标的分析,这将在调试中讨论,并将在下一节中讨论。

Linux 内核调试技巧

编写代码并不总是内核开发中最难的方面。 调试是真正的瓶颈,即使对于经验丰富的内核开发人员也是如此。 也就是说,大多数内核调试工具都是内核本身的一部分。 有时,内核通过称为Oops的消息帮助查找故障的起因。 然后,调试归结为分析消息。

糟糕和恐慌分析

OOPS 是 Linux 内核在发生错误或未处理的异常时打印的消息。 它尽最大努力描述异常,并在错误或异常发生之前转储调用堆栈。

以以下内核模块为例:

#include <linux/kernel.h>
#include <linux/module.h>
#include <linux/init.h>

static void __attribute__ ((__noinline__)) create_oops(void) {
        *(int *)0 = 0;
}

static int __init my_oops_init(void) {
       printk("oops from the module\n");
       create_oops();
       return 0;
}
static void __exit my_oops_exit(void) {
       printk("Goodbye world\n");
}
module_init(my_oops_init);
module_exit(my_oops_exit);
MODULE_LICENSE("GPL");

在前面的模块代码中,我们试图取消引用空指针,以使内核恐慌。 此外,我们使用__noinline__属性以使create_oops()不是内联的,从而允许它在反汇编期间和调用堆栈中显示为一个单独的函数。 此模块已在 ARM 和 x86 平台上构建和测试。 OOPS 消息和内容因机器而异:

# insmod /oops.ko 
[29934.977983] Unable to handle kernel NULL pointer dereference at virtual address 00000000
[29935.010853] pgd = cc59c000
[29935.013809] [00000000] *pgd=00000000
[29935.017425] Internal error: Oops - BUG: 805 [#1] PREEMPT ARM
[...]
[29935.193185] systime: 1602070584s
[29935.196435] CPU: 0 PID: 20021 Comm: insmod Tainted: P           O    4.4.106-ts-armv7l #1
[29935.204629] Hardware name: Columbus Platform
[29935.208916] task: cc731a40 ti: cc66c000 task.ti: cc66c000
[29935.214354] PC is at create_oops+0x18/0x20 [oops]
[29935.219082] LR is at my_oops_init+0x18/0x1000 [oops]
[29935.224068] pc : [<bf2a8018>]    lr : [<bf045018>]    psr: 60000013
[29935.224068] sp : cc66dda8  ip : cc66ddb8  fp : cc66ddb4
[29935.235572] r10: cc68c9a4  r9 : c08058d0  r8 : c08058d0
[29935.240813] r7 : 00000000  r6 : c0802048  r5 : bf045000  r4 : cd4eca40
[29935.247359] r3 : 00000000  r2 : a6af642b  r1 : c05f3a6a  r0 : 00000014
[29935.253906] Flags: nZCv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment none
[29935.261059] Control: 10c5387d  Table: 4c59c059  DAC: 00000051
[29935.266822] Process insmod (pid: 20021, stack limit = 0xcc66c208)
[29935.272932] Stack: (0xcc66dda8 to 0xcc66e000)
[29935.277311] dda0:                   cc66ddc4 cc66ddb8 bf045018 bf2a800c cc66de44 cc66ddc8
[29935.285518] ddc0: c01018b4 bf04500c cc66de0c cc66ddd8 c01efdbc a6af642b cff76eec cff6d28c
[29935.293725] dde0: cf001e40 cc24b600 c01e80b8 c01ee628 cf001e40 c01ee638 cc66de44 cc66de08
[...]
[29935.425018] dfe0: befdcc10 befdcc00 004fda50 b6eda3e0 a0000010 00000003 00000000 00000000
[29935.433257] Code: e24cb004 e52de004 e8bd4000 e3a03000 (e5833000) 
[29935.462814] ---[ end trace ebc2c98aeef9342e ]---
[29935.552962] Kernel panic - not syncing: Fatal exception

让我们仔细看看前面的转储,以了解一些重要的信息:

[29934.977983] Unable to handle kernel NULL pointer dereference at virtual address 00000000

第一行描述了 bug 及其性质,在本例中为,说明代码试图取消引用NULL指针:

[29935.214354] PC is at create_oops+0x18/0x20 [oops]

PC代表程序计数器,表示存储器中当前执行的指令地址。 在这里,我们看到我们在create_oops函数中,该函数位于oops模块中(在方括号中列出)。 十六进制数字表示函数中的指令指针是24(十六进制的0x18)字节,看起来是32(十六进制的0x20)字节长:

[29935.219082] LR is at my_oops_init+0x18/0x1000 [oops]

LR是链接寄存器,它包含程序计数器到达“返回子例程”指令时应设置到的地址。 换句话说,LR保存调用当前正在执行的函数(PC所在的函数)的函数的地址。 首先,这意味着my_oops_init是调用执行代码的函数。 它还意味着,如果PC中的函数已返回,则要执行的下一行将是my_oops_init+0x18,这意味着 CPU 将在从my_oops_init的起始地址开始的0x18偏移处分支:

[29935.224068] pc : [<bf2a8018>]    lr : [<bf045018>]    psr: 60000013

在前面的代码行中,pclrPCLR的实际十六进制内容,没有显示符号名称。 这些地址可以与addr2line程序一起使用,addr2line程序是另一个我们可以用来查找故障线路的工具。 这就是如果内核是在禁用CONFIG_KALLSYMS选项的情况下构建的,我们将在打印输出中看到这一点。 然后我们可以推断出create_oopsmy_oops_init的地址分别是0xbf2a80000xbf045000

[29935.224068] sp : cc66dda8  ip : cc66ddb8  fp : cc66ddb4 

sp代表堆栈指针并保存堆栈中的当前位置,而fp代表帧指针并指向堆栈中当前活动的帧。 当函数返回时,堆栈指针恢复为帧指针,帧指针是恰好在函数被调用之前的堆栈指针的值。 以下来自维基百科的例子很好地解释了这一点:

例如,DrawLine的堆栈帧将具有保存DrawSquare使用的帧指针值的内存位置。 该值在进入子例程时保存,并在返回时恢复:

[29935.235572] r10: cc68c9a4  r9 : c08058d0  r8 : c08058d0
[29935.240813] r7 : 00000000  r6 : c0802048  r5 : bf045000  r4 : cd4eca40
[29935.247359] r3 : 00000000  r2 : a6af642b  r1 : c05f3a6a  r0 : 00000014

上面是多个 CPU 寄存器的转储:

[29935.266822] Process insmod (pid: 20021, stack limit = 0xcc66c208)

前面的一行显示了发生死机的进程,在本例中为insmod,其 PID 为20021

还有 oops,其中存在回溯,有点类似于以下内容,它是通过键入echo c > /proc/sysrq-trigger生成的 oops 的摘录:

Figure 14.3 – Backtrace excerpt in a kernel oops

图 14.3-内核 OOPS 中的回溯摘录

回溯跟踪在生成 OOP 之前跟踪函数调用历史:

[29935.433257] Code: e24cb004 e52de004 e8bd4000 e3a03000 (e5833000) 

Code是发生 OOPS 时正在运行的机器代码段的十六进制转储。

OOPS 上的跟踪转储

当内核崩溃时,可以将kdump/kexeccrash实用程序一起使用,以检查系统在崩溃时的状态。 但是,这种技术不能让您看到在导致崩溃的事件之前发生了什么,这可能是理解或修复错误的一个很好的输入。

Ftrace 附带了一个试图解决此问题的功能。 为了启用它,您可以将1回显到/proc/sys/kernel/ftrace_dump_on_oops,或者在内核引导参数中启用ftrace_dump_on_oops。 在启用此功能的情况下配置 Ftrace 将指示 Ftrace 在 Oop 或死机时以 ASCII 格式将整个跟踪缓冲区转储到控制台。 让控制台输出到串行线使调试崩溃变得容易得多。 这样,您就可以设置好一切,只需等待崩溃。 一旦发生,您将在控制台上看到跟踪缓冲区。 然后,您将能够追溯导致坠机的事件。 跟踪事件可以追溯到多远取决于跟踪缓冲区的大小,因为这是存储事件历史数据的地方。

也就是说,转储到控制台可能需要很长时间,而且通常会在将所有内容放到适当位置之前缩小跟踪缓冲区,因为默认的 Ftrace 环形缓冲区超过每个 CPU 1 兆字节。 您可以使用/sys/kernel/debug/tracing/buffer_size_kb来减少跟踪缓冲区的大小,方法是在该文件中写入您想要的环形缓冲区的千字节数。 请注意,该值是按 CPU 计算的,而不是环形缓冲区的总大小。

以下是修改跟踪缓冲区大小的示例:

# echo 3 > /sys/kernel/debug/tracing/buffer_size_kb

前面的命令将把 Ftrace 环形缓冲区缩小到每个 CPU 3KB(1KB 可能就足够了;这取决于在崩溃之前需要返回多远)。

使用 objdump 识别内核模块中的错误代码行

我们可以使用objdump来反汇编目标文件,并识别生成 OOP 的行。 我们使用反汇编的代码来处理符号名称和偏移量,以便指向准确的故障线。

以下行将反汇编oops.as文件中的内核模块:

arm-XXXX-objdump -fS  oops.ko > oops.as

生成的输出文件将包含类似以下内容的内容:

[...]
architecture: arm, flags 0x00000011:
HAS_RELOC, HAS_SYMS
start address 0x00000000
Disassembly of section .text.unlikely:
00000000 <create_oops>:
   0:	e1a0c00d 	mov	ip, sp
   4:	e92dd800 	push	{fp, ip, lr, pc}
   8:	e24cb004 	sub	fp, ip, #4
   c:	e52de004 	push	{lr}		; (str lr, [sp, #-4]!)
  10:	ebfffffe 	bl	0 <__gnu_mcount_nc>
  14:	e3a03000 	mov	r3, #0
  18:	e5833000 	str	r3, [r3]
  1c:	e89da800 	ldm	sp, {fp, sp, pc}
Disassembly of section .init.text:
00000000 <init_module>:
   0:	e1a0c00d 	mov	ip, sp
   4:	e92dd800 	push	{fp, ip, lr, pc}
   8:	e24cb004 	sub	fp, ip, #4
   c:	e59f000c    ldr   r0, [pc, #12]    ; 20    <init_module+0x20>
  10:	ebfffffe 	bl	0 <printk>
  14:	ebfffffe 	bl	0 <init_module>
  18:	e3a00000 	mov	r0, #0
  1c:	e89da800 	ldm	sp, {fp, sp, pc}
  20:	00000000 	.word	0x00000000
Disassembly of section .exit.text:
00000000 <cleanup_module>:
   0:	e1a0c00d 	mov	ip, sp
   4:	e92dd800 	push	{fp, ip, lr, pc}
   8:	e24cb004 	sub	fp, ip, #4
   c:	e59f0004 	ldr	r0, [pc, #4]	; 18    <cleanup_module+0x18>
  10:	ebfffffe 	bl	0 <printk>
  14:	e89da800 	ldm	sp, {fp, sp, pc}
  18:	00000016 	.word	0x00000016

重要音符

编译模块时启用调试选项将使调试信息在.ko对象中可用。 在这种情况下,objdump -S将插入源代码和程序集以获得更好的视图。

从 OOPS 中,我们已经看到 PC 位于create_oops+0x18,它位于create_oops地址的0x18偏移量。 这就把我们带到了18: e5833000 str r3, [r3]线。 为了理解我们感兴趣的行,让我们描述一下它之前的行mov r3, #0。 在这行之后,我们有r3 = 0。 回到我们感兴趣的领域,对于熟悉 ARM 汇编语言的人来说,这意味着将r3写到r3所指向的原始地址([r3]的 C 等价物是*r3)。 请记住,这对应于我们代码中的*(int *)0 = 0

摘要

本章介绍了一些内核调试技巧,并解释了如何使用 Ftrace 跟踪代码以识别奇怪的行为,如耗时的函数和 IRQ 延迟。 我们讨论了核心驱动或设备驱动相关代码的 API 打印。 最后,我们学习了如何分析和调试内核 OOP。

这一章标志着这本书的结束,我希望你在阅读这本书的过程中和我在写这本书的时候一样享受这段旅程。 我也希望我在这本书中传授知识的最大努力能对你有所帮助。