Turing : Outils de profilage des appels d'une application

GNU gprof

Description

GNU gprof est un outil de profilage d'applications.

Ses fonctions sont :

  • Identification des fonctions ou sous-programmes les plus consommateurs par une technique d’échantillonnage,
  • 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
  • L'analyse se fait via la commande /bgsys/drivers/ppcfloor/gnu-linux/bin/powerpc64-bgq-linux-gprof
  • La variable d'environnement BG_GMON_RANK_SUBSET permet de choisir les processus à suivre (par défaut rangs 0 à 31). Elle est au format M, M:N ou M:N:S pour choisir respectivement le processus M, un intervalle allant de M à N ou un intervalle allant de M à N par pas de S.
  • La variable d'environnement BG_GMON_START_THREAD_TIMERS permet de suivre les threads pour les applications multithreadées (pas de suivi des threads par défaut, all pour les suivre tous, nocomm pour tous sauf les threads MPI)

Exemple

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

$ mpixlf90_r -pg profiling_code.f90
$ runjob --envs BG_GMON_RANK_SUBSET="1:2048:2" -np 20148 --rank-per-node 32 --exe a.out
$ powerpc64-bgq-linux-gprof nom_executable gmon.out.0
Flat profile:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total
 time   seconds   seconds    calls   s/call   s/call  name
 52.31     45.36    45.36   400000     0.00     0.00  .__hydro_utils_NMOD_riemann
 13.27     56.87    11.51      640     0.02     0.13  .__hydro_principal_NMOD_godunov
  9.51     65.12     8.25   400000     0.00     0.00  .__hydro_utils_NMOD_trace
  6.50     70.76     5.64   400000     0.00     0.00  .__hydro_utils_NMOD_slope
  6.01     75.97     5.22   400000     0.00     0.00  .__hydro_utils_NMOD_constoprim
  4.99     80.30     4.33   500000     0.00     0.00  .__hydro_utils_NMOD_eos
  2.24     82.24     1.94   400000     0.00     0.00  .__hydro_utils_NMOD_cmpflx
  1.42     83.47     1.23      160     0.01     0.01  .__hydro_principalNMODcmqdt
  0.74     84.11     0.64                             .__mcount_internal
  0.42     84.47     0.36                             .PAMI_Context_trylock_advancev
  0.28     84.71     0.24                             .SpinWaitTaskSwitchBGQ
  0.27     84.94     0.23                             .PAMI::Interface::Context::advance(...
...
...
...
granularity: each sample hit covers 2 byte(s) for 0.01% of 86.71 seconds

index % time    self  children    called     name
                0.00   10.45       1/8           ._xlsmpParRegionSetup_TPO [6]
                0.00   73.13       7/8           .ThdCode [3]
[1]     96.4    0.00   83.58       8         .hydro_main$$OL$$1 [1]
               11.51   69.92     640/640         .__hydro_principal_NMOD_godunov [2]
                1.23    0.87     160/160         .__hydro_principal_NMOD_cmpdt [10]
                0.05    0.00       8/8           .__hydro_principal_NMOD_init_hydro [30]
                0.00    0.00       8/8           .__omp_domain_decomposition_NMOD_init_omp [56]
-----------------------------------------------
               11.51   69.92     640/640         .hydro_main$$OL$$1 [1]
[2]     93.9   11.51   69.92     640         .__hydro_principal_NMOD_godunov [2]
               45.36    0.00  400000/400000      .__hydro_utils_NMOD_riemann [4]
                8.25    5.64  400000/400000      .__hydro_utils_NMOD_trace [5]
                5.22    3.46  400000/400000      .__hydro_utils_NMOD_constoprim [7]
                1.94    0.00  400000/400000      .__hydro_utils_NMOD_cmpflx [11]
                0.05    0.00  200000/200000      .__omp_domain_decomposition_NMOD_sync_x [29]
                0.01    0.00     640/640         .__hydro_utils_NMOD_make_boundary [37]
                0.00    0.00  200000/200000      .__omp_domain_decomposition_NMOD_sync_y [47]
                0.00    0.00     640/640         .allocate_work_space [48]
                0.00    0.00     640/640         .deallocate_work_space [49]
-----------------------------------------------

[3]     84.3    0.00   73.13                 .ThdCode [3]
                0.00   73.13       7/8           .hydro_main$$OL$$1 [1]
-----------------------------------------------
               45.36    0.00  400000/400000      .__hydro_principal_NMOD_godunov [2]
[4]     52.3   45.36    0.00  400000         .__hydro_utils_NMOD_riemann [4]
-----------------------------------------------
                8.25    5.64  400000/400000      .__hydro_principal_NMOD_godunov [2]
[5]     16.0    8.25    5.64  400000         .__hydro_utils_NMOD_trace [5]
                5.64    0.00  400000/400000      .__hydro_utils_NMOD_slope [8]
-----------------------------------------------
...
...
...

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’échantillonnage.