Comment puis-je profiler du code C ++ fonctionnant sous Linux?

J'ai une application C ++, fonctionnant sous Linux, que je suis en train d'optimiser. Comment identifier les zones de mon code qui s'exécutent lentement?

Si votre objectif est d'utiliser un profileur, utilisez l'un des suggestions.

Cependant, si vous êtes pressé et que vous pouvez interrompre manuellement votre programme sous le débogueur pendant qu'il est subjectivement lent, il existe un moyen simple de trouver des problèmes de performances.

Arrêtez-le plusieurs fois et regardez à chaque fois la pile des appels. S'il y a du code qui fait perdre un certain pourcentage du temps, 20% ou 50% ou autre, c'est la probabilité que vous l'attrapiez dans la loi sur chaque échantillon. Donc, c'est à peu près le pourcentage d'échantillons sur lesquels vous le verrez. Aucune conjecture éclairée n'est requise. Si vous avez une idée du problème, cela le prouvera ou le réfutera.

Vous pouvez rencontrer plusieurs problèmes de performances de tailles différentes. Si vous nettoyez l'un d'eux, les autres prendront un pourcentage plus élevé et seront plus faciles à repérer lors des passes suivantes. Cet effet d'agrandissement , lorsqu'il est aggravé par plusieurs problèmes, peut conduire à des facteurs d'accélération vraiment massifs.

Mise en garde : les programmeurs ont tendance à être sceptiques à l'égard de cette technique, sauf s'ils l'ont utilisée eux-mêmes. Ils diront que les profileurs vous donnent ces informations, mais cela n'est vrai que s'ils échantillonnent la pile d'appels entière, puis vous permettent d'examiner un ensemble aléatoire d'échantillons. (Les résumés sont là où les informations sont perdues.) Les graphiques d'appel ne vous donnent pas les mêmes informations, car

1. Ils ne résument pas au niveau de l'instruction, et
2. Ils donnent des résumés déroutants en présence de récursivité.

Ils diront également que cela ne fonctionne que sur les programmes de jouets, alors qu'en réalité cela fonctionne sur n'importe quel programme, et cela semble mieux fonctionner sur des programmes plus importants, car ils ont tendance à avoir plus de problèmes à trouver. Ils diront qu'il trouve parfois des choses qui ne sont pas des problèmes, mais cela n'est vrai que si vous voyez quelque chose une fois . Si vous voyez un problème sur plus d'un échantillon, c'est réel.

PS Cela peut également être fait sur des programmes multi-threads s'il existe un moyen de collecter des échantillons de pile d'appels du pool de threads à un moment donné, comme c'est le cas en Java.

