[Sugar-devel] opportunity for faster load time

[James Cameron]

I've dug further on XO-1 with os300 and Sugar-0.84.  I think the delay
you refer to is due to SVG rendering of the icons, since it correlates
to icon complexity and file size.

1.  excluding _add_activity, using a standalone test program.

import bundleregistry costs the most time, at about 1.5 seconds if
pagecache is flushed, or 1.15 seconds if not.  The get_registry call
was another 0.3 seconds on average.  The get_bundle_id,
get_activity_version and is_bundle_favorite calls were insignificant.

2.  instrumenting favoritesview.py with time.time() calls.

get_registry costs 0.16 seconds.  add_activity total costs 1.60
seconds.  I confirm your finding.  connect was insignificant.

3.  instrumenting _add_activity to measure total time by favourite
activity.  Result set below is the bundle id, the time measured, and
... the size of the icon file in bytes.

vu.lux.olpc.Speak	0.077	800
org.laptop.TamTamJam	0.120	5441
org.laptop.TamTamEdit	0.062	2672
org.laptop.MeasureActivity	0.059	1128
org.laptop.Memorize	0.049	1666
org.laptop.WebActivity	0.061	1414
org.laptop.Oficina	0.071	2045
com.garycmartin.Moon	0.104	1467
org.laptop.HelpActivity	0.047	1360
org.laptop.TamTamSynthLab	0.050	1091
edu.mit.media.ScratchActivity	0.088	3677
org.laptop.AcousticMeasure	0.073	4164
org.laptop.RecordActivity	0.041	1056
com.jotaro.ImplodeActivity	0.089	5544
org.laptop.Pippy	0.072	1399
vu.lux.olpc.Maze	0.033	791
org.laptop.TamTamMini	0.073	2733
org.laptop.Calculate	0.042	1366
org.vpri.EtoysActivity	0.070	1442
org.laptop.sugar.ReadActivity	0.056	1570
org.laptop.TurtleArtActivity	0.102	3223
org.laptop.Chat	0.049	913
org.laptop.AbiWordActivity	0.054	1648

Graphing the time against the file size suggested a correlation.

Taking the outliers (TamTamJam and TurtleArtActivity at the high end
vs Calculate and HelpActivity at the low end) and looking at these
icons, I see that the complex icons correspond to longer load times.

I suspect that much of the delay is the SVG rendering.

4.  digging deeper, instrumenting lower down, ActivityIcon is where the
time is spent.  Isolating each part of __init__ the primary and varying
cost is the call to _update.  All the other code in __init__ is under
0.02 seconds.  The call to _update ranges from 0.02 to 0.11 seconds.

What _update is doing is to assign values to stroke_color and
fill_color ... which in CanvasIcon are properties that activate
methods such as set_stroke_color and set_fill_color.

Splitting the time taken for each of these lines of _update show very
small times, and they don't add up to the time over the _update call.

Therefore something additional is happening between the end of the
ActivityIcon._refresh and ActivityIcon._update calls in
ActivityIcon.__init__.

My guess is that it is the deferred rendering of the icon by
hippocanvas.  But I don't know how to prove it.

I'm also curious about the size of the icon being set *after*
ActivityIcon instance is returned.  If rendering really is happening in
__init__, then what resolution is it happening at, and is it redone when
the size of the icon is constrained immediately after?

-- 
James Cameron
http://quozl.linux.org.au/