interaction with gprof

Salvatore Filippone filippone.salvatore@gmail.com
Mon Nov 18 12:58:00 GMT 2013


Hello,
I have been tracking some performance issues, and I  came across
something strange.
I have a test program taken from my numerical libraries which I am
using on a certain test case; I have been using the -pg option
(together with -O3) to investigate hotspots, and I have found that
compiling with 4.6.4 and 4.8.2, exact same program  and test case,
produces two different profiles. The first few lines are as follows:
-------------------------------------------------------
4.6.4:
--------------------------------------------------------
Flat profile:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total
 time   seconds   seconds    calls   s/call   s/call  name
 28.01     88.60    88.60      816     0.11     0.11  psb_s_coo_csgetrow_
 10.31    121.23    32.63      601     0.05     0.05  psb_d_csr_csmv_
  7.82    145.96    24.73     1069     0.02     0.02  daxpby_
  7.77    170.55    24.59    27320     0.00     0.00
__mld_diluk_impl_mod_MOD_iluk_fact
  6.80    192.05    21.50 79808971     0.00     0.00  msort_up_
  3.32    202.55    10.50      325     0.03     0.03
__psb_d_base_vect_mod_MOD_d_base_bld_x
  2.72    211.16     8.61        6     1.44     1.44  dnumbmm_
  2.67    219.62     8.46      325     0.03     0.03
__psb_d_base_vect_mod_MOD_d_base_zero
  2.66    228.05     8.43 67196690     0.00     0.00  psi_int_heap_get_first_
  2.64    236.40     8.35        6     1.39     2.49  symbmm_
-------------------------------------------------------
4.8.2
-------------------------------------------------------
Flat profile:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total
 time   seconds   seconds    calls   s/call   s/call  name
 30.43     88.43    88.43      816     0.11     0.11  psb_s_fix_coo_
 11.14    120.80    32.37      601     0.05     0.05  psb_d_csr_csmv_
  9.49    148.38    27.58        1    27.58   113.22
__mld_diluk_impl_mod_MOD_mld_diluk_factint
  6.92    168.50    20.12 79808971     0.00     0.00  msort_up_
  4.09    180.38    11.88     1069     0.01     0.01  daxpby_
  3.72    191.19    10.81      325     0.03     0.03
__psb_d_base_vect_mod_MOD_d_base_bld_x
  2.91    199.66     8.47        6     1.41     2.52  symbmm_
  2.91    208.12     8.46        6     1.41     1.41  dnumbmm_
  2.77    216.17     8.05 67196690     0.00     0.00  psi_int_heap_get_first_
  2.69    224.00     7.83       31     0.25     1.01  psb_d_fix_coo_inner_

========================================================
Now the disturbing fact is that the first routine mentioned in the
profile, with the same number of calls and the same accumulated time,
appears with two different names, and BOTH NAMES ARE WRONG.
In my naming scheme the _s_ stands for single precision version,
whereas the program (as can be seen from the second routine
psb_d_csr_csmv) is a double precision version, no single precision
routine is called. Indeed I even put some prints in the two routines
that GPROF is saying are called, and they do not show up.

So my question is: is this supposed to work?
If not, why (aka, what am I doing wrong)?
If yes, is it a problem on gprof's side, gfortran's side, an
interaction with MPI wrappers, all of the above, none of the above?
Anybody has any suggestions on how to reduce this and/or want to look
at the source code?
Thanks

Very perplexed yours
Salvatore



More information about the Fortran mailing list