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.8 jffs2_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. > > > High level tasks/functions ordered by total-time: > > 67.3 gtk.main() > > 33.6 __init__ of sugar/view/Shell.py > > 16.8 _start_journal_idle of sugar/view/Shell.py > > 11.6 __init__ shell/view/keyhandler.py > > 7.5 add sugar/shell/view/home/spreadlayout.py > > > > Note that 45% of Shell.__init__ and the 89% of _start_journal_idle > > went to blocking dbus calls. > > Just service activation, right? > > The datastore service and the journal will be profiled in separate > > sessions. > > Cool, that will be interesting as well. > > Nice job, in case startup time becomes a priority, we know now where to look > at. > > Thanks, > > Tomeu riccardo _______________________________________________ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel