[IPython-user] Profiling the long startup time

[Ville M. Vainio]

Merry Christmas !

With that out of the way... because there have been some reports of
long startup times on windows, I added a small utility
(tools/run_ipy_in_profiler.py in SVN trunk) to see where the time is
spent. Below is my first startup (subsequent startups are of course
much faster).

What we can see here (from cumtime) is that importing Debugger.py
takes .9 secs (on athlon 64 3000+), and it probably shouldn't be done
on every startup, but rather only when requested. The code does need
some untangling though to make it lazy.

(Shell imports utraTB imports Debugger, so their long times are all
because of Debugger.py)

It would be great if you could run this test yourself and post the
results, if you are having long startup times.

The script is at:

http://ipython.scipy.org/svn/ipython/ipython/trunk/tools/run_ipy_in_profiler.py



Sun Dec 24 13:19:57 2006    ipython_profiler_results
         57019 function calls (55491 primitive calls) in 5.970 CPU seconds
   Ordered by: internal time
   List reduced from 838 to 30 due to restriction <30>
   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
       11    1.489    0.135    1.490    0.135
q:\python25\lib\site-packages\pyreadline-1.3.1.svn.dev_r1839-py2.5.egg\pyreadline\console.py:494(get)
        1    0.639    0.639    0.938    0.938
q:\ipython\IPython\iplib.py:10(<module>)
       18    0.422    0.023    3.419    0.190 {__import__}
        1    0.260    0.260    0.264    0.264
q:\python25\lib\site-packages\pydb-1.19-py2.5.egg\pydb\gdb.py:3(<module>)
        1    0.247    0.247    1.186    1.186
Q:\ipython\IPython\Shell.py:7(<module>)
        1    0.213    0.213    0.693    0.693
q:\ipython\IPython\genutils.py:8(<module>)
        1    0.201    0.201    0.894    0.894
q:\ipython\IPython\Debugger.py:18(<module>)
        1    0.195    0.195    0.587    0.587
q:\python25\lib\site-packages\pydb-1.19-py2.5.egg\pydb\pydb.py:6(<module>)
        1    0.142    0.142    0.341    0.341
q:\home\_ipython\ipy_user_conf.py:15(<module>)
        1    0.133    0.133    0.155    0.155
Q:\ipython\IPython\Magic.py:4(<module>)
        1    0.127    0.127    0.227    0.227
Q:\ipython\IPython/Extensions\ipy_system_conf.py:8(<module>)
        1    0.086    0.086    0.095    0.095
Q:\ipython\IPython/Extensions\pspersistence.py:8(<module>)
        1    0.081    0.081    0.081    0.081
q:\ipython\IPython\hooks.py:35(<module>)
        1    0.080    0.080    1.031    1.031
q:\ipython\IPython\ipmaker.py:57(make_IPython)
        1    0.068    0.068    0.146    0.146
q:\python25\lib\site-packages\pyreadline-1.3.1.svn.dev_r1839-py2.5.egg\pyreadline\rlmain.py:9(<module>)
        1    0.064    0.064    1.008    1.008
q:\ipython\IPython\ultraTB.py:63(<module>)
        1    0.064    0.064    0.065    0.065
q:\ipython\IPython\PyColorize.py:31(<module>)
        1    0.060    0.060    0.060    0.060
q:\ipython\IPython/Extensions\jobctrl.py:21(<module>)
        1    0.057    0.057    0.067    0.067
q:\python25\lib\tempfile.py:18(<module>)
        1    0.056    0.056    0.057    0.057
q:\ipython\IPython\wildcard.py:5(<module>)
        1    0.056    0.056    0.103    0.103
q:\ipython\IPython\iplib.py:1256(init_readline)
        1    0.054    0.054    0.054    0.054
q:\python25\lib\fnmatch.py:40(filter)
        1    0.053    0.053    0.125    0.125
q:\python25\lib\optparse.py:14(<module>)
       24    0.051    0.002    0.051    0.002 {nt.stat}
        1    0.048    0.048    0.061    0.061
q:\python25\lib\gettext.py:11(<module>)
        1    0.048    0.048    0.105    0.105
q:\ipython\IPython\OInspect.py:10(<module>)
        1    0.047    0.047    0.211    0.211
q:\ipython\IPython\rlineimpl.py:9(<module>)
        1    0.043    0.043    0.105    0.105
q:\home\_ipython\ipy_profile_sh.py:8(<module>)
        1    0.043    0.043    0.052    0.052
q:\ipython\IPython\iplib.py:206(__init__)
        1    0.040    0.040    0.628    0.628
q:\python25\lib\site-packages\pydb-1.19-py2.5.egg\pydb\__init__.py:2(<module>)

-- 
Ville M. Vainio - vivainio.googlepages.com
blog=360.yahoo.com/villevainio - g[mail | talk]='vivainio'