Mik*_*vey 200
gprof (阅读论文)是出于历史原因而存在的。如果您认为它会帮助您发现性能问题,那么它从未如此宣传过。这是论文中所说的:
该配置文件可用于比较和评估各种实现的成本。
它并没有说它可以用于识别要评估的各种实现,尽管它确实暗示它可以在特殊情况下:
特别是如果发现程序的一小部分支配了它的执行时间。
那些不那么本地化的问题呢?那些不重要吗?不要对从未声称过的gprof抱有期望。它只是一个测量工具,并且只用于 CPU 密集型操作。
试试这个。
这是 44 倍加速的示例。
这是 730 倍的加速。
这是一个 8 分钟的视频演示。
这是统计数据的解释。
这是对批评的回答。  
关于程序有一个简单的观察。在给定的执行中,每条指令都占总时间(尤其是call指令)的一部分,从某种意义上说,如果不存在,则不会花费时间。在此期间,指令在堆栈中**。明白了这一点,你就可以看到——  
gprof体现了某些关于性能的神话,例如:
程序计数器采样很有用。
仅当您有一个不必要的热点瓶颈(例如大量标量值的冒泡排序)时,它才有用。例如,一旦您使用字符串比较将其更改为排序,它仍然是一个瓶颈,但程序计数器采样将看不到它,因为现在热点在字符串比较中。另一方面,如果要对扩展程序计数器(调用堆栈)进行采样,则会清楚地显示调用字符串比较的点,即排序循环。事实上,gprof是为了弥补 pc-only 采样的局限性。
计时功能比捕获耗时的代码行更重要。
这个神话的原因是gprof无法捕获堆栈样本,因此它对函数进行计时,计算它们的调用,并尝试捕获调用图。然而,一旦确定了一个代价高昂的函数,你仍然需要在它内部寻找负责时间的行。如果有您不需要查看的堆栈样本,这些线将在样本上。(一个典型的函数可能有 100 - 1000 条指令。一个函数调用是 1 条指令,所以定位开销大的调用的精度要高 2-3 个数量级。)
调用图很重要。
关于一个程序,你需要知道的不是它把时间花在哪里,而是为什么. 当它在一个函数中花费时间时,堆栈上的每一行代码都会在推理链中给出一个链接,说明它为什么存在。如果您只能看到堆栈的一部分,则只能看到部分原因,因此您无法确定该时间是否真的需要。调用图告诉你什么?每条弧线都告诉您某个函数 A 在某个时间段内正在调用某个函数 B。即使 A 只有一行这样的代码调用 B,该行也只给出了一小部分原因。如果你足够幸运,也许那条线有一个糟糕的理由。通常,您需要看到多条同时出现的线路才能找到原因。如果 A 在不止一个地方调用 B,那么它告诉你的会更少。
递归是一个棘手的令人困惑的问题。
那只是因为gprof和其他分析器认为需要生成调用图,然后将时间归因于节点。如果有堆栈的样本,则出现在样本上的每一行代码的时间成本是一个非常简单的数字——它所在的样本的比例。如果存在递归,则给定的行可以在样本上多次出现。 
不管。假设每 N ms 采集一次样本,并且这条线出现在 F% 的样本上(单独或不出现)。如果可以使该行不占用任何时间(例如通过删除它或在其周围分支),那么这些样本将消失,并且时间将减少 F%。
时间测量的准确性(因此需要大量样本)很重要。
想一想。如果一行代码出现在 5 个样本中的 3 个样本上,那么如果您可以像灯泡一样将其射出,那么所使用的时间大约会减少 60%。现在,您知道如果您采集了不同的 5 个样本,您可能只会看到 2 次,或多达 4 次。因此,60% 的测量更像是从 40% 到 80% 的一般范围。如果只有40%,你会说这个问题不值得修复吗?那么,当您真正想要的是发现问题时,时间准确性又有什么意义呢?500 或 5000 个样本会更精确地测量问题,但不会更准确地发现它。
语句或函数调用的计数很有用。
假设你知道一个函数被调用了 1000 次。你能从中看出它花费了多少时间?您还需要知道平均运行需要多长时间,乘以计数,再除以总时间。平均调用时间可能从纳秒到秒不等,因此仅凭计数并不能说明太多。如果有堆栈样本,则例程或任何语句的成本只是它所在的样本的一部分。如果可以使例程或语句不占用任何时间,那么原则上可以节省这部分时间,因此这与性能有最直接的关系。
阻塞时不需要采样
造成这种误解的原因有两个:1) 程序等待时 PC 采样是没有意义的,以及 2) 对计时准确性的关注。但是,对于 (1) 程序很可能正在等待它所要求的东西,例如文件 I/O,您需要知道这些,以及显示哪些堆栈样本。(显然,您希望在等待用户输入时排除样本。)对于 (2),如果程序只是因为与其他进程的竞争而等待,那么这可能是在它运行时以相当随机的方式发生的。因此,虽然程序可能需要更长的时间,但这不会对重要的统计数据产生很大影响,即语句在堆栈上的时间百分比。
“自时间”很重要
自时间只有在您在函数级别而不是行级别进行测量时才有意义,并且您认为您需要帮助来辨别函数时间是进入纯粹的本地计算还是在被调用的例程中。如果在行级别进行汇总,则一行如果在堆栈的末尾则表示自时间,否则表示包含时间。无论哪种方式,它的成本是它所在的堆栈样本的百分比,以便在任何一种情况下都能为您找到它。
必须以高频率采集样本
这源于这样一种想法,即性能问题可能是快速发生的,并且必须频繁采样才能解决它。但是,如果问题花费了 20%,比如说,在 10 秒(或其他)的总运行时间中,那么总时间中的每个样本将有 20% 的机会击中它,无论问题是否发生在像这样的单个片段
.....XXXXXXXX...........................
.^.^.^.^.^.^.^.^.^.^.^.^.^.^.^.^.^.^.^.^(20 个样本,4 个命中)
或在许多像这样的小片段
X...X...X.X..X.........X.....X....X.....
.^.^.^.^.^.^.^.^.^.^.^.^.^.^.^.^.^.^.^.^(20 个样本,3 个命中)中,
无论采用多少个样本,命中数的平均值约为 5 分之一,或者多少。(平均值 = 20 * 0.2 = 4。标准偏差 = +/- sqrt(20 * 0.2 * 0.8) = 1.8。)
你正在努力寻找的瓶颈
好像只有一个有。考虑以下执行时间线:vxvWvzvWvxvWvYvWvxvWv.vWvxvWvYvW
它由真正有用的工作组成,用 表示.。性能问题分别vWxYz占用 1/2、1/4、1/8、1/16、1/32 的时间。采样v很容易找到。去掉了,留下
xWzWxWYWxW.WxWYW
现在程序运行W时间减半,现在运行时间减半,而且很容易找到。它被删除,留下
xzxYx.xY
这个过程继续,每次删除最大的,按百分比,性能问题,直到没有可以删除的内容。现在唯一执行的是.,它的执行时间是原始程序所用时间的 1/32。这是放大效果,因为分母减少了,因此删除任何问题都会使余数变大,按百分比计算。
另一个关键点是必须找到每一个问题- 没有遗漏 5 个。任何未找到和修复的问题都会严重降低最终加速比。仅仅找到一些,但不是全部,还不够“足够好”。
补充:我只想指出gprof受欢迎的一个原因- 它正在被教授,大概是因为它是免费的,易于教授,并且已经存在了很长时间。快速谷歌搜索找到一些教授它(或似乎)的学术机构:
伯克利布克莱姆森科罗拉多公爵厄勒姆 fsu 印第安纳麻省理工学院 ncsa.illinois ncsu 纽普林斯顿 psu 斯坦福大学 ucsd umd umich 犹他州 utexas utk wustl
** 除了请求完成工作的其他方式外,不要留下任何说明原因的痕迹,例如通过消息发布。
Nor*_*sey 76
Valgrind有一个指令计数分析器和一个非常好的可视化工具KCacheGrind。正如 Mike Dunlavey 所建议的那样,Valgrind 计算了一个过程在堆栈中存活的指令的分数,尽管我很遗憾地说它在相互递归的情况下似乎变得混乱。但是可视化器非常好并且领先了光年gprof。
小智 65
由于我在这里没有看到关于perf哪个是用于在 Linux 上分析内核和用户应用程序的相对较新的工具的任何信息,因此我决定添加此信息。
perf如果您的 Linux 内核大于 2.6.32 或oprofile更旧,则可以使用。这两个程序都不需要您来检测您的程序(如gprof需要)。但是,为了正确获取调用图,perf您需要使用-fno-omit-frame-pointer. 例如:g++ -fno-omit-frame-pointer -O2 main.cpp。
您可以使用以下命令查看应用程序的“实时”分析perf top:
sudo perf top -p `pidof a.out` -K
或者,您可以记录正在运行的应用程序的性能数据,然后对其进行分析:
1) 记录性能数据:
perf record -p `pidof a.out`
或录制 10 秒:
perf record -p `pidof a.out` sleep 10
或用调用图记录 ()
perf record -g -p `pidof a.out` 
2) 分析记录的数据
perf report --stdio
perf report --stdio --sort=dso -g none
perf report --stdio -g none
perf report --stdio -g
或者您可以记录应用程序的性能数据并在此之后分析它们,只需以这种方式启动应用程序并等待它退出:
perf record ./a.out
这是分析测试程序的示例
测试程序在文件 main.cpp 中(我将把 main.cpp 放在消息的底部):
我是这样编译的:
g++ -m64 -fno-omit-frame-pointer -g main.cpp -L.  -ltcmalloc_minimal -o my_test
我使用libmalloc_minimial.so它,因为它是用编译的,-fno-omit-frame-pointer而 libc malloc 似乎是在没有此选项的情况下编译的。然后我运行我的测试程序
./my_test 100000000 
然后我记录一个正在运行的进程的性能数据:
perf record -g  -p `pidof my_test` -o ./my_test.perf.data sleep 30
然后我分析每个模块的负载:
性能报告 --stdio -g none --sort comm,dso -i ./my_test.perf.data
# Overhead  Command                 Shared Object
# ........  .......  ............................
#
    70.06%  my_test  my_test
    28.33%  my_test  libtcmalloc_minimal.so.0.1.0
     1.61%  my_test  [kernel.kallsyms]
