Re: Report on `views with many icons' profiling
On Tue, 2008-07-22 at 11:54 +0200, Tomeu Vizoso wrote: I think one can say that there's only one high-level operation: the call to _set_view in HomeBox.py; what happens as a consequence(/`parallel effect') is the firing of expose events and thus all the time that cProfile assigns to cairo and that sysprof shows in geode_drv.so. Expose is just the rendering of the cairo surface into the window. Do you know what proportion of the total time is expose? If I get it right the do_expose_event functions are taking 13.% of total time. While the function which is spending more time in cairo is do_paint_below_children of sugar/graphics/icon.py (27.6%). One thing I noted particularly is that 77% of the time of _set_view time goes to enable_xo_palette in sugar/view/home/favoritesview.py. It seems to me this last function is creating a new palette at every call (re-doing quite a bit of work scattered on various packages). I guess this can be done just once ? Yeah, _MyIcon.enable_palette() should just set a flag _palette_enabled to True. Then we should have a create_palette() method that creates the palette lazily when it is needed. Do you think this is worth doing in this release? Example: http://dev.laptop.org/git?p=sugar;a=commitdiff;h=960d90da474bb090c3905692e672301dab4cd515 For the ring layout case, all the rest looks ok to me or not worth optimizing. Can you please try to assess the impact to the user of any slowness we may have in there? --ring layout -- Perhaps we should ask the kids if they notice too much delay. I don't think so, this `transition' is much faster than those to other views. --freeform layout-- No need to ask ;) What about the mesh view? Have you seen any slowness there? You may need to connect to a jabber server in order to see enough icons. The mesh and group views use the same layout algo than the freeform view. Which are in your opinion the next steps we should take? - see if all the time in enable_xo_palette can be spared Think so, yeah. Good one. - use box2d for the freeform layout; I guess that any naive algorithm *handling* collision detection would perform worse than box2d and any non naive one (really handling collisions) isn't worth the time. Interesting, the current layout is a partial implementation of an algo devised by Eben. Would be good if he explained what the goals are on this regard and see which changes can be done that improve performance. I have some experience from when I was porting ODE to use ATLAS functions; it really is difficult to handle collision detection fastly. Thanks, Tomeu riccardo On Thu, Jul 17, 2008 at 7:43 PM, riccardo [EMAIL PROTECTED] wrote: 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,
Re: Report on `views with many icons' profiling
On Sat, 2008-07-19 at 11:49 +0200, Tomeu Vizoso wrote: This is really awesome, congrats. thanks ! I would like to know how much time takes every switch (including the redraw), is that 130ms and 170ms? Looks like it should be more to me. for the ring layout: favorite's view - list view : avg 0.15 sec list view - favorite's view : avg 0.15 sec for the freeform layout: favorite's view - list view : avg 0.16 sec list view - favorite's view : avg 0.85 sec In fact the 170ms value can be lowered but it makes very difficult to see whether both views are always redrawn or if sometimes one of the two is jumped (in the case of the freeform layout the screen is gray blank most of the time). Also, would like to see as well a top-down analysis, which are the top 3-5 high level operations that take most CPU? Are they executed more often than what would be strictly needed? I see in kcachegrind that _views_switch_...() was called 2481 times, this means that your script switched that many times? Yes, 2481 is the number of times the views were switched. I think one can say that there's only one high-level operation: the call to _set_view in HomeBox.py; what happens as a consequence(/`parallel effect') is the firing of expose events and thus all the time that cProfile assigns to cairo and that sysprof shows in geode_drv.so. One thing I noted particularly is that 77% of the time of _set_view time goes to enable_xo_palette in sugar/view/home/favoritesview.py. It seems to me this last function is creating a new palette at every call (re-doing quite a bit of work scattered on various packages). I guess this can be done just once ? For the ring layout case, all the rest looks ok to me or not worth optimizing. Can you please try to assess the impact to the user of any slowness we may have in there? --ring layout -- Perhaps we should ask the kids if they notice too much delay. I don't think so, this `transition' is much faster than those to other views. --freeform layout-- No need to ask ;) Which are in your opinion the next steps we should take? - see if all the time in enable_xo_palette can be spared - use box2d for the freeform layout; I guess that any naive algorithm *handling* collision detection would perform worse than box2d and any non naive one (really handling collisions) isn't worth the time. Thanks, Tomeu [Sorry about the late replies] :) thanks, riccardo On Thu, Jul 17, 2008 at 7:43 PM, riccardo [EMAIL PROTECTED] wrote: 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 :
Re: Report on `views with many icons' profiling
This is really awesome, congrats. I would like to know how much time takes every switch (including the redraw), is that 130ms and 170ms? Looks like it should be more to me. Also, would like to see as well a top-down analysis, which are the top 3-5 high level operations that take most CPU? Are they executed more often than what would be strictly needed? I see in kcachegrind that _views_switch_...() was called 2481 times, this means that your script switched that many times? Can you please try to assess the impact to the user of any slowness we may have in there? Which are in your opinion the next steps we should take? Thanks, Tomeu [Sorry about the late replies] On Thu, Jul 17, 2008 at 7:43 PM, riccardo [EMAIL PROTECTED] wrote: 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 ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Report on `views with many icons' profiling
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 ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
