跟踪 linux 内核调用_Linux用户和内核空间中的动态跟踪-白红宇

跟踪 linux 内核调用_Linux用户和内核空间中的动态跟踪

阅读量：2526 次

发布时间：2019-05-11

本文共 16185 字，大约阅读时间需要 53 分钟。

跟踪 linux 内核调用

您是否曾经遇到过这样的情况，即您意识到没有在代码中的某些点插入调试打印 ，所以现在您将不知道您的CPU是否命中了特定的代码行来执行，直到您重新编译该代码为止。调试语句？不用担心，这里有一个更简单的解决方案。基本上，您需要在源代码汇编指令的不同位置插入动态探测点。

对于高级用户，内核和提供了大量有关不同类型内核和用户空间跟踪机制的信息。但是，普通用户只需要几个简单的步骤和一个快速入门的示例。这就是本文的帮助之处。

让我们从定义开始。

探测点

探测点是一个调试语句，它有助于探索软件的执行特性（即，执行探测语句时的执行流程和软件数据结构的状态）。是probe语句的最简单形式，并且是开发人员用于内核黑客的基本工具之一。

静态与动态探测

因为它需要重新编译源代码，所以printk插入是一种静态探测方法。内核代码中重要位置上还有许多其他静态跟踪点可以动态启用或禁用。 Linux内核具有一些框架，可以帮助开发人员探测内核或用户空间应用程序而无需重新编译源代码。是在内核代码中插入探测点的一种动态方法，而在用户应用程序中这样做。

使用uprobe跟踪用户空间

可以使用sysfs接口或将uprobe跟踪点插入任何用户空间代码中。

使用sysfs界面插入长袍

考虑以下没有打印语句的简单测试代码，我们希望在某些指令中插入探针：

[      
     [ app-listing      
     ]      
     ]      
          
     [      
     source ,c      
     ]      
     .test.c

#include 
    
           
          
     #include 
     
            
          
     #include 
      
             
          
     static int func_1_cnt;     
     static int func_2_cnt;     
          
     static void func_1      
     ( void      
     )      
          
     {
            
             func_1_cnt++;     
          
     }      
          
     static void func_2      
     ( void      
     )      
          
     {
            
             func_2_cnt++;     
          
     }      
          
     int main      
     ( int argc, void      
     ** argv      
     )      
          
     {
            
             int number;     
          
                  
     while      
     (      
     1      
     )      
     {
            
                          
     sleep      
     (      
     1      
     ) ;     
                     number = rand      
     (      
     )      
     %      
     10 ;     
                          
     if      
     ( number      
     <      
     5      
     )      
                             func_2      
     (      
     ) ;     
                          
     else      
                             func_1      
     (      
     ) ;     
                  
     }      
          
     }

编译代码并找到要探测的指令地址：

# gcc -o test test.c      
          
     # objdump -d test

假设我们在ARM64平台上具有以下目标代码：

0000000000400620      
     < func_1      
     > :     
            
     400620 :            
     90000080        adrp    x0,      
     410000      
     < __FRAME_END__+0xf6f8      
     >      
            
     400624 :       912d4000        add     x0, x0,      
     #0xb50      
            
     400628 :       b9400000        ldr     w0,      
     [ x0      
     ]      
       40062c:            
     11000401        add     w1, w0,      
     #0x1      
            
     400630 :            
     90000080        adrp    x0,      
     410000      
     < __FRAME_END__+0xf6f8      
     >      
            
     400634 :       912d4000        add     x0, x0,      
     #0xb50      
            
     400638 :       b9000001        str     w1,      
     [ x0      
     ]      
       40063c:       d65f03c0        ret     
          
     0000000000400640      
     < func_2      
     > :     
            
     400640 :            
     90000080        adrp    x0,      
     410000      
     < __FRAME_END__+0xf6f8      
     >      
            
     400644 :       912d5000        add     x0, x0,      
     #0xb54      
            
     400648 :       b9400000        ldr     w0,      
     [ x0      
     ]      
       40064c:            
     11000401        add     w1, w0,      
     #0x1      
            
     400650 :            
     90000080        adrp    x0,      
     410000      
     < __FRAME_END__+0xf6f8      
     >      
            
     400654 :       912d5000        add     x0, x0,      
     #0xb54      
            
     400658 :       b9000001        str     w1,      
     [ x0      
     ]      
       40065c:       d65f03c0        ret

并且我们想在偏移量0x620和0x644处插入一个探针。执行以下命令：