然后分析每个函数的负载:
性能报告 --stdio -g none -i ./my_test.perf.data | C++过滤器
# Overhead  Command                 Shared Object                       Symbol
# ........  .......  ............................  ...........................
#
    29.30%  my_test  my_test                       [.] f2(long)
    29.14%  my_test  my_test                       [.] f1(long)
    15.17%  my_test  libtcmalloc_minimal.so.0.1.0  [.] operator new(unsigned long)
    13.16%  my_test  libtcmalloc_minimal.so.0.1.0  [.] operator delete(void*)
     9.44%  my_test  my_test                       [.] process_request(long)
     1.01%  my_test  my_test                       [.] operator delete(void*)@plt
     0.97%  my_test  my_test                       [.] operator new(unsigned long)@plt
     0.20%  my_test  my_test                       [.] main
     0.19%  my_test  [kernel.kallsyms]             [k] apic_timer_interrupt
     0.16%  my_test  [kernel.kallsyms]             [k] _spin_lock
     0.13%  my_test  [kernel.kallsyms]             [k] native_write_msr_safe
     and so on ...
然后分析调用链:
性能报告--stdio -g graph -i ./my_test.perf.data | C++过滤器
# Overhead  Command                 Shared Object                       Symbol
# ........  .......  ............................  ...........................
#
    29.30%  my_test  my_test                       [.] f2(long)
            |
            --- f2(long)
               |
                --29.01%-- process_request(long)
                          main
                          __libc_start_main
    29.14%  my_test  my_test                       [.] f1(long)
            |
            --- f1(long)
               |
               |--15.05%-- process_request(long)
               |          main
               |          __libc_start_main
               |
                --13.79%-- f2(long)
                          process_request(long)
                          main
                          __libc_start_main
    15.17%  my_test  libtcmalloc_minimal.so.0.1.0  [.] operator new(unsigned long)
            |
            --- operator new(unsigned long)
               |
               |--11.44%-- f1(long)
               |          |
               |          |--5.75%-- process_request(long)
               |          |          main
               |          |          __libc_start_main
               |          |
               |           --5.69%-- f2(long)
               |                     process_request(long)
               |                     main
               |                     __libc_start_main
               |
                --3.01%-- process_request(long)
                          main
                          __libc_start_main
    13.16%  my_test  libtcmalloc_minimal.so.0.1.0  [.] operator delete(void*)
            |
            --- operator delete(void*)
               |
               |--9.13%-- f1(long)
               |          |
               |          |--4.63%-- f2(long)
               |          |          process_request(long)
               |          |          main
               |          |          __libc_start_main
               |          |
               |           --4.51%-- process_request(long)
               |                     main
               |                     __libc_start_main
               |
               |--3.05%-- process_request(long)
               |          main
               |          __libc_start_main
               |
                --0.80%-- f2(long)
                          process_request(long)
                          main
                          __libc_start_main
     9.44%  my_test  my_test                       [.] process_request(long)
            |
            --- process_request(long)
               |
                --9.39%-- main
                          __libc_start_main
     1.01%  my_test  my_test                       [.] operator delete(void*)@plt
            |
            --- operator delete(void*)@plt
     0.97%  my_test  my_test                       [.] operator new(unsigned long)@plt
            |
            --- operator new(unsigned long)@plt
     0.20%  my_test  my_test                       [.] main
     0.19%  my_test  [kernel.kallsyms]             [k] apic_timer_interrupt
     0.16%  my_test  [kernel.kallsyms]             [k] _spin_lock
     and so on ...
