[Numpy-discussion] profiling code with hotshot and Numeric/numpy/scipy/...

[Ed Schofield]

Arnd Baecker wrote:
> Hi,
>
> I am trying to profile some code which I am converting from
> Numeric to numpy.
> However, the whole profiling seems to break down on the level of hotshot,
> depending on whether the code is run with Numeric/numpy or (old) scipy.
>
> For the attached test I get:
> - old scipy: all is fine!
> But all these fail
> - Numeric 24.2:
> - numpy version: 0.9.7.2256
> - scipy version: 0.4.8
>
> "Failing" means that I don't get a break-down on which routine takes how
> much time.
>
> First I would be interested whether someone else sees the same behaviour,
> or if we screwed up something with our installation.
>   

I've had trouble with this too.  I get more meaningful results using
prof.run('function()') instead of prof.runcall.  I wrote myself a little
wrapper function, which I'll include below.

But I'm still mystified why hotshot's runcall doesn't work ...

-- Ed


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


def profilerun(function, logfilename='temp.prof'):
    """A nice wrapper for the hotshot profiler.
    Usage:
        profilerun('my_statement')

    Example:
    >>> from scipy.linalg import inv
    >>> from numpy import rand
    >>> def timewaste(arg1=None, arg2=None):
    >>>     print "Arguments 1 and 2 are: " + str(arg1) + " and " +
str(arg2)
    >>>     a = rand(1000,1000)
    >>>     b = linalg.inv(a)
    >>>
    >>> profilerun('timewaste()')

    Example output:
             7 function calls in 0.917 CPU seconds

       Ordered by: internal time, call count

       ncalls  tottime  percall  cumtime  percall filename:lineno(function)
            1    0.916    0.916    0.917    0.917 basic.py:176(inv)
            1    0.000    0.000    0.000    0.000
function_base.py:162(asarray_chkfinite)
            1    0.000    0.000    0.917    0.917 <ipython
console>:1(timewaste)
            1    0.000    0.000    0.000    0.000
__init__.py:28(get_lapack_funcs)
            1    0.000    0.000    0.000    0.000 _internal.py:28(__init__)
            1    0.000    0.000    0.000    0.000 numeric.py:70(asarray)
            1    0.000    0.000    0.000    0.000
_internal.py:36(__getitem__)
            0    0.000             0.000          profile:0(profiler)

    """
    prof = hotshot.Profile(logfilename)
    output = prof.run(function)
    print "Output of function is:"
    print output
    prof.close()
    stats = hotshot.stats.load(logfilename)
    stats.strip_dirs()
    stats.sort_stats('time', 'calls')
    stats.print_stats()