# echo 'p:func_2_entry test:0x620' > /sys/kernel/debug/tracing/uprobe_events      
          
     # echo 'p:func_1_entry test:0x644' >> /sys/kernel/debug/tracing/uprobe_events      
          
     # echo 1 > /sys/kernel/debug/tracing/events/uprobes/enable      
          
     # ./test&

在上面的第一和第二第二个echo语句中， p告诉我们这是一个简单的探针 。（探测可以是简单的，也可以是return 。） func_n_entry是我们在跟踪输出中看到的名称。名称是一个可选字段；如果未提供，则应使用p_test_0x644之类的名称。 test是我们要在其中插入探针的可执行二进制文件。如果test不在当前目录中，则需要指定path_to_test / test 。 0x620或0x640是距程序开头的指令偏移量。请注意第二个echo语句中的>> ，因为我们想再添加一个探针。因此，当在前两个命令中插入探测点之后启用uprobe跟踪时，当我们写入events / uprobes / enable时，它将启用所有uprobe事件。通过写入events目录中创建的特定事件文件，我们也可以启用单个事件。插入并启用探测点后，只要执行所探测的指令，我们就可以看到跟踪条目。

阅读跟踪文件以查看输出：

# cat /sys/kernel/debug/tracing/trace      
          
     # tracer: nop      
          
     #      
          
     # entries-in-buffer/entries-written: 8/8   #P:8      
          
     #      
          
     #                              _-----=> irqs-off      
          
     #                             / _----=> need-resched      
          
     #                            | / _---=> hardirq/softirq      
          
     #                            || / _--=> preempt-depth      
          
     #                            ||| /     delay      
          
     #           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION      
          
     #              | |       |   ||||       |         |      
                 test-      
     2788       
     [ 003      
     ] ....       
     1740.674740 : func_1_entry:      
     ( 0x400644      
     )      
                 test-      
     2788       
     [ 003      
     ] ....       
     1741.674854 : func_1_entry:      
     ( 0x400644      
     )      
                 test-      
     2788       
     [ 003      
     ] ....       
     1742.674949 : func_2_entry:      
     ( 0x400620      
     )      
                 test-      
     2788       
     [ 003      
     ] ....       
     1743.675065 : func_2_entry:      
     ( 0x400620      
     )      
                 test-      
     2788       
     [ 003      
     ] ....       
     1744.675158 : func_1_entry:      
     ( 0x400644      
     )      
                 test-      
     2788       
     [ 003      
     ] ....       
     1745.675273 : func_1_entry:      
     ( 0x400644      
     )      
                 test-      
     2788       
     [ 003      
     ] ....       
     1746.675390 : func_2_entry:      
     ( 0x400620      
     )      
                 test-      
     2788       
     [ 003      
     ] ....       
     1747.675503 : func_2_entry:      
     ( 0x400620      
     )

我们可以看到什么任务是由哪个CPU完成的，以及它在什么时候执行了被探测的指令。

返回探针也可以插入任何指令中。当返回具有该指令的函数时，这将记录一个条目：

# echo 0 > /sys/kernel/debug/tracing/events/uprobes/enable      
          
     # echo 'r:func_2_exit test:0x620' >> /sys/kernel/debug/tracing/uprobe_events      
          
     # echo 'r:func_1_exit test:0x644' >> /sys/kernel/debug/tracing/uprobe_events      
          
     # echo 1 > /sys/kernel/debug/tracing/events/uprobes/enable

在这里，我们使用r代替p ，所有其他参数都相同。请注意，如果要插入新的探测点，则需要禁用uprobe事件：

            test-      
     3009       
     [ 002      
     ] ....       
     4813.852674 : func_1_entry:      
     ( 0x400644      
     )      
                 test-      
     3009       
     [ 002      
     ] ....       
     4813.852691 : func_1_exit:      
     ( 0x4006b0      
     < - 0x400644      
     )      
                 test-      
     3009       
     [ 002      
     ] ....       
     4814.852805 : func_2_entry:      
     ( 0x400620      
     )      
                 test-      
     3009       
     [ 002      
     ] ....       
     4814.852807 : func_2_exit:      
     ( 0x4006b8      
     < - 0x400620      
     )      
                 test-      
     3009       
     [ 002      
     ] ....       
     4815.852920 : func_2_entry:      
     ( 0x400620      
     )      
                 test-      
     3009       
     [ 002      
     ] ....       
     4815.852921 : func_2_exit:      
     ( 0x4006b8      
     < - 0x400620      
     )

上面的记录告诉我们func_1在时间戳4813.852691返回地址0x4006b0。

