MP_Lite: Timing functions

The MP_Time() function returns the relative time in seconds, similar to the MPI function MPI_Wclock(). Timing sections of code can be automated somewhat by bracketing the code of interest with MP_Enter() and MP_Leave() functions. A call to MP_Time_Report() at the end of a run will dump a sorted list of the time spent in each bracketed section to an output file. A common approach is to put these functions at the beginning and end of each function or subroutine of interest, with the function name being the argument to MP_Enter(). There must be a matching MP_Leave() for every MP_Enter() function, so be careful when using multiple return points that you put MP_Leave() calls before each.

If you want to get fancy, you can also calculate and return the number of floating point operations within the MP_Leave() function. MP_Time_Report() will then use this to calculate and return the MFlops rates. You can also return the number of bytes being transferred (as a negative number) if a communication call is bracketed, and MP_Time_Report() will print out the transfer rate in MB/sec.


Fortran timing functions

DOUBLE PRECISION t0
t0 = MP_Time()

CALL MP_Enter('Function name')
CALL MP_Leave(0.0d0)

CALL MP_Time_Report('time.out')
C timing functions
double t0, MP_Time();
t0 = MP_Time();

MP_Enter("Function name");
MP_Leave(0.0);

MP_Time_Report("time.out");

Example time report showing MFlops and MB/sec rates

Mcurie: cat t3e/t10m.256.out 

    time in seconds       +children    calls   name
    655.649 ( 79.6%)       655.649        1  Pair_Table()         123.33 MFlops
    132.509 ( 16.1%)       132.874       10  Calc_P()               5.23 MFlops
     17.433 (  2.1%)        18.114       10  Calc_Force()          57.14 MFlops
     15.156 (  1.8%)        15.156        1  Fcc_Gen()        
      0.682 (  0.1%)         0.682       50  Calc_Force() Comm     58.67 MB/sec
      0.633 (  0.1%)         0.633       10  Correct()             31.68 MFlops
      0.367 (  0.0%)         0.367       10  Calc_Fp()             27.83 MFlops
      0.365 (  0.0%)         0.365       50  Calc_P() Comm         54.74 MB/sec
      0.306 (  0.0%)       808.276        1  MAIN LOOP        
      0.270 (  0.0%)         0.270       10  Predict()            130.96 MFlops
      0.146 (  0.0%)         0.146        1  Pass_Sequence()  
      0.131 (  0.0%)       823.769        1  Everything       
      0.040 (  0.0%)         0.040        1  Reorder_Atoms()  
      0.032 (  0.0%)         0.032        1  Init_Pot()       
      0.028 (  0.0%)         0.028        1  Read_Params()    
      0.022 (  0.0%)         0.022        1  Redistribute()   

  21173.84 billion operations using 256 processors -->  25703.61 MFlops

The time report above was generated by putting MP_Enter('Subroutine()') statements at the beginning of all subroutines and MP_Leave(flops) at the end. The floating point operations are calculated by hand using the following table:


0 ops = integer operations, conditionals
1 op = floating operations {*,+,-,conditionals, type conversion}
3 ops = inversion (1.0/x)
4 ops = division (x/y), sqrt
8 ops = trig functions {sin, cos, exp, ...}

The flops value must be returned as a double, not an integer.
The two communication sections were also bracketed by MP_Enter() and MP_Leave() functions, and the number of bytes was returned through MP_Leave() as a negative double so that the MB/sec transfer rate could be calculated.