Re: [Matplotlib-users] Some remarks/questions about perceived slowness of matplotlib

SourceForge Headquarters 225 Broadway Suite 1600 San Diego, CA 92101 +1 (858) 454-5900

John Hunter wrote:
> This is where you can help us.  Saying specgram is slow is only
> marginally more useful than saying matplotlib is slow or python is
> slow.  What is helpful is to post a complete, free-standing script
> that we can run, with some attached performance numbers.  For
> starters, just run it with the Agg backend so we can isolate
> matplotlib from the respective GUIs.  Show us how the performance
> scales with the specgram parameters (frames and samples).  specgram is
> divided into two parts (if you look at the Axes.specgram you will see
> that it calls matplotlib.mlab.specgram to do the computation and
> Axes.imshow to visualize it.  Which part is slow: the mlab.specgram
> computation or the visualizion (imshow) part or both?  You can paste
> this function into your own python file and start timing different
> parts.  The most helpful "this is slow" posts come with profiler
> output so we can see where the bottlenecks are.  
(sorry for double posting)

Ok, here we go: I believe that the rendering of the figure returned by 
imshow to be slow.

For example, let's say I have a 2 minutes signal @ 8kHz sampling-rate, 
with windows of 256 samples with 50 % overlap. I have around 64 frames / 
seconds, eg ~ 8000 frames of 256 windows.

So for benchmark purposes, we can just send random data of shape 
8000x256 to imshow. In ipython, this takes a long time (around 2 seconds 
for imshow(data), where data = random(8000, 256)).

Now, on a small script to have a better idea:

import numpy as N
import pylab as P

def generate_data_2d(fr, nwin, hop, len):
    nframes = 1.0 * fr / hop * len
    return N.random.randn(nframes, nwin)

def bench_imshow(fr, nwin, hop, len, show = True):
    data    = generate_data_2d(fr, nwin, hop, 
len)                                        
    P.imshow(data)
    if show:

P.show()                                                                         

if __name__ == '__main__':
    # 2 minutes (120 sec) of sounds @ 8 kHz with 256 samples with 50 % 
overlap
    bench_imshow(8000, 256, 128, 120, show = False)

Now, I have a problem, because I don't know how to benchmark when using 
show to True (I have to manually close the figure).

If I run the above script with time, I got 1.5 seconds with show = False 
(after several trials to be sure matplotlib files are in the system 
cache: this matters because my home dir is on NFS). If I set show = 
True, and close the figure by hand once the figure is plotted, I have 
4.5 sec instead.

If I run the above script with -dAgg --versbose-helpful (I was looking 
for this one  to check numerix is correctly set to numpy:) ):

with show = False:

matplotlib data path 
/home/david/local/lib/python2.4/site-packages/matplotlib/mpl-data
$HOME=/home/david
CONFIGDIR=/home/david/.matplotlib
loaded rc file /home/david/.matplotlib/matplotlibrc
matplotlib version 0.87.7
verbose.level helpful
interactive is False
platform is linux2
numerix numpy 1.0.2.dev3484
font search path 
['/home/david/local/lib/python2.4/site-packages/matplotlib/mpl-data']
loaded ttfcache file /home/david/.matplotlib/ttffont.cache
backend Agg version v2.2

real    0m1.185s
user    0m0.808s
sys     0m0.224s

with show = True

matplotlib data path 
/home/david/local/lib/python2.4/site-packages/matplotlib/mpl-data
$HOME=/home/david
CONFIGDIR=/home/david/.matplotlib
loaded rc file /home/david/.matplotlib/matplotlibrc
matplotlib version 0.87.7
verbose.level helpful
interactive is False
platform is linux2
numerix numpy 1.0.2.dev3484
font search path 
['/home/david/local/lib/python2.4/site-packages/matplotlib/mpl-data']
loaded ttfcache file /home/david/.matplotlib/ttffont.cache
backend Agg version v2.2

real    0m1.193s
user    0m0.848s
sys     0m0.192s

So the problem is in the rendering, right ? (Not sure to understand 
exactly what Agg backend is doing).

Now, using hotshot (kcache grind profiles attached to the email), for 
the noshow case:

       1    0.001    0.001    0.839    0.839 
slowmatplotlib.py:181(bench_imshow_noshow)
       1    0.000    0.000    0.837    0.837 
slowmatplotlib.py:163(bench_imshow)
       1    0.000    0.000    0.586    0.586 
/home/david/local/lib/python2.4/site-packages/matplotlib/pylab.py:1894(imshow) 

       3    0.000    0.000    0.510    0.170 
/home/david/local/lib/python2.4/site-packages/matplotlib/pylab.py:883(gca)
       1    0.000    0.000    0.509    0.509 
/home/david/local/lib/python2.4/site-packages/matplotlib/pylab.py:950(ishold) 

       4    0.000    0.000    0.409    0.102 
/home/david/local/lib/python2.4/site-packages/matplotlib/pylab.py:903(gcf)
       1    0.000    0.000    0.409    0.409 
/home/david/local/lib/python2.4/site-packages/matplotlib/pylab.py:818(figure) 

       1    0.000    0.000    0.408    0.408 