# echo 0 > /sys/kernel/debug/tracing/events/uprobes/enable      
          
     # echo 'p:func_2_entry test:0x630' > /sys/kernel/debug/tracing/uprobe_events count=%x1      
          
     # echo 1 > /sys/kernel/debug/tracing/events/uprobes/enable      
          
     # echo > /sys/kernel/debug/tracing/trace      
          
     # ./test&

在这里，当执行偏移量为0x630的指令时，我们将ARM64 x1寄存器的值打印为count = 。

输出如下所示：

            test-      
     3095       
     [ 003      
     ] ....       
     7918.629728 : func_2_entry:      
     ( 0x400630      
     )      
     count =0x1     
                 test-      
     3095       
     [ 003      
     ] ....       
     7919.629884 : func_2_entry:      
     ( 0x400630      
     )      
     count =0x2     
                 test-      
     3095       
     [ 003      
     ] ....       
     7920.629988 : func_2_entry:      
     ( 0x400630      
     )      
     count =0x3     
                 test-      
     3095       
     [ 003      
     ] ....       
     7922.630272 : func_2_entry:      
     ( 0x400630      
     )      
     count =0x4     
                 test-      
     3095       
     [ 003      
     ] ....       
     7923.630429 : func_2_entry:      
     ( 0x400630      
     )      
     count =0x5

使用perf插入长袍

总是在需要插入探针的位置找到指令或函数的偏移量很麻烦，而且知道分配给任何局部变量的CPU寄存器的名称甚至更加复杂。 perf是有用的工具，可帮助您准备uprobe并将其插入源代码的任何行中。

除了perf之外，还有一些其他工具，例如SystemTap ， DTrace和LTTng ，可用于内核和用户空间跟踪。但是， perf与内核完全耦合，因此受到内核开发人员的青睐。

# gcc -g -o test test.c      
          
     # perf probe -x ./test func_2_entry=func_2      
          
     # perf probe -x ./test func_2_exit=func_2%return      
          
     # perf probe -x ./test test_15=test.c:15      
          
     # perf probe -x ./test test_25=test.c:25 number      
          
     # perf record -e probe_test:func_2_entry -e probe_test:func_2_exit -e probe_test:test_15  -e probe_test:test_25 ./test

如上面的示例所示，我们可以将探测点直接插入函数的开始和返回，源文件的特定行号等。您可以打印局部变量。您可以有许多其他选项，例如函数调用的所有实例（有关详细信息，请参见）。 perf探测器用于创建探测点事件，然后可以在执行./test可执行文件时使用perf记录来探测那些事件。创建perf探测点时，我们可以有其他记录选项，例如perf stat ，并且可以有很多后期分析选项，例如perf脚本或perf report 。

使用perf脚本 ，以上示例的输出如下所示：

# perf script      
                      
     test       
     2741      
     [ 002      
     ]        
     427.584681 : probe_test:test_25:      
     ( 4006a0      
     )      
     number =      
     3      
                      
     test       
     2741      
     [ 002      
     ]        
     427.584717 : probe_test:test_15:      
     (      
     400640      
     )      
                      
     test       
     2741      
     [ 002      
     ]        
     428.584861 : probe_test:test_25:      
     ( 4006a0      
     )      
     number =      
     6      
                      
     test       
     2741      
     [ 002      
     ]        
     428.584872 : probe_test:func_2_entry:      
     (      
     400620      
     )      
                      
     test       
     2741      
     [ 002      
     ]        
     428.584881 : probe_test:func_2_exit:      
     (      
     400620      
     < - 4006b8      
     )      
                      
     test       
     2741      
     [ 002      
     ]        
     429.585012 : probe_test:test_25:      
     ( 4006a0      
     )      
     number =      
     7      
                      
     test       
     2741      
     [ 002      
     ]        
     429.585021 : probe_test:func_2_entry:      
     (      
     400620      
     )      
                      
     test       
     2741      
     [ 002      
     ]        
     429.585025 : probe_test:func_2_exit:      
     (      
     400620      
     < - 4006b8      
     )

使用kprobe跟踪内核空间

与uprobe一样，可以使用sysfs接口或perf工具将kprobe跟踪点插入内核代码。

使用sysfs界面插入kprobe

我们可以在/ proc / kallsyms中的 大多数符号中插入kprobe ；其他符号已在内核中列入黑名单。如果将kprobe插入与kprobe插入不兼容的符号，则将其插入kprobe_events文件中会导致写入错误。也可以将探针插入到距符号基础一定距离的位置。像uprobe一样，我们也可以使用跟踪函数的返回。局部变量的值也可以打印在跟踪输出中。

本示例说明了如何执行此操作：

