了解 Linux 性能报告输出

问题描述 投票：0回答：1

虽然我可以直观地获得大部分结果，但我很难完全理解 

perf report
命令的输出，尤其是涉及调用图的内容，所以我编写了一个愚蠢的测试来彻底解决我的这个问题.

愚蠢的测试

我编译了以下内容：

gcc -Wall -pedantic perf-test.c -lm -o perf-test

没有积极的优化来避免内联等。

#include <math.h>

#define N 10000000UL

#define USELESSNESS(n)                          \
    do {                                        \
        unsigned long i;                        \
        double x = 42;                          \
        for (i = 0; i < (n); i++) x = sin(x);   \
    } while (0)

void baz()
{
    USELESSNESS(N);
}

void bar()
{
    USELESSNESS(2 * N);
    baz();
}

void foo()
{
    USELESSNESS(3 * N);
    bar();
    baz();
}

int main()
{
    foo();
    return 0;
}

平面轮廓

perf record ./perf-test
perf report

有了这些我得到：

  94,44%  perf-test  libm-2.19.so       [.] __sin_sse2
   2,09%  perf-test  perf-test          [.] sin@plt
   1,24%  perf-test  perf-test          [.] foo
   0,85%  perf-test  perf-test          [.] baz
   0,83%  perf-test  perf-test          [.] bar

这听起来很合理，因为繁重的工作实际上是由 

__sin_sse2
执行的，而 
sin@plt
可能只是一个包装器，而我的函数的开销仅考虑循环，总体而言：
3*N
迭代 
foo
，
 2*N
对于另外两个。

分层剖析

perf record -g ./perf-test
perf report -G
perf report

现在我得到的开销列有两个：

Children
（默认情况下输出按此排序）和
Self
（与平面轮廓相同的开销）。

从这里我开始感觉我错过了一些东西：无论我是否使用 

-G
，我都无法用“x 调用 y”或“y 被 x 调用”来解释层次结构，例如:

  • 没有 

    -G
    （“y 被 x 调用”）：

      -   94,34%    94,06%  perf-test  libm-2.19.so       [.] __sin_sse2
     - __sin_sse2
        + 43,67% foo
        + 41,45% main
        + 14,88% bar
  -   37,73%     0,00%  perf-test  perf-test          [.] main
       main
       __libc_start_main
  -   23,41%     1,35%  perf-test  perf-test          [.] foo
       foo
       main
       __libc_start_main
  -    6,43%     0,83%  perf-test  perf-test          [.] bar
       bar
       foo
       main
       __libc_start_main
  -    0,98%     0,98%  perf-test  perf-test          [.] baz
     - baz
        + 54,71% foo
        + 45,29% bar
    1. 为什么
      __sin_sse2
      被
      main
      （间接？）、
      foo
      和
      bar
      调用，而不是被
      baz
      调用？
    2. 为什么函数有时附加百分比和层次结构（例如，
      baz
      的最后一个实例），有时则没有（例如
      bar
      的最后一个实例）？

  • 与 

    -G
    （“x 调用 y”）：

      -   94,34%    94,06%  perf-test  libm-2.19.so       [.] __sin_sse2
     + __sin_sse2
     + __libc_start_main
     + main
  -   37,73%     0,00%  perf-test  perf-test          [.] main
     - main
        + 62,05% foo
        + 35,73% __sin_sse2
          2,23% sin@plt
  -   23,41%     1,35%  perf-test  perf-test          [.] foo
     - foo
        + 64,40% __sin_sse2
        + 29,18% bar
        + 3,98% sin@plt
          2,44% baz
       __libc_start_main
       main
       foo
    1. 我应该如何解释
      __sin_sse2
      下的前三个条目？
    2. main
      调用 
      foo
      没关系，但是为什么如果它调用 
      __sin_sse2
      和 
      sin@plt
      （间接？）它不会同时调用 
      bar
      和 
      baz
      ？
    3. 为什么
      __libc_start_main
      和
      main
      出现在
      foo
      下面？为什么
      foo
      出现两次？

