gprof ne donne aucune sortie

Question

J'essaie d'utiliser gprof pour profiler un code numérique que je développe, mais gprof semble ne pas pouvoir collecter des données de mon programme. Voici ma ligne de commande:

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

Le fichier gmon.out est créé, mais il semble ne pas avoir de données. Quand je lance

gprof -b fftw_test gmon.out > gprof.out 

Tout ce que je reçois est

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 

Toute autre idée?

Le code fait beaucoup de choses, il n'appelle pas simplement les routines FFTW. Il a des fonctions qui calculent certains coefficients complexes, fonctions qui multiplient les données d'entrée par ces coefficients, et ainsi de suite.

Edit .: Y compris l'exemple de code et les résultats.

#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; 
} 

lignes de commande:

$ 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 

Résultat:

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 

Et voilà.

Answer 1

gprof semble ne pas pouvoir collecter les données de mon programme. Voici ma ligne de commande:

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

Votre programme utilise la bibliothèque FFTW et se compose probablement presque uniquement des appels de bibliothèque FFTW. Quel est le temps de course? Votre programme peut être trop rapide pour être profilé avec gprof. Mise à jour La bibliothèque peut ne pas être vue par gprof car elle a été compilée sans le profilage gprof activé.

GNU gprof a deux parties. Tout d'abord, il appelle les appels de fonction dans les fichiers c/cpp qui ont été compilés avec l'option -pg (avec les appels de fonction mcount - https://en.wikipedia.org/wiki/Gprof) - pour obtenir des informations sur l'appelant/l'appelé. Deuxièmement, il relie la bibliothèque de profilage supplémentaire dans votre exécutable pour ajouter un échantillonnage périodique pour trouver quel code a été exécuté pour plus de temps. L'échantillonnage est fait avec profil (setitimer). Le profil Setitimer a une résolution limitée et ne peut pas résoudre les intervalles inférieurs à 10 ms ou 1 ms (100 ou 1000 échantillons par seconde).

Et dans votre exemple, la bibliothèque fftw a probablement été compilée sans instrumentation, donc aucun mcount ne l'appelle. Il peut encore être capturé en échantillonnant la partie, mais seulement pour le fil principal du programme (https://en.wikipedia.org/wiki/Gprof - "typiquement il ne profile que le fil principal de l'application").

perf profileur ont pas l'instrumentation avec mcount (déroulage il obtient appelé/appelant de la pile lors de l'enregistrement avec l'option -g), mais il a beaucoup de meilleures statistiques/variantes d'échantillonnage (il peut utiliser les compteurs de PMU du matériel), sans 100 ou 1000 Hz limite, et il prend en charge les threads (profils) correctement. Essayez perf record -F1000 ./fftw_test (avec fréquence d'échantillonnage de 1 kHz) et perf report ou perf report > report.txt.Il y a quelques GUI/HTML frontends à PERF aussi: https://github.com/KDAB/hotspothttps://github.com/jrfonseca/gprof2dot

Pour une meilleure setitimer check style profileur google-perftools https://github.com/gperftools/gperftools pour "CPU profileur".

======

Avec votre test, j'ai des résultats de gprof sur Debian 8.6 noyau Linux version 3.16.0-4-amd64 machine x86_64, g ++ (Debian 4.9.2-10), gprof est « GNU gprof (GNU Binutils pour 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 

Ainsi, gprof n'a pas pris des échantillons de temps dans ce 1 seconde exemple et avoir aucune information sur les appels dans les bibliothèques (ils ont été compilés sans -pg) . Après avoir ajouté quelques fonctions wrapper et d'interdire l'optimisation en ligne, j'ai des données de gprof, mais le temps de la bibliothèque n'a pas été représenté (il voit 0,72 secondes de 2 secondes d'exécution):

$ 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] 

Et perf voit toutes les parties:

$ 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