perf 采样解析调用栈

2022-09-26 15:34:25 浏览数 (2)

perf除了上述的采样形式,还支持解析函数执行的完整调用栈,并得到调用栈中各个环节的cpu消耗,并对位于同一调用栈的各个环节的采样占比进行加总,得到占用cpu比例最高的顶层栈。使用如下命令进行采样

代码语言:javascript复制
perf record -g --call-graph fp xxx  # xxx 代表具体要执行的命令
perf record -g --call-graph fp -p $(pid)  #采集特定的pid
perf record -g --call-graph fp -a #采集整个系统

perf report > perf.txt

比如我对本地一个centos系统的采集结果如下(注意采集过程可能会出现很多找不到符号的情况,此为正常现象,可能是在系统构建时,就剔除了部分可执行文件的函数符号,用于裁剪空间)

代码语言:javascript复制
# To display the perf.data header info, please use --header/--header-only options.
#
#
# Total Lost Samples: 0
#
# Samples: 3K of event 'cycles:ppp'
# Event count (approx.): 272061843461905
#
# Children      Self  Command          Shared Object                 Symbol
# ........  ........  ...............  ............................  ..............................................
#
    19.14%     0.00%  swapper          [kernel.kallsyms]             [k] cpu_startup_entry
            |
             --19.14%--cpu_startup_entry
                       |
                        --19.14%--cpuidle_enter
                                  |
                                  |--17.53%--__irqentry_text_start
                                  |          |
                                  |           --17.53%--smp_apic_timer_interrupt
                                  |                     |
                                  |                     |--2.03%--irq_exit
                                  |                     |          |
                                  |                     |          |--1.08%--tick_nohz_irq_exit
                                  |                     |          |          __tick_nohz_idle_enter
                                  |                     |          |
                                  |                     |           --0.95%--__softirqentry_text_start
                                  |                     |                     |
                                  |                     |                      --0.95%--run_timer_softirq
                                  |                     |                                |
                                  |                     |                                 --0.95%--call_timer_fn
                                  |                     |                                           |
                                  |                     |                                            --0.95%--process_timeout
                                  |                     |                                                      wake_up_process
                                  |                     |                                                      try_to_wake_up
                                  |                     |                                                      |
                                  |                     |                                                       --0.95%--select_task_rq_fair

	...
	
    19.14%     0.00%  swapper          [kernel.kallsyms]             [k] cpuidle_enter
            |
            ---cpuidle_enter
               |
               |--17.53%--__irqentry_text_start
               |          |
               |           --17.53%--smp_apic_timer_interrupt
               |                     |

其一:整体打印了函数调用的树状结构,并表征了一个符号占用的19.14%具体是由哪些采样的符号组成的。注意即使该符号没有被采样到,他也可能出现在这里,因为可能这个符号调用链的下层调用函数被采样到了,故而这个符号就会体现在这里,而且会把他所有调用到的函数被采样的结果加总起来,得到children这一列。

其二:其中children一列的总和,是可能大于100%的,因为对于每一个采样点,如果能获取到这个采样点完整的调用栈,就会把这个采样点的overhead加总到他的parent symbol的children那一列,而实际的调用栈可能是 A->B->C->D。如果D被采样到了,且比例是1.1%,而A,B,C都未被采样到。则 A,B,C的children那一列均是1.1%,D则self那一列和children那一列都是1.1%。都会呈现在上述report中,故而加总起来会超过100%。

这其实是 perf report 默认携带了 --children参数的结果,在3.16版本以后的内核perf report都是默认携带的–children的参数,会存在children那一列,并对该结果进行计算,以得到占用cpu比例最高的最顶层调用。

代码语言:javascript复制
perf report --no-children > perf.txt #默认读取perf.data

可以得到如下结果,overhead的加总为100%,同时可以看到具体符号的调用栈

代码语言:javascript复制
# To display the perf.data header info, please use --header/--header-only options.
#
#
# Total Lost Samples: 0
#
# Samples: 3K of event 'cycles:ppp'
# Event count (approx.): 272061843461905
#
# Overhead  Command          Shared Object                 Symbol
# ........  ...............  ............................  ..........................................
#
    14.55%  swapper          [kernel.kallsyms]             [k] smp_apic_timer_interrupt
            |
            ---smp_apic_timer_interrupt
               __irqentry_text_start
               cpuidle_enter
               cpu_startup_entry
               start_secondary

    14.55%  perf             [kernel.kallsyms]             [k] flat_send_IPI_mask
    12.93%  nvralarm         [kernel.kallsyms]             [k] copy_page
            |
            ---copy_page
               |
                --12.93%--do_huge_pmd_wp_page
                          handle_mm_fault
                          __do_page_fault
                          do_page_fault
                          page_fault
                          |
                           --12.93%--__reclaim_stacks
                                     0x12fc7

总结来说:

self:self记录的是最后一列的符号(可以理解为函数)本身采样数占总采样数的百分比

目的: 找到最底层的热点函数

Children:记录的是这个符号调用的其他符号(理解为子函数,包括直接调用和间接调用)的采样数之和占总采样数的百分比

目的:找到叫高层的热点函数

0 人点赞