Babel : Outils de profilage des appels d'une application

Sur Babel, il est possible de faire du profilage des appels d'une application de 2 façons distinctes : soit en utilisant GNU gprof, soit en utilisant la bibliothèque MPI Trace.

GNU gprof

Description

GNU gprof est un outil de profilage d'applications.

Ces fonctions sont :

  • Identification des fonctions ou sous-programmes les plus consommateurs par une technique d'échantillonage,
  • Classement en fonction de leurs importances respectives,
  • Arbre des appels.

Utilisation

  • Compiler avec l'option -pg (compilation et édition de liens)
  • Exécuter normalement l'application (introduit un peu d'overhead)
  • L'exécution génère un fichier gmon.out.x par processus (sauf si utilisé en conjonction avec MPI Trace ; dans ce cas seul 4 fichiers apparaissent ; voir la page sur MPI Trace)
  • L'analyse se fait via la commande /bgsys/drivers/ppcfloor/gnu-linux/bin/powerpc-bgp-linux-gprof
  • L'option –sumbg fusionne les résultats d'un grand nombre de processus.

Exemple

Voici un exemple d'utilisation de GNU gprof sur une application parallèle :

babel> /bgsys/drivers/ppcfloor/gnu-linux/bin/powerpc-bgp-linux-gprof --sumbg nom_executable
babel> /bgsys/drivers/ppcfloor/gnu-linux/bin/powerpc-bgp-linux-gprof nom_executable gmon.sum
Flat profile:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total
 time   seconds   seconds    calls   s/call   s/call  name
 34.35    847.37   847.37  2560000     0.00     0.00  calcul
 18.32   1299.18   451.81      256     1.76     6.50  main
 14.40   1654.28   355.10  2560000     0.00     0.00  erreur
  4.46   1764.36   110.08                             DCMF::Mapping::Mapping(DCMF::Personality&)
  3.18   1842.88    78.52                             DMA_RecFifoSimplePollNormalFifoById
  2.70   1909.53    66.66                             MPID_Segment_manipulate
  1.76   1953.00    43.47                             MPID_Segment_vector_pack_to_buf
  1.42   1988.05    35.05                             DCMF::Device::WorkQueue::SharedWorkQueue::bytesAvailableToConsume(unsigned int)
  1.38   2022.14    34.09                             DCMF::Protocol::MultiSend::TreeAllreduceRecvPostMessage::advanceDeep(DCMF::Queueing::Tree::TreeMsgContext)
  1.24   2052.67    30.53                             MPID_Segment_vector_unpack_to_buf
  1.00   2077.22    24.55                             DCMF::Device::WorkQueue::LocalBcastWQMessage::advance()
...
...
...
Call graph (explanation follows)

granularity: each sample hit covers 2 byte(s) for 0.00% of 2466.80 seconds
index % time    self  children    called     name
              451.81 1211.67     256/256         generic_start_main [2]
[1]     67.4  451.81 1211.67     256         main [1]
              847.37    0.00 2560000/2560000     calcul [3]
              355.10    0.00 2560000/2560000     erreur [4]
                8.93    0.00 2560000/2560000     communication [25]
                0.19    0.00     256/256         initialisation [123]
                0.09    0.00     256/256         voisinage [151]
                0.00    0.00     256/256         domaine [231]
-----------------------------------------------
                                                 <spontaneous>
[2]     67.4    0.00 1663.48                 generic_start_main [2]
              451.81 1211.67     256/256         main [1]
-----------------------------------------------
              847.37    0.00 2560000/2560000     main [1]
[3]     34.4  847.37    0.00 2560000         calcul [3]
-----------------------------------------------
              355.10    0.00 2560000/2560000     main [1]
[4]     14.4  355.10    0.00 2560000         erreur [4]
-----------------------------------------------
                                                 <spontaneous>
[5]      4.5  110.08    0.00                 DCMF::Mapping::Mapping(DCMF::Personality&amp;) [5]
-----------------------------------------------
                                                 <spontaneous>
[6]      3.2   78.52    0.00                 DMA_RecFifoSimplePollNormalFifoById [6]
-----------------------------------------------
...
...
...

Les résultats sont séparés en deux sections : la première donne les routines/fonctions classées par ordre décroissant de temps de calcul consommé dans celles-ci (hors temps consommés par les routines/fonctions appelées par celles-ci).

La deuxième section présente un classement en ordre décroissant des différentes fonctions par temps consommé par celles-ci et celles qu'elles appellent. Cette section permet également de savoir qui à appelé qui et combien de fois.

Vous trouverez des explications détaillées sur les chiffres donnés par cette commande dans les sorties qu'elle génère.

Attention : les chiffres donnés ne sont qu'approximatifs car les mesures se font par une technique d'échantillonage.

MPI Trace

Description

La bibliothèque MPI Trace est une bibliothèque de profilage des appels MPI fournie par IBM (voir la page sur cet usage). Cependant, en choisissant les bonnes options, elle peut également servir à réaliser un profilage des appels d'un exécutable.

Attention : la version par défaut de MPI Trace ne supporte pas cette fonctionnalité. Il faut utiliser la version présente dans le répertoire /bglocal/prod/tools_ibm/lib.

Attention : l'utilisation de cette bibliothèque entraîne des surcoûts qui peuvent ne pas être négligeables. C'est particulièrement vrai pour des appels répétés à des fonctions ou sous-programmes faisant peu d'opérations. Ces surcoûts peuvent également fausser les résultats en surestimant le temps passé dans ces fonctions/sous-programmes.

Utilisation

Pour l'utiliser, il faut :

  • Compiler avec l'option -qdebug=function_trace ;
  • Faire l'édition de liens avec les options supplémentaires suivantes (ne pas utiliser le module mpitrace) :
    1. L/bglocal/prod/tools_ibm/lib -lmpitrace
  • Exécuter l'application ainsi instrumentée en positionnant la variable d'environnement FLAT_PROFILE à yes.

Seuls 4 fichiers (au maximum) seront générés pour le profilage des fonctions : un fichier pour le processus passant le plus de temps dans les communications, un pour le moins, un pour la valeur médiane et le processus 0. Les noms des fichiers sont de la forme flat_profile.xxx avec xxx le rang du processus dans MPI_COMM_WORLD.

Exemple

Voici un exemple sur une application simple appelée my_appli et exécutée en mode interactif sur 256 coeurs :

$ mpixlf95_r -qdebug=function_trace my_appli.f90 -o my_appli -L/bglocal/prod/tools_ibm/lib -lmpitrace
$ bgrun -np 256 -mode VN -mapfile TXYZ -env ''FLAT_PROFILE=yes'' -exe ./my_appli

Un fichier de sortie typique ressemble à ceci :

$ cat flat_profile.0
-----------------------------------------------------------------------
Elapsed-time flat profile for MPI task 0.
-----------------------------------------------------------------------
Self(seconds) does not include calls to other routines, Inclusive does.
-----------------------------------------------------------------------
  %Time  Self(seconds)    Inclusive       #Calls  Routine
  49.95        6.8040        6.8040          100  __mod_calcul_NMOD_calcul
  19.33        2.6334       13.6529            1  poisson
  18.06        2.4607        2.4607          100  __mod_erreur_NMOD_erreur
  12.39        1.6879        1.6879          100  __mod_comm_NMOD_communication
   0.49        0.0669        0.0669            1  __mod_init_NMOD_initialisation