内核调试利器-ftrace使用教程(上文~)

1. 位置无关码

  • 加载地址:存储代码的物理地址。如ARM64处理器上电复位后是从0x0地址开始第一条指令的,所以通常这个地方存放代码最开始的部分,如异常向量表的处理地址
  • 运行地址:指程序运行时的地址
  • 链接地址:在编译链接时指定的地址,编程人员设想将来程序要运行的地址。程序所有标号的地址在链接后便确定了,不管程序在哪里运行都不会改变。aarch64-linux-gnu-obidump (objdump)工具进行反汇编查看的就接地链接地址

链接地址和运行地址可以相同,也可以不同。那什么时候运行地址和链接地址不相同,什么时候相同呢?我们以一块ARM64开发板为例,芯片内部有SRAM,起始地址为0x0,DDR内存的起始地址为0x4000 0000。

通常代码存储在 Nor Flash存储器或者 Nand Flash存储器中,芯片内部的 BOOT ROM会把开始的小部分代码装载到SRAM中运行。芯片上电复位之后,从SRAM中取指令。由于 Uboot的镜像太大了,SRAM放不下,因此必须要放在DDR内存中。通常Uboot编译时链接地址都没置到DDR内存中,也就是0x4000 0000地址处。那这时运行地址和链接地址就不一样了。运行地址为0x0,链接地址变成了0x4000 0000那么程序为什么还能运行呢个重要问题,就是位置无关代码和位置有关代码。

  • 位置无关代码:从字面意思看,该指令的执行是与内存地址无关的;无论运行地址和链接地址相等或者不相等,该指令都能正常运行。在汇编语言中,像BL、B、MOV指令属于位置无关指令,不管程序装载在哪个位置,它们都能正确地运行,它们的地址域是基于PC值的相对偏移寻址,相当于[pc+offset]
  • 位置有关代码:从字面意思看,该指令的执行是与内存地址有关的,和当前PC值无关。ARM汇编里面通过绝对跳转修改PC值为当前链接地址的值
ldr pc, = on_sdram ;跳到 SDRAM中继续执行

因此,当通过LDR指令跳转到链接地址处执行时,运行地址就等于链接地址了。这个过程叫作“重定位”。在重定位之前,程序只能执行和位置无关的一些汇编代码。为什么要刻意设置加载地址、运行地址以及链接地址不一样呢?如果所有代码都在ROM(或 Nor Flash存储器)中执行,那么链接地址可以与加载地址相同;而在实际项目应用中,往往想要把程序加载到DDR内存中,DDR内存的访问速度比ROM要快很多,而且容量也大。但是碍于加载地址的影响,不可能直接达到这一步,所以思路就是让程序的加载地址等于ROM起始地址,而链接地址等于DDR内存中某一处的起始地址(暂且称为 ram start)。程序先从ROM中启动,最先启动的部分要实现代码复制功能(把整个ROM代码复制到DDR内存中),并通过LDR指令来跳转到DDR内存中,也就是在链接地址里运行B指令没法实现这个跳转)。上述重定位过程在U-Boot中实现,如图所示。


当跳转到 Linux内核中时,U-Boot需要把 Linux内核映像内容复制到DDR内存中,然后跳转到内核入口地址处( stext函数)。当跳转到内核入口地址( stext函数)时,程序运行在运行地址,即DDR内存的地址。但是我们从 vmlinux看到的 stext 函数的链接地址是虚拟地址(内核启动汇编代码也需要一个重定位过程。这个重定位过程在__primary_switch()汇编函数中完成。启动MMU之后,通过ldr指令把 __primary_switched()函数的链接地址加载到x8寄存器,然后通过br指令跳转到 __primary_switched()函数的链接地址处,从而实现了重定位,如图所示

/* * The following fragment of code is executed with the MMU enabled. * *   x0 = __PHYS_OFFSET */SYM_FUNC_START_LOCAL(__primary_switched)  adr_lx4, init_task  init_cpu_task x4, x5, x6  adr_lx8, vectors// load VBAR_EL1 with virtual  msrvbar_el1, x8// vector table address  isb  stpx29, x30, [sp, #-16]!  movx29, sp  str_lx21, __fdt_pointer, x5// Save FDT pointer  ldr_lx4, kimage_vaddr// Save the offset between  subx4, x4, x0// the kernel virtual and  str_lx4, kimage_voffset, x5// physical mappings  // Clear BSS  adr_lx0, __bss_start  movx1, xzr  adr_lx2, __bss_stop  subx2, x2, x0  bl__pi_memset  dsbishst// Make zero page visible to PTW#if defined(CONFIG_KASAN_GENERIC) || defined(CONFIG_KASAN_SW_TAGS)  blkasan_early_init#endif  movx0, x21// pass FDT address in x0  blearly_fdt_map// Try mapping the FDT early  blinit_feature_override// Parse cpu feature overrides#ifdef CONFIG_RANDOMIZE_BASE  tstx23, ~(MIN_KIMG_ALIGN - 1)// already running randomized?  b.ne0f  blkaslr_early_init// parse FDT for KASLR options  cbzx0, 0f// KASLR disabled? just proceed  orrx23, x23, x0// record KASLR offset  ldpx29, x30, [sp], #16// we must enable KASLR, return  ret// to __primary_switch()0:#endif  blswitch_to_vhe// Prefer VHE if possible  ldpx29, x30, [sp], #16  blstart_kernel  ASM_BUG()SYM_FUNC_END(__primary_switched)

更多linux内核视频教程文档资料免费领取后台私信【内核】自行获取.

Linux内核源码/内存调优/文件系统/进程管理/设备驱动/网络协议栈-学习视频教程-腾讯课堂

2. ftrace

frace最早出现在 Linux2.6.27内核中,其设计目标简单,基于静态代码插桩(stub)技术,不需要用户通过额外的编程来定义 trace行为。静态代码插桩技术比较可靠,不会因为用户使用不当而导致内核崩溃。ftrace 的名字源于 function trace利用GCC的 profile特性在所有函数入口处添加一段插桩代码, ftrace重载这段代码来实现 trace 功能。GCC的-pg选项会在每个函数入口处加入 mcount的调用代码,原本 mcount有libc实现,而内核不会链接libc库,因此frace编写了自己的mcount stub函数。在使用ftrace之前,需要确保内核编译配置选项。

CONFIG_FTRACE=yONIFIG_HAVE_FUNCTION_TRACE=yCONFIG_HAVE_FUNCTION_GRAPH_TRACER=yCONFIG_HAVE_DYNAMIC_FTRACE=yCONFIG_FUNCTIONL_TRACER=yCONFIG_IRQSOFE_TRACER=YCONEIG_SCHED_TRACER=yCONFIG_ENABLE_DEFAULT_TRACERS=yCONFIG_FTRACE_SYSCALLS=yCONFIG_PREEMPT_TRACER=y

ftrace的相关配置选项比较多,针对不同的跟踪器有各自对应的配置选项。ftrace通过debugfs文件系统向用户空间提供访间接口,因此需要在系统启动时挂载 debugfs,可以修改系统的 /etc/fstab文件或手动挂载。

mount -t debugfs debugfs/sys/kernel/debug

在 sys/kernel/debug/trace目录下提供了各种跟踪器( tracer)和事件( event),一些常用的选项如下。

  • available_tracers:列出当前系统支持的跟踪器
  • available_events:列出当前系统支持的事件
  • current_tracer:设置和显示当前正在使用的跟踪器。使用echo命令把跟踪器的名字写入该文件,即可切换不同的跟踪器。默认为nop,即不做任何跟踪操作
  • trace: 读取跟踪信息。通过cat命令查看 ftrace记录下来的眼踪信息
  • tracing_on:用于开始或暂停跟踪
  • trace_options:设置 ftrace的一些相关选项

ftrace当前包含多个跟踪器,方便用户跟踪不同类型的信息,如进程睡眠、唤醒、抢占、延迟的信息。查看 available_tracers可以知道当前系统支持哪些跟踪器,如果系统支持的跟踪器上没有用户想要的。那就必须在配置内核时打开,然后重新编译内核。常用的ftrace跟踪器如下所示:

  • nop:不跟踪任何信息。将nop写入current_tracer文件可以清空之前收集到的跟踪信息
  • function:跟踪内核函数执行情况
  • function_graph:可以显示类似于C语言的函数调用关系图,比较直观
  • hwlat:用来跟踪与硬件相关的延时
  • blk:跟踪块设备的函数
  • mmiotrace:用于跟踪内存映射I/O操作
  • wakeup:跟踪普通优先级的进程从获得调度到被唤醒的最长延迟时间
  • weakup_rt:跟踪RT类型的任务从获得调度到被唤醒的最长延迟时间
  • irqoff:跟踪关闭中断的信息,并记录关闭的最大时长
  • preemptoff:跟踪关闭禁止抢占的信息,并记录关闭的最大时长

3. irqs跟踪器

当中断关闭(俗称关中断)后,CPU就不能响应其他的事件。如果这时有一个鼠标中断,要在下一次开中断时才能响应这个中断,这段延时称为中断延迟。向current_tracer文件写入 irqsoff字符串即可打开 irqsoff来跟踪中断延迟。

cd /sys/kernel/debug/tracing/echo 0 > options/function-trace //关闭 funct-trace可以减少一些延退echo irqsoff > current_traceecho 1 > tracing_on [...] //停顿一会儿echo 0 > tracing_oncat trace

4. Function tracing - no modification necessary

Ftrace 最强大的追踪器之一是函数追踪器。它使用gcc的-pg选项让内核中的每个函数调用一个特殊的函数“ mcount() ”。该函数必须在汇编中实现,因为调用不遵循正常的 C ABI。

当配置 CONFIG_DYNAMIC_FTRACE 时,调用会在启动时转换为 NOP,以保持系统以 100% 的性能运行。在编译过程中,记录了 mcount() 调用站点。该列表在启动时用于将这些站点转换为 NOP。由于 NOP 对跟踪毫无用处,因此当启用函数(或函数图)跟踪器时,保存该列表以将调用站点转换回跟踪调用。

由于此性能增强,强烈建议启用 CONFIG_DYNAMIC_FTRACE。此外,CONFIG_DYNAMIC_FTRACE 提供了筛选应跟踪哪个函数的能力。请注意,即使 NOP 在基准测试中没有显示任何影响,但已知添加-pg选项附带的帧指针会导致轻微的开销。

要找出哪些跟踪器可用,只需在跟踪目录中查找available_tracers文件即可 :

[tracing]# cat available_tracers function_graph function sched_switch nop

要启用函数跟踪器,只需将“function” echo 到 current_tracer文件中。

[tracing]# echo function > current_tracer[tracing]# cat current_tracerfunction[tracing]# cat trace | head -10# tracer: function##           TASK-PID    CPU#    TIMESTAMP  FUNCTION#              | |       |          |         |            bash-16939 [000]  6075.461561: mutex_unlock <-tracing_set_tracer          -0     [001]  6075.461561: _spin_unlock_irqrestore <-hrtimer_get_next_event          -0     [001]  6075.461562: rcu_needs_cpu <-tick_nohz_stop_sched_tick            bash-16939 [000]  6075.461563: inotify_inode_queue_event <-vfs_write          -0     [001]  6075.461563: mwait_idle <-cpu_idle            bash-16939 [000]  6075.461563: __fsnotify_parent <-vfs_write

标题很好地解释了输出的格式。前两项是跟踪的任务名称和 PID。执行跟踪的 CPU 位于括号内。时间戳是自启动以来的时间,后跟函数名称。在这种情况下,函数是被跟踪的函数,其父函数跟在“ <- ”符号之后。

这些信息非常强大,并且很好地显示了函数的流程。但这可能有点难以遵循。由 Frederic Weisbecker 创建的函数图跟踪器跟踪函数的进入和退出,这使跟踪器能够了解被调用函数的深度。函数图跟踪器可以使人眼更容易跟踪内核中的执行流程:

[tracing]# echo function_graph > current_tracer [tracing]# cat trace | head -20# tracer: function_graph## CPU  DURATION                  FUNCTION CALLS# |     |   |                     |   |   |   | 1)   1.015 us    |        _spin_lock_irqsave(); 1)   0.476 us    |        internal_add_timer(); 1)   0.423 us    |        wake_up_idle_cpu(); 1)   0.461 us    |        _spin_unlock_irqrestore(); 1)   4.770 us    |      } 1)   5.725 us    |    } 1)   0.450 us    |    mutex_unlock(); 1) + 24.243 us   |  } 1)   0.483 us    |  _spin_lock_irq(); 1)   0.517 us    |  _spin_unlock_irq(); 1)               |  prepare_to_wait() { 1)   0.468 us    |    _spin_lock_irqsave(); 1)   0.502 us    |    _spin_unlock_irqrestore(); 1)   2.411 us    |  } 1)   0.449 us    |  kthread_should_stop(); 1)               |  schedule() {

这给出了一个函数的开始和结束,用类似 C 的注释“ { ”来启动一个函数,“ } ”在末尾。叶函数不调用其他函数,只是以“ ; ”结尾。DURATION 列显示在相应函数中花费的时间。函数图跟踪器记录函数进入和退出的时间,并将差异报告为持续时间。这些数字只出现在叶函数和“ }" 符号。注意,这次还包括嵌套函数内所有函数的开销以及函数图跟踪器本身的开销。函数图跟踪器劫持了函数的返回地址,以便为函数插入跟踪回调函数退出。这会破坏 CPU 的分支预测并导致比函数跟踪器更多的开销。最接近的真实时序仅发生在叶函数中。

孤独的“ + ”是有一个注释标记。当持续时间大于 10 微秒时,显示“ + ”。如果持续时间大于 100 微秒,将显示“ !”。

5. Using trace_printk()

printk()是所有调试器之王,但它有一个问题。如果您正在调试诸如定时器中断、调度程序或网络之类的大容量区域,printk()可能会导致系统陷入困境,甚至可能会创建实时锁。添加一些printk()时,看到错误“消失”也很常见。这是由于printk()引入的绝对开销。

Ftrace 引入了一种新形式的printk()称为 trace_printk()。它可以像printk()一样使用,也可以在任何上下文中使用(中断代码、NMI 代码和调度程序代码)。是什么样的好的trace_printk()是,它不会输出到控制台。相反,它写入 Ftrace 环形缓冲区,并且可以通过跟踪文件读取。

使用trace_printk()写入环形缓冲区只需要大约十分之一微秒左右。但是使用printk(),尤其是在写入串行控制台时,每次写入可能需要几毫秒。trace_printk()的性能优势 使您可以记录内核中最敏感的区域,而几乎没有影响。

例如,您可以将这样的内容添加到内核或模块中:

trace_printk("read foo %d out of bar %p
", bar->foo, bar);

然后通过查看跟踪文件,您可以看到您的输出。

[tracing]# cat trace# tracer: nop##           TASK-PID    CPU#    TIMESTAMP  FUNCTION#              | |       |          |         |           <...>-10690 [003] 17279.332920: : read foo 10 out of bar ffff88001

上面的示例是通过添加一个实际上具有foo和bar构造的模块来完成的 。

trace_printk()输出将出现在任何跟踪器中,甚至是函数和函数图跟踪器。

[tracing]# echo function_graph > current_tracer[tracing]# insmod ~/modules/foo.ko[tracing]# cat trace# tracer: function_graph## CPU  DURATION                  FUNCTION CALLS# |     |   |                     |   |   |   | 3) + 16.283 us   |      } 3) + 17.364 us   |    } 3)               |    do_one_initcall() { 3)               |      /* read foo 10 out of bar ffff88001191bef8 */ 3)   4.221 us    |    } 3)               |    __wake_up() { 3)   0.633 us    |      _spin_lock_irqsave(); 3)   0.538 us    |      __wake_up_common(); 3)   0.563 us    |      _spin_unlock_irqrestore();

是的,trace_printk() 输出看起来像函数图跟踪器中的注释。

6. Starting and stopping the trace

显然,有时您只想跟踪特定的代码路径。也许您只想跟踪运行特定测试时发生的情况。文件tracing_on用于禁止环形缓冲区记录数据:

[tracing]# echo 0 > tracking_on

这将禁用 Ftrace 环形缓冲区的记录。其他所有事情仍然发生在跟踪器上,它们仍然会产生大部分开销。他们确实注意到环形缓冲区没有记录,也不会尝试写入任何数据,但仍会执行跟踪器发出的调用。

要重新启用环形缓冲区,只需将“1”写入该文件:

[tracing]# echo 1 >tracing_on

请注意,在数字和大于号“ > ”之间有一个空格非常重要。否则,您可能正在将标准输入或输出写入该文件。

[tracing]# echo 0>tracing_on /* 这行不通!*/

一个常见的运行可能是:

[tracing]# echo 0 > tracing_on[tracing]# echo function_graph > current_tracer[tracing]# echo 1 > tracing_on; run_test; echo 0 > tracing_on

第一行禁止环形缓冲区记录任何数据。接下来启用函数图跟踪器。函数图跟踪器的开销仍然存在,但不会将任何内容记录到跟踪缓冲区中。最后一行启用环形缓冲区,运行测试程序,然后禁用环形缓冲区。这缩小了函数图跟踪器存储的数据范围,以仅包括run_test程序积累的数据 。

7. Trace Markers

查看内核内部发生的事情可以让用户更好地了解他们的系统是如何工作的。但有时需要在用户空间发生的事情和内核内部发生的事情之间进行协调。跟踪中显示的时间戳都与跟踪中发生的事情有关,但它们与墙时间不太对应。

为了帮助同步用户空间和内核空间中的操作,创建了trace_marker文件。它提供了一种从用户空间写入 Ftrace 环形缓冲区的方法。该标记随后将出现在轨迹中,以给出轨迹中特定事件发生的位置。

[tracing]# echo hello world > trace_marker[tracing]# cat trace# tracer: nop##           TASK-PID    CPU#    TIMESTAMP  FUNCTION#              | |       |          |         |           <...>-3718  [001]  5546.183420: 0: hello world

在<...>表示该写的标记任务的名字没有记录。未来的版本可能会解决这个问题。

8. Starting, Stopping and Recording in a Program

该tracing_on和trace_marker 文件的工作很好地跟踪应用程序的活动,如果应用程序的源可用。如果应用程序中存在问题并且您需要找出应用程序特定位置的内核内部发生了什么,这两个文件就派上用场了。

在应用程序启动时,您可以打开这些文件以准备好文件描述符:

int trace_fd = -1;int marker_fd = -1;int main(int argc, char **argv){ char *debugfs; char path[256]; [...] debugfs = find_debugfs(); if (debugfs) {  strcpy(path, debugfs);  /* BEWARE buffer overflow */  strcat(path,"/tracing/tracing_on");  trace_fd = open(path, O_WRONLY);  if (trace_fd >= 0)   write(trace_fd, "1", 1);  strcpy(path, debugfs);  strcat(path,"/tracing/trace_marker");  marker_fd = open(path, O_WRONLY);

然后,在代码中的某个关键位置,可以放置标记以显示应用程序当前所在的位置:

if (marker_fd >= 0) write(marker_fd, "In critical area
", 17);if (critical_function() < 0) { /* we failed! */ if (trace_fd >= 0)  write(trace_fd, "0", 1);}

在查看示例时,您首先会看到一个名为“find_debugfs()”的函数。挂载调试文件系统的正确位置是/sys/kernel/debug但强大的工具不应依赖于挂载在那里的调试文件系统。find_debugfs()的示例 位于此处。文件描述符被初始化为 -1 以允许此代码在启用和不启用跟踪的内核的情况下工作。

当检测到问题时,将 ASCII 字符“0”写入trace_fd文件描述符将停止跟踪。正如在第 1 部分中讨论的那样,这只会禁用记录到 Ftrace 环形缓冲区中,但跟踪器仍然会产生开销。

使用上面的初始化代码时,跟踪将在应用程序开始时启用,因为跟踪器以覆盖模式运行。也就是说,当跟踪缓冲区填满时,它将删除旧数据并用新数据替换它。由于在出现问题时只有最近的跟踪信息是相关的,因此在应用程序正常运行期间无需停止和启动跟踪。只有在检测到问题时才需要禁用跟踪器,以便跟踪记录导致错误的历史记录。如果应用程序中需要间隔跟踪,它可以将 ASCII“1”写入 trace_fd 以启用跟踪。

下面是一个名为simple_trace.c的简单程序示例, 它使用上述初始化过程:

req.tv_sec = 0;req.tv_nsec = 1000;write(marker_fd, "before nano
", 12);nanosleep(&req, NULL);write(marker_fd, "after nano
", 11);write(trace_fd, "0", 1);

(由于这是一个仅用于示例目的的简单程序,因此未添加错误检查。) 这是跟踪这个简单程序的过程:

[tracing]# echo 0 > tracing_on[tracing]# echo function_graph > current_tracer[tracing]# ~/simple_trace[tracing]# cat trace

第一行禁用跟踪,因为程序将在启动时启用它。接下来选择函数图跟踪器。程序被执行,结果如下。请注意,输出可能有点冗长,其中大部分内容已被删除并替换为 [...]:

[...]  0)               |      __kmalloc() {  0)   0.528 us    |        get_slab();  0)   2.271 us    |      }  0)               |      /* before nano */  0)               |      kfree() {  0)   0.475 us    |        __phys_addr();  0)   2.062 us    |      }  0)   0.608 us    |      inotify_inode_queue_event();  0)   0.485 us    |      __fsnotify_parent(); [...]  1)   0.523 us    |          _spin_unlock();  0)   0.495 us    |    current_kernel_time();  1)               |          it_real_fn() {  0)   1.602 us    |  }  1)   0.728 us    |            __rcu_read_lock();  0)               |  sys_nanosleep() {  0)               |    hrtimer_nanosleep() {  0)   0.526 us    |      hrtimer_init();  1)   0.418 us    |            __rcu_read_lock();  0)               |      do_nanosleep() {  1)   1.114 us    |            _spin_lock_irqsave(); [...]  0)               |      __kmalloc() {  1)   2.760 us    |  }  0)   0.556 us    |        get_slab();  1)               |  mwait_idle() {  0)   1.851 us    |      }  0)               |      /* after nano */  0)               |      kfree() {  0)   0.486 us    |        __phys_addr();