PPS En règle générale, plus vous avez de couches d'abstraction dans votre logiciel, plus vous avez de chances de trouver que c'est la cause de problèmes de performances (et la possibilité d'obtenir une accélération).

Ajouté : Ce n'est peut-être pas évident, mais la technique d'échantillonnage de pile fonctionne aussi bien en présence de récursivité. La raison en est que le temps qui serait économisé par la suppression d'une instruction est approximé par la fraction d'échantillons qui la contient, quel que soit le nombre de fois où cela peut se produire dans un échantillon.

Une autre objection que j'entends souvent est: " Cela arrêtera quelque part au hasard, et le vrai problème manquera ". Cela vient d'avoir un concept préalable de ce qu'est le vrai problème. Une propriété clé des problèmes de performances est qu'ils défient les attentes. L'échantillonnage vous indique que quelque chose est un problème, et votre première réaction est l'incrédulité. C'est naturel, mais vous pouvez être sûr que s'il trouve un problème, c'est réel, et vice-versa.

Ajouté : Permettez-moi de faire une explication bayésienne de la façon dont cela fonctionne. Supposons qu'il y ait une instruction I(appel ou autre) qui se trouve sur la pile d'appels une fraction fdu temps (et coûte donc beaucoup). Par souci de simplicité, supposons que nous ne sachions pas ce que fc'est, mais supposons que ce soit 0,1, 0,2, 0,3, ... 0,9, 1,0, et la probabilité antérieure de chacune de ces possibilités est de 0,1, donc tous ces coûts sont également probables a priori.

Supposons ensuite que nous prenons seulement 2 échantillons de pile et que nous voyons des instructions Isur les deux échantillons, une observation désignée o=2/2. Cela nous donne de nouvelles estimations de la fréquence fde I, selon ceci:

Prior                                    
P(f=x) x  P(o=2/2|f=x) P(o=2/2&&f=x)  P(o=2/2&&f >= x)  P(f >= x | o=2/2)

0.1    1     1             0.1          0.1            0.25974026
0.1    0.9   0.81          0.081        0.181          0.47012987
0.1    0.8   0.64          0.064        0.245          0.636363636
0.1    0.7   0.49          0.049        0.294          0.763636364
0.1    0.6   0.36          0.036        0.33           0.857142857
0.1    0.5   0.25          0.025        0.355          0.922077922
0.1    0.4   0.16          0.016        0.371          0.963636364
0.1    0.3   0.09          0.009        0.38           0.987012987
0.1    0.2   0.04          0.004        0.384          0.997402597
0.1    0.1   0.01          0.001        0.385          1

                  P(o=2/2) 0.385                

La dernière colonne indique que, par exemple, la probabilité que f> = 0,5 soit de 92%, en hausse par rapport à l'hypothèse précédente de 60%.

Supposons que les hypothèses antérieures soient différentes. Supposons que nous P(f=0.1)supposions est .991 (presque certain), et toutes les autres possibilités sont presque impossibles (0.001). En d'autres termes, notre certitude préalable est que Ic'est bon marché. On obtient alors:

Prior                                    
P(f=x) x  P(o=2/2|f=x) P(o=2/2&& f=x)  P(o=2/2&&f >= x)  P(f >= x | o=2/2)

0.001  1    1              0.001        0.001          0.072727273
0.001  0.9  0.81           0.00081      0.00181        0.131636364
0.001  0.8  0.64           0.00064      0.00245        0.178181818
0.001  0.7  0.49           0.00049      0.00294        0.213818182
0.001  0.6  0.36           0.00036      0.0033         0.24
0.001  0.5  0.25           0.00025      0.00355        0.258181818
0.001  0.4  0.16           0.00016      0.00371        0.269818182
0.001  0.3  0.09           0.00009      0.0038         0.276363636
0.001  0.2  0.04           0.00004      0.00384        0.279272727
0.991  0.1  0.01           0.00991      0.01375        1

                  P(o=2/2) 0.01375                

Maintenant, il P(f >= 0.5)est de 26%, en hausse par rapport à l'hypothèse précédente de 0,6%. Bayes nous permet donc de mettre à jour notre estimation du coût probable de I. Si la quantité de données est petite, elle ne nous dit pas exactement quel est le coût, mais seulement qu'elle est suffisamment grande pour être corrigée.

Une autre façon de voir les choses s'appelle la règle de succession . Si vous lancez une pièce 2 fois et qu'elle revient en tête les deux fois, qu'est-ce que cela vous dit sur la pondération probable de la pièce? La façon respectée de répondre est de dire que c'est une distribution Beta, avec une valeur moyenne (number of hits + 1) / (number of tries + 2) = (2+1)/(2+2) = 75%.

(La clé est que nous voyons Iplus d'une fois. Si nous ne le voyons qu'une seule fois, cela ne nous dit pas grand-chose sauf que f> 0.)

Ainsi, même un très petit nombre d'échantillons peut nous en dire beaucoup sur le coût des instructions qu'il voit. (Et il les voir avec une fréquence Si, en moyenne, proportionnelle à leur coût. nÉchantillons sont prélevés, et fest le coût, puis Iapparaîtra sur des nf+/-sqrt(nf(1-f))échantillons. Exemple, n=10, f=0.3, c'est - 3+/-1.4échantillons.)

Ajouté : Pour donner une idée intuitive de la différence entre la mesure et l'échantillonnage aléatoire de la pile:
il existe maintenant des profileurs qui échantillonnent la pile, même à l'heure de l'horloge murale, mais ce qui en ressort est les mesures (ou chemin chaud, ou point chaud, à partir desquelles un "goulot d'étranglement" peut facilement se cacher). Ce qu'ils ne vous montrent pas (et ils pourraient facilement), ce sont les échantillons eux-mêmes. Et si votre objectif est de trouver le goulot d'étranglement, le nombre d'entre eux que vous devez voir est, en moyenne , 2 divisé par la fraction de temps qu'il faut. Donc, si cela prend 30% du temps, 2 / .3 = 6,7 échantillons, en moyenne, le montreront, et la probabilité que 20 échantillons le montrent est de 99,2%.

Voici une illustration immédiate de la différence entre l'examen des mesures et l'examen des échantillons de pile. Le goulot d'étranglement pourrait être un gros blob comme celui-ci, ou de nombreux petits, cela ne fait aucune différence.

La mesure est horizontale; il vous indique combien de temps les routines spécifiques prennent. L'échantillonnage est vertical. S'il existe un moyen d'éviter ce que fait l'ensemble du programme à ce moment, et si vous le voyez sur un deuxième échantillon , vous avez trouvé le goulot d'étranglement. C'est ce qui fait la différence - voir toute la raison du temps passé, pas seulement combien.

Vous pouvez utiliser Valgrind avec les options suivantes

valgrind --tool=callgrind ./(Your binary)

Il générera un fichier appelé callgrind.out.x. Vous pouvez ensuite utiliser l' kcachegrindoutil pour lire ce fichier. Il vous donnera une analyse graphique des choses avec des résultats comme quelles lignes coûtent combien.

Je suppose que vous utilisez GCC. La solution standard serait de profiler avec gprof .

Assurez-vous d'ajouter -pgà la compilation avant le profilage:

cc -o myprog myprog.c utils.c -g -pg

Je ne l'ai pas encore essayé mais j'ai entendu de bonnes choses sur google-perftools . Cela vaut vraiment la peine d'essayer.

Question connexe ici .

Quelques autres mots à la mode si gprofne font pas le travail pour vous: Valgrind , Intel VTune , Sun DTrace .

Les noyaux plus récents (par exemple les derniers noyaux Ubuntu) sont livrés avec les nouveaux outils 'perf' ( apt-get install linux-tools) AKA perf_events .

Ceux-ci sont livrés avec des profileurs d'échantillonnage classiques ( page de manuel ) ainsi que le chronogramme impressionnant !

L'important est que ces outils peuvent être le profilage du système et pas seulement le profilage des processus - ils peuvent montrer l'interaction entre les threads, les processus et le noyau et vous permettent de comprendre la planification et les dépendances d'E / S entre les processus.

J'utiliserais Valgrind et Callgrind comme base pour ma suite d'outils de profilage. Ce qui est important à savoir, c'est que Valgrind est fondamentalement une machine virtuelle:

(wikipedia) Valgrind est essentiellement une machine virtuelle utilisant des techniques de compilation juste à temps (JIT), y compris la recompilation dynamique. Rien du programme d'origine n'est jamais exécuté directement sur le processeur hôte. Au lieu de cela, Valgrind traduit d'abord le programme sous une forme temporaire et plus simple appelée représentation intermédiaire (IR), qui est une forme SSA indépendante du processeur. Après la conversion, un outil (voir ci-dessous) est libre de faire toutes les transformations qu'il souhaite sur l'IR, avant que Valgrind ne convertisse l'IR en code machine et laisse le processeur hôte l'exécuter.

Callgrind est un profileur basé sur cela. Le principal avantage est que vous n'avez pas à exécuter votre application pendant des heures pour obtenir un résultat fiable. Même une seconde course est suffisante pour obtenir des résultats solides et fiables, car Callgrind est un profileur sans sondage .

Un autre outil construit sur Valgrind est Massif. Je l'utilise pour profiler l'utilisation de la mémoire de tas. Cela fonctionne très bien. Ce qu'il fait, c'est qu'il vous donne des instantanés de l'utilisation de la mémoire - des informations détaillées CE QUI contient QUEL pourcentage de mémoire, et QUI l'avait mis là. Ces informations sont disponibles à différents moments de l'exécution de l'application.

La réponse à exécuter valgrind --tool=callgrindn'est pas tout à fait complète sans certaines options. Nous ne voulons généralement pas profiler 10 minutes de temps de démarrage lent sous Valgrind et nous voulons profiler notre programme lorsqu'il effectue une tâche.

Voilà donc ce que je recommande. Exécutez d'abord le programme:

valgrind --tool=callgrind --dump-instr=yes -v --instr-atstart=no ./binary > tmp

Maintenant, quand cela fonctionne et que nous voulons commencer le profilage, nous devons exécuter dans une autre fenêtre:

callgrind_control -i on

Cela active le profilage. Pour le désactiver et arrêter toute la tâche, nous pouvons utiliser:

callgrind_control -k

Nous avons maintenant quelques fichiers nommés callgrind.out. * Dans le répertoire courant. Pour voir les résultats de profilage, utilisez:

kcachegrind callgrind.out.*

Je recommande dans la fenêtre suivante de cliquer sur l'en-tête de colonne "Self", sinon cela montre que "main ()" est la tâche la plus longue. "Self" montre combien chaque fonction elle-même a pris du temps, pas avec les personnes à charge.

Ceci est une réponse à la réponse Gprof de Nazgob .

J'utilise Gprof ces deux derniers jours et j'ai déjà trouvé trois limitations importantes, dont une que je n'ai jamais vue (encore) documentée ailleurs:

1. Il ne fonctionne pas correctement sur du code multithread, sauf si vous utilisez une solution de contournement

2. Le graphe d'appel est confus par les pointeurs de fonction. Exemple: J'ai une fonction appelée multithread()qui me permet de multi-threader une fonction spécifiée sur un tableau spécifié (tous deux passés comme arguments). Gprof considère cependant tous les appels multithread()comme équivalents aux fins du calcul du temps passé chez les enfants. Étant donné que certaines fonctions que je passe multithread()prennent beaucoup plus de temps que d'autres, mes graphiques d'appel sont pour la plupart inutiles. (Pour ceux qui se demandent si le thread est le problème ici: non, multithread()peut éventuellement, et l'a fait dans ce cas, exécuter tout séquentiellement sur le thread appelant uniquement).

3. Il est dit ici que "... les chiffres du nombre d'appels sont calculés par comptage et non par échantillonnage. Ils sont complètement précis ...". Pourtant, je trouve que mon graphique d'appel me donne 5345859132 + 784984078 comme statistiques d'appels vers ma fonction la plus appelée, où le premier numéro est censé être des appels directs et le deuxième appels récursifs (qui sont tous de lui-même). Comme cela impliquait que j'avais un bug, j'ai mis de longs compteurs (64 bits) dans le code et j'ai recommencé la même exécution. Mes comptes: 5345859132 directs et 78094395406 appels auto-récursifs. Il y a beaucoup de chiffres, alors je soulignerai que les appels récursifs que je mesure sont de 78 milliards, contre 784 millions de Gprof: un facteur de 100 différent. Les deux exécutions étaient du code à thread unique et non optimisé, l'un compilé -get l'autre -pg.

Il s'agissait de GNU Gprof (GNU Binutils pour Debian) 2.18.0.20080103 fonctionnant sous Debian Lenny 64 bits, si cela peut aider quelqu'un.

Utilisez Valgrind, callgrind et kcachegrind:

valgrind --tool=callgrind ./(Your binary)

génère callgrind.out.x. Lisez-le en utilisant kcachegrind.

Utilisez gprof (add -pg):

cc -o myprog myprog.c utils.c -g -pg 

(pas si bon pour les multi-threads, les pointeurs de fonction)

Utilisez google-perftools:

Utilise l'échantillonnage du temps, les E / S et les goulots d'étranglement CPU sont révélés.

Intel VTune est le meilleur (gratuit à des fins éducatives).

Autres: AMD Codeanalyst (depuis remplacé par AMD CodeXL), OProfile, outils 'perf' (apt-get install linux-tools)

Enquête sur les techniques de profilage C ++

Dans cette réponse, j'utiliserai plusieurs outils différents pour analyser quelques programmes de test très simples, afin de comparer concrètement le fonctionnement de ces outils.

Le programme de test suivant est très simple et fait ce qui suit:

• mainappels fastet maybe_slow3 fois, l'un des maybe_slowappels étant lent

  L'appel lent de maybe_slowest 10 fois plus long et domine l'exécution si nous considérons les appels à la fonction enfant common. Idéalement, l'outil de profilage pourra nous orienter vers l'appel lent spécifique.

• à la fois fastet maybe_slowappel common, qui représente la majeure partie de l'exécution du programme

• L'interface du programme est:

  ./main.out [n [seed]]

  et le programme fait des O(n^2)boucles au total. seedest juste d'obtenir une sortie différente sans affecter l'exécution.

principal 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 nécessite de recompiler le logiciel avec l'instrumentation, et il utilise également une approche d'échantillonnage avec cette instrumentation. Il établit donc un équilibre entre la précision (l'échantillonnage n'est pas toujours entièrement précis et peut sauter des fonctions) et le ralentissement de l'exécution (l'instrumentation et l'échantillonnage sont des techniques relativement rapides qui ne ralentissent pas beaucoup l'exécution).

gprof est intégré à GCC / binutils, donc tout ce que nous avons à faire est de compiler avec l' -pgoption pour activer gprof. Nous exécutons ensuite le programme normalement avec un paramètre CLI de taille qui produit une exécution d'une durée raisonnable de quelques secondes ( 10000):

gcc -pg -ggdb3 -O3 -std=c99 -Wall -Wextra -pedantic -o main.out main.c
time ./main.out 10000

Pour des raisons pédagogiques, nous effectuerons également une course sans optimisations activées. Notez que cela est inutile dans la pratique, car vous ne vous souciez normalement que d'optimiser les performances du programme optimisé:

gcc -pg -ggdb3 -O0 -std=c99 -Wall -Wextra -pedantic -o main.out main.c
./main.out 10000

Tout d'abord, timenous indique que le temps d'exécution avec et sans -pgétait le même, ce qui est super: pas de ralentissement! J'ai cependant vu des comptes rendus de ralentissements 2x - 3x sur des logiciels complexes, par exemple comme indiqué dans ce ticket .

Parce que nous avons compilé avec -pg, l'exécution du programme produit un gmon.outfichier contenant les données de profilage.

Nous pouvons observer ce fichier graphiquement avec gprof2dotcomme demandé à: Est-il possible d'obtenir une représentation graphique des résultats de gprof?

sudo apt install graphviz
python3 -m pip install --user gprof2dot
gprof main.out > main.gprof
gprof2dot < main.gprof | dot -Tsvg -o output.svg

Ici, l' gprofoutil lit les gmon.outinformations de trace et génère un rapport lisible par l'homme main.gprof, qui gprof2dotlit ensuite pour générer un graphique.

La source de gprof2dot est à: https://github.com/jrfonseca/gprof2dot

Nous observons ce qui suit pour la -O0course:

et pour la -O3course:

La -O0sortie est assez explicite. Par exemple, cela montre que les 3 maybe_slowappels et leurs appels enfants occupent 97,56% du temps d'exécution total, bien que l'exécution de maybe_slowlui - même sans enfants représente 0,00% du temps d'exécution total, c'est-à-dire que presque tout le temps passé dans cette fonction a été consacré à les appels des enfants.

TODO: pourquoi est-il mainabsent de la -O3sortie, même si je peux le voir sur un btdans GDB? Fonction manquante de la sortie GProf Je pense que c'est parce que gprof est également basé sur l'échantillonnage en plus de son instrumentation compilée, et qu'il -O3 mainest tout simplement trop rapide et n'a obtenu aucun échantillon.

J'ai choisi la sortie SVG au lieu de PNG car le SVG est consultable avec Ctrl + F et la taille du fichier peut être environ 10 fois plus petite. De plus, la largeur et la hauteur de l'image générée peuvent être énormes avec des dizaines de milliers de pixels pour les logiciels complexes, et GNOME eog3.28.1 bogue dans ce cas pour les PNG, tandis que les SVG s'ouvrent automatiquement par mon navigateur. gimp 2.8 a bien fonctionné, voir aussi:

• /ubuntu/1112641/how-to-view-extremely-large-images
• /unix/77968/viewing-large-image-on-linux
• /superuser/356038/viewer-for-huge-images-under-linux-100-mp-color-images

mais même dans ce cas, vous ferez beaucoup glisser l'image pour trouver ce que vous voulez, voir par exemple cette image à partir d'un "vrai" exemple de logiciel tiré de ce ticket :

Pouvez-vous trouver facilement la pile d'appels la plus critique avec toutes ces petites lignes de spaghetti non triées qui se superposent? Il y a peut-être de meilleures dotoptions, j'en suis sûr, mais je ne veux pas y aller maintenant. Ce dont nous avons vraiment besoin, c'est d'une visionneuse dédiée appropriée, mais je n'en ai pas encore trouvé:

• Afficher la sortie gprof dans kcachegrind
• Quel est le meilleur remplacement pour KProf?

Vous pouvez cependant utiliser la carte de couleurs pour atténuer un peu ces problèmes. Par exemple, sur la grande image précédente, j'ai finalement réussi à trouver le chemin critique sur la gauche lorsque j'ai fait la brillante déduction que le vert vient après le rouge, suivi enfin par le bleu de plus en plus sombre.

Alternativement, nous pouvons également observer la sortie texte de l' gprofoutil binutils intégré que nous avons précédemment enregistré à:

cat main.gprof

Par défaut, cela produit une sortie extrêmement détaillée qui explique la signification des données de sortie. Comme je ne peux pas expliquer mieux que ça, je vous laisse le lire vous-même.

Une fois que vous avez compris le format de sortie des données, vous pouvez réduire la verbosité pour afficher uniquement les données sans le didacticiel avec l' -boption:

gprof -b main.out

Dans notre exemple, les résultats étaient pour -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

et pour -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

Comme un résumé très rapide pour chaque section, par exemple:

                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]

centre autour de la fonction qui est en retrait ( maybe_flow). [3]est l'ID de cette fonction. Au-dessus de la fonction, se trouvent ses appelants, et en dessous les callees.

Pour -O3, voyez ici comme dans la sortie graphique cela maybe_slowet fastn'avez pas de parent connu, c'est ce que la documentation dit que cela <spontaneous>signifie.

Je ne sais pas s'il existe une bonne façon de faire du profilage ligne par ligne avec gprof: `gprof` le temps passé dans des lignes de code particulières

valgrind callgrind

valgrind exécute le programme via la machine virtuelle valgrind. Cela rend le profilage très précis, mais il produit également un très grand ralentissement du programme. J'ai également mentionné kcachegrind précédemment à: Outils pour obtenir un graphe d'appel de fonction picturale de code

callgrind est l'outil de valgrind pour profiler le code et kcachegrind est un programme KDE qui peut visualiser la sortie du cachegrind.

Tout d'abord, nous devons supprimer l' -pgindicateur pour revenir à la compilation normale, sinon l'exécution échoue avec Profiling timer expired, et oui, c'est tellement courant que je l'ai fait et il y avait une question de débordement de pile pour cela.

Nous compilons et exécutons donc:

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

J'autorise --dump-instr=yes --collect-jumps=yescela, car cela permet également d'afficher des informations qui nous permettent d'afficher une ventilation des performances par chaîne de montage, à un coût supplémentaire relativement faible.

Au départ, timenous dit que le programme a pris 29,5 secondes pour s'exécuter, nous avons donc eu un ralentissement d'environ 15x sur cet exemple. De toute évidence, ce ralentissement va être une sérieuse limitation pour les charges de travail plus importantes. Sur "l'exemple du logiciel du monde réel" mentionné ici , j'ai observé un ralentissement de 80x.

La course génère un fichier de données de profil nommé callgrind.out.<pid>par exemple callgrind.out.8554dans mon cas. Nous visualisons ce fichier avec:

kcachegrind callgrind.out.8554

qui montre une interface graphique qui contient des données similaires à la sortie textuelle gprof:

De plus, si nous allons sur l'onglet "Call Graph" en bas à droite, nous voyons un graphique d'appel que nous pouvons exporter en cliquant dessus avec le bouton droit pour obtenir l'image suivante avec des quantités déraisonnables de bordure blanche :-)

Je pense que fastne s'affiche pas sur ce graphique parce que kcachegrind doit avoir simplifié la visualisation car cet appel prend trop peu de temps, ce sera probablement le comportement que vous souhaitez sur un vrai programme. Le menu du clic droit a quelques paramètres pour contrôler quand abattre de tels nœuds, mais je n'ai pas pu le faire afficher un appel aussi court après une tentative rapide. Si je clique sur fastdans la fenêtre de gauche, il montre un graphique d'appel avec fast, donc cette pile a été réellement capturée. Personne n'avait encore trouvé un moyen d'afficher le graphe d'appel complet: Faire en sorte que callgrind affiche tous les appels de fonction dans le callgraph kcachegrind

TODO sur un logiciel C ++ complexe, je vois quelques entrées de type <cycle N>, par exemple, <cycle 11>là où je m'attendrais à des noms de fonction, qu'est-ce que cela signifie? J'ai remarqué qu'il y avait un bouton "Détection de cycle" pour l'activer ou le désactiver, mais qu'est-ce que cela signifie?

perf de linux-tools

perfsemble utiliser exclusivement des mécanismes d'échantillonnage du noyau Linux. Cela le rend très simple à configurer, mais aussi pas entièrement précis.

sudo apt install linux-tools
time perf record -g ./main.out 10000

Cela a ajouté 0,2 seconde à l'exécution, nous sommes donc très bien dans le temps, mais je ne vois toujours pas beaucoup d'intérêt, après avoir développé le commonnœud avec la flèche droite du clavier:

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              

Alors j'essaie de comparer le -O0programme pour voir si cela montre quelque chose, et seulement maintenant, enfin, je vois un graphique d'appel:

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: que s'est-il passé lors de l' -O3exécution? Est-ce simplement cela maybe_slowet fastétait trop rapide et n'a pas obtenu d'échantillons? Cela fonctionne-t-il bien avec -O3des programmes plus importants dont l'exécution est plus longue? Ai-je manqué une option CLI? J'ai découvert le -Fcontrôle de la fréquence d'échantillonnage en Hertz, mais je l'ai augmentée au maximum autorisé par défaut de -F 39500(pourrait être augmenté avec sudo) et je ne vois toujours pas d'appels clairs.

Une chose intéressante à propos de perfl'outil FlameGraph de Brendan Gregg qui affiche les horaires de la pile d'appels d'une manière très soignée qui vous permet de voir rapidement les gros appels. L'outil est disponible sur: https://github.com/brendangregg/FlameGraph et est également mentionné sur son tutoriel de perf sur: http://www.brendangregg.com/perf.html#FlameGraphs Quand j'ai couru perfsans sudoje l'ai ERROR: No stack counts foundfait pour maintenant je vais le faire avec 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

mais dans un programme aussi simple, la sortie n'est pas très facile à comprendre, car nous ne pouvons pas facilement voir ni maybe_slowni fastsur ce graphique:

Sur un exemple plus complexe, il devient clair ce que le graphique signifie:

TODO il y a un journal de [unknown]fonctions dans cet exemple, pourquoi?

Une autre interface graphique performante qui pourrait en valoir la peine comprend:

• Plugin Eclipse Trace Compass: https://www.eclipse.org/tracecompass/

  Mais cela a l'inconvénient que vous devez d'abord convertir les données au format de trace commun, ce qui peut être fait avec perf data --to-ctf, mais il doit être activé au moment de la construction / avoir perfsuffisamment de nouveau, ce qui n'est pas le cas pour la perf dans Ubuntu 18.04

• https://github.com/KDAB/hotspot

  L'inconvénient est qu'il ne semble pas y avoir de paquet Ubuntu, et sa construction nécessite Qt 5.10 tandis qu'Ubuntu 18.04 est à Qt 5.9.

gperftools

Anciennement appelé "Google Performance Tools", source: https://github.com/gperftools/gperftools Sample based.

Installez d'abord gperftools avec:

sudo apt install google-perftools

Ensuite, nous pouvons activer le profileur de processeur gperftools de deux manières: au moment de l'exécution ou au moment de la construction.

Au moment de l'exécution, nous devons passer set the LD_PRELOADto point to libprofiler.so, que vous pouvez trouver avec locate libprofiler.so, par exemple sur mon système:

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

Alternativement, nous pouvons construire la bibliothèque au moment du lien, en passant LD_PRELOADau moment de l'exécution:

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

Voir aussi: gperftools - fichier de profil non vidé

La meilleure façon de voir ces données que j'ai trouvées jusqu'à présent est de faire en sorte que la sortie de pprof soit du même format que kcachegrind prend en entrée (oui, l'outil Valgrind-project-viewer-tool) et d'utiliser kcachegrind pour voir cela:

google-pprof --callgrind main.out prof.out  > callgrind.out
kcachegrind callgrind.out

Après avoir exécuté l'une de ces méthodes, nous obtenons un prof.outfichier de données de profil en sortie. Nous pouvons visualiser ce fichier graphiquement en SVG avec:

google-pprof --web main.out prof.out

qui donne comme un graphique d'appel familier comme les autres outils, mais avec l'unité maladroite de nombre d'échantillons plutôt que de secondes.

Alternativement, nous pouvons également obtenir des données textuelles avec:

google-pprof --text main.out prof.out

qui donne:

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

Voir aussi: Comment utiliser les outils google perf

Testé dans Ubuntu 18.04, gprof2dot 2019.11.30, valgrind 3.13.0, perf 4.15.18, Linux kernel 4.15.0, FLameGraph 1a0dc6985aad06e76857cf2a354bd5ba0c9ce96b, gperftools 2.5-2.

Pour les programmes monothread , vous pouvez utiliser igprof , The Ignominous Profiler: https://igprof.org/ .

Il s'agit d'un profileur d'échantillonnage, dans le sens de la ... longue ... réponse de Mike Dunlavey, qui emballera les résultats dans une arborescence de pile d'appels consultable, annotée avec le temps ou la mémoire passé dans chaque fonction, cumulative ou par fonction.

Il convient également de mentionner

1. HPCToolkit ( http://hpctoolkit.org/ ) - Open-source, fonctionne pour les programmes parallèles et possède une interface graphique avec laquelle regarder les résultats de plusieurs façons
2. Intel VTune ( https://software.intel.com/en-us/vtune ) - Si vous avez des compilateurs Intel, c'est très bien
3. TAU ( http://www.cs.uoregon.edu/research/tau/home.php )

J'ai utilisé HPCToolkit et VTune et ils sont très efficaces pour trouver le long pôle dans la tente et n'ont pas besoin de recompiler votre code (sauf que vous devez utiliser -g -O ou le type RelWithDebInfo dans CMake pour obtenir une sortie significative) . J'ai entendu dire que TAU avait des capacités similaires.

Ce sont les deux méthodes que j'utilise pour accélérer mon code:

Pour les applications liées au processeur:

1. Utilisez un profileur en mode DEBUG pour identifier les parties douteuses de votre code
2. Ensuite, passez en mode RELEASE et commentez les sections douteuses de votre code (stub avec rien) jusqu'à ce que vous voyiez des changements dans les performances.

Pour les applications liées aux E / S:

1. Utilisez un profileur en mode RELEASE pour identifier les parties douteuses de votre code.

NB

Si vous n'avez pas de profileur, utilisez le profileur du pauvre. Appuyez sur pause pendant le débogage de votre application. La plupart des suites de développeurs se diviseront en assembleur avec des numéros de ligne commentés. Vous êtes statistiquement susceptible d'atterrir dans une région qui consomme la plupart de vos cycles CPU.

Pour le CPU, la raison du profilage en mode DEBUG est que si votre profilage essayé en mode RELEASE , le compilateur va réduire les mathématiques, vectoriser les boucles et les fonctions en ligne qui ont tendance à globaliser votre code dans un désordre non mappable lorsqu'il est assemblé. Un désordre non mappable signifie que votre profileur ne sera pas en mesure d'identifier clairement ce qui prend si longtemps car l'assembly peut ne pas correspondre au code source en cours d'optimisation . Si vous avez besoin des performances (par exemple, sensibles au timing) du mode RELEASE , désactivez les fonctionnalités du débogueur si nécessaire pour conserver des performances utilisables.

Pour les E / S liées, le profileur peut toujours identifier les opérations d'E / S en mode RELEASE car les opérations d'E / S sont soit liées en externe à une bibliothèque partagée (la plupart du temps), soit, dans le pire des cas, se traduisent par un système. vecteur d'interruption d'appel (qui est également facilement identifiable par le profileur).

Vous pouvez utiliser la bibliothèque iprof:

https://gitlab.com/Neurochrom/iprof

https://github.com/Neurochrom/iprof

Il est multiplateforme et vous permet de ne pas mesurer les performances de votre application également en temps réel. Vous pouvez même l'associer à un graphique en direct. Avertissement complet: je suis l'auteur.

Vous pouvez utiliser un cadre de journalisation comme logurucar il comprend des horodatages et une disponibilité totale qui peuvent être bien utilisés pour le profilage:

Au travail, nous avons un outil vraiment sympa qui nous aide à surveiller ce que nous voulons en termes de planification. Cela a été utile à plusieurs reprises.

C'est en C ++ et doit être personnalisé selon vos besoins. Malheureusement, je ne peux pas partager de code, juste des concepts. Vous utilisez un "grand" volatiletampon contenant des horodatages et un ID d'événement que vous pouvez vider post mortem ou après avoir arrêté le système de journalisation (et le vider dans un fichier par exemple).

Vous récupérez le soi-disant grand tampon avec toutes les données et une petite interface les analyse et affiche les événements avec le nom (haut / bas + valeur) comme un oscilloscope le fait avec des couleurs (configuré dans un .hppfichier).

Vous personnalisez la quantité d'événements générés pour vous concentrer uniquement sur ce que vous désirez. Cela nous a beaucoup aidés à planifier les problèmes tout en consommant la quantité de CPU que nous voulions en fonction du nombre d'événements enregistrés par seconde.

Vous avez besoin de 3 fichiers:

toolname.hpp // interface
toolname.cpp // code
tool_events_id.hpp // Events ID

Le concept est de définir des événements tool_events_id.hppcomme ça:

// 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

Vous définissez également quelques fonctions dans toolname.hpp:

#define LOG_LEVEL_ERROR 0
#define LOG_LEVEL_WARN 1
// ...

void init(void);
void probe(id,payload);
// etc

Partout dans votre code, vous pouvez utiliser:

toolname<LOG_LEVEL>::log(EVENT_NAME,VALUE);

La probefonction utilise quelques lignes d'assemblage pour récupérer l'horodatage d'horloge dès que possible, puis définit une entrée dans le tampon. Nous avons également un incrément atomique pour trouver en toute sécurité un index où stocker l'événement du journal. Bien sûr, le tampon est circulaire.

J'espère que l'idée n'est pas obscurcie par le manque d'exemple de code.

En fait, un peu surpris pas beaucoup mentionné sur google / benchmark , alors qu'il est un peu lourd de préciser la zone spécifique du code, surtout si la base de code est un peu grande, mais j'ai trouvé cela très utile lorsqu'il est utilisé en combinaison aveccallgrind

À mon humble avis, identifier la pièce à l'origine du goulot d'étranglement est la clé ici. Je voudrais cependant essayer de répondre aux questions suivantes en premier et choisir l'outil en fonction de cela

1. mon algorithme est-il correct?
2. y a-t-il des serrures qui se révèlent être des goulots d'étranglement?
3. existe-t-il une section spécifique de code qui s'avère être un coupable?
4. qu'en est-il des E / S, gérées et optimisées?

valgrindavec la combinaison de callrindet kcachegrinddevrait fournir une estimation décente sur les points ci-dessus et une fois qu'il est établi qu'il y a des problèmes avec une section de code, je suggérerais de faire un micro repère google benchmarkest un bon point de départ.

Utilisez un -pgindicateur lors de la compilation et de la liaison du code et exécutez le fichier exécutable. Pendant l'exécution de ce programme, les données de profilage sont collectées dans le fichier a.out.
Il existe deux types de profilage différents

1- Profilage plat:
en exécutant la commande, gprog --flat-profile a.outvous obtenez les données suivantes
- quel pourcentage du temps total a été passé pour la fonction,
- combien de secondes ont été passées dans une fonction - y compris et excluant les appels aux sous-fonctions,
- le nombre de appels,
- le temps moyen par appel.

2- graphique
nous profilant la commande gprof --graph a.outpour obtenir les données suivantes pour chaque fonction qui comprend
- Dans chaque section, une fonction est marquée d'un numéro d'index.
- Au-dessus de la fonction, il y a une liste de fonctions qui appellent la fonction.
- Sous la fonction, il y a une liste des fonctions qui sont appelées par la fonction.

Pour obtenir plus d'informations, vous pouvez consulter https://sourceware.org/binutils/docs-2.32/gprof/

Comme personne n'a mentionné Arm MAP, j'ajouterais que personnellement, j'ai réussi à utiliser Map pour profiler un programme scientifique C ++.

Arm MAP est le profileur pour les codes C, C ++, Fortran et F90 parallèles, multithread ou à thread unique. Il fournit une analyse approfondie et un repérage des goulots d'étranglement sur la ligne source. Contrairement à la plupart des profileurs, il est conçu pour pouvoir profiler des pthreads, OpenMP ou MPI pour du code parallèle et fileté.

MAP est un logiciel commercial.

utiliser un logiciel de débogage comment identifier où le code s'exécute lentement?

pensez simplement que vous avez un obstacle pendant que vous êtes en mouvement, cela réduira votre vitesse

comme cette boucle de réallocation indésirable, les débordements de tampon, la recherche, les fuites de mémoire, etc.

g++ your_prg.cpp -pgou cc my_program.cpp -g -pgselon votre compilateur

Je ne l'ai pas encore essayé mais j'ai entendu de bonnes choses sur google-perftools. Cela vaut vraiment la peine d'essayer.

valgrind --tool=callgrind ./(Your binary)

Il générera un fichier appelé gmon.out ou callgrind.out.x. Vous pouvez ensuite utiliser kcachegrind ou l'outil de débogage pour lire ce fichier. Il vous donnera une analyse graphique des choses avec des résultats comme quelles lignes coûtent combien.

Je le pense