所以在这一点上你知道你的程序在哪里花费时间。
这是用于测试的 main.cpp:
#include <stdio.h>
#include <stdlib.h>
#include <time.h>
time_t f1(time_t time_value)
{
  for (int j =0; j < 10; ++j) {
    ++time_value;
    if (j%5 == 0) {
      double *p = new double;
      delete p;
    }
  }
  return time_value;
}
time_t f2(time_t time_value)
{
  for (int j =0; j < 40; ++j) {
    ++time_value;
  }
  time_value=f1(time_value);
  return time_value;
}
time_t process_request(time_t time_value)
{
  for (int j =0; j < 10; ++j) {
    int *p = new int;
    delete p;
    for (int m =0; m < 10; ++m) {
      ++time_value;
    }
  }
  for (int i =0; i < 10; ++i) {
    time_value=f1(time_value);
    time_value=f2(time_value);
  }
  return time_value;
}
int main(int argc, char* argv2[])
{
  int number_loops = argc > 1 ? atoi(argv2[1]) : 1;
  time_t time_value = time(0);
  printf("number loops %d\n", number_loops);
  printf("time_value: %d\n", time_value );
  for (int i =0; i < number_loops; ++i) {
    time_value = process_request(time_value);
  }
  printf("time_value: %ld\n", time_value );
  return 0;
}
| 归档时间: | 
 | 
| 查看次数: | 73741 次 | 
| 最近记录: |