【问题标题】:How to use google perf tools如何使用谷歌性能工具
【发布时间】:2012-06-08 02:42:59
【问题描述】:

我刚开始使用谷歌性能工具(google-perftoolslibgoogle-perftools4 包在 ubuntu 中),我发誓我在谷歌上搜索了大约一天但没有找到答案! 问题是我没有通过 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

就是这样!

【问题讨论】:

  • 您说您尝试了“CPUPROFILE_FREQUENC=10000”,但缺少一个 Y,所以如果实际(并且被忽略)那么您可能没有足够的样本来显示微小的 foo。
  • 您查看的是 CPU 时间,而不是挂钟时间。 foo 使用的 CPU 时间量几乎为零。它所做的只是调用执行 I/O 的库函数,并且 CPU 样本不会在 I/O 期间发生。

标签: profiling gperftools


【解决方案1】:

尝试将 LD_PRELOAD 设置为 just

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

looks like there are problems 在传递不以后缀 .so 结尾的共享库时。

【讨论】:

    【解决方案2】:

    TL;DR: foo 是为了获得分析事件又快又小,再运行 100 次。频率设置有错字,pprof 的采样频率不会超过 CONFIG_HZ(通常为 250)。最好切换到更现代的 Linux perf profiler (tutorial from its authors, wikipedia)。

    长版:

    您的 foo 函数太短太简单了 - 只需调用两个函数。使用g++ test.cc -lprofiler -o test.s -S -g 编译测试,使用c++filt 程序过滤test.s 以使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; 更改为更大的值,例如 10000 或更好的 100000(就像我在测试中所做的那样)。

    您还可以修复不正确的“CPUPROFILE_FREQUENC=10000”以更正CPUPROFILE_FREQUENCY(注意Y)。我应该说 10000 对于 CPUPROFILE_FREQUENCY 设置太高了,因为根据内核配置CONFIG_HZ(大多数 3.x 内核有 250,检查grep CONFIG_HZ= /boot/config*),它通常每秒只能生成 1000 或 250 个事件。 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=1000 foo 和 cout 的函数运行速度太快,无法在每次运行中获取任何分析事件(即使是 250 个事件/秒),因此您没有 foo,也没有任何输入/输出函数.在少量运行中,__write_nocancel 可能会发生采样事件,然后将报告 foo 和 libstdc++ 形式的 I/O 函数(不在最顶部的位置,因此请使用 pprof 或 @ 的 --text 选项987654348@),自身事件计数为零,子事件计数非零:

     ....
       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 频率或更高;用户空间和内核分析)和更好支持的分析器,Linux perf 分析器 (tutorial from its authorswikipedia)。

    有来自perfa=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 输出文件的文本报告,我将使用较少(因为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()                                                                                                                                                                         
    

    【讨论】:

      猜你喜欢
      • 1970-01-01
      • 1970-01-01
      • 1970-01-01
      • 1970-01-01
      • 1970-01-01
      • 2010-11-03
      • 2017-11-10
      • 1970-01-01
      • 1970-01-01
      相关资源
      最近更新 更多