Finding cpu time spent on my program

[Nick Craig-Wood]

kyosohma at gmail.com <kyosohma at gmail.com> wrote:
>  On Feb 5, 2:37 am, "jm.sur... at no.spam.gmail.com" <jm.sur... at gmail.com>
>  wrote:
> > I am trying to measure the time the processor spends on some
> > operation, and I want this measure to not depend on the current load
> > of the machine.
> 
>  One of the best ways to time small snippets of code is python's timeit
>  module. See the docs at
>  http://docs.python.org/lib/module-timeit.html

Timeit is very cool, but it doesn't measure CPU time, it measure real
time, eg on a linux box

$ python -m timeit 'for i in xrange(100000): pass'
100 loops, best of 3: 11.4 msec per loop

Now run 10 copies of the same program at once

$ for i in `seq 10` ; do python -m timeit 'for i in xrange(100000): pass' & done
10 loops, best of 3: 24.4 msec per loop
10 loops, best of 3: 83.2 msec per loop
10 loops, best of 3: 83.4 msec per loop
10 loops, best of 3: 81.4 msec per loop
10 loops, best of 3: 83 msec per loop
10 loops, best of 3: 60.7 msec per loop
10 loops, best of 3: 47 msec per loop
10 loops, best of 3: 48.6 msec per loop
10 loops, best of 3: 42.3 msec per loop
10 loops, best of 3: 38.7 msec per loop

> > Is there a way to measure the number of cpu cycles spent on my program
> > alone irrespective of the current load etc of the machine.

The most accurate way of measuring CPU usage under linux is getrusage,
eg

>>> import resource
>>> def cpu_time():
...     return resource.getrusage(resource.RUSAGE_SELF)[0]
... 

Now try this out

>>> def f():                 
...     for i in xrange(100000):
...             pass
... 
>>> start = cpu_time(); f(); dt = cpu_time() - start; print dt
0.008001
>>> start = cpu_time(); f(); dt = cpu_time() - start; print dt
0.012001
>>> start = cpu_time(); f(); dt = cpu_time() - start; print dt
0.012
>>> start = cpu_time(); f(); dt = cpu_time() - start; print dt
0.012001
>>> start = cpu_time(); f(); dt = cpu_time() - start; print dt
0.016001
>>> start = cpu_time(); f(); dt = cpu_time() - start; print dt
0.012001
>>> start = cpu_time(); f(); dt = cpu_time() - start; print dt
0.008001

You'll see the result is quantised to 4 ms (not sure what the .000001
bits are about!)

4ms is the clock rate of this machine, ie 250 Hz.  This is a compile
time option for the linux kernel and is usually set in the range 100
Hz to 1000 Hz.  The kernel doesn't measure CPU usage more accurately
than this.

-- 
Nick Craig-Wood <nick at craig-wood.com> -- http://www.craig-wood.com/nick