strange result from timeit
<p>I tried to repeat the functionality of IPython %time, but for some strange reason, results of testing of some function are horrific.</p>

<p>IPython:</p>

<pre><code>In [11]: from random import shuffle
   ....: import numpy as np
   ....: def numpy_seq_el_rank(seq, el):
   ....:     return sum(seq &lt; el)
   ....:
   ....: seq = np.array(xrange(10000))
   ....: shuffle(seq)
   ....:

In [12]: %timeit numpy_seq_el_rank(seq, 10000//2)
10000 loops, best of 3: 46.1 Âµs per loop
</code></pre>

<p>Python:</p>

<pre><code>from timeit import timeit, repeat

def my_timeit(code, setup, rep, loops):
    result = repeat(code, setup=setup, repeat=rep, number=loops)
    return '%d loops, best of %d: %0.9f sec per loop'%(loops, rep, min(result))

np_setup = '''
from random import shuffle
import numpy as np
def numpy_seq_el_rank(seq, el):
    return sum(seq &lt; el)

seq = np.array(xrange(10000))
shuffle(seq)
'''
np_code = 'numpy_seq_el_rank(seq, 10000//2)'

print 'Numpy seq_el_rank:\n\t%s'%my_timeit(code=np_code, setup=np_setup, rep=3, loops=100)
</code></pre>

<p>And its output:</p>

<pre class="lang-none prettyprint-override"><code>Numpy seq_el_rank:
    100 loops, best of 3: 1.655324947 sec per loop
</code></pre>

<p>As you can see, in python i made 100 loops instead 10000 (<em>and get 35000 times slower result</em>) as in ipython, because it takes really long time. Can anybody explain why result in python is so slow?</p>

<p>UPD:
Here is <code>cProfile.run('my_timeit(code=np_code, setup=np_setup, rep=3, loops=10000)')</code> output:</p>

<pre class="lang-none prettyprint-override"><code>         30650 function calls in 4.987 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    4.987    4.987 &lt;string&gt;:1(&lt;module&gt;)
        1    0.000    0.000    0.000    0.000 &lt;timeit-src&gt;:2(&lt;module&gt;)
        3    0.001    0.000    4.985    1.662 &lt;timeit-src&gt;:2(inner)
      300    0.006    0.000    4.961    0.017 &lt;timeit-src&gt;:7(numpy_seq_el_rank)
        1    0.000    0.000    4.987    4.987 Lab10.py:47(my_timeit)
        3    0.019    0.006    0.021    0.007 random.py:277(shuffle)
        1    0.000    0.000    0.002    0.002 timeit.py:121(__init__)
        3    0.000    0.000    4.985    1.662 timeit.py:185(timeit)
        1    0.000    0.000    4.985    4.985 timeit.py:208(repeat)
        1    0.000    0.000    4.987    4.987 timeit.py:239(repeat)
        2    0.000    0.000    0.000    0.000 timeit.py:90(reindent)
        3    0.002    0.001    0.002    0.001 {compile}
        3    0.000    0.000    0.000    0.000 {gc.disable}
        3    0.000    0.000    0.000    0.000 {gc.enable}
        3    0.000    0.000    0.000    0.000 {gc.isenabled}
        1    0.000    0.000    0.000    0.000 {globals}
        3    0.000    0.000    0.000    0.000 {isinstance}
        3    0.000    0.000    0.000    0.000 {len}
        3    0.000    0.000    0.000    0.000 {method 'append' of 'list' objects}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}
    29997    0.001    0.000    0.001    0.000 {method 'random' of '_random.Random' objects}
        2    0.000    0.000    0.000    0.000 {method 'replace' of 'str' objects}
        1    0.000    0.000    0.000    0.000 {min}
        3    0.003    0.001    0.003    0.001 {numpy.core.multiarray.array}
        1    0.000    0.000    0.000    0.000 {range}
      300    4.955    0.017    4.955    0.017 {sum}
        6    0.000    0.000    0.000    0.000 {time.clock}
</code></pre>

<p>There could be any number of reasons this code is running slower in one implementation of python than another. One may be optimized differently than another, one may pre-compile certain parts while the other is fully interpreted. The only way to figure out why is to profile your code.</p>

<p><a href="https://docs.python.org/2/library/profile.html" rel="nofollow">https://docs.python.org/2/library/profile.html</a></p>

<pre><code>import cProfile

cProfile.run('repeat(code, setup=setup, repeat=rep, number=loops)')
</code></pre>

<p>Will give a result similar to</p>

<pre class="lang-none prettyprint-override"><code>ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     1    0.000    0.000    0.000    0.000 &lt;stdin&gt;:1(testing)
     1    0.000    0.000    0.000    0.000 &lt;string&gt;:1(&lt;module&gt;)
     1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}
     1    0.000    0.000    0.000    0.000 {method 'upper' of 'str' objects}
</code></pre>

<p>Which shows you when function calls were made, how many times they were made and how long they took.</p>

python debugging time ipython