profiling - 如何使用谷歌性能工具

Question

我刚开始使用谷歌性能工具（google-perftools和libgoogle-perftools4ubuntu 中的包），我发誓我在谷歌上搜索了大约一天，但没有找到答案！问题是我没有通过 CPU 分析获得所有函数的结果。这是我的代码：

#include "gperftools/profiler.h"
#include <iostream>
#include <math.h>
using namespace std;
void bar()
{
        int a,b,c,d,j,k;
        a=0;
        int z=0;
        b = 1000;
        while(z < b)
        {
                while (a < b)
                {
                        d = sin(a);
                        c = cos(a);
                        j = tan(a);
                        k = tan(a);
                        k = d * c + j *k;
                        a++;
                }
                a = 0;
                z++;
        }
}
void foo()
{
        cout << "hey " << endl;
}

int main()
{
        ProfilerStart("/home/mohammad/gperf/dump.txt");

        int a = 1000;
        while(a--){foo();}
        bar();
        ProfilerFlush();
        ProfilerStop();
}

编译为g++ test.cc -lprofiler -o a.out

这就是我运行代码的方式：

CPUPROFILE=dump.txt ./a.out

我也试过这个：

CPUPROFILE_FREQUENCY=10000 LD_PRELOAD=/usr/local/lib/libprofiler.so.0.3.0 CPUPROFILE=dump.txt ./a.out

这就是我从中得到的google-pprof --text a.out dump.txt：

Using local file ./a.out.
Using local file ./dump.txt.
Total: 22 samples
8  36.4%  36.4%        8  36.4% 00d8cb04
6  27.3%  63.6%        6  27.3% bar
3  13.6%  77.3%        3  13.6% __cos (inline)
2   9.1%  86.4%        2   9.1% 00d8cab4
1   4.5%  90.9%        1   4.5% 00d8cab6
1   4.5%  95.5%        1   4.5% 00d8cb06
1   4.5% 100.0%        1   4.5% __write_nocancel
0   0.0% 100.0%        3  13.6% __cos

但是没有关于 foo 函数的信息！

我的系统信息：ubuntu 12.04 g++ 4.6.3

就这样！

score 13 · Accepted Answer

TL;DR：foo是为了快速而小规模地获取分析事件，再运行 100 次。频率设置有错字，pprof不会比 CONFIG_HZ（通常为 250）更频繁地采样。最好切换到更现代的 Linuxperf分析器（其作者的教程，维基百科）。

长版：

你的foo函数太短太简单了——只需调用两个函数。用编译测试g++ test.cc -lprofiler -o test.s -S -g，过滤test.swithc++filt程序以使 c++ 名称可读：

foo():
.LFB972:
        .loc 1 27 0
        pushq   %rbp
        movq    %rsp, %rbp
        .loc 1 28 0
        movl    $.LC0, %esi
        movl    std::cout, %edi
        call    std::basic_ostream<char, std::char_traits<char> >& std::operator<< <std::char_traits<char> >(std::basic_ostream<char, std::char_traits<char> >&, char const*)
        movl    std::basic_ostream<char, std::char_traits<char> >& std::endl<char, std::char_traits<char> >(std::basic_ostream<char, std::char_traits<char> >&), %esi
        movq    %rax, %rdi
        call    std::basic_ostream<char, std::char_traits<char> >::operator<<(std::basic_ostream<char, std::char_traits<char> >& (*)(std::basic_ostream<char, std::char_traits<char> >&))
        .loc 1 29 0
        popq    %rbp
        ret
.LFE972:
        .size   foo(), .-foo()

因此，要在配置文件中看到它，您应该运行foo更多次，将int a = 1000;main 更改为更大的值，例如 10000 或更好的 100000（就像我在测试中所做的那样）。

您也可以修复不正确的“ CPUPROFILE_FREQUENC=10000”来更正CPUPROFILE_FREQUENCY（注意Y）。我应该说 10000 对 CPUPROFILE_FREQUENCY 的设置太高了，因为它通常每秒只能生成 1000 或 250 个事件，具体取决于内核配置CONFIG_HZ（大多数 3.x 内核有 250，检查grep CONFIG_HZ= /boot/config*）。pprof 中 CPUPROFILE_FREQUENCY 的默认设置为 100。

我在 Ubuntu 14.04 上使用 bash 脚本测试了 CPUPROFILE_FREQUENCY: 100000、10000、1000、250 的不同值

for a in 100000 100000 10000 10000 1000 1000 300 300 250 250; do 
   echo -n "$a "; 
   CPUPROFILE_FREQUENCY=$a CPUPROFILE=dump$a.txt ./test >/dev/null;
done

结果是相同的 120-140 个事件和每个 ./test 大约 0.5 秒的运行时间，因此来自 google-perftools 的 cpuprofiler 不能为单线程每秒执行比内核中设置的 CONFIG_HZ 更多的事件（我有 250 个）。

