【问题标题】:gprof gives no outputgprof 没有输出
【发布时间】:2018-03-19 13:41:11
【问题描述】:

我正在尝试使用 gprof 来分析我正在开发的一些数字代码,但 gprof 似乎无法从我的程序中收集数据。这是我的命令行:

g++ -Wall -O3 -g -pg -o fftw_test fftw_test.cpp -lfftw3 -lfftw3_threads -lm && ./fftw_test

gmon.out 文件已创建,但似乎没有数据。当我跑步时

gprof -b fftw_test gmon.out > gprof.out

我得到的只是

Flat profile:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total           
 time   seconds   seconds    calls  Ts/call  Ts/call  name    


                        Call graph


granularity: each sample hit covers 2 byte(s) no time propagated

index % time    self  children    called     name


Index by function name

有什么见解吗?

代码做了很多事情,它不只是简单地调用 FFTW 例程。它具有计算某些复数系数的函数、将输入数据乘以这些系数的函数等等。

编辑。:包括示例代码和结果。

#include <cstdlib>
#include <ctime>

int main()
{
   std::srand( std::time( 0 ) );

   double sum = 0.0;

   for ( int i = 0; i < RAND_MAX; ++i )
      sum += std::rand() / ( double ) RAND_MAX;

   std::cout << sum << '\n';

   return 0;
}

命令行:

$ g++ -Wall -O3 -g -pg -o gprof_test gprof_test.cpp && ./gprof_test
1.07374e+09
$ gprof -b gprof_test gmon.out > gprof.out
$ cat gprof.out

结果:

Flat profile:

Each sample counts as 0.01 seconds.
 no time accumulated

  %   cumulative   self              self     total           
 time   seconds   seconds    calls  Ts/call  Ts/call  name    


                        Call graph


granularity: each sample hit covers 2 byte(s) no time propagated

index % time    self  children    called     name


Index by function name

就是这样。

【问题讨论】:

  • 没有一次互动?好吧,我已经尝试过用于 Linux 的 perf 工具,它们似乎做得很好,但解释输出并不是一件简单的事情。我想出了自己的“穷人分析器”类来帮助我完成这项工作,并最终减少了相当多的计算时间。
  • 埃利亚斯,这很奇怪。 Mike stackoverflow.com/users/23771/mike-dunlavey 通常推荐他的未获得专利的统计证明的 5 个随机回溯 gdb 穷人分析几乎每个带有 [profiling] 标记的问题。您的 gprof 可能已损坏,操作系统是什么?您能否创建(或在 fftw lib 示例中找到)更简单的程序变体,该变体将填充一些数据并使用空 gprof 报告调用 fftw 以允许我们测试您的案例?
  • 我对一个简单的主程序也有同样的问题。 Archlinux 上的 gcc 7.2.0 gprof 2.29.1。这就像不兼容的东西。
  • @IsaacPascual,你能在网上发布有问题的程序示例吗?您的程序是使用 fttw 进行大量计算还是太短了?
  • 您的程序将在 std::rand 函数中花费 100% 减去 epsilon 的时间,该函数尚未使用 -g 编译,是吗?因此,您的代码中基本上会出现零样本。

标签: g++ profiling gprof


【解决方案1】:

