Re: [sugar] rendering test
On Tue, 2008-09-30 at 21:30 +0200, Bernie Innocenti wrote: > Michel Dänzer wrote: > > On Sun, 2008-09-28 at 18:46 +0200, Bernie Innocenti wrote: > >> Tomeu Vizoso wrote: > >> > >>> On Sun, Sep 28, 2008 at 12:46 PM, Riccardo Lucchese > >>> <[EMAIL PROTECTED]> wrote: > >>>> On Sun, 2008-09-28 at 12:43 +0200, Riccardo Lucchese wrote: > >>>>> * build 703, xorg driver = amd, redraws = 200 > >>>>> - pixbuf: > >>>>> 98.63s > >>>>> 96.96s > >>>>> 96.58s > >>>>> 97.14s > >>>>> 99.21s > >>>>> > >>>>> * build 703, xorg driver = fbdev, redraws = 200 > >>>>> - pixbuf: > >>>>> 55.81s > >>>>> 55.40s > >>>>> 55.22s > >>>>> 55.50s > >>>>> 55.63s > >>>>> > >>>>> * build 2489, xorg driver = amd, redraws = 200 > >>>>> - pixbuf: > >>>>> 84.21s > >>>>> 84.81s > >>>>> 81.94s > >>>>> 81.79s > >>>>> 85.29s > >>>>> > >>>>> * build 2489, xorg driver = fbdev, redraws = 200 > >>>>> - pixbuf: > >>>>> 62.83s > >>>>> 62.81s > >>>>> 62.81s > >>>>> 62.66s > >>>>> 63.14s > >>>>> > >>>>> - joyride regressed sensibly at rendering with cairo since 703 > >>>>> - rendering pixbufs is extremely slow on the xo > >>>>> - server side surfaces are awesome ;) > >>>>> > >>>> and btw why is fbdev faster than the geode driver at rendering pixbufs ? > >> My performance tests with X 1.3 and 1.4 had shown that turning on EXA > >> makes many operations slower. It's hard to tell why, but it might have to > >> do with loosing XShmPut() (MIT shared memory), > > > > EXA does support XShmPutImage(), just not SHM pixmaps. > > I was remembering the code. > > As a result of ee7c684f21d, the PutImage hook in ShmFuncs is no longer > being used. Shall I commit a cleanup? > > > > Also note that the fbdev driver by default uses a shadow framebuffer in > > system RAM and only updates the visible screen contents at regular > > intervals. It might be fairer to compare with Option "ShadowFB" "off", > > at least assuming the amd driver provides other desirable features the > > fbdev driver can't provide. > > Riccardo, could you try that? > weird, testing with the ShadowFb option off slightly speeds up the test ;P avg time on 5 tries: ~57.5s (it was 62.83s) riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Re: [sugar] rendering test
On Mon, 2008-09-29 at 09:08 -0600, Jordan Crouse wrote: > On 28/09/08 18:46 +0200, Bernie Innocenti wrote: > > Tomeu Vizoso wrote: > > > Ooops. cc'ing to some other people/list in the hope someone more > > > knowledgeable than me will comment. > > > > Thanks. Please Cc me on posts like these to make sure I don't miss them. > > No, it doesn't bother me to receive 0.001% more mail. > > > > I've also Cc'd the Xorg list in case someone can give us more insight. > > > > > > > On Sun, Sep 28, 2008 at 12:46 PM, Riccardo Lucchese > > > <[EMAIL PROTECTED]> wrote: > > >> On Sun, 2008-09-28 at 12:43 +0200, Riccardo Lucchese wrote: > > >>> * build 703, xorg driver = amd, redraws = 200 > > >>> - pixbuf: > > >>> 98.63s > > >>> 96.96s > > >>> 96.58s > > >>> 97.14s > > >>> 99.21s > > >>> > > >>> * build 703, xorg driver = fbdev, redraws = 200 > > >>> - pixbuf: > > >>> 55.81s > > >>> 55.40s > > >>> 55.22s > > >>> 55.50s > > >>> 55.63s > > >>> > > >>> * build 2489, xorg driver = amd, redraws = 200 > > >>> - pixbuf: > > >>> 84.21s > > >>> 84.81s > > >>> 81.94s > > >>> 81.79s > > >>> 85.29s > > >>> > > >>> * build 2489, xorg driver = fbdev, redraws = 200 > > >>> - pixbuf: > > >>> 62.83s > > >>> 62.81s > > >>> 62.81s > > >>> 62.66s > > >>> 63.14s > > >>> > > >>> - joyride regressed sensibly at rendering with cairo since 703 > > >>> - rendering pixbufs is extremely slow on the xo > > >>> - server side surfaces are awesome ;) > > >>> > > >> and btw why is fbdev faster than the geode driver at rendering pixbufs ? > > > > Was fbdev running with EXA or XAA? (does fbdev even support EXA?) > > > > My performance tests with X 1.3 and 1.4 had shown that turning on EXA > > makes many operations slower. It's hard to tell why, but it might have to > > do with loosing XShmPut() (MIT shared memory), excessive migration of > > pixmaps to the framebuffer, and so on. X 1.5 was supposed to have a much > > better EXA, at least judging from the stream of patches landed on the tree. > > Indeed - migration is probably what is hurting us the most here. We > would probably have to do a more in-depth analysis of what is actually > happening in the engine, but the general rule of thumb is that it is very > very very very very bad to read from the video memory. > Timings with X 1.5 (I picked up the most recent package I could find on koji for fc9) don't change at all. riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Re: [sugar] rendering test
On Sun, 2008-09-28 at 18:46 +0200, Bernie Innocenti wrote: > >>> - joyride regressed sensibly at rendering with cairo since 703 > >>> - rendering pixbufs is extremely slow on the xo > >>> - server side surfaces are awesome ;) > >>> > >> and btw why is fbdev faster than the geode driver at rendering pixbufs ? > > Was fbdev running with EXA or XAA? (does fbdev even support EXA?) http://www.x.org/wiki/ExaStatus lists fbdev in the `Probably unsuitable for EXA support' section; so, I guess XAA. > My performance tests with X 1.3 and 1.4 had shown that turning on EXA > makes many operations slower. It's hard to tell why, but it might have to > do with loosing XShmPut() (MIT shared memory), excessive migration of > pixmaps to the framebuffer, and so on. X 1.5 was supposed to have a much > better EXA, at least judging from the stream of patches landed on the tree. > > I'd be very interested in seeing the output of oprofile while running your > benchmark on X 1.4 and X 1.5. Please, remember to install the debuginfo > packages for the X server, libcairo, and the geode driver. I haven't tried to run oprofile on the xo yet (it is on my todo list). If I remember well, ExaDoMoveOutPixmap (or a function with a similar name) and memcpy were always on top of sysprof profiles in rendering tests. riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Re: Stability and Memory Pressure in 8.2
Paul, On Wed, 2008-09-10 at 08:18 -0400, [EMAIL PROTECTED] wrote: > tomeu wrote: > > On Wed, Sep 10, 2008 at 2:05 PM, James Cameron <[EMAIL PROTECTED]> wrote: > > > > > Has anyone got an idea of how to measure the heap by usage? > > > > Not from outside python, but from inside we are using heapy: > > > > http://guppy-pe.sourceforge.net/ > > i started down that path yesterday afternoon, and realized that it > wasn't clear to me how i needed to invoke it. it seems to want > to be imported before you start the rest of your program, which > sort of forces you into interactive mode. is that your understanding? > i had been hoping to be able to "attach" to the sugar shell process, > in the way one might do with gdb. perhaps that's not possible. > There is kick-start tutorial on how to use heapy's remote monitor at the 56th page of http://guppy-pe.sourceforge.net/heapy-thesis.pdf For the shell I use to put `import guppy.heapy.RM' before any other import statement in main.py. riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Re: Stability and Memory Pressure in 8.2
On Wed, 2008-09-10 at 09:15 +0200, Marco Pesenti Gritti wrote: > On Wed, Sep 10, 2008 at 4:29 AM, Gary C Martin <[EMAIL PROTECTED]> wrote: > > > > OK, news is not great on the Activity front... > > > > SUMMARY: 759 vs 711 each Activity instance in 759 consumes an average > > of 1Mb more memory than the same Activity running in 711, with > > Write-57 reportedly taking significantly more than that (perhaps ~7Mb). > > > > Is top and/or ps memory usage calculated in the same way between these > > builds? Could make collecting real data pretty painful. > > Unfortunately not, there has been changes in the kernel. My > understanding is that private memory will be the same, while > calculation of shared memory has changed. Riccardo has a new kernel > somewhere with instructions on how to install it on 711. That should > make the memory usage comparable. > > Marco I used this newer kernel (as it accounts also for pss) for measurements with ps_mem on build 703: http://dev.laptop.org/~rlucchese/utils/703/kernel-2.6.25-20080501.3.olpc.231c7b715f4a8d0.i586.rpm It can be installed on the xo with: $ rpm -ivh kernel-rpm $ cp -a /boot/* /versions/boot/current/boot/ You will also have to update the ram disk image; you can follow the instructions at the bottom of http://wiki.laptop.org/go/Kernel_Building You may also want to try this patched ps_mem (shows pids and doesn't group entries by process name): http://dev.laptop.org/~rlucchese/utils/ps_mem.py riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Re: Stability and Memory Pressure in 8.2
On Tue, 2008-09-09 at 00:10 -0400, Michael Stone wrote: > Dear devel@, > > Kim, Greg, and I have concluded that the instability we experience under > memory-pressure in 8.2-759 and similar is the single "hard" issue that > we wish to _attempt_ to address before releasing 8.2 on current > timeframes. (We recognize that there are several other issues marked > as blocking the release but we are confident that they will be resolved > satisfactorily or are, in a few cases, beyond help.) > > Since most other aspects of the release seem to be running smoothly, Kim > asked me to take a more direct role in organizing our efforts produce a > release which avoids memory pressure when possible and which is > better-behaved when it strikes. > > To that end, I would like to ask for your assistance with the following > questions and tasks: > > * We need to determine why we encounter low-memory and out-of-memory > situations more frequently than in previous releases. > > - This means that we need to measure how our memory consumption > profile has changed since our previous releases. > > (cscott observes that we were unable to attack the F-9 image size > issues until we were able to quantify the effect of changes we had > made or were considering making. Consequently, he suggests that we > will be unable to attack our current space consumption problems > until we are able to generate good numbers (and displays).) > > - We need to think carefully about (or measure) whether our > memory-consumption patterns have changed. I am particularly > skeptical of our widespread use of tmpfsen since the pages consumed > by files stored on tmpfsen are permanently dirty (and are perhaps > accounted for differently than pages mapped into process' address > spaces?) > > - We need to check the configuration of applications like Browse > which have configurable caching behavior. (Search for "cache" or > "capacity" in about:config; check for important compile-time > configuration flags.) > > - We need to test in a variety of different network configurations > in order to determine to what extent the network/presence > environment affects memory consumption. > > * We need to check carefully for memory-leaks. Three mechanisms which > occur to me include: > > 1) running the system for a period of time, then scanning for > anomalies either manually or in some automated fashion from > userland, kernel-land, or OFW (via SysRq or SMM). > > 2) setting rlimits various processes and noting what dies > > 3) using debugging tools like the python garbage collection > module, guppy/heapy, gdb+macros, valgrind, efence, purify, etc. > looking for trouble. > > * We need to find out why the oom-killer is not killing things fast > enough. Based on our results, we might consider configuring > /proc/$pid/oom_adj to preferentially kill some processes (e.g., the > foreground [or background?] activities.) > > * We need to determine whether the oom-killer is killing the right > processes. (sysctl's vm.oom_dump_tasks can be set to 1 in order to > get more verbosity from the oom-killer when it fires). > > * We ought to ponder whether there are any additional "dirty hacks" we > can experiment with in order to reduce memory consumption; for > example, running the Shell and Journal (and DS?) in one process or > making use of the compressed-caching code published on this list some > months ago. > > * Random other stuff to think about: > > - rlimits, cgroups, and the memory resource controller > > - the warnings in the ramfs and tmpfs code about the deadlocks that > tmpfsen can generate under low- or no-memory conditions. > > - whether our kernel "overcommits" when allocation requests are made? > > - whether we can get Browse to behave intelligently when it receives > BadAlloc errors from X? > > - how to run bootchart on the XO > > - how to generate decent statistics and graphics (preferably in an > automated fashion) concerning memory usage as part of our test > suite > > - system-tap's kmalloc2.stp example > > In conclusion, more to come once I have some actual data; _please_ feel > free to assist in collecting it! (though be aware that I may 'volunteer' > you if I need your help. (That means you, Tomeu, Riccardo, Deepak, > ...)). > > Regards, > > Michael There are
Re: Almost 50% less free memory in joyride-2302 compared with Update.1 (708)
On Sat, 2008-08-23 at 21:31 +1000, James Cameron wrote:
> On Sat, Aug 23, 2008 at 12:01:07PM +0200, Marco Pesenti Gritti wrote:
> > On Fri, Aug 22, 2008 at 1:47 PM, James Cameron <[EMAIL PROTECTED]>
> wrote:
< ... >
> > Btw it's a shame that the python processes are grouped all together. I
> > wonder if we can fix ps_mem to show them separately, with the full
> > command.
>
> I agree.
>
The attached patch makes ps_mem show the process cmdline instead of its
name; it doesn't account for the /proc/[pid]/cmdline particular format
but output it's well readable.
riccardo
--- ps_mem.orig 2008-07-22 08:00:58.0 +0200
+++ ps_mem 2008-08-25 10:01:35.0 +0200
@@ -117,14 +117,16 @@
return (Private, Shared)
def getCmdName(pid):
-cmd = file("/proc/%d/status" % pid).readline()[6:-1]
-exe = os.path.basename(os.path.realpath("/proc/%d/exe" % pid))
-if exe.startswith(cmd):
-cmd=exe #show non truncated version
-#Note because we show the non truncated name
-#one can have separated programs as follows:
-#584.0 KiB + 1.0 MiB = 1.6 MiBmozilla-thunder (exe -> bash)
-# 56.0 MiB + 22.2 MiB = 78.2 MiBmozilla-thunderbird-bin
+cmd = file("/proc/%d/cmdline" % pid).readline()[:60]
+if not len(cmd):
+cmd = file("/proc/%d/status" % pid).readline()[6:-1]
+exe = os.path.basename(os.path.realpath("/proc/%d/exe" % pid))
+if exe.startswith(cmd):
+cmd=exe #show non truncated version
+#Note because we show the non truncated name
+#one can have separated programs as follows:
+#584.0 KiB + 1.0 MiB = 1.6 MiBmozilla-thunder (exe -> bash)
+# 56.0 MiB + 22.2 MiB = 78.2 MiBmozilla-thunderbird-bin
return cmd
cmds={}
___
Devel mailing list
Devel@lists.laptop.org
http://lists.laptop.org/listinfo/devel
Re: Rainbow cpu load when launching an activity?
Hi Gary On Fri, 2008-08-15 at 23:18 +0100, Gary C Martin wrote: > Hi Michael, > > On 15 Aug 2008, at 21:58, Michael Stone wrote: > > > On Fri, Aug 15, 2008 at 07:31:28PM +0100, Gary C Martin wrote: > >> I was curious to see (when testing in joyride-2301) that rainbow > >> (python /usr/sbin/rainbow-daemon) seems to be the process that's > >> eating the most CPU cycles during an activity launch. > > > > Well, rainbow does a little bit of work in order to make a new user, > > then it hands over control to the activity. Since we know that > > activity > > launching is already slow (hence the need for the module preloading > > hack), it's not very surprising to me to that you see it chewing CPU > > when launching activities. > > > > Feel free to profile, though; I'd certainly like to know it if I'm > > doing > > something truly idiotic. (Or if people are using rainbow in > > environments > > significantly different from my own.) > > Thanks, OK. I'm not exactly fully clued up on profiling such internals > but I'll look at instrumenting interesting points of your rainbow > source code on a running XO, and seeing if I have something useful to > report. Please don't let that put off anyone else more qualified from > looking. > Processes spawned by rainbow get their cmdline copied over from rainbow's one. So I think what you are seeing is that the *launched activity* is taking more cpu time than the journal and the shell. The following graph shows browse startup (pid 3612): http://dev.laptop.org/~rlucchese/temp__browse_warm.svg riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Re: Journal activity profiling
On Wed, 2008-08-13 at 18:02 +0200, Tomeu Vizoso wrote: > On Wed, Aug 13, 2008 at 5:20 PM, riccardo <[EMAIL PROTECTED]> wrote: > > On Wed, 2008-08-13 at 12:13 +0200, Tomeu Vizoso wrote: > >> On Tue, Aug 12, 2008 at 12:10 PM, riccardo <[EMAIL PROTECTED]> wrote: > >> > < ... > > >> > I find interesting to note that 28.5% of the total time goes to > >> > `get_date' of Journal.activity/misc.py because of the ngettext overhead. > >> > Perhaps translations could be cached ? > >> > >> Totally, but caching should already happen inside python's gettext: > >> > >> http://svn.python.org/view/python/tags/r251/Lib/gettext.py?rev=54864&view=markup > >> > >> If that isn't working for any reason, we would need to cache it > >> locally in sugar.util. Can you check it is slow in Spanish as well? > >> You may have found a very nice low hanging fruit ;) > > > > I can see similar percentages with spanish (perù) translations ;) > > > > Note that only the comboboxes entries get translated, the timestamp gets > > always shown in english. > > Ouch, that's bad. What I think it's going on is that missing > translations are not cached, so any missing translation will go all > the way down again and again. > > We need to check why we are not picking up the translations. Can you > enter a ticket for 8.2.0 and make it a blocker? Would be nice if you > can already tell where's the problem - and a patch would be awesome ;) > Translations seem to be cached to me; I think the point is that for every translation gettext.py searches new mo files. riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Re: Journal activity profiling
On Wed, 2008-08-13 at 12:13 +0200, Tomeu Vizoso wrote: > On Tue, Aug 12, 2008 at 12:10 PM, riccardo <[EMAIL PROTECTED]> wrote: > > Hi! > > > > Testcase: > > Fill the journal with hundreds of entries and automate the > > GtkScrollWindow in the journal to scroll one entry at time on a timeout. > > > > Build: joyride-2281 > > The test runs slower when the journal has more entries than when it's > > almost empty, why is it ? > > Not sure, perhaps because there are more entries in the DS so the > query takes more time? Can you check? I cannot reproduce it by just adding more objects to the DS. I think I had `particular' objs in the journal when I saw it: ie. if I only push .xo packages to the DS the journal scrolls very slowly (after activities get installed) > > > > I find interesting to note that 28.5% of the total time goes to > > `get_date' of Journal.activity/misc.py because of the ngettext overhead. > > Perhaps translations could be cached ? > > Totally, but caching should already happen inside python's gettext: > > http://svn.python.org/view/python/tags/r251/Lib/gettext.py?rev=54864&view=markup > > If that isn't working for any reason, we would need to cache it > locally in sugar.util. Can you check it is slow in Spanish as well? > You may have found a very nice low hanging fruit ;) I can see similar percentages with spanish (perù) translations ;) Note that only the comboboxes entries get translated, the timestamp gets always shown in english. Thanks, riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Re: Datastore profiling
On Wed, 2008-08-13 at 11:41 +0200, Tomeu Vizoso wrote: < ... > > It is updating the "what" combobox in the toolbar, see > SearchToolbar.refresh_filters(). > > This of course could be optimized in the same way that the list view > update is, by only refreshing once the journal comes visible again. To > check if this is worth doing, I'd do manually the user action you are > trying to make faster with and without refresh_filters() being called > and would check if there's a significant difference. Commenting the call to refresh_filters() makes the journal take only around 3% of the cpu. < ...> > We already have a cache for svg icons, but in this case s.g.combobox > is using a gtk.CellRendererPixbuf which doesn't use s.g.icon. We > should probably do our CellRenderer that uses s.g.icon, this would > give us colored icons, badges, etc. Good catch! yeah, most of the time in refresh_filters() goes to icons rendering. > Thanks, > > Tomeu ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Re: Datastore profiling
On Wed, 2008-08-13 at 12:18 +0200, Tomeu Vizoso wrote: > On Wed, Aug 13, 2008 at 12:10 PM, riccardo <[EMAIL PROTECTED]> wrote: > > On Wed, 2008-08-13 at 11:41 +0200, Tomeu Vizoso wrote: > >> On Sat, Aug 9, 2008 at 3:30 PM, riccardo <[EMAIL PROTECTED]> wrote: > >> > + Sysprof statistics: > >> > http://dev.laptop.org/~rlucchese/datastore_fill/small_files__b2000.sysprof > >> > > >> > I can't see anything relevant for libxapian and it's bindings (xapian > >> > dbg packages were installed) > >> > >> Perhaps because of the small amount of metadata? PROPS_WITH_PREVIEW in > >> http://dev.laptop.org/git?p=projects/datastore;a=blob;f=tests/test_sugar.py > >> would get you quite close to the real case. > > yeah, perhaps it makes sense to add more metadata also for the journal > > scrolling test ? > I repeated the test adding more metadata as you suggested: --- transfer_ownership = False --- test duration: ~164.9s --- transfer_ownership = True --- test duration: ~115.3s timings values are quite stable over a few tests riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Re: Journal activity profiling
On Wed, 2008-08-13 at 13:11 +0200, riccardo wrote: > On Wed, 2008-08-13 at 12:13 +0200, Tomeu Vizoso wrote: > > On Tue, Aug 12, 2008 at 12:10 PM, riccardo <[EMAIL PROTECTED]> wrote: < ... > > > > > Yeah, we should be much smarter about that. Right now, we cache three > > screens worth of DS entries so we reduce the frequency with which we > > call the DS. But we redraw the whole screen at every scroll. > > > Do you have any idea for redrawing less often? > what do you mean ? > mm the listview seems reasonably fast at drawing its entries, why so much defference ? thanks riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Re: Journal activity profiling
On Wed, 2008-08-13 at 12:13 +0200, Tomeu Vizoso wrote: > On Tue, Aug 12, 2008 at 12:10 PM, riccardo <[EMAIL PROTECTED]> wrote: > > Hi! > > > > Testcase: > > Fill the journal with hundreds of entries and automate the > > GtkScrollWindow in the journal to scroll one entry at time on a timeout. > > > > Build: joyride-2281 > > > > > > > > + Macro investigation of cpu usage > > A picker graph taken during the test can be found at: > > http://dev.laptop.org/~rlucchese/journal_scrolling/journal_scrolling.picker.svg > > (http://dev.laptop.org/~rlucchese/journal_scrolling/journal_scrolling.picker) > > > > The following tab shows cpu usage of the 4 processes that took more cpu > > time during the sampling time: > > ($ grapher -c4 -n -r cpu -i journal_scrolling.picker) > > > > tot% ps% cmdline > > --- > >68.2python /usr/bin/sugar-activity journalactivity... > > 88.6 20.4/usr/bin/X :0 -fp built-ins -wr ... > > 94.3 5.7 picker > > 99.5 5.2 python /usr/bin/datastore-service > > > > >From the interactions with X it seems the journal activity spends a > > sensible amount of time redrawing its entries. > > Yeah, we should be much smarter about that. Right now, we cache three > screens worth of DS entries so we reduce the frequency with which we > call the DS. But we redraw the whole screen at every scroll. > Do you have any idea for redrawing less often? what do you mean ? > > > The test runs slower when the journal has more entries than when it's > > almost empty, why is it ? > > Not sure, perhaps because there are more entries in the DS so the > query takes more time? Can you check? ok > > > + cProfile statistics (KCG format) for the journal activity: > > http://dev.laptop.org/~rlucchese/journal_scrolling/journal_scrolling.cProfile > > > > functions ordered by self-time: > > 17.2 gtk.main() > > 16.5 cairo.Context.paint() > > 4.find in gettext.py > > 3.9 set._jobject of Journal.activity/collapsedentry.py::228 > > 2.9 built-in method do_size_allocate > > 2.9 _expand_lang gettext.py > > 2.8 join in posixpath.py > > 2.6 posix.stat() > > 2.1 _update_color of Journal.activity/collapsedentry.py > > 1.7 normalize in locale. py > > 1.6 exists in posix.path.py > > 1.5 set._jobject of Journal.activity/collapsedentry.py::323 > > -- > > 59.8% > > > > I find interesting to note that 28.5% of the total time goes to > > `get_date' of Journal.activity/misc.py because of the ngettext overhead. > > Perhaps translations could be cached ? > > Totally, but caching should already happen inside python's gettext: > > http://svn.python.org/view/python/tags/r251/Lib/gettext.py?rev=54864&view=markup from cProfile one can see every call to gettext.translation(..) always calls gettex.find() and spends there most of the time. Looking at the source, and if I'm not missing anything, the call to `find' isn't conditioned and the call-parameter 'languages' always defaults to None thus activating the logic to `reload' all languages. > > If that isn't working for any reason, we would need to cache it > locally in sugar.util. Can you check it is slow in Spanish as well? > You may have found a very nice low hanging fruit ;) ok > > > + Sysprof statistics: > > http://dev.laptop.org/~rlucchese/journal_scrolling/journal_scrolling.sysprof > > > > Not very interesting this time. > > Yeah, no C-level function takes an absurd amount of time. It's python > code that makes too much work than is really needed. > > Thanks, > > Tomeu riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Re: Datastore profiling
On Wed, 2008-08-13 at 11:41 +0200, Tomeu Vizoso wrote: > On Sat, Aug 9, 2008 at 3:30 PM, riccardo <[EMAIL PROTECTED]> wrote: > > Hi, > > > > > > Testcase: > > Fill the datastore with `many small' objects. > > Which user-perceived action are you investigating? I thought the datastore is one of the `components' we wanted to profile. This was straightforward after writing the script that populates the DS that I wanted to use to profile the journal. > > > The test was automated with the script at: > > http://dev.laptop.org/~rlucchese/datastore_fill/fill_ds > > Why the need to restart sugar? I only send one signal to the DS (to stop and exit); in fact it can be done also without restarting sugar and sending a `start' signal to the process (so that the profiler gets enabled) > > > For this test only the _TEST_SMALL_FILES flag was set in `fill_ds' and > > the following cmdline was used: > > $ fill_ds -s sources/ -b 2000 > > In most cases, the files that activities put into the DS are moved > instead of copied, because of the long time that takes writing to > jffs2 due to compression. That will change the profiling results a > lot. > > For that, call datastore.write() with transfer_ownership=True. > > > The `sources' dir I used can be found at: > > http://dev.laptop.org/~rlucchese/datastore_fill/sources/ > > > > Before running the script all entries in the datastore were deleted. > > > > > > > > + Macro investigation of cpu usage > > A picker graph taken during the test can be found at: > > http://dev.laptop.org/~rlucchese/datastore_fill/small_files__b2000.picker.svg > > (http://dev.laptop.org/~rlucchese/datastore_fill/small_files__b2000.picker) > > > > The following tab shows cpu usage of the 3 processes that took more cpu > > time during the sampling time: > > ($ grapher -c2 -n -r cpu -i small_files__b2000.picker) > > > > tot% ps% cmdline > > --- > >55.0python /usr/bin/datastore-service > > 86.7 31.7python /usr/bin/sugar-activity > > journalactivity.JournalActivity - > > > > During the test the `favorites view' was shown and I think I was told > > the journal shouldn't take cpu time to update itself in this case. What > > is it doing than ? > > It is updating the "what" combobox in the toolbar, see > SearchToolbar.refresh_filters(). > > This of course could be optimized in the same way that the list view > update is, by only refreshing once the journal comes visible again. To > check if this is worth doing, I'd do manually the user action you are > trying to make faster with and without refresh_filters() being called > and would check if there's a significant difference. > > > + Test log > > http://dev.laptop.org/~rlucchese/datastore_fill/small_files__b2000.log > > > > It took 123+ seconds to fill the datastore with 484 files (total size > > 20041624 bytes; files pushed to the datastore where text_s.txt, > > text_s.odt and img_s.jpg from the sources dir linked above). The 123s > > value is very stable when repeating the test. > > > > > > > > + cProfile statistics (KCG format) for the datastore: > > http://dev.laptop.org/~rlucchese/datastore_fill/small_files__b2000.cProfile > > > > * functions ordered by self-time: > > 23.8 posix.write > > 16.8 send_message of _dbus_bindings.Connection > > 9.6 _database_gen_allterms_iter of xapian.py > > 4.2 flush of secore/indexerconnection.py > > 2.6 add of secore/indexerconnection.py > > 2.3 cPickle.dumps > > 2.perform of secore/fieldactions.py > > 1.7 _act_index_freetext of secore/fieldactions.py > > 1.6 index of datastore/xapianindex.py > > > > 64.6% > > > > I/O performance and dbus are predominant in results. > > As I said, I'm not sure the journal should be so `active' during the > > test; in the case it would be more interesting to repeat the test after > > a fix. > > Not sure yet if the journal optimization should be done (depends on > the result of the test suggested above) but we surely should repeat > the test with transfer_ownership=True. Automatic compression in jffs2 > is going to be much slower than anything else. ok > > > + Sysprof statistics: > > http://dev.laptop.org/~rlucchese/datastore_fill/small_files__b2000.sysprof > > > > I can't see anything relevant for libxapian and it's bindings (xapian > > d
Journal activity profiling
Hi! Testcase: Fill the journal with hundreds of entries and automate the GtkScrollWindow in the journal to scroll one entry at time on a timeout. Build: joyride-2281 + Macro investigation of cpu usage A picker graph taken during the test can be found at: http://dev.laptop.org/~rlucchese/journal_scrolling/journal_scrolling.picker.svg (http://dev.laptop.org/~rlucchese/journal_scrolling/journal_scrolling.picker) The following tab shows cpu usage of the 4 processes that took more cpu time during the sampling time: ($ grapher -c4 -n -r cpu -i journal_scrolling.picker) tot% ps% cmdline --- 68.2python /usr/bin/sugar-activity journalactivity... 88.6 20.4/usr/bin/X :0 -fp built-ins -wr ... 94.3 5.7 picker 99.5 5.2 python /usr/bin/datastore-service >From the interactions with X it seems the journal activity spends a sensible amount of time redrawing its entries. The test runs slower when the journal has more entries than when it's almost empty, why is it ? + cProfile statistics (KCG format) for the journal activity: http://dev.laptop.org/~rlucchese/journal_scrolling/journal_scrolling.cProfile functions ordered by self-time: 17.2 gtk.main() 16.5 cairo.Context.paint() 4.find in gettext.py 3.9 set._jobject of Journal.activity/collapsedentry.py::228 2.9 built-in method do_size_allocate 2.9 _expand_lang gettext.py 2.8 join in posixpath.py 2.6 posix.stat() 2.1 _update_color of Journal.activity/collapsedentry.py 1.7 normalize in locale. py 1.6 exists in posix.path.py 1.5 set._jobject of Journal.activity/collapsedentry.py::323 -- 59.8% I find interesting to note that 28.5% of the total time goes to `get_date' of Journal.activity/misc.py because of the ngettext overhead. Perhaps translations could be cached ? + Sysprof statistics: http://dev.laptop.org/~rlucchese/journal_scrolling/journal_scrolling.sysprof Not very interesting this time. Thanks, riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Re: Datastore profiling
On Sat, 2008-08-09 at 15:30 +0200, riccardo wrote:
> Hi,
>
>
> Testcase:
> Fill the datastore with `many small' objects.
>
> Build: 2266
< ... >
>
>
> + Sysprof statistics:
> http://dev.laptop.org/~rlucchese/datastore_fill/small_files__b2000.sysprof
>
> I can't see anything relevant for libxapian and it's bindings (xapian
> dbg packages were installed)
>
> Quite a bit of time goes to librsvg functions rendering svg icons to
> GtkPixbufs. Attaching strace to the journal activity and grepping "open"
> on its output gives:
> <
> ...
> open("/usr/share/icons/sugar/scalable/mimetypes/text-x-generic.svg",
> O_RDONLY|O_LARGEFILE) = 11
> open("/usr/share/icons/sugar/scalable/mimetypes/image-x-generic.svg",
> O_RDONLY|O_LARGEFILE) = 11
> open("/usr/share/icons/sugar/scalable/mimetypes/audio-x-generic.svg",
> O_RDONLY|O_LARGEFILE) = 11
> open("/usr/share/icons/sugar/scalable/mimetypes/video-x-generic.svg",
> O_RDONLY|O_LARGEFILE) = 11
> open("/usr/share/icons/sugar/scalable/mimetypes/text-uri-list.svg",
> O_RDONLY|O_LARGEFILE) = 11
> open("/usr/share/icons/sugar/scalable/mimetypes/text-x-generic.svg",
> O_RDONLY|O_LARGEFILE) = 11
> open("/usr/share/icons/sugar/scalable/mimetypes/image-x-generic.svg",
> O_RDONLY|O_LARGEFILE) = 11
> open("/usr/share/icons/sugar/scalable/mimetypes/audio-x-generic.svg",
> O_RDONLY|O_LARGEFILE) = 11
> open("/usr/share/icons/sugar/scalable/mimetypes/video-x-generic.svg",
> O_RDONLY|O_LARGEFILE) = 11
> ...
> >
>
> Does this come from sugar.mime or any sugar component ?
> If yes, would it be possible to share one icon-cache between all sugar
> modules ?
>
I repeated the test to get cProfile statistics for the journal
activity:
http://dev.laptop.org/~rlucchese/datastore_fill/cProfile_journal_while_filling_ds
98.4% of the total time goes to __data_store_created_cb.
Perhaps this function could only set a flag and delay data retrieval
(from the DS) to the next time the journal's window is shown?
Riccardo
___
Devel mailing list
Devel@lists.laptop.org
http://lists.laptop.org/listinfo/devel
Datastore profiling
Hi,
Testcase:
Fill the datastore with `many small' objects.
Build: 2266
The test was automated with the script at:
http://dev.laptop.org/~rlucchese/datastore_fill/fill_ds
For this test only the _TEST_SMALL_FILES flag was set in `fill_ds' and
the following cmdline was used:
$ fill_ds -s sources/ -b 2000
The `sources' dir I used can be found at:
http://dev.laptop.org/~rlucchese/datastore_fill/sources/
Before running the script all entries in the datastore were deleted.
+ Macro investigation of cpu usage
A picker graph taken during the test can be found at:
http://dev.laptop.org/~rlucchese/datastore_fill/small_files__b2000.picker.svg
(http://dev.laptop.org/~rlucchese/datastore_fill/small_files__b2000.picker)
The following tab shows cpu usage of the 3 processes that took more cpu
time during the sampling time:
($ grapher -c2 -n -r cpu -i small_files__b2000.picker)
tot% ps% cmdline
---
55.0python /usr/bin/datastore-service
86.7 31.7python /usr/bin/sugar-activity
journalactivity.JournalActivity -
During the test the `favorites view' was shown and I think I was told
the journal shouldn't take cpu time to update itself in this case. What
is it doing than ?
+ Test log
http://dev.laptop.org/~rlucchese/datastore_fill/small_files__b2000.log
It took 123+ seconds to fill the datastore with 484 files (total size
20041624 bytes; files pushed to the datastore where text_s.txt,
text_s.odt and img_s.jpg from the sources dir linked above). The 123s
value is very stable when repeating the test.
+ cProfile statistics (KCG format) for the datastore:
http://dev.laptop.org/~rlucchese/datastore_fill/small_files__b2000.cProfile
* functions ordered by self-time:
23.8 posix.write
16.8 send_message of _dbus_bindings.Connection
9.6 _database_gen_allterms_iter of xapian.py
4.2 flush of secore/indexerconnection.py
2.6 add of secore/indexerconnection.py
2.3 cPickle.dumps
2.perform of secore/fieldactions.py
1.7 _act_index_freetext of secore/fieldactions.py
1.6 index of datastore/xapianindex.py
64.6%
I/O performance and dbus are predominant in results.
As I said, I'm not sure the journal should be so `active' during the
test; in the case it would be more interesting to repeat the test after
a fix.
+ Sysprof statistics:
http://dev.laptop.org/~rlucchese/datastore_fill/small_files__b2000.sysprof
I can't see anything relevant for libxapian and it's bindings (xapian
dbg packages were installed)
Quite a bit of time goes to librsvg functions rendering svg icons to
GtkPixbufs. Attaching strace to the journal activity and grepping "open"
on its output gives:
<
...
open("/usr/share/icons/sugar/scalable/mimetypes/text-x-generic.svg",
O_RDONLY|O_LARGEFILE) = 11
open("/usr/share/icons/sugar/scalable/mimetypes/image-x-generic.svg",
O_RDONLY|O_LARGEFILE) = 11
open("/usr/share/icons/sugar/scalable/mimetypes/audio-x-generic.svg",
O_RDONLY|O_LARGEFILE) = 11
open("/usr/share/icons/sugar/scalable/mimetypes/video-x-generic.svg",
O_RDONLY|O_LARGEFILE) = 11
open("/usr/share/icons/sugar/scalable/mimetypes/text-uri-list.svg",
O_RDONLY|O_LARGEFILE) = 11
open("/usr/share/icons/sugar/scalable/mimetypes/text-x-generic.svg",
O_RDONLY|O_LARGEFILE) = 11
open("/usr/share/icons/sugar/scalable/mimetypes/image-x-generic.svg",
O_RDONLY|O_LARGEFILE) = 11
open("/usr/share/icons/sugar/scalable/mimetypes/audio-x-generic.svg",
O_RDONLY|O_LARGEFILE) = 11
open("/usr/share/icons/sugar/scalable/mimetypes/video-x-generic.svg",
O_RDONLY|O_LARGEFILE) = 11
...
>
Does this come from sugar.mime or any sugar component ?
If yes, would it be possible to share one icon-cache between all sugar
modules ?
Thanks,
riccardo
___
Devel mailing list
Devel@lists.laptop.org
http://lists.laptop.org/listinfo/devel
Icon rendering perfs comparison between builds 703 and joyride-2230
sreload__.picker) ($ grapher -c3 -n -r cpu -i \ 0703_icon_rendering__switch__alwaysreload__.picker) tot% ps% cmdline --- 88.0python /usr/bin/sugar-shell 96.6 8.6 picker 99.9 3.3 /usr/bin/X :0 -fp built-ins -wr ... + Redraw timings `do_expose_event' timings aren't very interesting here because different svg files take different times to be rendered to a cairo surface (log snippet at http://dev.laptop.org/~rlucchese/icon_rendering/2230_icon_rendering__switch__alwaysreload__sugar-shell.log) (log snippet at http://dev.laptop.org/~rlucchese/icon_rendering/0703_icon_rendering__switch__alwaysreload__sugar-shell.log) 2230 test duration : ~535.14s 703 test duration : ~537.4s + cProfile statistics (KCG format) for sugar-shell: Not very interesting for this testcase. Just note that cairo.Context.paint() is slightly slower (takes more time during the test) on build 2230. http://dev.laptop.org/~rlucchese/icon_rendering/2230_icon_rendering__switch__alwaysreload__sugar-shell.cProfile http://dev.laptop.org/~rlucchese/icon_rendering/0703_icon_rendering__switch__alwaysreload__sugar-shell.cProfile + Sysprof statistics: Not very interesting for this test case. (http://dev.laptop.org/~rlucchese/icon_rendering/2230_icon_rendering__switch__alwaysreload__.sysprof) (http://dev.laptop.org/~rlucchese/icon_rendering/0703_icon_rendering__switch__alwaysreload__.sysprof) Testcase 3: We measure rendering performance when drawing on an hippo.Canvas in build 2230 (only). This is done by adding 20 `computer-xo' icons to the friends view and automating the view's redraw. Patches: http://dev.laptop.org/~rlucchese/icon_rendering/patch_2230_friendsbox http://dev.laptop.org/~rlucchese/icon_rendering/patch_2230_friendsbox_test_homewindow The friends-view was redrawn 1 times during the test. + Macro investigation of cpu usage --- 2230 --- http://dev.laptop.org/~rlucchese/icon_rendering/2230_icon_rendering__friendsbox__.picker.svg (http://dev.laptop.org/~rlucchese/icon_rendering/2230_icon_rendering__friendsbox__.picker) ($ grapher -c3 -n -r cpu -i \ 2230_icon_rendering__friendsbox__.picker.svg) tot% ps% cmdline --- 47.9python /usr/bin/sugar-shell 92.0 44.2/usr/bin/X :0 -fp built-ins -wr ... 99.7 7.6 picker + cProfile statistics (KCG format) for sugar-shell: --- 2230 --- http://dev.laptop.org/~rlucchese/icon_rendering/2230_icon_rendering__friendsbox__sugar-shell.cProfile What we are interested in is the time spent in the function do_paint_below_children of sugar/graphics/icon.py: 77.5% of its time goes to cairo.Context.paint() while 14.7% of it goes get_surface (in class Icon). Where does get_surface spends its time ? 63.4 __getitem__ of sugar/util.py 7.4 _get_cache_key of sugar/graphics/icon.py 6.5 __contains__ sugar/graphics/util.py ! The LRU is using a dictionary to store entries I'm not sure of what the LRU does here: used for animations? for cpu-cache friendliness? + sysprof statistics: --- 2230 --- http://dev.laptop.org/~rlucchese/icon_rendering/2230_icon_rendering__friendsbox__.sysprof Comments to sysprof results for testcase #1 are `valid' also here. Also note that of all the time spent in libhippocanvas because of expose events only its 22.2% goes to cairo_paint(): python overhead is not negligible for this task. thanks, riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Re: sugar start-up profiling
On Fri, 2008-08-01 at 10:41 -0400, Eben Eliason wrote: > > On Fri, Aug 1, 2008 at 10:29 AM, Erik Garrison <[EMAIL PROTECTED]> > wrote: > On Fri, Aug 01, 2008 at 10:19:50AM -0400, Eben Eliason wrote: > > Another potentially interesting solution is a pseudo-spring > algorithm, by > > which we detect some numbers of neighbors (O(n)) and then we > "push" those > > neighbors away with some force vector, the magnitude of > which is weighted > > based on the size of the nodes, and the direction of which > is calculated as > > the angle between them. This solution doesn't, in theory, > yield results > > that are as good as the other options (since it pushes away > at a fixed > > angle, instead of towards nearby positions with ow weights), > but it should > > be really quick. > > > > I'm sure there are other options, or combinations of these, > that we could > > explore as well. > > > > > Could we be positioning icons on the basis of prior usage > patterns? By > this I mean that icons are spring'ed toward the XO icon with a > force > vector related to their recent usage patterns. Additionally, > activities > which are started at similar times could be spring'ed > together. I'm > envisioning a learning layout algorithm to distinguish the > most-used > activites. This layout necessitates the collection of usage > data which > could also be shared with our developers. > > > This is a good point, and I have to say "yes" and "no" at the same > time. I think your solution (I could be wrong!) is somewhat biased > toward the particular case of the Home view, but this algo needs to > work on the Groups and neighborhood views too. Perhaps there are some > (non-historical) ways to compare data in those views, but I'm not > sure. > > > In any case, there is another variable I would like to propose, which > is a suggested distance from the center of the screen -- or, if you'd > like, a spring of a particular k value between the center of the > screen and the object. My particular use case is that of search. I'd > like to see a bunch of search results slide onto the screen (and > non-results slide off), and I'd like it even more if the most relevant > matches moved closest to the center. This is essential for > scalability in the Groups and Neighborhood views. > > > I could also see this working to bring frequently used activities to > the center of the screen, and less frequently used ones to the edge > (thought that interferes with free placement). I also see it making > for an intuitive activity search in the favorites view. Even though > only favorites are shown on screen by default, anytime a search is > entered, the non-favorites (which, I propose, lay beyond the screen > edges) which match can slide in, and non-matching favorites slide off, > presenting this weighted view of matches. Clearing the entry, of > course, returns the view to its natural state, with only favorites > showing. > What about doing collision detection with Box2D (fast, well maintained etc..) ? This would enable any of the layout discussed here (and funny animations when new icons are dropped in the layout ;). > - Eben > > Erik > > riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Re: sugar start-up profiling
On Thu, 2008-07-31 at 17:27 +0100, Tomeu Vizoso wrote: > On Tue, Jul 29, 2008 at 3:15 PM, riccardo <[EMAIL PROTECTED]> wrote: > > Problem: sugar starts up slowly on the xo > > > > Tests were ran on an xo after a clean joyride-2181 install plus > > sucrose's activities. > > > > A graph of the ending part of the boot process can be found at: > > http://dev.laptop.org/~rlucchese/boot/boot.stats.svg > > (http://dev.laptop.org/~rlucchese/boot/boot.stats) > > > > It was obtained by running: > > $ picker -t 75 -o /tmp/boot.stats & > > $ grapher -i boot.stats -c10 > > > > The sampling period begins in `start()' in haldaemon's init script and > > lasts 75 seconds. > > > > The following tab shows cpu usage of the 10 processes that took more cpu > > time during the sampling time: > > $ grapher -i boot.stats -c13 -r cpu > > > > tot% ps% cmdline > > --- > >27.7/bin/sh /usr/bin/sugar > > 44.6 16.8jffs2_gcd_mtd0 > > 51.7 7.1 /usr/bin/env python /usr/bin/sugar-activity journal... > > 56.2 4.5 python /usr/bin/datastore-service > > 60.6 4.4 picker -t75 -o /tmp/boot.stats > > 64.3 3.8 python /usr/sbin/rainbow-daemon --daemon > > 68.0 3.6 xinit /usr/bin/olpc-session -- /usr/bin/X -fp built-ins... > > 71.3 3.3 /bin/sh /usr/bin/olpc-session > > 74.1 2.8 python /usr/bin/sugar-shell-service > > 76.9 2.8 python /usr/bin/sugar-presence-service > > 79.7 2.8 python /usr/sbin/rainbow-daemon --daemon > > 81.2 1.5 hald > > 82.6 1.4 ohmd > > > > Renicing jffs2_gcd_mtd0 to 19 in haldaemon's init script slightly > > speeds-up the last > > part of the boot: > > $ cat /home/olpc/.boot_time.prev (clean joyride) > > 56.27 > > > > $ cat /home/olpc/.boot_time > > 54.14 > > > > Note however that when renicing jffs2_gcd_mtd0, boot timings `became > > less deterministic, sometimes being slower than the `clean install' > > case. Stopwatch timings (from boot loader to fully redrawn shell): > > clean install : 1m34.0s > > renice trick : 1m30.2s +[0. to 4.5 sec] > > > > Would it be possible to make DS, sugar-presence-service and > > sugar-shell-service system services and thus decoupling them from the > > shell's start-up? > > Don't think so, as they look to me as quite tied to the user session. > What we should do (for 9.1.0) with the sugar-shell-service and the > journal is to run them inside the shell process, saving memory and > startup time. And we certainly shouldn't block when activating any > services, they should be started asynchronously. The DS seems to me a good candidate for being decoupled from the shell's startup. > > > A script was run that cat'ed all files (5700+) that sugar tries to open > > on boot. (http://dev.laptop.org/~rlucchese/boot/cat_sugar_startup_files) > > > > $ time sh cat_sugar_startup_files > > real 0m16.9s > > user 0m1.0s > > sys 0m12.2s > > > > Timings vary a lot when repeating the test (+-~30%). > > `top' shows that the remaining time goes to io-wait. > > > > Why don't those files get cached when repeating the test ? > > Interesting, anybody with kernel knowledge could comment on this? > > > cProfile statistics (KCG format) for sugar-shell (start-up only): > > http://dev.laptop.org/~rlucchese/boot/cProfile-shell > > > > Functions ordered by self-time (%): > > 32.2 gtk.main() > > 19.6 send_message_with_reply_and_block of dbus > > 12.8 block of dbus.lowlevel.PendingCall > > 7.3 grab of sugar._sugarext.KeyGrabber > > 3._add_weight of sugar/shell/view/home/grid.py > > 2.7 render_cairo of rsvg.Handle > > 1.12 __getitem__ of sugar/shell/view/home/grid.py > > --- > > 78.7 % > > > > Perhaps some dbus calls can be made asynchronous; this is taking 30+% of > > start-up time. > > Yup. Mostly service activation, see above. > > > It's curious that `grab` takes so much time: I don't see anything > > obvious looking at the code. > > Yeah, we should look at it, could be quite tasty low hanging fruit (7%). > > > Note that the layout for the favorite's view was set to the ring type; > > why is the shell computing weights in this case? > > I guess that's for the mesh and friends view? Oh, right! +1 for changing the algorithm. > > &g
sugar start-up profiling
matchbox-window-manager -use_titlebar... .. 77.9 2.8 49.25 25.74 python /usr/bin/sugar-presence-service .. 81.2 2.8 53.86 21.13 python /usr/bin/sugar-shell-service .. 85.7 4.5 58.89 16.10 python /usr/bin/datastore-service .. 92.8 7.1 62.86 12.13 usr/bin/env python /usr/... (journal) Accurate shell's start-up timings were taken by instrumentation: ---first launch (normal boot)--- /usr/bin/sugar : (1217317352.992) -- 0. entering main() in shell/main.py: (1217317368.162) -- 15.2 before entering gtk's mainloop shell/main.py: (1217317375.464) -- 22.5 ---second launch (ctrl+alt+erase)--- /usr/bin/sugar : (1217317725.747) -- 0. entering main() in shell/main.py: (1217317734.939) -- 9.2 before entering gtk's mainloop shell/main.py: (1217317741.023) -- 15.3 The datastore service and the journal will be profiled in separate sessions. Thanks, riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Re: automated tests
On Tue, 2008-07-22 at 17:20 +0200, riccardo wrote: > Hi, > > Is there already a facility for automated tests ? > (tinderbox + some-X-tool ?) > > If yes > - how does it works ? > - what kind of situations can it handle ? > > When redoing a tests it's a bit of a nightmare > to keep track of all changed files, or patch some of them > opportunely to run the `old' test. > > Was this issue already addressed ? Sorry, here I meant if there is already a tool in use that helps with the previous point. thanks ! riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
automated tests
Hi, Is there already a facility for automated tests ? (tinderbox + some-X-tool ?) If yes - how does it works ? - what kind of situations can it handle ? When redoing a tests it's a bit of a nightmare to keep track of all changed files, or patch some of them opportunely to run the `old' test. Was this issue already addressed ? thanks, Riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
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 > >> > > >>
yum issue on build 2181
Hi, when I try to install a package on the xo with yum i get: < Error: Cannot retrieve repository metadata(repmod.xml) for repository: olpc_development. Please ... > I'm sure it worked yesterday with the same build. thanks, riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Report on `switching between activities and the journal'
Hi, Problem: switching between activities and the journal is slow Test-case: the test consist of starting Write and switching between it and the journal for a sensible amount of time. All tests were run on a xo; the journal had 50 entries. Switching was automated by calling shell.activate_next_activity() every ~730ms (as the minimum value at which both activities could get completely redrawn). Real transition timings differ from the timer's period value of 730ms. The `switch' journal -> write takes an average of 735ms while the transition write -> journal takes values from 1 to 2 seconds. During the test, activate_next_activity() in Shell.py was called 695 times. cpu usage data gathered with Picker (pid 2564 is the Write activity): tot% ps% cmdline --- 34.6 python /usr/bin/sugar-activity journalactivity ... 57.1 22.6 python /usr/sbin/rainbow-daemon --daemon ... [Write] 77.9 20.8 python /usr/bin/datastore-service 85.0 7.2 python /usr/bin/sugar-shell 91.5 6.5 /usr/bin/X :0 -fp built-ins -wr -auth ... 97.1 5.6 picker (http://dev.laptop.org/~rlucchese/ActivitiesSwitching/journal-write/picker.stats) http://dev.laptop.org/~rlucchese/ActivitiesSwitching/journal-write/picker.stats.svg They were obtained by running: $ picker $ grapher -c6 -r cpu The 22.6% took by Write is due to the activity saving and loading its state (taking screnshots, reading/writing files..) regardless it change or not (http://lists.laptop.org/pipermail/devel/2008-July/016722.html). The shell is taking the 7% of cpu-time; isn't it too much for this task? cProfile statistics (KCacheGrind format) for the journal: http://dev.laptop.org/~rlucchese/ActivitiesSwitching/journal-write/cProfile-journalactivity The journal spends 69.4% of it's time in __refresh_idle_cb in listview.py. Ordering by function self-time: 29.7 : send_message_with_reply_and_block of dbus 15.7 : gtk.main() 10.9 : __init__ in activities/Journal.activity/palettes.py (2211 calls) 3.7 : cairo.Context.paint() 3.3 : __init__ sugar/graphics/palette.py Asynchronous dbus calls ? Perhaps icons and palettes could be cached ? cProfile statistics (KCacheGrind format) for Write: http://dev.laptop.org/~rlucchese/ActivitiesSwitching/journal-write/cProfile-write Similar results were already commented at http://lists.laptop.org/pipermail/devel/2008-July/016722.html for a similar task. cProfile statistics (KCacheGrind format) for the datastore-service aren't much interesting this time (a separate test case should be designed for it): http://dev.laptop.org/~rlucchese/ActivitiesSwitching/journal-write/cProfile-datastore cProfile statistics (KCacheGrind format) for sugar-shell: http://dev.laptop.org/~rlucchese/ActivitiesSwitching/journal-write/cProfile-shell 51.3% of time in the shell is going to send_message_with_reply_and_block of dbus. I guess this is because of the calls to the activities's services; maybe some of them can be made asynchronous ? Other functions showing particularly up by self-time are: 20.8 : gtk.main() 4.1 : __init_ in sugar/graphics/icon.py (1509 calls) 2.9 : wnck.Window.activate() 2.1 : __init_ in sugar/graphics/palette.py (859 calls) Perhaps icons and palettes could be cached ? sysprof statistics: http://dev.laptop.org/~rlucchese/ActivitiesSwitching/journal-write/sysprof.data Similar results were already commented at http://lists.laptop.org/pipermail/devel/2008-July/016722.html for a similar task. Only one more thing I note particularly: 1. Python is spending a lot of time in the kernel. Too much reading/writing to the nand ? thanks, riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
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 fun
Quick tabbing profiling (was Re: Report on `activities switching' profiling)
On Thu, 2008-07-17 at 10:31 +0200, riccardo wrote: > On Wed, 2008-07-16 at 11:17 -0400, Eben Eliason wrote: > > > > > > On Wed, Jul 16, 2008 at 11:04 AM, riccardo > > <[EMAIL PROTECTED]> wrote: > > (so that it never ends up in the journal) every 1100. The > > 1100ms value > > was chosen after some testing as the minimum value (or very > > near to it) > > at which both activities are able to completely redraw their > > windows on > > switching without artifacts. > > > > > > If you could, it would also be useful to test out the "quick tab" > > behavior. While it's true that after a short delay (I forget the > > exact number of ms) the activities redraw their windows, the behavior > > is supposed to prevent this redraw as long as the tabbing events > > happen quickly enough, so that the redraw doesn't add latency when > > attempting to bypass several activities in a row. I'm not sure if > > this is actually working properly on the XOs. > > Sure, I let you know when I have some results. > Test-case: the test consist of starting few activities and `quick-tabbing' between them for a sensible amount of time. Switching was automated by patching sugar-shell to call tabbinghandler.handle_next_activity() every 100ms; this value should trigger the `quick-tabbing' logic. All tests were run on a xo The following tab. and fig. show cpu time usage of the 8 processes taking more cpu time while running the test (pid 2233 and 2254 are two activities). (tot% us+sy) - (partial% us+sy) : cmdline - 39.8 : python /usr/bin/sugar-shell 75.0 - 35.1 : python /usr/bin/datastore-service 82.7 - 7.6 : picker -t30 86.5 - 3.8 : /bin/dbus-daemon --fork --print-pid 5 ... 88.9 - 2.3 : python /usr/bin/sugar-presence-service 90.8 - 1.8 : python /usr/sbin/rainbow-daemon --daemon (2233) 92.7 - 1.8 : python /usr/bin/sugar-activity journalactivity.Jou... 94.3 - 1.6 : python /usr/sbin/rainbow-daemon --daemon (2254) http://dev.laptop.org/~rlucchese/ActivitiesSwitching/quick-tabbing/picker.stats.svg (http://dev.laptop.org/~rlucchese/ActivitiesSwitching/quick-tabbing/picker.stats) They were obtained by running: $ picker -t30 -f10 $ grapher -c8 ! 75% of cpu-time goes to the shell and the datastore. next_activity() and previous_activity() in tabbinghandler.py call tabbing_set_activity(self, activity) in homemodel.py that in turn calls SetActive(False, ...) on the current activity and SetActive(True, ...) on the next activity. cProfile statistics (KCacheGrind format) for the shell and the datastore: http://dev.laptop.org/~rlucchese/ActivitiesSwitching/quick-tabbing/cProfile-shell http://dev.laptop.org/~rlucchese/ActivitiesSwitching/quick-tabbing/cProfile-datastore Ordering by function's self-time we have for sugar-shell: part% func name 26.8 : gtk.main() 11.9 : send_message_with_reply_and_block of dbus 8.2 : call_async of dbus 5.7 : __init__ in sugar/graphics/palette.py 8.2 5.3 : __init__ in sugar/graphics/icon.py 3.3 : gtk.Widget.show() 1.6 : gobject.GObject.connect() -- 62% Where means there is recursion between those functions. Ordering by function's self-time we have for the datastore: part% func name 41.9 : gobject.MainLoop.run 5.8 : flush in secore/indexerconnection.py 5.7 : posix.fork 3.9 : send_message of dbus 3.1 : replace in secore/indexerconnection.py 2.8 : cPickle.dumps 1.8 : perform in secore/fieldactions.py 1.5 : properties in datastore/model.py -- 67% I think sysprof statistics aren't extremely interesting in this case: http://dev.laptop.org/~rlucchese/ActivitiesSwitching/quick-tabbing/sysprof.data thanks, riccardo ___ 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
Re: Report on `activities switching' profiling
On Wed, 2008-07-16 at 11:17 -0400, Eben Eliason wrote: > > > On Wed, Jul 16, 2008 at 11:04 AM, riccardo > <[EMAIL PROTECTED]> wrote: > (so that it never ends up in the journal) every 1100. The > 1100ms value > was chosen after some testing as the minimum value (or very > near to it) > at which both activities are able to completely redraw their > windows on > switching without artifacts. > > > If you could, it would also be useful to test out the "quick tab" > behavior. While it's true that after a short delay (I forget the > exact number of ms) the activities redraw their windows, the behavior > is supposed to prevent this redraw as long as the tabbing events > happen quickly enough, so that the redraw doesn't add latency when > attempting to bypass several activities in a row. I'm not sure if > this is actually working properly on the XOs. Sure, I let you know when I have some results. > > I guess some time can be gained by not doing the conversion > Drawable -> > GdkPixbuf (sugar._sugarext.Preview.get_pixbuf) and perform the > scaling > and conversion directly on the first buffer. But IMHO the real > problem > is: > > ! Activities save their state and take previews continuously > regardless > of whether their state changed or not > > > Yeah, this would indeed be a problem. This ticket > -- http://dev.laptop.org/ticket/4365 -- deals with it to some extent, > and a patch is present there, but it's been ignored for some time now. > > > - Eben riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Re: How to make files uploaded at d.l.o accessible for downloads by anybody ?
On Wed, 2008-07-16 at 20:21 +0530, Sayamindu Dasgupta wrote: > On Wed, Jul 16, 2008 at 8:19 PM, riccardo <[EMAIL PROTECTED]> wrote: > > Hi, > > > > I'd like to have some files I uploaded at d.l.o accessible for downloads > > for anybody so that I can include links to them in reports send to the > > ml. > > > > How to do it ? ;) > > > > thanks, > > riccardo > > > > Put the files in $HOME/public_html > > -hth- > Sayamindu > > Thanks ! ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Report on `activities switching' profiling
Hi, Problem: switching between activities is noticeably too slow. Test-case: the test consist of starting Chat and Write and switching between them for a sensible amount of time. All tests were run on a xo. Switching was automated by patching sugar-shell to call shell.activate_next_activity() or shell.activate_previous_activity() (so that it never ends up in the journal) every 1100. The 1100ms value was chosen after some testing as the minimum value (or very near to it) at which both activities are able to completely redraw their windows on switching without artifacts. The following tab. and fig. show cpu time usage of the five processes taking more cpu time while running the test (the first two processes are chat and write). (tot% us+sy) - (partial% us+sy) : cmdline 28.9 - 28.9 : python /usr/sbin/rainbow-daemon --daemon 54.7 - 25.8 : python /usr/sbin/rainbow-daemon --daemon 66.5 - 11.7 : /usr/bin/X :0 -fp built-ins -wr -auth /home/olpc/.serverauth.1861 76.9 - 10.3 : python /usr/bin/datastore-service 85.3 - 8.4 : python /usr/bin/sugar-shell http://dev.laptop.org/~rlucchese/ActivitiesSwitching/chat-write/stats.picker.p84.svg (http://dev.laptop.org/~rlucchese/ActivitiesSwitching/chat-write/stats.picker) They were obtained by running: $ picker -t30 -f10 $ grapher -c5 ! 55% of cpu time goes to the activities, to do what? The two following files are cProfile statistics formatted to be viewed with KCacheGrind for the chat and write activity: http://dev.laptop.org/~rlucchese/ActivitiesSwitching/chat-write/cProfile-chat http://dev.laptop.org/~rlucchese/ActivitiesSwitching/chat-write/cProfile-write Ordering by function's self-time we have for chat: part% func name 17.3 : gtk.gdk.Pixbuf.scale_simple 13.6 : sugar._sugarext.Preview.get_pixbuf 10.4 : gtk.gdk.Pixbuf.save 6. : sugar._sugarext.Preview.take_screenshot -- 47.3% Values are almost the same for write. I guess some time can be gained by not doing the conversion Drawable -> GdkPixbuf (sugar._sugarext.Preview.get_pixbuf) and perform the scaling and conversion directly on the first buffer. But IMHO the real problem is: ! Activities save their state and take previews continuously regardless of whether their state changed or not Next, cProfile statistics for the shell: http://dev.laptop.org/~rlucchese/ActivitiesSwitching/chat-write/cProfile-shell Ordering by function self-time we have: part% func name 14.5 : set_message_with_reply_and_block of dbus 6.1 : 2.58 : __init__ of sugar/graphics/palette.py 1.65 : cairo.context.paint I don't understand what refers to (it appears also in the third entry); maybe Tomeu knows ? ;) Btw the shell is taking only the 8.4% of the total cpu time. There also cProfile statistics for the DS and the Journal but they are not very interesting this time: http://dev.laptop.org/~rlucchese/ActivitiesSwitching/chat-write/cProfile-datastore http://dev.laptop.org/~rlucchese/ActivitiesSwitching/chat-write/cProfile-journal The last tool we used is sysprof: http://dev.laptop.org/~rlucchese/ActivitiesSwitching/chat-write/stats.sysprof What it shows is somehow more difficult to comment on; I think is much more clear to just look at sysprof. Much time is spent in __PangoFontset_class_init->__do_global_ctors_aux; is this libpango or the python-pango bindings being 'reloaded' at every switch ? Next, `notable' thing is a memcpy in the xorg libfb module; all the screenshots ? libcairo doesn't seem to show up particularly. Did I miss something interesting in these tests ? Thanks, riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
How to make files uploaded at d.l.o accessible for downloads by anybody ?
Hi, I'd like to have some files I uploaded at d.l.o accessible for downloads for anybody so that I can include links to them in reports send to the ml. How to do it ? ;) thanks, riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Re: Re: Faster Launch of Activities
On Tue, 2008-07-15 at 11:47 +0200, riccardo wrote: > On Tue, 2008-07-15 at 05:01 -0400, Greg Smith wrote: > > description? > > > > It would be useful to see a comparison of build 656 v 703 v 708 v > > latest > > joyride. That's a lot so just 703 (last release image) vs latest > > Joyride > > would the top priority. > I'm not instrumenting the code but using a stopwatch so timings are a > bit rough. > > The test: > - reboot the machine > - wait that jfss2_gcd_mtd0 finishes hogging the cpu > (around 50 secs from when the shell is displayed) > - go to the listview > (*) > - for every activity (one at time), from the drop menu->start and take > the time until the full window redrawn > > - do it again from point (*) if you want to see the difference between > first startup and 'warm' startup > > I also use to gather stats with Picker while doing the test, to see > what processes are taking more cpu time; it also helps to catch > conditions where activities are fully redrawn at time x but really are > fully loaded at x+20sec (easy to see in etoys and browse). > > Are both first and second launch timings needed ? > > > Michael, > > > > What is the latest version of Joyride that people should be testing? > > > > I re-read your status e-mail July 12 and didn't see it in there: > > http://lists.laptop.org/pipermail/devel/2008-July/016457.html > > > > I didn't click on all the links so let me know if I missed it > > somewhere. Could anybody confirm the following points please ? - builds numbers - if it's ok to take those timings as explained above thanks, riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Re: Re: Faster Launch of Activities
On Tue, 2008-07-15 at 05:01 -0400, Greg Smith wrote: > description? > > It would be useful to see a comparison of build 656 v 703 v 708 v > latest > joyride. That's a lot so just 703 (last release image) vs latest > Joyride > would the top priority. I'm not instrumenting the code but using a stopwatch so timings are a bit rough. The test: - reboot the machine - wait that jfss2_gcd_mtd0 finishes hogging the cpu (around 50 secs from when the shell is displayed) - go to the listview (*) - for every activity (one at time), from the drop menu->start and take the time until the full window redrawn - do it again from point (*) if you want to see the difference between first startup and 'warm' startup I also use to gather stats with Picker while doing the test, to see what processes are taking more cpu time; it also helps to catch conditions where activities are fully redrawn at time x but really are fully loaded at x+20sec (easy to see in etoys and browse). Are both first and second launch timings needed ? > Michael, > > What is the latest version of Joyride that people should be testing? > > I re-read your status e-mail July 12 and didn't see it in there: > http://lists.laptop.org/pipermail/devel/2008-July/016457.html > > I didn't click on all the links so let me know if I missed it > somewhere. > thanks, riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Re: Faster Launch of Activities
On Mon, 2008-07-14 at 13:48 -0400, Chris Ball wrote: > Hi, > >> Let's get it on the roadmap for 9.1, when we've got time to >> actually make the fixes required and test them properly (unless >> someone really believes that speeding up sugar is a 4 line patch). > > I'd like to see an activity startup time comparison (just taken with a > stopwatch) between 650, joyride before the new sugar shell but after > rainbow prelaunch was added, and latest joyride. We should do this > before we ship 8.2, and in future we should try to publish changes to > activity startup time alongside patches that touch activity launch. > > I was planning on doing this measurement myself, but it's not getting to > the top of my stack. Could I persuade someone else to volunteer? I already have them for one of the latest joyrides. For my work I normally take first start-up and second launch timings. I haven't yet checked whether rainbow is now started after X in the latest joyride or if this is coming soon in the next builds. Would make sense for you to have the same timings taken also after restarting rainbow ? I'm not familiar with builds changelogs since 650; let me know from which of them you'd like these timings. riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Re: Introduction to `picker' and git link
On Wed, Jul 9, 2008 at 11:05 AM, Tomeu Vizoso <[EMAIL PROTECTED]> wrote: > On Wed, Jul 9, 2008 at 12:07 AM, Michael Stone <[EMAIL PROTECTED]> wrote: >> >> Perhaps you could modify the display so that each track is prominently >> labeled with the full arguments to the process? > > Yes, I'm curious to see the same graph with the process name as well > as the full command. I pushed the fixes to the git tree. In fact cmdline texts already had to be there but I wasn't accounting for the bogus format of /proc/x/cmdline. Here is a new example boot trace (I lost the .picker file I used yesterday): wget http://www.bodhidharma.info/out.grapher.svg This was obtained with $ picker -t120 -f10 (again from sshd's init script) $ grapher -p80 I'm going to rearrange cmdline texts to make them easier to read ;) Thanks, riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Introduction to `picker' and git link
Hi, as part of my intern work on profiling sugar, I've written a little application for gathering system and per process statistic from /proc called. It may reveal itself useful in catching interferences between processes or when profiling cpu/mem usage of long running processes. In fact there are two executables, picker and grapher. For my purposes picker is run on the xo and grapher on a pc to output pretty figures from the statistics blob generated by the first. An example figure can be found at: (it's quite big; better not to open it in a browser) wget http://www.bodhidharma.info/out.grapher.svg This figure shows the xo boot (starting from start() in sshd's init script) and lasts for 120sec (the sampling rate is 10Hz); the figure was generated by only showing the processes with higher cpu-time and that took up to 75% of the total cpu-time taken by all processes running on the xo for the `picking' time. In the future grapher may be extended to show more info, and maybe integrate timed sugar debug logs. Git tree is at: git+ssh://[EMAIL PROTECTED]/git/activities/picker Both executables take the -h option. Questions, hints, requests or bug reports .. I appreciate them all ;) Thanks, riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
Re: Project name: Picker is set up
Hi, There was a mistake on assigning the project. Thanks, riccardo On Tue, Jul 8, 2008 at 5:32 PM, Henry Edward Hardy <[EMAIL PROTECTED]> wrote: > Tue, 8 Jul 2008 13:13:42 +0200, "Riccardo Lucchese" > <[EMAIL PROTECTED]> wrote: > > 1. Project name: Picker > > Done. Your tree is here: > git+ssh://[EMAIL PROTECTED]/git/activities/picker > > Please follow instructions here for importing your project: > http://wiki.laptop.org/go/Importing_your_project > > Let us know if you have any problems with your tree. Happy hacking. > > Cheers, > > -- > Henry Edward Hardy > [EMAIL PROTECTED] > > ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
[project account request]
1. Project name :Picker
2. Existing website, if any :
3. One-line description :Lightweight system and processes
statistics (cpu/mem/io) gatherer.
4. Longer description :Gathers system and processes statistics from /proc
:and graphs them to pretty figures.
:
:It is useful to catch interactions
between processes and study
: cpu/mem/io usage of long running processes
5. URLs of similar projects :http://www.bootchart.org/
6. Committer list
Please list the maintainer (lead developer) as the first entry. Only list
developers who need to be given accounts so that they can commit to your
project's code repository, or push their own. There is no need to list
non-committer developers.
Username Full name SSH2 key URLE-mail
- --
#1 riccardo Riccardo Lucchese
riccardo.lucchese gmail.com
#2
#3
...
If any developers don't have their SSH2 keys on the web, please attach them
to the application e-mail.
7. Preferred development model
[ ] Central tree. Every developer can push his changes directly to the
project's git tree. This is the standard model that will be familiar to
CVS and Subversion users, and that tends to work well for most projects.
[X] Maintainer-owned tree. Every developer creates his own git tree, or
multiple git trees. He periodically asks the maintainer to look at one
or more of these trees, and merge changes into the maintainer-owned,
"main" tree. This is the model used by the Linux kernel, and is
well-suited to projects wishing to maintain a tighter control on code
entering the main tree.
If you choose the maintainer-owned tree model, but wish to set up some
shared trees where all of your project's committers can commit directly,
as might be the case with a "discussion" tree, or a tree for an individual
feature, you may send us such a request by e-mail, and we will set up the
tree for you.
8. Set up a project mailing list:
[ ] Yes, named after our project name
[ ] Yes, named __
[X] No
When your project is just getting off the ground, we suggest you eschew
a separate mailing list and instead keep discussion about your project
on the main OLPC development list. This will give you more input and
potentially attract more developers to your project; when the volume of
messages related to your project reaches some critical mass, we can
trivially create a separate mailing list for you.
If you need multiple lists, let us know. We discourage having many
mailing lists for smaller projects, as this tends to
stunt the growth of your project community. You can always add more lists
later.
9. Commit notifications
[ ] Notification of commits to the main tree should be e-mailed to the list
we chose to create above
[ ] A separate mailing list, -git, should be created for commit
notifications
[X] No commit notifications, please
10. Shell accounts
As a general rule, we don't provide shell accounts to developers unless
there's a demonstrated need. If you have one, please explain here, and
list the usernames of the committers above needing shell access.
I'd like being able to create personal git trees
11. Translation
[X] Set up the laptop.org Pootle server to allow translation
commits to be made
[ ] Translation arrangements have already been made at ___
12. Notes/comments:
This project is part of my work as an intern at OLPC.
Thanks,
riccardo
id_rsa.pub
Description: Binary data
___
Devel mailing list
Devel@lists.laptop.org
http://lists.laptop.org/listinfo/devel
Re: intern project on profiling sugar
On Fri, Jul 4, 2008 at 11:04 AM, Martin Dengler <[EMAIL PROTECTED]> wrote: > On Fri, Jul 04, 2008 at 08:56:34AM +0200, Riccardo Lucchese wrote: >> Hi >> >> I'm riccardo lucchese (rl) and will be an intern at olpc for the >> next ten weeks. My initial proposal for the internship was working >> on profiling sugar. i.e. why is activities startup so long ? ;) > > [...] > >> I was told that some of you have already specifically worked on this; >> that would be great if you could share your gotchas ;) > > http://dev.laptop.org/ticket/5228 > http://dev.laptop.org/ticket/5452 > http://dev.laptop.org/ticket/4349 > http://dev.laptop.org/ticket/7212 yeah, exactly ;) > > Martin > Thanks ! riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
intern project on profiling sugar
Hi I'm riccardo lucchese (rl) and will be an intern at olpc for the next ten weeks. My initial proposal for the internship was working on profiling sugar. i.e. why is activities startup so long ? ;) Right now I'm working on a tool for gathering cpu/mem/io statistics on the xo that produces pretty figures like bootchart does (http://www.bootchart.org/images/bootchart.png); the problem with bootchart was that it is quite heavyweight at decent sampling frequencies. This tool will be used for profiling activities startup and other actions suffering of long delaying. It is almost finished. With the same goal I'm writing a script that extracts perfs timings from data logged by sugar components so that it will be possible to run automated `regression' tests in the future. These tools will be used with other common profiling tools like the embedded python profiler, sysprof and oprofile. I was told that some of you have already specifically worked on this; that would be great if you could share your gotchas ;) I appreciate any hints on features those tools should have and any comments on this work! Thanks ! riccardo ___ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel
