[Numpy-discussion] profiling code with hotshot and Numeric/numpy/scipy/...
Arnd Baecker
arnd.baecker at web.de
Thu May 4 11:38:01 EDT 2006
On Thu, 4 May 2006, Fernando Perez wrote:
> On 5/4/06, Arnd Baecker <arnd.baecker at web.de> wrote:
>
> > Thanks for the wrapper - but it seems that is does not to help in my case:
> > I replaced in my script
> > prof.runcall(main)
> > by
> > prof.run("main()")
> > and still see the same output, i.e. no information in the
> > Numeric/numpy/scipy cases.
>
> Have you tried in ipython %prun or '%run -p'? The first will run a
> single statement, the second a whole script, undre the control of the
> OLD python profiler (not hotshot). While the 'profile' module lacks
> some of the niceties of hotshot, it may at least work here.
I use hotshot in combination with hotshot2cachegrind
and kcachegrind to get a nice visual display and line-by-line
profilings
(http://mail.enthought.com/pipermail/enthought-dev/2006-January/001075.html
has all the links ;-).
As far as I know this is not possible with the "old profiler".
So yes
> Not a permanent solution, but it could get you moving.
At the moment even timeit.py is sufficient, but `prun` is indeed
a very convenient option!
However, the output of this is also puzzling, ranging
from 6 (almost useless) lines for Numeric and
to overwhelming 6 screens (also useless?) for numpy (see below).
((Also, if you vary the order of the tests you also get
different results...))
Ouch, this looks like a mess - I know benchmarking/profiling
is considered to be tricky - but that tricky?
Many thanks,
Arnd
#############################################
Numeric version: 24.2
4 function calls in 0.490 CPU seconds
Ordered by: internal time
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.480 0.480 0.480 0.480
test_profile_problem_via_ipython.py:38(main)
1 0.010 0.010 0.490 0.490 <string>:1(?)
1 0.000 0.000 0.480 0.480
test_profile_problem_via_ipython.py:7(?)
0 0.000 0.000 profile:0(profiler)
1 0.000 0.000 0.490 0.490
profile:0(execfile(filename,prog_ns))
#############################################
scipy version: 0.3.2
18004 function calls in 1.080 CPU seconds
Ordered by: internal time
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.380 0.380 1.080 1.080
test_profile_problem_via_ipython.py:38(main)
1000 0.230 0.000 0.460 0.000 scimath.py:31(log)
2000 0.090 0.000 0.190 0.000 type_check.py:96(isreal)
2000 0.080 0.000 0.080 0.000 Numeric.py:655(sometrue)
2000 0.070 0.000 0.190 0.000 function_base.py:36(any)
6000 0.070 0.000 0.070 0.000 type_check.py:12(asarray)
2000 0.070 0.000 0.080 0.000 type_check.py:86(imag)
1000 0.050 0.000 0.240 0.000 scimath.py:25(sqrt)
2000 0.040 0.000 0.040 0.000 Numeric.py:583(ravel)
0 0.000 0.000 profile:0(profiler)
1 0.000 0.000 1.080 1.080
profile:0(execfile(filename,prog_ns))
1 0.000 0.000 1.080 1.080
test_profile_problem_via_ipython.py:7(?)
1 0.000 0.000 1.080 1.080 <string>:1(?)
#############################################
numpy version: 0.9.7.2256
33673 function calls (31376 primitive calls) in 1.380 CPU seconds
Ordered by: internal time
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.480 0.480 0.480 0.480
test_profile_problem_via_ipython.py:43(main)
1438 0.130 0.000 0.130 0.000 posixpath.py:171(exists)
3523 0.090 0.000 0.130 0.000 sre_parse.py:206(get)
486/59 0.080 0.000 0.380 0.006 sre_parse.py:367(_parse)
886/59 0.060 0.000 0.100 0.002 sre_compile.py:24(_compile)
364/59 0.060 0.000 0.380 0.006 sre_parse.py:312(_parse_sub)
4426 0.050 0.000 0.050 0.000 sre_parse.py:187(__next)
1032/408 0.050 0.000 0.050 0.000 sre_parse.py:147(getwidth)
81 0.040 0.000 0.040 0.000 auxfuncs.py:253(l_and)
150/94 0.030 0.000 0.190 0.002 glob.py:9(glob)
2269 0.030 0.000 0.040 0.000 sre_parse.py:200(match)
291 0.020 0.000 0.020 0.000
sre_compile.py:180(_optimize_charset)
2228 0.020 0.000 0.020 0.000 sre_parse.py:145(append)
1 0.020 0.020 0.020 0.020 linalg.py:3(?)
886 0.020 0.000 0.020 0.000 sre_parse.py:98(__init__)
59 0.020 0.000 0.020 0.000 sre_parse.py:75(__init__)
59 0.020 0.000 0.060 0.001
sre_compile.py:331(_compile_info)
79 0.010 0.000 0.010 0.000 auxfuncs.py:265(l_not)
111 0.010 0.000 0.010 0.000 sre_parse.py:221(isname)
1400 0.010 0.000 0.010 0.000 glob.py:49(<lambda>)
30 0.010 0.000 0.010 0.000
numerictypes.py:284(_add_array_type)
1 0.010 0.010 0.010 0.010 ma.py:9(?)
349 0.010 0.000 0.020 0.000 sre_compile.py:324(_simple)
56 0.010 0.000 0.020 0.000 glob.py:42(glob1)
40 0.010 0.000 0.010 0.000
sre_parse.py:135(__delitem__)
17/1 0.010 0.001 1.380 1.380 <string>:1(?)
1 0.010 0.010 0.530 0.530 crackfortran.py:14(?)
1 0.010 0.010 0.010 0.010 defmatrix.py:2(?)
1 0.010 0.010 0.010 0.010 numeric.py:1(?)
349 0.010 0.000 0.010 0.000
sre_parse.py:141(__getslice__)
55 0.010 0.000 0.010 0.000 posixpath.py:117(dirname)
2914 0.010 0.000 0.010 0.000 posixpath.py:56(join)
1 0.010 0.010 0.020 0.020 capi_maps.py:12(?)
1 0.000 0.000 0.000 0.000 records.py:1(?)
1 0.000 0.000 0.000 0.000
numerictypes.py:161(_add_aliases)
1 0.000 0.000 0.000 0.000
unittest.py:640(TextTestRunner)
1 0.000 0.000 0.000 0.000 ma.py:76(default_fill_value)
1 0.000 0.000 0.000 0.000 arraysetops.py:26(?)
1 0.000 0.000 0.000 0.000 function_base.py:2(?)
1 0.000 0.000 0.000 0.000
index_tricks.py:343(_index_expression_class)
1 0.000 0.000 0.000 0.000 ma.py:263(__init__)
473 0.000 0.000 0.000 0.000 sre_parse.py:269(_escape)
1 0.000 0.000 0.000 0.000
ma.py:320(domain_safe_divide)
1 0.000 0.000 0.000 0.000 ma.py:38(_MaskedPrintOption)
1 0.000 0.000 0.000 0.000 ma.py:261(domain_tan)
1 0.000 0.000 0.100 0.100
_import_tools.py:301(get_pkgdocs)
2 0.000 0.000 0.000 0.000 info.py:27(?)
1 0.000 0.000 0.310 0.310 __init__.py:15(?)
2 0.000 0.000 0.000 0.000 UserDict.py:41(has_key)
1 0.000 0.000 0.000 0.000 __config__.py:3(?)
16 0.000 0.000 0.000 0.000 auxfuncs.py:259(l_or)
1 0.000 0.000 0.010 0.010 numerictypes.py:76(?)
1 0.000 0.000 0.000 0.000 cfuncs.py:15(?)
1 0.000 0.000 0.000 0.000 __version__.py:1(?)
1 0.000 0.000 0.000 0.000 copy.py:389(_EmptyClass)
47 0.000 0.000 0.000 0.000 ma.py:2104(_m)
1 0.000 0.000 0.000 0.000 records.py:42(format_parser)
56 0.000 0.000 0.000 0.000 posixpath.py:39(normcase)
1 0.000 0.000 0.000 0.000
numpytest.py:180(_SciPyTextTestResult)
1 0.000 0.000 0.000 0.000
numpytest.py:99(_dummy_stream)
1 0.000 0.000 0.000 0.000 numeric.py:484(_setdef)
2 0.000 0.000 0.000 0.000 __svn_version__.py:1(?)
1 0.000 0.000 1.380 1.380
test_profile_problem_via_ipython.py:12(?)
1 0.000 0.000 0.000 0.000 index_tricks.py:229(r_class)
2 0.000 0.000 0.000 0.000 ma.py:496(size)
2 0.000 0.000 0.000 0.000
_import_tools.py:280(_format_titles)
5 0.000 0.000 0.000 0.000 ma.py:209(filled)
1 0.000 0.000 0.000 0.000 add_newdocs.py:2(?)
1 0.000 0.000 0.000 0.000
ma.py:1976(_maximum_operation)
2 0.000 0.000 0.000 0.000 ma.py:493(shape)
1 0.000 0.000 0.000 0.000
_import_tools.py:92(_get_sorted_names)
3 0.000 0.000 0.000 0.000 info.py:3(?)
6 0.000 0.000 0.000 0.000 sre_parse.py:218(isdigit)
16 0.000 0.000 0.000 0.000 _import_tools.py:258(log)
1 0.000 0.000 0.000 0.000 ufunclike.py:4(?)
59 0.000 0.000 0.000 0.000 sre_parse.py:183(__init__)
2 0.000 0.000 0.000 0.000
sre_compile.py:229(_mk_bitmap)
1 0.000 0.000 0.000 0.000 ma.py:29(MAError)
1 0.000 0.000 0.000 0.000 index_tricks.py:241(c_class)
1 0.000 0.000 0.000 0.000 auxfuncs.py:247(__init__)
1 0.000 0.000 0.000 0.000 unittest.py:78(TestResult)
1 0.000 0.000 0.000 0.000 index_tricks.py:278(ndindex)
1 0.000 0.000 0.000 0.000 fileinput.py:174(FileInput)
1 0.000 0.000 0.000 0.000 copy.py:54(Error)
2 0.000 0.000 0.000 0.000 info.py:28(?)
18 0.000 0.000 0.000 0.000
numerictypes.py:93(_evalname)
0 0.000 0.000 profile:0(profiler)
1 0.000 0.000 0.000 0.000 machar.py:8(?)
1 0.000 0.000 0.000 0.000
numpytest.py:197(SciPyTextTestRunner)
21 0.000 0.000 0.000 0.000
numerictypes.py:349(obj2sctype)
1 0.000 0.000 0.000 0.000
_import_tools.py:331(PackageLoaderDebug)
97 0.000 0.000 0.000 0.000 string.py:125(join)
1 0.000 0.000 0.210 0.210
_import_tools.py:118(__call__)
1 0.000 0.000 0.000 0.000 version.py:1(?)
349 0.000 0.000 0.000 0.000
sre_parse.py:139(__setitem__)
1 0.000 0.000 0.000 0.000 unittest.py:136(TestCase)
1 0.000 0.000 0.000 0.000 arrayprint.py:4(?)
14 0.000 0.000 0.110 0.008
_import_tools.py:236(_execcmd)
1 0.000 0.000 0.000 0.000 ma.py:499(MaskedArray)
1 0.000 0.000 0.000 0.000 stat.py:54(S_ISREG)
1 0.000 0.000 0.590 0.590 __init__.py:3(?)
2 0.000 0.000 0.000 0.000 UserDict.py:50(get)
59 0.000 0.000 0.560 0.009 sre.py:216(_compile)
1 0.000 0.000 0.000 0.000
index_tricks.py:145(concatenator)
1 0.000 0.000 0.000 0.000 unittest.py:686(TestProgram)
1 0.000 0.000 0.000 0.000 index_tricks.py:3(?)
1 0.000 0.000 0.000 0.000 utils.py:1(?)
1 0.000 0.000 0.000 0.000 oldnumeric.py:3(?)
1 0.000 0.000 0.000 0.000
index_tricks.py:250(__init__)
1 0.000 0.000 0.000 0.000 auxfuncs.py:15(?)
1 0.000 0.000 0.000 0.000 fnmatch.py:72(translate)
1 0.000 0.000 0.000 0.000
function_base.py:847(add_newdoc)
15 0.000 0.000 0.000 0.000 auxfuncs.py:393(gentitle)
2 0.000 0.000 0.000 0.000 index_tricks.py:82(__init__)
1 0.000 0.000 0.000 0.000 auxfuncs.py:243(F2PYError)
1 0.000 0.000 0.000 0.000 twodim_base.py:3(?)
8 0.000 0.000 0.000 0.000
_import_tools.py:268(_get_doc_title)
1 0.000 0.000 0.000 0.000 records.py:133(recarray)
1 0.000 0.000 0.000 0.000
defchararray.py:16(chararray)
2 0.000 0.000 0.000 0.000 oldnumeric.py:552(size)
264 0.000 0.000 0.000 0.000 sre_parse.py:80(opengroup)
[...]
More information about the NumPy-Discussion
mailing list