100000 PROFILE: interrupts/evictions/bytes = 124/1/6584
100000 PROFILE: interrupts/evictions/bytes = 134/0/7864
10000 PROFILE: interrupts/evictions/bytes = 125/0/7488
10000 PROFILE: interrupts/evictions/bytes = 123/0/6960
1000 PROFILE: interrupts/evictions/bytes = 134/0/6264
1000 PROFILE: interrupts/evictions/bytes = 125/2/7272
300 PROFILE: interrupts/evictions/bytes = 137/2/7984
300 PROFILE: interrupts/evictions/bytes = 126/0/7216
250 PROFILE: interrupts/evictions/bytes = 123/3/6680
250 PROFILE: interrupts/evictions/bytes = 137/2/7352

使用原始 a=1000foo并且 cout 的函数运行速度太快，无法在每次运行时获得任何分析事件（即使是 250 个事件/秒），因此您没有foo，也没有任何输入/输出函数。在少量运行中，__write_nocancel可能会得到采样事件，然后foo 和来自 libstdc++ 的 I/O 函数将被报告（不在最顶部的地方，所以使用or--text选项），自身事件计数为零，子事件非零数数：pprofgoogle-pprof

 ....
   1   0.9%  99.1%        1   0.9% __write_nocancel
 ....
   0   0.0% 100.0%        1   0.9% _IO_new_file_overflow
   0   0.0% 100.0%        1   0.9% _IO_new_file_write
   0   0.0% 100.0%        1   0.9% __GI__IO_putc
   0   0.0% 100.0%        1   0.9% foo
   0   0.0% 100.0%        1   0.9% new_do_write
   0   0.0% 100.0%        1   0.9% std::endl
   0   0.0% 100.0%        1   0.9% std::ostream::put

使用a=100000， foo 仍然太短太快无法获得自己的事件，但 I/O 函数有几个。这是我从长--text输出中提取的列表：

  34  24.6%  24.6%       34  24.6% __write_nocancel

   1   0.7%  95.7%       35  25.4% __GI__IO_fflush
   1   0.7%  96.4%        1   0.7% __GI__IO_putc
   1   0.7%  97.8%        2   1.4% std::operator<< 
   1   0.7%  98.6%       36  26.1% std::ostream::flush
   1   0.7%  99.3%        2   1.4% std::ostream::put
   0   0.0% 100.0%       34  24.6% _IO_new_file_sync
   0   0.0% 100.0%       34  24.6% _IO_new_file_write
   0   0.0% 100.0%       40  29.0% foo

   0   0.0% 100.0%       34  24.6% new_do_write

   0   0.0% 100.0%        2   1.4% std::endl

只有通过读取调用链的能力才能看到具有零自身计数器pprof的函数（如果没有省略帧信息，它知道谁调用了获得样本的函数）。

我还可以推荐更现代、功能更强大（软件和硬件事件，频率高达 5 kHz 或更高；用户空间和内核分析）和更好支持的分析器，Linuxperf分析器（其作者的教程，维基百科）。

有来自perfwith的结果a=10000：

$ perf record  ./test3  >/dev/null
 ... skip some perf's spam about inaccessibility of kernel symbols 
 ... note the 3 kHz frequency here VVVV
Lowering default frequency rate to 3250. 
Please consider tweaking /proc/sys/kernel/perf_event_max_sample_rate.
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.078 MB perf.data (~3386 samples) ]

要从perf.data输出文件中查看文本报告，我将使用 less（因为perf report默认情况下会启动交互式配置文件浏览器）：

$ perf report |less
... skip some extra info about the machine, kernel, and perf starting command
# Samples: 1K of event 'cycles'
# Event count (approx.): 1155264208
# Overhead   Command   Shared Object          Symbol
    41.94%    test3  libm-2.19.so         [.] __tan_sse2                                                                                                                                                                    
    16.95%    test3  libm-2.19.so         [.] __sin_sse2    
    13.40%    test3  libm-2.19.so         [.] __cos_sse2                                                                                                                                                                    
     4.93%    test3  test3                [.] bar()                                                                                                                                                                         
     2.90%    test3  libc-2.19.so         [.] __GI___libc_write    
....
     0.20%    test3  test3                [.] foo()

或perf report -n | less查看原始事件（样本）计数器：

# Overhead       Samples  Command        Shared Object 
    41.94%           663    test3  libm-2.19.so         [.] __tan_sse2                                                                                                                                                                    
    16.95%           268    test3  libm-2.19.so         [.] __sin_sse2   
    13.40%           212    test3  libm-2.19.so         [.] __cos_sse2                                                                                                                                                                    
     4.93%            78    test3  test3                [.] bar()                                                                                                                                                                         
     2.90%            62    test3  libc-2.19.so         [.] __GI___libc_write     
 ....
     0.20%             4    test3  test3                [.] foo()

score 0 · Accepted Answer

尝试将 LD_PRELOAD 设置为

LD_PRELOAD=/usr/local/lib/libprofiler.so

传递不以后缀 .so 结尾的共享库时似乎存在问题。

profiling - 如何使用谷歌性能工具

2 回答 2

Related

Reference