怀疑这个层次结构有两个级别，其中第二个级别实际上代表“x调用y”/“y被x调用”语义，但我厌倦了猜测，所以我在这里问。而且文档似乎没有帮助。

很抱歉这篇文章很长，但我希望所有这些上下文也可以对其他人有所帮助或作为参考。

c linux perf
1个回答
16
投票

好吧，让我们暂时忽略调用者和被调用者调用图之间的差异，主要是因为当我在我的机器上比较这两个选项之间的结果时，我只看到

kernel.kallsyms
DSO内部的效果，原因我不明白——我自己对此还比较陌生。

我发现对于你的例子来说，阅读整棵树会更容易一些。因此，使用 

--stdio
，让我们看看整个树中的 
__sin_sse2
：

# Overhead    Command      Shared Object                  Symbol
# ........  .........  .................  ......................
#
    94.72%  perf-test  libm-2.19.so       [.] __sin_sse2
            |
            --- __sin_sse2
               |
               |--44.20%-- foo
               |          |
               |           --100.00%-- main
               |                     __libc_start_main
               |                     _start
               |                     0x0
               |
               |--27.95%-- baz
               |          |
               |          |--51.78%-- bar
               |          |          foo
               |          |          main
               |          |          __libc_start_main
               |          |          _start
               |          |          0x0
               |          |
               |           --48.22%-- foo
               |                     main
               |                     __libc_start_main
               |                     _start
               |                     0x0
               |
                --27.84%-- bar
                          |
                           --100.00%-- foo
                                     main
                                     __libc_start_main
                                     _start
                                     0x0

所以，我读到这里的方式是：44% 的时间，

sin
是从 
foo
调用的； 27% 的时间是从 
baz
调用，27% 是从 bar 调用。

-g 的文档很有指导意义：

 -g [type,min[,limit],order[,key]], --call-graph
       Display call chains using type, min percent threshold, optional print limit and order. type can be either:

       ·   flat: single column, linear exposure of call chains.

       ·   graph: use a graph tree, displaying absolute overhead rates.

       ·   fractal: like graph, but displays relative rates. Each branch of the tree is considered as a new profiled object.

               order can be either:
               - callee: callee based call graph.
               - caller: inverted caller based call graph.

               key can be:
               - function: compare on functions
               - address: compare on individual code addresses

               Default: fractal,0.5,callee,function.

这里重要的一点是默认是分形的，在分形模式下，每个分支都是一个新对象。

因此，您可以看到 

baz
被调用的时间中有 50% 是从 
bar
调用的，另外 50% 是从 
foo
调用的。

这并不总是最有用的措施，因此使用 

-g graph
:

查看结果很有启发性 
94.72%  perf-test  libm-2.19.so       [.] __sin_sse2
        |
        --- __sin_sse2
           |
           |--41.87%-- foo
           |          |
           |           --41.48%-- main
           |                     __libc_start_main
           |                     _start
           |                     0x0
           |
           |--26.48%-- baz
           |          |
           |          |--13.50%-- bar
           |          |          foo
           |          |          main
           |          |          __libc_start_main
           |          |          _start
           |          |          0x0
           |          |
           |           --12.57%-- foo
           |                     main
           |                     __libc_start_main
           |                     _start
           |                     0x0
           |
            --26.38%-- bar
                      |
                       --26.17%-- foo
                                 main
                                 __libc_start_main
                                 _start
                                 0x0

这将更改为使用绝对百分比，其中报告该调用链的每个时间百分比：因此 

foo->bar
是总刻度数的 26%（依次调用 
baz
），
foo->baz
（直接）是 12占总蜱虫的百分比。

从

__sin_sse2
的角度来看，我仍然不知道为什么我看不到被调用者和调用者图之间有任何差异。

更新

我从命令行所做的一件事是如何收集调用图。 Linux perf 默认情况下使用帧指针方法来重建调用堆栈。当编译器使用 

-fomit-frame-pointer
作为 default 时，这可能会出现问题。所以我用了

perf record --call-graph dwarf ./perf-test
最新问题
© www.soinside.com 2019 - 2024. All rights reserved.