; disable all events, just to insure that we see only kprobe output      
     in trace.     
          
     # echo 0 > /sys/kernel/debug/tracing/events/enable      
     ; disable kprobe events      
     until probe points are inseted.     
          
     # echo 0 > /sys/kernel/debug/tracing/events/kprobes/enable      
     ;      
     clear out all the events from kprobe_events, to insure that we see output      
     for      
     ; only those      
     for      
     which we have enabled      
          
     # echo > /sys/kernel/debug/tracing/kprobe_events      
     ; insert probe point at kfree     
          
     # echo "p kfree" >> /sys/kernel/debug/tracing/kprobe_events      
     ; insert probe point at kfree+0x10 with name kfree_probe_10     
          
     # echo "p:kree_probe_10 kfree+0x10" >> /sys/kernel/debug/tracing/kprobe_events      
     ; insert probe point at kfree      
     return      
          
     # echo "r:kfree_probe kfree" >> /sys/kernel/debug/tracing/kprobe_events      
     ;      
     enable kprobe events      
     until probe points are inseted.     
          
     # echo 1 > /sys/kernel/debug/tracing/events/kprobes/enable

[ root      
     @ pratyush ~      
     ]      
     # more /sys/kernel/debug/tracing/trace      
          
     # tracer: nop      
          
     #      
          
     # entries-in-buffer/entries-written: 9037/9037   #P:8      
          
     #      
          
     #                              _-----=> irqs-off      
          
     #                             / _----=> need-resched      
          
     #                            | / _---=> hardirq/softirq      
          
     #                            || / _--=> preempt-depth      
          
     #                            ||| /     delay      
          
     #           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION      
          
     #              | |       |   ||||       |         |      
                 sshd-      
     2189       
     [ 002      
     ] dn..       
     1908.930731 : kree_probe:      
     ( __audit_syscall_exit+0x194      
     / 0x218      
     < - kfree      
     )      
                 sshd-      
     2189       
     [ 002      
     ] d...       
     1908.930744 : p_kfree_0:      
     ( kfree+0x0      
     / 0x214      
     )      
                 sshd-      
     2189       
     [ 002      
     ] d...       
     1908.930746 : kree_probe_10:      
     ( kfree+0x10      
     / 0x214      
     )

使用perf插入kprobe

与uprobe一样，我们可以使用perf在内核代码中插入kprobe。我们可以将一个探针点直接插入函数的开始和返回，源文件的特定行号等。我们可以为-k选项提供vmlinux ，或者可以为-s选项提供内核源代码路径。：

# perf probe -k vmlinux kfree_entry=kfree      
          
     # perf probe -k vmlinux kfree_exit=kfree%return      
          
     # perf probe -s ./  kfree_mid=mm/slub.c:3408 x      
          
     # perf record -e probe:kfree_entry -e probe:kfree_exit -e probe:kfree_mid sleep 10

使用perf脚本 ，我们将在上面的示例中看到以下输出：

# perf script      
                     
     sleep       
     2379      
     [ 001      
     ]       
     2702.291224 : probe:kfree_entry:      
     ( fffffe0000201944      
     )      
                     
     sleep       
     2379      
     [ 001      
     ]       
     2702.291229 : probe:kfree_mid:      
     ( fffffe0000201978      
     )      
     x =0x0     
                     
     sleep       
     2379      
     [ 001      
     ]       
     2702.291231 : probe:kfree_exit:      
     ( fffffe0000201944      
     < - fffffe000019f67c      
     )      
                     
     sleep       
     2379      
     [ 001      
     ]       
     2702.291241 : probe:kfree_entry:      
     ( fffffe0000201944      
     )      
                     
     sleep       
     2379      
     [ 001      
     ]       
     2702.291242 : probe:kfree_mid:      
     ( fffffe0000201978      
     )      
     x =0xfffffe01db8f6000     
                     
     sleep       
     2379      
     [ 001      
     ]       
     2702.291243 : probe:kfree_exit:      
     ( fffffe0000201944      
     < - fffffe000019f67c      
     )      
                     
     sleep       
     2379      
     [ 001      
     ]       
     2702.291249 : probe:kfree_entry:      
     ( fffffe0000201944      
     )      
                     
     sleep       
     2379      
     [ 001      
     ]       
     2702.291250 : probe:kfree_mid:      
     ( fffffe0000201978      
     )      
     x =0xfffffe01db8f6000     
                     
     sleep       
     2379      
     [ 001      
     ]       
     2702.291251 : probe:kfree_exit:      
     ( fffffe0000201944      
     < - fffffe000019f67c      
     )