15

Sometimes while optimizing code it is required to time certain portions of the code, I have been using the following for years but was wondering if there is a simpler/better way to do it?

call system_clock(count_rate=clock_rate) !Find the time rate
call system_clock(count=clock_start)     !Start Timer

call do_something_subroutine             !This is what gets timed

call system_clock(count=clock_stop)      ! Stop Timer

e_time = real(clock_stop-clock_start)/real(clock_rate)
David Ketcheson
  • 16,522
  • 4
  • 54
  • 105
Isopycnal Oscillation
  • 610
  • 1
  • 5
  • 14

3 Answers3

12

There are a few other ways to do this, with advantages and drawbacks:

  • MPI_WTIME: This is a high resolution wall-clock. It is probably the most `trusted' option; it just works. The downside is that if your program doesn't already use MPI, you'll have to wrap MPI around it (which isn't hard).
  • Use a fortran intrinsic (as you have): This is probably the easiest, and generally sufficient, but might not work so well on a strange architecture or for parallel jobs. There is a bit of a discussion on this Stack Overflow
  • Wrap a C call: Fortran and C are object-compatible, so its easy enough to write a wrapper around C calls. A code I work with uses getrusage, which might be an odd choice. There are many discussions of this on Stack Overflow.

My personal recommendation would be MPI_WTIME, as you know it will work well wherever there is MPI. Here is an example from a quick search:

  include 'mpif.h'
  DOUBLE PRECISION :: start, end
  start = MPI_Wtime()

  ! code to be timed

  end   = MPI_Wtime()
  write(*,*) 'That took ',end-start,' seconds'
Community
  • 1
Max Hutchinson
  • 3,051
  • 16
  • 29
4

If you use the GNU compiler, check out gprof.

In short, you'll add the -g flag to your compiler, like so: 

g77 -g -pg -0 myprogram myprogram.F

Then, run the output, and a file called gmon.out will show up in your directory. Then, call 

gprof --line myprogram gmon.out

This will give a line-by-line CPU time profile.

icurays1
  • 423
  • 2
  • 9
  • Thanks for the answer I just have to clarify that I was asking for a programmatic solution. A profiler is great but it is more than what I was asking for. – Isopycnal Oscillation Apr 11 '13 at 05:46
  • 3
    the flag is -pg, -g is for debug symbols (also interesting, but not required) – RSFalcon7 Apr 11 '13 at 13:50
  • I've heard in multiple places that the timings given by gprof are not necessarily accurate, such as http://www.yosefk.com/blog/how-profilers-lie-the-cases-of-gprof-and-kcachegrind.html, http://stackoverflow.com/questions/1777556/alternatives-to-gprof/1779343#1779343 (and various other Mike Dunlavey answers on Stack Overflow). Tools like gprof and kcachegrind are still useful, in that the number of function calls is still correct, and they give you some timing data, but I wouldn't treat it as gospel. The DOE has some tools for this, but I don't know if they're any better than inserting timers. – Geoff Oxberry Apr 11 '13 at 16:18
  • 1
    Seriously, @IsopycnalOscillation try to use the profiler. It is something new to learn, but it will help you tremendously (and clean up your code!) in the long run. – tmarthal Apr 11 '13 at 18:55
  • thanks @tmarthal I have used profilers before and I will definitely be using one for my next project - I totally agree with what you said. – Isopycnal Oscillation Apr 11 '13 at 21:00
2

As mentioned by icurays1 profiling is best. You can also slightly simplify the above ...

use utils
...
call tic()
   ! Section to be timed
call toc()
...
call tic()
   ! Section to be timed
call toc()
...

where the utils module contains ...

real(8) :: t1,t2
...
subroutine tic()
  implicit none
  call cpu_time(t1)
end subroutine tic

subroutine toc()
  implicit none
  call cpu_time(t2)
  ! if (rank==0) print*,"Time Taken -->", real(t2-t1)
  print*,"Time Taken -->", real(t2-t1)
end subroutine toc

If you have many such sections then pass a string, e.g., "section_id" in toc so that it prints the id/name along with the timing.

stali
  • 1,759
  • 1
  • 10
  • 13
  • I would suggest not making t1 and t2 global, but rather passing t1 as a parameter to both functions, to allow for multiple timers. You could also just return the time, not print anything. – Pedro Apr 11 '13 at 14:07