如何找到在Linux上运行的C++应用程序中运行缓慢的代码区域?
当前回答
还值得一提的是
HPC工具包(http://hpctoolkit.org/)-开源,适用于并行程序,并具有一个GUI,可通过该GUI以多种方式查看结果英特尔VTune(https://software.intel.com/en-us/vtune)-如果你有英特尔编译器,这很好τ(http://www.cs.uoregon.edu/research/tau/home.php)
我使用过HPCToolkit和VTune,它们在寻找帐篷中的长极点方面非常有效,并且不需要重新编译代码(除了必须在CMake中使用-g-O或RelWithDebInfo类型的内置来获得有意义的输出)。我听说TAU的能力类似。
其他回答
我会使用Valgrind和Callgrind作为我的仿形工具套件的基础。重要的是,Valgrind基本上是一台虚拟机:
(维基百科)Valgrind本质上是虚拟的机器使用准时制(JIT)编译技术,包括动态重新编译。没有来自的内容原始程序始终运行直接在主机处理器上。相反,Valgrind首先翻译将程序转换为临时的、更简单的形式称为中间表示(IR)是处理器中性的,转换后,工具(见下文)可以自由使用无论它想要什么样的转变在Valgrind翻译之前IR返回到机器代码中主机处理器运行它。
Callgrind是一个基于此的剖析器。主要的好处是,您不必运行应用程序数小时就能获得可靠的结果。因为Callgrind是一个非探测型剖面仪,所以即使一秒钟的运行也足以获得可靠的结果。
另一个基于Valgrind的工具是Massif。我使用它来分析堆内存使用情况。它工作得很好。它的作用是为您提供内存使用情况的快照--详细信息What hold What percentage of memory,and WHO has put it there。这些信息在应用程序运行的不同时间点可用。
如果没有一些选项,运行valgrind--tool=callgrind的答案并不完全。我们通常不希望在Valgrind下描述10分钟的缓慢启动时间,而希望在执行某些任务时描述我们的程序。
这就是我的建议。首先运行程序:
valgrind --tool=callgrind --dump-instr=yes -v --instr-atstart=no ./binary > tmp
现在,当它工作并且我们想要开始评测时,我们应该在另一个窗口中运行:
callgrind_control -i on
这将打开分析。若要关闭并停止整个任务,我们可以使用:
callgrind_control -k
现在,我们在当前目录中有一些名为callgrind.out.*的文件。要查看分析结果,请使用:
kcachegrind callgrind.out.*
我建议在下一个窗口中单击“Self”列标题,否则它会显示“main()”是最耗时的任务。“Self”显示每个函数本身花费的时间,而不是与依赖项一起花费的时间。
在工作中,我们有一个非常好的工具,它可以帮助我们监控我们想要的日程安排。这已多次有用。
它是用C++编写的,必须根据您的需要进行定制。不幸的是,我不能共享代码,只有概念。您使用一个包含时间戳和事件ID的“大”易失性缓冲区,可以在死后或停止日志系统后转储(例如,将其转储到文件中)。
您检索包含所有数据的所谓大缓冲区,一个小接口解析它并显示带有名称(up/down+value)的事件,就像示波器使用颜色(在.hpp文件中配置)所做的那样。
您可以自定义生成的事件数量,以仅关注您所需的内容。它帮助我们解决了调度问题,同时根据每秒记录的事件数量消耗了所需的CPU数量。
您需要3个文件:
toolname.hpp // interface
toolname.cpp // code
tool_events_id.hpp // Events ID
其概念是在tool_events_id.hpp中定义如下事件:
// EVENT_NAME ID BEGIN_END BG_COLOR NAME
#define SOCK_PDU_RECV_D 0x0301 //@D00301 BGEEAAAA # TX_PDU_Recv
#define SOCK_PDU_RECV_F 0x0302 //@F00301 BGEEAAAA # TX_PDU_Recv
您还可以在toolname.hpp中定义一些函数:
#define LOG_LEVEL_ERROR 0
#define LOG_LEVEL_WARN 1
// ...
void init(void);
void probe(id,payload);
// etc
代码中可以使用的任何位置:
toolname<LOG_LEVEL>::log(EVENT_NAME,VALUE);
probe函数使用几条装配线尽快检索时钟时间戳,然后在缓冲区中设置一个条目。我们还有一个原子增量来安全地找到存储日志事件的索引。当然,缓冲区是圆形的。
希望这个想法不会因为缺少示例代码而混淆。
对于单线程程序,您可以使用igprof,The Ignorminous Profiler:https://igprof.org/ .
这是一个采样分析器,沿着。。。长的Mike Dunlavey的回答,它将把结果包装在一个可浏览的调用堆栈树中,用每个函数(无论是累积的还是每个函数)花费的时间或内存进行注释。
C++评测技术综述:gprof vs valgrind vs perf vs gperftools
在这个答案中,我将使用几种不同的工具来分析一些非常简单的测试程序,以便具体比较这些工具的工作方式。
以下测试程序非常简单,可执行以下操作:
main调用fast和maybe_slow 3次,其中一个maybe_slow调用很慢maybe_slow的慢调用要长10倍,如果我们考虑到对子函数的调用是公共的,那么它在运行时占主导地位。理想情况下,分析工具将能够将我们指向特定的慢速调用。fast和maybe_slow调用都是公共的,这占了程序执行的大部分程序界面为:./main.out[n[seed]]程序总共执行O(n^2)个循环。seed只是在不影响运行时的情况下获得不同的输出。
主.c
#include <inttypes.h>
#include <stdio.h>
#include <stdlib.h>
uint64_t __attribute__ ((noinline)) common(uint64_t n, uint64_t seed) {
for (uint64_t i = 0; i < n; ++i) {
seed = (seed * seed) - (3 * seed) + 1;
}
return seed;
}
uint64_t __attribute__ ((noinline)) fast(uint64_t n, uint64_t seed) {
uint64_t max = (n / 10) + 1;
for (uint64_t i = 0; i < max; ++i) {
seed = common(n, (seed * seed) - (3 * seed) + 1);
}
return seed;
}
uint64_t __attribute__ ((noinline)) maybe_slow(uint64_t n, uint64_t seed, int is_slow) {
uint64_t max = n;
if (is_slow) {
max *= 10;
}
for (uint64_t i = 0; i < max; ++i) {
seed = common(n, (seed * seed) - (3 * seed) + 1);
}
return seed;
}
int main(int argc, char **argv) {
uint64_t n, seed;
if (argc > 1) {
n = strtoll(argv[1], NULL, 0);
} else {
n = 1;
}
if (argc > 2) {
seed = strtoll(argv[2], NULL, 0);
} else {
seed = 0;
}
seed += maybe_slow(n, seed, 0);
seed += fast(n, seed);
seed += maybe_slow(n, seed, 1);
seed += fast(n, seed);
seed += maybe_slow(n, seed, 0);
seed += fast(n, seed);
printf("%" PRIX64 "\n", seed);
return EXIT_SUCCESS;
}
gprof公司
gprof需要使用工具重新编译软件,并且它还使用采样方法和工具。因此,它在精度(采样并不总是完全准确的,可以跳过函数)和执行速度(插入和采样是相对快速的技术,不会大大降低执行速度)之间取得平衡。
gprof内置于GCC/binutils中,因此我们所要做的就是使用-pg选项进行编译以启用gprof。然后,我们使用大小CLI参数正常运行程序,该参数会产生几秒(10000)的合理运行时间:
gcc -pg -ggdb3 -O3 -std=c99 -Wall -Wextra -pedantic -o main.out main.c
time ./main.out 10000
出于教育原因,我们还将在未启用优化的情况下运行。请注意,这在实践中是无用的,因为您通常只关心优化优化程序的性能:
gcc -pg -ggdb3 -O0 -std=c99 -Wall -Wextra -pedantic -o main.out main.c
./main.out 10000
首先,时间告诉我们,使用和不使用-pg的执行时间是相同的,这很好:没有减速!然而,我已经看到复杂软件的速度下降了2倍到3倍,如这张罚单所示。
因为我们是用-pg编译的,所以运行该程序会生成一个包含评测数据的文件gmon.out。
我们可以用gprof2dot以图形方式观察该文件,如以下问题所问:是否可以获得gprof结果的图形表示?
sudo apt install graphviz
python3 -m pip install --user gprof2dot
gprof main.out > main.gprof
gprof2dot < main.gprof | dot -Tsvg -o output.svg
在这里,gprof工具读取gmon.out跟踪信息,并在main.gprof中生成一个人类可读的报告,gprof2dot随后读取该报告以生成图形。
gprof2dot的来源位于:https://github.com/jrfonseca/gprof2dot
对于-O0运行,我们观察到以下情况:
对于-O3运行:
-O0输出非常不言自明。例如,它显示3个maybe_slow调用及其子调用占总运行时的97.56%,尽管在没有子调用的情况下执行maybe_slow本身占总执行时间的0.00%,即几乎所有在该函数中花费的时间都花在子调用上。
TODO:为什么-O3输出中缺少main,尽管我可以在GDB中的bt上看到它?GProf输出中缺少函数,我认为这是因为GProf除了编译的工具外,还基于采样,而且-O3 main太快,没有采样。
我选择SVG输出而不是PNG,因为SVG可以用Ctrl+F搜索,文件大小可以小10倍。此外,对于复杂的软件,生成的图像的宽度和高度可以是数万像素,而GNOME eog 3.28.1在这种情况下对于PNG是错误的,而SVG会被我的浏览器自动打开。gimp 2.8运行良好,另请参见:
https://askubuntu.com/questions/1112641/how-to-view-extremely-large-imageshttps://unix.stackexchange.com/questions/77968/viewing-large-image-on-linuxhttps://superuser.com/questions/356038/viewer-for-huge-images-under-linux-100-mp-color-images
但即使如此,您仍将拖动图像以找到所需的内容,例如,此图像来自取自此票据的“真实”软件示例:
你能很容易地找到最关键的调用堆栈吗?我肯定可能有更好的圆点选项,但我现在不想去那里。我们真正需要的是一个合适的专用观众,但我还没有找到:
在kcachegrind中查看gprof输出哪个是KProf的最佳替代品?
然而,您可以使用颜色映射来稍微缓解这些问题。例如,在前一张巨大的图片上,我终于找到了左边的关键路径,我做出了一个绝妙的推论,即绿色在红色之后,最后是越来越深的蓝色。
或者,我们也可以观察gprof内置binutils工具的文本输出,我们之前保存在:
cat main.gprof
默认情况下,这会产生一个非常详细的输出,解释输出数据的含义。既然我不能解释得比这更好,我就让你自己读。
一旦您了解了数据输出格式,就可以使用-b选项减少详细信息,只显示数据,而无需使用教程:
gprof -b main.out
在我们的示例中,输出为-O0:
Flat profile:
Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls s/call s/call name
100.35 3.67 3.67 123003 0.00 0.00 common
0.00 3.67 0.00 3 0.00 0.03 fast
0.00 3.67 0.00 3 0.00 1.19 maybe_slow
Call graph
granularity: each sample hit covers 2 byte(s) for 0.27% of 3.67 seconds
index % time self children called name
0.09 0.00 3003/123003 fast [4]
3.58 0.00 120000/123003 maybe_slow [3]
[1] 100.0 3.67 0.00 123003 common [1]
-----------------------------------------------
<spontaneous>
[2] 100.0 0.00 3.67 main [2]
0.00 3.58 3/3 maybe_slow [3]
0.00 0.09 3/3 fast [4]
-----------------------------------------------
0.00 3.58 3/3 main [2]
[3] 97.6 0.00 3.58 3 maybe_slow [3]
3.58 0.00 120000/123003 common [1]
-----------------------------------------------
0.00 0.09 3/3 main [2]
[4] 2.4 0.00 0.09 3 fast [4]
0.09 0.00 3003/123003 common [1]
-----------------------------------------------
Index by function name
[1] common [4] fast [3] maybe_slow
对于-O3:
Flat profile:
Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls us/call us/call name
100.52 1.84 1.84 123003 14.96 14.96 common
Call graph
granularity: each sample hit covers 2 byte(s) for 0.54% of 1.84 seconds
index % time self children called name
0.04 0.00 3003/123003 fast [3]
1.79 0.00 120000/123003 maybe_slow [2]
[1] 100.0 1.84 0.00 123003 common [1]
-----------------------------------------------
<spontaneous>
[2] 97.6 0.00 1.79 maybe_slow [2]
1.79 0.00 120000/123003 common [1]
-----------------------------------------------
<spontaneous>
[3] 2.4 0.00 0.04 fast [3]
0.04 0.00 3003/123003 common [1]
-----------------------------------------------
Index by function name
[1] common
作为每个部分的快速总结,例如:
0.00 3.58 3/3 main [2]
[3] 97.6 0.00 3.58 3 maybe_slow [3]
3.58 0.00 120000/123003 common [1]
以左缩进的函数为中心(maybe_flow)。[3] 是该函数的ID。函数上方是其调用者,下方是被调用者。
对于-O3,请参见这里的图形输出,可能是因为slow和fast没有已知的父级,这就是文档中所说的<自发性>的意思。
我不确定是否有一种很好的方法可以用gprof进行逐行分析:“gprof”在特定代码行上花费的时间
valgrind callgrind公司
valgrind通过valgrind虚拟机运行程序。这使得分析非常准确,但也会导致程序的大幅减速。我之前也提到过kcachegrind:获取代码的图形函数调用图的工具
callgrind是valgrind分析代码的工具,kcachegrind是一个KDE程序,可以可视化cachegrind输出。
首先,我们必须删除-pg标志以返回正常编译,否则运行实际上会失败,评测计时器已过期,是的,这是很常见的,我这样做了,并且存在堆栈溢出问题。
因此,我们编译并运行为:
sudo apt install kcachegrind valgrind
gcc -ggdb3 -O3 -std=c99 -Wall -Wextra -pedantic -o main.out main.c
time valgrind --tool=callgrind valgrind --dump-instr=yes \
--collect-jumps=yes ./main.out 10000
我启用--dump instr=yes--collect jumps=yes,因为这也会转储信息,使我们能够以相对较小的额外开销成本查看每个装配线的性能细分。
不经意间,时间告诉我们程序执行需要29.5秒,所以在这个例子中,我们的速度减慢了大约15倍。显然,对于更大的工作负载来说,这种放缓将是一个严重的限制。在这里提到的“真实世界软件示例”中,我观察到了80倍的速度。
运行会生成一个名为callgrind.out.<pid>的配置文件数据文件,例如callgrind_out.8554。我们通过以下方式查看该文件:
kcachegrind callgrind.out.8554
其显示了包含与文本gprof输出类似的数据的GUI:
此外,如果我们转到右下角的“调用图”选项卡,我们会看到一个调用图,通过右键单击它可以导出该调用图,以获得以下带有不合理数量的白色边框的图像:-)
我认为fast没有显示在图表上,因为kcachegrind必须简化了可视化,因为调用占用的时间太少,这很可能是您在实际程序中想要的行为。右键单击菜单有一些设置来控制何时选择这样的节点,但我无法在快速尝试后显示如此短的调用。如果我单击左侧窗口上的fast,它会显示一个带有fast的调用图,所以堆栈实际上被捕获了。还没有人找到显示完整图形调用图的方法:让callgrind显示kcachegrind调用图中的所有函数调用
在复杂的C++软件上的TODO中,我看到了一些<cycle N>类型的条目,例如<cycle 11>,我期望的是函数名,这意味着什么?我注意到有一个“循环检测”按钮可以打开和关闭,但这意味着什么?
linux工具的性能
perf似乎只使用Linux内核采样机制。这使得设置非常简单,但也不完全准确。
sudo apt install linux-tools
time perf record -g ./main.out 10000
这增加了0.2秒的执行时间,因此我们在时间上很好,但在使用键盘右箭头扩展公共节点之后,我仍然看不到太多的兴趣:
Samples: 7K of event 'cycles:uppp', Event count (approx.): 6228527608
Children Self Command Shared Object Symbol
- 99.98% 99.88% main.out main.out [.] common
common
0.11% 0.11% main.out [kernel] [k] 0xffffffff8a6009e7
0.01% 0.01% main.out [kernel] [k] 0xffffffff8a600158
0.01% 0.00% main.out [unknown] [k] 0x0000000000000040
0.01% 0.00% main.out ld-2.27.so [.] _dl_sysdep_start
0.01% 0.00% main.out ld-2.27.so [.] dl_main
0.01% 0.00% main.out ld-2.27.so [.] mprotect
0.01% 0.00% main.out ld-2.27.so [.] _dl_map_object
0.01% 0.00% main.out ld-2.27.so [.] _xstat
0.00% 0.00% main.out ld-2.27.so [.] __GI___tunables_init
0.00% 0.00% main.out [unknown] [.] 0x2f3d4f4944555453
0.00% 0.00% main.out [unknown] [.] 0x00007fff3cfc57ac
0.00% 0.00% main.out ld-2.27.so [.] _start
因此,我尝试对-O0程序进行基准测试,看看它是否显示了任何内容,直到现在,最后,我才看到调用图:
Samples: 15K of event 'cycles:uppp', Event count (approx.): 12438962281
Children Self Command Shared Object Symbol
+ 99.99% 0.00% main.out [unknown] [.] 0x04be258d4c544155
+ 99.99% 0.00% main.out libc-2.27.so [.] __libc_start_main
- 99.99% 0.00% main.out main.out [.] main
- main
- 97.54% maybe_slow
common
- 2.45% fast
common
+ 99.96% 99.85% main.out main.out [.] common
+ 97.54% 0.03% main.out main.out [.] maybe_slow
+ 2.45% 0.00% main.out main.out [.] fast
0.11% 0.11% main.out [kernel] [k] 0xffffffff8a6009e7
0.00% 0.00% main.out [unknown] [k] 0x0000000000000040
0.00% 0.00% main.out ld-2.27.so [.] _dl_sysdep_start
0.00% 0.00% main.out ld-2.27.so [.] dl_main
0.00% 0.00% main.out ld-2.27.so [.] _dl_lookup_symbol_x
0.00% 0.00% main.out [kernel] [k] 0xffffffff8a600158
0.00% 0.00% main.out ld-2.27.so [.] mmap64
0.00% 0.00% main.out ld-2.27.so [.] _dl_map_object
0.00% 0.00% main.out ld-2.27.so [.] __GI___tunables_init
0.00% 0.00% main.out [unknown] [.] 0x552e53555f6e653d
0.00% 0.00% main.out [unknown] [.] 0x00007ffe1cf20fdb
0.00% 0.00% main.out ld-2.27.so [.] _start
TODO:执行-O3时发生了什么?难道只是因为速度太快,没有得到任何样本吗?在执行时间较长的大型程序上,它与-O3配合使用是否良好?我错过了一些CLI选项吗?我找到了-F来控制以赫兹为单位的采样频率,但我将其设置为默认允许的最大值-F 39500(可以使用sudo增加),我仍然看不到清晰的调用。
perf的一个很酷的地方是Brendan Gregg的FlameGraph工具,它以非常整洁的方式显示调用堆栈计时,让您可以快速看到大型调用。该工具位于:https://github.com/brendangregg/FlameGraph在他的perf教程中也有提到:http://www.brendangregg.com/perf.html#FlameGraphs当我在没有sudo的情况下运行perf时,我得到了错误:没有找到堆栈计数,所以现在我将使用sudo执行:
git clone https://github.com/brendangregg/FlameGraph
sudo perf record -F 99 -g -o perf_with_stack.data ./main.out 10000
sudo perf script -i perf_with_stack.data | FlameGraph/stackcollapse-perf.pl | FlameGraph/flamegraph.pl > flamegraph.svg
但在这样一个简单的程序中,输出不太容易理解,因为我们不能很容易地在该图上看到既慢又快:
在一个更复杂的例子中,图表的含义变得清晰:
TODO在该示例中有一个[未知]函数的日志,这是为什么?
另一个值得使用的性能GUI界面包括:
Eclipse Trace Compass插件:https://www.eclipse.org/tracecompass/但这有一个缺点,即您必须首先将数据转换为公共跟踪格式,这可以通过perf数据来完成,即转换为ctf,但它需要在构建时启用/具有足够的perf new,这两种情况都不适用于Ubuntu 18.04中的perfhttps://github.com/KDAB/hotspot这样做的缺点是似乎没有Ubuntu软件包,构建它需要Qt 5.10,而Ubuntu 18.04的Qt 5.9。但David Faure在评论中提到,没有AppImage包,这可能是一种方便的使用方法。
gperftools软件
以前称为“谷歌性能工具”,来源:https://github.com/gperftools/gperftools基于样本。
首先安装gperftools:
sudo apt install google-perftools
然后,我们可以通过两种方式启用gperftools CPU分析器:在运行时或在构建时。
在运行时,我们必须传递设置LD_PRELOAD以指向libprofiler.so,您可以通过查找libprofiler.so来找到它,例如在我的系统上:
gcc -ggdb3 -O3 -std=c99 -Wall -Wextra -pedantic -o main.out main.c
LD_PRELOAD=/usr/lib/x86_64-linux-gnu/libprofiler.so \
CPUPROFILE=prof.out ./main.out 10000
或者,我们可以在链接时构建库,在运行时分配传递LD_PRELOAD:
gcc -Wl,--no-as-needed,-lprofiler,--as-needed -ggdb3 -O3 -std=c99 -Wall -Wextra -pedantic -o main.out main.c
CPUPROFILE=prof.out ./main.out 10000
另请参见:gperftools-配置文件未转储
到目前为止,查看这些数据的最佳方法是使pprof输出与kcachegrind作为输入的格式相同(是的,Valgrind项目查看器工具),并使用kcachegrind来查看:
google-pprof --callgrind main.out prof.out > callgrind.out
kcachegrind callgrind.out
使用这些方法之一运行后,我们将得到一个prof.out配置文件数据文件作为输出。我们可以通过以下方式以图形方式将该文件视为SVG:
google-pprof --web main.out prof.out
与其他工具一样,它给出了一个熟悉的调用图,但使用了笨拙的样本数单位而不是秒。
或者,我们也可以通过以下方式获取一些文本数据:
google-pprof --text main.out prof.out
其给出:
Using local file main.out.
Using local file prof.out.
Total: 187 samples
187 100.0% 100.0% 187 100.0% common
0 0.0% 100.0% 187 100.0% __libc_start_main
0 0.0% 100.0% 187 100.0% _start
0 0.0% 100.0% 4 2.1% fast
0 0.0% 100.0% 187 100.0% main
0 0.0% 100.0% 183 97.9% maybe_slow
另请参阅:如何使用google perf工具
使用原始perf_event_open系统调用检测代码
我认为这是perf使用的同一个底层子系统,但您当然可以通过在编译时使用感兴趣的事件显式地检测程序来获得更大的控制。
对大多数人来说,这可能太过于硬核了,但这是一种乐趣。最小可运行示例:快速计算C程序中执行的指令数
英特尔VTune
https://en.wikipedia.org/wiki/VTune
这似乎是封闭源代码,仅适用于x86,但从我所听到的情况来看,这可能是令人惊讶的。我不知道使用它有多免费,但它似乎可以免费下载。TODO评估。
在Ubuntu 18.04、gprof2dot 2019.11.30、valgrind 3.13.0、perf 4.15.18、Linux内核4.15.0、FLameGraph 1a0dc6985aad06e76857cf2a354bd5ba0c9ce96b、gperftools2.5-2中测试。
推荐文章
- 在JS的Chrome CPU配置文件中,'self'和'total'之间的差异
- 在tmux中保持窗口名称固定
- 是否需要手动关闭ifstream?
- 如何生成一个核心转储在Linux上的分段错误?
- 在Python中如何在Linux和Windows中使用“/”(目录分隔符)?
- 为什么函数指针定义可以使用任意数量的&号或星号* ?
- 为什么我必须通过this指针访问模板基类成员?
- 什么是可重入函数?
- 什么是栈展开?
- 如何在内存中获取对象大小?
- 我如何读整个文件到性病::字符串在c++ ?
- 如何在c++中使用枚举
- 为什么512x512矩阵的转置比513x513矩阵的转置慢得多?
- 通过引用传递数组
- 为什么非const引用不能绑定到临时对象?