/home/david/local/lib/python2.4/site-packages/matplotlib/backends/backend_gtkagg.py:36(new_figure_manager) 

       1    0.003    0.003    0.400    0.400 
/home/david/local/lib/python2.4/site-packages/matplotlib/backends/backend_gtk.py:401(__init__) 

       1    0.000    0.000    0.397    0.397 
/home/david/local/lib/python2.4/site-packages/matplotlib/backends/backend_gtkagg.py:25(_get_toolbar) 

       1    0.001    0.001    0.397    0.397 
/home/david/local/lib/python2.4/site-packages/matplotlib/backends/backend_gtk.py:496(__init__) 

       1    0.000    0.000    0.396    0.396 
/home/david/local/lib/python2.4/site-packages/matplotlib/backend_bases.py:1112(__init__) 

       1    0.000    0.000    0.396    0.396 
/home/david/local/lib/python2.4/site-packages/matplotlib/backends/backend_gtk.py:557(_init_toolbar) 

       1    0.008    0.008    0.396    0.396 
/home/david/local/lib/python2.4/site-packages/matplotlib/backends/backend_gtk.py:595(_init_toolbar2_4) 

       1    0.388    0.388    0.388    0.388 
/home/david/local/lib/python2.4/site-packages/matplotlib/backends/backend_gtk.py:967(__init__) 

       1    0.251    0.251    0.251    0.251 
slowmatplotlib.py:155(generate_data_2d)
       3    0.000    0.000    0.101    0.034 
/home/david/local/lib/python2.4/site-packages/matplotlib/figure.py:629(gca)
       1    0.000    0.000    0.101    0.101 
/home/david/local/lib/python2.4/site-packages/matplotlib/figure.py:449(add_subplot) 

       1    0.000    0.000    0.100    0.100 
/home/david/local/lib/python2.4/site-packages/matplotlib/axes.py:4523(__init__) 

       1    0.000    0.000    0.100    0.100 
/home/david/local/lib/python2.4/site-packages/matplotlib/axes.py:337(__init__) 

But the show case is more interesting:

  ncalls  tottime  percall  cumtime  percall filename:lineno(function)
       1    0.002    0.002    3.886    3.886 
slowmatplotlib.py:177(bench_imshow_show)
       1    0.000    0.000    3.884    3.884 
slowmatplotlib.py:163(bench_imshow)
       1    0.698    0.698    3.003    3.003 
/home/david/local/lib/python2.4/site-packages/matplotlib/backends/backend_gtk.py:70(show) 

       2    0.000    0.000    2.266    1.133 
/home/david/local/lib/python2.4/site-packages/matplotlib/backends/backend_gtk.py:275(expose_event) 

       1    0.009    0.009    2.266    2.266 
/home/david/local/lib/python2.4/site-packages/matplotlib/backends/backend_gtkagg.py:71(_render_figure) 

       1    0.000    0.000    2.256    2.256 
/home/david/local/lib/python2.4/site-packages/matplotlib/backends/backend_agg.py:385(draw) 

       1    0.000    0.000    2.253    2.253 
/home/david/local/lib/python2.4/site-packages/matplotlib/figure.py:510(draw) 

       1    0.000    0.000    2.251    2.251 
/home/david/local/lib/python2.4/site-packages/matplotlib/axes.py:994(draw)
       1    0.005    0.005    1.951    1.951 
/home/david/local/lib/python2.4/site-packages/matplotlib/image.py:173(draw)
       1    0.096    0.096    1.946    1.946 
/home/david/local/lib/python2.4/site-packages/matplotlib/image.py:109(make_image) 

       1    0.002    0.002    1.850    1.850 
/home/david/local/lib/python2.4/site-packages/matplotlib/cm.py:50(to_rgba)
       1    0.001    0.001    0.949    0.949 
/home/david/local/lib/python2.4/site-packages/matplotlib/colors.py:735(__call__) 

       1    0.097    0.097    0.899    0.899 
/home/david/local/lib/python2.4/site-packages/matplotlib/colors.py:568(__call__) 

     325    0.050    0.000    0.671    0.002 
/home/david/local/lib/python2.4/site-packages/numpy/core/ma.py:533(__init__) 

       1    0.600    0.600    0.600    0.600 
/home/david/local/lib/python2.4/site-packages/numpy/core/fromnumeric.py:282(resize) 

       1    0.000    0.000    0.596    0.596 
/home/david/local/lib/python2.4/site-packages/matplotlib/pylab.py:1894(imshow) 

      10    0.570    0.057    0.570    0.057 
/home/david/local/lib/python2.4/site-packages/numpy/oldnumeric/functions.py:117(where) 

       3    0.000    0.000    0.513    0.171 
/home/david/local/lib/python2.4/site-packages/matplotlib/pylab.py:883(gca)
       1    0.000    0.000    0.513    0.513 
/home/david/local/lib/python2.4/site-packages/matplotlib/pylab.py:950(ishold) 

       4    0.000    0.000    0.408    0.102 
/home/david/local/lib/python2.4/site-packages/matplotlib/pylab.py:903(gcf)

For more details, see the .kc files which are the in the tbz2 archive, 
with the script for generating profiles for kcachegrind,

I will post an other email for the other problem (with several subplots)

cheers,

David