请注意,对 trace_marker 的写入在函数图跟踪器中显示为注释。这里的第一列代表 CPU。当我们像这样交错 CPU 跟踪时,可能很难读取跟踪。工具 grep 可以很容易地过滤它,或者可以使用 per_cpu 跟踪文件。per_cpu 跟踪文件位于 per_cpu 下的 debugfs 跟踪目录中。

[tracing]# ls per_cpucpu0  cpu1  cpu2  cpu3  cpu4  cpu5  cpu6  cpu7

在这些 CPU 目录中的每一个目录中都存在一个跟踪文件,仅显示该 CPU 的跟踪。要在不受其他 CPU 干扰的情况下更好地了解函数图跟踪器,只需查看 per_cpu/cpu0/trace。

[tracing]# cat per_cpu/cpu0/trace 0)               |      __kmalloc() { 0)   0.528 us    |        get_slab(); 0)   2.271 us    |      } 0)               |      /* before nano */ 0)               |      kfree() { 0)   0.475 us    |        __phys_addr(); 0)   2.062 us    |      } 0)   0.608 us    |      inotify_inode_queue_event(); 0)   0.485 us    |      __fsnotify_parent(); 0)   0.488 us    |      inotify_dentry_parent_queue_event(); 0)   1.106 us    |      fsnotify();[...] 0)   0.721 us    |    _spin_unlock_irqrestore(); 0)   3.380 us    |  } 0)               |  audit_syscall_entry() { 0)   0.495 us    |    current_kernel_time(); 0)   1.602 us    |  } 0)               |  sys_nanosleep() { 0)               |    hrtimer_nanosleep() { 0)   0.526 us    |      hrtimer_init(); 0)               |      do_nanosleep() { 0)               |        hrtimer_start_range_ns() { 0)               |          __hrtimer_start_range_ns() { 0)               |            lock_hrtimer_base() { 0)   0.866 us    |              _spin_lock_irqsave();[...] 0)               |      __kmalloc() { 0)               |        get_slab() { 0)   1.851 us    |      } 0)               |      /* after nano */ 0)               |      kfree() { 0)   0.486 us    |        __phys_addr();

由于文章篇幅有限,下文继续讲解

发表评论
留言与评论(共有 0 条评论) “”
   
验证码:

相关文章

推荐文章