How to calculate the execution time for a peace of code in Unix env?

[Magesh]

Consider a block,

fncall( ); /* tells me the current millisecond or something like that:
time-1 */
{/* block of code for which I need to know the exec time
...
...
...
}
fncall( ); /* tells me the current millisecond or something like that:
time-2 */

now I can calculate the diff in time to know the exec time for that
particular block. Is there any way like this?

Thx in advance to all who participate in this discussion...
- Magesh

 

[Nick Keighley]

fncall( ); /* tells me the current millisecond or something like that:
time-1 */
{/* block of code for which I need to know the exec time
..
..
..}

fncall( ); /* tells me the current millisecond or something like that:
time-2 */

now I can calculate the diff in time to know the exec time for that
particular block. Is there any way like this?

look at clock(). It doesn't give msec but it can be used for timeing.
You could run the inner loop many times to give a better reading.

 

[Keith Thompson]

look at clock(). It doesn't give msec but it can be used for timeing.
You could run the inner loop many times to give a better reading.

Keep in mind that the value returned by clock() indicates the amount
of CPU time used by the program. If that's what you need, that's
great, but if you're looking for wall clock time it's not going to
help you much.

You're probably better off using some system-specific method such as a
profiler.

 

[Duncan Muirhead]

Consider a block,

fncall( ); /* tells me the current millisecond or something like that:
time-1 */
{/* block of code for which I need to know the exec time
..
..
..
}
fncall( ); /* tells me the current millisecond or something like that:
time-2 */

now I can calculate the diff in time to know the exec time for that
particular block. Is there any way like this?

Thx in advance to all who participate in this discussion...
- Magesh

Off topic
/* return CPU seconds (system + user) used since program start start
*/
#include <sys/time.h>
#include <sys/resource.h>
double second( void)
{
struct rusage ru;
getrusage(RUSAGE_SELF,&ru) ;
return
(double) (ru.ru_utime.tv_sec+ru.ru_stime.tv_sec)
+ ((double) (ru.ru_utime.tv_usec+ru.ru_stime.tv_usec))*1.0e-6
;
}
The advantage of using this over clock() or gettimeofday() is that those
measure elapsed time, whereas the above measures the processor time used
by your process only.

 

[karthikbalaguru]

Consider a block,

fncall( ); /* tells me the current millisecond or something like that:
time-1 */
{/* block of code for which I need to know the exec time
..
..
..}

fncall( ); /* tells me the current millisecond or something like that:
time-2 */

now I can calculate the diff in time to know the exec time for that
particular block. Is there any way like this?

Thx in advance to all who participate in this discussion...
- Magesh

Lot of profilers are available.

Check : http://www.cs.utah.edu/dept/old/texinfo/as/gprof.html#SEC13

Here is an example portion of a call graph which shows a cycle
containing functions a and b. The cycle was entered by a call to a
from main; both a and b called c.

index % time self children called name
----------------------------------------
1.77 0 1/1 main [2]
[3] 91.71 1.77 0 1+5 <cycle 1 as a whole> [3]
1.02 0 3 b <cycle 1> [4]
0.75 0 2 a <cycle 1> [5]
----------------------------------------
3 a <cycle 1> [5]
[4] 52.85 1.02 0 0 b <cycle 1> [4]
2 a <cycle 1> [5]
0 0 3/6 c [6]
----------------------------------------
1.77 0 1/1 main [2]
2 b <cycle 1> [4]
[5] 38.86 0.75 0 1 a <cycle 1> [5]
3 b <cycle 1> [4]
0 0 3/6 c [6]
----------------------------------------

(The entire call graph for this program contains in addition an entry
for main, which calls a, and an entry for c, with callers a and b.)


index % time self children called name
<spontaneous>
[1] 100.00 0 1.93 0 start [1]
0.16 1.77 1/1 main [2]
----------------------------------------
0.16 1.77 1/1 start [1]
[2] 100.00 0.16 1.77 1 main [2]
1.77 0 1/1 a <cycle 1> [5]
----------------------------------------
1.77 0 1/1 main [2]
[3] 91.71 1.77 0 1+5 <cycle 1 as a whole> [3]
1.02 0 3 b <cycle 1> [4]
0.75 0 2 a <cycle 1> [5]
0 0 6/6 c [6]
----------------------------------------
3 a <cycle 1> [5]
[4] 52.85 1.02 0 0 b <cycle 1> [4]
2 a <cycle 1> [5]
0 0 3/6 c [6]
----------------------------------------
1.77 0 1/1 main [2]
2 b <cycle 1> [4]
[5] 38.86 0.75 0 1 a <cycle 1> [5]
3 b <cycle 1> [4]
0 0 3/6 c [6]
----------------------------------------
0 0 3/6 b <cycle 1> [4]
0 0 3/6 a <cycle 1> [5]
[6] 0.00 0 0 6 c [6]
----------------------------------------


Also,
Check : http://www.cs.mu.oz.au/research/mer...ser_guide/Using-mprof-for-time-profiling.html

Here is a small portion of the call graph profile from an example
program.

called/total parents
index %time self descendents called+self name
index
called/total children


<spontaneous>
[1] 100.0 0.00 0.75 0
call_engine_label [1]
0.00 0.75 1/1
do_interpreter [3]

-----------------------------------------------

0.00 0.75 1/1
do_interpreter [3]
[2] 100.0 0.00 0.75 1 io.run/0(0) [2]
0.00 0.00 1/1
io.init_state/2(0) [11]
0.00 0.74 1/1 main/2(0)
[4]

-----------------------------------------------

0.00 0.75 1/1
call_engine_label [1]
[3] 100.0 0.00 0.75 1 do_interpreter
[3]
0.00 0.75 1/1 io.run/0(0)
[2]

-----------------------------------------------

0.00 0.74 1/1 io.run/0(0)
[2]
[4] 99.9 0.00 0.74 1 main/2(0) [4]
0.00 0.74 1/1 sort/2(0)
[5]
0.00 0.00 1/1 print_list/
3(0) [16]
0.00 0.00 1/10
io.write_string/3(0) [18]

-----------------------------------------------

0.00 0.74 1/1 main/2(0)
[4]
[5] 99.9 0.00 0.74 1 sort/2(0) [5]
0.05 0.65 1/1 list.perm/
2(0) [6]
0.00 0.09 40320/40320 sorted/1(0)
[10]

-----------------------------------------------

8 list.perm/
2(0) [6]
0.05 0.65 1/1 sort/2(0)
[5]
[6] 86.6 0.05 0.65 1+8 list.perm/2(0)
[6]
0.00 0.60 5914/5914 list.insert/
3(2) [7]
8 list.perm/
2(0) [6]

-----------------------------------------------

0.00 0.60 5914/5914 list.perm/
2(0) [6]
[7] 80.0 0.00 0.60 5914 list.insert/3(2)
[7]
0.60 0.60 5914/5914 list.delete/
3(3) [8]

-----------------------------------------------

40319 list.delete/
3(3) [8]
0.60 0.60 5914/5914 list.insert/
3(2) [7]
[8] 80.0 0.60 0.60 5914+40319 list.delete/3(3)
[8]
40319 list.delete/
3(3) [8]

-----------------------------------------------

0.00 0.00 3/69283 tree234.set/
4(0) [15]
0.09 0.09 69280/69283 sorted/1(0)
[10]
[9] 13.3 0.10 0.10 69283 compare/3(0) [9]
0.00 0.00 3/3
__Compare___io__stream/0(0) [20]
0.00 0.00 69280/69280
builtin_compare_int/3(0) [27]

-----------------------------------------------

0.00 0.09 40320/40320 sort/2(0)
[5]
[10] 13.3 0.00 0.09 40320 sorted/1(0) [10]
0.09 0.09 69280/69283 compare/3(0)
[9]

-----------------------------------------------


Karthik Balaguru

 

[Keith Thompson]

The advantage of using this over clock() or gettimeofday() is that those
measure elapsed time, whereas the above measures the processor time used
by your process only.

No, clock() measures processor time.

 

[Tor Rustad]

Duncan Muirhead wrote:

[...]

The advantage of using this over clock() or gettimeofday() is that those
measure elapsed time, whereas the above measures the processor time used
by your process only.

Nope

7.23.2.1 The clock function
Synopsis
#include <time.h>
clock_t clock(void);
Description
The clock function determines the processor time used.

 

[pete]

No, clock() measures processor time.

clock() is for timing program execution.
If you want to know if one function runs faster than another,
clock() is good for that.

The subject line of this thread:
How to calculate the execution time for a peace of code in Unix env?
suggests to me that the use of clock() may be appropriate.

 

[Keith Thompson]

clock() is for timing program execution.
If you want to know if one function runs faster than another,
clock() is good for that.

Probably, but it depends on what you mean by "faster".