Report on `views with many icons' profiling

[riccardo]

Hi,

Problem: slow switching between views with many icons

Test-case: the test consist of switching between the favorites view and
the list view. Test were ran once with the ring layout in the favorite
view and once with the freeform layout; the xo had 25 activities
installed all checked as `favorite'. The action of switching was
automated with a timer with period 130ms when the ring layout was
selected and 170ms in the case of the freeform layout (as the minimum
values permitting complete redraw of the views).

Note that there is a noticeable delay when switching to the favorites
views when the selected layout is freeform.


--- RING layout ---
The following tab. and fig. show cpu time usage of the processes
taking more cpu time while running the test:

(tot% us+sy) - (partial% us+sy) : cmdline
             - 63.6             : python /usr/bin/sugar-shell
 91.2        - 27.5             : /usr/bin/X :0 -fp built-ins...
 99.5        - 8.2              : picker -t30

http://dev.laptop.org/~rlucchese/views/favorites_ring-list/picker.stats.svg
(http://dev.laptop.org/~rlucchese/views/favorites_ring-list/picker.stats )

They were obtained by running:
$ picker -t30
$ grapher -c3

--- FREEFORM layout ---
(tot% us+sy) - (partial% us+sy) : cmdline
             - 82.              : python /usr/bin/sugar-shell
 91.6        - 9.5              : /usr/bin/X :0 -fp built-ins...
 99.4        - 7.7              : picker -t30

http://dev.laptop.org/~rlucchese/views/favorites_freeform-list/picker.stats.svg
(http://dev.laptop.org/~rlucchese/views/favorites_freeform-list/picker.stats )

 ! sugar-shell is taking 20% more cpu time than in the ring layout case.



cProfile statistics (KCacheGrind format) for sugar-shell:
--- RING layout ---
http://dev.laptop.org/~rlucchese/views/favorites_ring-list/cProfile-shell

Ordering by function's self-time:
  %      func name
35.6   : cairo.Context.paint
3.9    : gtk.Container.add
2.     : sugar.graphics.palette.do_paint_below_children
1.9    : __setitem__ sugar.util
----------------------------------------------
57% 

Well, this isn't unexpected. But it's interesting when looking at
sysprof results (below).

--- FREEFORM layout ---
http://dev.laptop.org/~rlucchese/views/favorites_freeform-list/cProfile-shell

Ordering by function's self-time:
  %      func name
21.6   : _add_weight in sugar/shell/view/home/grid.py
21.5   : _remove_weight in sugar/shell/view/home/grid.py
10.6   : cairo.Context.paint
8.1    : __setitem__ sugar.util
5.7    : _compute_weight in sugar/shell/view/home/grid.py
----------------------------------------------
57.5% 

 ! Box2D would perform better ;)


Sysprof results. Well, in sysprof there are many nested levels, so it is
much more clear to just look at it.

--- RING layout ---
http://dev.laptop.org/~rlucchese/views/favorites_ring-list/sysprof.data

- most of self-time is spent in the kernel and in X/X-modules.

- time spent in the kernel is due to python and X, respectively 60%-40%.

- time spent `in X' goes mostly to the geode driver, and then, to Xorg
itself and the libexa module.


--- FREEFORM layout ---
http://dev.laptop.org/~rlucchese/views/favorites_freeform-list/sysprof.data

Notes for the ring layout are valid also here. 

There are two (new) entries in this case and they are taking more time
than the X geode module: python's numpy/core/multiarray.so and
numpy/core/umath.so. This is in relation with the algorithm used in the
freeform layout to avoid icons collisions.


thanks,
riccardo