如果您使用的是 gcc 6,您很可能会遇到 this 错误(请注意,该错误不是 Debian 特有的,而是取决于 gcc 的构建方式)。一种解决方法是简单地使用禁用与位置无关的代码生成的 `-no-pie' 选项进行编译。

如果您想了解更多关于 PIE 的信息,This 是一个好的开始。

【讨论】:

    【解决方案2】:

    gprof 似乎无法从我的程序中收集数据。这是我的命令行:

    g++ -Wall -O3 -g -pg -o fftw_test fftw_test.cpp -lfftw3 -lfftw3_threads -lm && ./fftw_test
    

    您的程序使用 fftw 库,并且可能几乎只包含 fftw 库调用。运行时间是多少?您的程序可能太快而无法使用 gprof 进行分析。 更新 gprof 可能看不到库,因为它是在未启用 gprof 分析的情况下编译的。

    GNU gprof 有两个部分。首先,它在使用 -pg 选项(使用 mcount 函数调用 - https://en.wikipedia.org/wiki/Gprof)编译的 c/cpp 文件中检测函数调用 - 以获取调用者/被调用者信息。其次,它将附加的分析库链接到您的可执行文件中,以添加定期采样以查找哪些代码执行了更多时间。使用 profil (setitimer) 进行采样。 Setitimer 分析的分辨率有限,无法解析小于 10 毫秒或 1 毫秒(每秒 100 或 1000 个样本)的间隔。

    在您的示例中,fftw 库可能是在没有检测的情况下编译的,因此其中没有 mcount 调用。它仍然可以通过采样部分捕获,但仅限于程序的主线程(https://en.wikipedia.org/wiki/Gprof - “通常它只分析应用程序的主线程”)。

    perf profiler 没有mcount 的检测(当使用-g 选项记录时,它从堆栈展开中获取被调用者/调用者),但它具有更好的统计/采样变量(它可以使用硬件 PMU 计数器),没有 100 或 1000 Hz 的限制,并且它正确支持(配置文件)线程。试试perf record -F1000 ./fftw_test(采样频率为 1 kHz)和perf reportperf report &gt; report.txt。也有一些 GUI/HTML 前端可以执行:https://github.com/KDAB/hotspothttps://github.com/jrfonseca/gprof2dot

    要获得更好的 setitimer 样式分析器,请检查 google-perftools https://github.com/gperftools/gperftools 中的“CPU PROFILER”。

    ======

    通过您的测试,我在 Debian 8.6 Linux 内核版本 3.16.0-4-amd64 x86_64 机器 g++ (Debian 4.9.2-10) 上获得了一些 gprof 结果,gprof 是“GNU gprof (GNU Binutils for Debian) 2.27”

    $ cat gprof_test.cpp
    #include <cstdlib>
    #include <ctime>
    #include <iostream>
    int main()
    {
       std::srand( std::time( 0 ) );
       double sum = 0.0;
       for ( int i = 0; i < 100000000; ++i )
          sum += std::rand() / ( double ) RAND_MAX;
       std::cout << sum << '\n';
       return 0;
    }
    $ g++ -Wall -O3 -g -pg -o gprof_test gprof_test.cpp && time ./gprof_test
    5.00069e+06
    real    0m0.992s
    $ gprof -b gprof_test gmon.out
    Flat profile:
    
    Each sample counts as 0.01 seconds.
     no time accumulated
    
      %   cumulative   self              self     total
     time   seconds   seconds    calls  Ts/call  Ts/call  name
      0.00      0.00     0.00        1     0.00     0.00  _GLOBAL__sub_I_main
    

    因此,gprof 在这个 1 秒的示例中没有捕获任何时间样本,并且没有关于调用库的信息(它们是在没有 -pg 的情况下编译的)。添加一些包装函数并禁止内联优化后,我从 gprof 获得了一些数据,但未计算库时间(它看到 0.72 秒的 2 秒运行时间):

    $ cat *cpp
    #include <cstdlib>
    #include <ctime>
    #include <iostream>
    
    int rand_wrapper1()
    {
      return std::rand();
    }
    int rand_scale1()
    {
      return rand_wrapper1() / ( double ) RAND_MAX;
    }
    int main()
    {
       std::srand( std::time( 0 ) );
       double sum = 0.0;
       for ( int i = 0; i < 100000000; ++i )
        sum+= rand_scale1();
    //      sum += std::rand() / ( double ) RAND_MAX;
       std::cout << sum << '\n';
       return 0;
    }
    $ g++ -Wall -O3 -fno-inline -g -pg -o gprof_test gprof_test.cpp && time ./gprof_test
    real    0m2.345s
    $ gprof -b gprof_test gmon.out
    Flat profile:
    
    Each sample counts as 0.01 seconds.
      %   cumulative   self              self     total
     time   seconds   seconds    calls  ns/call  ns/call  name
     80.02      0.57     0.57                             rand_scale1()
     19.29      0.71     0.14 100000000     1.37     1.37  rand_wrapper1()
      2.14      0.72     0.02                             frame_dummy
      0.00      0.72     0.00        1     0.00     0.00  _GLOBAL__sub_I__Z13rand_wrapper1v
      0.00      0.72     0.00        1     0.00     0.00  __static_initialization_and_destruction_0(int, int) [clone .constprop.0]
    
    
                            Call graph
    
    
    granularity: each sample hit covers 2 byte(s) for 1.39% of 0.72 seconds
    
    index % time    self  children    called     name
                                                     <spontaneous>
    [1]     97.9    0.57    0.14                 rand_scale1() [1]
                    0.14    0.00 100000000/100000000     rand_wrapper1() [2]
    -----------------------------------------------
                    0.14    0.00 100000000/100000000     rand_scale1() [1]
    [2]     19.0    0.14    0.00 100000000         rand_wrapper1() [2]
    

    而且 perf 可以看到所有部分:

    $ perf record ./gprof_test
    0
    [ perf record: Woken up 2 times to write data ]
    [ perf record: Captured and wrote 0.388 MB perf.data (~16954 samples) ]
    $ perf report |more   
    # Samples: 9K of event 'cycles'
    # Event count (approx.): 7373484231
    #
    # Overhead     Command      Shared Object                     Symbol
    # ........  ..........  .................  .........................
    #
        25.91%  gprof_test  gprof_test         [.] rand_scale1()
        21.65%  gprof_test  libc-2.19.so       [.] __mcount_internal
        13.88%  gprof_test  libc-2.19.so       [.] _mcount
        12.54%  gprof_test  gprof_test         [.] main
         9.35%  gprof_test  libc-2.19.so       [.] __random_r
         8.40%  gprof_test  libc-2.19.so       [.] __random
         3.97%  gprof_test  gprof_test         [.] rand_wrapper1()
         2.79%  gprof_test  libc-2.19.so       [.] rand
         1.41%  gprof_test  gprof_test         [.] mcount@plt
         0.03%  gprof_test  [kernel.kallsyms]  [k] memset
    

    【讨论】:

    • 不是这样的。我使用运行大循环的程序有相同的行为。
    • Elias,你能在网上发布有问题的程序示例(带有构建说明吗?)
    • 我已经编辑了这个问题。如果您有任何特定的代码示例希望我运行,我会很乐意这样做。
    • Elias,谢谢,我会在几天内测试代码。您能否也提供一些有关您的平台的提示,是 linux 还是 BSD 或 macos 和操作系统版本(例如 uname -a 输出删除了真实主机名)? g++ 和 gprof 版本?
    猜你喜欢
    • 2018-05-08
    • 1970-01-01
    • 2011-06-29
    • 2017-07-25
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    • 2010-10-03
    相关资源
    最近更新 更多