Code execution time measurements - strange


I’ve got a simple code like this:

	program test

c        Variables
	  integer, save :: nbl, nblcks, ijk, k, l, n, n2
	  integer, dimension(:), allocatable, save :: ijkpr
	  real(kind(zzz)), dimension(:,:), allocatable, save :: vvect
	  real rrnorm

	  real, dimension(2) :: tarray
	  integer :: total, t1, t2, t3, t4, t5, clock_rate, clock_max
	  real :: cputime, gputime

c        Setting the variables values
	  nblcks = 10000000
	  l = 110
	  rrnorm = 3.5

	  do n=1,200
	     ijkpr(n) = n

	  do n=1,1000
	    do n2=1,1000
	      vvect(n,n2) = n2+n

c        Loop
	  call system_clock(t1, clock_rate, clock_max)
	  do nbl=1,nblcks
	    do n=k,l
	  call system_clock(t2, clock_rate, clock_max)
	  cputime = 1000.0*real(t2-t1)/real(clock_rate)
	  write(*,*) 'CPU = ', cputime, ' ms, vvect(100,1)=', vvect(100,1)


And the time results in consecutive code executions are:
CPU = 1125.0 ms
CPU = 0 ms
CPU = 1110.0 ms
CPU = 0 ms
CPU = 0 ms

Why sometimes the same code takes 1125 ms and sometimes 0 ms? It is all running on the same machine, same system, just one execution right after another.
I tried different time measurement functions (etime, cpu_time, system_clock, etc) and there is always a similar result - zeros appear sometime. There is the same situation also with totaly different codes.

Thank for clearing me up this problem.

Hi szczelba,

Your results will be dependent upon your system’s clock granularity. Given your results, I’m assuming your running on Windows? Windows clock granularity is fairly course.

  • Mat

Following your suggestions, I’ve downloaded and ran a program which should change my current timer resolution to about 1ms (called Set Timer Resolution). But still, the results looks like this:

CPU = 1453 ms
CPU = 1438 ms
CPU = 1438 ms
CPU = 0 ms
CPU = 0 ms

I read that the default windows xp timer resolution is about 10-20 ms. It still should find a difference between 1453 ms and 0 ms…

How to understand this?